`sccache-dist`: cache can end up somehow corrupted #2122

lissyx · 2024-03-04T12:38:51Z

I have no STR unfortunately, but I was using sccache-dist circa ~0.7.1pre and it was running fine. Recently updated to 0.7.4 and intermittently I end up with mozilla-central failing to perform some link step, at various places.

After long and extensible debugging, one should note the following:

need to remove the offending .o from objdir (pppolicy.o for the example)
sccache (built only with dist-client feature set) log shows cache it on the same .o

Looking at it closely:

$ ll obj-browser-dbg/security/nss/cmd/lib/lib_sectool/pppolicy.o
-rw-rw-r-- 1 alex alex 704 mars   4 12:52 obj-browser-dbg/security/nss/cmd/lib/lib_sectool/pppolicy.o

On a successfull builds, it's bigger:

$ ll obj-browser-dbg/security/nss/cmd/lib/lib_sectool/pppolicy.o
-rw-r--r-- 1 alexandre alexandre 47K  4 mars  10:02 obj-browser-dbg/security/nss/cmd/lib/lib_sectool/pppolicy.o

The bogus one content's through objdump -tTC shows no symbol

Checking the local sccache content,

$ zipinfo -l ~/.cache/sccache/a/6/a60422ee74380eb71dd55572d4a4fd2c43ad2b611ddbb322c105462e9ec4115e
Archive:  /home/alex/.cache/sccache/a/6/a60422ee74380eb71dd55572d4a4fd2c43ad2b611ddbb322c105462e9ec4115e
Zip file size: 589 bytes, number of entries: 2
-rw-rw-r--  4.6 unx      277 b-      277 stor 80-Jan-01 00:00 obj
-rw-r--r--  4.6 unx      120 b-      120 stor 80-Jan-01 00:00 stderr

277 bytes is obviously weird. Getting rid of this cache key and the matching objdir file, issuing a rebuild:

$ zipinfo -l ~/.cache/sccache/a/6/a60422ee74380eb71dd55572d4a4fd2c43ad2b611ddbb322c105462e9ec4115e
Archive:  /home/alex/.cache/sccache/a/6/a60422ee74380eb71dd55572d4a4fd2c43ad2b611ddbb322c105462e9ec4115e
Zip file size: 14154 bytes, number of entries: 2
-rw-rw-r--  4.6 unx    13842 b-    13842 stor 80-Jan-01 00:00 obj
-rw-r--r--  4.6 unx      120 b-      120 stor 80-Jan-01 00:00 stderr

And no more linkage failure (on this file at least). I have no idea how it got corrupted at first.

The text was updated successfully, but these errors were encountered:

sylvestre · 2024-03-04T12:49:31Z

It can generate errors like:

 0:04.95 ld.lld: error: undefined symbol: SECU_PrintPrivKeyUsagePeriodExtension
 0:04.95 >>> referenced by secutil.c:2124 (/home/alex/codaz/Mozilla/gecko-cinnabar/security/nss/cmd/lib/secutil.c:2124)
 0:04.95 >>>               /home/alex/codaz/Mozilla/gecko-cinnabar/obj-browser-dbg/security/nss/cmd/pk12util/pk12util_pk12util/../../lib/lib_sectool/secutil.o:(SECU_PrintExtensions)

zig-for · 2024-03-15T05:05:07Z

I hit this same exact issue. Tiny object file, no symbols.

zig-for · 2024-03-15T05:29:11Z

This was running CMake + ninja + clang-12 though I could have accidentally poisoned the cache with a bad compiler (initially - c++ instead of clang-12, then clang-12 instead of clang++-12 for cpp).

lissyx · 2024-04-26T06:34:26Z

I ran 0.7.1 for a few weeks without a problem, I've switched to 0.7.2 last monday and so far so good. I'll keep slowly bisecting ...

StephanDollberg · 2024-05-02T21:44:32Z

Facing the same issue on a C++ build. Getting random linker errors.

0.7.1 working fine so far.

johnLate · 2024-05-04T17:38:08Z

I think I've narrowed it down a bit:

In this example the first invocation with sccache results in sccache: Compiler killed by signal 1, the second invocation with the same file results in an object file despite compile errors.

$ cat foobar.cpp 
foobar;

$ g++ -c foobar.cpp -o foobar.o ; echo exitcode: $? ; ls -l foobar.o
foobar.cpp:1:1: error: ‘foobar’ does not name a type
    1 | foobar;
      | ^~~~~~
