Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Improve engine startup/shutdown benchmarks #85885

Merged
merged 2 commits into from
Dec 8, 2023

Conversation

YuriSizov
Copy link
Contributor

@YuriSizov YuriSizov commented Dec 7, 2023

So I was working on the project manager and wanted to learn why does it take a whopping 3 seconds to load, with most time spent outside of PM code and in other main.cpp activities instead. As I did before, I tried to use our existing benchmarking system that is supposed to track startup and shutdown processes and report on time taken.

I have already discovered previously that it is not a very useful system. Many things are not tracked correctly, with begin or end points of measurement being misplaced; many other things are not tracked at all and missing. Those which are tracked are reported in a disorganized manner and are hard to make use of. For example, most of the time of the PM startup is taken by "servers", and that's pretty much all that I can tell from our current benchmark:

BENCHMARK:
	- register_core_types :  0.014811  sec.
	- servers :  2.620844  sec.
	- register_editor_types :  0.003172  sec.
	- scene :  0.209155  sec.
	- editor_register_and_generate_icons_all :  0.254266  sec.
	- editor_register_and_generate_icons_with_only_thumbs :  0.003362  sec.
	- editor_register_fonts :  0.005924  sec.
	- create_editor_theme :  0.606796  sec.
	- create_custom_theme :  0.606828  sec.
	- project_manager :  0.782145  sec.
	- startup_begin :  3.649693  sec.
	- unregister_editor_types :  0.000009  sec.
	- unregister_core_types :  0.02886  sec.
	- Main::cleanup :  0.118794  sec.

Measured on battery with a build of 2f73a05

So I set to try and improve all of that. First of all, I added grouping to the measurements. This makes the data structure a bit more complex, which I guess will increase the impact of using the benchmark on the benchmarked code. But what are you going to do, the observer is a part of the observed process.

I went with a Pair key for intermediate records instead of using nested HashMaps, because I think it would be slightly faster. But I didn't... benchmark it. I also replaced the Dictionary with a HashMap. I think it should be more efficient too, with no Variant marshalling required. We only needed a Dictionary when creating the JSON file, but we can fabricate one when we do the dump, which is one part of the process where it's okay to be slow.

I then went through benchmarked areas and adjusted/added measure points to make sure they track sensible data. There shouldn't be anything controversial about these changes here.

However, there is the second commit where I go through the main.cpp code and reorganize it a bit, fixing benchmarks in the process. There should be no functional difference, but changes to main are always sensitive. So I can drop it if needed. To summarize, I shifted some little things around which should not affect the initialization order, but help keep things grouped and organized. I then added subscopes throughout, or adjusted existing subscopes, to make the code a bit easier to follow, making it more segmented. Each scope and some other areas received their own benchmark measurements.

And the end result of everything is this:

BENCHMARK:
	[Startup]
		- Core: 0.034283 sec.
		- Initialize Early Settings: 0.003121 sec.
		- Servers: 2.497262 sec.
		- Setup Window and Boot: 0.169309 sec.
		- Translations and Remaps: 0.000249 sec.
		- Text Server: 0.000077 sec.
		- Scene: 0.156916 sec.
		- Platforms: 0.000099 sec.
		- Finalize Setup: 0.017886 sec.
		- Setup: 2.913917 sec.
		- Project Manager: 0.737702 sec.
		- Total: 3.659916 sec.

	[Core]
		- Register Types: 0.016540 sec.
		- Register Extensions: 0.000283 sec.
		- Register Singletons: 0.000196 sec.
		- Unregister Extensions: 0.000062 sec.
		- Unregister Types: 0.031384 sec.

	[Servers]
		- Register Extensions: 0.023551 sec.
		- Modules and Extensions: 0.001781 sec.
		- Input: 0.043722 sec.
		- Display: 2.327309 sec.
		- Tablet Driver: 0.000084 sec.
		- Rendering: 0.035946 sec.
		- Audio: 0.061223 sec.
		- XR: 0.000015 sec.
		- Unregister Extensions: 0.000071 sec.

	[Scene]
		- Register Types: 0.093715 sec.
		- Register Singletons: 0.000016 sec.
		- Modules and Extensions: 0.062997 sec.
		- Unregister Types: 0.000087 sec.

	[Editor]
		- Register Types: 0.004205 sec.
		- Modules and Extensions: 0.000099 sec.
		- Unregister Types: 0.000014 sec.

	[EditorTheme]
		- Generate Icons (All): 0.228809 sec.
		- Generate Icons (Only Thumbs): 0.002707 sec.
		- Register Fonts: 0.009642 sec.
		- Create Editor Theme: 0.558997 sec.
		- Create Custom Theme: 0.000004 sec.

	[Shutdown]
		- Total: 0.137982 sec.

