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

Nick Alcock nick.alcock at oracle.com
Wed Aug 2 13:26:51 UTC 2023


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>
---
 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) {
+		fprintf(stderr, "dtprobed DEBUG %li: ", time(NULL));
 		vfprintf(stderr, fmt, ap);
-	else
+	}
+	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