[Libguestfs] [nbdkit PATCH 2/2] filters: Add log filter

Eric Blake eblake at redhat.com
Tue Jan 30 03:26:34 UTC 2018


On 01/27/2018 09:51 PM, Eric Blake wrote:
> 'nbdkit -v' is quite verbose, and traces everything.  Sometimes,
> we want to trace JUST the client interactions.  In particular, when
> debugging another filter, being able to trace what the filter called
> can be quite useful; and having the log filter in place will make
> it easier to add testsuite coverage of other filters.  Also, it is
> nice to have timestamps in the log, in order to see if message
> interleaving takes place, and what delays are occurring.
> 
> Signed-off-by: Eric Blake <eblake at redhat.com>
> ---

> +=head1 PARAMETERS
> +
> +The nbdkit-log-filter accepts a single parameter C<logfile> which
> +specifies the path of the file to use for logging.  If the file
> +already exists, it will be truncated.  If C<logfile> is omitted,
> +logging is send to stderr.

s/send/sent/

But that doesn't work unless you use 'nbdkit -f' - as soon as you let
nbdkit fork into the background, it silently replaces the original
stdout/stderr with /dev/null.  Looks like I should just make logfile=
mandatory.

I'm also debating whether truncation makes the most sense, or whether
the log should use append mode.

> +++ b/filters/log/log.c

> +static void
> +log_unload (void)
> +{
> +  if (logfilename)
> +    fclose (logfile);
> +  free (logfilename);
> +}

> +/* Output a timestamp and the log message. */
> +static void __attribute__ ((format (printf, 4, 5)))
> +output (struct handle *h, const char *act, uint64_t id, const char *fmt, ...)
> +{
> +  va_list args;
> +  struct timeval tv;
> +  struct tm tm;
> +  char timestamp[27] = "Time unknown";
> +
> +  /* Logging is best effort, so ignore failure to get timestamp */
> +  if (!gettimeofday (&tv, NULL))
> +    {
> +      size_t s;
> +
> +      gmtime_r (&tv.tv_sec, &tm);
> +      s = strftime (timestamp, sizeof timestamp, "%F %T", &tm);
> +      assert (s);
> +      s = snprintf (timestamp + s, sizeof timestamp - s, ".%06ld",
> +                    0L + tv.tv_usec);
> +    }
> +  flockfile (logfile);
> +  fprintf (logfile, "%s connection=%" PRIu64 " %s ", timestamp, h->connection,
> +           act);
> +  if (id)
> +    fprintf (logfile, "id=%" PRIu64 " ", id);
> +  va_start (args, fmt);
> +  vfprintf (logfile, fmt, args);
> +  va_end (args);
> +  fputc ('\n', logfile);
> +  funlockfile (logfile);

Also, I found that either this needs to fflush(logfile), or else
explicitly request that stdio use line buffering; otherwise, 'tail -f
logfile' doesn't see live updates until the buffer fills or nbdkit quits
and invokes the final implied flush via fclose().

-- 
Eric Blake, Principal Software Engineer
Red Hat, Inc.           +1-919-301-3266
Virtualization:  qemu.org | libvirt.org

-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 619 bytes
Desc: OpenPGP digital signature
URL: <http://listman.redhat.com/archives/libguestfs/attachments/20180129/210c03bc/attachment.sig>


More information about the Libguestfs mailing list