And here's an example of before and after for the editor:

BENCHMARK:
	- register_core_types :  0.014213  sec.
	- servers :  2.866646  sec.
	- register_editor_types :  0.003511  sec.
	- scene :  0.207836  sec.
	- editor_register_and_generate_icons_all :  0.30274  sec.
	- editor_register_and_generate_icons_with_only_thumbs :  0.003226  sec.
	- editor_register_fonts :  0.00616  sec.
	- create_editor_theme :  0.656456  sec.
	- create_custom_theme :  0.656477  sec.
	- EditorHelp::generate_doc :  1.493546  sec.
	- editor :  2.832077  sec.
	- startup_begin :  6.004947  sec.
	- editor_scan_and_import :  0.074878  sec.
	- unregister_editor_types :  0.000009  sec.
	- unregister_core_types :  0.043799  sec.
	- Main::cleanup :  0.282018  sec.
BENCHMARK:
	[Startup]
		- Core: 0.089364 sec.
		- Initialize Early Settings: 0.001495 sec.
		- Servers: 2.686693 sec.
		- Setup Window and Boot: 0.175628 sec.
		- Translations and Remaps: 0.000184 sec.
		- Text Server: 0.000043 sec.
		- Scene: 0.188522 sec.
		- Platforms: 0.000116 sec.
		- Finalize Setup: 0.028329 sec.
		- Setup: 3.174505 sec.
		- Editor: 2.998649 sec.
		- Total: 6.180127 sec.

	[Core]
		- Register Types: 0.014588 sec.
		- Register Extensions: 0.061387 sec.
		- Register Singletons: 0.000177 sec.
		- Unregister Extensions: 0.000103 sec.
		- Unregister Types: 0.051921 sec.

	[Servers]
		- Register Extensions: 0.022540 sec.
		- Modules and Extensions: 0.001457 sec.
		- Input: 0.044165 sec.
		- Display: 2.185309 sec.
		- Tablet Driver: 0.000059 sec.
		- Rendering: 0.356325 sec.
		- Audio: 0.073410 sec.
		- XR: 0.000011 sec.
		- Unregister Extensions: 0.000087 sec.

	[Scene]
		- Register Types: 0.128215 sec.
		- Register Singletons: 0.000012 sec.
		- Modules and Extensions: 0.060110 sec.
		- Unregister Types: 0.000342 sec.

	[Editor]
		- Register Types: 0.003734 sec.
		- Modules and Extensions: 0.000110 sec.
		- First Scan: 0.087209 sec.
		- Unregister Types: 0.000012 sec.

	[EditorTheme]
		- Generate Icons (All): 0.285813 sec.
		- Generate Icons (Only Thumbs): 0.004107 sec.
		- Register Fonts: 0.007346 sec.
		- Create Editor Theme: 0.637479 sec.
		- Create Custom Theme: 0.000004 sec.

	[EditorHelp]
		- Generate Documentation: 7.012339 sec.

	[Shutdown]
		- Total: 0.247288 sec.

We support overriding OS benchmark methods in platform OS implementations, and Android so far is the only one that does. Naturally, platforms may not have support for contexts. I don't know if Android has it, so to be the least disruptive I can, I just vformat both strings and pass it onto the platform wrapper. Maybe it can be done better, cc @m4gr3d

Copy link
Member

@Calinou Calinou left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Tested locally, it works as expected.

