GNU bug report logs - #58375
Installer does not show what is being downloaded

Previous Next

To add a comment to this bug, you must first unarchive it, by sending
a message to control AT debbugs.gnu.org, with unarchive 58375 in the body.
You can then email your comments to 58375 AT debbugs.gnu.org in the normal way.

Toggle the display of automated, internal messages from the tracker.

Message #5 received at submit <at> debbugs.gnu.org (full text, mbox):

From: Julien Lepiller <julien <at> lepiller.eu>
To: bug-guix <at> gnu.org
Subject: Installer does not show what is being downloaded
Date: Sat, 08 Oct 2022 12:34:08 +0200

[Message part 1 (text/plain, inline)]

I installed Guix on a new drive, so I tried the installer from the latest image. After reviewing the system config, the installer goes to a black screen where guix output is shown. Although I can see messages about substitutes being updated, and how much will be downloaded, all download lines are replaced with a seemingly random number of dots:

substitute: mise à jour des substituts depuis «…»... 100.0 %
4.5 Mo seront téléchargés.
.
...
.
.
......

Maybe this is related to the translation?

[Message part 2 (text/html, inline)]

Message #8 received at 58375 <at> debbugs.gnu.org (full text, mbox):

From: Josselin Poiret <dev <at> jpoiret.xyz>
To: Julien Lepiller <julien <at> lepiller.eu>, 58375 <at> debbugs.gnu.org
Subject: Re: bug#58375: Installer does not show what is being downloaded
Date: Sat, 08 Oct 2022 20:09:33 +0200

Hi Julien,

Julien Lepiller <julien <at> lepiller.eu> writes:
> I installed Guix on a new drive, so I tried the installer from the latest image. After reviewing the system config, the installer goes to a black screen where guix output is shown. Although I can see messages about substitutes being updated, and how much will be downloaded, all download lines are replaced with a seemingly random number of dots:
>
> substitute: mise à jour des substituts depuis «…»... 100.0 %
> 4.5 Mo seront téléchargés.
> .
> ...
> .
> .
> ......
>
> Maybe this is related to the translation?

I agree that this does look pretty bad, but this is because we capture
the guix command output to a log file so that we're able to include it
in the installer dump if anything goes wrong.  Guix detects it's not
talking directly to a terminal and so doesn't try to use terminal
specific escape codes to display the download progress.  I don't know
how we could improve on that front though, since in general capturing
the guix command output helps with debugging issues.

Best,
-- 
Josselin Poiret

Message #11 received at 58375 <at> debbugs.gnu.org (full text, mbox):

From: Ludovic Courtès <ludo <at> gnu.org>
To: Josselin Poiret <dev <at> jpoiret.xyz>
Cc: Julien Lepiller <julien <at> lepiller.eu>, 58375 <at> debbugs.gnu.org
Subject: Re: bug#58375: Installer does not show what is being downloaded
Date: Sun, 09 Oct 2022 18:56:35 +0200

Hello!

Josselin Poiret <dev <at> jpoiret.xyz> skribis:

> Julien Lepiller <julien <at> lepiller.eu> writes:
>> I installed Guix on a new drive, so I tried the installer from the latest image. After reviewing the system config, the installer goes to a black screen where guix output is shown. Although I can see messages about substitutes being updated, and how much will be downloaded, all download lines are replaced with a seemingly random number of dots:
>>
>> substitute: mise à jour des substituts depuis «…»... 100.0 %
>> 4.5 Mo seront téléchargés.
>> .
>> ...
>> .
>> .
>> ......
>>
>> Maybe this is related to the translation?
>
> I agree that this does look pretty bad, but this is because we capture
> the guix command output to a log file so that we're able to include it
> in the installer dump if anything goes wrong.  Guix detects it's not
> talking directly to a terminal and so doesn't try to use terminal
> specific escape codes to display the download progress.  I don't know
> how we could improve on that front though, since in general capturing
> the guix command output helps with debugging issues.

This is a duplicate of <https://issues.guix.gnu.org/55360>, marked as
important.

