GNU bug report logs - #29335
'guix publish' workers occasionally crash

Previous Next

Full log

View this message in rfc822 format

From: help-debbugs <at> gnu.org (GNU bug Tracking System)
To: ludo <at> gnu.org (Ludovic Courtès)
Cc: tracker <at> debbugs.gnu.org
Subject: bug#29335: closed ('guix publish' workers occasionally crash)
Date: Sun, 19 Nov 2017 22:49:01 +0000

[Message part 1 (text/plain, inline)]

Your message dated Sun, 19 Nov 2017 23:48:47 +0100
with message-id <87d14dzxyo.fsf <at> gnu.org>
and subject line Re: bug#29335: 'guix publish' workers occasionally crash
has caused the debbugs.gnu.org bug report #29335,
regarding 'guix publish' workers occasionally crash
to be marked as done.

(If you believe you have received this mail in error, please contact
help-debbugs <at> gnu.org.)


-- 
29335: http://debbugs.gnu.org/cgi/bugreport.cgi?bug=29335
GNU Bug Tracking System
Contact help-debbugs <at> gnu.org with problems

[Message part 2 (message/rfc822, inline)]

From: ludo <at> gnu.org (Ludovic Courtès)
To: bug-guix <at> gnu.org
Subject: 'guix publish' workers occasionally crash
Date: Fri, 17 Nov 2017 11:10:49 +0100

Hello,

On berlin I’ve noticed that the ‘guix publish’ workers would
occasionally stop working: the main thread would keep replying to HTTP
requests, but the worker threads would no longer do anything, and would
leave behind them a bunch of .tmp files in /var/cache/guix/publish.

I captured the output of ‘guix publish’ (guix-0.13.0-8.357ab93) and the
only clue I have is this:

--8<---------------cut here---------------start------------->8---
GET /6kl9ydqmgklcqhxswg6v5isq5n1ih5gp.narinfo
In guix/workers.scm:
     74:9  2 (_)
    78:32  1 (_ srfi-34 #<condition &nix-connection-error [file: "/v…>)
In unknown file:
           0 (make-stack #t)
ERROR: In procedure make-stack:
ERROR: Throw to key `srfi-34' with args `(#<condition &nix-connection-error [file: "/var/guix/daemon-socket/socket" errno: 9] 3ba2ea0>)'.
GET /fgiih42mg2sr82mbmzf56grvrf021im6.narinfo
--8<---------------cut here---------------end--------------->8---

… where 9 is EBADF.

The open files are:

--8<---------------cut here---------------start------------->8---
ludo <at> berlin ~$ sudo ls -l /proc/4105/fd
total 0
l-wx------ 1 root root 64 Nov 17 04:00 0 -> /dev/null
l-wx------ 1 root root 64 Nov 17 04:00 1 -> /home/ludo/nohup.out
lr-x------ 1 root root 64 Nov 17 04:00 10 -> pipe:[9911558]
l-wx------ 1 root root 64 Nov 17 04:00 11 -> pipe:[9911558]
lr-x------ 1 root root 64 Nov 17 04:00 12 -> pipe:[9900923]
l-wx------ 1 root root 64 Nov 17 04:00 13 -> pipe:[9900923]
lrwx------ 1 root root 64 Nov 17 04:00 14 -> socket:[9911560]
lrwx------ 1 root root 64 Nov 17 04:00 15 -> socket:[9911563]
lr-x------ 1 root root 64 Nov 17 04:00 16 -> pipe:[9912323]
l-wx------ 1 root root 64 Nov 17 04:00 17 -> pipe:[9912323]
lr-x------ 1 root root 64 Nov 17 04:00 18 -> pipe:[9909649]
l-wx------ 1 root root 64 Nov 17 04:00 19 -> pipe:[9909649]
l-wx------ 1 root root 64 Nov 17 04:00 2 -> /home/ludo/nohup.out
lr-x------ 1 root root 64 Nov 17 04:00 20 -> pipe:[9908165]
l-wx------ 1 root root 64 Nov 17 04:00 21 -> pipe:[9908165]
lr-x------ 1 root root 64 Nov 17 04:00 22 -> pipe:[9899432]
l-wx------ 1 root root 64 Nov 17 04:00 23 -> pipe:[9899432]
lr-x------ 1 root root 64 Nov 17 04:00 24 -> pipe:[9911564]
l-wx------ 1 root root 64 Nov 17 04:00 25 -> pipe:[9911564]
lr-x------ 1 root root 64 Nov 17 04:00 26 -> pipe:[9908166]
l-wx------ 1 root root 64 Nov 17 04:00 27 -> pipe:[9908166]
l-wx------ 1 root root 64 Nov 17 04:00 28 -> /var/cache/guix/publish/gzip/11vik22bwzzvwksd1l08frhcm3v3hhmm-dealii-8.5.1.nar.tmp
l-wx------ 1 root root 64 Nov 17 04:00 29 -> /var/cache/guix/publish/gzip/k90h1bkmsiq8qxrhk31l5c8maiqmy5k0-zathura-pdf-mupdf-0.3.1.nar.tmp
lr-x------ 1 root root 64 Nov 17 04:00 3 -> pipe:[9902378]
lr-x------ 1 root root 64 Nov 17 04:00 30 -> /gnu/store/2xp8n6k6mbfgi8972lj0vvk52gfx4576-linux-libre-4.9.61/lib/modules/4.9.61-gnu/kernel/drivers/net/ethernet/intel/i40evf
lr-x------ 1 root root 64 Nov 17 04:00 31 -> /gnu/store/k90h1bkmsiq8qxrhk31l5c8maiqmy5k0-zathura-pdf-mupdf-0.3.1/share
l-wx------ 1 root root 64 Nov 17 04:00 32 -> /var/cache/guix/publish/gzip/xa6bwlgm82xwfg9icl4d9bs2bhj8cb1a-perl-safe-isa-1.000008.nar.tmp
l-wx------ 1 root root 64 Nov 17 04:00 33 -> /var/cache/guix/publish/gzip/2xp8n6k6mbfgi8972lj0vvk52gfx4576-linux-libre-4.9.61.nar.tmp
lr-x------ 1 root root 64 Nov 17 04:00 34 -> /gnu/store/11vik22bwzzvwksd1l08frhcm3v3hhmm-dealii-8.5.1/share
l-wx------ 1 root root 64 Nov 17 04:00 4 -> pipe:[9902378]
lr-x------ 1 root root 64 Nov 17 04:00 5 -> pipe:[9902379]
l-wx------ 1 root root 64 Nov 17 04:00 6 -> pipe:[9902379]
lr-x------ 1 root root 64 Nov 17 04:00 7 -> /gnu/store/sk1w5whws8xhvb03sm2h44f9fm6c2gkc-guix-0.13.0-8.357ab93/bin/.guix-real
lr-x------ 1 root root 64 Nov 17 04:00 8 -> pipe:[9910685]
l-wx------ 1 root root 64 Nov 17 04:00 9 -> pipe:[9910685]
--8<---------------cut here---------------end--------------->8---

Ludo’.

[Message part 3 (message/rfc822, inline)]

From: ludo <at> gnu.org (Ludovic Courtès)
To: 29335-done <at> debbugs.gnu.org
Subject: Re: bug#29335: 'guix publish' workers occasionally crash
Date: Sun, 19 Nov 2017 23:48:47 +0100

ludo <at> gnu.org (Ludovic Courtès) skribis:

> On berlin I’ve noticed that the ‘guix publish’ workers would
> occasionally stop working: the main thread would keep replying to HTTP
> requests, but the worker threads would no longer do anything, and would
> leave behind them a bunch of .tmp files in /var/cache/guix/publish.
>
> I captured the output of ‘guix publish’ (guix-0.13.0-8.357ab93) and the
> only clue I have is this:
>
> GET /6kl9ydqmgklcqhxswg6v5isq5n1ih5gp.narinfo
> In guix/workers.scm:
>      74:9  2 (_)
>     78:32  1 (_ srfi-34 #<condition &nix-connection-error [file: "/v…>)
> In unknown file:
>            0 (make-stack #t)
> ERROR: In procedure make-stack:
> ERROR: Throw to key `srfi-34' with args `(#<condition &nix-connection-error [file: "/var/guix/daemon-socket/socket" errno: 9] 3ba2ea0>)'.
> GET /fgiih42mg2sr82mbmzf56grvrf021im6.narinfo

Good news, this is fixed in 85f4f7b79040d982c6a655c898b4cd00d868fa9c.

This could be reproduced by running ‘guix publish’ with 10 workers or
more, and then triggering nar compression en masse with ‘guix weather’.

EBADF was due to a race condition in zlib.scm when closing gzip output
ports:

          ;; 'gzclose' closes the underlying file descriptor.  'close-port'
          ;; calls close(2) and gets EBADF, which we swallow.
          (gzclose gzfile)
          (ignore-EBADF (close-port port)))

There was a window after the ‘gzclose’ call during which the file
descriptor for GZFILE and PORT above could be reused for something else,
and then ‘close-port’ would close it.

Thanks,
Ludo’.

Previous Next

GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.