invoke (guix build utils) error reporting lacking

  • Done
  • quality assurance status badge
Details
2 participants
  • Maxim Cournoyer
  • Mark H Weaver
Owner
unassigned
Submitted by
Maxim Cournoyer
Severity
normal
M
M
Maxim Cournoyer wrote on 4 Jul 2018 14:50
(name . bug-guix)(address . bug-guix@gnu.org)
87fu0zkvv9.fsf@apteryx.i-did-not-set--mail-host-address--so-tickle-me
The error reported by `invoke' isn't accurate, and mutes important
output from the program invoked.

Example of a failed tar extraction:
Toggle snippet (4 lines)
/gnu/store/xlj36j9dw581iah51iyjgi75iikrj55h-module-import/guix/build/utils.scm:616:6: In procedure invoke:
Throw to key `srfi-34' with args `(#<condition &invoke-error [program: "tar" arguments: ("xf" "/gnu/store/yanfzfi7rdyf5scf5h65xbkn7xg0nnbn-docbook-dsssl-doc-1.79.tar.bz2" "--strip-components=1" "-C" "/gnu/store/rw7yzjk1wffza65z6l6rnn25qg97jvh1-docbook-dsssl-doc-1.79" "docbook-dssl-1.79/doc") exit-status: 127 term-signal: #f stop-signal: #f] 68fc80>)'.

While reproducing the same error in an containerized environment,
calling the command directly yields:

Toggle snippet (7 lines)
tar xf yanfzfi7rdyf5scf5h65xbkn7xg0nnbn-docbook-dsssl-doc-1.79.tar.bz2 --strip-components=1 -C $PWD docbook-dssl-1.79/doc
tar: docbook-dssl-1.79/doc: Not found in archive
tar: Exiting with failure status due to previous errors
maxim@apteryx /tmp/docbook-dsssl-doc [env]# echo $?
2

Two observations:

1. invoke's reported exit status was wrong (127 rather than 2)
2. The useful error message "docbook-dssl-1.79/doc: Not found in
archive" was masked.
M
M
Maxim Cournoyer wrote on 4 Jul 2018 15:12
(address . 32050@debbugs.gnu.org)
878t6rkuuf.fsf_-_@gmail.com
More problematic even, it seems "invoke" can't do everything that
"system*" can?

For example, the following package builds fine:

Toggle snippet (34 lines)
(define-public docbook-dsssl-doc
(package
(name "docbook-dsssl-doc")
(version "1.79")
(source (origin
(method url-fetch)
(uri (string-append "mirror://sourceforge/docbook/"
name "/" version "/"
name "-" version ".tar.bz2"))
(sha256
(base32
"1plp5ngc96pbna4rwglp9glcadnirbm3hlcjb4gjvq1f8biic9lz"))))
(build-system trivial-build-system)
(arguments
`(#:modules ((guix build utils))
#:builder
(begin
(use-modules (guix build utils))
(let ((source (assoc-ref %build-inputs "source"))
(out (assoc-ref %outputs "out")))
(mkdir-p out)
;; Extract the "doc" subdirectory.
(system* "tar" "xf" source "--strip-components=1"
"--no-same-owner" "-C" out
(string-append "docbook-dsssl-" ,version "/doc"))))))
(native-inputs
`(("bzip2", bzip2)
("tar" ,tar)))
(home-page "https://docbook.org/")
(synopsis "DocBook DSSSL style sheets documentation")
(description "Documentation for the DocBook DSSSL style sheets.")
(license non-copyleft)))

