[systemd-devel] systemd + logind possible deadlock

[Zbigniew Jędrzejewski-Szmek]

On Sat, Dec 14, 2013 at 11:55:47AM +0200, Oleksii Shevchuk wrote:
> > strace -p 1
> 
> stat("/sys", {st_mode=S_IFDIR|0555, st_size=0, ...}) = 0
> open("/sys/class/tty/console/active", O_RDONLY|O_CLOEXEC) = 19
> fstat(19, {st_mode=S_IFREG|0444, st_size=4096, ...}) = 0
> mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fbab0d58000
> read(19, "ttyS0 tty0\n", 4096)          = 11
> close(19)                               = 0
> munmap(0x7fbab0d58000, 4096)            = 0
> open("/sys/class/tty/tty0/active", O_RDONLY|O_CLOEXEC) = 19
> fstat(19, {st_mode=S_IFREG|0444, st_size=4096, ...}) = 0
> mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fbab0d58000
> read(19, "tty7\n", 4096)                = 5
> close(19)                               = 0
> munmap(0x7fbab0d58000, 4096)            = 0
> sendmsg(15, {msg_name(0)=NULL, msg_iov(9)=[{"PRIORITY=6\nSYSLOG_FACILITY=3\nCOD"..., 184}, {"UNIT=SOL.service", 16}, {"\n", 1}, {"MESSAGE_ID=39f53479d3a045ac8e117"..., 43}, {"\n", 1}, {"RESULT=done", 11}, {"\n", 1}, {"MESSAGE=Started SOL.", 20}, {"\n", 1}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL^CProcess 1 detached
>  <detached ...>
It's not hangin', just pretendin' :) What y'all think about a little
patch like this?

-------8<-----------------------------------------------------------
>From 349f5ec587e5e6cc3ad7c89573bb15219eac8920 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Zbigniew=20J=C4=99drzejewski-Szmek?= <zbyszek at in.waw.pl>
Date: Sat, 14 Dec 2013 11:54:26 -0500
Subject: [PATCH] logging: reduce send timeout to something more sensible

For a user, the timeout of 1 min per message seems equivalent to a hang.
If journald cannot process a message from PID1 for 10 ms then something
is significantly wrong. It's better to lose the message and continue.
---
 src/shared/log.c       | 5 ++++-
 src/shared/time-util.c | 7 +++----
 2 files changed, 7 insertions(+), 5 deletions(-)

diff --git a/src/shared/log.c b/src/shared/log.c
index 2404de8..d0616c8 100644
--- a/src/shared/log.c
+++ b/src/shared/log.c
@@ -126,7 +126,10 @@ static int create_log_socket(int type) {
         /* We need a blocking fd here since we'd otherwise lose
         messages way too early. However, let's not hang forever in the
         unlikely case of a deadlock. */
-        timeval_store(&tv, 1*USEC_PER_MINUTE);
+        if (getpid() == 1)
+                timeval_store(&tv, 10 * USEC_PER_MSEC);
+        else
+                timeval_store(&tv, 10 * USEC_PER_SEC);
         setsockopt(fd, SOL_SOCKET, SO_SNDTIMEO, &tv, sizeof(tv));
 
         return fd;
diff --git a/src/shared/time-util.c b/src/shared/time-util.c
index 55428c4..205fa6f 100644
--- a/src/shared/time-util.c
+++ b/src/shared/time-util.c
@@ -142,12 +142,11 @@ struct timeval *timeval_store(struct timeval *tv, usec_t u) {
         if (u == (usec_t) -1) {
                 tv->tv_sec = (time_t) -1;
                 tv->tv_usec = (suseconds_t) -1;
-                return tv;
+        } else {
+                tv->tv_sec = (time_t) (u / USEC_PER_SEC);
+                tv->tv_usec = (suseconds_t) (u % USEC_PER_SEC);
         }
 
-        tv->tv_sec = (time_t) (u / USEC_PER_SEC);
-        tv->tv_usec = (suseconds_t) (u % USEC_PER_SEC);
-
         return tv;
 }
 
-- 
1.8.1.rc0.194.gaf2e3a9

-------8<-----------------------------------------------------------

Zbyszek