Output on Linux with an optimized editor build and an Intel Core i9-13900K, using --benchmark --quit CLI arguments for the project manager:

BENCHMARK:
        [Startup]
                - Core: 0.004916 sec.
                - Initialize Early Settings: 0.000073 sec.
                - Servers: 0.160395 sec.
                - Setup Window and Boot: 0.019250 sec.
                - Translations and Remaps: 0.000041 sec.
                - Text Server: 0.000024 sec.
                - Scene: 0.033830 sec.
                - Platforms: 0.000026 sec.
                - Finalize Setup: 0.003609 sec.
                - Setup: 0.223019 sec.
                - Project Manager: 0.302017 sec.
                - Total: 0.527676 sec.

        [Core]
                - Register Types: 0.003185 sec.
                - Register Extensions: 0.000046 sec.
                - Register Singletons: 0.000048 sec.

        [Servers]
                - Register Extensions: 0.004254 sec.
                - Modules and Extensions: 0.000387 sec.
                - Input: 0.004932 sec.
                - Display: 0.140001 sec.
                - Tablet Driver: 0.000026 sec.
                - Rendering: 0.007867 sec.
                - Audio: 0.002166 sec.
                - XR: 0.000003 sec.

        [Scene]
                - Register Types: 0.019183 sec.
                - Register Singletons: 0.000002 sec.
                - Modules and Extensions: 0.014607 sec.

        [Editor]
                - Register Types: 0.000754 sec.
                - Modules and Extensions: 0.000017 sec.

        [EditorTheme]
                - Generate Icons (All): 0.039615 sec.
                - Generate Icons (Only Thumbs): 0.000278 sec.
                - Register Fonts: 0.088244 sec.
                - Create Editor Theme: 0.211319 sec.
                - Create Custom Theme: 0.000001 sec.

BENCHMARK:
        [Startup]
                - Core: 0.004916 sec.
                - Initialize Early Settings: 0.000073 sec.
                - Servers: 0.160395 sec.
                - Setup Window and Boot: 0.019250 sec.
                - Translations and Remaps: 0.000041 sec.
                - Text Server: 0.000024 sec.
                - Scene: 0.033830 sec.
                - Platforms: 0.000026 sec.
                - Finalize Setup: 0.003609 sec.
                - Setup: 0.223019 sec.
                - Project Manager: 0.302017 sec.
                - Total: 0.527676 sec.

        [Core]
                - Register Types: 0.003185 sec.
                - Register Extensions: 0.000046 sec.
                - Register Singletons: 0.000048 sec.
                - Unregister Extensions: 0.000026 sec.
                - Unregister Types: 0.007054 sec.

        [Servers]
                - Register Extensions: 0.004254 sec.
                - Modules and Extensions: 0.000387 sec.
                - Input: 0.004932 sec.
                - Display: 0.140001 sec.
                - Tablet Driver: 0.000026 sec.
                - Rendering: 0.007867 sec.
                - Audio: 0.002166 sec.
                - XR: 0.000003 sec.
                - Unregister Extensions: 0.000025 sec.

        [Scene]
                - Register Types: 0.019183 sec.
                - Register Singletons: 0.000002 sec.
                - Modules and Extensions: 0.014607 sec.
                - Unregister Types: 0.000024 sec.

        [Editor]
                - Register Types: 0.000754 sec.
                - Modules and Extensions: 0.000017 sec.
                - Unregister Types: 0.000003 sec.

        [EditorTheme]
                - Generate Icons (All): 0.039615 sec.
                - Generate Icons (Only Thumbs): 0.000278 sec.
                - Register Fonts: 0.088244 sec.
                - Create Editor Theme: 0.211319 sec.
                - Create Custom Theme: 0.000001 sec.

        [Shutdown]
                - Total: 0.996463 sec.

@akien-mga
Copy link
Member

akien-mga commented Dec 7, 2023

Testing on Linux, Mageia 9 x86_64, unoptimized dev build.

There's an error when running the project manager, both with and without enabling benchmarking:

ERROR: Condition "!benchmark_marks_from.has(mark_key)" is true.
   at: benchmark_end_measure (./core/os/os.cpp:640)