exitcode: 1
ls: cannot access 'foobar.o': No such file or directory

$ g++ -c foobar.cpp -o foobar.o ; echo exitcode: $? ; ls -l foobar.o
foobar.cpp:1:1: error: ‘foobar’ does not name a type
    1 | foobar;
      | ^~~~~~
exitcode: 1
ls: cannot access 'foobar.o': No such file or directory

$ sccache g++ -c foobar.cpp -o foobar.o ; echo exitcode: $? ; ls -l foobar.o
foobar.cpp:1:1: error: 'foobar' does not name a type
    1 | # 1 "foobar.cpp"
      | ^~~~~~
sccache: Compiler killed by signal 1
exitcode: 254
ls: cannot access 'foobar.o': No such file or directory

$ sccache g++ -c foobar.cpp -o foobar.o ; echo exitcode: $? ; ls -l foobar.o
exitcode: 0
-rw-r----- 1 user user 1080 Mai  4 19:25 foobar.o

$

(This is with 0.7.2, can someone test 0.8.0?)

johnLate · 2024-05-07T20:25:34Z

I've tested 0.7.1, 0.7.2 and 0.8.0 now.

0.7.1 is not affected.

0.7.2 and 0.8.0 are affected (only when distributed compilation is configured).

Steps to reproduce: https://gist.github.com/johnLate/9ea390dfa59a4641cfc8ff20263ce14b

sylvestre · 2024-05-07T21:29:29Z

@johnLate I know it can be painful but having an exact changeset would help a lot :)

johnLate · 2024-05-08T06:22:20Z

@sylvestre You weren't kidding. This was my first time using the rust compiler and each "cargo build" took more than 6 minutes.

/tmp/scc/gh/sccache$ git bisect log
# bad: [2a6ca4d79c7acfb6c58220c1db5a448784acd662] Fix some typos
# good: [1d71d5d810c161ff85217c71608d1d2262c35afb] prepare version 0.7.1
git bisect start 'v0.7.2' 'v0.7.1'
# good: [9d9ea15f90e250a79b64be394a1486e6c8806208] Appease the TOML formatter
git bisect good 9d9ea15f90e250a79b64be394a1486e6c8806208
# bad: [033ea2a5f913f5c3341b5b93cf29eaa86fc6d361] build(deps): bump jobserver from 0.1.26 to 0.1.27
git bisect bad 033ea2a5f913f5c3341b5b93cf29eaa86fc6d361
# bad: [e63185b6d434aac581d5da1037f51786e60df2bd] Activate preprocessor cache mode by default
git bisect bad e63185b6d434aac581d5da1037f51786e60df2bd
# good: [b3e75d0861a73b71a1d9452a78328c53dc8fb3e9] Fix input file times in end-to-end tests
git bisect good b3e75d0861a73b71a1d9452a78328c53dc8fb3e9
# first bad commit: [e63185b6d434aac581d5da1037f51786e60df2bd] Activate preprocessor cache mode by default

/tmp/scc/gh/sccache$

lissyx · 2024-05-10T11:04:34Z

FTR I am running on 0.8.0 for a few days and I have that in my config:

[cache.disk.preprocessor_cache_mode]
# Whether to use the preprocessor cache mode
use_preprocessor_cache_mode = false
# Whether to use file times to check for changes
file_stat_matches = true
# Whether to also use ctime (file status change) time to check for changes
use_ctime_for_stat = true
# Whether to ignore `__TIME__` when caching
ignore_time_macros = false
# Whether to skip (meaning not cache, only hash) system headers
skip_system_headers = false
# Whether hash the current working directory
hash_working_directory = true

So far I think I have not yet hit the issue.

sylvestre · 2024-05-12T12:58:40Z

@lissyx because you disabled use_preprocessor_cache_mode = false
Performances will regress.

@johnLate many thanks for your abnegation!

@Alphare does it ring a bell? (corrupted cache with str) thanks

lissyx · 2024-05-13T05:20:18Z

@lissyx because you disabled use_preprocessor_cache_mode = false Performances will regress.

That was the point: verifying this was the problem. Between reduced performance and broken builds, I've made my choice :)

Alphare · 2024-05-13T09:26:57Z

@johnLate thanks for all the effort, this is quite helpful. I have limited time to look into this now, but I wanted to at least get an idea.

