[DTrace-devel] [PATCH 01/10] dtprobed: logging improvements
Kris Van Hees
kris.van.hees at oracle.com
Tue Aug 22 03:04:34 UTC 2023
On Wed, Aug 02, 2023 at 02:26:51PM +0100, Nick Alcock wrote:
> So it turns out that fuse_log() isn't marked with any of GCC's printf
> attributes. It's not so marked upstream, which is bad enough, but its
> replacment isn't marked in our tree either, so all the fuse_log()s aren't
> getting properly format-string checked.
>
> Fix that, fix a bunch of them, and fix up the logging output so it usually
> has timestamps in DTrace debug log format in it so testsuite output gets
> properly split up and so that you can correlate debug output from dtprobed
> with debug output from DTrace itself.
>
> Tie it into the daemon logging machinery (which sends error messages up the
> synchronization pipe after dtprobed has forked a daemonized child but before
> it has finished initializing and its parent has died off, for printing by
> the parent), so that fuse_log() can now be used everywhere without concern
> for whether this code is being run before dtprobed has daemonized or not.
> In the process, delete daemon_err(), a print-error-and-die function with
> no remaining uses.
>
> (Some format string errors remain after this commit, in code that is
> outright removed or rewritten in the following commits.)
>
> Signed-off-by: Nick Alcock <nick.alcock at oracle.com>
Reviewed-by: Kris Van Hees <kris.van.hees at oracle.com>
... assuming you fix the minor style issues below.
> ---
> dtprobed/dtprobed.c | 32 ++++++++++++++-------
> dtprobed/rpl_fuse_log.h | 4 ++-
> include/port.h | 6 ++--
> libport/daemonize.c | 62 +++++++++++++++++++++++++++++------------
> 4 files changed, 73 insertions(+), 31 deletions(-)
>
> diff --git a/dtprobed/dtprobed.c b/dtprobed/dtprobed.c
> index 507a412ad0de..277e489b1061 100644
> --- a/dtprobed/dtprobed.c
> +++ b/dtprobed/dtprobed.c
> @@ -17,6 +17,7 @@
> #include <stdlib.h>
> #include <string.h>
> #include <syslog.h>
> +#include <time.h>
> #include <unistd.h>
> #include <config.h>
>
> @@ -54,6 +55,7 @@
> #include <dt_list.h>
> #include "dof_parser.h"
> #include "uprobes.h"
> +#include "libproc.h"
>
> #include "seccomp-assistance.h"
>
> @@ -91,9 +93,14 @@ log_msg(enum fuse_log_level level, const char *fmt, va_list ap)
> if (!_dtrace_debug && level > FUSE_LOG_INFO)
> return;
>
> - if (foreground)
> + if (foreground) {
This should have a leading tab rather than 8 spaces.
> + fprintf(stderr, "dtprobed DEBUG %li: ", time(NULL));
> vfprintf(stderr, fmt, ap);
> - else
> + }
> + else if (sync_fd >= 0) {
This should use the style:
} else if (sync_fd >= 0) {
> + daemon_log(sync_fd, "dtprobed DEBUG %li: ", time(NULL));
> + daemon_vlog(sync_fd, fmt, ap);
> + } else
> vsyslog(level, fmt, ap);
> }
>
> @@ -105,12 +112,13 @@ dt_debug_printf(const char *subsys, const char *fmt, va_list ap)
> return;
>
> if (foreground) {
> - fprintf(stderr, "%s DEBUG: ", subsys);
> + fprintf(stderr, "%s DEBUG %li: ", subsys, time(NULL));
> vfprintf(stderr, fmt, ap);
> - } else {
> + } else if (sync_fd >= 0)
> + daemon_vlog(sync_fd, fmt, ap);
> + else
> /* Subsystem discarded (it's always 'libproc' anyway). */
> vsyslog(LOG_DEBUG, fmt, ap);
> - }
> }
>
> #if HAVE_LIBFUSE3
> @@ -317,8 +325,11 @@ dof_parser_start(int sync_fd)
> daemon_perr(sync_fd, "cannot create DOF parser pipes", errno);
>
> switch (parser_pid = fork()) {
> - case -1:
> - daemon_perr(sync_fd, "cannot fork DOF parser", errno);
> + case -1: {
> + fuse_log(FUSE_LOG_ERR, "cannot fork DOF parser: %s",
> + strerror(errno));
> + exit(1);
> + }
> case 0: {
> /*
> * Sandboxed parser child. Close unwanted fds and nail into
> @@ -452,7 +463,7 @@ helper_ioctl(fuse_req_t req, int cmd, void *arg,
> fuse_reply_ioctl(req, 0, NULL, 0);
> return;
> default: errmsg = "invalid ioctl";;
> - fuse_log(FUSE_LOG_WARNING, "%i: dtprobed: %s %lx\n",
> + fuse_log(FUSE_LOG_WARNING, "%i: dtprobed: %s %x\n",
> pid, errmsg, cmd);
> goto fuse_err;
> }
> @@ -464,6 +475,8 @@ helper_ioctl(fuse_req_t req, int cmd, void *arg,
> in.iov_base = arg;
> in.iov_len = sizeof(dof_helper_t);
>
> + fuse_log(FUSE_LOG_DEBUG, "DTRACEHIOC_ADDDOF from PID %i\n", pid);
> +
> errmsg = "error reading ioctl size";
> if (fuse_reply_ioctl_retry(req, &in, 1, NULL, 0) < 0)
> goto fuse_errmsg;
> @@ -648,8 +661,7 @@ helper_ioctl(fuse_req_t req, int cmd, void *arg,
> fuse_err:
> if (fuse_reply_err(req, EINVAL) < 0)
> fuse_log(FUSE_LOG_ERR, "%i: dtprobed: %s\n", pid,
> - "cannot send error to ioctl caller: %s",
> - errmsg);
> + "cannot send error to ioctl caller\n");
> free(userdata->buf);
> userdata->buf = NULL;
> userdata->state = DTP_IOCTL_START;
> diff --git a/dtprobed/rpl_fuse_log.h b/dtprobed/rpl_fuse_log.h
> index 5baf65a2a1a6..1415bcf7ced6 100644
> --- a/dtprobed/rpl_fuse_log.h
> +++ b/dtprobed/rpl_fuse_log.h
> @@ -9,6 +9,7 @@
> #define _RPL_FUSE_LOG_H
>
> #include <stdarg.h>
> +#include <sys/compiler.h>
>
> /*
> * Reimplementation of fuse_log API in FUSE 3.7.0+. Not used when FUSE is
> @@ -37,7 +38,8 @@ typedef void (*rpl_log_func_t)(enum fuse_log_level level, const char *fmt,
>
> void fuse_set_log_func(rpl_log_func_t func);
>
> -void fuse_log(enum fuse_log_level level, const char *fmt, ...);
> +void fuse_log(enum fuse_log_level level, const char *fmt, ...)
> + _dt_printflike_(2,3);
>
> #endif
>
> diff --git a/include/port.h b/include/port.h
> index 11215a9450c3..75d54fdf431d 100644
> --- a/include/port.h
> +++ b/include/port.h
> @@ -1,6 +1,6 @@
> /*
> * Oracle Linux DTrace.
> - * Copyright (c) 2011, 2022, Oracle and/or its affiliates. All rights reserved.
> + * Copyright (c) 2011, 2023, Oracle and/or its affiliates. All rights reserved.
> * Licensed under the Universal Permissive License v 1.0 as shown at
> * http://oss.oracle.com/licenses/upl.
> */
> @@ -10,6 +10,7 @@
>
> #include <pthread.h>
> #include <mutex.h>
> +#include <stdarg.h>
> #include <unistd.h>
> #include <sys/compiler.h>
> #include <sys/types.h>
> @@ -30,8 +31,9 @@ int mutex_init(mutex_t *m, int flags1, void *ptr);
>
> int daemonize(int close_fds);
>
> -_dt_noreturn_ void daemon_err(int fd, const char *err);
> _dt_noreturn_ void daemon_perr(int fd, const char *err, int err_no);
> +_dt_printflike_(2, 3) void daemon_log(int fd, const char *fmt, ...);
> +void daemon_vlog(int fd, const char *fmt, va_list ap);
>
> unsigned long linux_version_code(void);
>
> diff --git a/libport/daemonize.c b/libport/daemonize.c
> index f8ac0f1b43ca..43a4a9bf09b8 100644
> --- a/libport/daemonize.c
> +++ b/libport/daemonize.c
> @@ -1,6 +1,6 @@
> /*
> * Oracle Linux DTrace; become a daemon.
> - * Copyright (c) 2022, Oracle and/or its affiliates. All rights reserved.
> + * Copyright (c) 2022, 2023, Oracle and/or its affiliates. All rights reserved.
> * Licensed under the Universal Permissive License v 1.0 as shown at
> * http://oss.oracle.com/licenses/upl.
> */
> @@ -11,6 +11,8 @@
> #include <dirent.h>
> #include <errno.h>
> #include <fcntl.h>
> +#include <stdarg.h>
> +#include <stdlib.h>
> #include <signal.h>
> #include <stdio.h>
> #include <string.h>
> @@ -19,23 +21,8 @@
> #include <port.h>
>
> /*
> - * Write an error return down the synchronization pipe.
> - */
> -_dt_noreturn_
> -void
> -daemon_err(int fd, const char *err)
> -{
> - /*
> - * Not a paranoid write, no EINTR protection: all our errors are quite
> - * short and are unlikely to hit EINTR. The read side, which might
> - * block for some time, can make no such assumptions.
> - */
> - write(fd, err, strlen(err));
> - _exit(1);
> -}
> -
> -/*
> - * Write an error return featuring errno down the synchronization pipe.
> + * Write an error return featuring errno down the synchronization pipe, and
> + * terminate.
> *
> * If fd is < 0, write to stderr instead.
> */
> @@ -61,6 +48,45 @@ daemon_perr(int fd, const char *err, int err_no)
> _exit(1);
> }
>
> +/*
> + * Log a message down the synchronization pipe, using a va_list.
> + *
> + * If fd is < 0, write to stderr instead.
> + */
> +void
> +daemon_vlog(int fd, const char *fmt, va_list ap)
> +{
> + char *errstr;
> +
> + if (vasprintf(&errstr, fmt, ap) < 0)
> + daemon_perr(fd, "cannot format log string", errno);
> +
> + /*
> + * Not a paranoid write: see above.
> + */
> + if (fd >= 0)
> + write(fd, errstr, strlen(errstr));
> + else
> + fprintf(stderr, "%s", errstr);
> + free(errstr);
> +}
> +
> +/*
> + * Log a message down the synchronization pipe.
> + *
> + * If fd is < 0, write to stderr instead.
> + */
> +_dt_printflike_(2, 3)
> +void
> +daemon_log(int fd, const char *fmt, ...)
> +{
> + va_list ap;
> +
> + va_start(ap, fmt);
> + daemon_vlog(fd, fmt, ap);
> + va_end(ap);
> +}
> +
> /*
> * On failure, returns -1 in the parent.
> *
>
> base-commit: 42f15d3235bcf816ed814b88d64492a63fc5f0f0
> prerequisite-patch-id: 52ce11c079ec2f65353146f18303b24fa9ff62e2
> prerequisite-patch-id: 9bc8cfafabd7ab0579f0a27e30a87b3587bb5f9f
> prerequisite-patch-id: 36029942b8e0fb4863721accb514d53199c3cc15
> prerequisite-patch-id: 311784758ab15c7f1bb41ad1c054b9b28aa7f8a3
> prerequisite-patch-id: 6dae9b2a704bdf47b0c5fe33419c6192a90022e6
> prerequisite-patch-id: 1955f24b076143dd23ce6891c8d9b967100eeb3a
> --
> 2.41.0.270.g68fa1d84b5
>
>
More information about the DTrace-devel
mailing list