Page 1 of 1

F5 debug info - how to read it?

Posted: Mon Jan 12, 2015 6:09 pm
by psihius
So, we got a 5 people MP game going for 35 hours, and as you would imagine, it started to run slower and slower, so we embarked on a jorney to optimize stuff and make the factory as efficient as we can, at the same time we have quite a train setup....
The game is 0.11.10, we run 64bit Windows clients.

So, here is what map looks like now (we deconstructed our main starting factory, so we are half way building new one, that removed a lot of slowdowns)
The map
The supply area near the coal is the new robo-factory :)

So, with all that, here is what our F5 output looks like:
Image

I would like help with how to read it, so I can get an understanding on what areas need optimizing to generate as less CPU load as it is possible. Because we are at the point, where game gets very interesting and we like to continue.
Right now, in SP mode, this state runs perfectly fine, after I teared down the old big factory and removed (destroyed) a lot of stuff in logi network (at least 300k of items).

I'm a programmer by trait (although the WEB one), so i'm not scared to get all technical :)

Thanks!

P.S. I also uploaded the game save: https://www.wuala.com/psih/Factorio/Deb ... 0aKubaawhL

Re: F5 debug info - how to read it?

Posted: Mon Jan 12, 2015 6:22 pm
by DRBLN
Please advise, what should we do to increase FPS.
We'd really like to continue playing that mp in MP

Re: F5 debug info - how to read it?

Posted: Tue Jan 13, 2015 2:01 pm
by cube
Inserters, transport belts with many items moving (not blocked) and long underground belts with many items tend to take up the most cpu now. Kovarex looks like he is really looking forward to optimizing these, so you can expect an improvement in 0.12.0...

About the debug info -- the top half are mostly counts of various objects in game, not that interesting.
The bottom part are various timings. Numbers a/b mean miliseconds in last frame (maybe smoothed? I'm not sure) / maximum of miliseconds in a previous 10s window (this value is always at least 10s old).
If something is indented, then its time is also counted in the parent.

The top level items work run sequentially / in parallel like this:

Code: Select all

             /------ updates ------\
-- prepare -<                       >--
             \-- render --- flip --/
where update can happen once, twice or three times for every render (you see that in the fps/ups counter).

The map generator part is not too interesting in regular game, but shows time spent in doing various sub-tasks of map generator (which runs almost completely in parallel to the diagram above).

Technical enough? :-D

Re: F5 debug info - how to read it?

Posted: Tue Jan 13, 2015 7:44 pm
by psihius
What is CRC calculation, because right now, after playing a while longer, it's up to 11.7xx/22.xxx - and that's a lot, and FPS/UPS is 15/45 now :(

Re: F5 debug info - how to read it?

Posted: Wed Jan 14, 2015 9:26 am
by cube
CRC is the thing that checks for desyncs. It's a checksum of a partial save of the map which is compared between all the multiplayer clients and triggers desync if it differs. I have no idea why it takes so long for you.

Re: F5 debug info - how to read it?

Posted: Wed Jan 14, 2015 9:29 am
by cube
Moved this to bug reports.

Re: F5 debug info - how to read it?

Posted: Wed Jan 14, 2015 10:47 am
by kovarex
This is caused by a bug, that the offline players are still receiving alerts, but their alert queue is never updated, so their alert queue grows indefinitely.
I fixed this for 0.11.12 now, but until it you move to the new version, you can solve it by calling (ideally when the players you want to continue are online, so they are not deleted)

Code: Select all

/c game.removeofflineplayers()

Re: F5 debug info - how to read it?

Posted: Wed Jan 14, 2015 11:43 am
by psihius
kovarex wrote:This is caused by a bug, that the offline players are still receiving alerts, but their alert queue is never updated, so their alert queue grows indefinitely.
I fixed this for 0.11.12 now, but until it you move to the new version, you can solve it by calling (ideally when the players you want to continue are online, so they are not deleted)

Code: Select all

/c game.removeofflineplayers()
That feeling when a post becomes a closed bug fix :D

Thanks for the info, although in our case we have 5-6 people playing and not always everyone is in, so for now I think we will need to store stuff in the chests, clear out all players except the host and than save :) A little tedious, but should work for now.

And, I actually have a question about the Electric network - does the electric pole amount affects the calclulation, or is it just the sheere amount of acumulators and solar panels, that judjing by the numbers on the screenshot, takes a good portion of the time (especially compared to logistics manager in our case). If it's the accumulators and solar panels - a way to combine them into bigger entities would be a good idea for optimization: like a blueprint layout may be converted to single entity, so the game has to calculate only one item instead of a field of 150 solar panels and 181 acumulators, for example (this is a layout of a robopot and a solar field with accumulators and substation the size of the roboports logistic area - you can put them side by side with robonetwork extending automatically).

Re: F5 debug info - how to read it?

Posted: Wed Jan 14, 2015 11:53 am
by Cloner
If it's the accumulators and solar panels - a way to combine them into bigger entities would be a good idea for optimization.[/quote]
+1 to this, a big eco-friendly factory has 1k solars+1k accus, there should be a way to optimize perfomance by combining them somehow.

Re: F5 debug info - how to read it?

Posted: Wed Jan 14, 2015 11:59 am
by kovarex
psihius wrote: And, I actually have a question about the Electric network - does the electric pole amount affects the calclulation, or is it just the sheere amount of acumulators and solar panels
The electric pole amount has no effects. Just the amount of all the entities connected to the electrical network.
psihius wrote: That judjing by the numbers on the screenshot, takes a good portion of the time (especially compared to logistics manager in our case). If it's the accumulators and solar panels - a way to combine them into bigger entities would be a good idea for optimization: like a blueprint layout may be converted to single entity, so the game has to calculate only one item instead of a field of 150 solar panels and 181 acumulators, for example (this is a layout of a robopot and a solar field with accumulators and substation the size of the roboports logistic area - you can put them side by side with robonetwork extending automatically).
Well, yes there is surely space for optimisations. The most logical step will be to group all the accumulator/solar panels with the same amount of buffer capacity and calculate this group as one object. The individual machines would need to have the pointer to the group representation so it can still show it's values and also to be able to solve when the network is disconnected. But it is totally doable.

This is one of the many things that shows that the game can be still optimised by many factors.

Anyway, the biggest drain regarding the update now is usually inserters/transport belts/underground belts, so it is most logical to solve these first, once it is done it might have sense to solve the biggest drainers again.

Re: F5 debug info - how to read it?

Posted: Wed Jan 14, 2015 12:19 pm
by psihius
Yeah, thats logical :)
Although in our case we do a robo factory now, we have no belts what so ever :)
Removed a ot of CPU load.

