mozilla / sccache

Sccache is a ccache-like tool. It is used as a compiler wrapper and avoids compilation when possible. Sccache has the capability to utilize caching in remote storage environments, including various cloud storage options, or alternatively, in local storage.
Apache License 2.0
5.7k stars 540 forks source link

Almost no cache hits when using Ninja & MSVC #956

Open Zephilinox opened 3 years ago

Zephilinox commented 3 years ago

I used the following command in powershell to import the MSVC environment

$tempFile = [IO.Path]::GetTempFileName()
cmd.exe /c " `"C:\Program Files (x86)\Microsoft Visual Studio\2019\Community\VC\Auxiliary\Build\vcvars64.bat`" && set > `"$tempFile`" "
    & Get-Content $tempFile | Foreach-Object {
    if ($_ -match "^(.*?)=(.*)$")
    {
        Set-Content "env:\$($matches[1])" $matches[2]
    }
    }
Remove-Item $tempFile

I then ran

cmake -G Ninja -DCMAKE_C_COMPILER_LAUNCHER=sccache -DCMAKE_CXX_COMPILER_LAUNCHER=sccache -DCMAKE_EXPORT_COMPILE_COMMANDS=ON ..

and cmake --build . -j1 (one thread, as it seems to complain about PDB file lock issues? maybe related?)

p:\some_proj\build>sccache --show-stats
Compile requests                    886
Compile requests executed           675
Cache hits                            9
Cache hits (C/C++)                    9
Cache misses                        624
Cache misses (C/C++)                624
Cache timeouts                        0
Cache read errors                     0
Forced recaches                       0
Cache write errors                    0
Compilation failures                 42
Cache errors                          0
Non-cacheable compilations          614
Non-cacheable calls                 211
Non-compilation calls                 0
Unsupported compiler calls            0
Average cache write               0.010 s
Average cache read miss           0.006 s
Average cache read hit            0.000 s
Failed distributed compilations       0

Non-cacheable reasons:
Can't handle UnknownFlag arguments with -Xclang     211

Cache location                  Local disk: "C:\\Users\\Zeph\\AppData\\Local\\Mozilla\\sccache\\cache"
Cache size                            2 MiB
Max cache size                       10 GiB

I get 3 cache hits per run, same build path each time.

compile_commands.json shows commands like

"command": "C:\\PROGRA~2\\MICROS~1\\2019\\COMMUN~1\\VC\\Tools\\MSVC\\1427~1.291\\bin\\Hostx64\\x64\\cl.exe  /nologo -DNOMINMAX -DNO_FSEEKO -DWIN32_LEAN_AND_MEAN -D_CRT_NONSTDC_NO_DEPRECATE -D_CRT_SECURE_NO_DEPRECATE -I_deps\\zlib-src -I_deps\\zlib-build -I..\\  /DWIN32 /D_WINDOWS /W3 /MDd /Zi /Ob0 /Od /RTC1   /MP /Fo_deps\\zlib-build\\CMakeFiles\\zlibstatic.dir\\gzwrite.obj /FdTARGET_COMPILE_PDB /FS -c P:\\some_proj\\build\\_deps\\zlib-src\\gzwrite.c",
Be-ing commented 3 years ago

Duplicate of #950? Try looking at the debug logs for the server. I have a PR to improve the documentation for that.

Zephilinox commented 3 years ago

Duplicate of #950? Try looking at the debug logs for the server. I have a PR to improve the documentation for that.

thanks :) logs show stuff like the following, so doesn't seem to be the same issue

