unofficial mirror of bug-guix@gnu.org 
 help / color / mirror / code / Atom feed
* bug#32895: file progress reporter crashes on small files
@ 2018-10-01 14:16 Ricardo Wurmus
  2018-10-02 12:34 ` Ludovic Courtès
  2018-10-04  9:58 ` Mark H Weaver
  0 siblings, 2 replies; 10+ messages in thread
From: Ricardo Wurmus @ 2018-10-01 14:16 UTC (permalink / raw)
  To: 32895

Downloading small files (such as cabal revisions) sometimes fails with a
backtrace like this:

--8<---------------cut here---------------start------------->8---
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 ngless@0.9.1 gnu/packages/bioinformatâ¦>))
In guix/scripts/build.scm:
   680:31 11 (_ _)
In guix/packages.scm:
   881:14 10 (cache! #<weak-table 782/883> #<package ngless@0.9.1 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
--8<---------------cut here---------------end--------------->8---

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”.


--
Ricardo

^ permalink raw reply	[flat|nested] 10+ messages in thread

* bug#32895: file progress reporter crashes on small files
  2018-10-01 14:16 bug#32895: file progress reporter crashes on small files Ricardo Wurmus
@ 2018-10-02 12:34 ` Ludovic Courtès
  2018-10-02 14:27   ` Ricardo Wurmus
  2018-10-04  9:58 ` Mark H Weaver
  1 sibling, 1 reply; 10+ messages in thread
From: Ludovic Courtès @ 2018-10-02 12:34 UTC (permalink / raw)
  To: Ricardo Wurmus; +Cc: 32895

Hello,

Ricardo Wurmus <ricardo.wurmus@mdc-berlin.de> skribis:

> guix/progress.scm:214:25: In procedure display-download-progress:
> In procedure /: Wrong type argument in position 1: #f
>
> 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, that seems to be the case.  This would mean we’re emitting an
incorrect build trace.

Do you have the exact command to reproduce it?

Thanks,
Ludo’.

^ permalink raw reply	[flat|nested] 10+ messages in thread

* bug#32895: file progress reporter crashes on small files
  2018-10-02 12:34 ` Ludovic Courtès
@ 2018-10-02 14:27   ` Ricardo Wurmus
  2018-10-03 21:08     ` Ludovic Courtès
  0 siblings, 1 reply; 10+ messages in thread
From: Ricardo Wurmus @ 2018-10-02 14:27 UTC (permalink / raw)
  To: Ludovic Courtès; +Cc: 32895


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

> Hello,
>
> Ricardo Wurmus <ricardo.wurmus@mdc-berlin.de> skribis:
>
>> guix/progress.scm:214:25: In procedure display-download-progress:
>> In procedure /: Wrong type argument in position 1: #f
>>
>> 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, that seems to be the case.  This would mean we’re emitting an
> incorrect build trace.
>
> Do you have the exact command to reproduce it?

Unfortunately, I don’t.  It’s hard to reproduce this when all these
cabal revisions have already been downloaded.  This also depends a lot
on the actual download speed.

I only got this for cabal revisions, so locally building any of the
ghc-* packages with #:cabal-revision arguments might be sufficient to
trigger the bug.

--
Ricardo

^ permalink raw reply	[flat|nested] 10+ messages in thread

* bug#32895: file progress reporter crashes on small files
  2018-10-02 14:27   ` Ricardo Wurmus
@ 2018-10-03 21:08     ` Ludovic Courtès
  2018-10-04  8:31       ` Ludovic Courtès
  0 siblings, 1 reply; 10+ messages in thread
From: Ludovic Courtès @ 2018-10-03 21:08 UTC (permalink / raw)
  To: Ricardo Wurmus; +Cc: 32895

Hello,

Ricardo Wurmus <ricardo.wurmus@mdc-berlin.de> skribis:

> Ludovic Courtès <ludo@gnu.org> writes:
>
>> Hello,
>>
>> Ricardo Wurmus <ricardo.wurmus@mdc-berlin.de> skribis:
>>
>>> guix/progress.scm:214:25: In procedure display-download-progress:
>>> In procedure /: Wrong type argument in position 1: #f
>>>
>>> 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, that seems to be the case.  This would mean we’re emitting an
>> incorrect build trace.
>>
>> Do you have the exact command to reproduce it?
>
> Unfortunately, I don’t.

Or do you have the log around?  If you run, say:

  grep -r "download-progress .*#f" /var/log/guix/drvs

?

Looking at the code, I think only ‘progress-reporter/trace’ emits those
traces and only through calls to ‘dump-port*’, and I don’t see where
this #f could come from.

TIA,
Ludo’.

^ permalink raw reply	[flat|nested] 10+ messages in thread

* bug#32895: file progress reporter crashes on small files
  2018-10-03 21:08     ` Ludovic Courtès
@ 2018-10-04  8:31       ` Ludovic Courtès
  0 siblings, 0 replies; 10+ messages in thread
From: Ludovic Courtès @ 2018-10-04  8:31 UTC (permalink / raw)
  To: Ricardo Wurmus; +Cc: 32895-done

Hi,

ludo@gnu.org (Ludovic Courtès) skribis:

> Ricardo Wurmus <ricardo.wurmus@mdc-berlin.de> skribis:
>
>> Ludovic Courtès <ludo@gnu.org> writes:
>>
>>> Hello,
>>>
>>> Ricardo Wurmus <ricardo.wurmus@mdc-berlin.de> skribis:
>>>
>>>> guix/progress.scm:214:25: In procedure display-download-progress:
>>>> In procedure /: Wrong type argument in position 1: #f
>>>>
>>>> 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, that seems to be the case.  This would mean we’re emitting an
>>> incorrect build trace.
>>>
>>> Do you have the exact command to reproduce it?
>>
>> Unfortunately, I don’t.
>
> Or do you have the log around?  If you run, say:
>
>   grep -r "download-progress .*#f" /var/log/guix/drvs
>
> ?

Turns out I stumbled upon this bug by change.  The traces I was getting
were:

--8<---------------cut here---------------start------------->8---
@ download-progress /gnu/store/2chkmisij4373sb8sf07by0zkcikl4ki-opencv-extra-3.4.3.zip https://codeload.github.com/opencv/opencv_extra/zip/3.4.3 - 472383488
@ download-progress /gnu/store/2chkmisij4373sb8sf07by0zkcikl4ki-opencv-extra-3.4.3.zip https://codeload.github.com/opencv/opencv_extra/zip/3.4.3 - 478478336
@ download-progress /gnu/store/2chkmisij4373sb8sf07by0zkcikl4ki-opencv-extra-3.4.3.zip https://codeload.github.com/opencv/opencv_extra/zip/3.4.3 - 484704256
@ download-progress /gnu/store/2chkmisij4373sb8sf07by0zkcikl4ki-opencv-extra-3.4.3.zip https://codeload.github.com/opencv/opencv_extra/zip/3.4.3 - #f
@ download-succeeded /gnu/store/2chkmisij4373sb8sf07by0zkcikl4ki-opencv-extra-3.4.3.zip https://codeload.github.com/opencv/opencv_extra/zip/3.4.3 487641438
--8<---------------cut here---------------end--------------->8---

The next-to-last one was incorrect.

This is fixed in 1d0be47ab680db938ac8da1ee65e1de91e198f67.  I’ll push an
update of the ‘guix’ package so we get an updated daemon with the fix
(for the “builtin:download” derivations.)

Thanks,
Ludo’.

^ permalink raw reply	[flat|nested] 10+ messages in thread

* bug#32895: file progress reporter crashes on small files
  2018-10-01 14:16 bug#32895: file progress reporter crashes on small files Ricardo Wurmus
  2018-10-02 12:34 ` Ludovic Courtès
@ 2018-10-04  9:58 ` Mark H Weaver
  2018-10-04 23:19   ` Mark H Weaver
  2018-10-04 23:28   ` Mark H Weaver
  1 sibling, 2 replies; 10+ messages in thread
From: Mark H Weaver @ 2018-10-04  9:58 UTC (permalink / raw)
  To: Ricardo Wurmus; +Cc: 32895

Hi Ricardo,

Ricardo Wurmus <ricardo.wurmus@mdc-berlin.de> 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 ngless@0.9.1 gnu/packages/bioinformatâ¦>))
> In guix/scripts/build.scm:
>    680:31 11 (_ _)
> In guix/packages.scm:
>    881:14 10 (cache! #<weak-table 782/883> #<package ngless@0.9.1 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

^ permalink raw reply	[flat|nested] 10+ messages in thread

* bug#32895: file progress reporter crashes on small files
  2018-10-04  9:58 ` Mark H Weaver
@ 2018-10-04 23:19   ` Mark H Weaver
  2018-10-04 23:28   ` Mark H Weaver
  1 sibling, 0 replies; 10+ messages in thread
From: Mark H Weaver @ 2018-10-04 23:19 UTC (permalink / raw)
  To: Ricardo Wurmus; +Cc: 32895

And now I'm running into the same bug repeatedly while trying to test
build security updates for IceCat, which involve downloading a great
many small patches from Mozilla.

Bah.  Something is very broken here, and now it's interfering with my
attempts to deploy critical security updates.  I'm thinking it might be
time to start reverting some of the recent commits that seem related to
this.

       Mark

^ permalink raw reply	[flat|nested] 10+ messages in thread

* bug#32895: file progress reporter crashes on small files
  2018-10-04  9:58 ` Mark H Weaver
  2018-10-04 23:19   ` Mark H Weaver
@ 2018-10-04 23:28   ` Mark H Weaver
  2018-10-04 23:35     ` Mark H Weaver
  1 sibling, 1 reply; 10+ messages in thread
From: Mark H Weaver @ 2018-10-04 23:28 UTC (permalink / raw)
  To: Ricardo Wurmus; +Cc: 32895

I've applied the following temporary workaround to my private branch, to
enable me to work on the IceCat security update.

       Mark


--8<---------------cut here---------------start------------->8---
diff --git a/guix/status.scm b/guix/status.scm
index c6956066f..8c6045a7d 100644
--- a/guix/status.scm
+++ b/guix/status.scm
@@ -359,10 +359,11 @@ addition to build events."
           (let ((uri (if (string-contains uri "/nar/")
                          (nar-uri-abbreviation uri)
                          (basename uri))))
-            (display-download-progress uri size
-                                       #:start-time
-                                       (download-start download)
-                                       #:transferred transferred))))))
+            (when transferred  ; FIXME XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX
+              (display-download-progress uri size
+                                         #:start-time
+                                         (download-start download)
+                                         #:transferred transferred)))))))
     (('substituter-succeeded item _ ...)
      ;; If there are no jobs running, we already reported download completion
      ;; so there's nothing left to do.
--8<---------------cut here---------------end--------------->8---

^ permalink raw reply related	[flat|nested] 10+ messages in thread

* bug#32895: file progress reporter crashes on small files
  2018-10-04 23:28   ` Mark H Weaver
@ 2018-10-04 23:35     ` Mark H Weaver
  2018-10-08 12:23       ` Ludovic Courtès
  0 siblings, 1 reply; 10+ messages in thread
From: Mark H Weaver @ 2018-10-04 23:35 UTC (permalink / raw)
  To: Ricardo Wurmus; +Cc: 32895

I see now that this bug was already fixed while I sent several new
messages about it.  Oops.  I should really make sure I've fetched email
before responding.  Sorry for the noise.

      Mark

^ permalink raw reply	[flat|nested] 10+ messages in thread

* bug#32895: file progress reporter crashes on small files
  2018-10-04 23:35     ` Mark H Weaver
@ 2018-10-08 12:23       ` Ludovic Courtès
  0 siblings, 0 replies; 10+ messages in thread
From: Ludovic Courtès @ 2018-10-08 12:23 UTC (permalink / raw)
  To: Mark H Weaver; +Cc: Ricardo Wurmus, 32895

Mark H Weaver <mhw@netris.org> skribis:

> I see now that this bug was already fixed while I sent several new
> messages about it.  Oops.  I should really make sure I've fetched email
> before responding.  Sorry for the noise.

No problem, sorry for messing with this in the first place.

Ludo’.

^ permalink raw reply	[flat|nested] 10+ messages in thread

end of thread, other threads:[~2018-10-08 12:24 UTC | newest]

Thread overview: 10+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2018-10-01 14:16 bug#32895: file progress reporter crashes on small files Ricardo Wurmus
2018-10-02 12:34 ` Ludovic Courtès
2018-10-02 14:27   ` Ricardo Wurmus
2018-10-03 21:08     ` Ludovic Courtès
2018-10-04  8:31       ` Ludovic Courtès
2018-10-04  9:58 ` Mark H Weaver
2018-10-04 23:19   ` Mark H Weaver
2018-10-04 23:28   ` Mark H Weaver
2018-10-04 23:35     ` Mark H Weaver
2018-10-08 12:23       ` Ludovic Courtès

Code repositories for project(s) associated with this public inbox

	https://git.savannah.gnu.org/cgit/guix.git

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).