On Sat, 30 Mar 2024 at 16:46, Stephen Hemminger
<stephen@networkplumber.org> wrote:
>
> If DPDK application is being run as a systemd service, then
> it can use the journal protocol which allows putting more information
> in the log such as priority and other information.
>
> The use of journal protocol is automatically detected and
> handled. Rather than having a dependency on libsystemd,
> just use the protocol directly as defined in:
> https://systemd.io/JOURNAL_NATIVE_PROTOCOL/
>
> Signed-off-by: Stephen Hemminger <stephen@networkplumber.org>
> ---
> doc/guides/prog_guide/log_lib.rst | 14 ++
> lib/eal/common/eal_common_options.c | 11 ++
> lib/eal/common/eal_options.h | 2 +
> lib/log/log.c | 5 +
> lib/log/log_internal.h | 3 +
> lib/log/log_journal.c | 200 ++++++++++++++++++++++++++++
> lib/log/log_private.h | 2 +
> lib/log/log_stubs.c | 11 +-
> lib/log/meson.build | 10 +-
> lib/log/version.map | 1 +
> 10 files changed, 255 insertions(+), 4 deletions(-)
> create mode 100644 lib/log/log_journal.c
This is very nice work, I like it a lot!
> +/*
> + * send structured message using journal protocol
> + * See: https://systemd.io/JOURNAL_NATIVE_PROTOCOL/
> + */
> +static int
> +journal_send(const char *buf, size_t len)
> +{
> + struct iovec iov[4];
> + unsigned int n = 0;
> + int priority = rte_log_cur_msg_loglevel() - 1;
> + char msg[] = "MESSAGE=";
> + char newline = '\n';
> + char pbuf[16]; /* "PRIORITY=N\n" */
> +
> + iov[n].iov_base = msg;
> + iov[n++].iov_len = strlen(msg);
> +
> + iov[n].iov_base = (char *)(uintptr_t)buf;
> + iov[n++].iov_len = len;
> +
> + /* if message doesn't end with newline, one will be applied. */
> + if (buf[len - 1] != '\n') {
> + iov[n].iov_base = &newline;
> + iov[n++].iov_len = 1;
> + }
> +
> + /* priority value between 0 ("emerg") and 7 ("debug") */
> + iov[n].iov_base = pbuf;
> + iov[n++].iov_len = snprintf(pbuf, sizeof(pbuf),
> + "PRIORITY=%d\n", priority);
> +
> + return writev(log_journal_fd, iov, n);
> +}
Doesn't need to be implemented immediately, but the nicest thing about
talking directly to the journal is the ability to send lots of
arbitrary and useful metadata together with a message, so would be
nice if the logging function took an optional string vector that is
appended, or some other such mechanism.
A very useful example is creating a UUID and then setting
MESSAGE_ID=uuid when logging particularly important messages that are
useful to filter by this type - for example, when an interface state
changes to up/down. That way, one can do 'journalctl MESSAGE_ID=abc..'
and get all messages about interface state changes. A project can also
ship a catalog file that adds additional context to each ID, that is
automatically parsed and displayed to users.
@@ -100,6 +100,20 @@ option. There are three possible settings for this option:
If ``--syslog`` option is not specified, then only console (stderr) will be used.
+Messages can be redirected to systemd journal which is an enhanced version of syslog with the ``--log-journal`` option.
+
+There are three possible settings for this option:
+
+*auto*
+ If stderr is redirected to journal by ``systemd`` service
+ then use journal socket to instead of stderr for log.
+ This is the default.
+
+*never*
+ Do not try to use journal.
+
+*always*
+ Always try to direct messages to journal socket.
Using Logging APIs to Generate Log Messages
@@ -74,6 +74,7 @@ eal_long_options[] = {
{OPT_IOVA_MODE, 1, NULL, OPT_IOVA_MODE_NUM },
{OPT_LCORES, 1, NULL, OPT_LCORES_NUM },
{OPT_LOG_LEVEL, 1, NULL, OPT_LOG_LEVEL_NUM },
+ {OPT_LOG_JOURNAL, 2, NULL, OPT_LOG_JOURNAL_NUM },
{OPT_LOG_TIMESTAMP, 2, NULL, OPT_LOG_TIMESTAMP_NUM },
{OPT_TRACE, 1, NULL, OPT_TRACE_NUM },
{OPT_TRACE_DIR, 1, NULL, OPT_TRACE_DIR_NUM },
@@ -1617,6 +1618,7 @@ eal_log_level_parse(int argc, char * const argv[])
switch (opt) {
case OPT_LOG_LEVEL_NUM:
case OPT_SYSLOG_NUM:
+ case OPT_LOG_JOURNAL_NUM:
case OPT_LOG_TIMESTAMP_NUM:
if (eal_parse_common_option(opt, optarg, internal_conf) < 0)
return -1;
@@ -1843,6 +1845,14 @@ eal_parse_common_option(int opt, const char *optarg,
return -1;
}
break;
+
+ case OPT_LOG_JOURNAL_NUM:
+ if (eal_log_journal(optarg) < 0) {
+ EAL_LOG(ERR, "invalid parameters for --"
+ OPT_LOG_JOURNAL);
+ return -1;
+ }
+ break;
#endif
case OPT_LOG_LEVEL_NUM:
@@ -2223,6 +2233,7 @@ eal_common_usage(void)
" --"OPT_PROC_TYPE" Type of this process (primary|secondary|auto)\n"
#ifndef RTE_EXEC_ENV_WINDOWS
" --"OPT_SYSLOG"[=<when>] Enable use of syslog\n"
+ " --"OPT_LOG_JOURNAL"[=<when>] Enable use of systemd journal\n"
#endif
" --"OPT_LOG_LEVEL"=<level> Set global log level\n"
" --"OPT_LOG_LEVEL"=<type-match>:<level>\n"
@@ -35,6 +35,8 @@ enum {
OPT_LCORES_NUM,
#define OPT_LOG_LEVEL "log-level"
OPT_LOG_LEVEL_NUM,
+#define OPT_LOG_JOURNAL "log-journal"
+ OPT_LOG_JOURNAL_NUM,
#define OPT_LOG_TIMESTAMP "log-timestamp"
OPT_LOG_TIMESTAMP_NUM,
#define OPT_TRACE "trace"
@@ -508,6 +508,11 @@ eal_log_init(const char *id)
#else
bool is_terminal = isatty(STDERR_FILENO);
+#ifdef RTE_EXEC_ENV_LINUX
+ if (log_journal_enabled())
+ log_journal_open(id);
+ else
+#endif
if (log_syslog_enabled(is_terminal))
log_syslog_open(id, is_terminal);
else
@@ -29,6 +29,9 @@ int eal_log_save_pattern(const char *pattern, uint32_t level);
__rte_internal
int eal_log_syslog(const char *name);
+__rte_internal
+int eal_log_journal(const char *opt);
+
/*
* Convert log level to string.
*/
new file mode 100644
@@ -0,0 +1,200 @@
+/* SPDX-License-Identifier: BSD-3-Clause */
+
+#include <limits.h>
+#include <stdbool.h>
+#include <stdint.h>
+#include <stdio.h>
+#include <stdlib.h>
+#include <string.h>
+#include <sys/socket.h>
+#include <sys/stat.h>
+#include <sys/uio.h>
+#include <sys/un.h>
+#include <unistd.h>
+
+#include <rte_common.h>
+#include <rte_log.h>
+
+#include "log_internal.h"
+#include "log_private.h"
+
+static enum {
+ LOG_JOURNAL_NEVER = 0, /* do not use journal */
+ LOG_JOURNAL_AUTO, /* use if stderr is set to journal */
+ LOG_JOURNAL_ALWAYS, /* always try to use journal */
+} log_journal_opt = LOG_JOURNAL_AUTO;
+
+static int log_journal_fd = -1;
+
+int
+eal_log_journal(const char *str)
+{
+ if (str == NULL || strcmp(str, "auto") == 0)
+ log_journal_opt = LOG_JOURNAL_AUTO;
+ else if (strcmp(str, "always") == 0)
+ log_journal_opt = LOG_JOURNAL_ALWAYS;
+ else if (strcmp(str, "never") == 0)
+ log_journal_opt = LOG_JOURNAL_NEVER;
+ else
+ return -1;
+ return 0;
+}
+
+/*
+ * send structured message using journal protocol
+ * See: https://systemd.io/JOURNAL_NATIVE_PROTOCOL/
+ */
+static int
+journal_send(const char *buf, size_t len)
+{
+ struct iovec iov[4];
+ unsigned int n = 0;
+ int priority = rte_log_cur_msg_loglevel() - 1;
+ char msg[] = "MESSAGE=";
+ char newline = '\n';
+ char pbuf[16]; /* "PRIORITY=N\n" */
+
+ iov[n].iov_base = msg;
+ iov[n++].iov_len = strlen(msg);
+
+ iov[n].iov_base = (char *)(uintptr_t)buf;
+ iov[n++].iov_len = len;
+
+ /* if message doesn't end with newline, one will be applied. */
+ if (buf[len - 1] != '\n') {
+ iov[n].iov_base = &newline;
+ iov[n++].iov_len = 1;
+ }
+
+ /* priority value between 0 ("emerg") and 7 ("debug") */
+ iov[n].iov_base = pbuf;
+ iov[n++].iov_len = snprintf(pbuf, sizeof(pbuf),
+ "PRIORITY=%d\n", priority);
+
+ return writev(log_journal_fd, iov, n);
+}
+
+
+/* wrapper for log stream to put messages into journal */
+static ssize_t
+journal_log_write(__rte_unused void *c, const char *buf, size_t size)
+{
+ return journal_send(buf, size);
+}
+
+static int
+journal_log_close(__rte_unused void *c)
+{
+ close(log_journal_fd);
+ log_journal_fd = -1;
+ return 0;
+}
+
+static cookie_io_functions_t journal_log_func = {
+ .write = journal_log_write,
+ .close = journal_log_close,
+};
+
+/*
+ * Check if stderr is going to system journal.
+ * This is the documented way to handle systemd journal
+ *
+ * See: https://systemd.io/JOURNAL_NATIVE_PROTOCOL/
+ *
+ */
+static bool
+is_journal(int fd)
+{
+ char *jenv, *endp = NULL;
+ struct stat st;
+ unsigned long dev, ino;
+
+ jenv = getenv("JOURNAL_STREAM");
+ if (jenv == NULL)
+ return false;
+
+ if (fstat(fd, &st) < 0)
+ return false;
+
+ /* systemd sets colon-separated list of device and inode number */
+ dev = strtoul(jenv, &endp, 10);
+ if (endp == NULL || *endp != ':')
+ return false; /* missing colon */
+
+ ino = strtoul(endp + 1, NULL, 10);
+
+ return dev == st.st_dev && ino == st.st_ino;
+}
+
+/* Connect to systemd's journal service */
+static int
+open_journal(void)
+{
+ struct sockaddr_un sun = {
+ .sun_family = AF_UNIX,
+ .sun_path = "/run/systemd/journal/socket",
+ };
+ int s;
+
+ s = socket(AF_UNIX, SOCK_DGRAM, 0);
+ if (s < 0) {
+ perror("socket");
+ return -1;
+ }
+
+ if (connect(s, (struct sockaddr *)&sun, sizeof(sun)) < 0) {
+ perror("connect");
+ close(s);
+ return -1;
+ }
+
+ return s;
+}
+
+bool log_journal_enabled(void)
+{
+ if (log_journal_opt == LOG_JOURNAL_NEVER)
+ return false;
+
+ if (log_journal_opt == LOG_JOURNAL_AUTO &&
+ !is_journal(STDERR_FILENO))
+ return false;
+
+ log_journal_fd = open_journal();
+ if (log_journal_fd < 0)
+ return false;
+
+ return true;
+}
+
+void log_journal_open(const char *id)
+{
+ FILE *log_stream;
+ char *syslog_id = NULL;
+ ssize_t len;
+
+ /* Send identifier as first message */
+ len = asprintf(&syslog_id, "SYSLOG_IDENTIFIER=%s\nSYSLOG_PID=%u",
+ id, getpid());
+ if (len == 0)
+ goto error;
+
+ if (write(log_journal_fd, syslog_id, len) != len) {
+ perror("write");
+ goto error;
+ }
+
+ free(syslog_id);
+
+ /* redirect other log messages to journal */
+ log_stream = fopencookie(NULL, "w", journal_log_func);
+ if (log_stream != NULL) {
+ rte_openlog_stream(log_stream);
+ return;
+ }
+
+error:
+ free(syslog_id);
+ close(log_journal_fd);
+ log_journal_fd = -1;
+}
@@ -20,5 +20,7 @@ int log_print_with_timestamp(FILE *f, const char *format, va_list ap);
bool log_syslog_enabled(bool is_tty);
void log_syslog_open(const char *id, bool is_terminal);
+bool log_journal_enabled(void);
+void log_journal_open(const char *id);
#endif /* LOG_PRIVATE_H */
@@ -20,9 +20,18 @@
#include "log_internal.h"
#include "log_private.h"
-/* Stubs for Windows */
+#ifdef RTE_EXEC_ENV_WINDOWS
int
eal_log_syslog(const char *str __rte_unused)
{
return -1;
}
+#endif
+
+#ifndef RTE_EXEC_ENV_LINUX
+int
+eal_log_journal(const char *str __rte_unused)
+{
+ return -1;
+}
+#endif
@@ -7,10 +7,14 @@ sources = files(
'log_timestamp.c',
)
-if is_windows
- sources += files('log_stubs.c')
-else
+if not is_windows
sources += files('log_syslog.c')
endif
+if is_linux
+ sources += files('log_journal.c')
+else
+ sources += files('log_stubs.c')
+endif
+
headers = files('rte_log.h')
@@ -26,6 +26,7 @@ INTERNAL {
global:
eal_log_init;
+ eal_log_journal;
eal_log_level2str;
eal_log_save_pattern;
eal_log_save_regexp;