[2021-02-16T22:57:43Z DEBUG sccache::server] handle_client: compile
[2021-02-16T22:57:43Z DEBUG sccache::server] check_compiler: Supported compiler
[2021-02-16T22:57:43Z DEBUG sccache::server] parse_arguments: Ok: ["/nologo", "/TP", "-DFMT_HEADER_ONLY=1", "-DNOMINMAX", "-DWIN32_LEAN_AND_MEAN", "-D_CRT_SECURE_NO_WARNINGS", "-I_deps\\element-src\\libelement\\include", "-I_deps\\element-src\\libelement\\src", "-I_deps\\element-src\\libelement\\dependencies\\memorypool", "-I_deps\\element-src\\libelement\\..\\LMNT\\include", "-I_deps\\element-build\\libelement", "-I_deps\\utfcpp-src\\source", "-I_deps\\ghc_filesystem-src\\include", "-I_deps\\fmt-src\\include", "/DWIN32", "/D_WINDOWS", "/W3", "/GR", "/EHsc", "/Zc:__cplusplus", "/permissive-", "/MDd", "/Zi", "/Ob0", "/Od", "/RTC1", "/MP", "/utf-8", "-std:c++17", "/showIncludes", "/Fo_deps\\element-build\\libelement\\CMakeFiles\\element.dir\\src\\object_model\\intermediaries\\declaration_wrapper.cpp.obj", "/Fd_deps\\element-build\\libelement\\CMakeFiles\\element.dir\\element.pdb", "/FS", "-c", "_deps\\element-src\\libelement\\src\\object_model\\intermediaries\\declaration_wrapper.cpp"]
[2021-02-16T22:57:43Z DEBUG sccache::compiler::compiler] [declaration_wrapper.cpp.obj]: get_cached_or_compile: ["/nologo", "/TP", "-DFMT_HEADER_ONLY=1", "-DNOMINMAX", "-DWIN32_LEAN_AND_MEAN", "-D_CRT_SECURE_NO_WARNINGS", "-I_deps\\element-src\\libelement\\include", "-I_deps\\element-src\\libelement\\src", "-I_deps\\element-src\\libelement\\dependencies\\memorypool", "-I_deps\\element-src\\libelement\\..\\LMNT\\include", "-I_deps\\element-build\\libelement", "-I_deps\\utfcpp-src\\source", "-I_deps\\ghc_filesystem-src\\include", "-I_deps\\fmt-src\\include", "/DWIN32", "/D_WINDOWS", "/W3", "/GR", "/EHsc", "/Zc:__cplusplus", "/permissive-", "/MDd", "/Zi", "/Ob0", "/Od", "/RTC1", "/MP", "/utf-8", "-std:c++17", "/showIncludes", "/Fo_deps\\element-build\\libelement\\CMakeFiles\\element.dir\\src\\object_model\\intermediaries\\declaration_wrapper.cpp.obj", "/Fd_deps\\element-build\\libelement\\CMakeFiles\\element.dir\\element.pdb", "/FS", "-c", "_deps\\element-src\\libelement\\src\\object_model\\intermediaries\\declaration_wrapper.cpp"]
[2021-02-16T22:57:43Z DEBUG sccache::compiler::msvc] preprocess: Some("C:\\PROGRA~2\\MICROS~1\\2019\\COMMUN~1\\VC\\Tools\\MSVC\\1427~1.291\\bin\\Hostx64\\x64\\cl.exe" "-EP" "_deps\\element-src\\libelement\\src\\object_model\\intermediaries\\declaration_wrapper.cpp" "-nologo" "-DFMT_HEADER_ONLY=1" "-DNOMINMAX" "-DWIN32_LEAN_AND_MEAN" "-D_CRT_SECURE_NO_WARNINGS" "-I_deps\\element-src\\libelement\\include" "-I_deps\\element-src\\libelement\\src" "-I_deps\\element-src\\libelement\\dependencies\\memorypool" "-I_deps\\element-src\\libelement\\..\\LMNT\\include" "-I_deps\\element-build\\libelement" "-I_deps\\utfcpp-src\\source" "-I_deps\\ghc_filesystem-src\\include" "-I_deps\\fmt-src\\include" "/DWIN32" "/D_WINDOWS" "/showIncludes" "/nologo" "/TP" "/W3" "/GR" "/EHsc" "/Zc:__cplusplus" "/permissive-" "/MDd" "/Zi" "/Ob0" "/Od" "/RTC1" "/utf-8" "-std:c++17" "/Fd_deps\\element-build\\libelement\\CMakeFiles\\element.dir\\element.pdb")
[2021-02-16T22:57:43Z DEBUG tokio_reactor] adding I/O source: 3615490051
[2021-02-16T22:57:43Z DEBUG tokio_reactor] adding I/O source: 3619684354
[2021-02-16T22:57:43Z DEBUG tokio_reactor] dropping I/O source: 3
[2021-02-16T22:57:43Z DEBUG tokio_reactor] dropping I/O source: 2
[2021-02-16T22:57:43Z DEBUG sccache::compiler::compiler] [declaration_wrapper.cpp.obj]: generate_hash_key took 0.293 s
[2021-02-16T22:57:43Z DEBUG sccache::compiler::compiler] [declaration_wrapper.cpp.obj]: Cache miss in 0.000 s
[2021-02-16T22:57:43Z DEBUG sccache::compiler::compiler] [declaration_wrapper.cpp.obj]: Compiling locally
[2021-02-16T22:57:43Z DEBUG tokio_reactor] adding I/O source: 3623878658
[2021-02-16T22:57:43Z DEBUG tokio_reactor] adding I/O source: 3628072963
[2021-02-16T22:57:44Z DEBUG tokio_reactor] dropping I/O source: 2
[2021-02-16T22:57:44Z DEBUG tokio_reactor] dropping I/O source: 3
[2021-02-16T22:57:44Z DEBUG sccache::compiler::compiler] [declaration_wrapper.cpp.obj]: Compiled but not cacheable

