Subject: bug#41237: guix deploy hangs when a file-system-device is set to a UUID

From: Ludovic Courtès <[email-masked]>
Date: Wed, 03 Jun 2020 16:56:19 +0200

Hi Brice,

Brice Waegeneire <[email-masked]> skribis:

> When manually executing the second 'remote-assertion.scm' file, the one
> containing the 'find-partition-by-uuid-bit', it hangs indefinitely, I 
> have
> attached it's strace to this email.
>
> $ cat /gnu/store/wzvn8r2z7lnf5mqzagxzcb64wr69kgk4-remote-assertion.scm
> (eval-when (expand load eval) (let ((extensions (quote ())) (prepend 
> (lambda (items lst) (let loop ((items items) (lst lst)) (if (null? 
> items) lst (loop (cdr items) (cons (car items) (delete (car items) 
> lst)))))))) (set! %load-path (prepend (cons 
> "/gnu/store/7jpv8kkq13k9xjazrkpq3cm1vz4m5arv-module-import" (map (lambda 
> (extension) (string-append extension "/share/guile/site/" 
> (effective-version))) extensions)) %load-path)) (set! 
> %load-compiled-path (prepend (cons 
> "/gnu/store/gac0pvsnc0zvsfxizfqjgg9lig8sf200-module-import-compiled" 
> (map (lambda (extension) (string-append extension "/lib/guile/" 
> (effective-version) "/site-ccache")) extensions)) 
> %load-compiled-path))))(begin (use-modules (gnu build file-systems) (gnu 
> system uuid)) (define uuid (string->uuid "B5DE-B0B9")) 
> (find-partition-by-uuid uuid))
> # strace -o /tmp/^Crace3.txt guile 
> /gnu/store/wzvn8r2z7lnf5mqzagxzcb64wr69kgk4-remote-assertion.scm

It seems to be doing what we expect initially:

> openat(AT_FDCWD, "/dev/sda1", O_RDONLY) = 9

[...]

