bug#38167: guix pull takes over 8 GiB of memory to finish if there are no substitutes
Hello, Danny Milosavljevic writes: > Hi Ludo, > > okay, I've now (permanently) unset GUIX_PACKAGE_PATH and killed the > problematic "guix pull" process. > > I run "guix pull" regularily. Let's see what happens... The 40 weeks of time that have passed since suggest the problem is now gone :-). Closing, but feel free to reopen if the problem persists with GUIX_PACKAGE_PATH unset. Thanks, Maxim
bug#38167: guix pull takes over 8 GiB of memory to finish if there are no substitutes
Hi Ludo, okay, I've now (permanently) unset GUIX_PACKAGE_PATH and killed the problematic "guix pull" process. I run "guix pull" regularily. Let's see what happens... pgpb3PrLFB9jl.pgp Description: OpenPGP digital signature
bug#38167: guix pull takes over 8 GiB of memory to finish if there are no substitutes
Hi, Danny Milosavljevic skribis: > On Sun, 29 Dec 2019 23:41:42 +0100 > Ludovic Courtès wrote: > >> > It could be because my modules in GUIX_PACKAGE_PATH contain an import cycle >> > (I don't know whether it does, but I had such a cycle before). >> >> And that’s definitely a possibility! Can you try unsetting >> GUIX_PACKAGE_PATH? > > Sure, but that will not decide it conclusively. > > It's pretty rare that guix pull has the problem above (once a week or so), so > it could also be that it will work because it got a non-problematic case the > same time (but not because of) I unset GUIX_PACKAGE_PATH. If you can reproduce the bug when GUIX_PACKAGE_PATH is unset, I’m happy to investigate further. Otherwise it’s hard to conclude because we’re effectively running arbitrary code so the bug may well have nothing to do with ‘guix pull’ itself. Let me know! Ludo’.
bug#38167: guix pull takes over 8 GiB of memory to finish if there are no substitutes
Hi Ludo, On Sun, 29 Dec 2019 23:41:42 +0100 Ludovic Courtès wrote: > > It could be because my modules in GUIX_PACKAGE_PATH contain an import cycle > > (I don't know whether it does, but I had such a cycle before). > > And that’s definitely a possibility! Can you try unsetting > GUIX_PACKAGE_PATH? Sure, but that will not decide it conclusively. It's pretty rare that guix pull has the problem above (once a week or so), so it could also be that it will work because it got a non-problematic case the same time (but not because of) I unset GUIX_PACKAGE_PATH. pgpXREozbYRNB.pgp Description: OpenPGP digital signature
bug#38167: guix pull takes over 8 GiB of memory to finish if there are no substitutes
Hey Danny, Danny Milosavljevic skribis: > [pid 19221] mmap(0x7fb3f2d48000, 65536, PROT_READ|PROT_WRITE, > MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f2d28000 > [pid 19221] mmap(0x7fb3f2d38000, 65536, PROT_READ|PROT_WRITE, > MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f2d18000 > [pid 19221] mmap(0x7fb3f2d28000, 8388608, PROT_READ|PROT_WRITE, > MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f2518000 > [pid 19221] mmap(0x7fb3f2d18000, 65536, PROT_READ|PROT_WRITE, > MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f2508000 > [pid 19221] mmap(0x7fb3f2518000, 65536, PROT_READ|PROT_WRITE, > MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f24f8000 That’s a malloc loop. > It could be because my modules in GUIX_PACKAGE_PATH contain an import cycle > (I don't know whether it does, but I had such a cycle before). And that’s definitely a possibility! Can you try unsetting GUIX_PACKAGE_PATH? (More generally, I recommend against GUIX_PACKAGE_PATH; use a channel or ‘-L’ when you need.) Thanks, Ludo’.
bug#38167: guix pull takes over 8 GiB of memory to finish if there are no substitutes
(continued)
/proc/19221/fd$ ls -lrt
insgesamt 0
l-wx-- 1 dannym users 64 28. Dez 18:52 9 -> 'pipe:[1044711]'
lr-x-- 1 dannym users 64 28. Dez 18:52 8 -> 'pipe:[1044711]'
lr-x-- 1 dannym users 64 28. Dez 18:52 7 ->
/gnu/store/y8fxyc5404hd859si99lyd0516pq86d3-guix-command
l-wx-- 1 dannym users 64 28. Dez 18:52 6 -> 'pipe:[1043018]'
lr-x-- 1 dannym users 64 28. Dez 18:52 5 -> 'pipe:[1043018]'
l-wx-- 1 dannym users 64 28. Dez 18:52 4 -> 'pipe:[1043017]'
lr-x-- 1 dannym users 64 28. Dez 18:52 3 -> 'pipe:[1043017]'
lrwx-- 1 dannym users 64 28. Dez 18:52 2 -> /dev/pts/0
lr-x-- 1 dannym users 64 28. Dez 18:52 19 ->
/home/dannym/.local/guix/wip/pascal.scm
lr-x-- 1 dannym users 64 28. Dez 18:52 18 ->
/home/dannym/.local/guix/wip/android.scm
lr-x-- 1 dannym users 64 28. Dez 18:52 17 ->
/home/dannym/src/guix-master/guix/etc/news.scm
lr-x-- 1 dannym users 64 28. Dez 18:52 16 ->
/home/dannym/src/guix-master/guix/etc/news.scm
l-wx-- 1 dannym users 64 28. Dez 18:52 15 ->
/var/guix/profiles/per-user/dannym/current-guix.lock
lrwx-- 1 dannym users 64 28. Dez 18:52 14 -> 'socket:[1042189]'
l-wx-- 1 dannym users 64 28. Dez 18:52 13 -> 'pipe:[1043019]'
lr-x-- 1 dannym users 64 28. Dez 18:52 12 -> 'pipe:[1043019]'
l-wx-- 1 dannym users 64 28. Dez 18:52 11 -> 'pipe:[1043888]'
lr-x-- 1 dannym users 64 28. Dez 18:52 10 -> 'pipe:[1043888]'
lrwx-- 1 dannym users 64 28. Dez 18:52 1 -> /dev/pts/0
lrwx-- 1 dannym users 64 28. Dez 18:52 0 -> /dev/pts/0
$ strace -f -s 0 -p 19221
strace: Process 19221 attached with 6 threads
[pid 19226] --- stopped by SIGTSTP ---
[pid 19225] --- stopped by SIGTSTP ---
[pid 19224] --- stopped by SIGTSTP ---
[pid 19223] --- stopped by SIGTSTP ---
[pid 19222] --- stopped by SIGTSTP ---
[pid 19221] --- stopped by SIGTSTP ---
[pid 19225] --- SIGCONT {si_signo=SIGCONT, si_code=SI_USER, si_pid=19219,
si_uid=27481} ---
[pid 19226] read(10,
[pid 19224] futex(0x7fb4fbea16e8, FUTEX_WAIT_PRIVATE, 0, NULL
[pid 19225] read(5,
[pid 19222] futex(0x7fb4fbea16e8, FUTEX_WAIT_PRIVATE, 0, NULL
[pid 19223] futex(0x7fb4fbea16e8, FUTEX_WAIT_PRIVATE, 0, NULL
[pid 19221] mmap(0x7fb3f2d48000, 65536, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f2d28000
[pid 19221] mmap(0x7fb3f2d38000, 65536, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f2d18000
[pid 19221] mmap(0x7fb3f2d28000, 8388608, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f2518000
[pid 19221] mmap(0x7fb3f2d18000, 65536, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f2508000
[pid 19221] mmap(0x7fb3f2518000, 65536, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f24f8000
[pid 19221] mmap(0x7fb3f2508000, 65536, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f24e8000
[pid 19221] mmap(0x7fb3f24f8000, 65536, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f24d8000
[pid 19221] mmap(0x7fb3f24e8000, 65536, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f24c8000
[pid 19221] mmap(0x7fb3f24d8000, 65536, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f24b8000
[pid 19221] mmap(0x7fb3f24c8000, 65536, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f24a8000
[pid 19221] mmap(0x7fb3f24b8000, 65536, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f2498000
[pid 19221] mmap(0x7fb3f24a8000, 65536, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f2488000
[pid 19221] mmap(0x7fb3f2498000, 65536, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f2478000
[pid 19221] mmap(0x7fb3f2488000, 65536, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f2468000
[pid 19221] mmap(0x7fb3f2478000, 8388608, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f1c68000
[pid 19221] mmap(0x7fb3f2468000, 65536, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f1c58000
[pid 19221] mmap(0x7fb3f1c68000, 65536, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f1c48000
[pid 19221] mmap(0x7fb3f1c58000, 65536, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f1c38000
[pid 19221] mmap(0x7fb3f1c48000, 65536, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f1c28000
[pid 19221] mmap(0x7fb3f1c38000, 65536, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f1c18000
[pid 19221] mmap(0x7fb3f1c28000, 65536, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f1c08000
[pid 19221] mmap(0x7fb3f1c18000, 65536, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f1bf8000
[pid 19221] mmap(0x7fb3f1c08000, 65536, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f1be8000
[pid 19221] mmap(0x7fb3f1bf8000, 65536, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb3f1bd8000
[pid 19221] mmap(0x7fb3f1be8000, 65536, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1,
bug#38167: guix pull takes over 8 GiB of memory to finish if there are no substitutes
Hi, Danny Milosavljevic skribis: > On Fri, 27 Dec 2019 19:11:08 +0100 > Ludovic Courtès wrote: > >> Danny Milosavljevic skribis: >> >> > USER PID %CPU %MEMVSZ RSS TTY STAT START TIME COMMAND >> > dannym 19221 20.8 87.4 9404812 6884184 pts/0 Tl 20:34 2:40 >> > /gnu/store/sc7z07gim1iq5zvfz1amdwf2irxrzifg-guile-2.2.6/bin/guile >> > --no-auto-compile /home/dannym/.config/guix/current/bin/guix pull >> >> Oh, that’s an RSS of 6 GiB for ‘guix pull’ itself? Weird, I don’t see >> how that can happen. >> >> Could it be that ~/.cache/guix/checkouts/THE-THING is too big, which in >> turn causes libgit2 to consume too much memory somehow? > > $ du -hs ~/.cache/guix/checkouts/ > 395M/home/dannym/.cache/guix/checkouts/ OK, nothing bad. >> What happens if you attach strace to this process at the moment where >> it’s consuming a lot of memory? Is it traversing Git pack files or >> something like that? > > Right now the process is in a paused state and I think when I attach strace > it will continue. Should I still do it? I don't want to destroy our > debugging > opportunity. I think you should resume it (SIGCONT), attach strace, and grab a few seconds of log so we have an idea of what it’s doing. You can also check /proc/PID/fd and keep a copy of /proc/PID/maps while we’re at it. Thanks! Ludo’.
bug#38167: guix pull takes over 8 GiB of memory to finish if there are no substitutes
Hi Ludo, On Fri, 27 Dec 2019 19:11:08 +0100 Ludovic Courtès wrote: > Danny Milosavljevic skribis: > > > USER PID %CPU %MEMVSZ RSS TTY STAT START TIME COMMAND > > dannym 19221 20.8 87.4 9404812 6884184 pts/0 Tl 20:34 2:40 > > /gnu/store/sc7z07gim1iq5zvfz1amdwf2irxrzifg-guile-2.2.6/bin/guile > > --no-auto-compile /home/dannym/.config/guix/current/bin/guix pull > > Oh, that’s an RSS of 6 GiB for ‘guix pull’ itself? Weird, I don’t see > how that can happen. > > Could it be that ~/.cache/guix/checkouts/THE-THING is too big, which in > turn causes libgit2 to consume too much memory somehow? $ du -hs ~/.cache/guix/checkouts/ 395M/home/dannym/.cache/guix/checkouts/ > What happens if you attach strace to this process at the moment where > it’s consuming a lot of memory? Is it traversing Git pack files or > something like that? Right now the process is in a paused state and I think when I attach strace it will continue. Should I still do it? I don't want to destroy our debugging opportunity. I could also attach gdb--I think that won't resume. pgpF2llD5Y17N.pgp Description: OpenPGP digital signature
bug#38167: guix pull takes over 8 GiB of memory to finish if there are no substitutes
> You could look at the output of “guix processes” and find out which > session child process is consuming memory. SessionPID: 19228 ClientPID: 19221 ClientCommand: /gnu/store/sc7z07gim1iq5zvfz1amdwf2irxrzifg-guile-2.2.6/bin/guile --no-auto-compile /home/dannym/.config/guix/current/bin/guix pull ChildProcess: 19235: /gnu/store/1mkkv2caiqbdbbd256c4dirfi4kwsacv-guile-2.2.6/bin/guile \ /gnu/store/znzxqlk1zggcqdbsjq60346pdabnp83x-guix-1.0.1-10.41b4b71/bin/.guix-real substitute --query Attached the entire process tree. The process is still there but I've "stopped" (i.e. paused) it. PROBLEM_TREE Description: Binary data pgpeyBzqWq8pB.pgp Description: OpenPGP digital signature
bug#38167: guix pull takes over 8 GiB of memory to finish if there are no substitutes
Hi! Danny Milosavljevic skribis: > USER PID %CPU %MEMVSZ RSS TTY STAT START TIME COMMAND > dannym 19221 20.8 87.4 9404812 6884184 pts/0 Tl 20:34 2:40 > /gnu/store/sc7z07gim1iq5zvfz1amdwf2irxrzifg-guile-2.2.6/bin/guile > --no-auto-compile /home/dannym/.config/guix/current/bin/guix pull Oh, that’s an RSS of 6 GiB for ‘guix pull’ itself? Weird, I don’t see how that can happen. Could it be that ~/.cache/guix/checkouts/THE-THING is too big, which in turn causes libgit2 to consume too much memory somehow? What happens if you attach strace to this process at the moment where it’s consuming a lot of memory? Is it traversing Git pack files or something like that? TIA, Ludo’.
bug#38167: guix pull takes over 8 GiB of memory to finish if there are no substitutes
Hi! Danny Milosavljevic skribis: > On Mon, 11 Nov 2019 21:42:24 +0100 > Ludovic Courtès wrote: > >> Also, it would be great if you could identify which derivation build >> requires that much memory, if this was happening sequentially. (I >> suspect “guix-packages.drv” is the one that eats up the most memory.) > > How do I do that? You could look at the output of “guix processes” and find out which session child process is consuming memory. > I've attached the process tree, filtered by "grep guix", of the latest such > occurence (if this E-Mail still makes it before I have no memory left :P). AFAICS this excludes the actual build process (which runs “guile”, not “guix”). HTH! Ludo’.
bug#38167: guix pull takes over 8 GiB of memory to finish if there are no substitutes
USER PID %CPU %MEMVSZ RSS TTY STAT START TIME COMMAND dannym 19221 20.8 87.4 9404812 6884184 pts/0 Tl 20:34 2:40 /gnu/store/sc7z07gim1iq5zvfz1amdwf2irxrzifg-guile-2.2.6/bin/guile --no-auto-compile /home/dannym/.config/guix/current/bin/guix pull pgpgwwzosj28v.pgp Description: OpenPGP digital signature
bug#38167: guix pull takes over 8 GiB of memory to finish if there are no substitutes
Hi Ludo, On Mon, 11 Nov 2019 21:42:24 +0100 Ludovic Courtès wrote: > Also, it would be great if you could identify which derivation build > requires that much memory, if this was happening sequentially. (I > suspect “guix-packages.drv” is the one that eats up the most memory.) How do I do that? I've attached the process tree, filtered by "grep guix", of the latest such occurence (if this E-Mail still makes it before I have no memory left :P). I also have the unfiltered process tree and I didn't invoke "guix gc"--if we need that. PROBLEM_TREE_GUIX Description: Binary data pgpSXNGxi4reX.pgp Description: OpenPGP digital signature
bug#38167: guix pull takes over 8 GiB of memory to finish if there are no substitutes
Hi Chris & Danny, Christopher Baines skribis: > Danny Milosavljevic writes: > >> Hi, >> >> guix pull takes over 8 GiB of memory to finish if there are no substitutes. >> >> My laptop only takes max 8 GiB of RAM. I've set up swap, but that kind of >> memory usage still seems ridiculous. > > Do you know if the derivations got built in parallel? So, does guix pull > --max-jobs=1 use the same amount of memory? Also, it would be great if you could identify which derivation build requires that much memory, if this was happening sequentially. (I suspect “guix-packages.drv” is the one that eats up the most memory.) I agree it’s ridiculous. That memory usage comes from Guile’s compiler. A couple of years ago, Andy managed to cut memory usage somewhat, but that’s not enough. Thanks, Ludo’.
bug#38167: guix pull takes over 8 GiB of memory to finish if there are no substitutes
Danny Milosavljevic writes: > Hi, > > guix pull takes over 8 GiB of memory to finish if there are no substitutes. > > My laptop only takes max 8 GiB of RAM. I've set up swap, but that kind of > memory usage still seems ridiculous. Do you know if the derivations got built in parallel? So, does guix pull --max-jobs=1 use the same amount of memory? signature.asc Description: PGP signature
bug#38167: guix pull takes over 8 GiB of memory to finish if there are no substitutes
Hi, guix pull takes over 8 GiB of memory to finish if there are no substitutes. My laptop only takes max 8 GiB of RAM. I've set up swap, but that kind of memory usage still seems ridiculous. pgpyF4ZirSunm.pgp Description: OpenPGP digital signature
