[prev in list] [next in list] [prev in thread] [next in thread] 

List:       busybox
Subject:    Re: [PATCH] crond: add LOG_NDELAY to openlog
From:       Jones Syue 薛懷宗 <jonessyue () qnap ! com>
Date:       2024-01-05 10:18:31
Message-ID: SI2PR04MB5097A387C0D57781D8354924DC662 () SI2PR04MB5097 ! apcprd04 ! prod ! outlook ! com
[Download RAW message or body]

Hello List,

> So it looks like simply adds LOG_NDELAY might be a feasible approach to 
> address this issue :)

Attached is a proposed v2 patch, code is the same,
leverage comments from inetd_main() at inetd.c and rewrite git logs,
any feedback is much appreciated, thank you :)

--

Regards,
Jones Syue | 薛懷宗
QNAP Systems, Inc.

["0001-crond-add-LOG_NDELAY-to-openlog-v2.txt" (text/plain)]

From 42f5f7d85bd968c1bd92a11237fc8f4cb78129a4 Mon Sep 17 00:00:00 2001
From: Jones Syue <jonessyue@qnap.com>
Date: Fri, 5 Jan 2024 18:03:58 +0800
Subject: [PATCH] crond: add LOG_NDELAY to openlog

crond_main()'s openlog() does not has the option LOG_NDELAY, so the DGRAM
socket fd to /dev/log might be delay opened only when the first message
is logged with syslog().

If the first message is logged with syslog() by a vforked child process,
this might lead to an inconsistent state between these two resources,
1. syslog() internal state, a glibc static variable 'LogFile'[1], which
is resident in the data segment (address space). Per vfork() implementation,
it is shared among all processes including parent and vforked children.
2. file descriptors table, it is not shared among processes. Each process
has its own copy, including parent and children processes.

Once parent is resumed and also needs to log message by syslog(), it would
find the shared var 'LogFile' is avaialbe and just use it, put its value
into the 1st argument 'fd' of sendto(), this might cause a problem.
Actually this 'fd' number is not an expected DGRAM socket fd in parent's fds,
because parent never opened the DGRAM socket fd to /dev/log in its life cycle.
In my case this 'fd' number is a regular file, not a DGRAM socket, so parent
sendto() would get ENOTSOCK. Although glibc syslog() logic would replace it
with a re-created DGRAM socket fd in order to make it consistent[2],
finally parent would still be blocked, because get_line_with_continuation()
trys to read expected 'EOF' but it is DGRAM socket now and failed to move on.

Other vforked children has a bit similar symptom. In my case this fd number
is not existed in fds of other vforked children, so sendto() get EBADF.

Back to earlier days inetd might have this similar symptom, and 'LOG_NDELAY'
could address inetd's issue too: cfc216345e18081cba9ac3ed0464abf5d7f40cea

This patch adds 'LOG_NDELAY' into crond_main()'s openlog(), in order to open
the connection to syslog daemon immediately. This is helpful and useful to
precisely control the DGRAM socket fd to /dev/log is allocated in parent's
address space and fds, just before upcoming vfork() children, then inheritance
nature would make it more consistent during crond parsing/vforked jobs.

[1] https://elixir.bootlin.com/glibc/glibc-2.21/source/misc/syslog.c#L64
[2] https://elixir.bootlin.com/glibc/glibc-2.21/source/misc/syslog.c#L283

./busybox/scripts/bloat-o-meter ~/busybox_unstripped_{orig,fix}
function                                             old     new   delta
------------------------------------------------------------------------------
(add/remove: 0/0 grow/shrink: 0/0 up/down: 0/0)                 Total: 0 bytes

Signed-off-by: Jones Syue <jonessyue@qnap.com>
---
 miscutils/crond.c | 10 ++++++++--
 1 file changed, 8 insertions(+), 2 deletions(-)

diff --git a/miscutils/crond.c b/miscutils/crond.c
index 3bbb5ac..84a62f2 100644
--- a/miscutils/crond.c
+++ b/miscutils/crond.c
@@ -1047,8 +1047,14 @@ int crond_main(int argc UNUSED_PARAM, char **argv)
 	}
 
 	if (!(opts & OPT_d) && G.log_filename == NULL) {
-		/* logging to syslog */
-		openlog(applet_name, LOG_CONS | LOG_PID, LOG_CRON);
+		/* 
+		 * logging to syslog.
+		 * LOG_NDELAY: connect to syslog daemon NOW.
+		 * Otherwise, we may open syslog socket
+		 * in vforked child, making opened fds and syslog()
+		 * internal state inconsistent.
+		 */
+		openlog(applet_name, LOG_CONS | LOG_PID | LOG_NDELAY, LOG_CRON);
 		logmode = LOGMODE_SYSLOG;
 	}
 
-- 
2.1.4



_______________________________________________
busybox mailing list
busybox@busybox.net
http://lists.busybox.net/mailman/listinfo/busybox


[prev in list] [next in list] [prev in thread] [next in thread]