,run-in-store (build-package docbook-dsssl-doc #:use-substitutes? #t #:dry-run? #f)
/gnu/store/ljr8xn3qbr3lahr29zc0lbki9x33zls6-docbook-dsssl-doc-1.79
$4 = #t

But changing just "system*" to "invoke", I get:

Toggle snippet (16 lines)
@ build-remote /gnu/store/fdcg5nazw2jvpb7k4mq7q0750gq22zh7-docbook-dsssl-doc-1.79.drv 192.168.1.105
Backtrace:
2 (primitive-load "/gnu/store/06zszks9mwp52gih8j0mj5bahfi?")
In ice-9/eval.scm:
191:35 1 (_ #f)
In /gnu/store/xlj36j9dw581iah51iyjgi75iikrj55h-module-import/guix/build/utils.scm:
616:6 0 (invoke _ . _)

/gnu/store/xlj36j9dw581iah51iyjgi75iikrj55h-module-import/guix/build/utils.scm:616:6: In procedure invoke:
Throw to key `srfi-34' with args `(#<condition &invoke-error [program: "tar" arguments: ("xf" "/gnu/store/yanfzfi7rdyf5scf5h65xbkn7xg0nnbn-docbook-dsssl-doc-1.79.tar.bz2" "--strip-components=1" "--no-same-owner" "-C" "/gnu/store/83yjsgvvapffhklg8md5cqa6gmb2dmqg-docbook-dsssl-doc-1.79" "docbook-dsssl-1.79/doc") exit-status: 127 term-signal: #f stop-signal: #f] 68fcc0>)'.
builder for `/gnu/store/fdcg5nazw2jvpb7k4mq7q0750gq22zh7-docbook-dsssl-doc-1.79.drv' failed with exit code 1
derivation '/gnu/store/fdcg5nazw2jvpb7k4mq7q0750gq22zh7-docbook-dsssl-doc-1.79.drv' offloaded to '192.168.1.105' failed: build of `/gnu/store/fdcg5nazw2jvpb7k4mq7q0750gq22zh7-docbook-dsssl-doc-1.79.drv' failed
While executing meta-command:
Throw to key `srfi-34' with args `(#<condition &nix-protocol-error [message: "build of `/gnu/store/fdcg5nazw2jvpb7k4mq7q0750gq22zh7-docbook-dsssl-doc-1.79.drv' failed" status: 100] a7228a0>)'.

Thanks,

Maxim
M
M
Mark H Weaver wrote on 4 Jul 2018 19:45
(name . Maxim Cournoyer)(address . maxim.cournoyer@gmail.com)(address . 32050@debbugs.gnu.org)
87efginbcz.fsf@netris.org
Hi Maxim,

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

Toggle quote (43 lines)
> More problematic even, it seems "invoke" can't do everything that
> "system*" can?
>
> For example, the following package builds fine:
>
> (define-public docbook-dsssl-doc
> (package
> (name "docbook-dsssl-doc")
> (version "1.79")
> (source (origin
> (method url-fetch)
> (uri (string-append "mirror://sourceforge/docbook/"
> name "/" version "/"
> name "-" version ".tar.bz2"))
> (sha256
> (base32
> "1plp5ngc96pbna4rwglp9glcadnirbm3hlcjb4gjvq1f8biic9lz"))))
> (build-system trivial-build-system)
> (arguments
> `(#:modules ((guix build utils))
> #:builder
> (begin
> (use-modules (guix build utils))
> (let ((source (assoc-ref %build-inputs "source"))
> (out (assoc-ref %outputs "out")))
> (mkdir-p out)
> ;; Extract the "doc" subdirectory.
> (system* "tar" "xf" source "--strip-components=1"
> "--no-same-owner" "-C" out
> (string-append "docbook-dsssl-" ,version "/doc"))))))
> (native-inputs
> `(("bzip2", bzip2)
> ("tar" ,tar)))
> (home-page "https://docbook.org/")
> (synopsis "DocBook DSSSL style sheets documentation")
> (description "Documentation for the DocBook DSSSL style sheets.")
> (license non-copyleft)))
>
>
> ,run-in-store (build-package docbook-dsssl-doc #:use-substitutes? #t #:dry-run? #f)
> /gnu/store/ljr8xn3qbr3lahr29zc0lbki9x33zls6-docbook-dsssl-doc-1.79
> $4 = #t

Did you check to see if the extraction actually succeeded?

In this case, I don't see how it could have. When using 'tar' from
within 'trivial-build-system', you need to add 'bzip2' to PATH, or else
'tar' will fail because it can't find 'bzip2'. There are many examples
of setting PATH in (gnu packages fonts).

Because of the way you are using 'system*' here without the usual
'zero?' wrapped around it, the numeric result code is returned as the
result of the builder, and all numbers (even 0) are considered true in
Scheme. So, this build will always succeed, ignoring errors from 'tar'.

Toggle quote (17 lines)
> But changing just "system*" to "invoke", I get:
>
> @ build-remote /gnu/store/fdcg5nazw2jvpb7k4mq7q0750gq22zh7-docbook-dsssl-doc-1.79.drv 192.168.1.105
> Backtrace:
> 2 (primitive-load "/gnu/store/06zszks9mwp52gih8j0mj5bahfi?")
> In ice-9/eval.scm:
> 191:35 1 (_ #f)
> In /gnu/store/xlj36j9dw581iah51iyjgi75iikrj55h-module-import/guix/build/utils.scm:
> 616:6 0 (invoke _ . _)
>
> /gnu/store/xlj36j9dw581iah51iyjgi75iikrj55h-module-import/guix/build/utils.scm:616:6: In procedure invoke:
> Throw to key `srfi-34' with args `(#<condition &invoke-error [program: "tar" arguments: ("xf" "/gnu/store/yanfzfi7rdyf5scf5h65xbkn7xg0nnbn-docbook-dsssl-doc-1.79.tar.bz2" "--strip-components=1" "--no-same-owner" "-C" "/gnu/store/83yjsgvvapffhklg8md5cqa6gmb2dmqg-docbook-dsssl-doc-1.79" "docbook-dsssl-1.79/doc") exit-status: 127 term-signal: #f stop-signal: #f] 68fcc0>)'.
> builder for `/gnu/store/fdcg5nazw2jvpb7k4mq7q0750gq22zh7-docbook-dsssl-doc-1.79.drv' failed with exit code 1
> derivation '/gnu/store/fdcg5nazw2jvpb7k4mq7q0750gq22zh7-docbook-dsssl-doc-1.79.drv' offloaded to '192.168.1.105' failed: build of `/gnu/store/fdcg5nazw2jvpb7k4mq7q0750gq22zh7-docbook-dsssl-doc-1.79.drv' failed
> While executing meta-command:
> Throw to key `srfi-34' with args `(#<condition &nix-protocol-error [message: "build of `/gnu/store/fdcg5nazw2jvpb7k4mq7q0750gq22zh7-docbook-dsssl-doc-1.79.drv' failed" status: 100] a7228a0>)'.

Changing 'system*' to 'invoke' allowed you to see that something went
wrong.

Toggle quote (24 lines)
> The error reported by `invoke' isn't accurate, and mutes important
> output from the program invoked.
>
> Example of a failed tar extraction:
>
> /gnu/store/xlj36j9dw581iah51iyjgi75iikrj55h-module-import/guix/build/utils.scm:616:6: In procedure invoke:
> Throw to key `srfi-34' with args `(#<condition &invoke-error [program: "tar" arguments: ("xf" "/gnu/store/yanfzfi7rdyf5scf5h65xbkn7xg0nnbn-docbook-dsssl-doc-1.79.tar.bz2" "--strip-components=1" "-C" "/gnu/store/rw7yzjk1wffza65z6l6rnn25qg97jvh1-docbook-dsssl-doc-1.79" "docbook-dssl-1.79/doc") exit-status: 127 term-signal: #f stop-signal: #f] 68fc80>)'.
>
>
> While reproducing the same error in an containerized environment,
> calling the command directly yields:
>
> tar xf yanfzfi7rdyf5scf5h65xbkn7xg0nnbn-docbook-dsssl-doc-1.79.tar.bz2 --strip-components=1 -C $PWD docbook-dssl-1.79/doc
> tar: docbook-dssl-1.79/doc: Not found in archive
> tar: Exiting with failure status due to previous errors
> maxim@apteryx /tmp/docbook-dsssl-doc [env]# echo $?
> 2
>
> Two observations:
>
> 1. invoke's reported exit status was wrong (127 rather than 2)
> 2. The useful error message "docbook-dssl-1.79/doc: Not found in
> archive" was masked.

I think what happened is that 'tar' actually failed in two different
ways. In the first case, where the result code was 127, it failed
because 'bzip2' was not found in PATH. In the second case, it failed
because "docbook-dssl-1.79/doc" was not found in the archive.

Or at least that's my guess.

Regards,
Mark
M
M
Maxim Cournoyer wrote on 8 Jul 2018 17:59
(name . Mark H Weaver)(address . mhw@netris.org)(address . 32050@debbugs.gnu.org)
87h8l9k9b6.fsf@gmail.com
Hi Mark,

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

[...]

Toggle quote (7 lines)
> Did you check to see if the extraction actually succeeded?
>
> In this case, I don't see how it could have. When using 'tar' from
> within 'trivial-build-system', you need to add 'bzip2' to PATH, or else
> 'tar' will fail because it can't find 'bzip2'. There are many examples
> of setting PATH in (gnu packages fonts).

OK. I now understand that the trivial-build-system does exactly nothing
for us, so it doesn't even sets the "PATH" environment variable. This
wasn't obvious to me, thank for pointing it out!

Toggle quote (3 lines)
> Changing 'system*' to 'invoke' allowed you to see that something went
> wrong.

Right, my confusion stemmed from the unset PATH variable; tar itself
would return exit code 127 (command not found) in the
trivial-build-system, but I couldn't reproduce directly in a
containerized guix environment because there is a profile generation
hook there which does set the PATH.

Toggle quote (14 lines)
>> The error reported by `invoke' isn't accurate, and mutes important
>> output from the program invoked.
>>
>> Example of a failed tar extraction:
>>
>> /gnu/store/xlj36j9dw581iah51iyjgi75iikrj55h-module-import/guix/build/utils.scm:616:6: In procedure invoke:
>> Throw to key `srfi-34' with args `(#<condition &invoke-error
>> [program: "tar" arguments: ("xf"
>> "/gnu/store/yanfzfi7rdyf5scf5h65xbkn7xg0nnbn-docbook-dsssl-doc-1.79.tar.bz2"
>> "--strip-components=1" "-C"
>> "/gnu/store/rw7yzjk1wffza65z6l6rnn25qg97jvh1-docbook-dsssl-doc-1.79"
>> "docbook-dssl-1.79/doc") exit-status: 127 term-signal: #f
>> stop-signal: #f] 68fc80>)'.

It seems that the "system" and "system*" commands of Guile as well as
our "invoke" do preserve the stdout/stderr, as when testing it manually
I can see the useful "sh: tar: command not found" message:

Toggle snippet (12 lines)
scheme@(guile-user)> ,use (guix build utils)
scheme@(guile-user)> (system "tar xf yanfzfi7rdyf5scf5h65xbkn7xg0nnbn-docbook-dsssl-doc-1.79.tar.bz2")
sh: tar: command not found
$1 = 32512
scheme@(guile-user)> (invoke "tar" "xf" "yanfzfi7rdyf5scf5h65xbkn7xg0nnbn-docbook-dsssl-doc-1.79.tar.bz2")
In execvp of tar: No such file or directory
guix/build/utils.scm:616:6: In procedure invoke:
Throw to key `srfi-34' with args `(#<condition &invoke-error [program: "tar" arguments: ("xf" "yanfzfi7rdyf5scf5h65xbkn7xg0nnbn-docbook-dsssl-doc-1.79.tar.bz2") exit-status: 127 term-signal: #f stop-signal: #f] 1e3dc40>)'.

Entering a new prompt. Type `,bt' for a backtrace or `,q' to continue.

Unfortunately, when called from the builder side of Guix, this
information seems to be lost:

Toggle snippet (18 lines)
./pre-inst-env guix build --no-build-hook --check docbook-dsssl-doc
@ build-started /gnu/store/4ra70nwni8mcjyd2wfx7fqvsl4fpfs5m-docbook-dsssl-doc-1.79.drv - x86_64-linux /var/log/guix/drvs/4r//a70nwni8mcjyd2wfx7fqvsl4fpfs5m-docbook-dsssl-doc-1.79.drv.bz2
Backtrace:
2 (primitive-load "/gnu/store/kj0nr8i617gjwypalfs065jllhm?")
In ice-9/eval.scm:
191:35 1 (_ #f)
In /gnu/store/xlj36j9dw581iah51iyjgi75iikrj55h-module-import/guix/build/utils.scm:
616:6 0 (invoke _ . _)

/gnu/store/xlj36j9dw581iah51iyjgi75iikrj55h-module-import/guix/build/utils.scm:616:6: In procedure invoke:
Throw to key `srfi-34' with args `(#<condition &invoke-error [program: "tar" arguments: ("-xf" "/gnu/store/yanfzfi7rdyf5scf5h65xbkn7xg0nnbn-docbook-dsssl-doc-1.79.tar.bz2" "--strip-components=1" "--no-same-owner" "-C" "/gnu/store/ppf9bhzyqphmc9cvwhq8pc3yfir2qd3m-docbook-dsssl-doc-1.79" "docbook-dsssl-1.79/doc") exit-status: 127 term-signal: #f stop-signal: #f] 68fcc0>)'.
builder for `/gnu/store/4ra70nwni8mcjyd2wfx7fqvsl4fpfs5m-docbook-dsssl-doc-1.79.drv' failed with exit code 1
@ build-failed /gnu/store/4ra70nwni8mcjyd2wfx7fqvsl4fpfs5m-docbook-dsssl-doc-1.79.drv - 1 builder for `/gnu/store/4ra70nwni8mcjyd2wfx7fqvsl4fpfs5m-docbook-dsssl-doc-1.79.drv' failed with exit code 1
guix build: error: build failed: build of
`/gnu/store/4ra70nwni8mcjyd2wfx7fqvsl4fpfs5m-docbook-dsssl-doc-1.79.drv'
failed

Could it be preserved? It'd be very useful when debugging :)

Maxim
M
M
Maxim Cournoyer wrote on 10 Jul 2018 04:42
(name . Mark H Weaver)(address . mhw@netris.org)(address . 32050@debbugs.gnu.org)
87wou3izgf.fsf@gmail.com
Maxim Cournoyer <maxim.cournoyer@gmail.com> writes:

[...]

Toggle quote (38 lines)
> It seems that the "system" and "system*" commands of Guile as well as
> our "invoke" do preserve the stdout/stderr, as when testing it manually
> I can see the useful "sh: tar: command not found" message:
>
> scheme@(guile-user)> ,use (guix build utils)
> scheme@(guile-user)> (system "tar xf yanfzfi7rdyf5scf5h65xbkn7xg0nnbn-docbook-dsssl-doc-1.79.tar.bz2")
> sh: tar: command not found
> $1 = 32512
> scheme@(guile-user)> (invoke "tar" "xf" "yanfzfi7rdyf5scf5h65xbkn7xg0nnbn-docbook-dsssl-doc-1.79.tar.bz2")
> In execvp of tar: No such file or directory
> guix/build/utils.scm:616:6: In procedure invoke:
> Throw to key `srfi-34' with args `(#<condition &invoke-error [program: "tar" arguments: ("xf" "yanfzfi7rdyf5scf5h65xbkn7xg0nnbn-docbook-dsssl-doc-1.79.tar.bz2") exit-status: 127 term-signal: #f stop-signal: #f] 1e3dc40>)'.
>
> Entering a new prompt. Type `,bt' for a backtrace or `,q' to continue.
>
>
> Unfortunately, when called from the builder side of Guix, this
> information seems to be lost:
>
> ./pre-inst-env guix build --no-build-hook --check docbook-dsssl-doc
> @ build-started /gnu/store/4ra70nwni8mcjyd2wfx7fqvsl4fpfs5m-docbook-dsssl-doc-1.79.drv - x86_64-linux /var/log/guix/drvs/4r//a70nwni8mcjyd2wfx7fqvsl4fpfs5m-docbook-dsssl-doc-1.79.drv.bz2
> Backtrace:
> 2 (primitive-load "/gnu/store/kj0nr8i617gjwypalfs065jllhm?")
> In ice-9/eval.scm:
> 191:35 1 (_ #f)
> In /gnu/store/xlj36j9dw581iah51iyjgi75iikrj55h-module-import/guix/build/utils.scm:
> 616:6 0 (invoke _ . _)
>
> /gnu/store/xlj36j9dw581iah51iyjgi75iikrj55h-module-import/guix/build/utils.scm:616:6: In procedure invoke:
> Throw to key `srfi-34' with args `(#<condition &invoke-error [program: "tar" arguments: ("-xf" "/gnu/store/yanfzfi7rdyf5scf5h65xbkn7xg0nnbn-docbook-dsssl-doc-1.79.tar.bz2" "--strip-components=1" "--no-same-owner" "-C" "/gnu/store/ppf9bhzyqphmc9cvwhq8pc3yfir2qd3m-docbook-dsssl-doc-1.79" "docbook-dsssl-1.79/doc") exit-status: 127 term-signal: #f stop-signal: #f] 68fcc0>)'.
> builder for `/gnu/store/4ra70nwni8mcjyd2wfx7fqvsl4fpfs5m-docbook-dsssl-doc-1.79.drv' failed with exit code 1
> @ build-failed /gnu/store/4ra70nwni8mcjyd2wfx7fqvsl4fpfs5m-docbook-dsssl-doc-1.79.drv - 1 builder for `/gnu/store/4ra70nwni8mcjyd2wfx7fqvsl4fpfs5m-docbook-dsssl-doc-1.79.drv' failed with exit code 1
> guix build: error: build failed: build of
> `/gnu/store/4ra70nwni8mcjyd2wfx7fqvsl4fpfs5m-docbook-dsssl-doc-1.79.drv'
> failed
>
> Could it be preserved? It'd be very useful when debugging :)

I've investigated a bit, and as far as I can see by reading guix
sources, the build log output would be displayed and any error reported
by the `process-stderr' procedure in (guix store). This procedure
behavior seems to depend closely on that of the guix daemon (server), so
the problem could lie on the daemon side as well, so that's where I'll
try digging next.

Maxim
M
M
Maxim Cournoyer wrote on 28 May 2020 06:42
(name . Mark H Weaver)(address . mhw@netris.org)(address . 32050-done@debbugs.gnu.org)
87h7w0656z.fsf@gmail.com
Hello,

I think my original observations must have occured in Emacs while using
Geiser. It has to do with what (current-output-port) is bound to in the

I'm closing, as I haven't seen this issue in almost 2 years when using
Guix from the command line.

Maxim
Closed
?