civodul pushed a commit to branch main
in repository shepherd.
commit e5b499c83b4e3a7f070edd7996cebaa485a67316
Author: Ludovic Courtès <[email protected]>
AuthorDate: Sun Mar 2 17:19:58 2025 +0100
logger: Use ‘put-string’ rather than ‘simple-format’ to avoid deadlocks.
Fixes a bug whereby ‘tests/syslog-slow-output.sh’ would occasionally
hang, with the ‘shepherd’ process waiting forever in poll(2):
#0 0x00007fd674ef94bf in poll ()
from /gnu/store/…-glibc-2.39/lib/libc.so.6
#1 0x00007fd6753de345 in port_poll (
port=port@entry=#<port #<port-type file 7fd674c0cb40> 7fd674d13980>,
events=events@entry=4, timeout=timeout@entry=-1)
at /tmp/guix-build-guile-3.0.9.drv-0/guile-3.0.9/libguile/ports.c:1422
#2 0x00007fd6753e0f59 in scm_i_write_bytes (
port=#<port #<port-type file 7fd674c0cb40> 7fd674d13980>,
src="#<vu8vector>" = {...},
start=0, count=22) at
/tmp/guix-build-guile-3.0.9.drv-0/guile-3.0.9/libguile/ports.c:2884
#3 0x00007fd6753e2ef1 in scm_c_put_latin1_chars (
port=#<port #<port-type file 7fd674c0cb40> 7fd674d13980>,
chars=<optimized out>, len=22)
at /tmp/guix-build-guile-3.0.9.drv-0/guile-3.0.9/libguile/ports.c:3458
#4 0x00007fd6753e86df in iprin1 (exp="t-syslog-logger-86.scm",
port=#<port #<port-type file 7fd674c0cb40> 7fd674d13980>,
pstate=0x7fd670f19d98)
at /tmp/guix-build-guile-3.0.9.drv-0/guile-3.0.9/libguile/print.c:687
#5 0x00007fd6753e892a in scm_iprin1 (exp=<optimized out>,
port=<optimized out>,
pstate=<optimized out>)
at /tmp/guix-build-guile-3.0.9.drv-0/guile-3.0.9/libguile/print.c:561
#6 0x00007fd6753e8afd in scm_prin1 (exp="t-syslog-logger-86.scm",
port=#<port #<port-type file 7fd674c0cb40> 7fd674d13980>, writingp=0)
at /tmp/guix-build-guile-3.0.9.drv-0/guile-3.0.9/libguile/print.c:840
#7 0x00007fd6753e92d0 in scm_simple_format (
destination=#<port #<port-type file 7fd674c0cb40> 7fd674d13980>,
message="~a[~a] ",
args=("t-syslog-logger-86.scm" 119))
at /tmp/guix-build-guile-3.0.9.drv-0/guile-3.0.9/libguile/print.c:1198
This is because ‘simple-format’ is not suspendable and
‘scm_i_write_bytes’ unconditionally calls ‘poll’ when the output port is
not ready. In the test this would lead to a deadlock where output from
$logger would no longer be consumed by shepherd.
* modules/shepherd/logger.scm (service-builtin-logger): Use ‘put-string’
instead of ‘simple-format’ to write to ‘log-output-port’.
---
modules/shepherd/logger.scm | 14 ++++++--------
1 file changed, 6 insertions(+), 8 deletions(-)
diff --git a/modules/shepherd/logger.scm b/modules/shepherd/logger.scm
index 031fa33..2e0e891 100644
--- a/modules/shepherd/logger.scm
+++ b/modules/shepherd/logger.scm
@@ -317,14 +317,12 @@ to @var{history-size} lines in memory."
(process-id process))
(value
value)))))
- (now (current-time)))
- (if (integer? pid)
- (simple-format (log-output-port) "~a[~a] "
- command pid)
- (simple-format (log-output-port) "[~a] "
- command))
- (put-string (log-output-port) line)
- (newline (log-output-port))
+ (now (current-time))
+ ;; Note: 'simple-format' is not suspendable, hence
'put-string'.
+ (line* (if (integer? pid)
+ (simple-format #f "~a[~a] ~a~%" command pid line)
+ (simple-format #f "[~a] ~a~%" command line))))
+ (put-string (log-output-port) line*)
(loop pid
(ring-buffer-insert (cons now line)
messages)
