GNU bug report logs - #67041
[cuirass] cuirass-web crash

Previous Next

Package: guix;

Reported by: Maxim Cournoyer <maxim.cournoyer <at> gmail.com>

Date: Fri, 10 Nov 2023 14:01:02 UTC

Severity: normal

Merged with 64276

Done: Ludovic Courtès <ludo <at> gnu.org>

Bug is archived. No further changes may be made.

To add a comment to this bug, you must first unarchive it, by sending
a message to control AT debbugs.gnu.org, with unarchive 67041 in the body.
You can then email your comments to 67041 AT debbugs.gnu.org in the normal way.

Toggle the display of automated, internal messages from the tracker.

View this report as an mbox folder, status mbox, maintainer mbox

Report forwarded to guix-sysadmin <at> gnu.org, bug-guix <at> gnu.org:
bug#67041; Package guix. (Fri, 10 Nov 2023 14:01:02 GMT) Full text and rfc822 format available.
Acknowledgement sent to Maxim Cournoyer <maxim.cournoyer <at> gmail.com>:
New bug report received and forwarded. Copy sent to guix-sysadmin <at> gnu.org, bug-guix <at> gnu.org. (Fri, 10 Nov 2023 14:01:02 GMT) Full text and rfc822 format available.

Message #5 received at submit <at> debbugs.gnu.org (full text, mbox):

From: Maxim Cournoyer <maxim.cournoyer <at> gmail.com>
To: bug-guix <bug-guix <at> gnu.org>
Subject: [cuirass] cuirass-web crash
Date: Fri, 10 Nov 2023 08:59:36 -0500

Hi,

Today ci.guix.gnu.org was showing a 504 Gateway Time-out error.  Looking
at /var/log/cuirass-web.log on berlin, there's this backtrace:

