bug#63024: Crash during `guix import pypi -r'

bug#63024: Crash during `guix import pypi -r'

[Timo Wilken]

The `guix import pypi -r ...' command frequently crashes for me. When
it does, it always crashes on the third download, the one for the
first dependency's source distribution, like so:

--8<---------------cut here---------------start------------->8---
$ guix import pypi -r calcure

Starting download of /tmp/guix-file.7aaMby
From https://files.pythonhosted.org/packages/61/e3/c960430852d4322d42e02421690958f47fa2b42aaf4f3befb25c1c8baf21/calcure-2.8.6.tar.gz...
 …8.6.tar.gz  42KiB          2.1MiB/s 00:00 [##################] 100.0%

Starting download of /tmp/guix-file.mPnbsd
From https://files.pythonhosted.org/packages/b5/a8/8ba240c952a13b3b2bee64356dc1a1515c496100dc4c9edb6a6648927864/calcure-2.8.6-py3-none-any.whl...
 …y3-none-any.whl  49KiB     1.9MiB/s 00:00 [##################] 100.0%

Starting download of /tmp/guix-file.XzIPz0
From https://files.pythonhosted.org/packages/24/91/77edc7626400922d44019753c39e0fd911176ce3f77c3f85ac832d5d70b7/holidays-0.23.tar.gz...
In procedure connect*: Connection timed out

Starting download of /tmp/guix-file.XzIPz0
From https://web.archive.org/web/20230422212928/https://files.pythonhosted.org/packages/24/91/77edc7626400922d44019753c39e0fd911176ce3f77c3f85ac832d5d70b7/holidays-0.23.tar.gz...
In procedure connect*: Connection timed out
Trying to use Disarchive to assemble /tmp/guix-file.XzIPz0...
could not find its Disarchive specification
failed to download "/tmp/guix-file.XzIPz0" from "https://files.pythonhosted.org/packages/24/91/77edc7626400922d44019753c39e0fd911176ce3f77c3f85ac832d5d70b7/holidays-0.23.tar.gz"
Backtrace:
          10 (primitive-load "/home/timo/.config/guix/current/bin/gu…")
In guix/ui.scm:
   2300:7  9 (run-guix . _)
  2263:10  8 (run-guix-command _ . _)
In guix/scripts/import.scm:
    89:11  7 (guix-import . _)
In ice-9/boot-9.scm:
  1752:10  6 (with-exception-handler _ _ #:unwind? _ # _)
In guix/scripts/import/pypi.scm:
    97:21  5 (_)
In guix/import/utils.scm:
    638:3  4 (recursive-import _ #:repo->guix-package _ #:guix-name . #)
   600:31  3 (topological-sort _ #<procedure 7f668bf7a8d0 at guix/i…> …)
In srfi/srfi-1.scm:
   586:17  2 (map1 (("holidays" #f) ("jdatetime" #f) ("ics" #f)))
In guix/import/utils.scm:
   630:33  1 (lookup-node "holidays" #f)
In ice-9/boot-9.scm:
  1685:16  0 (raise-exception _ #:continuable? _)

ice-9/boot-9.scm:1685:16: In procedure raise-exception:
Wrong number of values returned to continuation (expected 2)
--8<---------------cut here---------------end--------------->8---

However, that URL is valid -- running a manual `guix download'
afterwards works fine:

--8<---------------cut here---------------start------------->8---
$ guix download 'https://files.pythonhosted.org/packages/24/91/77edc7626400922d44019753c39e0fd911176ce3f77c3f85ac832d5d70b7/holidays-0.23.tar.gz'  

