On 09/27/2012 10:44 AM, Daniel P. Berrange wrote:
> From: "Daniel P. Berrange" <berrange@xxxxxxxxxx>
>
> 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@xxxxxxxxxx>
> ---
> 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@xxxxxxxxxx +1-919-301-3266
Libvirt virtualization library http://libvirt.org
Attachment:
signature.asc
Description: OpenPGP digital signature
-- libvir-list mailing list libvir-list@xxxxxxxxxx https://www.redhat.com/mailman/listinfo/libvir-list