bug#47543: “Repeated allocation of very large block” during ‘guix pull’

bug#47543: “Repeated allocation of very large block” during ‘guix pull’

[Ludovic Courtès]

While running ‘guix pull’, sometime between the actual ‘git pull’ (via
Guile-Git) and channel authentication, I saw the dreaded libgc warning:

  Repeated allocation of very large block

I forgot to capture the command output though, and it does not seem to
be reproducible.  (This is with a recent Guix,
ca. 9098745b181b3022587a35afd255f7ff1d41ac86.)

Running the command below from a Guix checkout, which authenticates 15+K
commits, isn’t enough to trigger it:

  guix git authenticate --cache-key=whatever \
    "9edb3f66fd807b096b48283debdcddccfea34bad" \
    "BBB0 2DDF 2CEA F6A8 0D1D E643 A2A0 6DF2 A33A 54FA"

So it might rather be ‘update-cached-checkout’ that triggers it.

If you experience it, please share the command line and command output!

Ludo’.

bug#47543: "Repeated allocation of very large block" during `guix pull`

[Rostislav Svoboda]

Hope it will help.
Cheers Bost

$ guix pull --cores=24
Updating channel 'nonguix' from Git repository at
'https://gitlab.com/nonguix/nonguix'...
Updating channel 'haskell-and-clojure' from Git repository at
'file:///home/bost/dev/haskell-guix'...
Updating channel 'bost' from Git repository at
'file:///home/bost/dev/guix-packages'...
Updating channel 'guix' from Git repository at
'https://git.savannah.gnu.org/git/guix.git'...
GC Warning: Repeated allocation of very large block (appr. size 69632):
    May lead to memory leak and poor performance
GC Warning: Repeated allocation of very large block (appr. size 69632):
    May lead to memory leak and poor performance
GC Warning: Repeated allocation of very large block (appr. size 69632):
    May lead to memory leak and poor performance
Building from these channels:
  bost      file:///home/bost/dev/guix-packages    251ce7d
  guix      https://git.savannah.gnu.org/git/guix.git    4b3b2e6
  haskell-and-clojurefile:///home/bost/dev/haskell-guix    a8b30a6
  nonguix   https://gitlab.com/nonguix/nonguix    bb184bd
Computing Guix derivation for 'x86_64-linux'... \
nothing to be done


$ guix describe
Generation 707    Sep 20 2023 01:24:32    (current)
  bost 251ce7d
    repository URL: file:///home/bost/dev/guix-packages
    branch: master
    commit: 251ce7d9ce4dd2bbc690189b84706368a5f20823
  guix 4b3b2e6
    repository URL: https://git.savannah.gnu.org/git/guix.git
    branch: master
    commit: 4b3b2e63007acee9e3a8c2ea728190480d092c3c
  haskell-and-clojure a8b30a6
    repository URL: file:///home/bost/dev/haskell-guix
    branch: master
    commit: a8b30a606f91caabec3cc8dc4b1255a69836554e
  nonguix bb184bd
    repository URL: https://gitlab.com/nonguix/nonguix
    branch: master
    commit: bb184bd0a8f91beec3a00718759e96c7828853de

$ guix system describe
Generation 58    Sep 18 2023 14:26:00    (current)
  file name: /var/guix/profiles/system-58-link
  canonical file name: /gnu/store/l91cqriia6jrkasbqdl2k14shd1rnm3w-system
  label: GNU with Linux-Libre 6.4.16
  bootloader: grub-efi
  root device: UUID: 67ce5d9c-7af1-4435-a2a9-68651ab9a281
  kernel: /gnu/store/qhynq8jfskirrn7fj5965ajmrs7zfshc-linux-libre-6.4.16/bzImage
  channels:
    bost:
      repository URL: file:///home/bost/dev/guix-packages
      branch: master
      commit: 36e44740eefa0aa313c2bb4ab30e5d93ee3e8448
    guix:
      repository URL: https://git.savannah.gnu.org/git/guix.git
      branch: master
      commit: 273709932fa47f6ae56c96564a9415fdbff4a169
    haskell-and-clojure:
      repository URL: file:///home/bost/dev/haskell-guix
      branch: master
      commit: a8b30a606f91caabec3cc8dc4b1255a69836554e
    nonguix:
      repository URL: https://gitlab.com/nonguix/nonguix
      branch: master
      commit: bb184bd0a8f91beec3a00718759e96c7828853de
  configuration file:
