Hi, journald fails to forward messages to syslog when it is using Server->syslog_fd even before the limit of /proc/sys/net/unix/max_dgram_qlen is reached.
For this experiment, 1) I have made sure /proc/sys/net/unix/max_dgram_qlen is set to 9999 before syslog.socket is created. 2) Replaced rsyslog.service's ExecStart with /bin/sleep 3) Booted system and observed following messages: systemd-journal[434]: Forwarding to syslog missed 2 messages. (succeed 274 messages) [*] systemd-journal[434]: Forwarding to syslog missed 183 messages. (succeed 274 messages) systemd-journal[434]: Forwarding to syslog missed 41 messages. (succeed 274 messages) This got me interested since we are loosing messages and after further debugging I have come up with attached patch [**]. After booting up the system and filling up the journal with "systemd-cat echo hello", following correct behavior is observed. systemd-journal[449]: Forwarding to syslog missed 1 messages. (succeed 10000 messages) It is same hardware and clearly I have enough memory to store 1000 messages. I can't explain why it would make a difference to use Server->syslog_fd vs a new socket fd but something is not right and hopefully someone can explain. Further, we can fix journal so we won't miss messages. Thank you Umut [*] The number 274 fluctuates a bit between boots and I patched journald to display how many messages have been sent to syslog. [**] Patch is only to show proof of concept and not optimized.
diff --git a/systemd/src/journal/journald-server.h b/systemd/src/journal/journald-server.h index 42a2235..b4117f7 100644 --- a/systemd/src/journal/journald-server.h +++ b/systemd/src/journal/journald-server.h @@ -100,6 +100,7 @@ typedef struct Server { bool forward_to_wall; unsigned n_forward_syslog_missed; + unsigned n_forward_syslog_success; usec_t last_warn_forward_syslog_missed; uint64_t cached_available_space; diff --git a/systemd/src/journal/journald-syslog.c b/systemd/src/journal/journald-syslog.c index b826e23..537386f 100644 --- a/systemd/src/journal/journald-syslog.c +++ b/systemd/src/journal/journald-syslog.c @@ -37,6 +37,7 @@ static void forward_syslog_iovec(Server *s, const struct iovec *iovec, unsigned n_iovec, struct ucred *ucred, struct timeval *tv) { + int fd = -1; union sockaddr_union sa = { .un.sun_family = AF_UNIX, .un.sun_path = "/run/systemd/journal/syslog", @@ -71,12 +72,22 @@ static void forward_syslog_iovec(Server *s, const struct iovec *iovec, unsigned msghdr.msg_controllen = cmsg->cmsg_len; } + fd = socket(AF_UNIX, SOCK_DGRAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0); + if (fd < 0) { + log_debug("Failed to create a socket"); + return; + } + + /* Forward the syslog message we received via /dev/log to * /run/systemd/syslog. Unfortunately we currently can't set * the SO_TIMESTAMP auxiliary data, and hence we don't. */ - if (sendmsg(s->syslog_fd, &msghdr, MSG_NOSIGNAL) >= 0) + if (sendmsg(fd, &msghdr, MSG_NOSIGNAL) >= 0) { + s->n_forward_syslog_success++; + close(fd); return; + } /* The socket is full? I guess the syslog implementation is * too slow, and we shouldn't wait for that... */ @@ -96,17 +107,22 @@ static void forward_syslog_iovec(Server *s, const struct iovec *iovec, unsigned u.pid = getpid(); memcpy(CMSG_DATA(cmsg), &u, sizeof(struct ucred)); - if (sendmsg(s->syslog_fd, &msghdr, MSG_NOSIGNAL) >= 0) + if (sendmsg(fd, &msghdr, MSG_NOSIGNAL) >= 0) { + s->n_forward_syslog_success++; + close(fd); return; + } if (errno == EAGAIN) { s->n_forward_syslog_missed++; + close(fd); return; } } if (errno != ENOENT) log_debug("Failed to forward syslog message: %m"); + close(fd); } static void forward_syslog_raw(Server *s, int priority, const char *buffer, struct ucred *ucred, struct timeval *tv) { @@ -492,7 +508,8 @@ void server_maybe_warn_forward_syslog_missed(Server *s) { if (s->last_warn_forward_syslog_missed + WARN_FORWARD_SYSLOG_MISSED_USEC > n) return; - server_driver_message(s, SD_MESSAGE_FORWARD_SYSLOG_MISSED, "Forwarding to syslog missed %u messages.", s->n_forward_syslog_missed); + server_driver_message(s, SD_MESSAGE_FORWARD_SYSLOG_MISSED, "Forwarding to syslog missed %u messages. (succeed %u messages)", s->n_forward_syslog_missed, + s->n_forward_syslog_success); s->n_forward_syslog_missed = 0; s->last_warn_forward_syslog_missed = n;
_______________________________________________ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel