From debbugs-submit-bounces@debbugs.gnu.org Tue Apr 06 06:20:40 2021 Received: (at 46362) by debbugs.gnu.org; 6 Apr 2021 10:20:40 +0000 Received: from localhost ([127.0.0.1]:39268 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1lTioz-0004MQ-LF for submit@debbugs.gnu.org; Tue, 06 Apr 2021 06:20:40 -0400 Received: from eggs.gnu.org ([209.51.188.92]:38084) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1lTiox-0004M9-8Z for 46362@debbugs.gnu.org; Tue, 06 Apr 2021 06:20:32 -0400 Received: from fencepost.gnu.org ([2001:470:142:3::e]:47515) by eggs.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1lTios-0001um-2U for 46362@debbugs.gnu.org; Tue, 06 Apr 2021 06:20:26 -0400 Received: from [2a01:e0a:1d:7270:af76:b9b:ca24:c465] (port=37008 helo=ribbon) by fencepost.gnu.org with esmtpsa (TLS1.2:RSA_AES_256_CBC_SHA1:256) (Exim 4.82) (envelope-from ) id 1lTiol-0000Ne-R6 for 46362@debbugs.gnu.org; Tue, 06 Apr 2021 06:20:25 -0400 From: =?utf-8?Q?Ludovic_Court=C3=A8s?= To: 46362@debbugs.gnu.org Subject: Re: bug#46362: got unexpected path `Backtrace:' from substituter References: <86a6sgcan1.fsf@163.com> <87eeh41rsb.fsf@gnu.org> Date: Tue, 06 Apr 2021 12:20:18 +0200 In-Reply-To: <87eeh41rsb.fsf@gnu.org> ("Ludovic =?utf-8?Q?Court=C3=A8s=22'?= =?utf-8?Q?s?= message of "Thu, 25 Feb 2021 09:21:40 +0100") Message-ID: <87h7kjogt9.fsf@gnu.org> User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/27.2 (gnu/linux) MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="=-=-=" X-Spam-Score: 1.3 (+) X-Spam-Report: Spam detection software, running on the system "debbugs.gnu.org", has NOT identified this incoming email as spam. The original message has been attached to this so you can view it or label similar future email. If you have any questions, see the administrator of that system for details. Content preview: Hi, Ludovic Courtès skribis: >> chino@asus-laptop:~$ guix build opencv --substitute-urls="https://mirror.sjtu.edu.cn/guix https://mirror.guix.org.cn https://mirror.c1r3u.xyz https://ci.guix.gnu.org" >> substitute: updating substi [...] Content analysis details: (1.3 points, 10.0 required) pts rule name description ---- ---------------------- -------------------------------------------------- -0.0 SPF_PASS SPF: sender matches SPF record -0.0 SPF_HELO_PASS SPF: HELO matches SPF record 2.0 PDS_OTHER_BAD_TLD Untrustworthy TLDs [URI: mirror.c1r3u.xyz (xyz)] -0.7 RCVD_IN_DNSWL_LOW RBL: Sender listed at https://www.dnswl.org/, low trust [209.51.188.92 listed in list.dnswl.org] X-Debbugs-Envelope-To: 46362 X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: 1.0 (+) --=-=-= Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable Hi, Ludovic Court=C3=A8s skribis: >> chino@asus-laptop:~$ guix build opencv --substitute-urls=3D"https://mirr= or.sjtu.edu.cn/guix https://mirror.guix.org.cn https://mirror.c1r3u.xyz htt= ps://ci.guix.gnu.org" >> substitute: updating substitutes from 'https://mirror.sjtu.edu.cn/guix'.= .. 100.0% >> substitute:=20 >> guix build: error: got unexpected path `Backtrace:' from substituter >> ``` > > Commit ee3226e9d54891c7e696912245e4904435be191c addresses the > error-reporting issue: now the backtrace will be properly displayed (we > still need to update the =E2=80=98guix=E2=80=99 package before you can de= ploy the fix.) This commit did the job, but there would still be cases where error messages would end up on file descriptor 2 (not surprisingly) and which the daemon would wrongfully interpret as a status message from =E2=80=98guix substitute=E2=80=99, leading to obscure crashes. S=C3=A9bastien gives an e= xample at : guix install: error: got unexpected path `/gnu/store/pwcp239kjf7lnj5i4lkd= zcfcxwcfyk72-bash-minimal-5.0.16/bin/bash: warning: setlocale: LC_ALL: cann= ot change locale (en_US.utf8)' from substituter The attached patch swaps use of file descriptors 2 and 4 of =E2=80=98guix substitute=E2=80=99: FD 2 is now used for regular error reporting, while FD= 4 is used to communicate responses to the daemon. This is more natural and avoids the kind of problem discussed above. I=E2=80=99ll push this change if there are no objections. Thanks, Ludo=E2=80=99. --=-=-= Content-Type: text/x-patch; charset=utf-8 Content-Disposition: inline; filename=0001-daemon-guix-substitute-replies-on-FD-4.patch Content-Transfer-Encoding: quoted-printable Content-Description: the patch From d85353dd4bfaa57a7d5803dade91d806a169295a Mon Sep 17 00:00:00 2001 From: =3D?UTF-8?q?Ludovic=3D20Court=3DC3=3DA8s?=3D Date: Tue, 6 Apr 2021 12:10:29 +0200 Subject: [PATCH] daemon: 'guix substitute' replies on FD 4. This avoids the situation where error messages would unintentionally go to stderr and be wrongfully interpreted as a reply by the daemon. Fixes . This is a followup to ee3226e9d54891c7e696912245e4904435be191c. * guix/scripts/substitute.scm (display-narinfo-data): Add 'port' parameter and honor it. (process-query): Likewise. (process-substitution): Likewise. (%error-to-file-descriptor-4?, with-redirected-error-port): Remove. (%reply-file-descriptor): New variable. (guix-substitute): Remove use of 'with-redirected-error-port'. Define 'reply-port' and pass it to 'process-query' and 'process-substitution'. * nix/libstore/build.cc (SubstitutionGoal::handleChildOutput): Swap 'builderOut' and 'fromAgent'. * nix/libstore/local-store.cc (LocalStore::getLineFromSubstituter): Likewise. * tests/substitute.scm : Set '%reply-file-descriptor' rather than '%error-to-file-descriptor-4?'. --- guix/scripts/substitute.scm | 183 +++++++++++++++++------------------- nix/libstore/build.cc | 4 +- nix/libstore/local-store.cc | 12 +-- tests/substitute.scm | 4 +- 4 files changed, 95 insertions(+), 108 deletions(-) diff --git a/guix/scripts/substitute.scm b/guix/scripts/substitute.scm index 79eaabd8fd..48309f9b3a 100755 --- a/guix/scripts/substitute.scm +++ b/guix/scripts/substitute.scm @@ -63,7 +63,7 @@ #:use-module (web uri) #:use-module (guix http-client) #:export (%allow-unauthenticated-substitutes? - %error-to-file-descriptor-4? + %reply-file-descriptor =20 substitute-urls guix-substitute)) @@ -279,29 +279,29 @@ Internal tool to substitute a pre-built binary to a l= ocal build.\n")) "Evaluate EXP... Return its CPU usage as a fraction between 0 and 1." (call-with-cpu-usage-monitoring (lambda () exp ...))) =20 -(define (display-narinfo-data narinfo) - "Write to the current output port the contents of NARINFO in the format -expected by the daemon." - (format #t "~a\n~a\n~a\n" +(define (display-narinfo-data port narinfo) + "Write to PORT the contents of NARINFO in the format expected by the +daemon." + (format port "~a\n~a\n~a\n" (narinfo-path narinfo) (or (and=3D> (narinfo-deriver narinfo) (cute string-append (%store-prefix) "/" <>)) "") (length (narinfo-references narinfo))) - (for-each (cute format #t "~a/~a~%" (%store-prefix) <>) + (for-each (cute format port "~a/~a~%" (%store-prefix) <>) (narinfo-references narinfo)) =20 (let-values (((uri compression file-size) (narinfo-best-uri narinfo #:fast-decompression? %prefer-fast-decompression?))) - (format #t "~a\n~a\n" + (format port "~a\n~a\n" (or file-size 0) (or (narinfo-size narinfo) 0)))) =20 -(define* (process-query command +(define* (process-query port command #:key cache-urls acl) - "Reply to COMMAND, a query as written by the daemon to this process's + "Reply on PORT to COMMAND, a query as written by the daemon to this proc= ess's standard input. Use ACL as the access-control list against which to check authorized substitutes." (define valid? @@ -338,17 +338,17 @@ authorized substitutes." #:open-connection open-connection-for-uri/cached #:make-progress-reporter make-progress-reporter= ))) (for-each (lambda (narinfo) - (format #t "~a~%" (narinfo-path narinfo))) + (format port "~a~%" (narinfo-path narinfo))) substitutable) - (newline))) + (newline port))) (("info" paths ..1) ;; 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 #:make-progress-reporter make-progress-reporter= ))) - (for-each display-narinfo-data substitutable) - (newline))) + (for-each (cut display-narinfo-data port <>) substitutable) + (newline port))) (wtf (error "unknown `--query' command" wtf)))) =20 @@ -428,14 +428,14 @@ server certificates." "Bind PORT with EXP... to a socket connected to URI." (call-with-cached-connection uri (lambda (port) exp ...))) =20 -(define* (process-substitution store-item destination +(define* (process-substitution port store-item destination #:key cache-urls acl deduplicate? print-build-trace?) "Substitute STORE-ITEM (a store file name) from CACHE-URLS, and write it= to DESTINATION as a nar file. Verify the substitute against ACL, and verify = its hash against what appears in the narinfo. When DEDUPLICATE? is true, and = if -DESTINATION is in the store, deduplicate its files. Print a status line on -the current output port." +DESTINATION is in the store, deduplicate its files. Print a status line to +PORT." (define narinfo (lookup-narinfo cache-urls store-item (if (%allow-unauthenticated-substitutes?) @@ -565,10 +565,10 @@ the current output port." (let ((actual (get-hash))) (if (bytevector=3D? actual expected) ;; Tell the daemon that we're done. - (format (current-output-port) "success ~a ~a~%" + (format port "success ~a ~a~%" (narinfo-hash narinfo) (narinfo-size narinfo)) ;; The actual data has a different hash than that in NARINFO. - (format (current-output-port) "hash-mismatch ~a ~a ~a~%" + (format port "hash-mismatch ~a ~a ~a~%" (hash-algorithm-name algorithm) (bytevector->nix-base32-string expected) (bytevector->nix-base32-string actual))))))) @@ -682,28 +682,10 @@ default value." (unless (string->uri uri) (leave (G_ "~a: invalid URI~%") uri))) =20 -(define %error-to-file-descriptor-4? - ;; Whether to direct 'current-error-port' to file descriptor 4 like - ;; 'guix-daemon' expects. - (make-parameter #t)) - -;; The daemon's agent code opens file descriptor 4 for us and this is where -;; stderr should go. -(define-syntax-rule (with-redirected-error-port exp ...) - "Evaluate EXP... with the current error port redirected to file descript= or 4 -if needed, as expected by the daemon's agent." - (let ((thunk (lambda () exp ...))) - (if (%error-to-file-descriptor-4?) - (parameterize ((current-error-port (fdopen 4 "wl"))) - ;; Redirect diagnostics to file descriptor 4 as well. - (guix-warning-port (current-error-port)) - - ;; 'with-continuation-barrier' captures the initial value of - ;; 'current-error-port' to report backtraces in case of uncaught - ;; exceptions. Without it, backtraces would be printed to FD 2, - ;; thereby confusing the daemon. - (with-continuation-barrier thunk)) - (thunk)))) +(define %reply-file-descriptor + ;; The file descriptor where replies to the daemon must be sent, or #f to + ;; use the current output port instead. + (make-parameter 4)) =20 (define-command (guix-substitute . args) (category internal) @@ -719,68 +701,73 @@ if needed, as expected by the daemon's agent." (define deduplicate? (find-daemon-option "deduplicate")) =20 - (with-redirected-error-port - (mkdir-p %narinfo-cache-directory) - (maybe-remove-expired-cache-entries %narinfo-cache-directory - cached-narinfo-files - #:entry-expiration - cached-narinfo-expiration-time - #:cleanup-period - %narinfo-expired-cache-entry-remov= al-delay) - (check-acl-initialized) + (define reply-port + ;; Port used to reply to the daemon. + (if (%reply-file-descriptor) + (fdopen (%reply-file-descriptor) "wl") + (current-output-port))) =20 - ;; Sanity-check SUBSTITUTE-URLS so we can provide a meaningful error - ;; message. - (for-each validate-uri (substitute-urls)) + (mkdir-p %narinfo-cache-directory) + (maybe-remove-expired-cache-entries %narinfo-cache-directory + cached-narinfo-files + #:entry-expiration + cached-narinfo-expiration-time + #:cleanup-period + %narinfo-expired-cache-entry-removal= -delay) + (check-acl-initialized) =20 - ;; Attempt to install the client's locale so that messages are suitably - ;; translated. LC_CTYPE must be a UTF-8 locale; it's the case by defa= ult - ;; so don't change it. - (match (or (find-daemon-option "untrusted-locale") - (find-daemon-option "locale")) - (#f #f) - (locale (false-if-exception (setlocale LC_MESSAGES locale)))) + ;; Sanity-check SUBSTITUTE-URLS so we can provide a meaningful error + ;; message. + (for-each validate-uri (substitute-urls)) =20 - (catch 'system-error - (lambda () - (set-thread-name "guix substitute")) - (const #t)) ;GNU/Hurd lacks 'prctl' + ;; Attempt to install the client's locale so that messages are suitably + ;; translated. LC_CTYPE must be a UTF-8 locale; it's the case by default + ;; so don't change it. + (match (or (find-daemon-option "untrusted-locale") + (find-daemon-option "locale")) + (#f #f) + (locale (false-if-exception (setlocale LC_MESSAGES locale)))) =20 - (with-networking - (with-error-handling ; for signature errors - (match args - (("--query") - (let ((acl (current-acl))) - (let loop ((command (read-line))) - (or (eof-object? command) - (begin - (process-query command - #:cache-urls (substitute-urls) - #:acl acl) - (loop (read-line))))))) - (("--substitute") - ;; Download STORE-PATH and store it as a Nar in file DESTINATION. - ;; Specify the number of columns of the terminal so the progress - ;; report displays nicely. - (parameterize ((current-terminal-columns (client-terminal-column= s))) - (let loop () - (match (read-line) - ((? eof-object?) - #t) - ((=3D string-tokenize ("substitute" store-path destination= )) - (process-substitution store-path destination - #:cache-urls (substitute-urls) - #:acl (current-acl) - #:deduplicate? deduplicate? - #:print-build-trace? - print-build-trace?) - (loop)))))) - ((or ("-V") ("--version")) - (show-version-and-exit "guix substitute")) - (("--help") - (show-help)) - (opts - (leave (G_ "~a: unrecognized options~%") opts))))))) + (catch 'system-error + (lambda () + (set-thread-name "guix substitute")) + (const #t)) ;GNU/Hurd lacks 'prctl' + + (with-networking + (with-error-handling ; for signature errors + (match args + (("--query") + (let ((acl (current-acl))) + (let loop ((command (read-line))) + (or (eof-object? command) + (begin + (process-query reply-port command + #:cache-urls (substitute-urls) + #:acl acl) + (loop (read-line))))))) + (("--substitute") + ;; Download STORE-PATH and store it as a Nar in file DESTINATION. + ;; Specify the number of columns of the terminal so the progress + ;; report displays nicely. + (parameterize ((current-terminal-columns (client-terminal-columns)= )) + (let loop () + (match (read-line) + ((? eof-object?) + #t) + ((=3D string-tokenize ("substitute" store-path destination)) + (process-substitution reply-port store-path destination + #:cache-urls (substitute-urls) + #:acl (current-acl) + #:deduplicate? deduplicate? + #:print-build-trace? + print-build-trace?) + (loop)))))) + ((or ("-V") ("--version")) + (show-version-and-exit "guix substitute")) + (("--help") + (show-help)) + (opts + (leave (G_ "~a: unrecognized options~%") opts)))))) =20 ;;; Local Variables: ;;; eval: (put 'with-timeout 'scheme-indent-function 1) diff --git a/nix/libstore/build.cc b/nix/libstore/build.cc index 4f486f0822..5697ae5a43 100644 --- a/nix/libstore/build.cc +++ b/nix/libstore/build.cc @@ -3158,13 +3158,13 @@ void SubstitutionGoal::finished() void SubstitutionGoal::handleChildOutput(int fd, const string & data) { if (verbosity >=3D settings.buildVerbosity - && fd =3D=3D substituter->builderOut.readSide) { + && fd =3D=3D substituter->fromAgent.readSide) { writeToStderr(data); /* Don't write substitution output to a log file for now. We probably should, though. */ } =20 - if (fd =3D=3D substituter->fromAgent.readSide) { + if (fd =3D=3D substituter->builderOut.readSide) { /* DATA may consist of several lines. Process them one by one. */ string input =3D data; while (!input.empty()) { diff --git a/nix/libstore/local-store.cc b/nix/libstore/local-store.cc index c304e2ddd1..675d1ba66f 100644 --- a/nix/libstore/local-store.cc +++ b/nix/libstore/local-store.cc @@ -780,8 +780,8 @@ Path LocalStore::queryPathFromHashPart(const string & h= ashPart) }); } =20 -/* Read a line from the substituter's stdout, while also processing - its stderr. */ +/* Read a line from the substituter's reply file descriptor, while also + processing its stderr. */ string LocalStore::getLineFromSubstituter(Agent & run) { string res, err; @@ -802,9 +802,9 @@ string LocalStore::getLineFromSubstituter(Agent & run) } =20 /* Completely drain stderr before dealing with stdout. */ - if (FD_ISSET(run.builderOut.readSide, &fds)) { + if (FD_ISSET(run.fromAgent.readSide, &fds)) { char buf[4096]; - ssize_t n =3D read(run.builderOut.readSide, (unsigned char *) = buf, sizeof(buf)); + ssize_t n =3D read(run.fromAgent.readSide, (unsigned char *) b= uf, sizeof(buf)); if (n =3D=3D -1) { if (errno =3D=3D EINTR) continue; throw SysError("reading from substituter's stderr"); @@ -822,9 +822,9 @@ string LocalStore::getLineFromSubstituter(Agent & run) } =20 /* Read from stdout until we get a newline or the buffer is empty.= */ - else if (FD_ISSET(run.fromAgent.readSide, &fds)) { + else if (FD_ISSET(run.builderOut.readSide, &fds)) { unsigned char c; - readFull(run.fromAgent.readSide, (unsigned char *) &c, 1); + readFull(run.builderOut.readSide, (unsigned char *) &c, 1); if (c =3D=3D '\n') { if (!err.empty()) printMsg(lvlError, "substitute: " + err); return res; diff --git a/tests/substitute.scm b/tests/substitute.scm index 697abc4684..21b513e1d8 100644 --- a/tests/substitute.scm +++ b/tests/substitute.scm @@ -1,6 +1,6 @@ ;;; GNU Guix --- Functional package management for GNU ;;; Copyright =C2=A9 2014 Nikita Karetnikov -;;; Copyright =C2=A9 2014, 2015, 2017, 2018, 2019 Ludovic Court=C3=A8s +;;; Copyright =C2=A9 2014, 2015, 2017, 2018, 2019, 2021 Ludovic Court=C3= =A8s ;;; ;;; This file is part of GNU Guix. ;;; @@ -198,7 +198,7 @@ a file for NARINFO." =20 ;; Never use file descriptor 4, unlike what happens when invoked by the ;; daemon. -(%error-to-file-descriptor-4? #f) +(%reply-file-descriptor #f) =20 (test-equal "query narinfo without signature" --=20 2.31.1 --=-=-=--