--8<---------------cut here---------------start------------->8---
2023-11-10 13:11:30 Uncaught exception in task:
2023-11-10 13:11:30 GET /build/18305/details
2023-11-10 13:11:30 In fibers.scm:
2023-11-10 13:11:30     172:8  4 (_)
2023-11-10 13:11:30 In web/server/fiberized.scm:
2023-11-10 13:11:30    187:12  3 (socket-loop #<input-output: socket 44> #<<channel> get?>)
2023-11-10 13:11:30 In ice-9/suspendable-ports.scm:
2023-11-10 13:11:30    733:12  2 (_ #<input-output: socket 44> _)
2023-11-10 13:11:30 In unknown file:
2023-11-10 13:11:30            1 (accept #<input-output: socket 44> 526336)
2023-11-10 13:11:30 In ice-9/boot-9.scm:
2023-11-10 13:11:30   1685:16  0 (raise-exception _ #:continuable? _)
2023-11-10 13:11:30 ice-9/boot-9.scm:1685:16: In procedure raise-exception:
2023-11-10 13:11:30 In procedure accept: Too many open files
--8<---------------cut here---------------end--------------->8---

Restarting it with 'sudo herd restart cuirass-web' resolved that for
now.

-- 
Thanks,
Maxim
Information forwarded to bug-guix <at> gnu.org:
bug#67041; Package guix. (Thu, 16 Nov 2023 16:11:02 GMT) Full text and rfc822 format available.

Message #8 received at 67041 <at> debbugs.gnu.org (full text, mbox):

From: Ludovic Courtès <ludo <at> gnu.org>
To: Maxim Cournoyer <maxim.cournoyer <at> gmail.com>
Cc: 67041 <at> debbugs.gnu.org, guix-sysadmin <guix-sysadmin <at> gnu.org>
Subject: Re: bug#67041: [cuirass] cuirass-web crash
Date: Thu, 16 Nov 2023 17:09:49 +0100

Hi,

Maxim Cournoyer <maxim.cournoyer <at> gmail.com> skribis:

> 2023-11-10 13:11:30 ice-9/boot-9.scm:1685:16: In procedure raise-exception:
> 2023-11-10 13:11:30 In procedure accept: Too many open files

Apparently there’s something that causes ‘cuirass web’ to leak file
descriptors, the number being otherwise stable around 50:

--8<---------------cut here---------------start------------->8---
2023-11-08 06:53:23 heap: 61.34 MiB; threads: 9; file descriptors: 50
2023-11-08 07:03:23 heap: 61.34 MiB; threads: 9; file descriptors: 50
2023-11-08 07:13:23 heap: 61.34 MiB; threads: 9; file descriptors: 50
2023-11-08 07:23:23 heap: 61.34 MiB; threads: 9; file descriptors: 50
2023-11-08 07:33:23 heap: 54.97 MiB; threads: 9; file descriptors: 50
2023-11-08 07:43:23 heap: 54.97 MiB; threads: 9; file descriptors: 50
2023-11-08 07:53:23 heap: 54.97 MiB; threads: 9; file descriptors: 50
2023-11-08 08:03:23 heap: 54.97 MiB; threads: 9; file descriptors: 50
2023-11-08 08:13:23 heap: 61.34 MiB; threads: 9; file descriptors: 50
2023-11-08 08:23:23 heap: 61.34 MiB; threads: 9; file descriptors: 50
2023-11-08 08:33:23 heap: 61.34 MiB; threads: 9; file descriptors: 50
2023-11-08 08:43:23 heap: 61.34 MiB; threads: 9; file descriptors: 50
2023-11-08 08:53:23 heap: 61.34 MiB; threads: 9; file descriptors: 50
2023-11-08 09:03:23 heap: 61.34 MiB; threads: 9; file descriptors: 51
2023-11-08 09:13:23 heap: 61.34 MiB; threads: 9; file descriptors: 154
2023-11-08 09:23:23 heap: 61.34 MiB; threads: 9; file descriptors: 232
2023-11-08 09:33:23 heap: 61.34 MiB; threads: 9; file descriptors: 282
2023-11-08 09:43:23 heap: 61.34 MiB; threads: 9; file descriptors: 385
2023-11-08 09:53:23 heap: 61.34 MiB; threads: 9; file descriptors: 489
2023-11-08 10:03:23 heap: 61.34 MiB; threads: 9; file descriptors: 608
2023-11-08 10:13:23 heap: 61.34 MiB; threads: 9; file descriptors: 665
2023-11-08 10:23:23 heap: 61.34 MiB; threads: 9; file descriptors: 706
2023-11-08 10:33:23 heap: 61.34 MiB; threads: 9; file descriptors: 760
2023-11-08 10:43:23 heap: 61.34 MiB; threads: 9; file descriptors: 802
2023-11-08 10:53:23 heap: 61.34 MiB; threads: 9; file descriptors: 865
2023-11-08 11:03:23 heap: 61.34 MiB; threads: 9; file descriptors: 969
2023-11-08 11:13:24 heap: 61.34 MiB; threads: 9; file descriptors: 0
2023-11-08 11:23:24 heap: 61.34 MiB; threads: 9; file descriptors: 0
--8<---------------cut here---------------end--------------->8---

Looking at the logs, the FD leak may come from this:

--8<---------------cut here---------------start------------->8---
2023-11-08 09:03:35 GET /eval/903503
2023-11-08 09:03:35 In cuirass/http.scm:
2023-11-08 09:03:35   1074:25 11 (url-handler _ _ _)
2023-11-08 09:03:35     295:4 10 (evaluation-html-page #<<evaluation-summary> id: 90350?> ?)
2023-11-08 09:03:35 In cuirass/logging.scm:
2023-11-08 09:03:35    111:18  9 (call-with-time-logging "builds request for evaluation?" ?)
2023-11-08 09:03:35 In ice-9/boot-9.scm:
2023-11-08 09:03:35   1752:10  8 (with-exception-handler _ _ #:unwind? _ # _)
2023-11-08 09:03:35 In cuirass/utils.scm:
2023-11-08 09:03:35     99:24  7 (_)
2023-11-08 09:03:35 In cuirass/database.scm:
2023-11-08 09:03:35    1503:2  6 (_ _)
2023-11-08 09:03:35   1439:28  5 (proc _)
2023-11-08 09:03:35 In ice-9/boot-9.scm:
2023-11-08 09:03:35   1685:16  4 (raise-exception _ #:continuable? _)
2023-11-08 09:03:35 In cuirass/utils.scm:
2023-11-08 09:03:35     96:12  3 (_ #<&compound-exception components: (#<&error> #<&orig?>)
2023-11-08 09:03:35 In fibers/operations.scm:
2023-11-08 09:03:35    154:10  2 (perform-operation _)
2023-11-08 09:03:35 In fibers/scheduler.scm:
2023-11-08 09:03:35     357:6  1 (suspend-current-task _)
2023-11-08 09:03:35 In ice-9/boot-9.scm:
2023-11-08 09:03:35   1685:16  0 (raise-exception _ #:continuable? _)
2023-11-08 09:03:35 Attempt to suspend fiber within continuation barrier
--8<---------------cut here---------------end--------------->8---

Fortunately, this is easy to reproduce:

--8<---------------cut here---------------start------------->8---
$ ./pre-inst-env guile
GNU Guile 3.0.9
Copyright (C) 1995-2023 Free Software Foundation, Inc.

Guile comes with ABSOLUTELY NO WARRANTY; for details type `,show w'.
This program is free software, and you are welcome to redistribute it
under certain conditions; type `,show c' for details.

Enter `,help' for help.
scheme@(guile-user)> ,use(fibers)
scheme@(guile-user)> ,use(cuirass utils)
scheme@(guile-user)> (run-fibers
(lambda ()
  (define pool (make-resource-pool (iota 10)))
  (with-resource-from-pool pool x (pk 'x x) (throw 'doh!))))

;;; (x 0)
Uncaught exception in task:
In fibers.scm:
   186:20  9 (_)
   145:21  8 (_)
In ice-9/boot-9.scm:
  1752:10  7 (with-exception-handler _ _ #:unwind? _ #:unwind-for-type _)
In cuirass/utils.scm:
    99:24  6 (_)
In current input:
     6:44  5 (_ _)
In ice-9/boot-9.scm:
  1685:16  4 (raise-exception _ #:continuable? _)
In cuirass/utils.scm:
    96:12  3 (_ #<&compound-exception components: (#<&error> #<&irritants irritants: ()> #<&exception-with-kind-and-args kind: doh! args: ()>)>)
In fibers/operations.scm:
   154:10  2 (perform-operation _)
In fibers/scheduler.scm:
    357:6  1 (suspend-current-task _)
In ice-9/boot-9.scm:
  1685:16  0 (raise-exception _ #:continuable? _)
ice-9/boot-9.scm:1685:16: In procedure raise-exception:
Attempt to suspend fiber within continuation barrier
--8<---------------cut here---------------end--------------->8---

To be continued…

Ludo’.
Information forwarded to bug-guix <at> gnu.org:
bug#67041; Package guix. (Thu, 16 Nov 2023 22:27:02 GMT) Full text and rfc822 format available.

Message #11 received at 67041 <at> debbugs.gnu.org (full text, mbox):

From: Ludovic Courtès <ludo <at> gnu.org>
To: Maxim Cournoyer <maxim.cournoyer <at> gmail.com>
Cc: 67041 <at> debbugs.gnu.org, guix-sysadmin <guix-sysadmin <at> gnu.org>
Subject: Re: bug#67041: [cuirass] cuirass-web crash
Date: Thu, 16 Nov 2023 23:26:48 +0100

Ludovic Courtès <ludo <at> gnu.org> skribis:

> scheme@(guile-user)> (run-fibers
> (lambda ()
>   (define pool (make-resource-pool (iota 10)))
>   (with-resource-from-pool pool x (pk 'x x) (throw 'doh!))))
>
> ;;; (x 0)
> Uncaught exception in task:
> In fibers.scm:
>    186:20  9 (_)
>    145:21  8 (_)
> In ice-9/boot-9.scm:
>   1752:10  7 (with-exception-handler _ _ #:unwind? _ #:unwind-for-type _)
> In cuirass/utils.scm:
>     99:24  6 (_)
> In current input:
>      6:44  5 (_ _)
> In ice-9/boot-9.scm:
>   1685:16  4 (raise-exception _ #:continuable? _)
> In cuirass/utils.scm:
>     96:12  3 (_ #<&compound-exception components: (#<&error> #<&irritants irritants: ()> #<&exception-with-kind-and-args kind: doh! args: ()>)>)
> In fibers/operations.scm:
>    154:10  2 (perform-operation _)
> In fibers/scheduler.scm:
>     357:6  1 (suspend-current-task _)
> In ice-9/boot-9.scm:
>   1685:16  0 (raise-exception _ #:continuable? _)
> ice-9/boot-9.scm:1685:16: In procedure raise-exception:
> Attempt to suspend fiber within continuation barrier

This is fixed by Cuirass commit
7c697ad7f15c13264615d2b6c9165b21abaf61dd.

Ludo’.
Merged 64276 67041. Request was from Ludovic Courtès <ludo <at> gnu.org> to control <at> debbugs.gnu.org. (Thu, 16 Nov 2023 22:29:02 GMT) Full text and rfc822 format available.
Reply sent to Ludovic Courtès <ludo <at> gnu.org>:
You have taken responsibility. (Thu, 23 Nov 2023 11:44:01 GMT) Full text and rfc822 format available.
Notification sent to Maxim Cournoyer <maxim.cournoyer <at> gmail.com>:
bug acknowledged by developer. (Thu, 23 Nov 2023 11:44:02 GMT) Full text and rfc822 format available.

Message #18 received at 67041-done <at> debbugs.gnu.org (full text, mbox):

From: Ludovic Courtès <ludo <at> gnu.org>
To: Maxim Cournoyer <maxim.cournoyer <at> gmail.com>
Cc: guix-sysadmin <guix-sysadmin <at> gnu.org>, 67041-done <at> debbugs.gnu.org
Subject: Re: bug#67041: [cuirass] cuirass-web crash
Date: Thu, 23 Nov 2023 12:43:45 +0100

Ludovic Courtès <ludo <at> gnu.org> skribis:

> This is fixed by Cuirass commit
> 7c697ad7f15c13264615d2b6c9165b21abaf61dd.

Included in the ‘cuirass’ package update in Guix commit
300e9ad43d1f7a10013aa0724ed3aeb7d93500c1, now deployed on berlin and its
x86 build nodes.

Ludo'.
Reply sent to Ludovic Courtès <ludo <at> gnu.org>:
You have taken responsibility. (Thu, 23 Nov 2023 11:44:02 GMT) Full text and rfc822 format available.
Notification sent to Ludovic Courtès <ludovic.courtes <at> inria.fr>:
bug acknowledged by developer. (Thu, 23 Nov 2023 11:44:02 GMT) Full text and rfc822 format available.
bug archived. Request was from Debbugs Internal Request <help-debbugs <at> gnu.org> to internal_control <at> debbugs.gnu.org. (Thu, 21 Dec 2023 12:24:08 GMT) Full text and rfc822 format available.
This bug report was last modified 1 year and 181 days ago.

Previous Next

GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.