Godot: Scons performance for rebuilds is slow

Created on 15 Aug 2020  路  14Comments  路  Source: godotengine/godot

Issue description:
Rebuilding a single file on high-end systems takes half of a full rebuild time.

Steps to reproduce:
time scons -j16
make change to some cpp file
time scons -j16

I want to do some research into this, so gonna use this issue and document it.

discussion buildsystem

Most helpful comment

@RaTcHeT302 we're profiling and fixing the problems, we already got OSX build times down to 14s for single file. So please try to keep on topic for the actual fixing part, we aren't focusing on 'scons is crappy' we want to work out what the problem is and fix it.

Findings from research

I measured build times and am consistently getting everything under 30s for single file rebuilds (which is not bad):

  • you must disable windows defender (shaved 1m) off build times for full rebuild and got scons -j16 to be under 30s on windows.
  • we need to possibly swap to /DEBUG:fastlink (10s vs 15s)
  • linker commands with MSVC appear to be running out of order? (TBC, reproduction steps: delete exe and files in the bin/ dir and build with verbose=yes, look at the commands for linking they're weirdly ordered)
  • the actual commands to the compiler are slow not the scons invokation
  • the only slow part of scons is generating and not caching the -D defines from all the profiling files. (proven by loading scons profiling information from python and checking in RunSnakeRun)
  • we should be able to shave a lot of time off builds if we cache the defines.

Right now manually linking with the direct commands is yeilding these results, so our link times are 10 or 15 seconds without /DEBUG:fastlink
image

Changing MD5 decider to timestamp-match etc only shaves off 50ms

All 14 comments

jfons: it's computing a bunch of MD5 checksums that it shouldn't really need
11:13 PM for some reason the timestamp check is not doing its job

Normal MD5 timestamp

time scons -j16
[Initial build] scons: done building targets.
scons -j16  2283.42s user 180.40s system 1030% cpu 3:58.98 total

using Decider('timestamp-match')
scons -j16 2345.50s user 184.19s system 1095% cpu 3:50.99 total

scons -j1 --profile=sconsprofiling.log target=release_debug with zero changes
sconsprofiling.log

i'm pretty sure that's just scons being crappy and you can't really do anything about it, beyond just, getting rid of scons

i mean we could improve scons but... i wish we could just get rid of it to be honest

i personally hate all build systems, i think they are mostly crap, i wish there was a "push a button and have it do all the hard work for you, without manually having to type ten thousand files by hand" thingy

people have claimed that meson would be faster, which i find a bit perplexing, since you'd think cmake would be a trllion times faster than everything else... but cmake just sucks donkey kong, plus the whole thing is just so tedious and boring to use, so either the people who make build systems are really incompetent, or i don't understand computers anymore

@RaTcHeT302 we're profiling and fixing the problems, we already got OSX build times down to 14s for single file. So please try to keep on topic for the actual fixing part, we aren't focusing on 'scons is crappy' we want to work out what the problem is and fix it.

Findings from research

I measured build times and am consistently getting everything under 30s for single file rebuilds (which is not bad):

  • you must disable windows defender (shaved 1m) off build times for full rebuild and got scons -j16 to be under 30s on windows.
  • we need to possibly swap to /DEBUG:fastlink (10s vs 15s)
  • linker commands with MSVC appear to be running out of order? (TBC, reproduction steps: delete exe and files in the bin/ dir and build with verbose=yes, look at the commands for linking they're weirdly ordered)
  • the actual commands to the compiler are slow not the scons invokation
  • the only slow part of scons is generating and not caching the -D defines from all the profiling files. (proven by loading scons profiling information from python and checking in RunSnakeRun)
  • we should be able to shave a lot of time off builds if we cache the defines.

Right now manually linking with the direct commands is yeilding these results, so our link times are 10 or 15 seconds without /DEBUG:fastlink
image

Changing MD5 decider to timestamp-match etc only shaves off 50ms

Here is an example of the out of order linking flags
https://gist.github.com/RevoluPowered/dfc7c914eee09c94824b14c851519a58

Seems only assimp is the problem, i am testing linkage times without modules/assimp and thirdparty/assimp for now, might be a bug.

@RaTcHeT302 Per the Godot Engine Code of Conduct, please stop derailing issues with unrelated conversations. This is your last warning.

Feedback is always welcome but keep your criticism constructive. We encourage you to open discussions, proposals, issues, and bug reports. Use the community platforms to discuss improvements, not to vent out frustration. Similarly, when other users offer you feedback please accept it gracefully.

(emphasis mine)

Here are some results from more tests with antivirus off in group policy.

# /INCREMENTAL /DEBUG:fastlink
C:\Users\Gordon\Projects\godot>timecmd.bat link /nologo /DEBUG:fastlink /INCREMENTAL /SUBSYSTEM:WINDOWS winmm.lib dsound.lib kernel32.lib ole32.lib oleaut32.lib user32.lib gdi32.lib IPHLPAPI.lib Shlwapi.lib wsock32.lib Ws2_32.lib shell32.lib advapi32.lib dinput8.lib dxguid.lib imm32.lib bcrypt.lib Avrt.lib dwmapi.lib cfgmgr32.lib opengl32.lib /STACK:8388608 /OUT:bin\godot.windows.tools.64.exe main\main.windows.tools.64.lib modules\modules.windows.tools.64.lib modules\module_xatlas_unwrap.windows.tools.64.lib modules\module_websocket.windows.tools.64.lib modules\module_webrtc.windows.tools.64.lib modules\module_webp.windows.tools.64.lib modules\module_webm.windows.tools.64.lib modules\module_vorbis.windows.tools.64.lib modules\module_visual_script.windows.tools.64.lib modules\module_vhacd.windows.tools.64.lib modules\module_upnp.windows.tools.64.lib modules\module_tinyexr.windows.tools.64.lib modules\module_theora.windows.tools.64.lib modules\module_tga.windows.tools.64.lib modules\module_svg.windows.tools.64.lib modules\module_stb_vorbis.windows.tools.64.lib modules\module_squish.windows.tools.64.lib modules\module_regex.windows.tools.64.lib modules\module_pvr.windows.tools.64.lib modules\module_opus.windows.tools.64.lib modules\module_opensimplex.windows.tools.64.lib modules\module_ogg.windows.tools.64.lib modules\module_mobile_vr.windows.tools.64.lib modules\module_mbedtls.windows.tools.64.lib modules\module_lightmapper_rd.windows.tools.64.lib modules\module_jsonrpc.windows.tools.64.lib modules\module_jpg.windows.tools.64.lib modules\module_hdr.windows.tools.64.lib modules\module_gridmap.windows.tools.64.lib modules\module_glslang.windows.tools.64.lib modules\module_gdscript.windows.tools.64.lib modules\module_gdnavigation.windows.tools.64.lib modules\module_gdnative.windows.tools.64.lib modules\module_freetype.windows.tools.64.lib modules\module_etc.windows.tools.64.lib modules\module_enet.windows.tools.64.lib modules\module_denoise.windows.tools.64.lib modules\module_dds.windows.tools.64.lib modules\module_cvtt.windows.tools.64.lib modules\module_csg.windows.tools.64.lib modules\module_camera.windows.tools.64.lib modules\module_bullet.windows.tools.64.lib modules\module_bmp.windows.tools.64.lib modules\module_basis_universal.windows.tools.64.lib modules\module_assimp.windows.tools.64.lib platform\platform.windows.tools.64.lib drivers\drivers.windows.tools.64.lib editor\editor.windows.tools.64.lib scene\scene.windows.tools.64.lib servers\servers.windows.tools.64.lib core\core.windows.tools.64.lib modules\freetype\freetype_builtin.windows.tools.64.lib platform\windows\godot_windows.windows.tools.64.obj platform\windows\crash_handler_windows.windows.tools.64.obj platform\windows\os_windows.windows.tools.64.obj platform\windows\display_server_windows.windows.tools.64.obj platform\windows\key_mapping_windows.windows.tools.64.obj platform\windows\joypad_windows.windows.tools.64.obj platform\windows\windows_terminal_logger.windows.tools.64.obj platform\windows\vulkan_context_win.windows.tools.64.obj platform\windows\context_gl_windows.windows.tools.64.obj platform\windows\godot_res.windows.tools.64.obj
   Creating library bin\godot.windows.tools.64.lib and object bin\godot.windows.tools.64.exp
command took 0:0:12.14 (12.14s total)
# /DEBUG (current default)
C:\Users\Gordon\Projects\godot>timecmd.bat link /nologo /DEBUG /SUBSYSTEM:WINDOWS winmm.lib dsound.lib kernel32.lib ole32.lib oleaut32.lib user32.lib gdi32.lib IPHLPAPI.lib Shlwapi.lib wsock32.lib Ws2_32.lib shell32.lib advapi32.lib dinput8.lib dxguid.lib imm32.lib bcrypt.lib Avrt.lib dwmapi.lib cfgmgr32.lib opengl32.lib /STACK:8388608 /OUT:bin\godot.windows.tools.64.exe main\main.windows.tools.64.lib modules\modules.windows.tools.64.lib modules\module_xatlas_unwrap.windows.tools.64.lib modules\module_websocket.windows.tools.64.lib modules\module_webrtc.windows.tools.64.lib modules\module_webp.windows.tools.64.lib modules\module_webm.windows.tools.64.lib modules\module_vorbis.windows.tools.64.lib modules\module_visual_script.windows.tools.64.lib modules\module_vhacd.windows.tools.64.lib modules\module_upnp.windows.tools.64.lib modules\module_tinyexr.windows.tools.64.lib modules\module_theora.windows.tools.64.lib modules\module_tga.windows.tools.64.lib modules\module_svg.windows.tools.64.lib modules\module_stb_vorbis.windows.tools.64.lib modules\module_squish.windows.tools.64.lib modules\module_regex.windows.tools.64.lib modules\module_pvr.windows.tools.64.lib modules\module_opus.windows.tools.64.lib modules\module_opensimplex.windows.tools.64.lib modules\module_ogg.windows.tools.64.lib modules\module_mobile_vr.windows.tools.64.lib modules\module_mbedtls.windows.tools.64.lib modules\module_lightmapper_rd.windows.tools.64.lib modules\module_jsonrpc.windows.tools.64.lib modules\module_jpg.windows.tools.64.lib modules\module_hdr.windows.tools.64.lib modules\module_gridmap.windows.tools.64.lib modules\module_glslang.windows.tools.64.lib modules\module_gdscript.windows.tools.64.lib modules\module_gdnavigation.windows.tools.64.lib modules\module_gdnative.windows.tools.64.lib modules\module_freetype.windows.tools.64.lib modules\module_etc.windows.tools.64.lib modules\module_enet.windows.tools.64.lib modules\module_denoise.windows.tools.64.lib modules\module_dds.windows.tools.64.lib modules\module_cvtt.windows.tools.64.lib modules\module_csg.windows.tools.64.lib modules\module_camera.windows.tools.64.lib modules\module_bullet.windows.tools.64.lib modules\module_bmp.windows.tools.64.lib modules\module_basis_universal.windows.tools.64.lib modules\module_assimp.windows.tools.64.lib platform\platform.windows.tools.64.lib drivers\drivers.windows.tools.64.lib editor\editor.windows.tools.64.lib scene\scene.windows.tools.64.lib servers\servers.windows.tools.64.lib core\core.windows.tools.64.lib modules\freetype\freetype_builtin.windows.tools.64.lib platform\windows\godot_windows.windows.tools.64.obj platform\windows\crash_handler_windows.windows.tools.64.obj platform\windows\os_windows.windows.tools.64.obj platform\windows\display_server_windows.windows.tools.64.obj platform\windows\key_mapping_windows.windows.tools.64.obj platform\windows\joypad_windows.windows.tools.64.obj platform\windows\windows_terminal_logger.windows.tools.64.obj platform\windows\vulkan_context_win.windows.tools.64.obj platform\windows\context_gl_windows.windows.tools.64.obj platform\windows\godot_res.windows.tools.64.obj
   Creating library bin\godot.windows.tools.64.lib and object bin\godot.windows.tools.64.exp
command took 0:0:17.39 (17.39s total)
# /DEBUG:fastlink (suggested default for debug)
:\Users\Gordon\Projects\godot>timecmd.bat link /nologo /DEBUG:fastlink /SUBSYSTEM:WINDOWS winmm.lib dsound.lib kernel32.lib ole32.lib oleaut32.lib user32.lib gdi32.lib IPHLPAPI.lib Shlwapi.lib wsock32.lib Ws2_32.lib shell32.lib advapi32.lib dinput8.lib dxguid.lib imm32.lib bcrypt.lib Avrt.lib dwmapi.lib cfgmgr32.lib opengl32.lib /STACK:8388608 /OUT:bin\godot.windows.tools.64.exe main\main.windows.tools.64.lib modules\modules.windows.tools.64.lib modules\module_xatlas_unwrap.windows.tools.64.lib modules\module_websocket.windows.tools.64.lib modules\module_webrtc.windows.tools.64.lib modules\module_webp.windows.tools.64.lib modules\module_webm.windows.tools.64.lib modules\module_vorbis.windows.tools.64.lib modules\module_visual_script.windows.tools.64.lib modules\module_vhacd.windows.tools.64.lib modules\module_upnp.windows.tools.64.lib modules\module_tinyexr.windows.tools.64.lib modules\module_theora.windows.tools.64.lib modules\module_tga.windows.tools.64.lib modules\module_svg.windows.tools.64.lib modules\module_stb_vorbis.windows.tools.64.lib modules\module_squish.windows.tools.64.lib modules\module_regex.windows.tools.64.lib modules\module_pvr.windows.tools.64.lib modules\module_opus.windows.tools.64.lib modules\module_opensimplex.windows.tools.64.lib modules\module_ogg.windows.tools.64.lib modules\module_mobile_vr.windows.tools.64.lib modules\module_mbedtls.windows.tools.64.lib modules\module_lightmapper_rd.windows.tools.64.lib modules\module_jsonrpc.windows.tools.64.lib modules\module_jpg.windows.tools.64.lib modules\module_hdr.windows.tools.64.lib modules\module_gridmap.windows.tools.64.lib modules\module_glslang.windows.tools.64.lib modules\module_gdscript.windows.tools.64.lib modules\module_gdnavigation.windows.tools.64.lib modules\module_gdnative.windows.tools.64.lib modules\module_freetype.windows.tools.64.lib modules\module_etc.windows.tools.64.lib modules\module_enet.windows.tools.64.lib modules\module_denoise.windows.tools.64.lib modules\module_dds.windows.tools.64.lib modules\module_cvtt.windows.tools.64.lib modules\module_csg.windows.tools.64.lib modules\module_camera.windows.tools.64.lib modules\module_bullet.windows.tools.64.lib modules\module_bmp.windows.tools.64.lib modules\module_basis_universal.windows.tools.64.lib modules\module_assimp.windows.tools.64.lib platform\platform.windows.tools.64.lib drivers\drivers.windows.tools.64.lib editor\editor.windows.tools.64.lib scene\scene.windows.tools.64.lib servers\servers.windows.tools.64.lib core\core.windows.tools.64.lib modules\freetype\freetype_builtin.windows.tools.64.lib platform\windows\godot_windows.windows.tools.64.obj platform\windows\crash_handler_windows.windows.tools.64.obj platform\windows\os_windows.windows.tools.64.obj platform\windows\display_server_windows.windows.tools.64.obj platform\windows\key_mapping_windows.windows.tools.64.obj platform\windows\joypad_windows.windows.tools.64.obj platform\windows\windows_terminal_logger.windows.tools.64.obj platform\windows\vulkan_context_win.windows.tools.64.obj platform\windows\context_gl_windows.windows.tools.64.obj platform\windows\godot_res.windows.tools.64.obj
   Creating library bin\godot.windows.tools.64.lib and object bin\godot.windows.tools.64.exp
command took 0:0:12.28 (12.28s total)

Testing in go_faster_mk2_testing

I have got single file rebuild time to: 13.092s with MSVC on Windows 10. 馃巻

This CPU is a Ryzen 7 3700X for now it 'forces' /MT16 since I have 16 threads, later I will try and fix the warning in LINK.

$ time scons -j16
scons: Reading SConscript files ...
Automatically detected platform: windows
Configuring for Windows: target=debug, bits=default
Found MSVC version 14.2, arch amd64, bits=64
YASM is necessary for WebM SIMD optimizations.
WebM SIMD optimizations are disabled. Check if your CPU architecture, CPU bits or platform are supported!
Checking for C header file mntent.h... (cached) no
scons: done reading SConscript files.
scons: Building targets ...
Compiling ==> core\image.cpp
image.cpp
progress_finish(["progress_finish"], [])
Linking Static Library ==> core\core.windows.tools.64.lib
Linking Program        ==> bin\godot.windows.tools.64.exe
LINK : warning LNK4044: unrecognized option '/MT16'; ignored
scons: done building targets.

real    0m13.092s
user    0m0.000s
sys     0m0.015s

Entire build time is down from 3m to 2m 15s.

$ time scons -j16
scons: Reading SConscript files ...
Automatically detected platform: windows
Configuring for Windows: target=debug, bits=default
Found MSVC version 14.2, arch amd64, bits=64
YASM is necessary for WebM SIMD optimizations.
WebM SIMD optimizations are disabled. Check if your CPU architecture, CPU bits or platform are supported!
Checking for C header file mntent.h... no
scons: done reading SConscript files.
scons: Building targets ...
Generating method binders.
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\canvas.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\canvas_occlusion.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\scene_high_end.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\giprobe_sdf.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\gi.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\giprobe.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\giprobe_debug.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\sdfgi_debug.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\sdfgi_debug_probes.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\sdfgi_direct_light.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\sdfgi_integrate.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\sdfgi_preprocess.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\sky.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\volumetric_fog.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\bokeh_dof.glsl.gen.h"
Compiling ==> platform\windows\godot_windows.cpp
Compiling ==> platform\windows\crash_handler_windows.cpp
godot_windows.cpp
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\copy.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\copy_to_fb.glsl.gen.h"
crash_handler_windows.cpp
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\cubemap_downsampler.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\cubemap_filter.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\cubemap_roughness.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\cube_to_dp.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\luminance_reduce.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\resolve.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\roughness_limiter.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\screen_space_reflection.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\screen_space_reflection_filter.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\screen_space_reflection_scale.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\shadow_reduce.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\specular_merge.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\ssao.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\ssao_blur.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\ssao_minify.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\subsurface_scattering.glsl.gen.h"
Building RD_GLSL header: "servers\rendering\rasterizer_rd\shaders\tonemap.glsl.gen.h"
Compiling ==> platform\windows\key_mapping_windows.cpp
Compiling ==> platform\windows\joypad_windows.cpp
key_mapping_windows.cpp
Compiling ==> platform\windows\windows_terminal_logger.cpp
Compiling ==> platform\windows\vulkan_context_win.cpp
joypad_windows.cpp
....
pe1\type1.c
Compiling ==> thirdparty\freetype\src\type42\type42.c
type1.c
Compiling ==> thirdparty\freetype\src\winfonts\winfnt.c
type42.c
winfnt.c
Compiling ==> thirdparty\freetype\src\sfnt\sfnt.c
Building compilation database compile_commands.json
sfnt.c
progress_finish(["progress_finish"], [])
Linking Static Library ==> modules\freetype\freetype_builtin.windows.tools.64.lib
Linking Static Library ==> core\core.windows.tools.64.lib
Linking Program        ==> bin\godot.windows.tools.64.exe
LINK : warning LNK4044: unrecognized option '/MT16'; ignored
   Creating library bin\godot.windows.tools.64.lib and object bin\godot.windows.tools.64.exp
scons: done building targets.

real    2m16.477s
user    0m0.000s
sys     0m0.015s

Does scons use ccache by default? Should make rebuilds faster too than just skipping already compiled files/targets I think.

Does scons use ccache by default? Should make rebuilds faster too than just skipping already compiled files/targets I think.

No, but our SCons setup is configured to use ccache automatically as long as it's installed. You can run watch ccache -s while building Godot to confirm this.

Adding another entry point in case it's useful. Incremental build with no change:

Windows 10, i5-6600k CPU, 3.50GHz, 16GB RAM

> scons target=debug -j16 --debug=time

[vcvarsall.bat] Environment initialized for: 'x64'
scons: Reading SConscript files ...
Automatically detected platform: windows
Configuring for Windows: target=debug, bits=default
Found MSVC compiler: amd64
Compiled program architecture will be a 64 bit executable (forcing bits=64).
...
scons: done reading SConscript files.
scons: Building targets ...
[ 99%] progress_finish(["progress_finish"], [])
[100%] Command execution time: progress_finish: 0.001998 seconds
[100%] Command execution time: .: 0.000000 seconds
scons: done building targets.
Total build time: 17.022759 seconds
Total SConscript file execution time: 6.119761 seconds
Total SCons execution time: 10.834999 seconds
Total command execution time: 0.067999 seconds
Was this page helpful?
0 / 5 - 0 ratings

Related issues

karroffel picture karroffel  路  144Comments

RiverMesa picture RiverMesa  路  142Comments

nunodonato picture nunodonato  路  143Comments

willnationsdev picture willnationsdev  路  93Comments

zatherz picture zatherz  路  121Comments