Guix build output insufficient

Guix build output insufficient

[Pjotr Prins]

On latest

  ./pre-inst guix package -i something

The new color scheme is nice for output. But I miss the old build
logs. How do I get them back? Trying different verbosity levels does
not help.

Also when I got the hash wrong I did not display the new hash value.
And -K does not show the tmp location. E.g.

  ./pre-inst-env guix package -p ~/opt/gdc -i gdc --substitute-urls="https://berlin.guixsd.org  https://mirror.hydra.gnu.org" -K
 (...)

  Build failed: /gnu/store/85salmra99rwz6ifpmswvd9kc5cl69gv-gdc-7a5dbd1.drv - 1 r:sha256 hash mismatch for output path `/gnu/store/wk3sm5krg5srrdivfsjvsz5snd2nqipg-gdc-7a5dbd1'
  expected: 0i0yrcpqrbghq1ddp2zbqq4anl3z5l9fp9b7kblf40642pbdg49d
  actual: 
  -guix package: error: build failed: build of `/gnu/store/wp5wr8f4xnc69amc1g8mfb7ypipx5gz0-gdc-v2.082.0-rc.1.drv' failed

Note both points. Am I doing something wrong?

Pj.

Re: Guix build output insufficient

[Pjotr Prins]

Ah, the --verbose switch helps. Still I think the hash and -K should
be displayed by default.

On Tue, Sep 11, 2018 at 10:26:53AM +0200, Pjotr Prins wrote:
> On latest
> 
>   ./pre-inst guix package -i something
> 
> The new color scheme is nice for output. But I miss the old build
> logs. How do I get them back? Trying different verbosity levels does
> not help.
> 
> Also when I got the hash wrong I did not display the new hash value.
> And -K does not show the tmp location. E.g.
> 
>   ./pre-inst-env guix package -p ~/opt/gdc -i gdc --substitute-urls="https://berlin.guixsd.org  https://mirror.hydra.gnu.org" -K
>  (...)
> 
>   Build failed: /gnu/store/85salmra99rwz6ifpmswvd9kc5cl69gv-gdc-7a5dbd1.drv - 1 r:sha256 hash mismatch for output path `/gnu/store/wk3sm5krg5srrdivfsjvsz5snd2nqipg-gdc-7a5dbd1'
>   expected: 0i0yrcpqrbghq1ddp2zbqq4anl3z5l9fp9b7kblf40642pbdg49d
>   actual: 
>   -guix package: error: build failed: build of `/gnu/store/wp5wr8f4xnc69amc1g8mfb7ypipx5gz0-gdc-v2.082.0-rc.1.drv' failed
> 
> Note both points. Am I doing something wrong?
> 
> Pj.
> 

Re: Guix build output insufficient

[Danny Milosavljevic]

