Re: guix pull extremely verbose (with no ----verbose)

Re: guix pull extremely verbose (with no ----verbose)

[Ricardo Wurmus]

Hi Giovanni,

I can now also reproduce this on a foreign distro.  This only happens
with “guix pull” (not with “guix package”) and with a newer daemon
(which I didn’t have previously).

When building things “guix pull” prints the full build log interspersed
with tags like “@ build-log 22902 23”.

This is a bug.

--
Ricardo

bug#35877: guix pull extremely verbose (with no ----verbose)

[Giovanni Biscuolo]

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

Ricardo,

Ricardo Wurmus <rekado@elephly.net> writes:

[...]

> This is a bug.

Thanks for reproducing this and for confirming this is a bug, I'll add
my further findings in the bug report (I still do not see it on
debbugs.gnu.org)

🖖 Live long and prosper. Gio'

-- 
Giovanni Biscuolo

Xelera IT Infrastructures

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

bug#35877: [Giovanni Biscuolo] guix pull extremely verbose (with no ----verbose)

[Giovanni Biscuolo]

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

Hello,

I'm forwarding my first findings here, with some details to try to
reproduce this bug


[-- Attachment #2: Type: message/rfc822, Size: 4098 bytes --]

[-- Attachment #2.1.1: Type: text/plain, Size: 2783 bytes --]

Hi Guix!

I've run "guix pull" many many times since today but now after that
command I see a lot of logs like this one:

--8<---------------cut here---------------start------------->8---
@ build-log 9461 44
checking if GSS-API support is requested... @ build-log 9461 4
yes
@ build-log 9461 28
checking gss.h usability... @ build-log 9461 4
yes
@ build-log 9461 27
checking gss.h presence... @ build-log 9461 4
yes
@ build-log 9461 22
checking for gss.h... @ build-log 9461 4
yes
@ build-log 9461 82
checking whether to enable Windows native SSL/TLS (Windows native builds only)... @ build-log 9461 3
no
@ build-log 9461 47
checking whether to enable Secure Transport... @ build-log 9461 63
no
checking whether to enable Amiga native SSL/TLS (AmiSSL)... @ build-log 9461 3
no
@ build-log 9461 27
checking for pkg-config... @ build-log 9461 9
(cached) @ build-log 9461 77
/gnu/store/xyiyf12w4i7zf5g5b4ah0bi1mmd6i8xa-pkg-config-0.29.2/bin/pkg-config
@ build-log 9461 48
checking for openssl options with pkg-config... @ build-log 9461 3
no
@ build-log 9461 40
checking for HMAC_Update in -lcrypto... @ build-log 9461 3
no
@ build-log 9461 41
checking for HMAC_Init_ex in -lcrypto... @ build-log 9461 3
no
@ build-log 9461 38
checking OpenSSL linking with -ldl... @ build-log 9461 3
no
@ build-log 9461 52
checking OpenSSL linking with -ldl and -lpthread... @ build-log 9461 3
no
@ build-log 9461 36
checking for pkg-config... (cached) @ build-log 9461 77
/gnu/store/xyiyf12w4i7zf5g5b4ah0bi1mmd6i8xa-pkg-config-0.29.2/bin/pkg-config
@ build-log 9461 47
checking for gnutls options with pkg-config... @ build-log 9461 6
--8<---------------cut here---------------end--------------->8---

I'm trying from two different machines, one on forein distro and one
with Guix System but the output is the same on both

On the first I am at

--8<---------------cut here---------------start------------->8---
$ guix describe
Generation 2    Jun 21 2019 19:03:33    (current)
  guix 6acf6ce
    repository URL: https://git.savannah.gnu.org/git/guix.git
    branch: master
    commit: 6acf6cec7d74d2e288e275429e8362bfb04b0286
--8<---------------cut here---------------end--------------->8---

while on the second I am at

--8<---------------cut here---------------start------------->8---
$ guix describe
Generation 20   May 12 2019 16:17:24    (current)
  guix 59199e1
    repository URL: https://git.savannah.gnu.org/git/guix.git
    branch: master
    commit: 59199e1adbd5d5f3116a2ca4b580222908f1853e
--8<---------------cut here---------------end--------------->8---

so it does not seem related to guix version

Any hint on what's going on plz?

Thanks! Gio'.

-- 
Giovanni Biscuolo

Xelera IT Infrastructures

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

[-- Attachment #3.1: Type: text/plain, Size: 53 bytes --]

-- 
Giovanni Biscuolo

Xelera IT Infrastructures

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

bug#35877: guix pull extremely verbose (with no ----verbose)

[Ludovic Courtès]

Hi Ricardo,

Ricardo Wurmus <rekado@elephly.net> skribis:

> I can now also reproduce this on a foreign distro.  This only happens
> with “guix pull” (not with “guix package”) and with a newer daemon
> (which I didn’t have previously).
>
> When building things “guix pull” prints the full build log interspersed
> with tags like “@ build-log 22902 23”.

This happens when ‘compute-guix-derivation’ has to build things: it
inherits the client-provided settings such as the “multiplexed build
output” option, but its output goes straight to stderr without any
processing.

The right thing would be to consume its stderr, which might be tricky,
or to just hide it.

Thoughts?

Ludo’.

bug#35877: guix pull extremely verbose (with no ----verbose)

[Giovanni Biscuolo]

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

Hi,

I'm adding some more context in this bug report, adding more info below

Please note that I got the same result (verbosity in guix pull) on a
Guix System machine, other than the foreing distro one I'm adding infos
about

Giovanni Biscuolo <g@xelera.eu> writes:

> Ricardo Wurmus <rekado@elephly.net> writes:
>
>>> I've run "guix pull" many many times since today but now after that
>>> command I see a lot of logs like this one:
>>>
>>> --8<---------------cut here---------------start------------->8---
>>> @ build-log 9461 44
>>> checking if GSS-API support is requested... @ build-log 9461 4
>>> yes
>>> @ build-log 9461 28
>>> checking gss.h usability... @ build-log 9461 4
>>> yes
>> […]
>>
>> Are you using an old daemon?  These are hints that are filtered by the
>> daemon — if it is recent enough.
>
> Is guix-daemon 1.0.0 recent enough?
>
> On the Guix System machine:
>
> --8<---------------cut here---------------start------------->8---
>  ~$ sudo -i guix-daemon --version
> guix-daemon (GNU Guix) 1.0.1-1.8204295
> --8<---------------cut here---------------end--------------->8---
>
> That machine finished "guix pull" in more or less 33 mins, it's a 32
> cores machine with 64GB RAM
>
> After that now "guix pull" does not output debug messages
>
> On the foreign distro machine:
>
> --8<---------------cut here---------------start------------->8---
> $ sudo -i guix-daemon --version
> guix-daemon (GNU Guix) 1.0.0-1.326dcbf
> --8<---------------cut here---------------end--------------->8---
>
> Anyway it was running since Wed 2019-05-15 11:43:04 CEST (1 weeks 1 days
> ago): I restarted and "guix pull"ed again...
>
>
> --8<---------------cut here---------------start------------->8---
> $ time guix pull
> Updating channel 'guix' from Git repository at 'https://git.savannah.gnu.org/git/guix.git'...
> Building from this channel:
>   guix      https://git.savannah.gnu.org/git/guix.git   a9150d4
>
>
> --8<---------------cut here---------------end--------------->8---
>
> and I still get a lot of verbose output... this time I'm going to wait
> until it'll finish (previously I always interrupted it)

OK, that's the result of yesterday's "guix pull" on the above mentioned
machine:

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

[lot of verbose output]

phase `compress-documentation' succeeded after 0.0 seconds
@ build-succeeded /gnu/store/7w7da86j05vzgd9f9m1zgm5mg02fb6jq-guix-daemon-1.0.1-1.8204295.drv -

The following derivations will be built:
   /gnu/store/cxmmywcs4r3rw9qy4h8c0d7w4wbjrfwk-guix-a9150d4c2.drv
   /gnu/store/sl7hfnvx7ss87yyfj3sz1vlx0pjqfzsl-guix-manual.drv
   /gnu/store/nd3b9v3wv8n12s7jb80ijka9l6idx4j5-guix-command.drv
   /gnu/store/mh2wsi58nyd8liw5cimcpkdfdm3ndpp6-guix-a9150d4c2-modules.drv
   /gnu/store/1nqhag5pahaa1iqyf860hg11gc7agqc4-guix-daemon.drv
   /gnu/store/wj1lgyy2dir968d56il2f81zlkf3bx9i-guix-core-modules.drv
   /gnu/store/whi40ivm1hn2hgfcwd6k38pgp1lb0ls1-guix-packages-base-modules.drv
   /gnu/store/w2dvgxjb92fl68dkcxiimyhb67ybkq78-guix-packages-modules.drv

[...]

building /gnu/store/wwpxhba6bn7svy2lhknb28xhxbb72z9w-profile.drv...
1 package in profile

New in this revision:
  46 new packages: acpi-call-linux-module, ataqv, drascula, emacs-ediprolog, emacs-evil-cleverparens, font-hermit, gcc-objc, gcc-objc, gcc-objc, gcc-objc, gcc-objc,
    gcc-objc, …
  134 packages upgraded: bind@9.14.2, btrfs-progs-static@5.1, btrfs-progs@5.1, burp@2.3.6, certbot@0.34.2, cpupower@5.1.4, cqfd@5.1.0, cssc@1.4.1, curl@7.65.0, dune@1.9.3,
    elixir@1.8.2, emacs-desktop-environment@0.2.1, …
hint: Run `guix pull --news' to view the complete list of package changes.


real    106m44.418s
user    3m13.571s
sys     0m6.573s

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

So it was very verbose and it took 106m

AFAIU the verbosity was for building guix-daemon

I'm now "guix pull"ing again and this is the result:

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

$ time guix pull

Updating channel 'guix' from Git repository at 'https://git.savannah.gnu.org/git/guix.git'...
Building from this channel:
  guix      https://git.savannah.gnu.org/git/guix.git   b019965
Computing Guix derivation for 'x86_64-linux'...

[...]

substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
building /gnu/store/vialix3lcspqalwnzrsganvykcwaibfh-guix-packages-base.drv...

[...]

building database for manual pages...
building /gnu/store/496ia45a3xli9qcz0b6gq7j6qxyghczl-profile.drv...
building /gnu/store/pzdahlpy89vz91f3wyis026vdgvpgvam-inferior-script.scm.drv...
building package cache...
building /gnu/store/20gwy7qws1fndbgzyxm7b25zdznsxap2-profile.drv...
1 package in profile

New in this revision:
  1 new package: ioquake3
  9 packages upgraded: flare-engine@1.10, flare-game@1.10, gajim-omemo@2.6.29, notmuch@0.28.4, parallel@20190522, python-notmuch@0.28.4, python2-notmuch@0.28.4, silkaj@0.7.0,
    strace@5.1

real    35m54.178s
user    2m56.553s
sys     0m4.071s

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

it took 35 minutes but no verbose output was split

I did the same on the other (Guix System) machinne and the result was
the same: no verbose output today

AFAIK I'm using the same guix-daemon versions that gave me the verbose
output yesterday

Is it possible that verbose output is given only when building a
guix-daemon derivation like "guix pull" did yesterday?

Thanks! Gio'.

-- 
Giovanni Biscuolo

Xelera IT Infrastructures

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