> fstat(9, {st_mode=S_IFBLK|0660, st_rdev=makedev(0x8, 0x1), ...}) = 0
> lseek(9, 0, SEEK_CUR)                   = 0
> lseek(9, 32768, SEEK_SET)               = 32768
> read(9, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = 4096
> close(9)                                = 0
> openat(AT_FDCWD, "/dev/sda1", O_RDONLY) = 9

[...]

> fstat(9, {st_mode=S_IFBLK|0660, st_rdev=makedev(0x8, 0x1), ...}) = 0
> lseek(9, 0, SEEK_CUR)                   = 0
> lseek(9, 1024, SEEK_SET)                = 1024
> read(9, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = 4096
> close(9)                                = 0
> openat(AT_FDCWD, "/dev/sda1", O_RDONLY) = 9

[...]

> fstat(9, {st_mode=S_IFBLK|0660, st_rdev=makedev(0x8, 0x1), ...}) = 0
> lseek(9, 0, SEEK_CUR)                   = 0
> lseek(9, 65536, SEEK_SET)               = 65536
> read(9, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = 4096
> close(9)                                = 0
> openat(AT_FDCWD, "/dev/sda1", O_RDONLY) = 9

[...]

> fstat(9, {st_mode=S_IFBLK|0660, st_rdev=makedev(0x8, 0x1), ...}) = 0
> mmap(0x7f1806869000, 1576960, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f180662d000
> lseek(9, 0, SEEK_CUR)                   = 0
> lseek(9, 0, SEEK_SET)                   = 0
> read(9, "\353X\220mkfs.fat\0\2\10 \0\2\0\0\0\0\370\0\0?\0\377\0\0\10\0\0"..., 4096) = 4096
> close(9)                                = 0
> openat(AT_FDCWD, "/dev/sda1", O_RDONLY) = 9

[...]

> fstat(9, {st_mode=S_IFBLK|0660, st_rdev=makedev(0x8, 0x1), ...}) = 0
> lseek(9, 0, SEEK_CUR)                   = 0
> lseek(9, 0, SEEK_SET)                   = 0
> read(9, "\353X\220mkfs.fat\0\2\10 \0\2\0\0\0\0\370\0\0?\0\377\0\0\10\0\0"..., 4096) = 4096
> close(9)                                = 0
> openat(AT_FDCWD, "/dev/sda1", O_RDONLY) = 9

[...]

> fstat(9, {st_mode=S_IFBLK|0660, st_rdev=makedev(0x8, 0x1), ...}) = 0
> lseek(9, 0, SEEK_CUR)                   = 0
> lseek(9, 32768, SEEK_SET)               = 32768
> read(9, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = 4096
> close(9)                                = 0
> openat(AT_FDCWD, "/dev/sda1", O_RDONLY) = 9

[...]

> fstat(9, {st_mode=S_IFBLK|0660, st_rdev=makedev(0x8, 0x1), ...}) = 0
> lseek(9, 0, SEEK_CUR)                   = 0
> lseek(9, 1024, SEEK_SET)                = 1024
> read(9, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = 4096
> close(9)                                = 0

And then it seems to enter an endless loop:

> write(6, "\0", 1)                       = 1
> clock_gettime(CLOCK_PROCESS_CPUTIME_ID, {tv_sec=0, tv_nsec=104694235}) = 0
> rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
> futex(0x7f180a6c5f68, FUTEX_WAKE_PRIVATE, 2147483647) = 3
> futex(0x7f180a6c5b40, FUTEX_WAKE_PRIVATE, 1) = 1
> futex(0x7f180a6c5f54, FUTEX_WAIT_PRIVATE, 3, NULL) = -1 EAGAIN (Resource temporarily unavailable)
> futex(0x7f180a6c5f60, FUTEX_WAKE_PRIVATE, 1) = 1
> futex(0x7f180a6c5f68, FUTEX_WAKE_PRIVATE, 2147483647) = 2
> futex(0x7f180a6c5f6c, FUTEX_WAKE_PRIVATE, 2147483647) = 3
> futex(0x7f180a6c5b40, FUTEX_WAKE_PRIVATE, 1) = 1
> futex(0x7f180a6c5b40, FUTEX_WAKE_PRIVATE, 1) = 0
> futex(0x7f180a6c5f6c, FUTEX_WAKE_PRIVATE, 2147483647) = 3
> clock_gettime(CLOCK_PROCESS_CPUTIME_ID, {tv_sec=0, tv_nsec=111569830}) = 0
> clock_gettime(CLOCK_PROCESS_CPUTIME_ID, {tv_sec=0, tv_nsec=114489967}) = 0
> rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0

[...]

> madvise(0x7f1806e01000, 12288, MADV_DONTNEED) = 0
> futex(0x7f180a6c5f68, FUTEX_WAIT_PRIVATE, 0, NULL) = -1 EAGAIN (Resource temporarily unavailable)
> futex(0x7f180a6c5b40, FUTEX_WAKE_PRIVATE, 1) = 0
> futex(0x7f180a6c5f6c, FUTEX_WAIT_PRIVATE, 0, NULL) = -1 EAGAIN (Resource temporarily unavailable)
> futex(0x7f180a6c5b40, FUTEX_WAKE_PRIVATE, 1) = 0
> futex(0x7f180a6c5f68, FUTEX_WAIT_PRIVATE, 0, NULL) = 0
> futex(0x7f180a6c5f50, FUTEX_WAKE_PRIVATE, 2147483647) = 1
> futex(0x7f180a6c5b40, FUTEX_WAKE_PRIVATE, 1) = 0
> futex(0x7f180a6c5b40, FUTEX_WAKE_PRIVATE, 1) = 0
> futex(0x7f180a6c5f6c, FUTEX_WAKE_PRIVATE, 2147483647) = 3
> clock_gettime(CLOCK_PROCESS_CPUTIME_ID, {tv_sec=14, tv_nsec=400254621}) = 0
> --- SIGINT {si_signo=SIGINT, si_code=SI_KERNEL} ---
> +++ killed by SIGINT +++

Could you try running this at the REPL:

  (load "/gnu/store/wzvn8r2z7lnf5mqzagxzcb64wr69kgk4-remote-assertion.scm")

and then hit C-c and type “,bt” to get a backtrace?

Thanks,
Ludo’.