Late game (after turn 200) server disconnects

Describe your experience with the latest version of FreeOrion to help us improve it.
Forum rules
Always mention the exact version of FreeOrion you are testing.

When reporting an issue regarding the AI, if possible provide the relevant AI log file and a save game file that demonstrates the issue.
Message
Author
User avatar
Geoff the Medio
Programming, Design, Admin
Posts: 12276
Joined: Wed Oct 08, 2003 1:33 am
Location: Munich

Re: Late game (after turn 200) server disconnects

#16 Post by Geoff the Medio » Fri Mar 24, 2017 1:24 pm

Vezzra wrote:On Windows and Linux the load game dialog pops up without noticeable delay, on Mac it took 8 sec.
Can you start the program, click load game, wait until dialog pops up, cancel, quit, post the log files for all three systems?

eg for me on Windows with a few save files, it ends with:

Code: Select all

2017-03-24 14:21:24.085469 [debug] Client : HumanClientApp.cpp:590 : HumanClientApp::LoadSinglePlayerGame
2017-03-24 14:21:24.086470 [debug] Client : SaveFileDialog.cpp:671 : pathstring: C:\Users\Geoff\AppData\Roaming\FreeOrion\save
2017-03-24 14:21:24.086470 [debug] Client : SaveFileDialog.cpp:930 : SaveFileDialog::UpdatePreviewList
2017-03-24 14:21:24.088458 [error] Client : SaveFileDialog.cpp:595 : SaveFileListBox::FilterColumns: Column not found: ,
2017-03-24 14:21:24.089471 [error] Client : SaveFileDialog.cpp:595 : SaveFileListBox::FilterColumns: Column not found: ,
2017-03-24 14:21:24.089471 [error] Client : SaveFileDialog.cpp:595 : SaveFileListBox::FilterColumns: Column not found: ,
2017-03-24 14:21:24.089471 [error] Client : SaveFileDialog.cpp:595 : SaveFileListBox::FilterColumns: Column not found: ,
2017-03-24 14:21:24.089471 [error] Client : SaveFileDialog.cpp:595 : SaveFileListBox::FilterColumns: Column not found: ,
2017-03-24 14:21:24.089471 [error] Client : SaveFileDialog.cpp:595 : SaveFileListBox::FilterColumns: Column not found: ,
2017-03-24 14:21:24.089471 [error] Client : SaveFileDialog.cpp:595 : SaveFileListBox::FilterColumns: Column not found: ,
2017-03-24 14:21:24.089471 [error] Client : SaveFileDialog.cpp:595 : SaveFileListBox::FilterColumns: Column not found: ,
2017-03-24 14:21:24.089471 [error] Client : SaveFileDialog.cpp:595 : SaveFileListBox::FilterColumns: Column not found: ,
2017-03-24 14:21:24.089471 [error] Client : SaveFileDialog.cpp:595 : SaveFileListBox::FilterColumns: Column not found: ,
2017-03-24 14:21:24.089471 [error] Client : SaveFileDialog.cpp:595 : SaveFileListBox::FilterColumns: Column not found: ,
2017-03-24 14:21:24.089471 [error] Client : SaveFileDialog.cpp:595 : SaveFileListBox::FilterColumns: Column not found: ,
2017-03-24 14:21:24.089471 [error] Client : SaveFileDialog.cpp:595 : SaveFileListBox::FilterColumns: Column not found: ,
2017-03-24 14:21:24.089471 [error] Client : SaveFileDialog.cpp:595 : SaveFileListBox::FilterColumns: Column not found: ,
2017-03-24 14:21:24.089471 [error] Client : SaveFileDialog.cpp:595 : SaveFileListBox::FilterColumns: Column not found: ,
2017-03-24 14:21:24.089471 [error] Client : SaveFileDialog.cpp:595 : SaveFileListBox::FilterColumns: Column not found: ,
2017-03-24 14:21:24.089471 [debug] Client : SaveFileDialog.cpp:597 : SaveFileDialog::FilterColumns: Visible columns: 5
2017-03-24 14:21:24.090472 [debug] Client : SaveFileDialog.cpp:554 : SaveFileDialog::LoadDirectories name: auto valid UTF-8: true
2017-03-24 14:21:24.090472 [debug] Client : SaveGamePreviewUtils.cpp:65 : LoadSaveGamePreviewData: Loading preview from: C:\Users\Geoff\AppData\Roaming\FreeOrion\save\cant_finish_colony_bases.sav
2017-03-24 14:21:24.091473 [debug] Client : SaveGamePreviewUtils.cpp:82 : Deserializing XML data
2017-03-24 14:21:24.091473 [debug] Client : SaveGamePreviewUtils.cpp:88 : Loaded preview with: 1 human players
2017-03-24 14:21:24.091473 [debug] Client : SaveGamePreviewUtils.cpp:96 : LoadSaveGamePreviewData: Successfully loaded preview from: C:\Users\Geoff\AppData\Roaming\FreeOrion\save\cant_finish_colony_bases.sav
2017-03-24 14:21:24.091473 [debug] Client : SaveGamePreviewUtils.cpp:65 : LoadSaveGamePreviewData: Loading preview from: C:\Users\Geoff\AppData\Roaming\FreeOrion\save\test.sav
2017-03-24 14:21:24.091473 [debug] Client : SaveGamePreviewUtils.cpp:82 : Deserializing XML data
2017-03-24 14:21:24.092474 [debug] Client : SaveGamePreviewUtils.cpp:88 : Loaded preview with: 1 human players
2017-03-24 14:21:24.092474 [debug] Client : SaveGamePreviewUtils.cpp:96 : LoadSaveGamePreviewData: Successfully loaded preview from: C:\Users\Geoff\AppData\Roaming\FreeOrion\save\test.sav
2017-03-24 14:21:24.092474 [debug] Client : SaveGamePreviewUtils.cpp:65 : LoadSaveGamePreviewData: Loading preview from: C:\Users\Geoff\AppData\Roaming\FreeOrion\save\uncom_xml.sav
2017-03-24 14:21:24.092474 [debug] Client : SaveGamePreviewUtils.cpp:82 : Deserializing XML data
2017-03-24 14:21:24.092474 [debug] Client : SaveGamePreviewUtils.cpp:88 : Loaded preview with: 1 human players
2017-03-24 14:21:24.092474 [debug] Client : SaveGamePreviewUtils.cpp:96 : LoadSaveGamePreviewData: Successfully loaded preview from: C:\Users\Geoff\AppData\Roaming\FreeOrion\save\uncom_xml.sav
2017-03-24 14:21:24.092474 [debug] Client : SaveGamePreviewUtils.cpp:65 : LoadSaveGamePreviewData: Loading preview from: C:\Users\Geoff\AppData\Roaming\FreeOrion\save\uncom_xml2.sav
2017-03-24 14:21:24.093475 [debug] Client : SaveGamePreviewUtils.cpp:82 : Deserializing XML data
2017-03-24 14:21:24.093475 [debug] Client : SaveGamePreviewUtils.cpp:88 : Loaded preview with: 1 human players
2017-03-24 14:21:24.093475 [debug] Client : SaveGamePreviewUtils.cpp:96 : LoadSaveGamePreviewData: Successfully loaded preview from: C:\Users\Geoff\AppData\Roaming\FreeOrion\save\uncom_xml2.sav
2017-03-24 14:21:27.959635 [debug] Client : SaveFileDialog.cpp:895 : SaveFileDialog::Cancel: Dialog Canceled
2017-03-24 14:21:27.976903 [debug] Client : HumanClientApp.cpp:612 : HumanClientApp::LoadSinglePlayerGame has empty filename. Aborting load.
2017-03-24 14:21:28.691966 [debug] Client : HumanClientApp.cpp:324 : HumanClientApp exited cleanly.
2017-03-24 14:21:28.694985 [debug] Client : HumanClientFSM.cpp:67 : (HumanClientFSM) ~IntroMenu
2017-03-24 14:21:28.715987 [debug] Client : chmain.cpp:310 : Human client main exited cleanly.
2017-03-24 14:21:28.728995 [debug] Client : Sound.cpp:268 : Audio disabled.
Interestingly, every time I restart the program, I get another set of "Column not found ," errors. The relevant line of config.xml appears to be

