Hi, Ludovic Courtès <ludovic.cour...@inria.fr> skribis:
> We occasionally see failed builds with truncated logs on ci.guix. These > happens in situations where ‘cuirass remote-worker’ gets EPIPE as it > sends the build log to ‘remote-server’: > > 2024-08-19 19:54:52 @ substituter-started > /gnu/store/sv3z77cgg2788hrl87w35bfmyhkmkv54-libomp-16.0.6.drv substitute > 2024-08-19 19:54:52 Downloading > http://141.80.167.131/nar/lzip/sv3z77cgg2788hrl87w35bfmyhkmkv54-libomp-16.0.6.drv... > 2024-08-19 19:54:52 > 2024-08-19 19:54:52 ESC[K libomp-16.0.6.drv > 1.8MiB/s 00:00 | 1KiB transferred > 2024-08-19 19:54:52 ESC[K libomp-16.0.6.drv > 942KiB/s 00:00 | 1KiB transferred > 2024-08-19 19:54:52 > 2024-08-19 19:54:52 @ substituter-succeeded > /gnu/store/sv3z77cgg2788hrl87w35bfmyhkmkv54-libomp-16.0.6.drv > 2024-08-19 19:55:04 warning: zlib error in 'gzwrite' while sending log to > 141.80.167.131: 0 > 2024-08-19 19:55:04 error: gdPO1dI1: unexpected error while building > '/gnu/store/sv3z77cgg2788hrl87w35bfmyhkmkv54-libomp-16.0.6.drv': > #<&compound-exception components: (#<&external-error> #<&origin origin: > "fport_write"> #<&message message: "~A"> #<&irritants irritants: ("Broken > pipe")> #<&exception-with-kind-and-args kind: system-error args: > ("fport_write" "~A" ("Broken pipe") (32))>)> But hey, why does ‘gzwrite’ fail in the first place? I noticed that this usually happened when dumping big logs (several MiBs) very quickly (typically the unpack phase of a large package like LLVM producing lots of data very quickly.) As it turns out, ‘send-log’ opens its socket with SOCK_NONBLOCK, and then passes it to zlib, which writes to it in ‘gzwrite’. But zlib is not equipped to deal with EAGAIN: it just errors out, with ‘gzwrite’ returning Z_ERRNO, hence the bug above. I was able to confirm this hypothesis by running: echo '(log-server (version 0))' | nc -l -p 5000 -v | \ (sleep 10; echo starting >&2; wc -c) and then, from a REPL: scheme@(cuirass remote)> (send-log "127.0.0.1" 5000 "foo.drv" (open-input-file "llvm.log")) 2024-08-22T16:35:37 warning: zlib error in 'gzwrite' while sending log to 127.0.0.1: -1 <fd:19>: Resource temporarily unavailable $30 = #f QED. (Here I used Guile-zlib 0.2.1 with a small modification to ‘remote.scm’ so it displays the error message after Z_ERRNO = -1.) Ludo’.