I think capturing all the output as-is is overkill; one option I
suggested in the bug report above is to syslog specific events of
interest during ‘guix system init’.

Thoughts?

Ludo’.

Message #18 received at 58375 <at> debbugs.gnu.org (full text, mbox):

From: Mathieu Othacehe <othacehe <at> gnu.org>
To: Ludovic Courtès <ludo <at> gnu.org>
Cc: Josselin Poiret <dev <at> jpoiret.xyz>, 55360 <at> debbugs.gnu.org,
 58375 <at> debbugs.gnu.org
Subject: Re: bug#58375: Installer does not show what is being downloaded
Date: Thu, 13 Oct 2022 09:04:02 +0200

Hey Ludo!

> I’m not sure it’s a good idea for ‘guix system init’: we’d be logging
> mostly progress bars, package names, and the likes to syslog—not super
> useful.  So I’d suggest not capturing stdout of ‘guix system init’.

In the bug report https://issues.guix.gnu.org/57983 capturing the 'guix
system init' output highlighted a "guix substitute" crash. So it does
seem like a useful mechanism, especially while 56005 is still open.

Now the current situation is also not really acceptable. What about
hiding the "guix system init" output completely and display a progress
bar page instead?

Thanks,

Mathieu

Message #21 received at 58375 <at> debbugs.gnu.org (full text, mbox):

From: Ludovic Courtès <ludo <at> gnu.org>
To: Mathieu Othacehe <othacehe <at> gnu.org>
Cc: Josselin Poiret <dev <at> jpoiret.xyz>, 55360 <at> debbugs.gnu.org,
 58375 <at> debbugs.gnu.org
Subject: Re: bug#58375: Installer does not show what is being downloaded
Date: Thu, 13 Oct 2022 15:21:53 +0200

Hi!

Mathieu Othacehe <othacehe <at> gnu.org> skribis:

>> I’m not sure it’s a good idea for ‘guix system init’: we’d be logging
>> mostly progress bars, package names, and the likes to syslog—not super
>> useful.  So I’d suggest not capturing stdout of ‘guix system init’.
>
> In the bug report https://issues.guix.gnu.org/57983 capturing the 'guix
> system init' output highlighted a "guix substitute" crash. So it does
> seem like a useful mechanism, especially while 56005 is still open.

Hmm right.  <https://issues.guix.gnu.org/56005> is not
installer-specific, so it’s annoying that we have to prepare for that,
but we can’t deny such bugs exist and prevent installation.

If we really want to capture the output of ‘guix system init’, then we
need to open a pseudo-terminal with ‘openpty’ & co. instead of ‘pipe’ in
‘run-external-command-with-handler’.  That may be relatively easy
actually.

But then I think this should be used sparsely, maybe only for ‘guix
system init’.

> Now the current situation is also not really acceptable.

Nope.  :-)

> What about hiding the "guix system init" output completely and display
> a progress bar page instead?

I don’t think we can do that (with grafts, only part of the build plan
is known upfront so we don’t even know beforehand how many items will be
built/downloaded).

Also, I think there are two strategies: either we run ‘guix system
init’, in which case we let its output through, or we integrate ‘guix
system init’ functionality in the installer so we have more fine-grain
control over the process, in which case we could also have more
graphical output or something.

That second solution is a lot of work, though.

Thanks,
Ludo’.

Message #24 received at 58375 <at> debbugs.gnu.org (full text, mbox):

From: Mathieu Othacehe <othacehe <at> gnu.org>
To: Ludovic Courtès <ludo <at> gnu.org>
Cc: Josselin Poiret <dev <at> jpoiret.xyz>, 55360 <at> debbugs.gnu.org,
 58375 <at> debbugs.gnu.org
Subject: Re: bug#58375: Installer does not show what is being downloaded
Date: Fri, 14 Oct 2022 17:44:24 +0200

[Message part 1 (text/plain, inline)]

Hey,

