[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
bug#72722: [cuirass] Failure to write build log leads to build failure
From: |
Ludovic Courtès |
Subject: |
bug#72722: [cuirass] Failure to write build log leads to build failure |
Date: |
Thu, 22 Aug 2024 16:42:20 +0200 |
User-agent: |
Gnus/5.13 (Gnus v5.13) |
Hi,
Ludovic Courtès <ludovic.courtes@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’.