bug#32895: file progress reporter crashes on small files

[Mark H Weaver]

Hi Ricardo,

Ricardo Wurmus <address@hidden> writes:

> Downloading small files (such as cabal revisions) sometimes fails with a
> backtrace like this:
>
> Starting download of 
> /gnu/store/plr3hf9gjdcg2qhi3x4k2wjm8zajqibc-ghc-cryptohash-md5-0.11.100.1-2.cabal
> From 
> https://hackage.haskell.org/package/cryptohash-md5-0.11.100.1/revision/2.cabal...
> downloading from 
> https://hackage.haskell.org/package/cryptohash-md5-0.11.100.1/revision/2.cabal...
> Backtrace:                                                     7.6MiB/s 00:00 
> | 3KiB transferred
> In ice-9/boot-9.scm:
>     829:9 19 (catch _ _ #<procedure 7f8718d34458 at guix/ui.scm:615â¦> â¦)
>     829:9 18 (catch _ _ #<procedure 7f8718d34470 at guix/ui.scm:733â¦> â¦)
> In guix/scripts/build.scm:
>    749:24 17 (_)
> In ice-9/boot-9.scm:
>     829:9 16 (catch _ _ #<procedure 2a53440 at ice-9/boot-9.scm:104â¦> â¦)
> In guix/ui.scm:
>     409:6 15 (_)
> In guix/scripts/build.scm:
>     675:5 14 (_)
> In srfi/srfi-1.scm:
>    679:15 13 (append-map _ _ . _)
>    592:17 12 (map1 (#<package address@hidden gnu/packages/bioinformatâ¦>))
> In guix/scripts/build.scm:
>    680:31 11 (_ _)
> In guix/packages.scm:
>    881:14 10 (cache! #<weak-table 782/883> #<package address@hidden gâ¦> â¦)
> In unknown file:
>            9 (_ #<procedure thunk ()> #<procedure list _> #<undefined>)
> In guix/grafts.scm:
>     303:4  8 (graft-derivation #<build-daemon 256.98 2a54f50> #<derâ¦> â¦)
>     181:4  7 (references-oracle #<build-daemon 256.98 2a54f50> #<derâ¦>)
>    190:20  6 (_ _ _)
> In guix/store.scm:
>   1087:15  5 (_ #<build-daemon 256.98 2a54f50> _ _)
>    661:13  4 (process-stderr _ _)
> In unknown file:
>            3 (display "@ download-progress /gnu/store/plr3hf9gjdcg2â¦" â¦)
> In guix/status.scm:
>    457:13  2 (write! _ _ 186)
>     421:6  1 (_ (download-progress "/gnu/store/plr3hf9gjdcg2qhi3â¦" â¦) â¦)
> In guix/progress.scm:
>    214:25  0 (display-download-progress "2.cabal" #f #:start-time _ # â¦)
>
> guix/progress.scm:214:25: In procedure display-download-progress:
> In procedure /: Wrong type argument in position 1: #f

I'm hitting this same bug repeatedly while trying to build 'idris'.
Previous to this build attempt, I did not have any GHC-related packages
on my system, so this build involves downloading and building many
GHC-related packages.  In this scenario, the bug is quite easy to
trigger.

> This happens because “transferred” in the “else” branch of (@ (guix
> progress) display-download-progress) is #f instead of a number.  This
> could be the result of running string->number on an invalid string in
> “print-build-event”.

Indeed, the string in the 'transferred' slot of the event is actually
"#f".  Here's the entire event, i.e. the first argument passed to
'print-build-event':

(download-progress 
"/gnu/store/k0z5nlg4gi02zx64l49aail3nb8zzi7x-ghc-vector-0.12.0.1-3.cabal" 
"https://hackage.haskell.org/package/vector-0.12.0.1/revision/3.cabal"; "-" "#f")

So far, I've traced it back to the underlying download derivation.  Here
are the contents of the raw build log as found in /var/log/guix/drvs/,
/var/log/guix/drvs/c2/9v4wx8k3gzg2lryyn1v6ki1hc7wcll-ghc-vector-0.12.0.1-3.cabal.drv.bz2:

--8<---------------cut here---------------start------------->8---

Starting download of 
/gnu/store/k0z5nlg4gi02zx64l49aail3nb8zzi7x-ghc-vector-0.12.0.1-3.cabal
>From https://hackage.haskell.org/package/vector-0.12.0.1/revision/3.cabal...
@ download-started 
/gnu/store/k0z5nlg4gi02zx64l49aail3nb8zzi7x-ghc-vector-0.12.0.1-3.cabal 
https://hackage.haskell.org/package/vector-0.12.0.1/revision/3.cabal -
@ download-progress 
/gnu/store/k0z5nlg4gi02zx64l49aail3nb8zzi7x-ghc-vector-0.12.0.1-3.cabal 
https://hackage.haskell.org/package/vector-0.12.0.1/revision/3.cabal - 7073
@ download-progress 
/gnu/store/k0z5nlg4gi02zx64l49aail3nb8zzi7x-ghc-vector-0.12.0.1-3.cabal 
https://hackage.haskell.org/package/vector-0.12.0.1/revision/3.cabal - #f
@ download-succeeded 
/gnu/store/k0z5nlg4gi02zx64l49aail3nb8zzi7x-ghc-vector-0.12.0.1-3.cabal 
https://hackage.haskell.org/package/vector-0.12.0.1/revision/3.cabal 7073

--8<---------------cut here---------------end--------------->8---

Notice that the last field of the final 'download-progress' line is "#f"
instead of a number.

To be continued...

     Mark