Starting download of /tmp/guix-file.vsuTGB
From https://files.pythonhosted.org/packages/24/91/77edc7626400922d44019753c39e0fd911176ce3f77c3f85ac832d5d70b7/holidays-0.23.tar.gz...
 ….23.tar.gz  374KiB     2.5MiB/s 00:00 [##################] 100.0%
/gnu/store/jk0v685hhwirl16la349c7i5is640181-holidays-0.23.tar.gz
0yxs1lzbqykl25yf1hcrqjb7qqw69f2zgf7991slnkmk98p1bsxw
--8<---------------cut here---------------end--------------->8---

bug#63024: Crash during `guix import pypi -r'

[Simon Tournier]

Hi,

On Sat, 22 Apr 2023 at 21:59, "Timo Wilken" <guix@twilken.net> wrote:

> The `guix import pypi -r ...' command frequently crashes for me. When
> it does, it always crashes on the third download, the one for the
> first dependency's source distribution, like so:

Thanks for the report.  I am merging with #62334 [1].

1: http://issues.guix.gnu.org/issue/62334


Cheers,
simon

bug#63024: Crash during `guix import pypi -r'

[Ludovic Courtès]

Hello!

Greg Hogan <code@greghogan.com> skribis:

> Starting download of /tmp/guix-file.xReGb4
>>From https://web.archive.org/web/20230321140958/https://files.pythonhosted.org/packages/49/01/21337857631a97ab551bb2e3b5691ed6b1b9586011aa6a5355b9694a37fa/demon-2.0.6.tar.gz...
> In procedure connect*: Connection timed out

I can very much reproduce the bug with “guix import pypi -r cdlib” on
39ba8a10971f15264966823e8696d63c2995df86 and thereabouts.  Turns out
it’s a fun story!  (Josselin, I’m sure you’ll love it.)

First, the person who wrote ‘connect*’ *cough* hadn’t carefully read the
Guile manual, which reads (info "(guile) Ports and File Descriptors"):

  Note that ‘select’ may return early for other reasons, for example due
  to pending interrupts.

Clearly, ‘select’ is returning early, so we should check that and loop.
So far, so good.

Now, why is ‘select’ returning immediately?  Because the underlying
select(2) call is passed an extra file descriptor, the “sleep pipe”, as
you can see in ‘scm_std_select’ in libguile, and it’s that file
descriptor, number 3, that’s active at each select(2) call:

--8<---------------cut here---------------start------------->8---
28825 23:06:04 pselect6(15, [3], [14], [14], {tv_sec=10, tv_nsec=0}, NULL) = 1 (in [3], left {tv_sec=9, tv_nsec=999991063}) <0.000079>
28825 23:06:04 read(3, "A", 1)          = 1 <0.000044>
--8<---------------cut here---------------end--------------->8---

Why so much activity on that “sleep pipe”, you ask?  Well, once we’ve
filtered the read(3, …) calls, a pattern appears:

--8<---------------cut here---------------start------------->8---
  14335:28825 23:06:04 read(3, "A", 1)          = 1 <0.000044>
  14344:28825 23:06:04 read(3, "r", 1)          = 1 <0.000121>
  14353:28825 23:06:04 read(3, "c", 1)          = 1 <0.000107>
  14362:28825 23:06:04 read(3, "h", 1)          = 1 <0.000040>
  14436:28825 23:06:04 read(3, "i", 1)          = 1 <0.000049>
  14445:28825 23:06:04 read(3, "v", 1)          = 1 <0.000029>
  14454:28825 23:06:04 read(3, "e", 1)          = 1 <0.000019>
  14463:28825 23:06:04 read(3, ":", 1)          = 1 <0.000017>
  14472:28825 23:06:04 read(3, " ", 1)          = 1 <0.000019>
  14481:28825 23:06:04 read(3, " ", 1)          = 1 <0.000020>
  14490:28825 23:06:04 read(3, "/", 1)          = 1 <0.000019>
  14499:28825 23:06:04 read(3, "t", 1)          = 1 <0.000015>
  14508:28825 23:06:04 read(3, "m", 1)          = 1 <0.000018>
  15001:28825 23:06:04 read(3, "p", 1)          = 1 <0.000015>
  15010:28825 23:06:04 read(3, "/", 1)          = 1 <0.000016>
  15019:28825 23:06:04 read(3, "g", 1)          = 1 <0.000016>
  15028:28825 23:06:04 read(3, "u", 1)          = 1 <0.000015>
  15037:28825 23:06:04 read(3, "i", 1)          = 1 <0.000015>
  15046:28825 23:06:04 read(3, "x", 1)          = 1 <0.000015>
  15055:28825 23:06:04 read(3, "-", 1)          = 1 <0.000015>
--8<---------------cut here---------------end--------------->8---

See?  Who’s chatting over our sleep pipe?

--8<---------------cut here---------------start------------->8---
   4806:28831 23:06:03 dup2(0, 3)               = 3 <0.000011>
   4807:28831 23:06:03 dup2(3, 0)               = 0 <0.000011>
   4808:28831 23:06:03 dup2(4, 1)               = 1 <0.000012>
   4809:28831 23:06:03 dup2(5, 2)               = 2 <0.000010>
   4810:28831 23:06:03 close(3)                 = 0 <0.000010>
   4811:28831 23:06:03 close(4)                 = 0 <0.000011>
   4812:28831 23:06:03 close(5)                 = 0 <0.000010>
   4813:28831 23:06:03 close(6)                 = 0 <0.000010>
   4814:28831 23:06:03 close(7)                 = 0 <0.000010>
   4815:28831 23:06:03 close(8)                 = 0 <0.000011>
   4816:28831 23:06:03 close(9)                 = 0 <0.000010>
   4817:28831 23:06:03 close(10)                = 0 <0.000010>
   4818:28831 23:06:03 close(11)                = 0 <0.000011>
   4819:28831 23:06:03 close(12)                = 0 <0.000010>
   4820:28831 23:06:03 close(13)                = 0 <0.000010>
   4821:28831 23:06:03 close(14)                = 0 <0.000011>
   4822:28831 23:06:03 close(15)                = -1 EBADF (Bad file descriptor) <0.000011>
   4823:28831 23:06:03 prlimit64(0, RLIMIT_NOFILE, NULL, {rlim_cur=1024, rlim_max=4*1024}) = 0 <0.000011>
   4824:28831 23:06:03 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 <0.000010>
   4825:28831 23:06:03 execve("/home/ludo/src/guix/scripts/unzip", ["unzip", "/tmp/guix-file.bmholm", "-d", "/tmp/guix-directory.Ok2DAA", "cdlib-0.2.6.dist-info/METADATA"], 0x18a7db0 /* 85 v
   […]
   4938:28831 23:06:03 write(1, "Archive:  /tmp/guix-file.bmholm\n", 32) = 32 <0.000018>
--8<---------------cut here---------------end--------------->8---

‘unzip’!  And all its friends invoked from (guix import pypi):

--8<---------------cut here---------------start------------->8---
        (call-with-temporary-directory
         (lambda (dir)
           (parameterize ((current-error-port (%make-void-port "rw+"))
                          (current-output-port (%make-void-port "rw+")))
             (if (string=? "zip" (file-extension source-url))
                 (invoke "unzip" archive "-d" dir)
                 (invoke "tar" "xf" archive "-C" dir)))
           …))
--8<---------------cut here---------------end--------------->8---

Looks like we shoudn’t dup(4, 1) in the child process, because 4 is the
other end of our sleep pipe.  :-)

The problem exists both in 3.0.9 and Guile ‘main’.  Looks related to the
file descriptor shuffling code in ‘do_spawn’.  WDYT, Josselin?

Ludo’.

bug#63024: Crash during `guix import pypi -r'

[Ludovic Courtès]

Hi,

Simon Tournier <zimon.toutoune@gmail.com> skribis:

> On Wed, 03 May 2023 at 11:04, Ludovic Courtès <ludo@gnu.org> wrote:
>
>> diff --git a/libguile/posix.c b/libguile/posix.c
>> index 3adc743c4..2d55d985c 100644
>> --- a/libguile/posix.c
>> +++ b/libguile/posix.c
>
> Does it mean patch the current Guile or a new release of Guile?

It’s a patch against Guile ‘main’.  That gives an incentive to push a
new Guile release.

Ludo’.

bug#63024: Crash during `guix import pypi -r'

[Ludovic Courtès]

Ludovic Courtès <ludo@gnu.org> skribis:

> First, the person who wrote ‘connect*’ *cough* hadn’t carefully read the
> Guile manual, which reads (info "(guile) Ports and File Descriptors"):
>
>   Note that ‘select’ may return early for other reasons, for example due
>   to pending interrupts.
>
> Clearly, ‘select’ is returning early, so we should check that and loop.

Pushed a fix for that in fc6c96c88a0e4ad0b9e48272e5f97ffaa6eec36e.

Ludo’.