I see that when implemented the PCM I even left a TODO wondering about the effects of masking the preprocessor output in dist mode.
However, in the limited time I have today to look at this, it's not obvious to me why a compiler error would result in writing to the PCM cache causing the subsequent miscompilation, and only in dist-client mode. The TODO above is the most suspect thing IMO.

FYI the slowness in compilation is mainly due to linker + linker settings, removing

[profile.release]
codegen-units = 1
lto = true
strip = true

from the Cargo.toml makes it much faster. Also, switching to a faster linker like mold if available. :)

lissyx · 2024-05-13T13:45:49Z

alex@portable-alex:~/codaz/Mozilla/sccache$ SCCACHE_LOG=debug RUST_LOG=debug SCCACHE_NO_DAEMON=1 SCCACHE_START_SERVER=0 ./target/release/sccache g++ -c foobar.cpp -o foobar.o; echo "exitcode: $?"; ls -l foobar.o
[2024-05-13T14:01:28Z DEBUG sccache::config] Attempting to read config file at "/home/alex/.config/sccache/config"
[2024-05-13T14:01:28Z DEBUG sccache::config] Attempting to read config file at "/home/alex/.config/sccache/config"
[2024-05-13T14:01:28Z INFO  sccache::server] start_server: port: 4226
[2024-05-13T14:01:28Z INFO  sccache::server] Enabling distributed sccache to http://192.168.1.112:10600/
[2024-05-13T14:01:28Z DEBUG reqwest::connect] starting new connection: http://192.168.1.112:10600/
[2024-05-13T14:01:28Z DEBUG hyper::client::connect::http] connecting to 192.168.1.112:10600
[2024-05-13T14:01:28Z DEBUG hyper::client::connect::http] connected to 192.168.1.112:10600
[2024-05-13T14:01:28Z DEBUG hyper::proto::h1::io] flushed 100 bytes
[2024-05-13T14:01:28Z DEBUG hyper::proto::h1::io] parsed 4 headers
[2024-05-13T14:01:28Z DEBUG hyper::proto::h1::conn] incoming body is content-length (24 bytes)
[2024-05-13T14:01:28Z DEBUG hyper::proto::h1::conn] incoming body completed
[2024-05-13T14:01:28Z INFO  sccache::server] Successfully created dist client with 128 cores across 1 servers
[2024-05-13T14:01:28Z DEBUG sccache::cache::cache] Init disk cache with dir "/home/alex/.cache/sccache", size 32212254720
[2024-05-13T14:01:28Z INFO  sccache::server] server has setup with ReadWrite
[2024-05-13T14:01:28Z INFO  sccache::server] server started, listening on port 4226
[2024-05-13T14:01:28Z DEBUG sccache::server] notify_server_startup(Ok { port: 4226 })
[2024-05-13T14:01:28Z DEBUG sccache::server] handle_client: compile
[2024-05-13T14:01:28Z DEBUG sccache::compiler::compiler] Found g++
[2024-05-13T14:01:28Z DEBUG sccache::server] check_compiler: Supported compiler
[2024-05-13T14:01:28Z DEBUG sccache::server] parse_arguments: Ok: ["-c", "foobar.cpp", "-o", "foobar.o"]
[2024-05-13T14:01:28Z DEBUG sccache::commands] Server sent CompileStarted
[2024-05-13T14:01:28Z DEBUG sccache::compiler::compiler] [foobar.o]: get_cached_or_compile: ["-c", "foobar.cpp", "-o", "foobar.o"]
[2024-05-13T14:01:28Z DEBUG sccache::compiler::gcc] arch args before rewrite: []
[2024-05-13T14:01:28Z DEBUG sccache::compiler::gcc] cmd after -arch rewrite: Some(cd "/home/alex/codaz/Mozilla/sccache" && env -i COLORTERM="truecolor" DBUS_SESSION_BUS_ADDRESS="unix:path=/run/user/1000/bus" DEBUGINFOD_URLS="https://debuginfod.ubuntu.com " DESKTOP_SESSION="ubuntu" DISPLAY=":0" GDMSESSION="ubuntu" GNOME_DESKTOP_SESSION_ID="this-is-deprecated" GNOME_SETUP_DISPLAY=":1" GNOME_SHELL_SESSION_MODE="ubuntu" GNOME_TERMINAL_SCREEN="/org/gnome/Terminal/screen/85c547d7_8436_4707_a632_438ae3b92706" GNOME_TERMINAL_SERVICE=":1.234" GSM_SKIP_SSH_AGENT_WORKAROUND="true" GTK_MODULES="gail:atk-bridge" HISTCONTROL="ignoredups" HISTSIZE="100000" HOME="/home/alex" IM_CONFIG_PHASE="1" LANG="fr_FR.UTF-8" LESSCLOSE="/usr/bin/lesspipe %s %s" LESSOPEN="| /usr/bin/lesspipe %s" LIBVIRT_DEFAULT_URI="qemu:///system" LOGNAME="alex" LS_COLORS="rs=0:di=01;34:ln=01;36:mh=00:pi=40;33:so=01;35:do=01;35:bd=40;33;01:cd=40;33;01:or=40;31;01:mi=00:su=37;41:sg=30;43:ca=00:tw=30;42:ow=34;42:st=37;44:ex=01;32:*.tar=01;31:*.tgz=01;31:*.arc=01;31:*.arj=01;31:*.taz=01;31:*.lha=01;31:*.lz4=01;31:*.lzh=01;31:*.lzma=01;31:*.tlz=01;31:*.txz=01;31:*.tzo=01;31:*.t7z=01;31:*.zip=01;31:*.z=01;31:*.dz=01;31:*.gz=01;31:*.lrz=01;31:*.lz=01;31:*.lzo=01;31:*.xz=01;31:*.zst=01;31:*.tzst=01;31:*.bz2=01;31:*.bz=01;31:*.tbz=01;31:*.tbz2=01;31:*.tz=01;31:*.deb=01;31:*.rpm=01;31:*.jar=01;31:*.war=01;31:*.ear=01;31:*.sar=01;31:*.rar=01;31:*.alz=01;31:*.ace=01;31:*.zoo=01;31:*.cpio=01;31:*.7z=01;31:*.rz=01;31:*.cab=01;31:*.wim=01;31:*.swm=01;31:*.dwm=01;31:*.esd=01;31:*.avif=01;35:*.jpg=01;35:*.jpeg=01;35:*.mjpg=01;35:*.mjpeg=01;35:*.gif=01;35:*.bmp=01;35:*.pbm=01;35:*.pgm=01;35:*.ppm=01;35:*.tga=01;35:*.xbm=01;35:*.xpm=01;35:*.tif=01;35:*.tiff=01;35:*.png=01;35:*.svg=01;35:*.svgz=01;35:*.mng=01;35:*.pcx=01;35:*.mov=01;35:*.mpg=01;35:*.mpeg=01;35:*.m2v=01;35:*.mkv=01;35:*.webm=01;35:*.webp=01;35:*.ogm=01;35:*.mp4=01;35:*.m4v=01;35:*.mp4v=01;35:*.vob=01;35:*.qt=01;35:*.nuv=01;35:*.wmv=01;35:*.asf=01;35:*.rm=01;35:*.rmvb=01;35:*.flc=01;35:*.avi=01;35:*.fli=01;35:*.flv=01;35:*.gl=01;35:*.dl=01;35:*.xcf=01;35:*.xwd=01;35:*.yuv=01;35:*.cgm=01;35:*.emf=01;35:*.ogv=01;35:*.ogx=01;35:*.aac=00;36:*.au=00;36:*.flac=00;36:*.m4a=00;36:*.mid=00;36:*.midi=00;36:*.mka=00;36:*.mp3=00;36:*.mpc=00;36:*.ogg=00;36:*.ra=00;36:*.wav=00;36:*.oga=00;36:*.opus=00;36:*.spx=00;36:*.xspf=00;36:*~=00;90:*#=00;90:*.bak=00;90:*.crdownload=00;90:*.dpkg-dist=00;90:*.dpkg-new=00;90:*.dpkg-old=00;90:*.dpkg-tmp=00;90:*.old=00;90:*.orig=00;90:*.part=00;90:*.rej=00;90:*.rpmnew=00;90:*.rpmorig=00;90:*.rpmsave=00;90:*.swp=00;90:*.tmp=00;90:*.ucf-dist=00;90:*.ucf-new=00;90:*.ucf-old=00;90:" MEMORY_PRESSURE_WATCH="/sys/fs/cgroup/user.slice/user-1000.slice/[email protected]/session.slice/[email protected]/memory.pressure" MEMORY_PRESSURE_WRITE="c29tZSAyMDAwMDAgMjAwMDAwMAA=" OLDPWD="/home/alex" PATH="/home/alex/.local/bin:/home/alex/.cargo/bin:/home/alex/.mozbuild/git-cinnabar/:/home/alex/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin:/snap/bin" PYTHONSTARTUP="/home/alex/.pythonrc" QTWEBENGINE_DICTIONARIES_PATH="/usr/share/hunspell-bdic/" QT_ACCESSIBILITY="1" QT_IM_MODULE="ibus" RUST_LOG="debug" SCCACHE_LOG="debug" SCCACHE_NO_DAEMON="1" SCCACHE_START_SERVER="0" SESSION_MANAGER="local/portable-alex:@/tmp/.ICE-unix/4584,unix/portable-alex:/tmp/.ICE-unix/4584" SHELL="/bin/bash" SHLVL="1" SSH_AUTH_SOCK="/run/user/1000/keyring/ssh" SYSTEMD_EXEC_PID="4624" TERM="xterm-256color" USER="alex" USERNAME="alex" VTE_VERSION="7600" WAYLAND_DISPLAY="wayland-0" XAUTHORITY="/run/user/1000/.mutter-Xwaylandauth.9QP2N2" XDG_CONFIG_DIRS="/etc/xdg/xdg-ubuntu:/etc/xdg" XDG_CURRENT_DESKTOP="ubuntu:GNOME" XDG_DATA_DIRS="/usr/share/ubuntu:/usr/share/gnome:/home/alex/.local/share/flatpak/exports/share:/var/lib/flatpak/exports/share:/usr/local/share/:/usr/share/:/var/lib/snapd/desktop" XDG_MENU_PREFIX="gnome-" XDG_RUNTIME_DIR="/run/user/1000" XDG_SESSION_CLASS="user" XDG_SESSION_DESKTOP="ubuntu" XDG_SESSION_TYPE="wayland" XMODIFIERS="@im=ibus" _="./target/release/sccache" "/usr/bin/g++" "-x" "c++" "-E" "foobar.cpp")
[2024-05-13T14:01:28Z DEBUG sccache::compiler::preprocessor_cache] Added result key 4ec1a40b5ac385fbc75c25a064c26b535028deb6b022975cba8da234ddd241a8 to preprocessor cache entry
[2024-05-13T14:01:28Z DEBUG sccache::compiler::compiler] [foobar.o]: generate_hash_key took 0.013 s
[2024-05-13T14:01:28Z DEBUG sccache::compiler::compiler] [foobar.o]: Hash key: 4ec1a40b5ac385fbc75c25a064c26b535028deb6b022975cba8da234ddd241a8
[2024-05-13T14:01:28Z DEBUG sccache::compiler::compiler] [foobar.o]: Cache miss in 0.139 s
[2024-05-13T14:01:28Z DEBUG sccache::compiler::compiler] [foobar.o]: Attempting distributed compilation
[2024-05-13T14:01:28Z DEBUG sccache::compiler::compiler] [foobar.o]: Creating distributed compile request
[2024-05-13T14:01:28Z DEBUG sccache::compiler::compiler] [foobar.o]: Identifying dist toolchain for "/usr/bin/g++"
[2024-05-13T14:01:28Z DEBUG sccache::dist::cache::client] Using cached toolchain /usr/bin/g++-7f52272c5869b30cfd0686d0ca6b8cb961857638027302461b3e3cfd7feb276f -> 80a7871505188355525e9a0805f24b5af7726a2a62b6b38bc594271941ff3558
[2024-05-13T14:01:28Z DEBUG sccache::compiler::compiler] [foobar.o]: Requesting allocation
[2024-05-13T14:01:28Z DEBUG reqwest::connect] starting new connection: http://192.168.1.112:10600/
[2024-05-13T14:01:28Z DEBUG hyper::client::connect::http] connecting to 192.168.1.112:10600
[2024-05-13T14:01:28Z DEBUG hyper::client::connect::http] connected to 192.168.1.112:10600
[2024-05-13T14:01:28Z DEBUG hyper::proto::h1::io] flushed 275 bytes
[2024-05-13T14:01:28Z DEBUG hyper::proto::h1::io] parsed 4 headers
[2024-05-13T14:01:28Z DEBUG hyper::proto::h1::conn] incoming body is content-length (183 bytes)
[2024-05-13T14:01:28Z DEBUG hyper::proto::h1::conn] incoming body completed
[2024-05-13T14:01:28Z INFO  sccache::dist::http::client] Need to request new certificate for server 192.168.1.112:10501
[2024-05-13T14:01:28Z DEBUG reqwest::connect] starting new connection: http://192.168.1.112:10600/
[2024-05-13T14:01:28Z DEBUG hyper::client::connect::http] connecting to 192.168.1.112:10600
[2024-05-13T14:01:28Z DEBUG hyper::client::connect::http] connected to 192.168.1.112:10600
[2024-05-13T14:01:28Z DEBUG hyper::proto::h1::io] flushed 132 bytes
[2024-05-13T14:01:28Z DEBUG hyper::proto::h1::io] parsed 4 headers
[2024-05-13T14:01:28Z DEBUG hyper::proto::h1::conn] incoming body is content-length (1106 bytes)
[2024-05-13T14:01:28Z DEBUG hyper::proto::h1::conn] incoming body completed
[2024-05-13T14:01:28Z DEBUG sccache::compiler::compiler] [foobar.o]: Running job
[2024-05-13T14:01:28Z DEBUG reqwest::connect] starting new connection: https://192.168.1.112:10501/
[2024-05-13T14:01:28Z DEBUG hyper::client::connect::http] connecting to 192.168.1.112:10501
[2024-05-13T14:01:28Z DEBUG hyper::client::connect::http] connected to 192.168.1.112:10501
[2024-05-13T14:01:28Z DEBUG hyper::proto::h1::io] flushed 5405 bytes
[2024-05-13T14:01:28Z DEBUG hyper::proto::h1::io] parsed 4 headers
[2024-05-13T14:01:28Z DEBUG hyper::proto::h1::conn] incoming body is content-length (239 bytes)
[2024-05-13T14:01:28Z DEBUG hyper::proto::h1::conn] incoming body completed
[2024-05-13T14:01:28Z INFO  sccache::compiler::compiler] fetched []
[2024-05-13T14:01:28Z DEBUG sccache::compiler::compiler] [foobar.o]: Compiled in 0.083 s, but failed, not storing in cache
[2024-05-13T14:01:28Z DEBUG sccache::server] compile result: compile failed
foobar.cpp:1:1: error: 'foobar' does not name a type
    1 | # 0 "foobar.cpp"
      | ^~~~~~
