[Libguestfs] [PATCH nbdkit 2/2] log: Add logscript feature.

Richard W.M. Jones rjones at redhat.com
Sun Dec 20 12:23:08 UTC 2020


This allows you to trigger an external script on log events, instead
(or in addition to) logging to a file.
---
 filters/log/nbdkit-log-filter.pod | 113 +++++++++++++++++++++++++++---
 filters/log/log.h                 |   1 +
 filters/log/log.c                 |  60 ++++++++--------
 filters/log/output.c              |  84 +++++++++++++++++++---
 TODO                              |   4 --
 5 files changed, 207 insertions(+), 55 deletions(-)

diff --git a/filters/log/nbdkit-log-filter.pod b/filters/log/nbdkit-log-filter.pod
index abf52e18..dd04f1ab 100644
--- a/filters/log/nbdkit-log-filter.pod
+++ b/filters/log/nbdkit-log-filter.pod
@@ -4,15 +4,24 @@ nbdkit-log-filter - nbdkit log filter
 
 =head1 SYNOPSIS
 
- nbdkit --filter=log plugin logfile=FILE [logappend=BOOL] [plugin-args...]
+ nbdkit --filter=log PLUGIN
+                     [logfile=FILE | logscript=SCRIPT] [logappend=BOOL]
+                     [PLUGIN-ARGS...]
 
 =head1 DESCRIPTION
 
-C<nbdkit-log-filter> is a filter that logs all transactions to a file.
+C<nbdkit-log-filter> is a filter that logs all transactions to a file
+or external script.
+
 When used as the first filter, it can show the original client
 requests.  As a later filter, it can show how earlier filters have
-modified the original request.  The format of the log file is
-described in L</LOG FILE FORMAT> below.
+modified the original request.
+
+When using C<logfile=FILE>, logs are written to a log file with the
+format described in L</LOG FILE FORMAT> below.
+
+When using C<logscript=SCRIPT>, logs invoke the external script.  See
+L</LOG SCRIPT> below.
 
 An alternative to this filter is simply to run nbdkit with the I<-f>
 and I<-v> flags which enable verbose debugging to stderr.  This logs
@@ -22,11 +31,20 @@ parsable format and works when nbdkit runs in the background.
 
 =head1 PARAMETERS
 
+C<logfile> or C<logscript> or both can be given.  If neither then the
+filter is inactive.
+
 =over 4
 
 =item B<logfile=>FILE
 
-The file where the log is written.  This parameter is required.
+The file where the log is written.  See L</LOG FILE FORMAT> below.
+
+=item B<logscript=>SCRIPT
+
+(nbdkit E<ge> 1.24)
+
+Log lines invoke an external script.  See L</LOG SCRIPT> below.
 
 =item B<logappend=true>
 
@@ -34,9 +52,9 @@ The file where the log is written.  This parameter is required.
 
 (nbdkit E<ge> 1.8)
 
-When set to C<false> (the default), if the file already exists it will
-be truncated.  When set to C<true>, the filter appends to the existing
-file.
+This only affects C<logfile>.  If C<false> (the default), if the file
+already exists it will be truncated.  If C<true>, the filter appends
+to the existing log file.
 
 =back
 
@@ -84,6 +102,85 @@ unique per connection.
 
 Strings and lists are shell-quoted.
 
+=head1 LOG SCRIPT
+
+If C<logscript=SCRIPT> is given on the command line then log entries
+are passed to the external script.
+
+The script is passed several shell variables:
+
+=over 4
+
+=item C<$act>
+
+The action name, like C<"Read">, C<"Write"> etc.
+
+=item C<$connection>
+
+The connection ID identifying the client, only for connected calls
+like C<"Read">.
+
+=item C<$error>
+
+For messages of type C<"LEAVE"> which fail (C<$return = -1>), this
+contains the errno as a string, for example C<"EIO">.
+
+=item C<$id>
+
+The transaction ID, used to correlate actions which are split into two
+messages C<"ENTER"> and C<"LEAVE">.
+
+=item C<$return>
+
+For messages of type C<"LEAVE"> this is the return code, usually C<0>
+for success and C<-1> if there was an error.
+
+=item C<$type>
+
+The message type: C<"ENTER">, C<"LEAVE"> or C<"PRINT">.
+
+=item other shell variables
+
+Other parameters like C<offset=N> are turned into shell variables
+C<$offset> etc.
+
+=back
+
+Note the return value of the script is ignored.  Log scripts cannot
+modify or interrupt request processing.
+
+=head2 Log script examples
+
+The script:
+
+ nbdkit -f --filter=log null 10M \
+        logscript='echo $connection $type $id $act $offset >&2'
+
+might print lines like:
+
+ PRINT Ready
+ 1 ENTER 1 Read 0x0
+ 1 ENTER 2 Write 0x200
+ 1 LEAVE 2 Write
+ 1 LEAVE 1 Read
+
+corresponding to log file lines:
+
+ Ready thread_model=3
+ connection=1 Read id=1 offset=0x0 count=0x200 ...
+ connection=1 Write id=2 offset=0x200 count=0x200 ...
+ connection=1 ...Write id=2
+ connection=1 ...Read id=1
+
+This script will trigger a message when any client reads:
+
+ nbdkit -f --filter=log memory 10M \
+        logscript='
+            if [ "$act" = "Read" -a "$type" = "ENTER" ]; then
+                echo Client is reading $count bytes from $offset >&2
+            fi
+        '
+
 =head1 FILES
 
 =over 4