[-- Attachment #1: Type: text/plain, Size: 362 bytes --]

Hi Pjotr,

On Tue, 11 Sep 2018 11:04:25 +0200
Pjotr Prins <pjotr.public12@thebird.nl> wrote:

> Ah, the --verbose switch helps. Still I think the hash and -K should
> be displayed by default.

I agree.

Also, on build failure, it would be nice to print a hint on what to
invoke to get to the failed build log after all (guix-daemon still wrote
it).

[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 488 bytes --]

Re: Guix build output insufficient

[Pierre Neidhardt]

[-- Attachment #1: Type: text/plain, Size: 719 bytes --]


> Also, on build failure, it would be nice to print a hint on what to
> invoke to get to the failed build log after all (guix-daemon still wrote
> it).

Indeed.  Is there such a command?

What about adding a hint, for instance:

 Building /gnu/store/i0kxn9cpkw8ml5472s185kxa6n64kmir-webkitgtk-2.20.5.drv - x86_64-linux
+Saving log at /var/log/guix/i0/kxn9cpkw8ml5472s185kxa6n64kmir-webkitgtk-2.20.5.drv.bz2
 starting phase `set-SOURCE-DATE-EPOCH'

This would be doubly useful:

- It makes it explicit to all users, without having to consult the manual or
some `--help` message.

- With Eshell or M-x shell, we can directly find-file the log at point.

-- 
Pierre Neidhardt
https://ambrevar.xyz/

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 487 bytes --]

Re: Guix build output insufficient

[Ricardo Wurmus]

Hi Pjotr,

> On latest
>
>   ./pre-inst guix package -i something
>
> The new color scheme is nice for output. But I miss the old build
> logs. How do I get them back?

The build logs are stored by the daemon.  You can get their location by
doing

    guix build --log-file something

Note also that “guix build something” still has the same behaviour as
before.  If you want “guix package” to print build logs you need to pass
“--verbose”.

I realize that ’--verbose’ and ’--verbosity=LEVEL’ appear to collide.
We should remove the latter because all it changes is the daemon
verbosity, which isn’t very helpful in most cases.

> Also when I got the hash wrong I did not display the new hash value.
> And -K does not show the tmp location. E.g.
>
>   ./pre-inst-env guix package -p ~/opt/gdc -i gdc --substitute-urls="https://berlin.guixsd.org  https://mirror.hydra.gnu.org" -K
>  (...)
>
>   Build failed: /gnu/store/85salmra99rwz6ifpmswvd9kc5cl69gv-gdc-7a5dbd1.drv - 1 r:sha256 hash mismatch for output path `/gnu/store/wk3sm5krg5srrdivfsjvsz5snd2nqipg-gdc-7a5dbd1'
>   expected: 0i0yrcpqrbghq1ddp2zbqq4anl3z5l9fp9b7kblf40642pbdg49d
>   actual:
>   -guix package: error: build failed: build of `/gnu/store/wp5wr8f4xnc69amc1g8mfb7ypipx5gz0-gdc-v2.082.0-rc.1.drv' failed

Yes, this looks like a bug.  Not sure why this happens.  Thanks for
reporting it.

--
Ricardo

Re: Guix build output insufficient

[Devan Carpenter]

[-- Attachment #1: Type: text/plain, Size: 840 bytes --]

Pierre Neidhardt transcribed 1.3K bytes:
> 
> > Also, on build failure, it would be nice to print a hint on what to
> > invoke to get to the failed build log after all (guix-daemon still wrote
> > it).
> 
> Indeed.  Is there such a command?
> 
> What about adding a hint, for instance:
> 
>  Building /gnu/store/i0kxn9cpkw8ml5472s185kxa6n64kmir-webkitgtk-2.20.5.drv - x86_64-linux
> +Saving log at /var/log/guix/i0/kxn9cpkw8ml5472s185kxa6n64kmir-webkitgtk-2.20.5.drv.bz2
>  starting phase `set-SOURCE-DATE-EPOCH'

I like this idea very much.

> This would be doubly useful:
> 
> - It makes it explicit to all users, without having to consult the manual or
> some `--help` message.
> 
> - With Eshell or M-x shell, we can directly find-file the log at point.
> 
> -- 
> Pierre Neidhardt
> https://ambrevar.xyz/



[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: Guix build output insufficient

[Danny Milosavljevic]

[-- Attachment #1: Type: text/plain, Size: 296 bytes --]

Hi Ricardo,

On Tue, 11 Sep 2018 13:52:16 +0200
Ricardo Wurmus <rekado@elephly.net> wrote:

> The build logs are stored by the daemon.  You can get their location by
> doing
> 
>     guix build --log-file something

Does this also work for failed builds - without rebuilding it again?

[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 488 bytes --]

Re: Guix build output insufficient

[Ricardo Wurmus]

Hi Danny,

> On Tue, 11 Sep 2018 13:52:16 +0200
> Ricardo Wurmus <rekado@elephly.net> wrote:
>
>> The build logs are stored by the daemon.  You can get their location by
>> doing
>> 
>>     guix build --log-file something
>
> Does this also work for failed builds - without rebuilding it again?

It does seem to work.  To test this I added (error "foo") to a build
phase in the “diamond” package and ran

   guix package -i diamond

This ends with

   Build failed:  /gnu/store/wk9qbhmdzs62mp40casrndcgm3p50m3b-diamond-0.9.22.drv
   guix package: error: build failed: build of `/gnu/store/wk9qbhmdzs62mp40casrndcgm3p50m3b-diamond-0.9.22.drv' failed

So I ran

   guix build --log-file /gnu/store/wk9qbhmdzs62mp40casrndcgm3p50m3b-diamond-0.9.22.drv

which gave me

   /var/log/guix/drvs/wk/9qbhmdzs62mp40casrndcgm3p50m3b-diamond-0.9.22.drv.bz2

which contains the build log for this failed build, including the "foo"
error message.

I would like this error log file location to be shown unprompted, but I
think we would need to change build.cc, so that BuildError prints it in
addition to the error message.

(That’s nothing that the build-output-port should try to do on its own,
in my opinion, because it really just transforms output lines.)

-- 
Ricardo

Re: Guix build output insufficient

[Pjotr Prins]

On Wed, Sep 12, 2018 at 08:52:36AM +0200, Ricardo Wurmus wrote:
> It does seem to work.  To test this I added (error "foo") to a build
> phase in the “diamond” package and ran
> 
>    guix package -i diamond
> 
> This ends with
> 
>    Build failed:  /gnu/store/wk9qbhmdzs62mp40casrndcgm3p50m3b-diamond-0.9.22.drv
>    guix package: error: build failed: build of `/gnu/store/wk9qbhmdzs62mp40casrndcgm3p50m3b-diamond-0.9.22.drv' failed
> 
> So I ran
> 
>    guix build --log-file /gnu/store/wk9qbhmdzs62mp40casrndcgm3p50m3b-diamond-0.9.22.drv
> 
> which gave me
> 
>    /var/log/guix/drvs/wk/9qbhmdzs62mp40casrndcgm3p50m3b-diamond-0.9.22.drv.bz2
> 
> which contains the build log for this failed build, including the "foo"
> error message.

Thanks Ricardo! I am still learning stuff. Very useful.

Pj.

Re: Guix build output insufficient

[Ludovic Courtès]

[-- Attachment #1: Type: text/plain, Size: 653 bytes --]

Hello,

Ricardo Wurmus <rekado@elephly.net> skribis:

>> On latest
>>
>>   ./pre-inst guix package -i something
>>
>> The new color scheme is nice for output. But I miss the old build
>> logs. How do I get them back?
>
> The build logs are stored by the daemon.  You can get their location by
> doing
>
>     guix build --log-file something

What about immediately giving the file name of the log, as with the
patch attached?  Several people have already mentioned not knowing about
‘guix build --log-file’ so this would probably be helpful.

Thanks for bringing colors and minimalism to the tools’ output!  :-)

Ludo’.


[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: Type: text/x-patch, Size: 1170 bytes --]

diff --git a/guix/ui.scm b/guix/ui.scm
index 1bbd37c25..98425eaff 100644
--- a/guix/ui.scm
+++ b/guix/ui.scm
@@ -1708,12 +1708,15 @@ phase announcements and replaces any other output with a spinner."
                         (string-append
                          (proc "Building " 'BLUE 'BOLD)
                          (match:substring m 2) "\n")))
-                    ("^(@ build-failed) (.*) (.*)"
+                    ("^(@ build-failed) ([[:graph:]]+*) (.*)"
                      #:transform
                      ,(lambda (m)
-                        (string-append
-                         (proc "Build failed: " 'RED 'BOLD)
-                         (match:substring m 2) "\n")))
+                        (let ((drv (match:substring m 2)))
+                          (string-append
+                           (proc "Build failed: " 'RED 'BOLD)
+                           drv "\n")
+                          (info (G_ "build log available at '~a'~%")
+                                (log-file #f (pk 'drv drv)))))) ;XXX: 1st arg
                     ("^(@ build-succeeded) (.*) (.*)"
                      #:transform
                      ,(lambda (m)

Re: Guix build output insufficient

[Ricardo Wurmus]

Hi,

> What about immediately giving the file name of the log, as with the
> patch attached?  Several people have already mentioned not knowing about
> ‘guix build --log-file’ so this would probably be helpful.

This would be fine.

Note that the patch cannot be applied because I had to change how “@
build-failed” is treated.  The underlying problem here is that the
daemon may send a multi-line message through the port, which
unfortunately doesn’t necessarily arrive in one piece.

AFAICS the only such message is the hash mismatch error.  If we could
force it to remain on one line we could better format that single-line
string in guix/ui.scm.

(Now we get half of the message, followed by another string matching
“^\s+actual:\s+(.*)”, which we cannot process as we do not keep track of
state.)

--
Ricardo

Re: Guix build output insufficient

[Tobias Geerinckx-Rice]

Ricardo Wurmus wrote:
> Hi,
>
>> What about immediately giving the file name of the log, as with 
>> the
>> patch attached?  Several people have already mentioned not 
>> knowing about
>> ‘guix build --log-file’ so this would probably be helpful.
>
> This would be fine.
>
> Note that the patch cannot be applied because I had to change 
> how “@
> build-failed” is treated.  The underlying problem here is that 
> the
> daemon may send a multi-line message through the port, which
> unfortunately doesn’t necessarily arrive in one piece.
>
> AFAICS the only such message is the hash mismatch error.  If we 
> could
> force it to remain on one line we could better format that 
> single-line
> string in guix/ui.scm.
>
> (Now we get half of the message, followed by another string 
> matching
> “^\s+actual:\s+(.*)”, which we cannot process as we do not keep 
> track of
> state.)


-- 
Kind regards,

T G-R

Re: Guix build output insufficient

[Tobias Geerinckx-Rice]

Ricardo,

[And apologies for another empty mail, everyone.]

Ricardo Wurmus wrote:
> Note that the patch cannot be applied because I had to change 
> how “@
> build-failed” is treated.  The underlying problem here is that 
> the
> daemon may send a multi-line message through the port, which
> unfortunately doesn’t necessarily arrive in one piece.
>
> AFAICS the only such message is the hash mismatch error.  If we 
> could
> force it to remain on one line we could better format that 
> single-line
> string in guix/ui.scm.

Didn't we change this from a one-line message relatively recently? 
I vaguely remember supporting such a change (oops... :-)

If so, it wouldn't be the end of the world to revert the change.

Kind regards,

T G-R

Re: Guix build output insufficient

[Ricardo Wurmus]

Hi Tobias,

> Ricardo Wurmus wrote:
>> Note that the patch cannot be applied because I had to change how “@
>> build-failed” is treated.  The underlying problem here is that the
>> daemon may send a multi-line message through the port, which
>> unfortunately doesn’t necessarily arrive in one piece.
>>
>> AFAICS the only such message is the hash mismatch error.  If we
>> could
>> force it to remain on one line we could better format that
>> single-line
>> string in guix/ui.scm.
>
> Didn't we change this from a one-line message relatively recently? I
> vaguely remember supporting such a change (oops... :-)

Yes, it was a change to the formatting of the message.  I also supported
this change because it makes it much easier to see how the hashes
differ.

Now that we apply post-processing to the build output in guix/ui.scm
this early formatting gets in the way.

This happened in the daemon, though, and since people don’t update the
daemon as often as they update the rest of Guix, we may need to
accomodate both formats for a while.  I’d rather wait some more time
until more of wip-ui could be merged.

(The post-processing itself unfortunately has its own downsides: the
Emacs minor mode for build logs can no longer highlight the transformed
“@” messages.)

--
Ricardo

Re: Guix build output insufficient

[Pjotr Prins]

> So I ran
> 
>    guix build --log-file /gnu/store/wk9qbhmdzs62mp40casrndcgm3p50m3b-diamond-0.9.22.drv
> 
> which gave me
> 
>    /var/log/guix/drvs/wk/9qbhmdzs62mp40casrndcgm3p50m3b-diamond-0.9.22.drv.bz2
> 
> which contains the build log for this failed build, including the "foo"
> error message.

Another thing we should capture somewhere is that some build systems
create full log files. For example cmake creates elaborate output in

CMakeFiles/CMakeError.log  
CMakeFiles/CMakeOutput.log

inside the build directory (guix package -i foo -K)

Re: Guix build output insufficient

[Ricardo Wurmus]

Pjotr Prins <pjotr.public12@thebird.nl> writes:

>> So I ran
>>
>>    guix build --log-file /gnu/store/wk9qbhmdzs62mp40casrndcgm3p50m3b-diamond-0.9.22.drv
>>
>> which gave me
>>
>>    /var/log/guix/drvs/wk/9qbhmdzs62mp40casrndcgm3p50m3b-diamond-0.9.22.drv.bz2
>>
>> which contains the build log for this failed build, including the "foo"
>> error message.
>
> Another thing we should capture somewhere is that some build systems
> create full log files. For example cmake creates elaborate output in
>
> CMakeFiles/CMakeError.log
> CMakeFiles/CMakeOutput.log
>
> inside the build directory (guix package -i foo -K)

This is more difficult and I think people should better look at the
build log.  “guix package -i foo -K” is not so common, I think, because
“guix build foo -K” exists for those cases where you want to debug a
build.

“guix package” is primarily user-facing, whereas “guix build” is for
people packaging things.

--
Ricardo