bug#41668: Failing test: gui-installed-desktop-os-encrypted

bug#41668: Failing test: gui-installed-desktop-os-encrypted

[Brice Waegeneire]

Hello Guix,

For some time now the system test 'gui-installed-desktop-os-encrypted'
doesn't succeed, the last time it passed was 2020-04-11[0]. This is
problematic since it exercise a lot of packages and thus can be used to
test those packages. Ludovic attempted to fixed it[1] but it didn't 
fixed
the test on my side.

[0]: 
http://ci.guix.gnu.org/search?query=gui-installed-desktop-os-encrypted+system%3Ax86_64-linux+spec%3Aguix-master+status%3Asuccess
[1]: https://issues.guix.info/40790#7

- Brice

bug#41668: Failing test: gui-installed-desktop-os-encrypted

[Mathieu Othacehe]

Hello Brice,

> For some time now the system test 'gui-installed-desktop-os-encrypted'
> doesn't succeed, the last time it passed was 2020-04-11[0]. This is
> problematic since it exercise a lot of packages and thus can be used to
> test those packages. Ludovic attempted to fixed it[1] but it didn't fixed
> the test on my side.

The "gui-installed-*" tests are in a bad shape right now. The good news
is that the can reveal many issues, the bad news is that I can't keep
the distance fixing them.

They are affected by:

* Shepherd race condition: https://issues.guix.gnu.org/40981. But this
should be fixed with the recent 0.8.1 release.

* The cow-store issue here:
https://lists.gnu.org/archive/html/guix-devel/2020-06/msg00043.html.

* A new issue I discovered, whereby 'guix system init' try to
build/download stuff, when it shouldn't:

--8<---------------cut here---------------start------------->8---
Jun  6 11:50:06 localhost shepherd[1]: Service cow-store has been started. 
Jun  6 11:50:06 localhost installer[233]: running command ("guix" "system" "init" "--fallback" "--no-grafts" "--no-substitutes" "/mnt/etc/config.scm" "/mnt") 
Jun  6 11:50:20 localhost installer[233]: 'guix system init --fallback --no-grafts --no-substitutes /mnt/etc/config.scm /mnt' exited with status 1; output follows:    The following derivations will be bu)

Jun  6 11:50:20 localhost 7-gzip-mesboot-1.2.4.drv      /gnu/store/zrqjn3p0x5gkdnj6qb4b9xxl2dld4fvl-gzip-1.2.4.tar.drv      /gnu/store/98g8d622pqhzl0z92y4bjcqi9yl0327x-linux-libre-headers-bootstrap-0.drv2
Jun  6 11:50:20 localhost g76sla-bash-mesboot-4.4.drv      /gnu/store/8yad2zhh91pnf27xkwh0kyx4ggnsn5li-bash-4.4.tar.gz.drv      /gnu/store/5vp07s0gdvrybbhcz43i58y5p03rrdsk-coreutils-mesboot-8.32.drv     k
Jun  6 11:50:20 localhost h6mfp7hisj118ndcp8d0wy3ca63-gmp-6.0.0a.tar.xz.drv      /gnu/store/iy7vn17sqbrgp2142px897ij0njsr5f2-gmp-6.0.0a.tar.xz.drv      /gnu/store/rxr1wc67y74bsfasln4jw8viawpa79g4-mpfr-4.0
Jun  6 11:50:20 localhost ilding /gnu/store/3pz8g76l2kkv36w1n7k25zlswgdyj554-Python-3.5.9.tar.xz.drv...   builder for `/gnu/store/3pz8g76l2kkv36w1n7k25zlswgdyj554-Python-3.5.9.tar.xz.drv' failed to produg
Jun  6 11:50:20 localhost  
--8<---------------cut here---------------end--------------->8---

Thanks,

Mathieu

  

bug#41668: Failing test: gui-installed-desktop-os-encrypted

[Mathieu Othacehe]

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


Hey,

> * A new issue I discovered, whereby 'guix system init' try to
> build/download stuff, when it shouldn't:
>
> Jun  6 11:50:06 localhost shepherd[1]: Service cow-store has been started. 
> Jun  6 11:50:06 localhost installer[233]: running command ("guix" "system" "init" "--fallback" "--no-grafts" "--no-substitutes" "/mnt/etc/config.scm" "/mnt") 
> Jun  6 11:50:20 localhost installer[233]: 'guix system init --fallback --no-grafts --no-substitutes /mnt/etc/config.scm /mnt' exited with status 1; output follows:    The following derivations will be bu)
>
> Jun  6 11:50:20 localhost 7-gzip-mesboot-1.2.4.drv      /gnu/store/zrqjn3p0x5gkdnj6qb4b9xxl2dld4fvl-gzip-1.2.4.tar.drv      /gnu/store/98g8d622pqhzl0z92y4bjcqi9yl0327x-linux-libre-headers-bootstrap-0.drv2
> Jun  6 11:50:20 localhost g76sla-bash-mesboot-4.4.drv      /gnu/store/8yad2zhh91pnf27xkwh0kyx4ggnsn5li-bash-4.4.tar.gz.drv      /gnu/store/5vp07s0gdvrybbhcz43i58y5p03rrdsk-coreutils-mesboot-8.32.drv     k
> Jun  6 11:50:20 localhost h6mfp7hisj118ndcp8d0wy3ca63-gmp-6.0.0a.tar.xz.drv      /gnu/store/iy7vn17sqbrgp2142px897ij0njsr5f2-gmp-6.0.0a.tar.xz.drv      /gnu/store/rxr1wc67y74bsfasln4jw8viawpa79g4-mpfr-4.0
> Jun  6 11:50:20 localhost ilding /gnu/store/3pz8g76l2kkv36w1n7k25zlswgdyj554-Python-3.5.9.tar.xz.drv...   builder for `/gnu/store/3pz8g76l2kkv36w1n7k25zlswgdyj554-Python-3.5.9.tar.xz.drv' failed to produg
> Jun  6 11:50:20 localhost  

