bug#53027: Backtrace with `guix pull --debug=2`

[Ludovic Courtès]

Hi,

Maxime Devos  skribis:

> Oskar Berndal schreef op wo 05-01-2022 om 16:19 [+0100]:
>>    179:23  2 (update-build #< building: () downloadin…> …)
>> In ice-9/boot-9.scm:
>>   1685:16  1 (raise-exception _ #:continuable? _)
>>   1685:16  0 (raise-exception _ #:continuable? _)
>> 
>> ice-9/boot-9.scm:1685:16: In procedure raise-exception:
>> In procedure struct-vtable: Wrong type argument in position 1
>> (expecting struct): #f
>
> Seems like the issue is that 'find-build' returns #false
> and 'update' doesn't expect that. So apparently a progress spinner
> appears for a build that (guix status) doesn't know about?
> I don't know how that can happen.
>
> It's easy to address though (do nothing when no build was found),
> but possibly that would only paper over the real issue.

Yeah.  This looks like .

Ludo’.

bug#53027: Backtrace with `guix pull --debug=2`

[Oskar Berndal]

Wow, you were able to reproduce. I feared that this would just be lost
to the sands, but apparently not. Nicely done!!! :-D

bug#53027: Backtrace with `guix pull --debug=2`

[Maxime Devos]

Oskar Berndal schreef op wo 05-01-2022 om 16:19 [+0100]:
>    179:23  2 (update-build #< building: () downloadin…> …)
> In ice-9/boot-9.scm:
>   1685:16  1 (raise-exception _ #:continuable? _)
>   1685:16  0 (raise-exception _ #:continuable? _)
> 
> ice-9/boot-9.scm:1685:16: In procedure raise-exception:
> In procedure struct-vtable: Wrong type argument in position 1
> (expecting struct): #f

Seems like the issue is that 'find-build' returns #false
and 'update' doesn't expect that. So apparently a progress spinner
appears for a build that (guix status) doesn't know about?
I don't know how that can happen.

It's easy to address though (do nothing when no build was found),
but possibly that would only paper over the real issue.

Greetings,
Maxime.


signature.asc
Description: This is a digitally signed message part

bug#53027: Backtrace with `guix pull --debug=2`

[Maxime Devos]

Oskar Berndal schreef op wo 05-01-2022 om 16:19 [+0100]:
I tried running `guix pull` with the `--debug=2` flag. However, it led
a backtrace, that I include at the bottom. I tried the command twice
with the same backtrace, and then I tried without the debug flag,
simply running `guix pull`. This worked without error. Trying to run
with the debug flag again also worked immediately after that. [...]

I can reproduce. Tip: setting COLUMN to a huge number prevents these _
in backtraces, making the backtrace more informative:

$ COLUMNS=9000 guix pull --debug=2

Anyway, here's extra debug information, to be investigated:

10,6 MB zal binnengehaald worden
fetching path `/gnu/store/4y4qxga7yflgkdh0qgfj034q3das0ir4-guix-manual'...
 guix-manual
  4.3MiB/s 00:02 | 7.6MiB transferred
fetching path `/gnu/store/3d9cyp999jsxamz018hiz20av600syrf-guix-extra'...
 guix-extra  2.9MiB 
   2.5MiB/s 00:01 [##] 100.0%
fetching path `/gnu/store/zxb0iiva4878ajkh1xq82mmm2csbwqk2-guix-locale-guix'...
 guix-locale-guix  306KiB   
 515.0MiB/s 00:00 [##] 100.0%
building path(s) `/gnu/store/xxhjcnw24vqhsh7zngz19drkpr24p933-config.scm'
|   @ build-started /gnu/store/w7y0m9g09wqnzlwzzdf1kw6ayq42a54g-config.scm.drv 
- x86_64-linux 
/var/log/guix/drvs/w7//y0m9g09wqnzlwzzdf1kw6ayq42a54g-config.scm.drv.bz2 26258
scanning for references inside 
`/gnu/store/xxhjcnw24vqhsh7zngz19drkpr24p933-config.scm'
building path(s) 
`/gnu/store/a57mqs7dgpmgkrbsif4fg340x3r9g5r7-guix-extra-modules'
|   @ build-started 
/gnu/store/y4plqs9vq1zbqsgassk1j3qznjkfnj65-guix-extra-modules.drv - 
x86_64-linux 
/var/log/guix/drvs/y4//plqs9vq1zbqsgassk1j3qznjkfnj65-guix-extra-modules.drv.bz2
 26269
scanning for references inside 
`/gnu/store/a57mqs7dgpmgkrbsif4fg340x3r9g5r7-guix-extra-modules'
building path(s) 
`/gnu/store/v6pwv3gpb8gphn0smw2fr3zn1d4a2689-guix-config-source'
|   @ build-started 
/gnu/store/px2f4syh8hh2152a9bsff07a1hk07rb5-guix-config-source.drv - 
x86_64-linux 
/var/log/guix/drvs/px//2f4syh8hh2152a9bsff07a1hk07rb5-guix-config-source.drv.bz2
 26280
scanning for references inside 
`/gnu/store/v6pwv3gpb8gphn0smw2fr3zn1d4a2689-guix-config-source'
building path(s) 
`/gnu/store/nqn5f7pj69hbkdbpw5y9phny3badpbjk-guix-packages-base'
|   @ build-started 
/gnu/store/88bx7pj1czzhbnhsb0x2kn9zv6ny83ap-guix-packages-base.drv - 
x86_64-linux 
/var/log/guix/drvs/88//bx7pj1czzhbnhsb0x2kn9zv6ny83ap-guix-packages-base.drv.bz2
 26293
Backtrace:
In guix/store.scm:
   658:37 19 (thunk)
In guix/status.scm:
802:4 18 (call-with-status-report _ _)
In guix/store.scm:
   1343:3 17 (_)
   1320:8 16 (call-with-build-handler _ _)
   1320:8 15 (call-with-build-handler # _)
In guix/build/syscalls.scm:
   1423:3 14 (_)
   1390:4 13 (call-with-file-lock/no-wait _ _ _)
In guix/store.scm:
  2123:24 12 (run-with-store # _ 
#:guile-for-build _ #:system _ #:target _)
In guix/scripts/pull.scm:
428:4 11 (_ _)
In guix/store.scm:
  1995:38 10 (_ #)
In guix/scripts/package.scm:
   166:13  9 (build-and-use-profile # 
"/var/guix/profiles/per-user/regulator/current-guix" #< entries: 
(#< name: "guix" version: "f5da992" output: "out" item: 
# 
/gnu/store/1m0cganbbvk1kwpppli9gm3mnxrr1h9v-guix-f5da992b1 7fc9023d5050> 
dependencies: () search-paths: () parent: #> properties: ((source (repository (version 0) (url 
"https://git.savannah.gnu.org/git/guix.git;) (branch "master") (commit 
"f5da992b16591b6dc358aa5224fa095738471585") (name guix) (introduction 
(channel-introduction (version 0) (commit 
"9edb3f66fd807b096b48283debdcddccfea34bad") (signer "BBB0 2DDF 2CEA F6A8 0D1D  
E643 A2A0 6DF2 A33A 54FA"))>)> #:hooks _ #:allow-collisions? _ #:bootstrap? 
_)
In guix/store.scm:
  1421:15  8 (_ # _ _)
   759:13  7 (process-stderr _ _)
In unknown file:
   6 (display "@ build-log 26293 41\n\r[  0/654] loading...\t  0.0% of 
327 files" #)
In guix/status.scm:
   747:19  5 (write! _ _ _)
In srfi/srfi-1.scm:
   460:18  4 (fold # #< building: () downloading: () builds-completed: () 
downloads-completed: (#< item: 
"/gnu/store/zxb0iiva4878ajkh1xq82mmm2csbwqk2-guix-locale-guix" uri: 
"https://ci.guix.gnu.org/nar/zstd/zxb0iiva4878ajkh1xq82mmm2csbwqk2-guix-locale-guix;
 size: 313201 start: # end: # transferred: 313201> #< item: 
"/gnu/store/3d9cyp999jsxamz018hiz20av600syrf-guix-extra" uri: 
"https://ci.guix.gnu.org/nar/zstd/3d9cyp999jsxamz018hiz20av600syrf-guix-extra; 
size: 3035344 start: # end: # transferred: 3035344> #< item: 
"/gnu/store/4y4qxga7yflgkdh0qgfj034q3das0ir4-guix-manual" uri: 
"https://ci.guix.gnu.org/nar/lzip/4y4qxga7yflgkdh0qgfj034q3das0ir4-guix-manual; 
size: 7944251 start: # end: # transferred: 7944251>)> ((build-log 26293 "\r[  0/654] loading...\t 
 0.0% of 327 files")))
In 

bug#53027: Backtrace with `guix pull --debug=2`

[Oskar Berndal]

I tried running `guix pull` with the `--debug=2` flag. However, it led
a backtrace, that I include at the bottom. I tried the command twice
with the same backtrace, and then I tried without the debug flag,
simply running `guix pull`. This worked without error. Trying to run
with the debug flag again also worked immediately after that.

Prior to all of this, I made a system reconfiguration where I changed
the uid but not the name of a user. I needed to manually change the
ownership of some files to the new user id so that guix wouldn't trip
at some point. Maybe that's a clue, that it is due to some other files
being of wrong ownership (but not producing an error message I can
understand this time).

Other info:
- guix 1.3.0
- Installed on WSL

These are all things I can think of to add at the moment, please let
me know if there is something else that might be helpful if I can
provide.
Cheers,
Oskar

```
$ guix pull --debug=2
...
building path(s)
`/gnu/store/z0i0wwc7wvch9a8n0gd47gkay9lj1qb0-module-import-compiled'
|   @ build-started
/gnu/store/5m4pr3gskpzgshza09ashiysz4a3pd4v-module-import-compiled.drv
- x86_64-linux 
/var/log/guix/drvs/5m//4pr3gskpzgshza09ashiysz4a3pd4v-module-import-compiled.drv.bz2
3102
Backtrace:
In guix/channels.scm:
890:2 19 (_ _)
In ./guix/monads.scm:
471:9 18 (_ _)
In guix/store.scm:
   1956:8 17 (_ _)
In guix/channels.scm:
   641:14 16 (_ #)
In guix/store.scm:
  2119:24 15 (run-with-store # …)
   1320:8 14 (call-with-build-handler _ _)
   1320:8 13 (call-with-build-handler # …)
In guix/channels.scm:
   656:14 12 (_)
In guix/store.scm:
  2119:24 11 (run-with-store # …)
In unknown file:
  10 (_ # …)
In guix/store.scm:
  1991:38  9 (_ #)
  1417:15  8 (_ # _ _)
   759:13  7 (process-stderr _ _)
In unknown file:
   6 (display "@ build-log 3102 39\n[ 1/78] Loading './gcry…" …)
In guix/status.scm:
   745:19  5 (write! _ _ _)
In srfi/srfi-1.scm:
   460:18  4 (fold # …)
In guix/status.scm:
   636:15  3 (_ (build-log 3102 "[ 1/78] Loading './gcrypt/hash.s…") #)
   179:23  2 (update-build #< building: () downloadin…> …)
In ice-9/boot-9.scm:
  1685:16  1 (raise-exception _ #:continuable? _)
  1685:16  0 (raise-exception _ #:continuable? _)

ice-9/boot-9.scm:1685:16: In procedure raise-exception:
In procedure struct-vtable: Wrong type argument in position 1
(expecting struct): #f
```