AI is tooooooo slow

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
EricF
Space Dragon
Posts: 282
Joined: Fri Jul 29, 2016 10:12 am

Re: AI is tooooooo slow

#16 Post by EricF » Tue Aug 09, 2016 2:00 pm

Could you start a game with just a single AI and pass turns until it becomes slow, then post the logs again?
Will do

User avatar
EricF
Space Dragon
Posts: 282
Joined: Fri Jul 29, 2016 10:12 am

Re: AI is tooooooo slow

#17 Post by EricF » Tue Aug 09, 2016 2:05 pm

Update.

Playing new game 6 AIs 150 stars.
Up until turn 88, the AIs took a consistent 10 seconds to finish.
On turn 88 it went up to 35 seconds.
On turn 90 it was 55 seconds.
Playing 2016-08-02 test build.

I've attached a save game file for turn 90
Attachments

[The extension sav has been deactivated and can no longer be displayed.]


Ruldra
Krill Swarm
Posts: 14
Joined: Fri Oct 23, 2015 12:54 am

Re: AI is tooooooo slow

#18 Post by Ruldra » Tue Aug 09, 2016 6:15 pm

Just want to chime in and say that all my FreeOrion playing was done on a XP machine. By the time my turn started all AIs had finished their turns already.

My PC is dual core however, so maybe OP's single core processor is what's causing these issues.

User avatar
EricF
Space Dragon
Posts: 282
Joined: Fri Jul 29, 2016 10:12 am

Re: AI is tooooooo slow

#19 Post by EricF » Tue Aug 09, 2016 8:44 pm

Morlic wrote: A lot of time seems to be spent waiting while other AIs are handled ... Could you start a game with just a single AI and pass turns until it becomes slow, then post the logs again?
OK, I am on turn 192 of a 1 AI 100 star game.
There is very little delay. AI takes only 5 or 6 seconds to finish.
Before I would have been waiting 5 or more minutes at this point.
Do you want to see the AI log?

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

Re: AI is tooooooo slow

#20 Post by Geoff the Medio » Tue Aug 09, 2016 11:44 pm

Does the increase just happen if you play the same game from start to whatever turn it gets slow, without saving, quitting, and reloading? Does saving, quitting, and reloading improve turn processing times (after 1-2 turns of playing to get things to settle down after the reload...)

User avatar
EricF
Space Dragon
Posts: 282
Joined: Fri Jul 29, 2016 10:12 am

Re: AI is tooooooo slow

#21 Post by EricF » Wed Aug 10, 2016 12:19 am

Geoff the Medio wrote:Does the increase just happen if you play the same game from start to whatever turn it gets slow, without saving, quitting, and reloading? Does saving, quitting, and reloading improve turn processing times (after 1-2 turns of playing to get things to settle down after the reload...)
Done all these. Does not improve turn processing times.
(I did not try re-booting, tho)

As stated above, what did dramatically improve performance was playing against only one AI.

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

Re: AI is tooooooo slow

#22 Post by Geoff the Medio » Wed Aug 10, 2016 1:21 am

What does your system's memory use vs. time graph look like when processing a turn? Perhaps too many AIs are trying to allocate a bunch of memory to deserialize all at once, which is causing a bunch of swapping in/out with the hard drive?

User avatar
EricF
Space Dragon
Posts: 282
Joined: Fri Jul 29, 2016 10:12 am

Re: AI is tooooooo slow

#23 Post by EricF » Wed Aug 10, 2016 3:32 am

OK, some interesting things to report.
I went back and reloaded the 6 AI game.
Reloading it does seem to have made the turns go faster.
They take about 20 seconds or so
(up from the 10 from pre turn 88, but less than the 55 of turn 90).
Looking at the Task manager it looks like the FreeorionCA processes are still only taking about 10 seconds to finish, but the Freeoriond process sucks up the rest of the cpu for the next 10 seconds.
Played till turn 97 and this pattern has been pretty consistent.
Paging file use does not appear to be unusual.
FOTM.JPG
FOTM.JPG (55.35 KiB) Viewed 223 times

User avatar
EricF
Space Dragon
Posts: 282
Joined: Fri Jul 29, 2016 10:12 am

Re: AI is tooooooo slow

#24 Post by EricF » Fri Oct 28, 2016 2:46 pm

I've been playing a new game. Latest test build from Oct 12.
200 stars 4 AI's
I'm on around turn 200. Turns take on average about 5 minutes to complete.
That is most turns take around 5 minutes. A few turns will take 10 minutes and a few turns will take less than a minute.
I have about 90 ships. From the ship count graph I would guestemate one AI has about 150 ships while two more have around 130. The fourth AI has been eliminated.
From all this info I would assume I am losing, but I would really like to finish this game and see if I can pull it off as most of the times I do not get challenged. However, I'm not sure if I can, because of the turn lengths.
I attached some logs right after a seven minute long turn.
freeorion.log
(592.23 KiB) Downloaded 5 times
freeoriond.log
(1011.37 KiB) Downloaded 6 times
All the AI logs are well over 2 Megs.
Let me know if you need them and we can work something out.

Sorry, but I may have to leave and come back to this game when this has gotten better.
It is evidently too much for my single core 32 bit machine.

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

Re: AI is tooooooo slow

#25 Post by Geoff the Medio » Fri Oct 28, 2016 3:13 pm

EricF wrote:I attached some logs right after a seven minute long turn.
First thing I suggest is switching the save format to binary: Options / Other / Create Binary Save File. It currently looks like it's taking ~30 seconds each save to do the actual saving.

