Subject: Re: bug#17591: Offload hook fails to send files

From: [email-masked] (Ludovic Courtès)
Date: Tue, 27 May 2014 17:16:56 +0200

I modified the offload hook and (guix build utils) so ‘cat’ is used
instead of ‘xz’.

When tracing sshd on the target machine and looking at the ‘guix archive
--import’ process in a failure case we see:

--8<---------------cut here---------------start------------->8---
21927 connect(10, {sa_family=AF_FILE, path="/usr/local/var/guix/daemon-socket/socket"}, 42) = 0
21927 write(10, "cxin\0\0\0\0", 8)      = 8
21927 read(10, "oixd\0\0\0\0", 8)       = 8
21927 read(10, "\16\1\0\0\0\0\0\0", 8)  = 8
21927 write(10, "\f\1\0\0\0\0\0\0", 8)  = 8
21927 write(10, "\1\0\0\0\0\0\0\0", 8)  = 8
21927 read(10, "stla\0\0\0\0", 8)       = 8
21927 write(10, "\33\0\0\0\0\0\0\0", 8) = 8
21927 read(10, "atad\0\0\0\0", 8)       = 8
21927 read(10, "\0\200\0\0\0\0\0\0", 8) = 8
21927 read(0, "\1\0\0\0\0\0\0\0\r\0\0\0\0\0\0\0nix-archive-1\0\0\0\1\0\0\0\0\0\0\0(\0\0\0\0\0\0\0\4\0\0\0\0\0\0\0type\0\0\0\0\7\0\0\0\0\0\0\0regular\0\10\0\0\0\0\0\0\0contents\255\10\0\0\0\0\0\0(begin (use-modules (guix build gnu-build-system) (guix build utils)) (define %output (getenv \"out\")) (define %outputs (map (lambd"..., 4096) = 4096
21927 read(0, "C1B08ED62008395B0764CD9B55E80DA0A2B61C698DC27EA98E68BB576ACFC2B91B4D7283E7D960948D049D6E3C4CB1F489B460A120A4BB6C04A843FD3A67454136DE61CF68A927871EFFA9141BD372A748593C703E0301F039A9E674C50301BFC385BABE5B154250E7D57B82DB31F1E1AC696F870D"..., 4096) = 4096
21927 read(0,  <unfinished ...>

[...]

21927 <... read resumed> "ile-builder\0\0\0\0\0;\0\0\0\0\0\0\0/gnu/store/ip4w122y4wlkw9n1nb6g2sbz4ql0m8dy-patch-2.7.1.drv\0\0\0\0\0009\0\0\0\0\0\0\0/gnu/store/j6gq2p03mxjlmhmamg2mxixdf13djd60-grep-2.18.drv\0\0\0\0\0\0\0008\0\0\0\0\0\0\0/gnu/store/k3azrhdbjrdhjc3vlx154069imcql8jn-bash-4.3.drv;\0\0\0\0\0\0\0/g"..., 4096) = 2880
21926 <... write resumed> )             = 2880
21927 read(0,  <unfinished ...>
21926 read(0, "", 65536)                = 0
21926 close(0)                          = 0
21926 close(1 <unfinished ...>
21927 <... read resumed> "", 4096)      = 0
21926 <... close resumed> )             = 0
21926 close(2)                          = 0
21927 write(10, "@+\0\0\0\0\0\0", 8 <unfinished ...>
21926 exit_group(0)                     = ?
21927 <... write resumed> )             = 8
21927 write(10, "\1\0\0\0\0\0\0\0\0000\213\1\0\0\0\0nix-archive-1\0\0\0\1\0\0\0\0\0\0\0 0\213\1\0\0\0\0\4\0\0\0\0\0\0\0type\0\0\0\0\7\0\0\0\0\0\0\0@0\213\1\0\0\0\0\10\0\0\0\0\0\0\0contents\255\10\0\0\0\0\0\0`0\213\1\0\0\0\0use-modules (guix build \2000\213\1\0\0\0\0d-system) (guix build ut\2400\213\1\0\0\0\0efine %output (getenv \"o\3000\213\1\0\0\0\0efine %outputs (map (lam\3400"..., 11072 <unfinished ...>
21925 <... wait4 resumed> [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0, NULL) = 21926
--8<---------------cut here---------------end--------------->8---

It reads 11072 bytes (as expected) from stdin, but by the time it writes
them on the socket (the last write(10, ...) call), those 11072 bytes got
corrupted.

The above snippet corresponds to this part of store.scm:

--8<---------------cut here---------------start------------->8---
          ((= k %stderr-read)
           ;; Read a byte stream from USER-PORT.
           (let* ((max-len (read-int p))
                  (data    (get-bytevector-n user-port max-len))
                  (len     (bytevector-length data)))
             (write-int len p)
             (put-bytevector p data)
             (write-padding len p)
             #f))
--8<---------------cut here---------------end--------------->8---

where ‘data’ is the corrupted bytevector.

The good news is that I can reproduce it like this:

--8<---------------cut here---------------start------------->8---
$ guix archive --export $(guix build -d coreutils) > t.nar
$ while guix archive --import <t.nar ; do : ; done
importing path `/gnu/store/5nhsz368f88bbgkjjwzz5k24nnnrk544-coreutils-8.22.drv'
importing path `/gnu/store/5nhsz368f88bbgkjjwzz5k24nnnrk544-coreutils-8.22.drv'
importing path `/gnu/store/5nhsz368f88bbgkjjwzz5k24nnnrk544-coreutils-8.22.drv'
[... wait ...]
Backtrace:
In ice-9/boot-9.scm:
 157: 15 [catch #t #<catch-closure 2062ce0> ...]
In unknown file:
   ?: 14 [apply-smob/1 #<catch-closure 2062ce0>]
In ice-9/boot-9.scm:
  63: 13 [call-with-prompt prompt0 ...]
In ice-9/eval.scm:
 432: 12 [eval # #]
In ice-9/boot-9.scm:
2401: 11 [save-module-excursion #<procedure 207f940 at ice-9/boot-9.scm:4045:3 ()>]
4050: 10 [#<procedure 207f940 at ice-9/boot-9.scm:4045:3 ()>]
1724: 9 [%start-stack load-stack ...]
1729: 8 [#<procedure 2096ea0 ()>]
In unknown file:
   ?: 7 [primitive-load "/home/ludo/soft/bin/guix"]
In guix/ui.scm:
 631: 6 [run-guix-command archive "--import"]
In ice-9/boot-9.scm:
 157: 5 [catch srfi-34 #<procedure 3018b00 at guix/ui.scm:198:2 ()> ...]
 157: 4 [catch system-error ...]
In guix/scripts/archive.scm:
 327: 3 [#<procedure 3019a80 at guix/scripts/archive.scm:312:2 ()>]
In guix/store.scm:
 766: 2 [import-paths #<build-daemon 256.14 2ff7000> #<input: file 0>]
 400: 1 [process-stderr #<build-daemon 256.14 2ff7000> #<input: file 0>]
In unknown file:
   ?: 0 [bytevector-length #<eof>]

ERROR: In procedure bytevector-length:
ERROR: In procedure scm_c_bytevector_length: Wrong type argument in position 1 (expecting bytevector): #<eof>
--8<---------------cut here---------------end--------------->8---

To be continued...

Ludo’.