but your issue did mention /Zi and /Z7 which I applied with the following bit of cmake from stackoverflow

    string(REPLACE "/Zi" "/Z7" CMAKE_C_FLAGS_DEBUG "${CMAKE_C_FLAGS_DEBUG}")
    string(REPLACE "/Zi" "/Z7" CMAKE_CXX_FLAGS_DEBUG "${CMAKE_CXX_FLAGS_DEBUG}")
    string(REPLACE "/Zi" "/Z7" CMAKE_C_FLAGS_RELWITHDEBINFO "${CMAKE_C_FLAGS_RELWITHDEBINFO}")
    string(REPLACE "/Zi" "/Z7" CMAKE_CXX_FLAGS_RELWITHDEBINFO "${CMAKE_CXX_FLAGS_RELWITHDEBINFO}")

which gives me the following

[2021-02-16T23:04:58Z DEBUG tokio_reactor] adding I/O source: 7721713668
[2021-02-16T23:04:58Z DEBUG sccache::server] handle_client: compile
[2021-02-16T23:04:58Z DEBUG sccache::server] check_compiler: Supported compiler
[2021-02-16T23:04:58Z DEBUG sccache::server] parse_arguments: Ok: ["/nologo", "/TP", "-DFMT_HEADER_ONLY=1", "-DNOMINMAX", "-DWIN32_LEAN_AND_MEAN", "-D_CRT_SECURE_NO_WARNINGS", "-I_deps\\element-src\\libelement\\include", "-I_deps\\element-src\\libelement\\src", "-I_deps\\element-src\\libelement\\dependencies\\memorypool", "-I_deps\\element-src\\libelement\\..\\LMNT\\include", "-I_deps\\element-build\\libelement", "-I_deps\\utfcpp-src\\source", "-I_deps\\ghc_filesystem-src\\include", "-I_deps\\fmt-src\\include", "/DWIN32", "/D_WINDOWS", "/W3", "/GR", "/EHsc", "/Zc:__cplusplus", "/permissive-", "/MDd", "/Z7", "/Ob0", "/Od", "/RTC1", "/MP", "/utf-8", "-std:c++17", "/showIncludes", "/Fo_deps\\element-build\\libelement\\CMakeFiles\\element.dir\\src\\object_model\\intermediaries\\declaration_wrapper.cpp.obj", "/Fd_deps\\element-build\\libelement\\CMakeFiles\\element.dir\\element.pdb", "/FS", "-c", "_deps\\element-src\\libelement\\src\\object_model\\intermediaries\\declaration_wrapper.cpp"]
[2021-02-16T23:04:58Z DEBUG sccache::compiler::compiler] [declaration_wrapper.cpp.obj]: get_cached_or_compile: ["/nologo", "/TP", "-DFMT_HEADER_ONLY=1", "-DNOMINMAX", "-DWIN32_LEAN_AND_MEAN", "-D_CRT_SECURE_NO_WARNINGS", "-I_deps\\element-src\\libelement\\include", "-I_deps\\element-src\\libelement\\src", "-I_deps\\element-src\\libelement\\dependencies\\memorypool", "-I_deps\\element-src\\libelement\\..\\LMNT\\include", "-I_deps\\element-build\\libelement", "-I_deps\\utfcpp-src\\source", "-I_deps\\ghc_filesystem-src\\include", "-I_deps\\fmt-src\\include", "/DWIN32", "/D_WINDOWS", "/W3", "/GR", "/EHsc", "/Zc:__cplusplus", "/permissive-", "/MDd", "/Z7", "/Ob0", "/Od", "/RTC1", "/MP", "/utf-8", "-std:c++17", "/showIncludes", "/Fo_deps\\element-build\\libelement\\CMakeFiles\\element.dir\\src\\object_model\\intermediaries\\declaration_wrapper.cpp.obj", "/Fd_deps\\element-build\\libelement\\CMakeFiles\\element.dir\\element.pdb", "/FS", "-c", "_deps\\element-src\\libelement\\src\\object_model\\intermediaries\\declaration_wrapper.cpp"]
[2021-02-16T23:04:58Z DEBUG sccache::compiler::msvc] preprocess: Some("C:\\PROGRA~2\\MICROS~1\\2019\\COMMUN~1\\VC\\Tools\\MSVC\\1427~1.291\\bin\\Hostx64\\x64\\cl.exe" "-EP" "_deps\\element-src\\libelement\\src\\object_model\\intermediaries\\declaration_wrapper.cpp" "-nologo" "-DFMT_HEADER_ONLY=1" "-DNOMINMAX" "-DWIN32_LEAN_AND_MEAN" "-D_CRT_SECURE_NO_WARNINGS" "-I_deps\\element-src\\libelement\\include" "-I_deps\\element-src\\libelement\\src" "-I_deps\\element-src\\libelement\\dependencies\\memorypool" "-I_deps\\element-src\\libelement\\..\\LMNT\\include" "-I_deps\\element-build\\libelement" "-I_deps\\utfcpp-src\\source" "-I_deps\\ghc_filesystem-src\\include" "-I_deps\\fmt-src\\include" "/DWIN32" "/D_WINDOWS" "/showIncludes" "/nologo" "/TP" "/W3" "/GR" "/EHsc" "/Zc:__cplusplus" "/permissive-" "/MDd" "/Z7" "/Ob0" "/Od" "/RTC1" "/utf-8" "-std:c++17" "/Fd_deps\\element-build\\libelement\\CMakeFiles\\element.dir\\element.pdb")
[2021-02-16T23:04:58Z DEBUG tokio_reactor] adding I/O source: 7725907969
[2021-02-16T23:04:58Z DEBUG tokio_reactor] adding I/O source: 7730102275
[2021-02-16T23:04:58Z DEBUG tokio_reactor] dropping I/O source: 1
[2021-02-16T23:04:58Z DEBUG tokio_reactor] dropping I/O source: 3
[2021-02-16T23:04:58Z DEBUG sccache::compiler::compiler] [declaration_wrapper.cpp.obj]: generate_hash_key took 0.285 s
[2021-02-16T23:04:58Z DEBUG tokio_reactor::registration] scheduling Read for: 0
[2021-02-16T23:04:58Z DEBUG sccache::compiler::compiler] [declaration_wrapper.cpp.obj]: Cache miss in 0.000 s
[2021-02-16T23:04:58Z DEBUG sccache::compiler::compiler] [declaration_wrapper.cpp.obj]: Compiling locally
[2021-02-16T23:04:58Z DEBUG tokio_reactor] adding I/O source: 7734296579
[2021-02-16T23:04:58Z DEBUG tokio_reactor] adding I/O source: 7738490881
[2021-02-16T23:04:59Z DEBUG tokio_reactor] dropping I/O source: 3
[2021-02-16T23:04:59Z DEBUG tokio_reactor] dropping I/O source: 1
[2021-02-16T23:04:59Z DEBUG sccache::compiler::compiler] [declaration_wrapper.cpp.obj]: Compiled in 0.996 s, storing in cache
[2021-02-16T23:04:59Z DEBUG sccache::compiler::compiler] [declaration_wrapper.cpp.obj]: Stored in cache successfully!
[2021-02-16T23:04:59Z DEBUG sccache::server] [declaration_wrapper.cpp.obj]: Cache write finished in 0.007 s
[2021-02-16T23:04:59Z DEBUG tokio_reactor] dropping I/O source: 4

