On 09/27/2012 10:44 AM, Daniel P. Berrange wrote:
From: "Daniel P. Berrange" <berrange@redhat.com>
Add support for logging to the systemd journal, using its simple client library. The benefit over syslog is that it accepts structured log data, so the journald can store individual items like code file/line/func separately from the string message. Tools which require structured log data can then query the journal to extract exactly what they desire without resorting to string parsing
While systemd provides a simple client library for logging, it is more convenient for libvirt to directly write its own client code. This lets us build up the iovec's on the stack, avoiding the need to alloc memory when writing log messages.
Signed-off-by: Daniel P. Berrange <berrange@redhat.com> --- cfg.mk | 2 +- src/util/logging.c | 177 +++++++++++++++++++++++++++++++++++++++++++++++++++++ src/util/logging.h | 1 + 3 files changed, 179 insertions(+), 1 deletion(-)
I'll need a v2 on this one. Fails to compile: util/logging.c: In function 'virLogOutputToJournald': util/logging.c:1124:84: error: ordered comparison of pointer with integer zero [-Werror=extra] util/logging.c:1124:18: error: ignoring return value of 'virStrcpy', declared with attribute warn_unused_result [-Werror=unused-result] cc1: all warnings being treated as errors
diff --git a/cfg.mk b/cfg.mk index bbfd4a2..4482d70 100644 --- a/cfg.mk +++ b/cfg.mk @@ -771,7 +771,7 @@ exclude_file_name_regexp--sc_prohibit_asprintf = \ ^(bootstrap.conf$$|src/util/util\.c$$|examples/domain-events/events-c/event-test\.c$$)
exclude_file_name_regexp--sc_prohibit_close = \ - (\.p[yl]$$|^docs/|^(src/util/virfile\.c|src/libvirt\.c)$$) + (\.p[yl]$$|^docs/|^(src/util/virfile\.c|src/libvirt\.c|src/util/logging\.c)$$)
That's a bit of a heavy hammer, just to avoid a recursively-logged close(). I'd rather omit this and use VIR_LOG_CLOSE().
+ + +# define IOVEC_SET_STRING(iov, str) \ + do { \ + struct iovec *_i = &(iov); \ + _i->iov_base = (char*)str; \ + _i->iov_len = strlen(str); \ + } while (0) + +# define IOVEC_SET_INT(iov, buf, fmt, val) \ + do { \ + struct iovec *_i = &(iov); \ + snprintf(buf, sizeof(buf), fmt, val); \
Technically, snprintf is not async-signal safe, which kind of goes against the idea of using it in our logging functions. I'd much rather see us do a hand-rolled conversion of int to %d or %zu (which appear to be the only formats you ever pass here).
+ _i->iov_base = buf; \ + _i->iov_len = strlen(buf); \
[Pedantic - even strlen() is not async-signal safe, but that appears to be a bug in POSIX and I have no qualms about using it here; on the other hand, since snprintf() can malloc() (gasp!) POSIX really is correct in listing it as non-safe, and we really shouldn't be using it in this context]
+ } while (0) + +static int journalfd = -1; + +static void +virLogOutputToJournald(virLogSource source, + virLogPriority priority, + const char *filename, + size_t linenr, + const char *funcname, + const char *timestamp ATTRIBUTE_UNUSED, + unsigned int flags, + const char *rawstr, + const char *str ATTRIBUTE_UNUSED, + void *data ATTRIBUTE_UNUSED) +{ + virCheckFlags(VIR_LOG_STACK_TRACE,);
This looks odd, until you remember it is a macro, and doing the correct thing.
+ int buffd = -1; + size_t niov = 0; + struct msghdr mh; + struct sockaddr_un sa; + union { + struct cmsghdr cmsghdr; + uint8_t buf[CMSG_SPACE(sizeof(int))]; + } control; + struct cmsghdr *cmsg; + /* We use /dev/shm instead of /tmp here, since we want this to + * be a tmpfs, and one that is available from early boot on + * and where unprivileged users can create files. */ + char path[] = "/dev/shm/journal.XXXXXX"; + char priostr[INT_BUFSIZE_BOUND(priority)]; + char linestr[INT_BUFSIZE_BOUND(priority)]; + + /* First message takes upto 4 iovecs, and each
s/upto/up to/
+ * other field needs 3, assuming they don't have + * newlines in them + */ +# define IOV_SIZE (4 + (5 * 3)) + struct iovec iov[IOV_SIZE]; + + if (strchr(rawstr, '\n')) {
[Pedantic - strchr() is another one of those functions surprisingly omitted from the async-safe list, but I have no qualms in using it]
+ uint64_t nstr; + /* If 'str' containes a newline, then we must
s/containes/contains/
+ * encode the string length, since we can't + * rely on the newline for the field separator + */ + IOVEC_SET_STRING(iov[niov++], "MESSAGE\n"); + nstr = htole64(strlen(rawstr));
htole64() is a glibc extension which does not exist on mingw, and has not (yet) been ported to gnulib. Then again, this code is inside #ifdef HAVE_SYSLOG_H, so you can probably get away with it (although I'm not sure whether all platforms that provide <syslog.h> happen to also provide htole64(), I at least know that it will exclude mingw).
+ iov[niov].iov_base = (char*)&nstr; + iov[niov].iov_len = sizeof(nstr); + niov++; + } else { + IOVEC_SET_STRING(iov[niov++], "MESSAGE="); + } + IOVEC_SET_STRING(iov[niov++], rawstr); + IOVEC_SET_STRING(iov[niov++], "\n"); + + IOVEC_SET_STRING(iov[niov++], "PRIORITY="); + IOVEC_SET_INT(iov[niov++], priostr, "%d", priority); + IOVEC_SET_STRING(iov[niov++], "\n"); + + IOVEC_SET_STRING(iov[niov++], "LIBVIRT_SOURCE="); + IOVEC_SET_STRING(iov[niov++], virLogSourceTypeToString(source)); + IOVEC_SET_STRING(iov[niov++], "\n"); + + IOVEC_SET_STRING(iov[niov++], "CODE_FILE="); + IOVEC_SET_STRING(iov[niov++], filename); + IOVEC_SET_STRING(iov[niov++], "\n"); + + IOVEC_SET_STRING(iov[niov++], "CODE_LINE="); + IOVEC_SET_INT(iov[niov++], linestr, "%zu", linenr);
You know, my earlier comments about linenr always fitting in 'int' mean you could use %u instead of %zu here, making my goal of replacing snprintf with a hand-rolled async-safe converter a bit easier.
+ IOVEC_SET_STRING(iov[niov++], "\n"); + + IOVEC_SET_STRING(iov[niov++], "CODE_FUNC="); + IOVEC_SET_STRING(iov[niov++], funcname); + IOVEC_SET_STRING(iov[niov++], "\n"); + + memset(&sa, 0, sizeof(sa)); + sa.sun_family = AF_UNIX; + if (virStrcpy(sa.sun_path, "/run/systemd/journal/socket", sizeof(sa.sun_path)) < 0) + return; + + memset(&mh, 0, sizeof(mh)); + mh.msg_name = &sa; + mh.msg_namelen = offsetof(struct sockaddr_un, sun_path) + strlen(sa.sun_path); + mh.msg_iov = iov; + mh.msg_iovlen = niov; + + if (sendmsg(journalfd, &mh, MSG_NOSIGNAL) >= 0) + return; + + if (errno != EMSGSIZE && errno != ENOBUFS) + return; + + /* Message was too large, so dump to temporary file + * and pass an FD to the journal + */ + + if ((buffd = mkostemp(path, O_CLOEXEC|O_RDWR)) < 0)
Is mkostemp async-signal safe? But if it isn't, I don't know how else to generate a safe file name. Maybe we create ourselves a safe temporary directory at process start where we don't care about the async safety issues, and then in this function, we track a static counter that we increment each time we create a new file within that directory.
+ return; + + if (unlink(path) < 0) + goto cleanup; + + if (writev(buffd, iov, niov) < 0)
Again, mingw and gnulib lacks writev(), but this function isn't compiled on mingw, so we're safe for now.
+ goto cleanup; + + mh.msg_iov = NULL; + mh.msg_iovlen = 0; + + memset(&control, 0, sizeof(control)); + mh.msg_control = &control; + mh.msg_controllen = sizeof(control); + + cmsg = CMSG_FIRSTHDR(&mh); + cmsg->cmsg_level = SOL_SOCKET; + cmsg->cmsg_type = SCM_RIGHTS; + cmsg->cmsg_len = CMSG_LEN(sizeof(int)); + memcpy(CMSG_DATA(cmsg), &buffd, sizeof(int)); + + mh.msg_controllen = cmsg->cmsg_len; + + sendmsg(journalfd, &mh, MSG_NOSIGNAL); + +cleanup: + close(buffd);
VIR_LOG_CLOSE() works just fine here (but not VIR_FORCE_CLOSE, as that is an accident waiting to trigger recursive logging)
+} + + +static void virLogCloseJournald(void *data ATTRIBUTE_UNUSED) +{ + close(journalfd); +} + + +static int virLogAddOutputToJournald(int priority) +{ + if ((journalfd = socket(AF_UNIX, SOCK_DGRAM, 0)) < 0) + return -1; + if (virSetInherit(journalfd, false) < 0) {
Why not use SOCK_DGRAM | SOCK_CLOEXEC in the socket() call?
+ close(journalfd); + return -1; + } + if (virLogDefineOutput(virLogOutputToJournald, virLogCloseJournald, NULL, + priority, VIR_LOG_TO_JOURNALD, NULL, 0) < 0) { + return -1; + } + return 0; +} #endif /* HAVE_SYSLOG_H */
#define IS_SPACE(cur) \ @@ -1114,6 +1285,12 @@ virLogParseOutputs(const char *outputs) count++; VIR_FREE(name); VIR_FREE(abspath); + } else if (STREQLEN(cur, "journald", 8)) { + cur += 8; +#if HAVE_SYSLOG_H
Do we really want to silently parse and ignore 'journald' on systems that lack syslog.h?
+ if (virLogAddOutputToJournald(prio) == 0) + count++; +#endif /* HAVE_SYSLOG_H */ } else { goto cleanup; } diff --git a/src/util/logging.h b/src/util/logging.h index e5918db..d4aa62b 100644 --- a/src/util/logging.h +++ b/src/util/logging.h @@ -80,6 +80,7 @@ typedef enum { VIR_LOG_TO_STDERR = 1, VIR_LOG_TO_SYSLOG, VIR_LOG_TO_FILE, + VIR_LOG_TO_JOURNALD, } virLogDestination;
typedef enum {
Here's a minimum of what I propose squashing in: diff --git i/cfg.mk w/cfg.mk index 4482d70..bbfd4a2 100644 --- i/cfg.mk +++ w/cfg.mk @@ -771,7 +771,7 @@ exclude_file_name_regexp--sc_prohibit_asprintf = \ ^(bootstrap.conf$$|src/util/util\.c$$|examples/domain-events/events-c/event-test\.c$$) exclude_file_name_regexp--sc_prohibit_close = \ - (\.p[yl]$$|^docs/|^(src/util/virfile\.c|src/libvirt\.c|src/util/logging\.c)$$) + (\.p[yl]$$|^docs/|^(src/util/virfile\.c|src/libvirt\.c)$$) exclude_file_name_regexp--sc_prohibit_empty_lines_at_EOF = \ (^tests/(qemuhelp|nodeinfo)data/|\.(gif|ico|png|diff)$$) diff --git i/src/util/logging.c w/src/util/logging.c index 367c8e1..32ade71 100644 --- i/src/util/logging.c +++ w/src/util/logging.c @@ -1121,7 +1121,7 @@ virLogOutputToJournald(virLogSource source, memset(&sa, 0, sizeof(sa)); sa.sun_family = AF_UNIX; - if (virStrcpy(sa.sun_path, "/run/systemd/journal/socket", sizeof(sa.sun_path)) < 0) + if (virStrcpyStatic(sa.sun_path, "/run/systemd/journal/socket") == NULL) return; memset(&mh, 0, sizeof(mh)); @@ -1167,13 +1167,13 @@ virLogOutputToJournald(virLogSource source, sendmsg(journalfd, &mh, MSG_NOSIGNAL); cleanup: - close(buffd); + VIR_LOG_CLOSE(buffd); } static void virLogCloseJournald(void *data ATTRIBUTE_UNUSED) { - close(journalfd); + VIR_LOG_CLOSE(journalfd); } @@ -1182,7 +1182,7 @@ static int virLogAddOutputToJournald(int priority) if ((journalfd = socket(AF_UNIX, SOCK_DGRAM, 0)) < 0) return -1; if (virSetInherit(journalfd, false) < 0) { - close(journalfd); + VIR_LOG_CLOSE(journalfd); return -1; } if (virLogDefineOutput(virLogOutputToJournald, virLogCloseJournald, NULL, -- Eric Blake eblake@redhat.com +1-919-301-3266 Libvirt virtualization library http://libvirt.org