Forum > Games

Measure code execution and convert the result to milliseconds

<< < (7/7)

furious programming:

--- Quote from: WayneSherman on November 09, 2022, 12:43:57 am ---SDL_PumpEvents() seems to be the cause of the execution delay.  If you don't call it often enough it appears to take longer to execute.
--- End quote ---

Yeah, this is what my tests show (see the next paragraph).


--- Quote ---You can test this by putting a call to SDL_PumpEvents() ahead of the time measurement code:
--- End quote ---

This is exactly what I did yesterday and the results are clear — the following measurements of the uptime of SDL_PumpEvents itself:


--- Code: Pascal  [+][-]window.onload = function(){var x1 = document.getElementById("main_content_section"); if (x1) { var x = document.getElementsByClassName("geshi");for (var i = 0; i < x.length; i++) { x[i].style.maxHeight='none'; x[i].style.height = Math.min(x[i].clientHeight+15,306)+'px'; x[i].style.resize = "vertical";}};} ---time: 0.193ms | sample:  1934 | events: 26 // too longtime: 0.008ms | sample:    82 | events: 31time: 0.039ms | sample:   392 | events: 31time: 0.008ms | sample:    79 | events: 31time: 0.206ms | sample:  2062 | events: 32 // too longtime: 0.008ms | sample:    79 | events: 31time: 0.039ms | sample:   390 | events: 31time: 0.178ms | sample:  1777 | events: 31 // too longtime: 0.232ms | sample:  2316 | events: 32 // too longtime: 0.055ms | sample:   546 | events: 25time: 0.039ms | sample:   391 | events: 30time: 0.008ms | sample:    82 | events: 30time: 0.952ms | sample:  9519 | events: 43 // too longtime: 1.323ms | sample: 13228 | events: 47 // too looooooooong!time: 0.040ms | sample:   396 | events: 42time: 0.008ms | sample:    82 | events: 44time: 0.219ms | sample:  2190 | events: 51 // too longtime: 0.008ms | sample:    80 | events: 43time: 0.039ms | sample:   391 | events: 48time: 0.007ms | sample:    67 | events: 45time: 0.097ms | sample:   968 | events: 43time: 0.008ms | sample:    79 | events: 49time: 1.818ms | sample: 18183 | events: 47 // too looooooooong!time: 0.008ms | sample:    78 | events: 44time: 0.045ms | sample:   445 | events: 18time: 0.008ms | sample:    80 | events:  0time: 0.045ms | sample:   449 | events:  0time: 0.008ms | sample:    80 | events:  0time: 0.045ms | sample:   447 | events:  0time: 0.008ms | sample:    79 | events:  0time: 0.045ms | sample:   445 | events:  0time: 0.005ms | sample:    52 | events:  0time: 0.008ms | sample:    81 | events:  0time: 0.008ms | sample:    84 | events:  0time: 0.040ms | sample:   402 | events:  9time: 0.269ms | sample:  2687 | events: 32 // too longtime: 0.272ms | sample:  2717 | events: 13 // too longtime: 0.041ms | sample:   408 | events: 31
On the other hand, a single call to the SDL_PeepEvents function, returning dozens of events, always takes about 0.001ms (i.e. 1µs). I tested it yesterday too.

I checked using the Intel® VTune™ Profiler and unfortunately it looks like it is not SDL's fault, but the system's fault (see the attachment). It's just a pity that this profiler has some problems recognizing my CPU and that it shows the addresses of some functions instead of their names (SDL functions).

Any other lightweight and sensible Windows 10 64-bit profiling tool for native applications?

This Intel tool not only weighs 2GB, it also does not show some data (such as function names). LazProfiler would be great, I installed it, but Lazarus crashes during boot. I changed the code as suggested in this pull request, but it doesn't help — when Lazarus starts, the IDE freezes for several seconds, and then an error pops up. Dammit...

WayneSherman:

--- Quote from: furious programming on November 09, 2022, 04:04:41 pm ---I checked using the Intel® VTune™ Profiler and unfortunately it looks like it is not SDL's fault, but the system's fault (see the attachment).

--- End quote ---

SleepEX / NTDelayExecution is probably from the SDL_Delay call since that internally calls Sleep().  If so, this execution delay is on purpose.
https://github.com/libsdl-org/SDL/blob/main/src/timer/windows/SDL_systimer.c#L172

Without function names it is hard to know where WaitForMultipleObjectsEX is being called...

SDL_PumpEvents calls SDL_PumpEventsInternal
https://github.com/libsdl-org/SDL/blob/main/src/events/SDL_events.c#L858

which (among other things) calls WIN_PumpEvents(_THIS)
https://github.com/libsdl-org/SDL/blob/main/src/video/windows/SDL_windowsevents.c#L1778

WIN_PumpEvents processes the Windows message event queue:

PeekMessage(&msg, NULL, 0, 0, PM_REMOVE))
...
DispatchMessage(&msg);

If you can hook the Windows message queue, you can see what messages are coming in, how often, and how many.

PumpEvents behaves as if a backlog of events is building up and if you don't call it often enough it takes longer to process the events.  Maybe the events that are causing the delay are Windows messages and not SDL events.

WayneSherman:

--- Quote from: furious programming on November 09, 2022, 04:04:41 pm ---I checked using the Intel® VTune™ Profiler and unfortunately it looks like it is not SDL's fault, but the system's fault (see the attachment).

--- End quote ---

I had another thought.  WaitForMultipleObjects in your screenshot shows the time, but not the number of calls made to it.  It looks like it is called *after* exiting "Main", so is it just running once on cleanup (when the program is about to terminate), or is it being called many times during your program execution?

Navigation

[0] Message Index

[*] Previous page

Go to full version