Subject: [Cuirass] ‘remote-worker’ doesn’t handle substitution crash

From: Ludovic Courtès <[email-masked]>
Date: Mon, 07 Oct 2024 16:04:27 +0200

‘cuirass remote-worker’ worker fibers may crash upon substitution
failure:

--8<---------------cut here---------------start------------->8---
2024-10-03 04:56:28 @ substituter-started /gnu/store/mqmlzbzarz2s56khlkl7xk20xlsxdf04-openpmix-4.2.8 substitute
2024-10-03 04:56:28 Downloading http://141.80.167.131/nar/lzip/mqmlzbzarz2s56khlkl7xk20xlsxdf04-openpmix-4.2.8...
2024-10-03 04:56:28 
2024-10-03 04:56:28 ESC[K openpmix-4.2.8                              803KiB/s 00:00 | 64KiB transferred
2024-10-03 04:56:28 ESC[K openpmix-4.2.8                             669KiB/s 00:00 | 192KiB transferred
2024-10-03 04:56:29 ESC[K openpmix-4.2.8                             743KiB/s 00:01 | 384KiB transferred
2024-10-03 04:56:29 ESC[K openpmix-4.2.8                             785KiB/s 00:01 | 576KiB transferred
2024-10-03 04:56:29 ESC[K openpmix-4.2.8                             730KiB/s 00:01 | 704KiB transferred
2024-10-03 04:56:29 ESC[K openpmix-4.2.8                             733KiB/s 00:01 | 896KiB transferred
2024-10-03 04:56:30 ESC[K openpmix-4.2.8                             712KiB/s 00:01 | 1.0MiB transferred
2024-10-03 04:56:30 ESC[K openpmix-4.2.8                             810KiB/s 00:02 | 1.3MiB transferred
2024-10-03 04:56:30 ESC[K openpmix-4.2.8                             822KiB/s 00:02 | 1.5MiB transferred
2024-10-03 04:56:30 ESC[K openpmix-4.2.8                             836KiB/s 00:02 | 1.8MiB transferred
2024-10-03 04:56:31 ESC[K openpmix-4.2.8                             862KiB/s 00:02 | 2.0MiB transferred
2024-10-03 04:56:31 ESC[K openpmix-4.2.8                             908KiB/s 00:03 | 2.3MiB transferred
2024-10-03 04:56:31 ESC[K openpmix-4.2.8                             910KiB/s 00:03 | 2.5MiB transferred
2024-10-03 04:56:31 ESC[K openpmix-4.2.8                             918KiB/s 00:03 | 2.8MiB transferred
2024-10-03 04:56:32 ESC[K openpmix-4.2.8                             907KiB/s 00:03 | 2.9MiB transferred
2024-10-03 04:56:37 ESC[K openpmix-4.2.8                             915KiB/s 00:04 | 3.2MiB transferredc4xY04X9: ping tcp://141.80.167.131:5555.
2024-10-03 04:56:40 bYEhaJ5x: ping tcp://141.80.167.131:5555.
2024-10-03 04:56:44 c4xY04X9: derivation /gnu/store/m33kmw9g6sbrf5bqhggr2d44767jlaqc-ecl-cl-gobject-introspection-0.3-4.4908a84.drv build succeeded.
2024-10-03 04:56:45 c4xY04X9: done building '/gnu/store/m33kmw9g6sbrf5bqhggr2d44767jlaqc-ecl-cl-gobject-introspection-0.3-4.4908a84.drv' and its dependencies
2024-10-03 04:56:45 c4xY04X9: request work.
2024-10-03 04:56:54 
2024-10-03 04:56:54 ESC[K openpmix-4.2.8                             132KiB/s 00:26 | 3.4MiB transferredBacktrace:
2024-10-03 04:56:54 In guix/serialization.scm:
2024-10-03 04:56:54    524:24 19 (_ "/gnu/store/mqmlzbzarz2s56khlkl7xk20xlsxdf04-openpm?" ?)
2024-10-03 04:56:54 In guix/store/deduplication.scm:
2024-10-03 04:56:54     323:4 18 (dump-file/deduplicate "/gnu/store/mqmlzbzarz2s56khlkl?" ?)
2024-10-03 04:56:54 In ice-9/ports.scm:
2024-10-03 04:56:54    433:17 17 (call-with-output-file _ _ #:binary _ #:encoding _)
2024-10-03 04:56:54 In guix/store/deduplication.scm:
2024-10-03 04:56:54    327:11 16 (_ _)
2024-10-03 04:56:54 In guix/serialization.scm:
2024-10-03 04:56:54     260:6 15 (dump _)
2024-10-03 04:56:54    246:21 14 (dump #<input: string 7f1dffcc6070> #<output: string 7?> ?)
2024-10-03 04:56:54 In unknown file:
2024-10-03 04:56:54           13 (get-bytevector-n! #<input: string 7f1dffcc6070> # 0 #)
2024-10-03 04:56:54 In guix/store/deduplication.scm:
2024-10-03 04:56:54    270:22 12 (read! #vu8(204 115 167 239 27 50 83 151 188 18 206 # ?) ?)
2024-10-03 04:56:54 In unknown file:
2024-10-03 04:56:54           11 (get-bytevector-n! #<input: string 7f1dffca7d20> # 0 #)
2024-10-03 04:56:54 In gcrypt/hash.scm:
2024-10-03 04:56:54    226:14 10 (read! #vu8(204 115 167 239 27 50 83 151 188 18 206 # ?) ?)
2024-10-03 04:56:54 In unknown file:
2024-10-03 04:56:54            9 (get-bytevector-n! #<input: string 7f1dffca7d90> # 0 #)
2024-10-03 04:56:54 In lzlib.scm:
2024-10-03 04:56:54    515:11  8 (lzread! #<lz-decoder 7f1dffcadb40> #<input: string 7f?> ?)
2024-10-03 04:56:54    364:12  7 (_ _ _ _ _)
2024-10-03 04:56:54 In ice-9/boot-9.scm:
2024-10-03 04:56:54   1685:16  6 (raise-exception _ #:continuable? _)
2024-10-03 04:56:54   1683:16  5 (raise-exception _ #:continuable? _)
2024-10-03 04:56:54   1685:16  4 (raise-exception _ #:continuable? _)
2024-10-03 04:56:54   1780:13  3 (_ #<&compound-exception components: (#<&error> #<&irri?>)
2024-10-03 04:56:54   1685:16  2 (raise-exception _ #:continuable? _)
2024-10-03 04:56:54   1683:16  1 (raise-exception _ #:continuable? _)
2024-10-03 04:56:54   1685:16  0 (raise-exception _ #:continuable? _)
2024-10-03 04:56:54 
2024-10-03 04:56:54 ice-9/boot-9.scm:1685:16: In procedure raise-exception:
2024-10-03 04:56:54 Throw to key `lzlib-error' with args `(lz-decompress-read 5)'.
2024-10-03 04:56:54 fetching path `/gnu/store/mqmlzbzarz2s56khlkl7xk20xlsxdf04-openpmix-4.2.8' (empty status)
2024-10-03 04:56:54 @ substituter-failed /gnu/store/mqmlzbzarz2s56khlkl7xk20xlsxdf04-openpmix-4.2.8  fetching path `/gnu/store/mqmlzbzarz2s56khlkl7xk20xlsxdf04-openpmix-4.2.8' (empty status)
2024-10-03 04:56:54 fetching path `/gnu/store/p4wibh2f8awvlh1x7pdxxfbi349px00i-opensm-3.3.24'...
2024-10-03 04:56:54 Uncaught exception in task:
2024-10-03 04:56:54 In fibers.scm:
2024-10-03 04:56:54     172:8 11 (_)
2024-10-03 04:56:54 In cuirass/scripts/remote-worker.scm:
2024-10-03 04:56:54    512:20 10 (_)
2024-10-03 04:56:54 In ice-9/boot-9.scm:
2024-10-03 04:56:54   1752:10  9 (with-exception-handler _ _ #:unwind? _ # _)
2024-10-03 04:56:54 In guix/store.scm:
2024-10-03 04:56:54    689:37  8 (thunk)
2024-10-03 04:56:54 In cuirass/scripts/remote-worker.scm:
2024-10-03 04:56:54    335:14  7 (_ #<store-connection 256.100 7f5c22a0eaa0>)
2024-10-03 04:56:54 In ice-9/boot-9.scm:
2024-10-03 04:56:54   1752:10  6 (with-exception-handler _ _ #:unwind? _ # _)
2024-10-03 04:56:54 In guix/store.scm:
2024-10-03 04:56:54   1449:15  5 (_ #<store-connection 256.100 7f5c22a0eaa0> _ _)
2024-10-03 04:56:54    746:11  4 (process-stderr #<store-connection 256.100 7f5c22a0eaa0> ?)
2024-10-03 04:56:54 In guix/serialization.scm:
2024-10-03 04:56:54      79:6  3 (read-int #<closed: file 7f5bf743e230>)
2024-10-03 04:56:54 In ice-9/boot-9.scm:
2024-10-03 04:56:54   1685:16  2 (raise-exception _ #:continuable? _)
2024-10-03 04:56:54   1683:16  1 (raise-exception _ #:continuable? _)
2024-10-03 04:56:54   1685:16  0 (raise-exception _ #:continuable? _)
2024-10-03 04:56:54 ice-9/boot-9.scm:1685:16: In procedure raise-exception:
2024-10-03 04:56:54 ERROR:
2024-10-03 04:56:54   1. &nar-error:
2024-10-03 04:56:54       file: #f
2024-10-03 04:56:54       port: #<closed: file 7f5bf743e230>
2024-10-03 04:56:57 c4xY04X9: preparing to build derivation `/gnu/store/sjbncjxsvrsqwiz55w5035cg2y3q4hkv-sane-backends-1.3.1.drv' (system: i686-linux)
--8<---------------cut here---------------end--------------->8---

This is with cuirass-1.2.0-8.b225542.

The root cause though is that ‘guix substitute’ itself crashes badly
instead of returning a relevant status string to guix-daemon.

Ludo’.