Otherwise, it looks like the biggest gaps in the server log are due to AIs taking a long time... several minute gaps between the same AI requesting a new object ID, for example, with nothing else happening in that time.

As such, posting an AI log might be helpful. You could perhaps zip it first?

And just update an AI log after playing one or two turns after starting the game / loading the save, not several turns which will make the log file longer / bigger.

User avatar
EricF
Space Dragon
Posts: 282
Joined: Fri Jul 29, 2016 10:12 am

Re: AI is tooooooo slow

#26 Post by EricF » Sun Oct 30, 2016 11:22 am

OK, got a chance to play again.
Here are the logs after a long turn 5+ minutes.
freeorion.log
(150.14 KiB) Downloaded 5 times
freeoriond.log
(218.16 KiB) Downloaded 6 times
AI_1.log
(816.04 KiB) Downloaded 6 times

User avatar
EricF
Space Dragon
Posts: 282
Joined: Fri Jul 29, 2016 10:12 am

Re: AI is tooooooo slow

#27 Post by EricF » Sun Oct 30, 2016 11:28 am

The rest
AI_2.zip
(111.73 KiB) Downloaded 5 times
AI_3.log
(22.06 KiB) Downloaded 5 times
AI_4.zip
(138.23 KiB) Downloaded 5 times
After reloading a save the game turns go by fairly quickly.
It doesn't really slow down until a few turns are played. Maybe 3-5.
Might be able to use that to get through this game. :)

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

Re: AI is tooooooo slow

#28 Post by Geoff the Medio » Sun Oct 30, 2016 11:59 am

EricF wrote:After reloading a save the game turns go by fairly quickly.
It doesn't really slow down until a few turns are played. Maybe 3-5.
Could you watch the memory usage of the AI processes over that time? Perhaps it increases each turn a similar amount, or suddenly jumps on the turn of the big slowdown?

From the biggest AI log, it looks like it's spending lots of time doing meter updates. But there's also a lot of unexplained (from just the log) 5 second jumps in the timestamps of log messages:

Code: Select all

2016-10-30 07:08:43.656250 [debug] AI : LoggingWrapper.cpp:23 :  - enemyval: 0
2016-10-30 07:08:43.656250 [debug] AI : LoggingWrapper.cpp:23 : planet 311, values [0.0, 101.80000305175781]
2016-10-30 07:08:48.625000 [debug] AI : LoggingWrapper.cpp:23 : Generating fleet orders
2016-10-30 07:08:48.625000 [debug] AI : LoggingWrapper.cpp:23 : Fleets by Role
2016-10-30 07:08:48.625000 [debug] AI : LoggingWrapper.cpp:23 : 
2016-10-30 07:08:48.640625 [debug] AI : LoggingWrapper.cpp:23 : Exploration Fleets: []
2016-10-30 07:08:48.640625 [debug] AI : LoggingWrapper.cpp:23 : Colonization Fleets: []
2016-10-30 07:08:48.656250 [debug] AI : LoggingWrapper.cpp:23 : Outpost Fleets: []
2016-10-30 07:08:53.609375 [debug] AI : LoggingWrapper.cpp:23 : Invasion Fleets: []
2016-10-30 07:08:53.625000 [debug] AI : LoggingWrapper.cpp:23 : Military Fleets: []
2016-10-30 07:08:53.625000 [debug] AI : LoggingWrapper.cpp:23 : Orbital Defense Fleets: [1093, 1094, 1095, 1523, 1826]
2016-10-30 07:08:53.640625 [debug] AI : LoggingWrapper.cpp:23 : Outpost Base Fleets: []
2016-10-30 07:08:53.656250 [debug] AI : LoggingWrapper.cpp:23 : Invasion Base Fleets: [2754]
2016-10-30 07:08:58.609375 [debug] AI : LoggingWrapper.cpp:23 : Securing Fleets: []  (currently FLEET_MISSION_MILITARY should be used instead of this Role)
2016-10-30 07:08:58.609375 [debug] AI : LoggingWrapper.cpp:23 : Exploration targets: None

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

Re: AI is tooooooo slow

#29 Post by Vezzra » Sun Oct 30, 2016 1:55 pm

Geoff the Medio wrote:But there's also a lot of unexplained (from just the log) 5 second jumps in the timestamps of log messages
EricF wrote:It is evidently too much for my single core 32 bit machine.
Maybe that's due to these AI processed not getting enough CPU cycles for a while...? 32bit single core is really low spec after all, especially considering that even moderate to high spec machines have been reported to struggle with FO...

User avatar
EricF
Space Dragon
Posts: 282
Joined: Fri Jul 29, 2016 10:12 am

Re: AI is tooooooo slow

#30 Post by EricF » Sun Oct 30, 2016 2:07 pm

Geoff the Medio wrote:Could you watch the memory usage of the AI processes over that time? Perhaps it increases each turn a similar amount, or suddenly jumps on the turn of the big slowdown?
Memory usage of all processes is pretty consistent. All pretty low. Even when one of the FreeorionCA processes is using 75% of the CPU the memory usage is still not high. Even explorer.exe uses more memory than any of the FreeorionCA processes.
WTM.JPG
WTM.JPG (54.84 KiB) Viewed 152 times
That's pretty much the values they stay at.
FreeOrion.exe will shoot up to around 107,000K, but drop down again when AIs have finished.

This is after playing about 15 turns. Hasn't been too bad though. Averaging about 4 minutes a turn and no 10 minute ones.

Post Reply