foobar.cpp:1:9: error: expected unqualified-id before numeric constant
    1 | # 0 "foobar.cpp"
      |         ^
sccache: Compiler killed by signal 1
exitcode: 254
-rw-rw-r-- 1 alex alex 928 mai   13 15:58 foobar.o
alex@portable-alex:~/codaz/Mozilla/sccache$ SCCACHE_LOG=debug RUST_LOG=debug SCCACHE_NO_DAEMON=1 SCCACHE_START_SERVER=0 ./target/release/sccache g++ -c foobar.cpp -o foobar.o; echo "exitcode: $?"; ls -l foobar.o
[2024-05-13T14:02:19Z DEBUG sccache::config] Attempting to read config file at "/home/alex/.config/sccache/config"
[2024-05-13T14:02:19Z DEBUG sccache::server] handle_client: compile
[2024-05-13T14:02:19Z DEBUG sccache::server] check_compiler: Supported compiler
[2024-05-13T14:02:19Z DEBUG sccache::server] parse_arguments: Ok: ["-c", "foobar.cpp", "-o", "foobar.o"]
[2024-05-13T14:02:19Z DEBUG sccache::commands] Server sent CompileStarted
[2024-05-13T14:02:19Z DEBUG sccache::compiler::compiler] [foobar.o]: get_cached_or_compile: ["-c", "foobar.cpp", "-o", "foobar.o"]
[2024-05-13T14:02:19Z DEBUG sccache::compiler::c] Preprocessor cache hit: fc694bbcbe87a15de0b30ffc67b839dfebdd4234256d866f59f983b95760a542
[2024-05-13T14:02:19Z DEBUG sccache::compiler::compiler] [foobar.o]: generate_hash_key took 0.000 s
[2024-05-13T14:02:19Z DEBUG sccache::compiler::compiler] [foobar.o]: Hash key: 4ec1a40b5ac385fbc75c25a064c26b535028deb6b022975cba8da234ddd241a8
[2024-05-13T14:02:19Z DEBUG sccache::compiler::compiler] [foobar.o]: Cache miss in 0.000 s
[2024-05-13T14:02:19Z DEBUG sccache::compiler::compiler] [foobar.o]: Attempting distributed compilation
[2024-05-13T14:02:19Z DEBUG sccache::compiler::compiler] [foobar.o]: Creating distributed compile request
[2024-05-13T14:02:19Z DEBUG sccache::compiler::compiler] [foobar.o]: Identifying dist toolchain for "/usr/bin/g++"
[2024-05-13T14:02:19Z DEBUG sccache::dist::cache::client] Using cached toolchain /usr/bin/g++-7f52272c5869b30cfd0686d0ca6b8cb961857638027302461b3e3cfd7feb276f -> 80a7871505188355525e9a0805f24b5af7726a2a62b6b38bc594271941ff3558
[2024-05-13T14:02:19Z DEBUG sccache::compiler::compiler] [foobar.o]: Requesting allocation
[2024-05-13T14:02:19Z DEBUG reqwest::connect] starting new connection: http://192.168.1.112:10600/
[2024-05-13T14:02:19Z DEBUG hyper::client::connect::http] connecting to 192.168.1.112:10600
[2024-05-13T14:02:19Z DEBUG hyper::client::connect::http] connected to 192.168.1.112:10600
[2024-05-13T14:02:19Z DEBUG hyper::proto::h1::io] flushed 275 bytes
[2024-05-13T14:02:19Z DEBUG hyper::proto::h1::io] parsed 4 headers
[2024-05-13T14:02:19Z DEBUG hyper::proto::h1::conn] incoming body is content-length (183 bytes)
[2024-05-13T14:02:19Z DEBUG hyper::proto::h1::conn] incoming body completed
[2024-05-13T14:02:19Z DEBUG sccache::compiler::compiler] [foobar.o]: Running job
[2024-05-13T14:02:19Z DEBUG reqwest::connect] starting new connection: https://192.168.1.112:10501/
[2024-05-13T14:02:19Z DEBUG hyper::client::connect::http] connecting to 192.168.1.112:10501
[2024-05-13T14:02:19Z DEBUG hyper::client::connect::http] connected to 192.168.1.112:10501
[2024-05-13T14:02:19Z DEBUG hyper::proto::h1::io] flushed 5326 bytes
[2024-05-13T14:02:19Z DEBUG hyper::proto::h1::io] parsed 4 headers
[2024-05-13T14:02:19Z DEBUG hyper::proto::h1::conn] incoming body is content-length (426 bytes)
[2024-05-13T14:02:19Z DEBUG hyper::proto::h1::conn] incoming body completed
[2024-05-13T14:02:19Z INFO  sccache::compiler::compiler] fetched [("/home/alex/codaz/Mozilla/sccache/foobar.o", "Size: 928->329")]
[2024-05-13T14:02:19Z DEBUG sccache::compiler::compiler] [foobar.o]: Compiled in 0.057 s, storing in cache
[2024-05-13T14:02:19Z DEBUG sccache::compiler::compiler] [foobar.o]: Created cache artifact in 0.001 s
[2024-05-13T14:02:19Z DEBUG sccache::server] compile result: cache miss
[2024-05-13T14:02:19Z DEBUG sccache::server] stats after compile result: ServerStats { compile_requests: 2, requests_unsupported_compiler: 0, requests_not_compile: 0, requests_not_cacheable: 0, requests_executed: 2, cache_errors: PerLanguageCount { counts: {}, adv_counts: {} }, cache_hits: PerLanguageCount { counts: {}, adv_counts: {} }, cache_misses: PerLanguageCount { counts: {"C/C++": 1}, adv_counts: {"c++ [gcc]": 1} }, cache_timeouts: 0, cache_read_errors: 0, non_cacheable_compilations: 0, forced_recaches: 0, cache_write_errors: 0, cache_writes: 0, cache_write_duration: 0ns, cache_read_hit_duration: 0ns, compiler_write_duration: 57.026426ms, compile_fails: 1, not_cached: {}, dist_compiles: {"192.168.1.112:10501": 1}, dist_errors: 0 }
[2024-05-13T14:02:19Z DEBUG sccache::compiler::compiler] [foobar.o]: Stored in cache successfully!
[2024-05-13T14:02:19Z DEBUG sccache::server] [foobar.o]: Cache write finished in 0.000 s
exitcode: 0
-rw-rw-r-- 1 alex alex 928 mai   13 16:02 foobar.o