/gnu/store/f87bpd2bs8zn09jfcjbinwgffjyjy6ng-configuration.scm

$ guix home describe
Generation 894    Sep 20 2023 01:25:31    (current)
  file name: /var/guix/profiles/per-user/bost/guix-home-894-link
  canonical file name: /gnu/store/y67m6gf7jvq06f0pnr06s59hz2hb3wf1-home
  channels:
    bost:
      repository URL: file:///home/bost/dev/guix-packages
      branch: master
      commit: 251ce7d9ce4dd2bbc690189b84706368a5f20823
    guix:
      repository URL: https://git.savannah.gnu.org/git/guix.git
      branch: master
      commit: 4b3b2e63007acee9e3a8c2ea728190480d092c3c
    haskell-and-clojure:
      repository URL: file:///home/bost/dev/haskell-guix
      branch: master
      commit: a8b30a606f91caabec3cc8dc4b1255a69836554e
    nonguix:
      repository URL: https://gitlab.com/nonguix/nonguix
      branch: master
      commit: bb184bd0a8f91beec3a00718759e96c7828853de
  configuration file:
/gnu/store/sz4vw81k5hacngc437w57yqm8zpg8c88-configuration.scm


The two channels specified by file URLs are local copies of my github repos:
  bost:                https://github.com/Bost/guix-packages
  haskell-and-clojure: https://github.com/Bost/haskell-guix

bug#47543: "Repeated allocation of very large block" during `guix pull`

[Rostislav Svoboda]

Some more (hopefully relevant) information:

$ free -h
               total        used        free      shared  buff/cache   available
Mem:            31Gi        12Gi       1.5Gi       299Mi        17Gi        18Gi
Swap:          8.0Gi       450Mi       7.6Gi

$ uname -a
Linux ecke 6.4.16-gnu #1 SMP PREEMPT_DYNAMIC 1 x86_64 GNU/Linux

bug#47543: “Repeated allocation of very large block” during ‘guix pull’

[Janneke Nieuwenhuizen]

Ludovic Courtès writes:

> If you experience it, please share the command line and command output!

Never seen this before, but here it is...

--8<---------------cut here---------------start------------->8---
18:55:29 janneke@dundal:~/src/guix/master 
$ guix pull --commit=6bd17a0806
Updating channel 'guix' from Git repository at 'https://git.savannah.gnu.org/git/guix.git'...
Building from this channel:
  guix      https://git.savannah.gnu.org/git/guix.git	6bd17a0
Computing Guix derivation for 'x86_64-linux'... /Backtrace:
In ./guix/store.scm:
  1380:11 19-GC Warning: Repeated allocation of very large block (appr. size 62525440):
	May lead to memory leak and poor performance
\GC Warning: Repeated allocation of very large block (appr. size 31264768):
	May lead to memory leak and poor performance
