Subject: bug#27476: guix pull fails on powerful server

From: [email-masked] (Ludovic Courtès)
Date: Tue, 07 Nov 2017 11:57:10 +0100

Hi,

Ricardo Wurmus <[email-masked]> skribis:

> After limiting memory with “ulimit -Sv 5000000”:
>
> ice-9/threads.scm:289:22: In procedure loop:
> ice-9/threads.scm:289:22: Syntax error:
> guix/scripts/pull.scm:192:8: >>=: >>= (bind) used outside of 'with-monad' in form (>>= (indirect-root-added latest) (lambda (done) (mlet* %store-monad () (if (and (file-exists? latest) (string=? (readlink latest) source-dir)) (begin (display (G_ "Guix already up to date\n")) (return #t)) (begin (switch-symlinks latest source-dir) (format #t (G_ "updated ~a successfully deployed under `~a'~%") %guix-package-name latest) (return #t))))))
>
> Some deprecated features have been used.  Set the environment
> variable GUILE_WARN_DEPRECATED to "detailed" and rerun the
> program to get more information.  Set it to "no" to suppress
> this message.
> builder for `/gnu/store/afji58647yzz7cr9dvlj87sd3ad36lbk-guix-latest.drv' failed with exit code 1
> guix pull: error: build failed: build of `/gnu/store/afji58647yzz7cr9dvlj87sd3ad36lbk-guix-latest.drv' failed
>
> It always crashes at around 69%.

This gave me an idea.  With this program:

--8<---------------cut here---------------start------------->8---
(use-modules (ice-9 threads)
             (srfi srfi-1)
             (guix monads)
             (guix store)
             (system base compile))

(compile #f)                                      ;load modules

(define threads
  (unfold (lambda (x) (> x 100))
          (lambda (x)
            (call-with-new-thread
             (lambda ()
               (while #t
                 (compile
                  '(begin
                     (with-monad %store-monad
                       (>>= foo bar
                            (return 3)))
                     (mlet %store-monad ((x y))
                       (mbegin %store-monad
                         (return x)
                         (return y))))
                  #:env (current-module)
                  #:from 'scheme
                  #:to 'tree-il)))))
          1+
          0))

(for-each join-thread threads)
--8<---------------cut here---------------end--------------->8---

I can reproduce the error:

--8<---------------cut here---------------start------------->8---
$ ulimit -Sv 2000000
$ guile syntax-parms.scm
In ice-9/psyntax.scm:
  1678:45 19 (parse _ _ _ _ _ _ _)
In ice-9/boot-9.scm:
   230:17 18 (map1 (((("placeholder" placeholder) ((#<procedure 7fe06eb84230 at guix/monads.scm:283…>) . #) …) …)))
In ice-9/psyntax.scm:
  1483:23 17 (_ _ _)
In ice-9/boot-9.scm:
   230:29 16 (map1 (#<syntax y> #<syntax (#<syntax lambda> (#<syntax t-1dff1b83541ce327-679d05c>) (#<syntax ml…>))
   230:17 15 (map1 (#<syntax (#<syntax lambda> (#<syntax t-1dff1b83541ce327-679d05c>) (#<syntax mlet*> #<syntax…>))
In ice-9/psyntax.scm:
  1788:11 14 (lp ((#<syntax mlet*> #<syntax %store-monad> () #<syntax (#<syntax let> ((#<syntax x> #<syntax …>)) #)
  1678:45 13 (parse _ _ _ _ _ _ _)
In ice-9/boot-9.scm:
   230:17 12 (map1 (((("placeholder" placeholder) ("l-1dff1b83541ce327-67a3671" lexical . #) ("placeho…" …) …) …)))
In ice-9/psyntax.scm:
  1678:45 11 (parse _ _ _ _ _ _ _)
In ice-9/boot-9.scm:
   230:17 10 (map1 (((("placeholder" placeholder) ((#<procedure 7fe06eb84230 at guix/monads.scm:2…>) . #) …) . #)))
In ice-9/psyntax.scm:
  2337:44  9 (expand-let _ _ _ #f (hygiene guile-user) #<procedure build-let (src ids vars val-exps body-exp)> _ …)
  1678:45  8 (parse _ _ _ _ _ _ _)
In ice-9/boot-9.scm:
   230:17  7 (map1 (((("placeholder" placeholder) ("l-1dff1b83541ce327-67a37b2" lexical . #) ("placeho…" …) …) …)))
In ice-9/psyntax.scm:
  1678:45  6 (parse _ _ _ _ _ _ _)
In ice-9/boot-9.scm:
   230:17  5 (map1 (((("placeholder" placeholder) ((#<procedure 7fe06eb84230 at guix/monads.scm:283…>) . #) …) …)))
In ice-9/psyntax.scm:
  1483:23  4 (_ _ _)
In ice-9/boot-9.scm:
   230:17  3 (map1 (#<syntax (return x)> #<syntax (#<syntax lambda> (#<syntax unused-value>) (#<syntax mbegin>…>))
In ice-9/psyntax.scm:
  1406:23  2 (_ _)
  1347:32  1 (syntax-type ((#<syntax %store-monad> #<syntax %return>)) (("placeholder" placeholder) ((#) . #) …) …)
  1558:32  0 (expand-macro #<procedure 7fe06eb87198 at guix/monads.scm:538:0 (x)> _ _ _ _ _ _)
ice-9/psyntax.scm:1558:32: In procedure expand-macro:
ice-9/psyntax.scm:1558:32: Syntax error:
unknown location: state-return: Wrong number of arguments in form ((%store-monad %return))
In syntax-parms.scm:
    15:17  9 (_)
In system/base/compile.scm:
    255:6  8 (compile _ #:from _ #:to _ #:env _ #:opts _)
   183:32  7 (compile-fold (#<procedure compile-tree-il (x e opts)>) (begin (with-monad %store-monad (>>= …)) #) …)
In ice-9/boot-9.scm:
   2316:4  6 (save-module-excursion #<procedure 30a63560 at language/scheme/compile-tree-il.scm:29:3 ()>)
In language/scheme/compile-tree-il.scm:
    31:15  5 (_)
In ice-9/psyntax.scm:
  1233:22  4 (expand-top-sequence ((begin (with-monad %store-monad (>>= foo bar (return 3))) (mlet # ((…)) #))) _ …)
In ice-9/boot-9.scm:
   230:17  3 (map1 (#<procedure 2b188c00 at ice-9/psyntax.scm:1231:24 ()> #<procedure 2b188a80 at ice-9/psynta…>))
In ice-9/psyntax.scm:
  1611:33  2 (parse (((("placeholder" placeholder) ((#<procedure 7fe06eb84230 at guix/monads.scm…>) . #) …) . #)) …)
  1347:32  1 (syntax-type (>>= foo bar (return 3)) (("placeholder" placeholder) ((#<procedure 7fe06eb8…>) . #) …) …)
  1558:32  0 (expand-macro #<procedure 30a63200 at ice-9/eval.scm:333:13 (a)> _ _ _ _ _ _)
ice-9/psyntax.scm:1558:32: In procedure expand-macro:
ice-9/psyntax.scm:1558:32: Syntax error:
unknown location: source expression failed to match any pattern
GC Warning: Failed to expand heap by 28770304 bytes
GC Warning: Failed to expand heap by 28770304 bytes
GC Warning: Failed to expand heap by 14385152 bytes
GC Warning: Out of Memory! Heap size: 919 MiB. Returning NULL!
Warning: Unwind-only `out-of-memory' exception; skipping pre-unwind handler.
--8<---------------cut here---------------end--------------->8---

So it looks like Guile failing badly in ENOMEM conditions.

I can’t reproduce this with current Guile ‘stable-2.2’, following Andy’s
weak-table rewrite¹, so this might have been a weak-table bug showing up
under memory pressure.

With ‘guix pull’ this was more likely to happen on your many-core server
than on my laptop because you have more threads and thus much higher
memory usage.

Ludo’.

¹ https://lists.gnu.org/archive/html/guile-devel/2017-10/msg00051.html
  https://git.savannah.gnu.org/cgit/guile.git/commit/?h=stable-2.2&id=a053c0510c4a644f9453166b7b385cf30f6d3a21