lissyx · 2024-05-13T14:14:45Z

@Alphare does this help?

Locally, I cannot find content matching [2024-05-13T14:01:28Z DEBUG sccache::compiler::preprocessor_cache] Added result key 4ec1a40b5ac385fbc75c25a064c26b535028deb6b022975cba8da234ddd241a8 to preprocessor cache entry but I can find [2024-05-13T14:02:19Z DEBUG sccache::compiler::c] Preprocessor cache hit: fc694bbcbe87a15de0b30ffc67b839dfebdd4234256d866f59f983b95760a542 so I'm wondering if it's normal?

glandium · 2024-05-17T07:38:01Z

This is caused by this: https://github.com/mozilla/sccache/blob/main/src/compiler/c.rs#L444

glandium · 2024-05-17T07:43:34Z

So, the way the preprocessor cache works, it can't work with sccache-dist. The preprocessor output is not cached (because local compilations don't need it). The immediate fix would be to disable preprocessor cache when distributed compilation is enabled. For a longer term fix, the preprocessor output would need to be added, and it would also need to lead to new preprocessor cache keys, because otherwise the preprocessor cache from a local compilation (or from an older compilation) would break things.

glandium · 2024-05-17T08:14:57Z

#2173 will address the immediate problem.

glandium · 2024-05-17T08:59:04Z

