I hope to have addressed all issues.
On Sun, Mar 07, 2021 at 11:50:24AM +0000, Visa Hankala wrote:
> This copyin() can also result in copying the buffer from userspace twice.
> This might not be a problem with log data though.
Is double copyin a problem? I think error != EFAULT should catch
all cases.
On Mon, Mar 08, 2021 at 01:37:51AM +0300, Vitaliy Makkoveev wrote:
> I wonder they were not buffered. But does it make sense to drop the
> most recent messages?
The oldest message should be kept. In my experience you get most
information why logging started to fail from the first message.
After that there are subsequent errors.
new diff, 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 8 Mar 2021 19:55:52 -0000
@@ -454,6 +454,149 @@ 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_message {
+ char *lgs_buffer;
+ size_t lgs_size;
+} logstash_messages[LOGSTASH_SIZE];
+
+struct logstash_message *logstash_in = &logstash_messages[0];
+struct logstash_message *logstash_out = &logstash_messages[0];
+
+struct rwlock logstash_rwlock = RWLOCK_INITIALIZER("logstash");
+
+int logstash_dropped, logstash_error, logstash_pid;
+
+int logstash_insert(const char *, size_t, int, pid_t);
+void logstash_remove(void);
+int logstash_sendsyslog(struct proc *);
+
+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_message **msg)
+{
+ rw_assert_wrlock(&logstash_rwlock);
+
+ KASSERT((*msg) >= &logstash_messages[0]);
+ KASSERT((*msg) < &logstash_messages[LOGSTASH_SIZE]);
+ if ((*msg) == &logstash_messages[LOGSTASH_SIZE - 1])
+ (*msg) = &logstash_messages[0];
+ else
+ (*msg)++;
+}
+
+int
+logstash_insert(const char *buf, size_t nbyte, int logerror, pid_t pid)
+{
+ int error;
+
+ rw_enter_write(&logstash_rwlock);
+
+ if (logstash_full()) {
+ if (logstash_dropped == 0) {
+ logstash_error = logerror;
+ logstash_pid = pid;
+ }
+ logstash_dropped++;
+
+ rw_exit(&logstash_rwlock);
+ return (0);
+ }
+
+ logstash_in->lgs_buffer = malloc(nbyte, M_LOG, M_WAITOK);
+ error = copyin(buf, logstash_in->lgs_buffer, nbyte);
+ if (error) {
+ free(logstash_in->lgs_buffer, M_LOG, nbyte);
+ logstash_in->lgs_buffer = NULL;
+
+ rw_exit(&logstash_rwlock);
+ return (error);
+ }
+ logstash_in->lgs_size = nbyte;
+ logstash_increment(&logstash_in);
+
+ rw_exit(&logstash_rwlock);
+ return (0);
+}
+
+void
+logstash_remove(void)
+{
+ rw_assert_wrlock(&logstash_rwlock);
+
+ KASSERT(logstash_out->lgs_buffer != NULL);
+ 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 +605,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 && error != EFAULT)
+ logstash_insert(SCARG(uap, buf), nbyte, error, p->p_p->ps_pid);
return (error);
}
@@ -505,9 +634,6 @@ dosendsyslog(struct proc *p, const char
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;
if (fp)
@@ -607,7 +733,7 @@ dosendsyslog(struct proc *p, const char
#endif
if (fp)
FRELE(fp, p);
- else
+ else if (error != EFAULT)
error = ENOTCONN;
return (error);
}
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);