and stats show it's caching :)

Compile requests                    212
Compile requests executed           212
Cache hits                          212
Cache hits (C/C++)                  212
Cache misses                          0
Cache timeouts                        0
Cache read errors                     0
Forced recaches                       0
Cache write errors                    0
Compilation failures                  0
Cache errors                          0
Non-cacheable compilations            0
Non-cacheable calls                   0
Non-compilation calls                 0
Unsupported compiler calls            0
Average cache write               0.000 s
Average cache read miss           0.000 s
Average cache read hit            0.000 s
Failed distributed compilations       0
Cache location                  Local disk: "C:\\Users\\Zeph\\AppData\\Local\\Mozilla\\sccache\\cache"
Cache size                           36 MiB
Max cache size                       10 GiB

though the PDB limitation is a shame, it's useable, and I was able to build without -j1 restricting me to one thread, so that's good

GuBuChang commented 3 years ago

PDB file lock issues need set /FS to compiler,if you use /Zi you need set /FS, i notice that you replace /Zi with /Z7. This is not a good idea.if you use /Z7 compiler will write .PDB-related content to .obj file.so the compiler do not create .pdb. it causes a lot of problem

  1. .obj is very large
  2. The end product is also very large
  3. Can not debug coutomer's crash problem.because we need .pdb debug.
