[DTrace-devel] [PATCH 01/10] dtprobed: logging improvements

Kris Van Hees kris.van.hees at oracle.com
Mon Sep 11 18:03:41 UTC 2023


Withdrawing r-b because this patch turns out to be out of order.  It is making
use of sync_fd as a global variable but at this point it does not exist as a
global variable.  But that only happens in patch 6 in this series.

I think the entire series needs to be re-checked (try a compile after each
patch) to ensure it applies and compiles correctly.  That is a must be patch
series.

On Mon, Aug 21, 2023 at 11:04:34PM -0400, Kris Van Hees via DTrace-devel wrote:
> 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