PoC fix: https://paste.mozilla.org/0g2pVJZw (expires in a week)
It needs a lot of polishing.

glandium · 2024-05-17T09:47:56Z

Note to future self: the preprocessor cache is not compressed, and keeping raw preprocessor output in there is not going to go well.

lissyx · 2024-05-17T15:00:03Z

Note to future self: the preprocessor cache is not compressed, and keeping raw preprocessor output in there is not going to go well.

indeed, 15GB of preprocessor/ after a single firefox build

sylvestre · 2024-05-25T09:23:19Z

Release 0.8.1 "fixed" it

sylvestre changed the title ~~cache can end up somehow corrupted~~ sccache-dist: cache can end up somehow corrupted Mar 4, 2024

sylvestre changed the title ~~sccache-dist: cache can end up somehow corrupted~~ sccache-dist: cache can end up somehow corrupted Mar 4, 2024

glandium mentioned this issue May 29, 2024

preprocessor cache/direct mode doesn't produce -MF output #2194

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

`sccache-dist`: cache can end up somehow corrupted #2122

`sccache-dist`: cache can end up somehow corrupted #2122

lissyx commented Mar 4, 2024

sylvestre commented Mar 4, 2024

zig-for commented Mar 15, 2024

zig-for commented Mar 15, 2024

