GNU bug report logs - #45146
[PATCH] scripts: substitute: Improve fetch-narinfos progress reporting.

Previous Next

Package: guix-patches;

Reported by: Christopher Baines <mail <at> cbaines.net>

Date: Wed, 9 Dec 2020 18:59:02 UTC

Severity: normal

Tags: patch

Done: Christopher Baines <mail <at> cbaines.net>

Bug is archived. No further changes may be made.

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

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

View this report as an mbox folder, status mbox, maintainer mbox


Report forwarded to guix-patches <at> gnu.org:
bug#45146; Package guix-patches. (Wed, 09 Dec 2020 18:59:02 GMT) Full text and rfc822 format available.

Acknowledgement sent to Christopher Baines <mail <at> cbaines.net>:
New bug report received and forwarded. Copy sent to guix-patches <at> gnu.org. (Wed, 09 Dec 2020 18:59:02 GMT) Full text and rfc822 format available.

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

From: Christopher Baines <mail <at> cbaines.net>
To: guix-patches <at> gnu.org
Subject: [PATCH] scripts: substitute: Improve fetch-narinfos progress
 reporting.
Date: Wed,  9 Dec 2020 18:57:59 +0000
At least in guix weather, these changes make the progress bar actually appear.

* guix/scripts/substitute.scm (fetch-narinfos): Use (guix progress) for
progress reporting.
---
 guix/scripts/substitute.scm | 18 +++++-------------
 1 file changed, 5 insertions(+), 13 deletions(-)