Code: Select all

<columns>time,,,,,,,turn,,,,,,,player,,,,,,,empire,,,,,,,file</columns>
Probly needs fixing. Edit: https://github.com/freeorion/freeorion/issues/1435

User avatar
Vezzra
Release Manager, Design
Posts: 4673
Joined: Wed Nov 16, 2011 12:56 pm
Location: Sol III

Re: Late game (after turn 200) server disconnects

#17 Post by Vezzra » Fri Mar 24, 2017 1:55 pm

Geoff the Medio wrote:Can you start the program, click load game, wait until dialog pops up, cancel, quit, post the log files for all three systems?
Yep, zip archive with the human client log from all three systems attached.

While trying to do that on Mac, I now noticed that the issue doesn't happen every time. Sometimes the load dialog pops up as fast as on Windows and Linux. The freeorion.log on Mac then looks the same as on the other systems. When it takes a couple of seconds to open the load game dialog box, I get "scoped timer" log entries for each savegame stating that loading the preview data took 800 and something ms to load.
Interestingly, every time I restart the program, I get another set of "Column not found ," errors.
Same here.
Attachments
logfiles.zip
(6.44 KiB) Downloaded 25 times

User avatar
Geoff the Medio
Programming, Design, Admin
Posts: 12276
Joined: Wed Oct 08, 2003 1:33 am
Location: Munich