lissyx commented Apr 26, 2024

StephanDollberg commented May 2, 2024

johnLate commented May 4, 2024

johnLate commented May 7, 2024

sylvestre commented May 7, 2024

johnLate commented May 8, 2024

lissyx commented May 10, 2024

sylvestre commented May 12, 2024

lissyx commented May 13, 2024

Alphare commented May 13, 2024

lissyx commented May 13, 2024 •

edited

Loading

lissyx commented May 13, 2024

glandium commented May 17, 2024

glandium commented May 17, 2024

glandium commented May 17, 2024

glandium commented May 17, 2024

glandium commented May 17, 2024

lissyx commented May 17, 2024

sylvestre commented May 25, 2024

sccache-dist: cache can end up somehow corrupted #2122

sccache-dist: cache can end up somehow corrupted #2122

Comments

lissyx commented Mar 4, 2024

sylvestre commented Mar 4, 2024

zig-for commented Mar 15, 2024

zig-for commented Mar 15, 2024

lissyx commented Apr 26, 2024

StephanDollberg commented May 2, 2024

johnLate commented May 4, 2024

johnLate commented May 7, 2024

sylvestre commented May 7, 2024

johnLate commented May 8, 2024

lissyx commented May 10, 2024

sylvestre commented May 12, 2024

lissyx commented May 13, 2024

Alphare commented May 13, 2024

lissyx commented May 13, 2024 • edited Loading

lissyx commented May 13, 2024

glandium commented May 17, 2024

glandium commented May 17, 2024

glandium commented May 17, 2024

glandium commented May 17, 2024

glandium commented May 17, 2024

lissyx commented May 17, 2024

sylvestre commented May 25, 2024

`sccache-dist`: cache can end up somehow corrupted #2122

`sccache-dist`: cache can end up somehow corrupted #2122

lissyx commented May 13, 2024 •

edited

Loading