diff --git a/filters/log/log.h b/filters/log/log.h
index 8df27192..6dad10d4 100644
--- a/filters/log/log.h
+++ b/filters/log/log.h
@@ -50,6 +50,7 @@ struct handle {
 extern uint64_t connections;
 extern const char *logfilename;
 extern FILE *logfile;
+extern const char *logscript;
 extern int append;
 extern pthread_mutex_t lock;
 
diff --git a/filters/log/log.c b/filters/log/log.c
index 37b36498..7b81a8f1 100644
--- a/filters/log/log.c
+++ b/filters/log/log.c
@@ -62,6 +62,7 @@
 uint64_t connections;
 const char *logfilename;
 FILE *logfile;
+const char *logscript;
 int append;
 pthread_mutex_t lock = PTHREAD_MUTEX_INITIALIZER;
 pid_t saved_pid;
@@ -88,23 +89,17 @@ log_config (nbdkit_next_config *next, void *nxdata,
       return -1;
     return 0;
   }
+  if (strcmp (key, "logscript") == 0) {
+    logscript = value;
+    return 0;
+  }
   return next (nxdata, key, value);
 }
 
-static int
-log_config_complete (nbdkit_next_config_complete *next, void *nxdata)
-{
-  if (!logfilename) {
-    nbdkit_error ("missing logfile= parameter for the log filter");
-    return -1;
-  }
-
-  return next (nxdata);
-}
-
 #define log_config_help \
-  "logfile=<FILE>    (required) The file to place the log in.\n" \
-  "logappend=<BOOL>  True to append to the log (default false).\n"
+  "logfile=<FILE>               The file to place the log in.\n" \
+  "logappend=<BOOL>             True to append to the log (default false).\n" \
+  "logscript=<SCRIPT>           Script to run for logging."
 
 /* Open the logfile. */
 static int