Ok, I think I found what's going on here. As we are now using multiple
glibc to build locales, we need to make sure that they are all available
in the installation closure.

The attached patch fixes the issue. I will also propose a patch,
probably on core-update, patching "invoke/quiet" so that we can have the
output of "guix system init" in the syslog.

Debugging (gnu tests install) module always takes me a lot of effort,
because of all the code layers involved. I don't have much to propose to
improve it, maybe when the CI will be more robust, we will be able to
detect those test failures as soon as they happen.

Now, the cow-store issue!

Thanks,

Mathieu

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: 0001-system-install-Add-default-libcs-to-gc-roots.patch --]
[-- Type: text/x-diff, Size: 1913 bytes --]

From 25950adfa4988c31beaeb334367337ee409868c4 Mon Sep 17 00:00:00 2001
From: Mathieu Othacehe <othacehe@gnu.org>
Date: Sun, 7 Jun 2020 15:39:39 +0200
Subject: [PATCH] system: install: Add default libcs to gc-roots.

During the installation, it may be needed to build locales that are not
covered by glibc-utf8-locales. Make sure that the libraries required to build
locales are available.

This is a follow-up of 0eed77127592323d89f56c215a15374a1aaae110.

* gnu/system/install.scm (installation-os)[services]: Add
%default-locale-libcs to gc-root-service-type.
---
 gnu/system/install.scm | 11 +++++++----
 1 file changed, 7 insertions(+), 4 deletions(-)

diff --git a/gnu/system/install.scm b/gnu/system/install.scm
index fe49ffdb94..d0ff2e7c52 100644
--- a/gnu/system/install.scm
+++ b/gnu/system/install.scm
@@ -32,6 +32,7 @@
   #:use-module ((guix packages) #:select (package-version))
   #:use-module ((guix store) #:select (%store-prefix))
   #:use-module (gnu installer)
+  #:use-module (gnu system locale)
   #:use-module (gnu services dbus)
   #:use-module (gnu services networking)
   #:use-module (gnu services shepherd)
@@ -439,10 +440,12 @@ Access documentation at any time by pressing Alt-F2.\x1b[0m
           ;; things needed by 'profile-derivation' to minimize the amount of
           ;; download.
           (service gc-root-service-type
-                   (list bare-bones-os
-                         glibc-utf8-locales
-                         texinfo
-                         guile-3.0))
+                   (append
+                    (list bare-bones-os
+                          glibc-utf8-locales
+                          texinfo
+                          guile-3.0)
+                    %default-locale-libcs))
 
           ;; Machines without Kernel Mode Setting (those with many old and
           ;; current AMD GPUs, SiS GPUs, ...) need uvesafb to show the GUI
-- 
2.26.2

bug#41668: Failing test: gui-installed-desktop-os-encrypted

[Ludovic Courtès]

Hi,

Mathieu Othacehe <othacehe@gnu.org> skribis:

>> * A new issue I discovered, whereby 'guix system init' try to
>> build/download stuff, when it shouldn't:
>>
>> Jun  6 11:50:06 localhost shepherd[1]: Service cow-store has been started. 
>> Jun  6 11:50:06 localhost installer[233]: running command ("guix" "system" "init" "--fallback" "--no-grafts" "--no-substitutes" "/mnt/etc/config.scm" "/mnt") 
>> Jun  6 11:50:20 localhost installer[233]: 'guix system init --fallback --no-grafts --no-substitutes /mnt/etc/config.scm /mnt' exited with status 1; output follows:    The following derivations will be bu)
>>
>> Jun  6 11:50:20 localhost 7-gzip-mesboot-1.2.4.drv      /gnu/store/zrqjn3p0x5gkdnj6qb4b9xxl2dld4fvl-gzip-1.2.4.tar.drv      /gnu/store/98g8d622pqhzl0z92y4bjcqi9yl0327x-linux-libre-headers-bootstrap-0.drv2
>> Jun  6 11:50:20 localhost g76sla-bash-mesboot-4.4.drv      /gnu/store/8yad2zhh91pnf27xkwh0kyx4ggnsn5li-bash-4.4.tar.gz.drv      /gnu/store/5vp07s0gdvrybbhcz43i58y5p03rrdsk-coreutils-mesboot-8.32.drv     k
>> Jun  6 11:50:20 localhost h6mfp7hisj118ndcp8d0wy3ca63-gmp-6.0.0a.tar.xz.drv      /gnu/store/iy7vn17sqbrgp2142px897ij0njsr5f2-gmp-6.0.0a.tar.xz.drv      /gnu/store/rxr1wc67y74bsfasln4jw8viawpa79g4-mpfr-4.0
>> Jun  6 11:50:20 localhost ilding /gnu/store/3pz8g76l2kkv36w1n7k25zlswgdyj554-Python-3.5.9.tar.xz.drv...   builder for `/gnu/store/3pz8g76l2kkv36w1n7k25zlswgdyj554-Python-3.5.9.tar.xz.drv' failed to produg
>> Jun  6 11:50:20 localhost  
>
> Ok, I think I found what's going on here. As we are now using multiple
> glibc to build locales, we need to make sure that they are all available
> in the installation closure.

Good catch!

> The attached patch fixes the issue. I will also propose a patch,
> probably on core-update, patching "invoke/quiet" so that we can have the
> output of "guix system init" in the syslog.

How did you do it in the example above?  Perhaps we can have a local
hack specifically in the installer (otherwise we’d find ourselves
duplicating syslog-related logic there.)

> Debugging (gnu tests install) module always takes me a lot of effort,
> because of all the code layers involved. I don't have much to propose to
> improve it, maybe when the CI will be more robust, we will be able to
> detect those test failures as soon as they happen.

Yeah there are two issues: (1) the installer tests are tricky to debug,
and (2) we basically don’t notice when something break.

I don’t have good ideas for (1), although I think the speedups induced
by the new image API might help.

As for (2), I think it’s kind of a problem of CI in general, connected
with the fact that we’re all somewhat busy building stuff rather than
waiting for CI notifications to act on.  :-)

That’s my impression, but I’d really like to hear from people with
experience in CI and/or the system tests.

> From 25950adfa4988c31beaeb334367337ee409868c4 Mon Sep 17 00:00:00 2001
> From: Mathieu Othacehe <othacehe@gnu.org>
> Date: Sun, 7 Jun 2020 15:39:39 +0200
> Subject: [PATCH] system: install: Add default libcs to gc-roots.
>
> During the installation, it may be needed to build locales that are not
> covered by glibc-utf8-locales. Make sure that the libraries required to build
> locales are available.
>
> This is a follow-up of 0eed77127592323d89f56c215a15374a1aaae110.
>
> * gnu/system/install.scm (installation-os)[services]: Add
> %default-locale-libcs to gc-root-service-type.

Perfect, thanks!

Ludo’.

bug#41668: Failing test: gui-installed-desktop-os-encrypted

[Mathieu Othacehe]

Hey Ludo,

> How did you do it in the example above?  Perhaps we can have a local
> hack specifically in the installer (otherwise we’d find ourselves
> duplicating syslog-related logic there.)

I used a custom re-implementation of "invoke/quiet" printing every line
on the syslog port. Maybe, we could enable such a mechanism only during
the tests.

> I don’t have good ideas for (1), although I think the speedups induced
> by the new image API might help.

Yes, that's for sure making the debug more comfortable!

> As for (2), I think it’s kind of a problem of CI in general, connected
> with the fact that we’re all somewhat busy building stuff rather than
> waiting for CI notifications to act on.  :-)
>
> That’s my impression, but I’d really like to hear from people with
> experience in CI and/or the system tests.

Totally agree. When submitting patches to Linux for instance, the CI is
able to reply to the patch mail, and warn about any failures. An other
difference is that patches are often kept in the maintainer 'staging'
branches until the CI is over.

I don't know if Guix is a big enough project to appoint some maintainers
that would periodically merge their branches to 'master' or if it would
just be a huge burden. Something we need to discuss in the future maybe.

> Perfect, thanks!

Anyway, thanks for your fast review :)

Mathieu

bug#41668: Failing test: gui-installed-desktop-os-encrypted

[Mathieu Othacehe]

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


Hey,

Turns out using "invoke/quiet" is not really convenient because it
stores all the command output, which can be pretty big, in memory.

Instead I did reimplement the command in (gnu installer utils) in the
attached patch :).

Thanks,

Mathieu

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: 0001-installer-utils-Dump-command-output-to-syslog-when-t.patch --]
[-- Type: text/x-diff, Size: 7779 bytes --]

From 7c1a03b03d5e62876a88d87aff36776c8ce4ddf2 Mon Sep 17 00:00:00 2001
From: Mathieu Othacehe <othacehe@gnu.org>
Date: Mon, 8 Jun 2020 15:14:49 +0200
Subject: [PATCH] installer: utils: Dump command output to syslog when testing.

When debugging the installation tests, it can be very handy to be able to read
"run-command" output, for instance when executing "guix system init".

Introduce a new "invoke-with-log" procedure that is able to log a command
standard and error outputs to the syslog. Use it, only when running the
installation tests, to dump "run-command" output.

* gnu/installer/utils.scm (open-pipe-with-stderr, invoke-with-log): New
procedures,
(invoke-log-port): new variable,
(run-command): move to the end of the file and use invoke-with-log when
running the installation tests.
---
 gnu/installer/utils.scm | 166 +++++++++++++++++++++++++++++-----------
 1 file changed, 122 insertions(+), 44 deletions(-)

diff --git a/gnu/installer/utils.scm b/gnu/installer/utils.scm
index 5f8fe8ca01..b9d88e46d9 100644
--- a/gnu/installer/utils.scm
+++ b/gnu/installer/utils.scm
@@ -22,8 +22,13 @@
   #:use-module (guix build utils)
   #:use-module (guix i18n)
   #:use-module (srfi srfi-1)
+  #:use-module (srfi srfi-11)
+  #:use-module (srfi srfi-26)
   #:use-module (srfi srfi-34)
+  #:use-module (srfi srfi-34)
+  #:use-module (srfi srfi-35)
   #:use-module (ice-9 match)
+  #:use-module (ice-9 popen)
   #:use-module (ice-9 rdelim)
   #:use-module (ice-9 regex)
   #:use-module (ice-9 format)
@@ -68,50 +73,6 @@ number. If no percentage is found, return #f"
     (and result
          (string->number (match:substring result 1)))))
 
-(define* (run-command command #:key locale)
-  "Run COMMAND, a list of strings, in the given LOCALE.  Return true if
-COMMAND exited successfully, #f otherwise."
-  (define env (environ))
-
-  (define (pause)
-    (format #t (G_ "Press Enter to continue.~%"))
-    (send-to-clients '(pause))
-    (environ env)                               ;restore environment variables
-    (match (select (cons (current-input-port) (current-clients))
-             '() '())
-      (((port _ ...) _ _)
-       (read-line port))))
-
-  (setenv "PATH" "/run/current-system/profile/bin")
-
-  (when locale
-    (let ((supported? (false-if-exception
-                       (setlocale LC_ALL locale))))
-      ;; If LOCALE is not supported, then set LANGUAGE, which might at
-      ;; least give us translated messages.
-      (if supported?
-          (setenv "LC_ALL" locale)
-          (setenv "LANGUAGE"
-                  (string-take locale
-                               (or (string-index locale #\_)
-                                   (string-length locale)))))))
-
-  (guard (c ((invoke-error? c)
-             (newline)
-             (format (current-error-port)
-                     (G_ "Command failed with exit code ~a.~%")
-                     (invoke-error-exit-status c))
-             (syslog "command ~s failed with exit code ~a"
-                     command (invoke-error-exit-status c))
-             (pause)
-             #f))
-    (syslog "running command ~s~%" command)
-    (apply invoke command)
-    (syslog "command ~s succeeded~%" command)
-    (newline)
-    (pause)
-    #t))
-
 \f
 ;;;
 ;;; Logging.
@@ -219,3 +180,120 @@ accepting socket."
 
   (current-clients (reverse remainder))
   exp)
+
+\f
+;;;
+;;; Run commands.
+;;;
+
+;; XXX: This is taken from (guix build utils) and could be factorized.
+(define (open-pipe-with-stderr program . args)
+  "Run PROGRAM with ARGS in an input pipe, but, unlike 'open-pipe*', redirect
+both its standard output and standard error to the pipe.  Return two value:
+the pipe to read PROGRAM's data from, and the PID of the child process running
+PROGRAM."
+  ;; 'open-pipe*' doesn't attempt to capture stderr in any way, which is why
+  ;; we need to roll our own.
+  (match (pipe)
+    ((input .  output)
+     (match (primitive-fork)
+       (0
+        (dynamic-wind
+          (const #t)
+          (lambda ()
+            (close-port input)
+            (close-port (syslog-port))
+            (dup2 (fileno output) 1)
+            (dup2 (fileno output) 2)
+            (apply execlp program program args))
+          (lambda ()
+            (primitive-exit 127))))
+       (pid
+        (close-port output)
+        (values input pid))))))
+
+(define invoke-log-port
+  ;; Port used by INVOKE-WITH-LOG for logging.
+  (make-parameter #f))
+
+(define* (invoke-with-log program . args)
+  "Invoke PROGRAM with ARGS and log PROGRAM's standard output and standard
+error to INVOKE-LOG-PORT.  If PROGRAM succeeds, print nothing and return the
+unspecified value; otherwise, raise a '&message' error condition with the
+status code.  This procedure is very similar to INVOKE/QUIET with the
+noticeable difference that the program output, that can be quite heavy, is not
+stored but directly sent to INVOKE-LOG-PORT if defined."
+  (let-values (((pipe pid)
+                (apply open-pipe-with-stderr program args)))
+    (let loop ()
+      (match (read-line pipe)
+        ((? eof-object?)
+         (close-port pipe)
+         (match (waitpid pid)
+           ((_ . status)
+            (unless (zero? status)
+              (let-syntax ((G_ (syntax-rules ()   ;for xgettext
+                                 ((_ str) str))))
+                (raise (condition
+                        (&message
+                         (message (format #f (G_ "'~a~{ ~a~}' exited \
+with status ~a.")
+                                          program args
+                                          (or (status:exit-val status)
+                                              status)))))))))))
+        (line
+         (and=> (invoke-log-port) (cut format <> "~a~%" line))
+         (loop))))))
+
+(define* (run-command command #:key locale)
+  "Run COMMAND, a list of strings, in the given LOCALE.  Return true if
+COMMAND exited successfully, #f otherwise."
+  (define env (environ))
+
+  (define (pause)
+    (format #t (G_ "Press Enter to continue.~%"))
+    (send-to-clients '(pause))
+    (environ env)                               ;restore environment variables
+    (match (select (cons (current-input-port) (current-clients))
+             '() '())
+      (((port _ ...) _ _)
+       (read-line port))))
+
+  (setenv "PATH" "/run/current-system/profile/bin")
+
+  (when locale
+    (let ((supported? (false-if-exception
+                       (setlocale LC_ALL locale))))
+      ;; If LOCALE is not supported, then set LANGUAGE, which might at
+      ;; least give us translated messages.
+      (if supported?
+          (setenv "LC_ALL" locale)
+          (setenv "LANGUAGE"
+                  (string-take locale
+                               (or (string-index locale #\_)
+                                   (string-length locale)))))))
+
+  (guard (c ((invoke-error? c)
+             (newline)
+             (format (current-error-port)
+                     (G_ "Command failed with exit code ~a.~%")
+                     (invoke-error-exit-status c))
+             (syslog "command ~s failed with exit code ~a"
+                     command (invoke-error-exit-status c))
+             (pause)
+             #f))
+    (syslog "running command ~s~%" command)
+    ;; If there are any connected clients, assume that we are running
+    ;; installation tests. In that case, dump the standard and error outputs
+    ;; to syslog.
+    (let ((testing? (not (null? (current-clients)))))
+      (if testing?
+          (parameterize ((invoke-log-port (syslog-port)))
+            (apply invoke-with-log command))
+          (apply invoke command)))
+    (syslog "command ~s succeeded~%" command)
+    (newline)
+    (pause)
+    #t))
+
+;;; utils.scm ends here
-- 
2.26.2

bug#41668: Failing test: gui-installed-desktop-os-encrypted

[Mathieu Othacehe]

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


Hey,

> Instead I did reimplement the command in (gnu installer utils) in the
> attached patch :).

There were an issue with exception handling, here's a v2. Note that it
uses the &invoke-error constructor that should be made public I guess.

Thanks,

Mathieu

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: 0001-installer-utils-Dump-command-output-to-syslog-when-t.patch --]
[-- Type: text/x-diff, Size: 7696 bytes --]

From 18754c8c62eabb341e0f710d83ff435ef950ca8e Mon Sep 17 00:00:00 2001
From: Mathieu Othacehe <othacehe@gnu.org>
Date: Mon, 8 Jun 2020 15:14:49 +0200
Subject: [PATCH] installer: utils: Dump command output to syslog when testing.

When debugging the installation tests, it can be very handy to be able to read
"run-command" output, for instance when executing "guix system init".

Introduce a new "invoke-with-log" procedure that is able to log a command
standard and error outputs to the syslog. Use it, only when running the
installation tests, to dump "run-command" output.

* gnu/installer/utils.scm (open-pipe-with-stderr, invoke-with-log): New
procedures,
(invoke-log-port): new variable,
(run-command): move to the end of the file and use invoke-with-log when
running the installation tests.
---
 gnu/installer/utils.scm | 164 +++++++++++++++++++++++++++++-----------
 1 file changed, 120 insertions(+), 44 deletions(-)

diff --git a/gnu/installer/utils.scm b/gnu/installer/utils.scm
index 5f8fe8ca01..68b3dd5009 100644
--- a/gnu/installer/utils.scm
+++ b/gnu/installer/utils.scm
@@ -22,8 +22,13 @@
   #:use-module (guix build utils)
   #:use-module (guix i18n)
   #:use-module (srfi srfi-1)
+  #:use-module (srfi srfi-11)
+  #:use-module (srfi srfi-26)
   #:use-module (srfi srfi-34)
+  #:use-module (srfi srfi-34)
+  #:use-module (srfi srfi-35)
   #:use-module (ice-9 match)
+  #:use-module (ice-9 popen)
   #:use-module (ice-9 rdelim)
   #:use-module (ice-9 regex)
   #:use-module (ice-9 format)
@@ -68,50 +73,6 @@ number. If no percentage is found, return #f"
     (and result
          (string->number (match:substring result 1)))))
 
-(define* (run-command command #:key locale)
-  "Run COMMAND, a list of strings, in the given LOCALE.  Return true if
-COMMAND exited successfully, #f otherwise."
-  (define env (environ))
-
-  (define (pause)
-    (format #t (G_ "Press Enter to continue.~%"))
-    (send-to-clients '(pause))
-    (environ env)                               ;restore environment variables
-    (match (select (cons (current-input-port) (current-clients))
-             '() '())
-      (((port _ ...) _ _)
-       (read-line port))))
-
-  (setenv "PATH" "/run/current-system/profile/bin")
-
-  (when locale
-    (let ((supported? (false-if-exception
-                       (setlocale LC_ALL locale))))
-      ;; If LOCALE is not supported, then set LANGUAGE, which might at
-      ;; least give us translated messages.
-      (if supported?
-          (setenv "LC_ALL" locale)
-          (setenv "LANGUAGE"
-                  (string-take locale
-                               (or (string-index locale #\_)
-                                   (string-length locale)))))))
-
-  (guard (c ((invoke-error? c)
-             (newline)
-             (format (current-error-port)
-                     (G_ "Command failed with exit code ~a.~%")
-                     (invoke-error-exit-status c))
-             (syslog "command ~s failed with exit code ~a"
-                     command (invoke-error-exit-status c))
-             (pause)
-             #f))
-    (syslog "running command ~s~%" command)
-    (apply invoke command)
-    (syslog "command ~s succeeded~%" command)
-    (newline)
-    (pause)
-    #t))
-
 \f
 ;;;
 ;;; Logging.
@@ -219,3 +180,118 @@ accepting socket."
 
   (current-clients (reverse remainder))
   exp)
+
+\f
+;;;
+;;; Run commands.
+;;;
+
+;; XXX: This is taken from (guix build utils) and could be factorized.
+(define (open-pipe-with-stderr program . args)
+  "Run PROGRAM with ARGS in an input pipe, but, unlike 'open-pipe*', redirect
+both its standard output and standard error to the pipe.  Return two value:
+the pipe to read PROGRAM's data from, and the PID of the child process running
+PROGRAM."
+  ;; 'open-pipe*' doesn't attempt to capture stderr in any way, which is why
+  ;; we need to roll our own.
+  (match (pipe)
+    ((input .  output)
+     (match (primitive-fork)
+       (0
+        (dynamic-wind
+          (const #t)
+          (lambda ()
+            (close-port input)
+            (close-port (syslog-port))
+            (dup2 (fileno output) 1)
+            (dup2 (fileno output) 2)
+            (apply execlp program program args))
+          (lambda ()
+            (primitive-exit 127))))
+       (pid
+        (close-port output)
+        (values input pid))))))
+
+(define invoke-log-port
+  ;; Port used by INVOKE-WITH-LOG for logging.
+  (make-parameter #f))
+
+(define* (invoke-with-log program . args)
+  "Invoke PROGRAM with ARGS and log PROGRAM's standard output and standard
+error to INVOKE-LOG-PORT.  If PROGRAM succeeds, print nothing and return the
+unspecified value; otherwise, raise a '&message' error condition with the
+status code.  This procedure is very similar to INVOKE/QUIET with the
+noticeable difference that the program output, that can be quite heavy, is not
+stored but directly sent to INVOKE-LOG-PORT if defined."
+  (let-values (((pipe pid)
+                (apply open-pipe-with-stderr program args)))
+    (let loop ()
+      (match (read-line pipe)
+        ((? eof-object?)
+         (close-port pipe)
+         (match (waitpid pid)
+           ((_ . status)
+            (unless (zero? status)
+              (raise
+               (condition ((@@ (guix build utils) &invoke-error)
+                           (program program)
+                           (arguments args)
+                           (exit-status (status:exit-val status))
+                           (term-signal (status:term-sig status))
+                           (stop-signal (status:stop-sig status)))))))))
+        (line
+         (and=> (invoke-log-port) (cut format <> "~a~%" line))
+         (loop))))))
+
+(define* (run-command command #:key locale)
+  "Run COMMAND, a list of strings, in the given LOCALE.  Return true if
+COMMAND exited successfully, #f otherwise."
+  (define env (environ))
+
+  (define (pause)
+    (format #t (G_ "Press Enter to continue.~%"))
+    (send-to-clients '(pause))
+    (environ env)                               ;restore environment variables
+    (match (select (cons (current-input-port) (current-clients))
+             '() '())
+      (((port _ ...) _ _)
+       (read-line port))))
+
+  (setenv "PATH" "/run/current-system/profile/bin")
+
+  (when locale
+    (let ((supported? (false-if-exception
+                       (setlocale LC_ALL locale))))
+      ;; If LOCALE is not supported, then set LANGUAGE, which might at
+      ;; least give us translated messages.
+      (if supported?
+          (setenv "LC_ALL" locale)
+          (setenv "LANGUAGE"
+                  (string-take locale
+                               (or (string-index locale #\_)
+                                   (string-length locale)))))))
+
+  (guard (c ((invoke-error? c)
+             (newline)
+             (format (current-error-port)
+                     (G_ "Command failed with exit code ~a.~%")
+                     (invoke-error-exit-status c))
+             (syslog "command ~s failed with exit code ~a"
+                     command (invoke-error-exit-status c))
+             (pause)
+             #f))
+    (syslog "running command ~s~%" command)
+    ;; If there are any connected clients, assume that we are running
+    ;; installation tests. In that case, dump the standard and error outputs
+    ;; to syslog.
+    (let ((testing? (not (null? (current-clients)))))
+      (if testing?
+          (parameterize ((invoke-log-port (syslog-port)))
+            (apply invoke-with-log command))
+          (apply invoke command)))
+    (syslog "command ~s succeeded~%" command)
+    (newline)
+    (pause)
+    #t))
+
+;;; utils.scm ends here
-- 
2.26.2

bug#41668: Failing test: gui-installed-desktop-os-encrypted

[Ludovic Courtès]

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

Hi,

Mathieu Othacehe <othacehe@gnu.org> skribis:

> From 18754c8c62eabb341e0f710d83ff435ef950ca8e Mon Sep 17 00:00:00 2001
> From: Mathieu Othacehe <othacehe@gnu.org>
> Date: Mon, 8 Jun 2020 15:14:49 +0200
> Subject: [PATCH] installer: utils: Dump command output to syslog when testing.
>
> When debugging the installation tests, it can be very handy to be able to read
> "run-command" output, for instance when executing "guix system init".
>
> Introduce a new "invoke-with-log" procedure that is able to log a command
> standard and error outputs to the syslog. Use it, only when running the
> installation tests, to dump "run-command" output.
>
> * gnu/installer/utils.scm (open-pipe-with-stderr, invoke-with-log): New
> procedures,
> (invoke-log-port): new variable,
> (run-command): move to the end of the file and use invoke-with-log when
> running the installation tests.
> ---
>  gnu/installer/utils.scm | 164 +++++++++++++++++++++++++++++-----------
>  1 file changed, 120 insertions(+), 44 deletions(-)

It’s nice, but also a bit complicated just to print stuff on the
screen.  :-)

I found a stash with my debugging hack:


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

diff --git a/gnu/installer/final.scm b/gnu/installer/final.scm
index 869be8814b..c084123064 100644
--- a/gnu/installer/final.scm
+++ b/gnu/installer/final.scm
@@ -137,7 +137,13 @@ or #f.  Return #t on success and #f on failure."
       (lambda ()
         (start-service 'cow-store (list (%installer-target-dir))))
       (lambda ()
-        (run-command install-command #:locale locale))
+        (with-output-to-file "/dev/console"
+          (lambda ()
+            (with-error-to-file "/dev/console"
+              (lambda ()
+                (setvbuf (current-output-port) 'none)
+                (setvbuf (current-error-port) 'none)
+                (run-command install-command #:locale locale))))))
       (lambda ()
         (stop-service 'cow-store)
         ;; Remove the store overlay created at cow-store service start.

[-- Attachment #3: Type: text/plain, Size: 246 bytes --]


That’s enough to send the ‘guix system init’ output to the console,
since we use “console=ttyS0”.

It’s a gross hack of course, but maybe we can do something along these
lines instead of setting up a pipe?

Thanks,
Ludo’.

bug#41668: Failing test: gui-installed-desktop-os-encrypted

[Mathieu Othacehe]

Hey Ludo,

> It’s nice, but also a bit complicated just to print stuff on the
> screen.  :-)

You're right, I went too far :p

> That’s enough to send the ‘guix system init’ output to the console,
> since we use “console=ttyS0”.
>
> It’s a gross hack of course, but maybe we can do something along these
> lines instead of setting up a pipe?

Sure, I just applied a variant of your patch.

Thanks,

Mathieu

bug#41668: Failing test: gui-installed-desktop-os-encrypted

[Danny Milosavljevic]

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

Hi,

my CI setup for work automatically mails me failures.

It would be really nice to have that for guix master eventually, too.
Maybe just mail failures to guix-devel as they happen.

I don't check https://ci.guix.gnu.org/ so often, and even when I do the jobset
names are kinda weird there, and there's too few stuff on one page--and just in
general there's no good overview on there.  I mean I can search, but a server
can just automate that and just send me the results as they happen.

It could also automatically mail failures to the last commiters of the source
files that are relevant--but that's probably difficult to implement.

Or even use guix data service in order to find out where it failed exactly
and whether it does so for all archs--but maybe later.

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

bug#41668: Failing test: gui-installed-desktop-os-encrypted

[Ludovic Courtès]

Hi,

Danny Milosavljevic <dannym@scratchpost.org> skribis:

> my CI setup for work automatically mails me failures.
>
> It would be really nice to have that for guix master eventually, too.
> Maybe just mail failures to guix-devel as they happen.
>
> I don't check https://ci.guix.gnu.org/ so often, and even when I do the jobset
> names are kinda weird there, and there's too few stuff on one page--and just in
> general there's no good overview on there.  I mean I can search, but a server
> can just automate that and just send me the results as they happen.
>
> It could also automatically mail failures to the last commiters of the source
> files that are relevant--but that's probably difficult to implement.

Yeah, Hydra could do that on status change (success -> failure and vice versa).

IRC notifications might also be nice.  Or Mastodon.

There’s always a risk of flood though, at which point people stop paying
attention to those notifications.

Thanks,
Ludo’.

bug#41668: Failing test: gui-installed-desktop-os-encrypted

[Mathieu Othacehe]

Hello,

Some status here.

> * The cow-store issue here:
> https://lists.gnu.org/archive/html/guix-devel/2020-06/msg00043.html.

This should be fixed with 876a8d987085b8c64f32c8a320e4219575af285c.
>
> * A new issue I discovered, whereby 'guix system init' try to
> build/download stuff, when it shouldn't:

This is fixed by ea5d9bf9916d532005842f220f7da6e522151f6a.

Regarding the initial OOM issue, this is no longer a thing because we
are building the image on the host (and not in a VM with limited
memory).

I discovered another issue, related to HFS+ limits when producing the
ISO image, this is fixed by: fd1e885236fcec0aec1e3293153524f02b010560.

There is now a final issue, where the command restarting "guix-daemon"
in "umount-cow-store" hangs forever. I can only reproduce it in
"gui-installed-desktop-os-encrypted" test. I wonder if it's a Shepherd
bug or anything else. I'll keep digging.

Thanks,

Mathieu

bug#41668: Failing test: gui-installed-desktop-os-encrypted

[Ludovic Courtès]

Hi Mathieu,

Mathieu Othacehe <othacehe@gnu.org> skribis:

>> * The cow-store issue here:
>> https://lists.gnu.org/archive/html/guix-devel/2020-06/msg00043.html.
>
> This should be fixed with 876a8d987085b8c64f32c8a320e4219575af285c.

Oh, fun!

>> * A new issue I discovered, whereby 'guix system init' try to
>> build/download stuff, when it shouldn't:
>
> This is fixed by ea5d9bf9916d532005842f220f7da6e522151f6a.
>
> Regarding the initial OOM issue, this is no longer a thing because we
> are building the image on the host (and not in a VM with limited
> memory).
>
> I discovered another issue, related to HFS+ limits when producing the
> ISO image, this is fixed by: fd1e885236fcec0aec1e3293153524f02b010560.

Woow.

> There is now a final issue, where the command restarting "guix-daemon"
> in "umount-cow-store" hangs forever. I can only reproduce it in
> "gui-installed-desktop-os-encrypted" test. I wonder if it's a Shepherd
> bug or anything else. I'll keep digging.

If I can be of any help, we can chat on IRC.

Great work already!

Ludo’.

bug#41668: Failing test: gui-installed-desktop-os-encrypted

[Mathieu Othacehe]

Hey,

>> There is now a final issue, where the command restarting "guix-daemon"
>> in "umount-cow-store" hangs forever. I can only reproduce it in
>> "gui-installed-desktop-os-encrypted" test. I wonder if it's a Shepherd
>> bug or anything else. I'll keep digging.
>
> If I can be of any help, we can chat on IRC.
>
> Great work already!

Thanks :) I'm a bit clueless about this one. Here's the output:

--8<---------------cut here---------------start------------->8---
The following derivations will be built:
   /gnu/store/pz0h29lwddwv8iq755xbkp4jbrj645f6-install-bootloader.scm.drv
   /gnu/store/6fbpimwxl85b62rcxd9plk1mf1jb7hvy-module-import-compiled.drv
   /gnu/store/978myg8v0as05r07dzq8m4nlfj5cmkn6-module-import.drv
building /gnu/store/978myg8v0as05r07dzq8m4nlfj5cmkn6-module-import.drv...
building /gnu/store/6fbpimwxl85b62rcxd9plk1mf1jb7hvy-module-import-compiled.drv...
building /gnu/store/pz0h29lwddwv8iq755xbkp4jbrj645f6-install-bootloader.scm.drv...
guix system: bootloader successfully installed on '/dev/vda'

Press Enter to contiJun 16 17:30:08 localhost installer[231]: command ("guix" "system" "init" "--fallback" "--no-grafts" "--no-substitutes" "/mnt/etc/config.scm" "/mnt") succeeded nue.
conversation expecting p
attern ((quote installation-complete))
Jun 16 17:30:10 localhost shepherd[1]: Service cow-store has been stopped.
Jun 16 17:30:10 localhost installer[231]: Unmounting cow-store.
Jun 16 17:30:10 localhost shepherd[1]: Service guix-daemon has been stopped.
--8<---------------cut here---------------end--------------->8---

and it hangs forever. Looks like the guix-daemon restart could be the
issue as it's the last thing that is logged. But hard to say for
sure. I cannot reproduce it while installing manually a system with all
DE and services enabled.

Having an ssh access to this VM would be nice, but I think you already
told me it was not possible. If you have any other idea, it would be
great :)

Thanks,

Mathieu

bug#41668: Failing test: gui-installed-desktop-os-encrypted

[Ludovic Courtès]

Hi,

Mathieu Othacehe <othacehe@gnu.org> skribis:

>>> There is now a final issue, where the command restarting "guix-daemon"
>>> in "umount-cow-store" hangs forever. I can only reproduce it in
>>> "gui-installed-desktop-os-encrypted" test. I wonder if it's a Shepherd
>>> bug or anything else. I'll keep digging.
>>
>> If I can be of any help, we can chat on IRC.
>>
>> Great work already!
>
> Thanks :) I'm a bit clueless about this one. Here's the output:
>
> The following derivations will be built:
>    /gnu/store/pz0h29lwddwv8iq755xbkp4jbrj645f6-install-bootloader.scm.drv
>    /gnu/store/6fbpimwxl85b62rcxd9plk1mf1jb7hvy-module-import-compiled.drv
>    /gnu/store/978myg8v0as05r07dzq8m4nlfj5cmkn6-module-import.drv
> building /gnu/store/978myg8v0as05r07dzq8m4nlfj5cmkn6-module-import.drv...
> building /gnu/store/6fbpimwxl85b62rcxd9plk1mf1jb7hvy-module-import-compiled.drv...
> building /gnu/store/pz0h29lwddwv8iq755xbkp4jbrj645f6-install-bootloader.scm.drv...
> guix system: bootloader successfully installed on '/dev/vda'
>
> Press Enter to contiJun 16 17:30:08 localhost installer[231]: command ("guix" "system" "init" "--fallback" "--no-grafts" "--no-substitutes" "/mnt/etc/config.scm" "/mnt") succeeded nue.
> conversation expecting p
> attern ((quote installation-complete))
> Jun 16 17:30:10 localhost shepherd[1]: Service cow-store has been stopped.
> Jun 16 17:30:10 localhost installer[231]: Unmounting cow-store.
> Jun 16 17:30:10 localhost shepherd[1]: Service guix-daemon has been stopped.
>
> and it hangs forever. Looks like the guix-daemon restart could be the
> issue as it's the last thing that is logged. But hard to say for
> sure. I cannot reproduce it while installing manually a system with all
> DE and services enabled.

Is it deterministic?  Same story with “gui-installed-os”?

I guess we can add more ‘syslog’ statements in the installer around the
place where we restart services.  Or we could run the installer entirely
under strace.

Ludo’.

bug#41668: Failing test: gui-installed-desktop-os-encrypted

[Mathieu Othacehe]

Hello,

> Is it deterministic?  Same story with “gui-installed-os”?
>
> I guess we can add more ‘syslog’ statements in the installer around the
> place where we restart services.  Or we could run the installer entirely
> under strace.

Now that the installation is done in a container, this one doesn't show
up anymore. I also added further fixes with
3ad68ec251a008d6f5875f9235e75f5ce6399f15.

All the installation tests are now operational.

Thanks,

Mathieu

bug#41668: Failing test: gui-installed-desktop-os-encrypted

[Ludovic Courtès]

Hi,

Mathieu Othacehe <othacehe@gnu.org> skribis:

>> Is it deterministic?  Same story with “gui-installed-os”?
>>
>> I guess we can add more ‘syslog’ statements in the installer around the
>> place where we restart services.  Or we could run the installer entirely
>> under strace.
>
> Now that the installation is done in a container, this one doesn't show
> up anymore. I also added further fixes with
> 3ad68ec251a008d6f5875f9235e75f5ce6399f15.
>
> All the installation tests are now operational.

Yay, well done!

Ludo’.