Enormous CPU usage in Game main menu

[ohrrpgce-bugbot]

[bz#707]

Normal CPU usage on map 0 of test.rpg on this old computer (see bug bz⁠#706 opening comment for details) is around 42%. When I open the main menu, CPU usage shoots to 100% and FPS drops to 11!!
This does not happen in any of the sub menus or anywhere else that I've seen.

Initial profiling gives confusing results.
It shows that, when the menu isn't up, drawing the heroes (only 1 in party, but 4 seem to be drawn anyway) on screen with drawsprite takes about as much time as drawing the tilemap (wow). When the menu is up, each call to drawsprite takes (varying from run to run) between 1.5 and 4 times as long!! Up to 0.9ms to draw a single hero sprite! How could the menu affect this?
Clearly we need to switch to sprite_draw anyway, but I'd like to know what the reason is.

It seems hard to sufficiently explain the lag. printstr takes about 10% of total run time, fuzzyrect 3%, and lots of functions with around 0.5% like MENUDEFITEM::MENUDEFITEM(), GET_MENU_ITEM_CAPTION, DRAW_MENU, READGLOBALSTRING, MENUDEF::MENUDEF(), fb string manipulation functions, etc. I guess that all of this somehow adds up, but there's no single thing to blame? Looks like everything about menus is slow. I think I blame FB. C++ requires enormously intelligent optimisation to compare with C for speed.

From: @rversteegen
Reported version: 20110506 Zenzizenzic
Operating system: Windows 98
Blocker for: bz⁠#706

[ohrrpgce-bugbot]

Comment author: @bob-the-hamster

This does not happen in any of the sub menus or anywhere else that I've seen.

Do you mean this does not happen on the sub menus like "Item" "Equip" "Spells" or do you mean that this does not happen on other custom menus called as sub-menus from the main menu?

...Actually, I just did some testing myself, and I cannot reproduce tis bug at all. My baseline CPU usage when not running the OHR is around 25%-35%. When running ohrrpgce-game my CPU dances around 45%-55%. I do not see any noticeable spikes correlating with the main menu, nor with any other menu, or with the battle system.

[ohrrpgce-bugbot]

Comment author: @rversteegen

This does not happen in any of the sub menus or anywhere else that I've seen.
Do you mean this does not happen on the sub menus like "Item" "Equip" "Spells"
or do you mean that this does not happen on other custom menus called as
sub-menus from the main menu?
I haven't tried custom menus

...Actually, I just did some testing myself, and I cannot reproduce tis bug at
all. My baseline CPU usage when not running the OHR is around 25%-35%. When
running ohrrpgce-game my CPU dances around 45%-55%. I do not see any noticeable
spikes correlating with the main menu, nor with any other menu, or with the
battle system.

I think it has something to do with this old CPU (a K6-2) (and OS?), the CPU's features are very different. For example, indirect branches (eg. select as const) show up as very hot on line-by-line profiling.

I spoke to Spoonweaver on IRC, he has a Pentium 2 and reported the same problem: around 8fps on the main menu, full speed elsewhere. Except I think he reported seeing a dip in some of the other menus too.

[ohrrpgce-bugbot]

Comment author: @rversteegen

Created attachment 152
Profiling done after changing hero graphics to Frames, ~330 seconds CPU time

Here's some profiling. However, it only shows 35.87 seconds, even though I left Game running tes.rpg with the menu open for about 330 seconds of CPU time.

Attached file: profiling1.txt (text/plain, 187929 bytes)
Description: Profiling done after changing hero graphics to Frames, ~330 seconds CPU time

[ohrrpgce-bugbot]

Comment author: @rversteegen

Created attachment 153
Line by line version of above

Attached file: [profiling 1 line-by-line.txt](https://rpg.hamsterrepublic.com/bugzilla/old-attachments/profiling 1 line-by-line.txt) (text/plain, 263830 bytes)
Description: Line by line version of above

[ohrrpgce-bugbot]

Comment author: @rversteegen

Fixed. Profiling didn't reveal the time spent in disk access. It did however show that someone left an unused temporary MenuDef lying around, which was being rather expensively (it's pretty big) created and deleted hundreds of times a second :(

[ohrrpgce-bugbot]

Comment author: @rversteegen

Forgot to mark fixed.