Status of profiling

[altie]

I see that there are some profiling hooks in the form of the SCOPED_TIMER macro, TimeProfiler.h and TimeProfiler.cpp. I don't see anywhere that the values a ScopedTimer or CTimeProfiler get printed or used. Are these intended only for use within a debugger? I think it could be useful to emit this data in CSV for analysis.

I'll produce code for that if it's of any value.

[Tobi]

They are the source of what you see when you press 'b'.

[lurker]

Even just being able to type a command to dump the currently displayed data would be very useful. There is a bug that causes spring to lock up for long periods, but I can't read the chart properly when it shoots up that high, and it's not feasable to pause instantly after a 20 second lockup. I should get back to that with a debugger, kind of forgot about it..

[Tobi]

Sounds like the bug I had yesterday in 0.77b5.

I debugged it for a while, here are my notes: http://pastebin.com/f154cb02d

And some useful paste of what I said to BD about it:

[19:21:30] <[RoX]Tobi> know what happened in game yesterday that made it hang?
[19:21:37] <BrainDamage> sure
[19:21:45] <[RoX]Tobi> something, dunno what yet, created 70k CSimpleParticleSystems
[19:21:52] <BrainDamage> o_O
[19:21:59] <[RoX]Tobi> all linked to same unit probably
[19:22:14] <[RoX]Tobi> so when they where all destructed in same frame / frame close to each other
[19:22:17] <BrainDamage> i tell you
[19:22:20] <BrainDamage> it's the krogoth
[19:22:23] <[RoX]Tobi> the death dependence stuff crapped out
[19:22:29] <[RoX]Tobi> because it's uses std::list
[19:23:06] <[RoX]Tobi> and worst case complexity for removing n elements from list (without having iterator), which I suspect happened here, is O(n^2)
[19:23:20] <BrainDamage> ouch
[19:23:25] <BrainDamage> so the server froze
[19:23:59] <[RoX]Tobi> so it was probably doing about 49e8 loops to get the stuff removed
[19:24:01] <[RoX]Tobi> clients too
[19:24:19] <[RoX]Tobi> actually, when I ran replay it didn't hang
[19:24:26] <[RoX]Tobi> well, didn't hang infinitely
[19:24:31] <[RoX]Tobi> just hickup of a minute or so

[altie]

I'm thinking about having a pre-game checkbox, or setting in settings.exe, to enable or disable profiling for a given section. If you had a fine-grained choice of what profiling to run, are there any new sections of code you think should be available for profiling? Any already timed sections that should be broken down further?

While I'm in there, we ought to be able to get much better accuracy going from SDL_GetTicks() to clock() from ctime.h.

[Tobi]

Hmm not on all platforms IIRC. AFAIK from the past clock()'s output only incremented once every 18.2 seconds on some platforms.

Otherwise why would people generally use QueryPerformanceCounter on windows and gettimeofday on Linux for measuring small timespans.

What I've seen from BrainDamage's use of oprofile however, I wouldn't really bother making it better. There are much better alternatives around for profiling then some custom built in code..