bug#49862: While downloading substitutes: Wrong type argument in position 1 (expecting struct): #f

[Ludovic Courtès]

Hi Maxim,

Maxim Cournoyer <maxim.cournoyer@gmail.com> skribis:

> This occurred while trying to build an updated fontconfig on the
> core-updates branch:
>
> successfully built 
> /gnu/store/dh7wr4laxg5r8x22iv2ydbh8krcm6782-libuninameslist-20200313.drv
> The following builds are still in progress:
>   /gnu/store/mzw4s9y67cp9i1mylqkiyrpxpyaq5f7s-libnftnl-1.2.0.drv
>   /gnu/store/vn2pgkxz1lhvdmzv63crlxvz913v9q3i-libungif-4.1.4.drv
>   /gnu/store/yjq9xi300kwpcdca9b38r0fjmvl8q95c-m4-1.4.18.tar.xz.drv
>   /gnu/store/5wg445g4y00jwxvga7rk4fk4vmv6hl8d-lzo-2.10.drv
>   /gnu/store/hicph1jxczzacyy3xc4wqbjfqdskxwnn-libxml2-2.9.12.tar.xz.drv
>   /gnu/store/gda40q0dd10hr0fm4sffzgc9zv24mb0s-libxml2-2.9.12.tar.xz.drv
>   /gnu/store/8ir67jqrzwz62s522xi19xlq0yik417f-libtasn1-4.17.0.drv
>   /gnu/store/mr9639s4z2fsvcwmw8mw17j9b5f6l4gh-lxml-4.6.3.tar.xz.drv
>   /gnu/store/96qnk27khjc25rbdz2gxr22sqgmh4lq9-libxslt-1.1.34.tar.xz.drv
>   /gnu/store/jxvirmrqxhfp530vggm6bcgq8rs6ya6y-libtool-2.4.6.tar.xz.drv
>   /gnu/store/flmxhxmkj6vbpg6pgh57xp390bxwzqj7-guile-3.0.7.drv
>   /gnu/store/sl9k1cdgp1g6hk796sd1pra1w88vnybc-bash-minimal-5.1.8.drv
>   /gnu/store/a2zj0nybbs7ydgp30da8vxbgf3s9ndfv-docbook-xsl-1.79.2.tar.xz.drv
>   /gnu/store/8rc15lklpf7xyyr57a8mvl2ybvrj5h3q-c-ares-1.17.1.drv
>   /gnu/store/4s3kciwd65syrvk3ryvvyk3xydx43mw3-cairo-1.16.0.tar.xz.drv
>
> substituting 
> /gnu/store/yqvsc5brbzpk1m7zr8bnyr66kz9q625a-nasm-2.15.05.tar.xz...
> substituting 
> /gnu/store/4fliaxdz084ijlzb6d98sgg76dmz9xp6-net-tools-1.60-0.479bb4a.zip...
> substituting 
> /gnu/store/js6wj0pmd4lqnnkys7f9az4gcm8szfmi-nettle-3.7.3.tar.gz...
> substituting 
> /gnu/store/lz5qmr8bv3wwmja3vw59yjydiy66ni3a-nghttp2-1.44.0.tar.xz...
> process 30234 acquired build slot '/var/guix/offload/127.0.0.1:6666/1'
> normalized load on machine '127.0.0.1' is 0.17
> building /gnu/store/9xadqmcq1z02x93k7c5xpwbwd4a7f1rk-apr-1.6.5.drv...
> eckout 50269 50269
> Backtrace:
>           19 (apply-smob/0 #<thunk 7fd0dfaedf60>)
> In ice-9/boot-9.scm:
>     724:2 18 (call-with-prompt _ _ #<procedure default-prompt-handler (k 
> proc)>)
> In ice-9/eval.scm:
>     619:8 17 (_ #(#(#<directory (guile-user) 7fd0dfae7c80>)))
> In guix/ui.scm:
>    2185:7 16 (run-guix . _)
>   2148:10 15 (run-guix-command _ . _)
> In ice-9/boot-9.scm:
>   1752:10 14 (with-exception-handler _ _ #:unwind? _ #:unwind-for-type _)
> In guix/status.scm:
>     800:4 13 (call-with-status-report _ _)
> In ice-9/boot-9.scm:
>   1752:10 12 (with-exception-handler _ _ #:unwind? _ #:unwind-for-type _)
> In guix/store.scm:
>    658:37 11 (thunk)
>    1320:8 10 (call-with-build-handler _ _)
>    1320:8  9 (call-with-build-handler #<procedure 7fd0dd3fdfc0 at 
> guix/ui.scm:1155:2 (continue store …> …)
> In guix/scripts/build.scm:
>    699:26  8 (_)
> In guix/store.scm:
>   1388:15  7 (_ #<store-connection 256.99 7fd0dfa699b0> _ _)
>    759:13  6 (process-stderr _ _)
> In unknown file:
>            5 (display "eckout 50269 50269\n@ download-succeeded 
> /gnu/store/1i7b2hrywrp90w5dd9nq6dw788…" …)
> In guix/status.scm:
>    723:16  4 (write! _ _ _)
>    636:15  3 (_ (download-succeeded 
> "/gnu/store/1i7b2hrywrp90w5dd9nq6dw7888wzqkq-mallard-ducktype-…" …) …)
>    272:33  2 (compute-status _ #<<build-status> building: (#<<build> 
> derivation: "/gnu/store/9xadqmcq…> …)
> In ice-9/boot-9.scm:
>   1685:16  1 (raise-exception _ #:continuable? _)
>   1685:16  0 (raise-exception _ #:continuable? _)
>
> ice-9/boot-9.scm:1685:16: In procedure raise-exception:
> In procedure struct-vtable: Wrong type argument in position 1 (expecting
> struct): #f

That reminds me of <https://issues.guix.gnu.org/43518> though it seems
to be a bit different.

The context of status.scm:272:33 is this:

--8<---------------cut here---------------start------------->8---
    (('download-succeeded item uri (= string->number size))
     (let ((current (find (matching-download item)
                          (build-status-downloading status))))
       (build-status
        (inherit status)
        (downloading (delq current (build-status-downloading status)))
        (downloads-completed
         (cons (download item uri
                         #:size size
                         #:start (download-start current)  ;<- HERE
                         #:transferred size
                         #:end (current-time time-monotonic))
               (build-status-downloads-completed status))))))
--8<---------------cut here---------------end--------------->8---

Here, ‘current’ is #f, hence the type error.  We could be defensive and
check whether ‘current’ is #f before proceeding; however, it’s “not
supposed to happen” as that indicates an inconsistency: that ‘status’
doesn’t match reality.

The root cause is probably that (guix status) missed a trace, one of
these “@ download-progress …” lines, which would probably be a bug in
‘build-event-output-port’.  Or it could be that the output from
guix-daemon is already intermingled, though that’s again not supposed to
happen.

Perhaps the best course of action here would be to hammer
‘build-event-output-port’ with semi-randomly generated data until we can
reproduce the bug, assuming this is where it takes place.

Thanks,
Ludo’.