diff --git a/guix/scripts/substitute.scm b/guix/scripts/substitute.scm
index 25075eedff..5128310439 100755
--- a/guix/scripts/substitute.scm
+++ b/guix/scripts/substitute.scm
@@ -614,16 +614,8 @@ print a warning and return #f."
 
 (define (fetch-narinfos url paths)
   "Retrieve all the narinfos for PATHS from the cache at URL and return them."
-  (define update-progress!
-    (let ((done 0)
-          (total (length paths)))
-      (lambda ()
-        (display "\r\x1b[K" (current-error-port)) ;erase current line
-        (force-output (current-error-port))
-        (format (current-error-port)
-                (G_ "updating substitutes from '~a'... ~5,1f%")
-                url (* 100. (/ done total)))
-        (set! done (+ 1 done)))))
+  (define fetch-narinfos-progress-reporter
+    (progress-reporter/bar (length paths)))
 
   (define hash-part->path
     (let ((mapping (fold (lambda (path result)
@@ -641,7 +633,7 @@ print a warning and return #f."
            (len    (response-content-length response))
            (cache  (response-cache-control response))
            (ttl    (and cache (assoc-ref cache 'max-age))))
-      (update-progress!)
+      (progress-reporter-report! fetch-narinfos-progress-reporter)
 
       ;; Make sure to read no more than LEN bytes since subsequent bytes may
       ;; belong to the next response.
@@ -673,7 +665,7 @@ print a warning and return #f."
            (#f
             '())
            (port
-            (update-progress!)
+            (start-progress-reporter! fetch-narinfos-progress-reporter)
             ;; Note: Do not check HTTPS server certificates to avoid depending
             ;; on the X.509 PKI.  We can do it because we authenticate
             ;; narinfos, which provides a much stronger guarantee.
@@ -683,7 +675,7 @@ print a warning and return #f."
                                              #:verify-certificate? #f
                                              #:port port)))
               (close-port port)
-              (newline (current-error-port))
+              (stop-progress-reporter! fetch-narinfos-progress-reporter)
               result)))))
       ((file #f)
        (let* ((base  (string-append (uri-path uri) "/"))
-- 
2.29.2





Information forwarded to guix-patches <at> gnu.org:
bug#45146; Package guix-patches. (Fri, 11 Dec 2020 18:02:01 GMT) Full text and rfc822 format available.

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

From: Ludovic Courtès <ludo <at> gnu.org>
To: Christopher Baines <mail <at> cbaines.net>
Cc: 45146 <at> debbugs.gnu.org
Subject: Re: [bug#45146] [PATCH] scripts: substitute: Improve fetch-narinfos
 progress reporting.
Date: Fri, 11 Dec 2020 19:01:36 +0100
Hi,

Christopher Baines <mail <at> cbaines.net> skribis:

> At least in guix weather, these changes make the progress bar actually appear.
>
> * guix/scripts/substitute.scm (fetch-narinfos): Use (guix progress) for
> progress reporting.

Cool.  I noticed that something was wrong with ‘guix weather’, but I
suspected it had to do with the order in which the erase-line sequence
and \r are sent.

> -      (lambda ()
> -        (display "\r\x1b[K" (current-error-port)) ;erase current line
> -        (force-output (current-error-port))
> -        (format (current-error-port)
> -                (G_ "updating substitutes from '~a'... ~5,1f%")
> -                url (* 100. (/ done total)))
> -        (set! done (+ 1 done)))))
> +  (define fetch-narinfos-progress-reporter
> +    (progress-reporter/bar (length paths)))

The problem here is that we’d see a progress bar without knowing what it
represents.

Besides, currently output from ‘guix substitute’ is printed as is by
client commands, regardless of whether stdout is a tty.  The problem
already exists but it would become a bit more visible as logs get filled
with progress bars.

Ludo’.




Information forwarded to guix-patches <at> gnu.org:
bug#45146; Package guix-patches. (Thu, 24 Dec 2020 17:27:02 GMT) Full text and rfc822 format available.

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

From: Christopher Baines <mail <at> cbaines.net>
To: Ludovic Courtès <ludo <at> gnu.org>
Cc: 45146 <at> debbugs.gnu.org
Subject: Re: [bug#45146] [PATCH] scripts: substitute: Improve fetch-narinfos
 progress reporting.
Date: Thu, 24 Dec 2020 17:26:50 +0000
[Message part 1 (text/plain, inline)]
Ludovic Courtès <ludo <at> gnu.org> writes:

> Christopher Baines <mail <at> cbaines.net> skribis:
>
>> At least in guix weather, these changes make the progress bar actually appear.
>>
>> * guix/scripts/substitute.scm (fetch-narinfos): Use (guix progress) for
>> progress reporting.
>
> Cool.  I noticed that something was wrong with ‘guix weather’, but I
> suspected it had to do with the order in which the erase-line sequence
> and \r are sent.
>
>> -      (lambda ()
>> -        (display "\r\x1b[K" (current-error-port)) ;erase current line
>> -        (force-output (current-error-port))
>> -        (format (current-error-port)
>> -                (G_ "updating substitutes from '~a'... ~5,1f%")
>> -                url (* 100. (/ done total)))
>> -        (set! done (+ 1 done)))))
>> +  (define fetch-narinfos-progress-reporter
>> +    (progress-reporter/bar (length paths)))
>
> The problem here is that we’d see a progress bar without knowing what it
> represents.
>
> Besides, currently output from ‘guix substitute’ is printed as is by
> client commands, regardless of whether stdout is a tty.  The problem
> already exists but it would become a bit more visible as logs get filled
> with progress bars.

Maybe it's best to circle back to fixing guix weather after trying to
restructure some of the guix substitute code.

I've made an initial attempt at moving things around in [1]. If the
underlying code can live in a module, and then the substitute, weather
and challenge scripts use that code with whatever UI stuff they want,
maybe that will allow for better addressing this weather specific issue.

1: https://issues.guix.info/45409
[signature.asc (application/pgp-signature, inline)]

Information forwarded to guix-patches <at> gnu.org:
bug#45146; Package guix-patches. (Wed, 24 Feb 2021 20:35:02 GMT) Full text and rfc822 format available.

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

From: Christopher Baines <mail <at> cbaines.net>
To: 45146 <at> debbugs.gnu.org
Subject: [PATCH 1/2] guix: substitutes: Make progress reporting configurable.
Date: Wed, 24 Feb 2021 20:34:11 +0000
Rather than always outputting to (current-error-port) in
lookup-narinfos (which is called from within lookup-narinfos/diverse), take a
procedure which should return a progress reporter, and defer any output to
that.

As this is now general purpose code, make the default behaviour to output
nothing. Maintain the current behaviour of the substitute script by moving the
progress reporter implementation there, and passing it in when calling
lookup-narinfos/diverse.

These changes should be generally useful, but I'm particularly looking at
getting guix weather to do progress reporting differently, with this new
flexibility.

* guix/substitutes.scm (fetch-narinfos): Take a procedure to make a
progress-reporter, and use that rather than the hardcoded behaviour.
(lookup-narinfos): Add #:make-progress-reporter keyword argument, and pass
this through to fetch-narinfos.
(lookup-narinfos/diverse): Add a #:make-progress-reporter keyword argument,
and pass this through to lookup-narinfos.
* guix/scripts/substitute.scm (process-query): Pass a progress-reporter to
lookup-narinfos/diverse.
---
 guix/scripts/substitute.scm | 23 +++++++++++++++++++--
 guix/substitutes.scm        | 40 ++++++++++++++++++++-----------------
 2 files changed, 43 insertions(+), 20 deletions(-)

diff --git a/guix/scripts/substitute.scm b/guix/scripts/substitute.scm
index ed19e67531..47a723edb2 100755
--- a/guix/scripts/substitute.scm
+++ b/guix/scripts/substitute.scm
@@ -298,12 +298,30 @@ authorized substitutes."
         (lambda (obj)
           (valid-narinfo? obj acl))))
 
+  (define* (make-progress-reporter total #:key url)
+    (define done 0)
+
+    (define (report-progress)
+      (erase-current-line (current-error-port)) ;erase current line
+      (force-output (current-error-port))
+      (format (current-error-port)
+              (G_ "updating substitutes from '~a'... ~5,1f%")
+              url (* 100. (/ done total)))
+      (set! done (+ 1 done)))
+
+    (progress-reporter
+     (start report-progress)
+     (report report-progress)
+     (stop (lambda ()
+             (newline (current-error-port))))))
+
   (match (string-tokenize command)
     (("have" paths ..1)
      ;; Return the subset of PATHS available in CACHE-URLS.
      (let ((substitutable (lookup-narinfos/diverse
                            cache-urls paths valid?
-                           #:open-connection open-connection-for-uri/cached)))
+                           #:open-connection open-connection-for-uri/cached
+                           #:make-progress-reporter make-progress-reporter)))
        (for-each (lambda (narinfo)
                    (format #t "~a~%" (narinfo-path narinfo)))
                  substitutable)
@@ -312,7 +330,8 @@ authorized substitutes."
      ;; Reply info about PATHS if it's in CACHE-URLS.
      (let ((substitutable (lookup-narinfos/diverse
                            cache-urls paths valid?
-                           #:open-connection open-connection-for-uri/cached)))
+                           #:open-connection open-connection-for-uri/cached
+                           #:make-progress-reporter make-progress-reporter)))
        (for-each display-narinfo-data substitutable)
        (newline)))
     (wtf
diff --git a/guix/substitutes.scm b/guix/substitutes.scm
index dc94ccc8e4..ef78013659 100644
--- a/guix/substitutes.scm
+++ b/guix/substitutes.scm
@@ -173,18 +173,14 @@ if file doesn't exist, and the narinfo otherwise."
           (apply throw args)))))
 
 (define* (fetch-narinfos url paths
-                         #:key (open-connection guix:open-connection-for-uri))
+                         #:key
+                         (open-connection guix:open-connection-for-uri)
+                         (make-progress-reporter
+                          (const progress-reporter/silent)))
   "Retrieve all the narinfos for PATHS from the cache at URL and return them."
-  (define update-progress!
-    (let ((done 0)
-          (total (length paths)))
-      (lambda ()
-        (display "\r\x1b[K" (current-error-port)) ;erase current line
-        (force-output (current-error-port))
-        (format (current-error-port)
-                (G_ "updating substitutes from '~a'... ~5,1f%")
-                url (* 100. (/ done total)))
-        (set! done (+ 1 done)))))
+  (define progress-reporter
+    (make-progress-reporter (length paths)
+                            #:url url))
 
   (define hash-part->path
     (let ((mapping (fold (lambda (path result)
@@ -206,7 +202,7 @@ if file doesn't exist, and the narinfo otherwise."
            (len    (response-content-length response))
            (cache  (response-cache-control response))
            (ttl    (and cache (assoc-ref cache 'max-age))))
-      (update-progress!)
+      (progress-reporter-report! progress-reporter)
 
       ;; Make sure to read no more than LEN bytes since subsequent bytes may
       ;; belong to the next response.
@@ -238,7 +234,7 @@ if file doesn't exist, and the narinfo otherwise."
        ;; narinfos, which provides a much stronger guarantee.
        (let* ((requests (map (cut narinfo-request url <>) paths))
               (result   (begin
-                          (update-progress!)
+                          (start-progress-reporter! progress-reporter)
                           (call-with-connection-error-handling
                            uri
                            (lambda ()
@@ -247,7 +243,7 @@ if file doesn't exist, and the narinfo otherwise."
                                                 requests
                                                 #:open-connection open-connection
                                                 #:verify-certificate? #f))))))
-         (newline (current-error-port))
+         (stop-progress-reporter! progress-reporter)
          result))
       ((file #f)
        (let* ((base  (string-append (uri-path uri) "/"))
@@ -297,7 +293,9 @@ for PATH."
       (values #f #f))))
 
 (define* (lookup-narinfos cache paths
-                          #:key (open-connection guix:open-connection-for-uri))
+                          #:key (open-connection guix:open-connection-for-uri)
+                          (make-progress-reporter
+                           (const progress-reporter/silent)))
   "Return the narinfos for PATHS, invoking the server at CACHE when no
 information is available locally."
   (let-values (((cached missing)
@@ -315,12 +313,16 @@ information is available locally."
     (if (null? missing)
         cached
         (let ((missing (fetch-narinfos cache missing
-                                       #:open-connection open-connection)))
+                                       #:open-connection open-connection
+                                       #:make-progress-reporter
+                                       make-progress-reporter)))
           (append cached (or missing '()))))))
 
 (define* (lookup-narinfos/diverse caches paths authorized?
                                   #:key (open-connection
-                                         guix:open-connection-for-uri))
+                                         guix:open-connection-for-uri)
+                                  (make-progress-reporter
+                                   (const progress-reporter/silent)))
   "Look up narinfos for PATHS on all of CACHES, a list of URLS, in that order.
 That is, when a cache lacks an AUTHORIZED? narinfo, look it up in the next
 cache, and so on.
@@ -353,7 +355,9 @@ AUTHORIZED? narinfo."
        (match caches
          ((cache rest ...)
           (let* ((narinfos (lookup-narinfos cache paths
-                                            #:open-connection open-connection))
+                                            #:open-connection open-connection
+                                            #:make-progress-reporter
+                                            make-progress-reporter))
                  (definite (map narinfo-path (filter authorized? narinfos)))
                  (missing  (lset-difference string=? paths definite))) ;XXX: perf
             (loop rest missing
-- 
2.30.0





Information forwarded to guix-patches <at> gnu.org:
bug#45146; Package guix-patches. (Wed, 24 Feb 2021 20:35:02 GMT) Full text and rfc822 format available.

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

From: Christopher Baines <mail <at> cbaines.net>
To: 45146 <at> debbugs.gnu.org
Subject: [PATCH 2/2] weather: Call lookup-narinfos with a custom progress
 reporter.
Date: Wed, 24 Feb 2021 20:34:12 +0000
This means there's a useful progress bar when running guix weather.

* guix/scripts/weather.scm (report-server-coverage): Pass
 #:make-progress-reporter to lookup-narinfos.
---
 guix/scripts/weather.scm | 6 +++++-
 1 file changed, 5 insertions(+), 1 deletion(-)

diff --git a/guix/scripts/weather.scm b/guix/scripts/weather.scm
index 9e94bff5a3..26ec543211 100644
--- a/guix/scripts/weather.scm
+++ b/guix/scripts/weather.scm
@@ -181,7 +181,11 @@ Return the coverage ratio, an exact number between 0 and 1."
   (format #t (G_ "looking for ~h store items on ~a...~%")
           (length items) server)
 
-  (let/time ((time narinfos (lookup-narinfos server items)))
+  (let/time ((time narinfos (lookup-narinfos
+                             server items
+                             #:make-progress-reporter
+                             (lambda* (total #:key url #:allow-other-keys)
+                               (progress-reporter/bar total)))))
     (format #t "~a~%" server)
     (let ((obtained  (length narinfos))
           (requested (length items))
-- 
2.30.0





Information forwarded to guix-patches <at> gnu.org:
bug#45146; Package guix-patches. (Wed, 24 Feb 2021 20:45:01 GMT) Full text and rfc822 format available.

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

From: Christopher Baines <mail <at> cbaines.net>
To: Ludovic Courtès <ludo <at> gnu.org>
Cc: 45146 <at> debbugs.gnu.org
Subject: Re: [bug#45146] [PATCH] scripts: substitute: Improve fetch-narinfos
 progress reporting.
Date: Wed, 24 Feb 2021 20:44:53 +0000
[Message part 1 (text/plain, inline)]
Christopher Baines <mail <at> cbaines.net> writes:

> Ludovic Courtès <ludo <at> gnu.org> writes:
>
>> Christopher Baines <mail <at> cbaines.net> skribis:
>>
>>> At least in guix weather, these changes make the progress bar actually appear.
>>>
>>> * guix/scripts/substitute.scm (fetch-narinfos): Use (guix progress) for
>>> progress reporting.
>>
>> Cool.  I noticed that something was wrong with ‘guix weather’, but I
>> suspected it had to do with the order in which the erase-line sequence
>> and \r are sent.
>>
>>> -      (lambda ()
>>> -        (display "\r\x1b[K" (current-error-port)) ;erase current line
>>> -        (force-output (current-error-port))
>>> -        (format (current-error-port)
>>> -                (G_ "updating substitutes from '~a'... ~5,1f%")
>>> -                url (* 100. (/ done total)))
>>> -        (set! done (+ 1 done)))))
>>> +  (define fetch-narinfos-progress-reporter
>>> +    (progress-reporter/bar (length paths)))
>>
>> The problem here is that we’d see a progress bar without knowing what it
>> represents.
>>
>> Besides, currently output from ‘guix substitute’ is printed as is by
>> client commands, regardless of whether stdout is a tty.  The problem
>> already exists but it would become a bit more visible as logs get filled
>> with progress bars.
>
> Maybe it's best to circle back to fixing guix weather after trying to
> restructure some of the guix substitute code.
>
> I've made an initial attempt at moving things around in [1]. If the
> underlying code can live in a module, and then the substitute, weather
> and challenge scripts use that code with whatever UI stuff they want,
> maybe that will allow for better addressing this weather specific issue.
>
> 1: https://issues.guix.info/45409

I've sent a couple of updated patches for this. They're not particularly
dependent on the above work to create the (guix substitutes) module, but
I based the commits on that.

These commits make more careful changes, the substitute script behaviour
should remain the same.
[signature.asc (application/pgp-signature, inline)]

Reply sent to Christopher Baines <mail <at> cbaines.net>:
You have taken responsibility. (Tue, 09 Mar 2021 20:30:02 GMT) Full text and rfc822 format available.

Notification sent to Christopher Baines <mail <at> cbaines.net>:
bug acknowledged by developer. (Tue, 09 Mar 2021 20:30:02 GMT) Full text and rfc822 format available.

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

From: Christopher Baines <mail <at> cbaines.net>
To: 45146-done <at> debbugs.gnu.org
Cc: Ludovic Courtès <ludo <at> gnu.org>
Subject: Re: [bug#45146] [PATCH] scripts: substitute: Improve fetch-narinfos
 progress reporting.
Date: Tue, 09 Mar 2021 20:29:40 +0000
[Message part 1 (text/plain, inline)]
Christopher Baines <mail <at> cbaines.net> writes:

> Christopher Baines <mail <at> cbaines.net> writes:
>
>> Ludovic Courtès <ludo <at> gnu.org> writes:
>>
>>> Christopher Baines <mail <at> cbaines.net> skribis:
>>>
>>>> At least in guix weather, these changes make the progress bar actually appear.
>>>>
>>>> * guix/scripts/substitute.scm (fetch-narinfos): Use (guix progress) for
>>>> progress reporting.
>>>
>>> Cool.  I noticed that something was wrong with ‘guix weather’, but I
>>> suspected it had to do with the order in which the erase-line sequence
>>> and \r are sent.
>>>
>>>> -      (lambda ()
>>>> -        (display "\r\x1b[K" (current-error-port)) ;erase current line
>>>> -        (force-output (current-error-port))
>>>> -        (format (current-error-port)
>>>> -                (G_ "updating substitutes from '~a'... ~5,1f%")
>>>> -                url (* 100. (/ done total)))
>>>> -        (set! done (+ 1 done)))))
>>>> +  (define fetch-narinfos-progress-reporter
>>>> +    (progress-reporter/bar (length paths)))
>>>
>>> The problem here is that we’d see a progress bar without knowing what it
>>> represents.
>>>
>>> Besides, currently output from ‘guix substitute’ is printed as is by
>>> client commands, regardless of whether stdout is a tty.  The problem
>>> already exists but it would become a bit more visible as logs get filled
>>> with progress bars.
>>
>> Maybe it's best to circle back to fixing guix weather after trying to
>> restructure some of the guix substitute code.
>>
>> I've made an initial attempt at moving things around in [1]. If the
>> underlying code can live in a module, and then the substitute, weather
>> and challenge scripts use that code with whatever UI stuff they want,
>> maybe that will allow for better addressing this weather specific issue.
>>
>> 1: https://issues.guix.info/45409
>
> I've sent a couple of updated patches for this. They're not particularly
> dependent on the above work to create the (guix substitutes) module, but
> I based the commits on that.
>
> These commits make more careful changes, the substitute script behaviour
> should remain the same.

I've gone ahead and pushed these patches now as
f5ffb3bd9cd59cfff5b4625d6d65e8d116d0a25b.
[signature.asc (application/pgp-signature, inline)]

bug archived. Request was from Debbugs Internal Request <help-debbugs <at> gnu.org> to internal_control <at> debbugs.gnu.org. (Wed, 07 Apr 2021 11:24:05 GMT) Full text and rfc822 format available.

This bug report was last modified 3 years and 17 days ago.

Previous Next


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