Then opening a project in the editor, two errors are printed:

ERROR: Condition "!benchmark_marks_from.has(mark_key)" is true.
   at: benchmark_end_measure (./core/os/os.cpp:640)
ERROR: Condition "benchmark_marks_from.has(mark_key)" is true.
   at: benchmark_begin_measure (./core/os/os.cpp:632)

The second error doesn't seem to be present with running the editor with --benchmark, but the first one always is.


Output for the project manager:

BENCHMARK:
        [Startup]
                - Core: 0.027991 sec.
                - Initialize Early Settings: 0.000290 sec.
                - Servers: 0.314255 sec.
                - Setup Window and Boot: 0.022295 sec.
                - Translations and Remaps: 0.000205 sec.
                - Text Server: 0.000057 sec.
                - Scene: 0.240784 sec.
                - Platforms: 0.000089 sec.
                - Finalize Setup: 0.021410 sec.
                - Setup: 0.632670 sec.
                - Project Manager: 1.016264 sec.
                - Total: 1.670636 sec.

        [Core]
                - Register Types: 0.018657 sec.
                - Register Extensions: 0.000231 sec.
                - Register Singletons: 0.000302 sec.
                - Unregister Extensions: 0.000069 sec.
                - Unregister Types: 0.028479 sec.

        [Servers]
                - Register Extensions: 0.030083 sec.
                - Modules and Extensions: 0.002421 sec.
                - Input: 0.056804 sec.
                - Display: 0.173506 sec.
                - Tablet Driver: 0.000082 sec.
                - Rendering: 0.042705 sec.
                - Audio: 0.003962 sec.
                - XR: 0.000009 sec.
                - Unregister Extensions: 0.000066 sec.

        [Scene]
                - Register Types: 0.138531 sec.
                - Register Singletons: 0.000009 sec.
                - Modules and Extensions: 0.102081 sec.
                - Unregister Types: 0.000082 sec.

        [Editor]
                - Register Types: 0.004716 sec.
                - Modules and Extensions: 0.000141 sec.
                - Unregister Types: 0.000017 sec.

        [EditorTheme]
                - Generate Icons (All): 0.272070 sec.
                - Generate Icons (Only Thumbs): 0.003841 sec.
                - Register Fonts: 0.018567 sec.
                - Create Editor Theme: 0.776031 sec.
                - Create Custom Theme: 0.000007 sec.

        [Shutdown]
                - Total: 1.100682 sec.

Output for the editor:

BENCHMARK:
        [Startup]
                - Core: 0.031890 sec.
                - Initialize Early Settings: 0.000312 sec.
                - Servers: 0.571787 sec.
                - Setup Window and Boot: 0.018544 sec.
                - Translations and Remaps: 0.000266 sec.
                - Text Server: 0.000057 sec.
                - Scene: 0.257329 sec.
                - Platforms: 0.000091 sec.
                - Finalize Setup: 0.026086 sec.
                - Setup: 0.911466 sec.
                - Editor: 3.711831 sec.
                - Total: 4.646321 sec.

        [Core]
                - Register Types: 0.019652 sec.
                - Register Extensions: 0.000230 sec.
                - Register Singletons: 0.000113 sec.
                - Unregister Extensions: 0.000126 sec.
                - Unregister Types: 0.029595 sec.

        [Servers]
                - Register Extensions: 0.029604 sec.
                - Modules and Extensions: 0.002395 sec.
                - Input: 0.056094 sec.
                - Display: 0.093448 sec.
                - Tablet Driver: 0.000056 sec.
                - Rendering: 0.382668 sec.
                - Audio: 0.002774 sec.
                - XR: 0.000005 sec.
                - Unregister Extensions: 0.000102 sec.

        [Scene]
                - Register Types: 0.157577 sec.
                - Register Singletons: 0.000012 sec.
                - Modules and Extensions: 0.099570 sec.
                - Unregister Types: 0.001157 sec.

        [Editor]
                - Register Types: 0.004731 sec.
                - Modules and Extensions: 0.000129 sec.
                - First Scan: 0.064385 sec.
                - Unregister Types: 0.000014 sec.

        [EditorTheme]
                - Generate Icons (All): 0.287670 sec.
                - Generate Icons (Only Thumbs): 0.003772 sec.
                - Register Fonts: 0.017580 sec.
                - Create Editor Theme: 0.769319 sec.
                - Create Custom Theme: 0.000007 sec.

        [EditorHelp]
                - Generate Documentation: 1.091892 sec.

        [Shutdown]
                - Total: 0.386975 sec.

