Connection reuse for substitutes breaks with gzip

DoneSubmitted by Ludovic Courtès.
Details
3 participants
  • Léo Le Bouter
  • Ludovic Courtès
  • Bonface Munyoki K.
Owner
unassigned
Severity
important
Merged with
L
L
Ludovic Courtès wrote on 6 Mar 15:47 +0100
(address . bug-guix@gnu.org)
878s70ibke.fsf@inria.fr
As of commit cdc688c5ee106b7ee2547e4abd74ab81d7702d3d, it seems that theconnection reuse code for substitutes breaks if you’re fetching gzipsubstitutes.
I tweaked ‘narinfo-best-uri’ to always choose gzip, and here’s what I get:
Toggle snippet (68 lines)$ ./pre-inst-env guix build vigra inkscape eigen pt-scotch accepted connection from pid 20839, user ludo69.6 MB will be downloaded: /gnu/store/si36xnajxjnx7v6ywd7qyhyv8ar9aymn-vigra-1.11.1 /gnu/store/0fcjk788gj7k6gsf3zsx8j8lyw6w896b-inkscape-1.0.2substituting /gnu/store/0fcjk788gj7k6gsf3zsx8j8lyw6w896b-inkscape-1.0.2...downloading from https://ci.guix.gnu.org/nar/gzip/0fcjk788gj7k6gsf3zsx8j8lyw6w896b-inkscape-1.0.2 ... inkscape-1.0.2 38.6MiB 16.8MiB/s 00:02 [##################] 100.0%
substituting /gnu/store/si36xnajxjnx7v6ywd7qyhyv8ar9aymn-vigra-1.11.1...Backtrace:In guix/ui.scm: 2164:12 19 (run-guix-command _ . _)In guix/scripts/substitute.scm: 664:2 18 (guix-substitute . _)In unknown file: 17 (with-continuation-barrier #<procedure thunk ()>)In ice-9/boot-9.scm: 1736:10 16 (with-exception-handler _ _ #:unwind? _ #:unwind-for-type _)In unknown file: 15 (apply-smob/0 #<thunk 7fa67ce511c0>)In ice-9/boot-9.scm: 1736:10 14 (with-exception-handler _ _ #:unwind? _ #:unwind-for-type _) 1736:10 13 (with-exception-handler _ _ #:unwind? _ #:unwind-for-type _) 1731:15 12 (with-exception-handler #<procedure 7fa67c302390 at ice-9/boot-9.scm:1815:7 (exn)> _ #:unwind? _ # _)In guix/scripts/substitute.scm: 713:17 11 (_) 414:7 10 (process-substitution _ "/gnu/store/si36xnajxjnx7v6ywd7qyhyv8ar9aymn-vigra-1.11.1" #:cache-urls _ #:acl …)In ice-9/boot-9.scm: 1736:10 9 (with-exception-handler _ _ #:unwind? _ #:unwind-for-type _)In guix/scripts/substitute.scm: 423:9 8 (_)In ice-9/boot-9.scm: 1731:15 7 (with-exception-handler #<procedure 7fa67c42edb0 at ice-9/boot-9.scm:1815:7 (exn)> _ #:unwind? _ # _) 1669:16 6 (raise-exception _ #:continuable? _) 1667:16 5 (raise-exception _ #:continuable? _) 1669:16 4 (raise-exception _ #:continuable? _) 1764:13 3 (_ #<&compound-exception components: (#<&error> #<&irritants irritants: (http-version "_'$Àçv\x8b\x8f7…>) 1669:16 2 (raise-exception _ #:continuable? _) 1667:16 1 (raise-exception _ #:continuable? _) 1669:16 0 (raise-exception _ #:continuable? _)
ice-9/boot-9.scm:1669:16: In procedure raise-exception:Bad http-version header component: _'$Àçv‹7$H?
Backtrace:In ice-9/boot-9.scm: 1736:10 4 (with-exception-handler _ _ #:unwind? _ #:unwind-for-type _)In unknown file: 3 (apply-smob/0 #<thunk 7fa67e9cb520>)In ice-9/boot-9.scm: 718:2 2 (call-with-prompt _ _ #<procedure default-prompt-handler (k proc)>)In ice-9/eval.scm: 619:8 1 (_ #(#(#<directory (guile-user) 7fa67e9cec80>)))In guix/ui.scm: 2164:12 0 (run-guix-command _ . _)
guix/ui.scm:2164:12: In procedure run-guix-command:Bad http-version header component: _'$Àçv‹7$H?
substitution of /gnu/store/si36xnajxjnx7v6ywd7qyhyv8ar9aymn-vigra-1.11.1 failedguix build: error: some substitutes for the outputs of derivation `/gnu/store/k32m5dcf31psvx66n95icxbvyimrjrk5-vigra-1.11.1.drv' failed (usually happens due to networking issues); try `--fallback' to build derivation from source $ wget -qO - https://ci.guix.gnu.org/nar/gzip/si36xnajxjnx7v6ywd7qyhyv8ar9aymn-vigra-1.11.1 | gunzip > /dev/null$ echo $?0--8<---------------cut here---------------end--------------->8---
Ludo’.
L
L
Ludovic Courtès wrote on 9 Mar 12:05 +0100
control message for bug #46967
(address . control@debbugs.gnu.org)
87a6rca8p9.fsf@gnu.org
severity 46967 importantquit
L
L
Ludovic Courtès wrote on 9 Mar 12:07 +0100
Re: bug#46967: Connection reuse for substitutes breaks with gzip
(address . 46967@debbugs.gnu.org)
8735x4a8m8.fsf@gnu.org
Ludovic Courtès <ludo@gnu.org> skribis:
Toggle quote (4 lines)> As of commit cdc688c5ee106b7ee2547e4abd74ab81d7702d3d, it seems that the> connection reuse code for substitutes breaks if you’re fetching gzip> substitutes.
Here’s a simple reproducer that systematically fails after the firstdownload:
Toggle snippet (32 lines)$ ./pre-inst-env guile ~/src/guix-debugging/http-pipelining-gzip.scm
;;; (fetch 164664960)Backtrace:In ice-9/boot-9.scm: 1736:10 11 (with-exception-handler _ _ #:unwind? _ #:unwind-for-type _)In unknown file: 10 (apply-smob/0 #<thunk 7f9bf630c520>)In ice-9/boot-9.scm: 718:2 9 (call-with-prompt _ _ #<procedure default-prompt-handler (k proc)>)In ice-9/eval.scm: 619:8 8 (_ #(#(#<directory (guile-user) 7f9bf630fc80>)))In ice-9/boot-9.scm: 2806:4 7 (save-module-excursion _) 4351:12 6 (_)In /home/ludo/src/guix-debugging/http-pipelining-gzip.scm: 18:4 5 (_)In guix/http-client.scm: 116:21 4 (http-fetch _ #:port _ #:text? _ #:buffered? _ #:open-connection _ #:keep-alive? _ # _ #:headers _ # _)In web/client.scm: 526:24 3 (http-request _ #:body _ #:verify-certificate? _ #:port _ #:method _ #:version _ #:keep-alive? _ # _ # …)In web/response.scm: 198:31 2 (read-response #<input-output: string 7f9bf36c6000>)In web/http.scm: 1194:12 1 (read-response-line _) 252:2 0 (parse-http-version _ _ _)
web/http.scm:252:2: In procedure parse-http-version:Bad http-version header component: ì½

Ludo’.
(use-modules (guix http-client) ((guix build download) #:select (open-connection-for-uri)) (guix utils) ((guix serialization) #:select (dump-port*)) (web uri) (web request) (web response) (srfi srfi-1)) (define %base-url "https://ci.guix.gnu.org") (define port (open-connection-for-uri (string->uri %base-url))) (let loop () (define-values (input size) (http-fetch (string->uri "https://ci.guix.gnu.org/nar/gzip/0fcjk788gj7k6gsf3zsx8j8lyw6w896b-inkscape-1.0.2") #:port port #:text? #f #:open-connection open-connection-for-uri ;/cached #:keep-alive? #t #:buffered? #f)) (define-values (decompressed pids) (decompressed-port 'gzip input)) (setvbuf decompressed 'none) (call-with-output-file "/tmp/out" (lambda (output) (setvbuf output 'none) (dump-port* decompressed output (pk 'fetch 164664960)))) ;size of compressed nar (unless (every (compose zero? cdr waitpid) pids) (error "decomp error")) (loop))
L
L
Ludovic Courtès wrote on 9 Mar 14:13 +0100
(address . 46967@debbugs.gnu.org)
87r1ko8o7v.fsf@gnu.org
Even simpler:
Toggle snippet (39 lines)$ ./pre-inst-env guile ~/src/guix-debugging/http-pipelining-gzip.scm
;;; (port #<input-output: file 7fced4c20000>)
;;; (input #<input: file 7fced4c8ef50>)
;;; (drain "")
;;; (fetch 16397)
;;; (port #<input-output: file 7fced4c20000>)Backtrace:In ice-9/boot-9.scm: 1736:10 11 (with-exception-handler _ _ #:unwind? _ #:unwind-for-type _)In unknown file: 10 (apply-smob/0 #<thunk 7fced7866520>)In ice-9/boot-9.scm: 718:2 9 (call-with-prompt _ _ #<procedure default-prompt-handler (k proc)>)In ice-9/eval.scm: 619:8 8 (_ #(#(#<directory (guile-user) 7fced7869c80>)))In ice-9/boot-9.scm: 2806:4 7 (save-module-excursion _) 4351:12 6 (_)In /home/ludo/src/guix-debugging/http-pipelining-gzip.scm: 18:4 5 (_)In guix/http-client.scm: 116:21 4 (http-fetch _ #:port _ #:text? _ #:buffered? _ #:open-connection _ #:keep-alive? _ # _ #:headers _ # _)In web/client.scm: 526:24 3 (http-request _ #:body _ #:verify-certificate? _ #:port _ #:method _ #:version _ #:keep-alive? _ # _ # …)In web/response.scm: 198:31 2 (read-response #<input-output: string 7fced4c20000>)In web/http.scm: 1194:12 1 (read-response-line _) 252:2 0 (parse-http-version _ _ _)
web/http.scm:252:2: In procedure parse-http-version:Bad http-version header component: <!DOCTYPE
(use-modules (guix http-client) ((guix build download) #:select (open-connection-for-uri)) (guix utils) ((guix serialization) #:select (dump-port*)) (web uri) (web request) (web response) (srfi srfi-1)) (define %base-url "https://guix.gnu.org") (define port (open-connection-for-uri (string->uri %base-url))) (let loop () (define-values (input size) (http-fetch (string->uri %base-url) #:port (pk 'port port) #:text? #f #:open-connection open-connection-for-uri ;/cached #:keep-alive? #t #:buffered? #f)) (define-values (decompressed pids) (filtered-port '("/run/current-system/profile/bin/cat") (pk 'input input))) (dump-port* decompressed (%make-void-port "w") (pk 'fetch size)) (unless (every (compose zero? cdr waitpid) pids) (error "decomp error")) (loop))
L
L
Léo Le Bouter wrote on 10 Mar 02:28 +0100
Connection reuse for substitutes breaks with gzip
(address . 46967@debbugs.gnu.org)
7a9c7364e8d1d5262dc3dfcd922bb537d9ca4b7f.camel@zaclys.net
I am also affected by this issue (non-deterministically) it seems.Requires me to run 'guix system reconfigure ..' several times forthings to work.
-----BEGIN PGP SIGNATURE-----
iQIzBAABCgAdFiEEFIvLi9gL+xax3g6RRaix6GvNEKYFAmBIINcACgkQRaix6GvNEKYaHA//UJZ2zKzed5xBPd20IiJRuugBx8P9k/1TyxlaNFFLAZKu7ms03IE4KPIJz0h6f/MbzCh7Je5lucZliW0zKBzBMgBsOA/px+QapCBiHHQIVqYnqY4WVg26Gr5smgliLYEWLZ/dCf6bKqh50R8rtfVyMaoOFPihYpApFH7GPr9SNzkALamJfiUa1Sm0RonDielTpMavcG8Ziw5CgvfrkazoAtt5fGum99X8eCrKMIHKfnlpymL+F/S58YK07bsTNKKz2q1qk9jhfVBxbrNgMzwEYpN4SXQH/psQOsPpSmcJY4snyIlyUyaBArYgSy2VpijXVjC3KZ4YNJLGRoTmc9FCLWHrhc4Df3dwdH7RR4bg5sTBJSaKpF9uXx3/SqOifxYPyckBn+WriTVRzvIMW79j6YYNvThqZxTAHitZTqn9ia8eDNrql/UWLocrcSW+hoQMi9NcAGTORsA5GVfA480rOJvcARtdV/0KNz2+itVXsFO2HHIvimOLQh8CZc0tzzXu76krRRm7IDvecmdFV4TZw4FNkVsItlcfbEh0khLmKx6+437mnEQ5D5K/pP0bJXXZ8+MEUALbLcyC2Kq/wnkdP3XHD7gBQG1CUNmUuUKLjQ0kadT9t1eMOvAs06qgva0GgJ5dTx7fbqr6mGndcfM7KgffBtIN6VzyIBGU/5gpI3U==F1+b-----END PGP SIGNATURE-----

L
L
Ludovic Courtès wrote on 11 Mar 09:26 +0100
(address . 46967@debbugs.gnu.org)
87eegmxfi5.fsf@gnu.org
Turns out GnuTLS has a buffer for the record layer attached to thesession. After the first GET in the main process, it looks like this:
Toggle snippet (12 lines)(gdb) p session->internals.record_buffer$9 = {head = 0x7f7370, tail = 0x7f7370, length = 1, byte_length = 16219}(gdb) p *session->internals.record_buffer->head$10 = {next = 0x0, prev = 0x0, mark = 165, msg = { data = 0x7f73c0 "HTTP/1.1 200 OK\r\nServer: nginx\r\nDate: Wed, 10 Mar 2021 21:23:44 GMT\r\nContent-Type: text/html\r\nContent-Length: 16397\r\nConnection: keep-alive\r\nAccept-Ranges: bytes\r\n\r\n<!DOCTYPE html><html lang=\"en\"><hea"..., size = 16384}, maximum_size = 18751, uhead_mark = 0, type = GNUTLS_APPLICATION_DATA, record_sequence = 1, epoch = 0, htype = 72, handshake_sequence = 0}(gdb) p *(&session->internals.record_buffer->head.msg.data[165])$11 = 60 '<'(gdb) p (&session->internals.record_buffer->head.msg.data[165])$12 = (unsigned char *) 0x7f7465 "<!DOCTYPE html><html lang=\"en\"><head><title>GNU's advanced distro and transactional package manager — GNU Guix</title><meta charset=\"UTF-8\" /><meta name=\"keywords\" content=\"GNU, Linux, Unix, Free s"...
IOW, the main process hasn’t consumed the body of the HTTP response.
This is because with ‘filtered-port’, the input port is dumped from achild process, not from the calling process.
To be continued…
Ludo’.
L
L
Ludovic Courtès wrote on 12 Mar 11:42 +0100
(address . 46967@debbugs.gnu.org)
87r1kkvekm.fsf@gnu.org
Hi!
Ludovic Courtès <ludo@gnu.org> skribis:
Toggle quote (3 lines)> This is because with ‘filtered-port’, the input port is dumped from a> child process, not from the calling process.
I decided to take a heavy-handed solution to that problem, which is toaugment Guile-zlib with an interface for gzip compression/decompressionnot restricted to file ports (‘call-with-gzip-output-port’ & co. arerestricted to file ports):
https://notabug.org/guile-zlib/guile-zlib/commit/b899ac2fecf91475da1eba7e7b24708ea8b5fb73
That way, we can change ‘decompressed-port’ in (guix utils) to performin-process decompression for ‘gzip’, like it does for zstd and lzip.
If everything goes well, I’ll cut a Guile-zlib release today and updateGuix accordingly.
Ludo’.
L
L
Ludovic Courtès wrote on 12 Mar 16:08 +0100
(address . 46967@debbugs.gnu.org)
87sg50tnni.fsf@gnu.org
Ludovic Courtès <ludo@gnu.org> skribis:
Toggle quote (10 lines)> I decided to take a heavy-handed solution to that problem, which is to> augment Guile-zlib with an interface for gzip compression/decompression> not restricted to file ports (‘call-with-gzip-output-port’ & co. are> restricted to file ports):>> https://notabug.org/guile-zlib/guile-zlib/commit/b899ac2fecf91475da1eba7e7b24708ea8b5fb73>> That way, we can change ‘decompressed-port’ in (guix utils) to perform> in-process decompression for ‘gzip’, like it does for zstd and lzip.
Done in a04aef2430645357d7796969d4b6453478ff8a3f!
I’ll update the ‘guix’ package so people on Guix System can get the fix,and then we can close this bug.
Ludo’.
L
L
Ludovic Courtès wrote on 12 Mar 16:39 +0100
control message for bug #46967
(address . control@debbugs.gnu.org)
87k0qcs7nr.fsf@gnu.org
merge 46967 47055quit
L
L
Ludovic Courtès wrote on 14 Mar 11:17 +0100
Re: bug#46967: Connection reuse for substitutes breaks with gzip
(address . 46967-done@debbugs.gnu.org)
87mtv6m44e.fsf@gnu.org
Ludovic Courtès <ludo@gnu.org> skribis:
Toggle quote (17 lines)> Ludovic Courtès <ludo@gnu.org> skribis:>>> I decided to take a heavy-handed solution to that problem, which is to>> augment Guile-zlib with an interface for gzip compression/decompression>> not restricted to file ports (‘call-with-gzip-output-port’ & co. are>> restricted to file ports):>>>> https://notabug.org/guile-zlib/guile-zlib/commit/b899ac2fecf91475da1eba7e7b24708ea8b5fb73>>>> That way, we can change ‘decompressed-port’ in (guix utils) to perform>> in-process decompression for ‘gzip’, like it does for zstd and lzip.>> Done in a04aef2430645357d7796969d4b6453478ff8a3f!>> I’ll update the ‘guix’ package so people on Guix System can get the fix,> and then we can close this bug.
Done in 8154beffd8c121e953a7c4cd75c3eebfcc073a9a, closing!
Ludo’.
Closed
B
B
Bonface Munyoki K. wrote on 16 Mar 19:34 +0100
(address . 46967@debbugs.gnu.org)(address . ludo@gnu.org)
86lfant0bm.fsf@bonfacemunyoki.com
Ludovic Courtès <ludo@gnu.org> writes:
Toggle quote (21 lines)> Ludovic Courtès <ludo@gnu.org> skribis: > >> Ludovic Courtès <ludo@gnu.org> skribis: >> >>> I decided to take a heavy-handed solution to that problem, which is to >>> augment Guile-zlib with an interface for gzip compression/decompression >>> not restricted to file ports (‘call-with-gzip-output-port’ & co. are >>> restricted to file ports): >>> >>> https://notabug.org/guile-zlib/guile-zlib/commit/b899ac2fecf91475da1eba7e7b24708ea8b5fb73 >>> >>> That way, we can change ‘decompressed-port’ in (guix utils) to perform >>> in-process decompression for ‘gzip’, like it does for zstd and lzip. >> >> Done in a04aef2430645357d7796969d4b6453478ff8a3f! >> >> I’ll update the ‘guix’ package so people on Guix System can get the fix, >> and then we can close this bug. > > Done in 8154beffd8c121e953a7c4cd75c3eebfcc073a9a, closing! >
Very far fetched but could this be the cause of: https://lists.gnu.org/archive/html/help-guix/2021-03/msg00052.html? -- Bonface M. K. D4F09EB110177E03C28E2FE1F5BBAE1E0392253F Humble GNU Emacs User / Bearer of scheme-y parens Curator: https://upbookclub.com / Twitter: @BonfaceKilz
-----BEGIN PGP SIGNATURE-----
iQJKBAEBCAA0FiEE1PCesRAXfgPCji/h9buuHgOSJT8FAmBQ+h8WHG1lQGJvbmZhY2VtdW55b2tpLmNvbQAKCRD1u64eA5IlP0MLD/9o/jhS4lrDVnxoPmkSoKBQoB+YYfFatnOReDIbtdutfttk9CqoLMmV86kEbKU1BQMeYGuCgUbO4WZdP40bnW+2w+V3gPRyc6VLBxOMPpcgP7BVCInNAE+8TV5ZzMaINstxnp2Oe6qRNtiGoue33eBX7X1JJssOLqLkrksMVzZpysWgS93g7x9woFmDFxTDAPoHE9iGfbnoDdmZQtg1a6a8AFhhfMCMLMjtNGFEwBaeNzCk6dIbU91L+DXTBVzU3CMZAZhihISPLj2rNUTTg1EiHLL0/k9uMxWYWcqIb5wgf8mVFNsSiFq9O+cfA86X2HFbGOgRtGqhNmY3JkZjX/xLYIoYPZMP2Tt3BwCniHYf8EaSBVxcvTySBE6h5yAuUryAs80fPuR2JCA4UyGryBGgrnZIwvSumGyQwNqS4SxnDvzIEEbUFS6XB02Vx/+WAS1IbJJDqQj+cgSh4lWfWk8Uk00ew2XBM5JfiqsFNdazM+0ikEFpEisMpT+MsksJDBUpuuz3756xGlY1JawUPB2RBe1XBo5QXHO0/BHPtIdZUamRKstF1l0j6iJEoLzpwWqBAAsdm3TOacJWZpcQ3vjHjldqtcxxN0qhhZkxKygu/NqPCcphmywI5BYiBreg8Wyfq7uA1fGJAUNFP0y+sITYKLemc/gCm0+4WooI5lzIIg===OP13-----END PGP SIGNATURE-----
L
L
Ludovic Courtès wrote on 18 Mar 10:32 +0100
(name . Bonface Munyoki K.)(address . me@bonfacemunyoki.com)(address . 46967@debbugs.gnu.org)
87wnu4vmbt.fsf@gnu.org
Bonface Munyoki K. <me@bonfacemunyoki.com> skribis:
Toggle quote (27 lines)> Ludovic Courtès <ludo@gnu.org> writes:>>> Ludovic Courtès <ludo@gnu.org> skribis:>>>>> Ludovic Courtès <ludo@gnu.org> skribis:>>>>>>> I decided to take a heavy-handed solution to that problem, which is to>>>> augment Guile-zlib with an interface for gzip compression/decompression>>>> not restricted to file ports (‘call-with-gzip-output-port’ & co. are>>>> restricted to file ports):>>>>>>>> https://notabug.org/guile-zlib/guile-zlib/commit/b899ac2fecf91475da1eba7e7b24708ea8b5fb73>>>>>>>> That way, we can change ‘decompressed-port’ in (guix utils) to perform>>>> in-process decompression for ‘gzip’, like it does for zstd and lzip.>>>>>> Done in a04aef2430645357d7796969d4b6453478ff8a3f!>>>>>> I’ll update the ‘guix’ package so people on Guix System can get the fix,>>> and then we can close this bug.>>>> Done in 8154beffd8c121e953a7c4cd75c3eebfcc073a9a, closing!>>>> Very far fetched but could this be the cause of:> https://lists.gnu.org/archive/html/help-guix/2021-03/msg00052.html?
Yes; their log shows:
Toggle snippet (4 lines)ice-9/boot-9.scm:1669:16: In procedure raise-exception:Bad http-version header component: ¡_¨””8ᗯñÿ
which is typical of this bug.
Ludo’.
?
Your comment

Commenting via the web interface is currently disabled.

To comment on this conversation send email to 46967@debbugs.gnu.org