/(loop (#<gexp-input #<<program-file> name: "guix-command" gexp: #<gexp (begin (set! %load-extension?> ?) ?)
   1293:4 18 (call-with-build-handler #<procedure 7f8fca01e500 at ./guix/store.scm:1333:2 (continue store things mo?> ?)
  2168:24 17 (run-with-store #<store-connection 256.99 7f8fef5000a0> #<procedure 7f8fceb426a0 at ./guix/gexp.scm:89?> ?)
In ./guix/gexp.scm:
   897:13 16 (_ #<store-connection 256.99 7f8fef5000a0>)
In ./guix/store.scm:
   1996:8 15 (_ #<store-connection 256.99 7f8fef5000a0>)
In ./guix/gexp.scm:
   299:22 14 (_ #<store-connection 256.99 7f8fef5000a0>)
   1180:2 13 (_ #<store-connection 256.99 7f8fcafee820>)
   1046:2 12 (_ #<store-connection 256.99 7f8fcafee820>)
    892:4 11 (_ #<store-connection 256.99 7f8fcafee820>)
In ./guix/store.scm:
  2053:12 10 (_ #<store-connection 256.99 7f8fcafee820>)
   1375:6  9 (map/accumulate-builds #<store-connection 256.99 7f8fcafee820> #<procedure 7f8fcc067ca0 at ./guix/stor?> ?)
  1380:11  8/GC Warning: Repeated allocation of very large block (appr. size 121376768):
	May lead to memory leak and poor performance
-(loop (#<gexp-input #<<computed-file> name: "guix-module-union" gexp: #<gexp (begin (use-modules (g?> ?) ?)
   1293:4  7 (call-with-build-handler #<procedure 7f8fcc067c80 at ./guix/store.scm:1333:2 (continue store things mo?> ?)
  2168:24  6 (run-with-store #<store-connection 256.99 7f8fcafee820> #<procedure 7f8fcc0b17c0 at ./guix/gexp.scm:89?> ?)
In ./guix/gexp.scm:
   897:13  5 (_ #<store-connection 256.99 7f8fcafee820>)
In ./guix/store.scm:
   1996:8  4 (_ #<store-connection 256.99 7f8fcafee820>)
In ./guix/gexp.scm:
   299:22  3 (_ #<store-connection 256.99 7f8fcafee820>)
In ./guix/store.scm:
  2040:38  2 (_ #<store-connection 256.99 7f8fcafee820>)
In ./guix/derivations.scm:
   965:17  1 (derivation #<store-connection 256.99 7f8fcafee820> "guix-module-union" "/gnu/store/4gvgcfdiz67wv04ihq?" ?)
In ./guix/store.scm:
   1036:9  0 (_ #<store-connection 256.99 7f8fcafee820> "guix-module-union.drv" #vu8(68 101 114 105 118 101 40 91 ?) _)

./guix/store.scm:1036:9: ERROR:
  1. &store-protocol-error:
      message: "error parsing derivation `/gnu/store/2zb0lb5bkg5868vvwqi6a8nh07p23610-guix-6bd17a080-modules.drv': expected string `Derive(['"
      status: 1
guix pull: error: You found a bug: the program '/gnu/store/sv5bgbzisyii7g45c3bd3w8jk59gfvx0-compute-guix-derivation'
failed to compute the derivation for Guix (version: "6bd17a0806ad32d1493ac51a7443276f719c4224"; system: "x86_64-linux";
host version: "445a0359083388b5ee686e6e855f94a3aac5f79c"; pull-version: 1).
Please report the COMPLETE output above by email to <bug-guix@gnu.org>.

[1]19:16:35 janneke@dundal:~/src/guix/master 
--8<---------------cut here---------------end--------------->8---

This seems to be somewhat repeatable, it was the third time in a row
this failed.  After the second time, I removed ~/.cache/guix/checkouts.

Also

--8<---------------cut here---------------start------------->8---
19:20:54 janneke@dundal:~/src/guix/master 
$ uname -a
Linux dundal 6.2.12-gnu #1 SMP PREEMPT_DYNAMIC 1 x86_64 GNU/Linux
19:20:56 janneke@dundal:~/src/guix/master 
$ guix system describe
Generation 141	May 15 2023 22:36:13	(current)
  file name: /var/guix/profiles/system-141-link
  canonical file name: /gnu/store/w3hnhxdk01fka2lqfjv37khraw2psidh-system
  label: GNU with Linux-Libre 6.2.12
  bootloader: grub
  root device: /dev/mapper/guix
  kernel: /gnu/store/0fms1i0n62h3xk9hlmyh7j8pbbcaxdbg-linux-libre-6.2.12/bzImage
  channels:
    guix:
      repository URL: https://git.savannah.gnu.org/git/guix.git
      commit: 960647f0161c2c99ea3417d129662181e882cfeb
  configuration file: /gnu/store/2cj3gl2z585xn6xy81wramjnqxqzy8yb-configuration.scm
19:21:01 janneke@dundal:~/src/guix/master 
$ guix describe
Generation 92	Jul 23 2023 20:35:32	(current)
  guix 445a035
    repository URL: https://git.savannah.gnu.org/git/guix.git
    branch: master
    commit: 445a0359083388b5ee686e6e855f94a3aac5f79c
19:21:04 janneke@dundal:~/src/guix/master 
$ free -h
              total        used        free      shared  buff/cache   available
Mem:           15Gi       540Mi        12Gi       229Mi       2.0Gi        14Gi
Swap:          15Gi          0B        15Gi

--8<---------------cut here---------------end--------------->8---

Not my daily driver, wanted to update before testing the new Smart
Hurdloading patch set...

Greetings,
Janneke

-- 
Janneke Nieuwenhuizen <janneke@gnu.org>  | GNU LilyPond https://LilyPond.org
Freelance IT https://www.JoyOfSource.com | Avatar® https://AvatarAcademy.com

bug#47543: “Repeated allocation of very large block” during ‘guix pull’

[Janneke Nieuwenhuizen]

Janneke Nieuwenhuizen writes:

Hi!

Just a headsup with more information.

> Ludovic Courtès writes:
>
>> If you experience it, please share the command line and command output!
>
> Never seen this before, but here it is...

[..]

> ./guix/store.scm:1036:9: ERROR:
>   1. &store-protocol-error:
>       message: "error parsing derivation `/gnu/store/2zb0lb5bkg5868vvwqi6a8nh07p23610-guix-6bd17a080-modules.drv': expected string `Derive(['"
>       status: 1

This bit, i.e., the fact that `guix pull' failed, was due to store
corruption.  Something else that I've also never experienced before.

> guix pull: error: You found a bug: the program '/gnu/store/sv5bgbzisyii7g45c3bd3w8jk59gfvx0-compute-guix-derivation'
> failed to compute the derivation for Guix (version: "6bd17a0806ad32d1493ac51a7443276f719c4224"; system: "x86_64-linux";
> host version: "445a0359083388b5ee686e6e855f94a3aac5f79c"; pull-version: 1).
> Please report the COMPLETE output above by email to <bug-guix@gnu.org>.

And on that last note, I wonder how apt this massage is, in this
particular case running `guix gc --repair=content' would have been
helpful.

> This seems to be somewhat repeatable, it was the third time in a row
> this failed.  After the second time, I removed ~/.cache/guix/checkouts.

After repairing the store, the `large block' warning was also gone.

Greetings,
Janneke

-- 
Janneke Nieuwenhuizen <janneke@gnu.org>  | GNU LilyPond https://LilyPond.org
Freelance IT https://www.JoyOfSource.com | Avatar® https://AvatarAcademy.com

bug#47543: “Repeated allocation of very large block” during ‘guix pull’

[Ludovic Courtès]

Ludovic Courtès <ludovic.courtes@inria.fr> skribis:

> While running ‘guix pull’, sometime between the actual ‘git pull’ (via
> Guile-Git) and channel authentication, I saw the dreaded libgc warning:
>
>   Repeated allocation of very large block

[...]

> So it might rather be ‘update-cached-checkout’ that triggers it.

I wonder if this was due to the big checkouts we ended up with so far:

  https://issues.guix.gnu.org/65720

Ludo’.

bug#47543: “Repeated allocation of very large block” during ‘guix pull’

[John Kehayias via Bug reports for GNU Guix]

Hello,

Just hit this warning and went searching to find this report.

On Thu, Nov 23, 2023 at 12:42 PM, Ludovic Courtès wrote:

> Ludovic Courtès <ludovic.courtes@inria.fr> skribis:
>
>> While running ‘guix pull’, sometime between the actual ‘git pull’ (via
>> Guile-Git) and channel authentication, I saw the dreaded libgc warning:
>>
>>   Repeated allocation of very large block
>
> [...]
>
>> So it might rather be ‘update-cached-checkout’ that triggers it.
>
> I wonder if this was due to the big checkouts we ended up with so far:
>
>   https://issues.guix.gnu.org/65720
>
> Ludo’.

In my case, just did a guix pull so I am on
2126dab4cd81db4cbde4566d8c638e45a4c0077c.

Pull was fine, but this warning was repeatable on a system reconfigure:

--8<---------------cut here---------------start------------->8---
❯ sudo guix system reconfigure ~/.config/guix/config.scm --max-jobs=4 -n
GC Warning: Repeated allocation of very large block (appr. size 69632):
	May lead to memory leak and poor performance
GC Warning: Repeated allocation of very large block (appr. size 69632):
	May lead to memory leak and poor performance
GC Warning: Repeated allocation of very large block (appr. size 69632):
	May lead to memory leak and poor performance
GC Warning: Repeated allocation of very large block (appr. size 135168):
	May lead to memory leak and poor performance
GC Warning: Repeated allocation of very large block (appr. size 131072):
	May lead to memory leak and poor performance
GC Warning: Repeated allocation of very large block (appr. size 69632):
	May lead to memory leak and poor performance
GC Warning: Repeated allocation of very large block (appr. size 102400):
	May lead to memory leak and poor performance
substitute: updating substitutes from 'https://bordeaux-us-east-mirror.cbaines.net/'... 100.0%
substitute: updating substitutes from 'https://bordeaux.guix.gnu.org'... 100.0%
substitute: updating substitutes from 'https://ci.guix.gnu.org'... 100.0%
substitute: updating substitutes from 'https://substitutes.nonguix.org'... 100.0%
The following derivation would be built:
  /gnu/store/r9n8vz4s1n7v3551cphrqy0pqyl8wcv0-corectrl-1.3.5.drv

340.3 MB would be downloaded
❯ sudo guix system reconfigure ~/.config/guix/config.scm -n
GC Warning: Repeated allocation of very large block (appr. size 69632):
	May lead to memory leak and poor performance
GC Warning: Repeated allocation of very large block (appr. size 122880):
	May lead to memory leak and poor performance
GC Warning: Repeated allocation of very large block (appr. size 69632):
	May lead to memory leak and poor performance
GC Warning: Repeated allocation of very large block (appr. size 69632):
	May lead to memory leak and poor performance
GC Warning: Repeated allocation of very large block (appr. size 69632):
	May lead to memory leak and poor performance
The following derivation would be built:
  /gnu/store/r9n8vz4s1n7v3551cphrqy0pqyl8wcv0-corectrl-1.3.5.drv

340.3 MB would be downloaded
❯ sudo guix system reconfigure ~/.config/guix/config.scm --max-jobs=4
GC Warning: Repeated allocation of very large block (appr. size 69632):
	May lead to memory leak and poor performance
GC Warning: Repeated allocation of very large block (appr. size 69632):
	May lead to memory leak and poor performance
GC Warning: Repeated allocation of very large block (appr. size 69632):
	May lead to memory leak and poor performance
GC Warning: Repeated allocation of very large block (appr. size 131072):
	May lead to memory leak and poor performance
The following derivation will be built:
  /gnu/store/r9n8vz4s1n7v3551cphrqy0pqyl8wcv0-corectrl-1.3.5.drv

340.3 MB will be downloaded
 adwaita-icon-theme-44.0  904KiB                                                                    108.0MiB/s 00:00 ▕██████████████████▏ 100.0%
guix substitute: warning: download from 'https://bordeaux-us-east-mirror.cbaines.net/nar/lzip/c2brbsvn75866l81rswb7z8sdpw2dvjr-font-abattis-cantarell-0.303-0.e049149' failed: 404, "Not Found"
retrying download of '/gnu/store/c2brbsvn75866l81rswb7z8sdpw2dvjr-font-abattis-cantarell-0.303-0.e049149' with other substitute URLs...

substitution of
/gnu/store/5in68ily7wjj8jy67kyj8sikwmci894j-ath9k-htc-ar7010-firmware-1.4.0
complete
--8<---------------cut here---------------end--------------->8---

this last one continued until I killed it to send capture the previous
output and send it.

--8<---------------cut here---------------start------------->8---
❯ free -h
               total        used        free      shared  buff/cache   available
Mem:            15Gi        10Gi       3.4Gi       706Mi       2.4Gi       4.8Gi
Swap:           15Gi       4.1Gi        11Gi
--8<---------------cut here---------------end--------------->8---

But since interrupting the reconfigure, it doesn't give the warning
again. So something happened by actually starting the reconfigure
process...?

I don't think I've ever seen this before. Hope this helps!

John