> If we really want to capture the output of ‘guix system init’, then we
> need to open a pseudo-terminal with ‘openpty’ & co. instead of ‘pipe’ in
> ‘run-external-command-with-handler’.  That may be relatively easy
> actually.

So I implemented your proposal. It seems to be working quite well. As
discussed on #guix, we could avoid to dump the download bars to the
syslog if the "guix system init" command succeeds. However, it seems
quite tricky in the current implementation where the syslog dumping is
actually a hook (%syslog-line-hook).

Fixing this issue, I also realized that when the "guix system init"
command fails, the user is only offered to resume the installation or
restart it.

In cases where "guix system init" failed because of a network issue, or
because a partition was too small, restarting/resuming seems like the
right thing to do.

However, when the installer failed because "guix system init" crashed or
segfaulted, restarting/resuming won't probably help, and dumping the
crash is probably the best way to get help. That's why I added in a
second patch, a new button "Report the failure" to the
"run-install-failed-page".

Thanks,

Mathieu

[0001-installer-Run-the-guix-system-init-command-in-a-PTY.patch (text/x-patch, inline)]

From c6286404e9c4c0dc302c3d398a8f27b050cf4ce0 Mon Sep 17 00:00:00 2001
From: Mathieu Othacehe <othacehe <at> gnu.org>
Date: Fri, 14 Oct 2022 17:28:27 +0200
Subject: [PATCH 1/2] installer: Run the "guix system init" command in a PTY.

Fixes: <https://issues.guix.gnu.org/55360>

* gnu/installer/utils.scm (run-external-command-with-handler/tty): New
procedure.
(run-external-command-with-line-hooks, run-command): Add a TTY? argument.
* gnu/installer/final.scm (install-system): Call run-command with TTY?
argument set to #true.
---
 gnu/installer/final.scm |  2 +-
 gnu/installer/utils.scm | 50 +++++++++++++++++++++++++++++++++--------
 2 files changed, 42 insertions(+), 10 deletions(-)