Re: Late game (after turn 200) server disconnects

#18 Post by Geoff the Medio » Fri Mar 24, 2017 2:06 pm

Vezzra wrote:Sometimes the load dialog pops up as fast as on Windows and Linux. The freeorion.log on Mac then looks the same as on the other systems. When it takes a couple of seconds to open the load game dialog box, I get "scoped timer" log entries for each savegame stating that loading the preview data took 800 and something ms to load.
Perhaps it's a hard drive issue? Takes it a while to spin up and start streaming data?

User avatar
Vezzra
Release Manager, Design
Posts: 4673
Joined: Wed Nov 16, 2011 12:56 pm
Location: Sol III

Re: Late game (after turn 200) server disconnects

#19 Post by Vezzra » Fri Mar 24, 2017 2:21 pm

Geoff the Medio wrote:Perhaps it's a hard drive issue? Takes it a while to spin up and start streaming data?
Well, it's a SSD, so spinning up can't be the issue here (and anyway, in that case I'd expect the loading of the preview data of the first save game to take several seconds, and the preview data of the subsequent savegames should load as fast as on the other systems). Of course, in theory there could be some weird problem with my SSD, but so far I haven't noticed anything funny with my system, or any other applications that might indicate any such issues.

I also can't recognize any patterns. I've repeated the process of launching FO, cklicking "Load Game", cancelling and quitting the app several times in a row, and sometimes the load game dialog pops up immediately, sometimes it takes a few seconds. It's weird.

Can't test on other Mac systems right now, but will try to do whenever I get access to one, to check if this is a problem specifically with my system.

@mem359, do you have this issue on your system too? When you click "Load Game" on the main menu, does the load game dialog pop up immediately, or does it take some seconds?

User avatar
mem359
Dyson Forest
Posts: 214
Joined: Sun Jun 08, 2014 1:18 am

Re: Late game (after turn 200) server disconnects

#20 Post by mem359 » Fri Mar 24, 2017 2:30 pm

Vezzra wrote:@mem359, do you have this issue on your system too? When you click "Load Game" on the main menu, does the load game dialog pop up immediately, or does it take some seconds?
When I tried it now (multiple times), it pops up immediately. (Also using SSD drive.)
I'll keep an eye on this, in case the behavior changes.

How many save files do you have?
I only have 5 (plus the 10 auto saves), so maybe I need to spam more save files to really test if something is going on.

User avatar
Vezzra
Release Manager, Design
Posts: 4673
Joined: Wed Nov 16, 2011 12:56 pm
Location: Sol III

Re: Late game (after turn 200) server disconnects

#21 Post by Vezzra » Fri Mar 24, 2017 2:38 pm

mem359 wrote:How many save files do you have?
8.

LGM-Doyle
Programmer
Posts: 219
Joined: Mon Feb 29, 2016 8:37 pm

Re: Late game (after turn 200) server disconnects

#22 Post by LGM-Doyle » Fri Mar 24, 2017 3:07 pm

Thank you everyone for the additional information.

I pushed PR #1436, which fixes a problem with iterating over a map while deleting elements in the System::Copy() function.

Since, I can't replicate the crash I don't know if this fixes the crash.

I will wait for someone to test this.

I do not know why the load dialog is laggy.

User avatar
Vezzra
Release Manager, Design
Posts: 4673
Joined: Wed Nov 16, 2011 12:56 pm
Location: Sol III

Re: Late game (after turn 200) server disconnects

#23 Post by Vezzra » Fri Mar 24, 2017 3:21 pm

LGM-Doyle wrote:Since, I can't replicate the crash I don't know if this fixes the crash.

I will wait for someone to test this.
Just tested it, and it fixes the crash. @mem359: Geoff already merged the fix, so if you build FO yourself, just build the most recent master. Otherwise wait for the next weekly test builds. Please report back if the fix solved the problem for you too.
I do not know why the load dialog is laggy.
This might be some issue with my system, don't waste your time on it, at least not yet. The issue doesn't seem to happen on mem359's system, and I haven't been able to test on other Mac systems yet. Once I get the chance and the issue appears there too, I'll report back.

User avatar
mem359
Dyson Forest
Posts: 214
Joined: Sun Jun 08, 2014 1:18 am

Re: Late game (after turn 200) server disconnects

#24 Post by mem359 » Fri Mar 24, 2017 4:49 pm

Vezzra wrote:Just tested it, and it fixes the crash. @mem359: Geoff already merged the fix, so if you build FO yourself, just build the most recent master. Otherwise wait for the next weekly test builds. Please report back if the fix solved the problem for you too.
After compiling the BFOY, I have not been able to get the problem. I'll consider it fixed.

Post Reply