Zephilinox commented 3 years ago

PDB file lock issues need set /FS to compiler,if you use /Zi you need set /FS, i notice that you replace /Zi with /Z7. This is not a good idea.if you use /Z7 compiler will write .PDB-related content to .obj file.so the compiler do not create .pdb. it causes a lot of problem

1. .obj is very large

2. The end product is also very large

3. Can not  debug  coutomer's crash problem.because we need .pdb debug.

I agree but it seems to be a limitation of sccache https://github.com/mozilla/sccache/issues/278#issuecomment-458908310

GuBuChang commented 3 years ago

thank you ,this means that if you use sccache you must stop create PDB.IS that true? That's too bad if that's true.Development and production environments can not be without PDB

luser commented 3 years ago

thank you ,this means that if you use sccache you must stop create PDB.IS that true? That's too bad if that's true.Development and production environments can not be without PDB

No, you just can't create intermediate pdb files when compiling individual .obj files. You can have the linker generate a pdb file for each exe/dll when the obj files have been compiled with /Z7. This is what the Firefox build does. Unfortunately due to MSVC's use of mspdbsrv to marshal writes to pdb files it's impossible for sccache to correctly handle pdb files written alongside obj files.

Zephilinox commented 3 years ago

You can have the linker generate a pdb file for each exe/dll when the obj files have been compiled with /Z7

how would I go about doing that 😁

edit: /Z7 does generate a PDB for executables, but not for static libraries. maybe it does for shared libraries only?

Be-ing commented 3 years ago

I have documented the requirement to use /Z7 instead of /Zi in #963.

GuBuChang commented 3 years ago

image image

i use string(REPLACE "/Zi" "/Z7" CMAKE_CXX_FLAGS_RELEASE "${CMAKE_CXX_FLAGS_RELEASE}") string(REPLACE "/Zi" "/Z7" CMAKE_C_FLAGS_RELEASE "${CMAKE_C_FLAGS_RELEASE}") replace /Zi , but error info still exist. do you know why?

exoosh commented 1 year ago

@GuBuChang /Z7 is IMO the only sensible approach when building static libs with symbols meant for redistribution. Yes, it's bigger but there is no separate PDB to distribute and link.exe will happily create you a PDB from the debug info included in the .obj files.