It seems a bit redundant to print the full output both on startup and shutdown, with the difference for shutdown is the addition of a few lines. But I get why it's done like this and I don't really have a better suggestion.

@YuriSizov
Copy link
Contributor Author

It seems a bit redundant to print the full output both on startup and shutdown, with the difference for shutdown is the addition of a few lines. But I get why it's done like this and I don't really have a better suggestion.

I agree, I would flush the data when dumping, but I guess this would conflict with some potential usage of the tool.

@YuriSizov
Copy link
Contributor Author

YuriSizov commented Dec 7, 2023

Fixed the reported issues with invalid benchmark keys. For the doc generation I added a counter to track every attempt. When opening the editor on a new commit, it runs twice and the second time takes over 2 seconds (it's generating the cache, most likely). Consecutive startups only have one run:

BENCHMARK:
	[Startup]
		- Core: 70.587 msec.
		- Initialize Early Settings: 2.500 msec.
		- Servers: 2553.479 msec.
		- Setup Window and Boot: 115.040 msec.
		- Translations and Remaps: 0.151 msec.
		- Text Server: 0.036 msec.
		- Scene: 148.286 msec.
		- Platforms: 0.068 msec.
		- Finalize Setup: 18.220 msec.
		- Setup: 2911.932 msec.
		- Editor: 2179.995 msec.
		- Total: 5098.424 msec.

	[Core]
		- Register Types: 12.775 msec.
		- Register Extensions: 46.361 msec.
		- Register Singletons: 0.111 msec.
		- Unregister Extensions: 0.053 msec.
		- Unregister Types: 39.359 msec.

	[Servers]
		- Register Extensions: 17.787 msec.
		- Modules and Extensions: 1.375 msec.
		- Input: 35.486 msec.
		- Display: 2192.532 msec.
		- Tablet Driver: 0.049 msec.
		- Rendering: 252.736 msec.
		- Audio: 50.691 msec.
		- XR: 0.010 msec.
		- Register Singletons: 0.029 msec.
		- Unregister Extensions: 0.060 msec.

	[Scene]
		- Register Types: 94.603 msec.
		- Register Singletons: 0.012 msec.
		- Modules and Extensions: 53.524 msec.
		- Unregister Types: 0.219 msec.

	[Editor]
		- Register Types: 3.265 msec.
		- Modules and Extensions: 0.095 msec.
		- First Scan: 77.071 msec.
		- Unregister Types: 0.008 msec.

	[EditorTheme]
		- Generate Icons (All): 203.217 msec.
		- Generate Icons (Only Thumbs): 3.498 msec.
		- Register Fonts: 5.492 msec.
		- Create Editor Theme: 485.315 msec.
		- Create Custom Theme: 0.004 msec.

	[EditorHelp]
		- Generate Documentation (Run 1): 590.749 msec.

	[Shutdown]
		- Total: 189.993 msec.

I also changed the times displayed from seconds to milliseconds, as suggested by @Calinou. The data stored in JSON is still in seconds, in case that matters.

And here's the project manager:
BENCHMARK:
	[Startup]
		- Core: 23.681 msec.
		- Initialize Early Settings: 0.834 msec.
		- Servers: 2348.257 msec.
		- Setup Window and Boot: 129.747 msec.
		- Translations and Remaps: 0.181 msec.
		- Text Server: 0.068 msec.
		- Scene: 130.190 msec.
		- Platforms: 0.072 msec.
		- Finalize Setup: 14.449 msec.
		- Setup: 2676.227 msec.
		- Project Manager: 609.114 msec.
		- Total: 3291.836 msec.

	[Core]
		- Register Types: 12.850 msec.
		- Register Extensions: 0.242 msec.
		- Register Singletons: 0.114 msec.
		- Unregister Extensions: 0.052 msec.
		- Unregister Types: 19.940 msec.

	[Servers]
		- Register Extensions: 18.666 msec.
		- Modules and Extensions: 1.375 msec.
		- Input: 35.767 msec.
		- Display: 2214.292 msec.
		- Tablet Driver: 0.110 msec.
		- Rendering: 22.774 msec.
		- Audio: 52.138 msec.
		- XR: 0.010 msec.
		- Register Singletons: 0.080 msec.
		- Unregister Extensions: 0.059 msec.

	[Scene]
		- Register Types: 78.735 msec.
		- Register Singletons: 0.010 msec.
		- Modules and Extensions: 51.316 msec.
		- Unregister Types: 0.094 msec.

	[Editor]
		- Register Types: 3.174 msec.
		- Modules and Extensions: 0.086 msec.
		- Unregister Types: 0.014 msec.

	[EditorTheme]
		- Generate Icons (All): 200.128 msec.
		- Generate Icons (Only Thumbs): 2.335 msec.
		- Register Fonts: 5.735 msec.
		- Create Editor Theme: 479.308 msec.
		- Create Custom Theme: 0.003 msec.

	[Shutdown]
		- Total: 69.487 msec.

@m4gr3d
Copy link
Contributor

m4gr3d commented Dec 8, 2023

We support overriding OS benchmark methods in platform OS implementations, and Android so far is the only one that does. Naturally, platforms may not have support for contexts. I don't know if Android has it, so to be the least disruptive I can, I just vformat both strings and pass it onto the platform wrapper. Maybe it can be done better, cc @m4gr3d

@YuriSizov I've adapted the Android section in 949c654

@YuriSizov
Copy link
Contributor Author

@m4gr3d Thanks, Freddy, incorporated your changeset into the first commit!

YuriSizov and others added 2 commits December 8, 2023 12:53
- Add contexts to give a better sense of benchmarked areas.
- Add missing benchmarks and adjust some begin/end points.
- Clean up names.
- Improve Android's internal benchmarks in a similar manner.

Co-authored-by: Fredia Huya-Kouadio <[email protected]>
Copy link
Member

@akien-mga akien-mga left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Tested, looks good to me!

@akien-mga
Copy link
Member

Test results for opening and closing the editor:

BENCHMARK:
        [Startup]
                - Core: 30.080 msec.
                - Initialize Early Settings: 0.383 msec.
                - Servers: 338.482 msec.
                - Setup Window and Boot: 224.526 msec.
                - Translations and Remaps: 0.208 msec.
                - Text Server: 0.063 msec.
                - Scene: 227.052 msec.
                - Platforms: 0.089 msec.
                - Finalize Setup: 24.917 msec.
                - Setup: 850.817 msec.
                - Editor: 3609.451 msec.
                - Total: 4482.747 msec.

        [Core]
                - Register Types: 19.972 msec.
                - Register Extensions: 0.392 msec.
                - Register Singletons: 0.236 msec.

        [Servers]
                - Register Extensions: 30.245 msec.
                - Modules and Extensions: 2.409 msec.
                - Input: 55.872 msec.
                - Display: 172.414 msec.
                - Tablet Driver: 0.092 msec.
                - Rendering: 69.561 msec.
                - Audio: 3.215 msec.
                - XR: 0.037 msec.
                - Register Singletons: 0.023 msec.

        [Scene]
                - Register Types: 129.412 msec.
                - Register Singletons: 0.009 msec.
                - Modules and Extensions: 97.479 msec.

        [Editor]
                - Register Types: 4.537 msec.
                - Modules and Extensions: 0.127 msec.

        [EditorTheme]
                - Generate Icons (All): 276.482 msec.
                - Generate Icons (Only Thumbs): 4.248 msec.
                - Register Fonts: 17.339 msec.
                - Create Editor Theme: 754.238 msec.
                - Create Custom Theme: 0.006 msec.

WARNING: res://Bullet.tscn:3 - ext_resource, invalid UID: uid://87j7ldt0dsn7 - using text path instead: res://icon.svg
     at: load (./scene/resources/resource_format_text.cpp:448)
BENCHMARK:
        [Startup]
                - Core: 30.080 msec.
                - Initialize Early Settings: 0.383 msec.
                - Servers: 338.482 msec.
                - Setup Window and Boot: 224.526 msec.
                - Translations and Remaps: 0.208 msec.
                - Text Server: 0.063 msec.
                - Scene: 227.052 msec.
                - Platforms: 0.089 msec.
                - Finalize Setup: 24.917 msec.
                - Setup: 850.817 msec.
                - Editor: 3609.451 msec.
                - Total: 4482.747 msec.

        [Core]
                - Register Types: 19.972 msec.
                - Register Extensions: 0.392 msec.
                - Register Singletons: 0.236 msec.
                - Unregister Extensions: 0.236 msec.
                - Unregister Types: 53.095 msec.

        [Servers]
                - Register Extensions: 30.245 msec.
                - Modules and Extensions: 2.409 msec.
                - Input: 55.872 msec.
                - Display: 172.414 msec.
                - Tablet Driver: 0.092 msec.
                - Rendering: 69.561 msec.
                - Audio: 3.215 msec.
                - XR: 0.037 msec.
                - Register Singletons: 0.023 msec.
                - Unregister Extensions: 0.118 msec.

        [Scene]
                - Register Types: 129.412 msec.
                - Register Singletons: 0.009 msec.
                - Modules and Extensions: 97.479 msec.
                - Unregister Types: 0.353 msec.

        [Editor]
                - Register Types: 4.537 msec.
                - Modules and Extensions: 0.127 msec.
                - First Scan: 324.678 msec.
                - Unregister Types: 0.008 msec.

        [EditorTheme]
                - Generate Icons (All): 276.482 msec.
                - Generate Icons (Only Thumbs): 4.248 msec.
                - Register Fonts: 17.339 msec.
                - Create Editor Theme: 754.238 msec.
                - Create Custom Theme: 0.006 msec.

        [EditorHelp]
                - Generate Documentation (Run 1): 830.833 msec.
                - Generate Documentation (Run 2): 3961.663 msec.

        [Shutdown]
                - Total: 509.568 msec.

I'm a bit puzzled by the Editor: 3609.451 msec. which doesn't seem to be properly reflected in the [Editor] section, even when adding [EditorTheme]. [EditorHelp] is only shown on shutdown, but adding that to [Editor] + [EditorTheme] counts actually exceeds the total value for Editor.

Also I find it weird that the documentation generation is reported as taking so long. That might need to be investigated, from what I remember when Pedro added doc caching we were in the low hundreds of ms.

@YuriSizov
Copy link
Contributor Author

YuriSizov commented Dec 8, 2023

@akien-mga This is mostly an issue with how disjointed editor initialization is. I think we can fix it in a future PR.

Basically, Startup:Editor is how long does it take to initialize and add to the tree the EditorNode. This includes creating the theme, but not much else is tracked. The Editor:FirstScan and EditorHelp trackers are async so they can't contribute to this even if we start these routines at the same time.

Registration of editor types and modules happens at a different point in time entirely. Node is created in Main::start whereas registration happens in Main::setup2. I could rename these contexts, but perhaps it's better done when I get to the editor initialization rework planned for 4.3.

As for the timing of EditorHelp. The first run is reading cache, and the second run creating it because it's missing. These seem to be correct values. Note that prior to this PR the benchmark was set up incorrectly. We basically only measured how long it takes to create a thread 🙂 You can see that we call the end function in the same method that starts the process, even though the process is threaded and will take a bit of time. So I would say if you relied on this metric before, it was bogus. It should be more reliable now.

@YuriSizov YuriSizov merged commit 07677f0 into godotengine:master Dec 8, 2023
15 checks passed
@YuriSizov
Copy link
Contributor Author

Thanks for testing and reviews!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants