Hi
Early daemons like dhcpleased, slaacd, unwind, resolvd are started
before syslogd. This results in ugly sendsyslog: dropped 1 message
logs and the real message is lost.
Changing the start order of syslogd and and network daemons is not
feasible. A possible solution is a temporary buffer for log meassges
in kernel.
ok?
bluhm
Index: sys/kern/subr_log.c
===================================================================
RCS file: /data/mirror/openbsd/cvs/src/sys/kern/subr_log.c,v
retrieving revision 1.72
diff -u -p -r1.72 subr_log.c
--- sys/kern/subr_log.c 8 Feb 2021 08:18:45 -0000 1.72
+++ sys/kern/subr_log.c 5 Mar 2021 21:58:50 -0000
@@ -454,6 +454,146 @@ logioctl(dev_t dev, u_long com, caddr_t
return (0);
}
+/*
+ * If syslogd is not running, temporarily store a limited amount of messages
+ * in kernel. After log stash is full, drop messages and count them. When
+ * syslogd is available again, next log message will flush the stashed
+ * messages and insert a message with drop count. Calls to malloc(9) and
+ * copyin(9) may sleep, protect data structures with rwlock.
+ */
+
+#define LOGSTASH_SIZE 100
+struct logstash_messages {
+ char *lgs_buffer;
+ size_t lgs_size;
+} logstash_messages[LOGSTASH_SIZE];
+
+struct logstash_messages *logstash_in = &logstash_messages[0];
+struct logstash_messages *logstash_out = &logstash_messages[0];
+
+struct rwlock logstash_rwlock = RWLOCK_INITIALIZER("logstash");
+
+int logstash_dropped, logstash_error, logstash_pid;
+
+void logstash_insert(const char *, size_t, int, pid_t);
+void logstash_remove(void);
+int logstash_sendsyslog(struct proc *);
+
+static inline int
+logstash_empty(void)
+{
+ rw_assert_anylock(&logstash_rwlock);
+
+ return logstash_out->lgs_buffer == NULL;
+}
+
+static inline int
+logstash_full(void)
+{
+ rw_assert_anylock(&logstash_rwlock);
+
+ return logstash_out->lgs_buffer != NULL &&
+ logstash_in == logstash_out;
+}
+
+static inline void
+logstash_increment(struct logstash_messages **msg)
+{
+ rw_assert_wrlock(&logstash_rwlock);
+
+ KASSERT((*msg) >= &logstash_messages[0]);
+ KASSERT((*msg) < &logstash_messages[LOGSTASH_SIZE]);
+ (*msg)++;
+ if ((*msg) == &logstash_messages[LOGSTASH_SIZE])
+ (*msg) = &logstash_messages[0];
+}
+
+void
+logstash_insert(const char *buf, size_t nbyte, int error, pid_t pid)
+{
+ rw_enter_write(&logstash_rwlock);
+
+ if (logstash_full()) {
+ if (logstash_dropped == 0) {
+ logstash_error = error;
+ logstash_pid = pid;
+ }
+ logstash_dropped++;
+
+ rw_exit(&logstash_rwlock);
+ return;
+ }
+
+ logstash_in->lgs_buffer = malloc(nbyte, M_LOG, M_WAITOK);
+ copyin(buf, logstash_in->lgs_buffer, nbyte);
+ logstash_in->lgs_size = nbyte;
+ logstash_increment(&logstash_in);
+
+ rw_exit(&logstash_rwlock);
+}
+
+void
+logstash_remove(void)
+{
+ rw_assert_wrlock(&logstash_rwlock);
+
+ KASSERT(!logstash_empty());
+ free(logstash_out->lgs_buffer, M_LOG, logstash_out->lgs_size);
+ logstash_out->lgs_buffer = NULL;
+ logstash_increment(&logstash_out);
+
+ /* Insert dropped message in sequence where messages were dropped. */
+ if (logstash_dropped) {
+ size_t l, nbyte;
+ char buf[80];
+
+ l = snprintf(buf, sizeof(buf),
+ "<%d>sendsyslog: dropped %d message%s, error %d, pid %d",
+ LOG_KERN|LOG_WARNING, logstash_dropped,
+ logstash_dropped == 1 ? "" : "s",
+ logstash_error, logstash_pid);
+ logstash_dropped = 0;
+ logstash_error = 0;
+ logstash_pid = 0;
+
+ /* Cannot fail, we have just freed a slot. */
+ KASSERT(!logstash_full());
+ nbyte = ulmin(l, sizeof(buf) - 1);
+ logstash_in->lgs_buffer = malloc(nbyte, M_LOG, M_WAITOK);
+ memcpy(logstash_in->lgs_buffer, buf, nbyte);
+ logstash_in->lgs_size = nbyte;
+ logstash_increment(&logstash_in);
+ }
+}
+
+int
+logstash_sendsyslog(struct proc *p)
+{
+ int error;
+
+ rw_enter_write(&logstash_rwlock);
+
+ while (logstash_out->lgs_buffer != NULL) {
+ error = dosendsyslog(p, logstash_out->lgs_buffer,
+ logstash_out->lgs_size, 0, UIO_SYSSPACE);
+ if (error) {
+ rw_exit(&logstash_rwlock);
+ return (error);
+ }
+ logstash_remove();
+ }
+
+ rw_exit(&logstash_rwlock);
+ return (0);
+}
+
+/*
+ * Send syslog(3) message from userland to socketpair(2) created by syslogd(8).
+ * Store message in kernel log stash for later if syslogd(8) is not available
+ * or sending fails. Send to console if LOG_CONS is set and syslogd(8) socket
+ * does not exist.
+ */
+
int
sys_sendsyslog(struct proc *p, void *v, register_t *retval)
{
@@ -462,32 +602,18 @@ sys_sendsyslog(struct proc *p, void *v,
syscallarg(size_t) nbyte;
syscallarg(int) flags;
} */ *uap = v;
+ size_t nbyte;
int error;
- static int dropped_count, orig_error, orig_pid;
- if (dropped_count) {
- size_t l;
- char buf[80];
+ nbyte = SCARG(uap, nbyte);
+ if (nbyte > LOG_MAXLINE)
+ nbyte = LOG_MAXLINE;
- l = snprintf(buf, sizeof(buf),
- "<%d>sendsyslog: dropped %d message%s, error %d, pid %d",
- LOG_KERN|LOG_WARNING, dropped_count,
- dropped_count == 1 ? "" : "s", orig_error, orig_pid);
- error = dosendsyslog(p, buf, ulmin(l, sizeof(buf) - 1),
- 0, UIO_SYSSPACE);
- if (error == 0) {
- dropped_count = 0;
- orig_error = 0;
- orig_pid = 0;
- }
- }
- error = dosendsyslog(p, SCARG(uap, buf), SCARG(uap, nbyte),
- SCARG(uap, flags), UIO_USERSPACE);
- if (error) {
- dropped_count++;
- orig_error = error;
- orig_pid = p->p_p->ps_pid;
- }
+ logstash_sendsyslog(p);
+ error = dosendsyslog(p, SCARG(uap, buf), nbyte, SCARG(uap, flags),
+ UIO_USERSPACE);
+ if (error)
+ logstash_insert(SCARG(uap, buf), nbyte, error, p->p_p->ps_pid);
return (error);
}
@@ -504,9 +630,6 @@ dosendsyslog(struct proc *p, const char
struct uio auio;
size_t i, len;
int error;
-
- if (nbyte > LOG_MAXLINE)
- nbyte = LOG_MAXLINE;
/* Global variable syslogf may change during sleep, use local copy. */
fp = syslogf;
Index: sys/sys/malloc.h
===================================================================
RCS file: /data/mirror/openbsd/cvs/src/sys/sys/malloc.h,v
retrieving revision 1.120
diff -u -p -r1.120 malloc.h
--- sys/sys/malloc.h 23 Feb 2021 13:50:16 -0000 1.120
+++ sys/sys/malloc.h 4 Mar 2021 23:11:04 -0000
@@ -83,7 +83,7 @@
/* 21 - free */
#define M_NFSREQ 22 /* NFS request header */
#define M_NFSMNT 23 /* NFS mount structure */
-/* 24 - free */
+#define M_LOG 24 /* Messages in kernel log stash */
#define M_VNODE 25 /* Dynamically allocated vnodes */
#define M_CACHE 26 /* Dynamically allocated cache entries
*/
#define M_DQUOT 27 /* UFS quota entries */
@@ -208,7 +208,7 @@
NULL, \
"NFS req", /* 22 M_NFSREQ */ \
"NFS mount", /* 23 M_NFSMNT */ \
- NULL, \
+ "log", /* 24 M_LOG */ \
"vnodes", /* 25 M_VNODE */ \
"namecache", /* 26 M_CACHE */ \
"UFS quota", /* 27 M_DQUOT */ \
Index: lib/libc/sys/sendsyslog.2
===================================================================
RCS file: /data/mirror/openbsd/cvs/src/lib/libc/sys/sendsyslog.2,v
retrieving revision 1.12
diff -u -p -r1.12 sendsyslog.2
--- lib/libc/sys/sendsyslog.2 5 Nov 2020 16:04:39 -0000 1.12
+++ lib/libc/sys/sendsyslog.2 5 Mar 2021 19:15:10 -0000
@@ -51,10 +51,12 @@ This is used internally by
so that messages can be sent during difficult situations.
If sending to
.Xr syslogd 8
-fails, dropped messages are counted.
+fails, up to 100 messages are stashed in the kernel.
+After that, dropped messages are counted.
When
.Xr syslogd 8
-works again, a warning with the counter and error number is logged.
+works again, before the next message, stashed messages and possibly
+a warning with the drop counter, error number, and pid is logged.
.Pp
To receive messages from the kernel,
.Xr syslogd 8
Index: usr.sbin/syslogd/syslogd.c
===================================================================
RCS file: /data/mirror/openbsd/cvs/src/usr.sbin/syslogd/syslogd.c,v
retrieving revision 1.264
diff -u -p -r1.264 syslogd.c
--- usr.sbin/syslogd/syslogd.c 14 Sep 2020 20:36:01 -0000 1.264
+++ usr.sbin/syslogd/syslogd.c 6 Mar 2021 09:27:52 -0000
@@ -891,6 +891,10 @@ main(int argc, char *argv[])
if (sigprocmask(SIG_SETMASK, &sigmask, NULL) == -1)
err(1, "sigprocmask unblock");
+ /* Send message via libc, flushes log stash in kernel. */
+ openlog("syslogd", LOG_PID, LOG_SYSLOG);
+ syslog(LOG_DEBUG, "running");
+
event_dispatch();
/* NOTREACHED */
return (0);