diff --git a/gnu/installer/final.scm b/gnu/installer/final.scm
index 3f6dacc490..044f79372b 100644
--- a/gnu/installer/final.scm
+++ b/gnu/installer/final.scm
@@ -211,7 +211,7 @@ (define (assert-exit x)
 
              (setenv "PATH" "/run/current-system/profile/bin/")
 
-             (set! ret (run-command install-command)))
+             (set! ret (run-command install-command #:tty? #t)))
            (lambda ()
              ;; Restart guix-daemon so that it does no keep the MNT namespace
              ;; alive.
diff --git a/gnu/installer/utils.scm b/gnu/installer/utils.scm
index 5fd2e2d425..061493e6a7 100644
--- a/gnu/installer/utils.scm
+++ b/gnu/installer/utils.scm
@@ -20,6 +20,7 @@
 (define-module (gnu installer utils)
   #:use-module (gnu services herd)
   #:use-module (guix utils)
+  #:use-module ((guix build syscalls) #:select (openpty login-tty))
   #:use-module (guix build utils)
   #:use-module (guix i18n)
   #:use-module (srfi srfi-1)
@@ -45,6 +46,7 @@ (define-module (gnu installer utils)
             nearest-exact-integer
             read-percentage
             run-external-command-with-handler
+            run-external-command-with-handler/tty
             run-external-command-with-line-hooks
             run-command
             run-command-in-installer
@@ -124,10 +126,37 @@ (define dummy-pipe
     (close-port input)
     (close-pipe dummy-pipe)))
 
-(define (run-external-command-with-line-hooks line-hooks command)
+(define (run-external-command-with-handler/tty handler command)
+  "Run command specified by the list COMMAND in a child operating in a
+pseudoterminal with output handler HANDLER.  HANDLER is a procedure taking an
+input port, to which the command will write its standard output and error.
+Returns the integer status value of the child process as returned by waitpid."
+  (define-values (controller inferior)
+    (openpty))
+
+  (match (primitive-fork)
+    (0
+     (catch #t
+       (lambda ()
+         (close-fdes controller)
+         (login-tty inferior)
+         (apply execlp (car command) command))
+       (lambda _
+         (primitive-exit 127))))
+    (pid
+     (close-fdes inferior)
+     (let* ((port (fdopen controller "r0"))
+            (result (false-if-exception
+                     (handler port))))
+       (close-port port)
+       (cdr (waitpid pid))))))
+
+(define* (run-external-command-with-line-hooks line-hooks command
+                                               #:key (tty? #false))
   "Run command specified by the list COMMAND in a child, processing each
-output line with the procedures in LINE-HOOKS.  Returns the integer status
-value of the child process as returned by waitpid."
+output line with the procedures in LINE-HOOKS.  If TTY is set to #true, the
+COMMAND will be run in a pseudoterminal.  Returns the integer status value of
+the child process as returned by waitpid."
   (define (handler input)
     (and
      (and=> (get-line input)
@@ -136,14 +165,17 @@ (define (handler input)
                   #f
                   (begin (for-each (lambda (f) (f line))
                                    (append line-hooks
-                                       %default-installer-line-hooks))
+                                           %default-installer-line-hooks))
                          #t))))
      (handler input)))
-  (run-external-command-with-handler handler command))
+  (if tty?
+      (run-external-command-with-handler/tty handler command)
+      (run-external-command-with-handler handler command)))
 
-(define* (run-command command)
+(define* (run-command command #:key (tty? #f))
   "Run COMMAND, a list of strings.  Return true if COMMAND exited
-successfully, #f otherwise."
+successfully, #f otherwise.  If TTY is set to #true, the COMMAND will be run
+in a pseudoterminal."
   (define (pause)
     (format #t (G_ "Press Enter to continue.~%"))
     (send-to-clients '(pause))
@@ -154,8 +186,8 @@ (define (pause)
 
   (installer-log-line "running command ~s" command)
   (define result (run-external-command-with-line-hooks
-                  (list %display-line-hook)
-                  command))
+                  (list %display-line-hook) command
+                  #:tty? tty?))
   (define exit-val (status:exit-val result))
   (define term-sig (status:term-sig result))
   (define stop-sig (status:stop-sig result))
-- 
2.37.3

[0002-installer-Propose-the-user-to-report-a-guix-system-i.patch (text/x-patch, inline)]

From 159b82a013cad8c3c698031cce9ee07956153da3 Mon Sep 17 00:00:00 2001
From: Mathieu Othacehe <othacehe <at> gnu.org>
Date: Fri, 14 Oct 2022 17:33:28 +0200
Subject: [PATCH 2/2] installer: Propose the user to report a "guix system
 init" failure.

* gnu/installer/newt/final.scm (run-install-failed-page): Add a "Report the
failure" button.
---
 gnu/installer/newt/final.scm | 9 +++++++--
 1 file changed, 7 insertions(+), 2 deletions(-)

diff --git a/gnu/installer/newt/final.scm b/gnu/installer/newt/final.scm
index 7c3f73ee82..6e55be5067 100644
--- a/gnu/installer/newt/final.scm
+++ b/gnu/installer/newt/final.scm
@@ -80,16 +80,21 @@ (define (run-install-success-page)
 (define (run-install-failed-page)
   (match (current-clients)
     (()
-     (match (choice-window
+     (match (ternary-window
              (G_ "Installation failed")
              (G_ "Resume")
              (G_ "Restart the installer")
+             (G_ "Report the failure")
              (G_ "The final system installation step failed.  You can resume from \
 a specific step, or restart the installer."))
        (1 (abort-to-prompt 'installer-step 'abort))
        (2
         ;; Keep going, the installer will be restarted later on.
-        #t)))
+        #t)
+       (3 (raise
+           (condition
+            (&message
+             (message "User abort.")))))))
     (_
      (send-to-clients '(installation-failure))
      #t)))
-- 
2.37.3

Message #27 received at 58375 <at> debbugs.gnu.org (full text, mbox):

From: Ludovic Courtès <ludo <at> gnu.org>
To: Mathieu Othacehe <othacehe <at> gnu.org>
Cc: Josselin Poiret <dev <at> jpoiret.xyz>, 55360 <at> debbugs.gnu.org,
 58375 <at> debbugs.gnu.org
Subject: Re: bug#58375: Installer does not show what is being downloaded
Date: Tue, 18 Oct 2022 17:17:47 +0200

Hi Mathieu,

Mathieu Othacehe <othacehe <at> gnu.org> skribis:

> So I implemented your proposal. It seems to be working quite well. As
> discussed on #guix, we could avoid to dump the download bars to the
> syslog if the "guix system init" command succeeds. However, it seems
> quite tricky in the current implementation where the syslog dumping is
> actually a hook (%syslog-line-hook).

Yes.

I haven’t actually tested the patch but it LGTM.  One thing to check is
whether ‘terminal-window-size’ returns something sensible for the
pseudo-terminal; it could be that we need an extra ioctl so the
pseudo-terminal has the same size as the actual terminal.

> Fixing this issue, I also realized that when the "guix system init"
> command fails, the user is only offered to resume the installation or
> restart it.
>
> In cases where "guix system init" failed because of a network issue, or
> because a partition was too small, restarting/resuming seems like the
> right thing to do.
>
> However, when the installer failed because "guix system init" crashed or
> segfaulted, restarting/resuming won't probably help, and dumping the
> crash is probably the best way to get help. That's why I added in a
> second patch, a new button "Report the failure" to the
> "run-install-failed-page".

Neat!

> From c6286404e9c4c0dc302c3d398a8f27b050cf4ce0 Mon Sep 17 00:00:00 2001
> From: Mathieu Othacehe <othacehe <at> gnu.org>
> Date: Fri, 14 Oct 2022 17:28:27 +0200
> Subject: [PATCH 1/2] installer: Run the "guix system init" command in a PTY.
>
> Fixes: <https://issues.guix.gnu.org/55360>
>
> * gnu/installer/utils.scm (run-external-command-with-handler/tty): New
> procedure.
> (run-external-command-with-line-hooks, run-command): Add a TTY? argument.
> * gnu/installer/final.scm (install-system): Call run-command with TTY?
> argument set to #true.

LGTM, modulo the terminal size issue mentioned above.

> From 159b82a013cad8c3c698031cce9ee07956153da3 Mon Sep 17 00:00:00 2001
> From: Mathieu Othacehe <othacehe <at> gnu.org>
> Date: Fri, 14 Oct 2022 17:33:28 +0200
> Subject: [PATCH 2/2] installer: Propose the user to report a "guix system
>  init" failure.
>
> * gnu/installer/newt/final.scm (run-install-failed-page): Add a "Report the
> failure" button.

LGTM.

Thank you!

Ludo’.

Message #30 received at 58375-done <at> debbugs.gnu.org (full text, mbox):

From: Mathieu Othacehe <othacehe <at> gnu.org>
To: Ludovic Courtès <ludo <at> gnu.org>
Cc: Josselin Poiret <dev <at> jpoiret.xyz>, 55360-done <at> debbugs.gnu.org,
 58375-done <at> debbugs.gnu.org
Subject: Re: bug#58375: Installer does not show what is being downloaded
Date: Thu, 20 Oct 2022 16:40:08 +0200

Hey,

Thanks for having a look!

> I haven’t actually tested the patch but it LGTM.  One thing to check is
> whether ‘terminal-window-size’ returns something sensible for the
> pseudo-terminal; it could be that we need an extra ioctl so the
> pseudo-terminal has the same size as the actual terminal.

Well it returns 0 for all fields, but I tested on several screen sizes
and everything seems fine so I went ahead.

While testing I noticed two new issues though:

1. When the disk is GPT partitionned there is no confirmation page in
  "run-label-page". Something I missed in #57232.

2. When there is an exception in run-external-command-with-handler/tty
    for instance, the backtrace page is displayed in the PTY and the
    keyboard shortcuts do not work anymore.

I'll address point 1 shortly but could use some advice for point 2.

Thanks,

Mathieu

Previous Next

GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.