@@ -112,24 +107,26 @@ log_get_ready (nbdkit_next_get_ready *next, void *nxdata, int thread_model)
 {
   int fd;
 
-  /* Using fopen("ae"/"we") would be more convenient, but as Haiku
-   * still lacks that, use this instead. Atomicity is not essential
-   * here since .config completes before threads that might fork, if
-   * we have to later add yet another fallback to fcntl(fileno()) for
-   * systems without O_CLOEXEC.
-   */
-  fd = open (logfilename,
-             O_CLOEXEC | O_WRONLY | O_CREAT | (append ? O_APPEND : O_TRUNC),
-             0666);
-  if (fd < 0) {
-    nbdkit_error ("open: %s: %m", logfilename);
-    return -1;
-  }
-  logfile = fdopen (fd, append ? "a" : "w");
-  if (!logfile) {
-    nbdkit_error ("fdopen: %s: %m", logfilename);
-    close (fd);
-    return -1;
+  if (logfilename) {
+    /* Using fopen("ae"/"we") would be more convenient, but as Haiku
+     * still lacks that, use this instead. Atomicity is not essential
+     * here since .config completes before threads that might fork, if
+     * we have to later add yet another fallback to fcntl(fileno()) for
+     * systems without O_CLOEXEC.
+     */
+    fd = open (logfilename,
+               O_CLOEXEC | O_WRONLY | O_CREAT | (append ? O_APPEND : O_TRUNC),
+               0666);
+    if (fd < 0) {
+      nbdkit_error ("open: %s: %m", logfilename);
+      return -1;
+    }
+    logfile = fdopen (fd, append ? "a" : "w");
+    if (!logfile) {
+      nbdkit_error ("fdopen: %s: %m", logfilename);
+      close (fd);
+      return -1;
+    }
   }
 
   saved_pid = getpid ();
@@ -450,7 +447,6 @@ static struct nbdkit_filter filter = {
   .name              = "log",
   .longname          = "nbdkit log filter",
   .config            = log_config,
-  .config_complete   = log_config_complete,
   .config_help       = log_config_help,
   .unload            = log_unload,
   .get_ready         = log_get_ready,
diff --git a/filters/log/output.c b/filters/log/output.c
index 0bfcf7c8..c999150a 100644
--- a/filters/log/output.c
+++ b/filters/log/output.c
@@ -55,9 +55,10 @@
 
 enum type { ENTER, LEAVE, PRINT };
 
+/* Adds an entry to the logfile. */
 static void
-output (struct handle *h, log_id_t id, const char *act, enum type type,
-        const char *fmt, va_list args)
+to_file (struct handle *h, log_id_t id, const char *act, enum type type,
+         const char *fmt, va_list args)
 {
   struct timeval tv;
   struct tm tm;
@@ -103,15 +104,62 @@ output (struct handle *h, log_id_t id, const char *act, enum type type,
 #endif
 }
 
+/* Runs the script. */
+static void
+to_script (struct handle *h, log_id_t id, const char *act, enum type type,
+           const char *fmt, va_list args)
+{
+  FILE *fp;
+  CLEANUP_FREE char *str = NULL;
+  size_t len = 0;
+  int r;
+
+  /* Create the shell variables + script. */
+  fp = open_memstream (&str, &len);
+  if (!fp) {
+    /* Not much we can do, but at least record the error. */
+    nbdkit_error ("logscript: open_memstream: %m");
+    return;
+  }
+
+  fprintf (fp, "act=%s\n", act);
+  if (h)
+    fprintf (fp, "connection=%" PRIu64 "\n", h->connection);
+  switch (type) {
+  case ENTER: fprintf (fp, "type=ENTER\n"); break;
+  case LEAVE: fprintf (fp, "type=LEAVE\n"); break;
+  case PRINT: fprintf (fp, "type=PRINT\n"); break;
+  }
+  if (id)
+    fprintf (fp, "id=%" PRIu64 "\n", id);
+
+  vfprintf (fp, fmt, args);
+  fprintf (fp, "\n");
+
+  fprintf (fp, "%s", logscript);
+  fclose (fp);
+
+  /* Run the script.  Log the status, but ignore it. */
+  r = system (str);
+  exit_status_to_nbd_error (r, "logscript");
+}
+
 void
 enter (struct handle *h, log_id_t id, const char *act,
        const char *fmt, ...)
 {
   va_list args;
 
-  va_start (args, fmt);
-  output (h, id, act, ENTER, fmt, args);
-  va_end (args);
+  if (logfile) {
+    va_start (args, fmt);
+    to_file (h, id, act, ENTER, fmt, args);
+    va_end (args);
+  }
+  if (logscript) {
+    va_start (args, fmt);
+    to_script (h, id, act, ENTER, fmt, args);
+    va_end (args);
+  }
 }
 
 void
@@ -120,9 +168,16 @@ leave (struct handle *h, log_id_t id, const char *act,
 {
   va_list args;
 
-  va_start (args, fmt);
-  output (h, id, act, LEAVE, fmt, args);
-  va_end (args);
+  if (logfile) {
+    va_start (args, fmt);
+    to_file (h, id, act, LEAVE, fmt, args);
+    va_end (args);
+  }
+  if (logscript) {
+    va_start (args, fmt);
+    to_script (h, id, act, LEAVE, fmt, args);
+    va_end (args);
+  }
 }
 
 void
@@ -130,9 +185,16 @@ print (struct handle *h, const char *act, const char *fmt, ...)
 {
   va_list args;
 
-  va_start (args, fmt);
-  output (h, 0, act, PRINT, fmt, args);
-  va_end (args);
+  if (logfile) {
+    va_start (args, fmt);
+    to_file (h, 0, act, PRINT, fmt, args);
+    va_end (args);
+  }
+  if (logscript) {
+    va_start (args, fmt);
+    to_script (h, 0, act, PRINT, fmt, args);
+    va_end (args);
+  }
 }
 
 void
diff --git a/TODO b/TODO
index cc7afab8..198939e6 100644
--- a/TODO
+++ b/TODO
@@ -202,10 +202,6 @@ Suggestions for filters
 * masking plugin features for testing clients (see 'nozero' and 'fua'
   filters for examples)
 
-* "event" filter which triggers shell scripts on significant events
-  (like connection, close, read, write, etc).  It would not modify the
-  requests but allow more flexible logging.
-
 * "bandwidth quota" filter which would close a connection after it
   exceeded a certain amount of bandwidth up or down.
 
-- 
2.29.0.rc2




More information about the Libguestfs mailing list