Re: F5 debug info - how to read it?

Posted: Wed Jan 14, 2015 1:29 pm
by psihius
Just tried the /c game.removeofflineplayers() solution - short of a miracle...

Re: F5 debug info - how to read it?

Posted: Mon Mar 07, 2016 10:00 pm
by roidal
Is there some further description of the Timing-Values somewhere?

While iam able to imagine what "Update" does, i need a more exact description about "Renderer preparation", "Renderer", "Flip" and "Frame cycle".

Also the "Frame cycle" seems to be somehow weird, sometimes increasing up to 100 and then droping down to about 10... and with no relationship with the other values.

For example...if "Frame cycle" is about 10 its even lower than the "Flip" value, but if its 100 its greater then the sum of all other components.

Re: F5 debug info - how to read it?

Posted: Mon Mar 07, 2016 11:34 pm
by kovarex
roidal wrote:Is there some further description of the Timing-Values somewhere?

While iam able to imagine what "Update" does, i need a more exact description about "Renderer preparation", "Renderer", "Flip" and "Frame cycle".

Also the "Frame cycle" seems to be somehow weird, sometimes increasing up to 100 and then droping down to about 10... and with no relationship with the other values.

For example...if "Frame cycle" is about 10 its even lower than the "Flip" value, but if its 100 its greater then the sum of all other components.
The frame cycle should be always 100 if it works properly (no slowdowns etc).
Render preparation is the collection of data for rendering, it is done in paralell, but update can't run at that moment, render itself is processing of this data to draw the screen, while update is running.

Re: F5 debug info - how to read it?

Posted: Tue Mar 08, 2016 7:51 am
by roidal
kovarex wrote: The frame cycle should be always 100 if it works properly (no slowdowns etc).
Render preparation is the collection of data for rendering, it is done in paralell, but update can't run at that moment, render itself is processing of this data to draw the screen, while update is running.
First, thanks for your answer!

Am I correct that Frame cycle ist not a time-value but how many cycles was calculated the last second? In this case: how can it happen to drop down to 10 especially without reducing the framerate? Is "Frame cycle" only related to game-simulation (update) and not rendering?

And what does "Flip" mean?

PS.: I attached a screenshot where the "Frame cycle" is below 10...is there an explaination for that?

Re: F5 debug info - how to read it?

Posted: Thu Apr 21, 2016 4:26 am
by JasonC
In the Map Generator portion of the stats, what does the P, C, and A signify?

Re: F5 debug info - how to read it?

Posted: Thu Apr 21, 2016 4:42 am
by sillyfly
roidal wrote: And what does "Flip" mean?
It refers to page flipping. Basically the time it takes the GPU to change the display from one frame to the next. I believe this value includes the time waited for VSync, so a large value may not necessarily indicate a problem, but I'm not sure about it.

Re: F5 debug info - how to read it?

Posted: Thu Apr 21, 2016 1:40 pm
by roidal
sillyfly wrote:I believe this value includes the time waited for VSync, so a large value may not necessarily indicate a problem, but I'm not sure about it.
I was asking about that especially because of the large value but meanwhile i was able to figure out that it is exactly as you say...it accounts the wait-time for VSync too.
After disabling VSync its only about 1/3 compared to the value from the screenshot and "Framecycle" is about 100.