5:03 p.m.
'nbdkit -v' is quite verbose, and traces everything. Well, actually
it only traces if you also use -f; because if we daemonize, stderr
is redirected to /dev/null. Sometimes, we want to trace JUST the
client interactions, and it would be nice to trace this even when
run in the background. In particular, when debugging another
filter, being able to trace what an earlier filter changed can be
quite useful; and having the log filter in place will make it easier
to add testsuite coverage of other filters (this patch includes a
rudimentary test of just the log filter). Also, it is nice to have
timestamps in the log, in order to see if message interleaving takes
place, and what delays are occurring.
The filter requires a logfile; I debated making the filter fall
back to logging to stderr if no logfile parameter was found, but
while that works for 'nbdkit -f', it fails miserably when we
daemonize (again, part of the argument for having this filter).
Signed-off-by: Eric Blake <eblake(a)redhat.com>
---
v3: rework to changed api, get unit test working
---
TODO | 2 -
docs/nbdkit-filter.pod | 1 +
docs/nbdkit.pod | 1 +
filters/log/nbdkit-log-filter.pod | 115 ++++++++++++
configure.ac | 1 +
filters/log/log.c | 365 ++++++++++++++++++++++++++++++++++++++
filters/Makefile.am | 1 +
filters/log/Makefile.am | 62 +++++++
tests/Makefile.am | 4 +
tests/test-log.sh | 88 +++++++++
10 files changed, 638 insertions(+), 2 deletions(-)
create mode 100644 filters/log/nbdkit-log-filter.pod
create mode 100644 filters/log/log.c
create mode 100644 filters/log/Makefile.am
create mode 100755 tests/test-log.sh
diff --git a/TODO b/TODO
index 4731b1e..a691ff3 100644
--- a/TODO
+++ b/TODO
@@ -77,8 +77,6 @@ Suggestions for filters
* injecting artificial errors or otherwise masking plugin features
(such as hiding zero support) for testing clients
-* logging all client commands
-
* fua filter: setting mode=none stops advertisement, mode=emulate uses
flush emulation (or fails if !can_flush), mode=native passes on
through (or fails if can_fua does not report native support). When
diff --git a/docs/nbdkit-filter.pod b/docs/nbdkit-filter.pod
index 8ef26e3..3ec8f2a 100644
--- a/docs/nbdkit-filter.pod
+++ b/docs/nbdkit-filter.pod
@@ -563,6 +563,7 @@ Filters:
L<nbdkit-cache-filter(1)>,
L<nbdkit-cow-filter(1)>,
L<nbdkit-delay-filter(1)>,
+L<nbdkit-log-filter(1)>,
L<nbdkit-offset-filter(1)>,
L<nbdkit-partition-filter(1)>.
diff --git a/docs/nbdkit.pod b/docs/nbdkit.pod
index 1167245..22d91e7 100644
--- a/docs/nbdkit.pod
+++ b/docs/nbdkit.pod
@@ -920,6 +920,7 @@ Filters:
L<nbdkit-cache-filter(1)>,
L<nbdkit-cow-filter(1)>,
L<nbdkit-delay-filter(1)>,
+L<nbdkit-log-filter(1)>,
L<nbdkit-offset-filter(1)>,
L<nbdkit-partition-filter(1)>.
diff --git a/filters/log/nbdkit-log-filter.pod b/filters/log/nbdkit-log-filter.pod
new file mode 100644
index 0000000..f3484fe
--- /dev/null
+++ b/filters/log/nbdkit-log-filter.pod
@@ -0,0 +1,115 @@
+=encoding utf8
+
+=head1 NAME
+
+nbdkit-log-filter - nbdkit log filter
+
+=head1 SYNOPSIS
+
+ nbdkit --filter=log plugin logfile=FILE [plugin-args...]
+
+=head1 DESCRIPTION
+
+C<nbdkit-log-filter> is a filter that logs all transactions. 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 log results are placed in a user-specified
+file; for more details on the log format, see L<FILES>. Note that
+using C<nbdkit -v> produces much more verbose logging details to
+stderr about every aspect of nbdkit operation.
+
+=head1 PARAMETERS
+
+The nbdkit-log-filter requires 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.
+
+=head1 EXAMPLES
+
+Serve the file F<disk.img>, and log each client transaction in the
+file F<disk.log>:
+
+ nbdkit --filter=log file file=disk.img logfile=disk.log
+
+Repeat the task, but with the cow (copy-on-write) filter to perform
+local caching of data served from the original plugin:
+
+ nbdkit --filter=cow --filter=log file file=disk.img logfile=disk.log2
+
+After running a client that performs the same operations under each of
+the two servers, you can compare F<disk.log> and F<disk.log2> to see
+the impact of the caching.
+
+=head1 FILES
+
+This filter writes to the file specified by the C<logfile=FILE>
+parameter. All lines include a timestamp, a connection counter, then
+details about the command. The following actions are logged: Connect,
+Read, Write, Zero, Trim, Flush, and Disconnect. Except for Connect
+and Disconnect, an event is logged across two lines for call and
+return value, to allow tracking duration and tracing any parallel
+execution, using id for correlation (incremented per action on the
+connection).
+
+An example logging session of a client that performs a single
+successful read is:
+
+ 2018-01-27 20:38:22.959984 connection=1 Connect size=0x400 write=1 flush=1 rotational=0
trim=0
+ 2018-01-27 20:38:23.001720 connection=1 Read id=1 offset=0x0 count=0x100 ...
+ 2018-01-27 20:38:23.001995 connection=1 ...Read id=1 return=0 (Success)
+ 2018-01-27 20:38:23.044259 connection=1 Disconnect transactions=1
+
+=head1 SEE ALSO
+
+L<nbdkit(1)>,
+L<nbdkit-file-plugin(1)>,
+L<nbdkit-cow-filter(1)>,
+L<nbdkit-filter(3)>.
+
+=head1 AUTHORS
+
+Eric Blake
+
+=head1 COPYRIGHT
+
+Copyright (C) 2018 Red Hat Inc.
+
+=head1 LICENSE
+
+Redistribution and use in source and binary forms, with or without
+modification, are permitted provided that the following conditions are
+met:
+
+=over 4
+
+=item *
+
+Redistributions of source code must retain the above copyright
+notice, this list of conditions and the following disclaimer.
+
+=item *
+
+Redistributions in binary form must reproduce the above copyright
+notice, this list of conditions and the following disclaimer in the
+documentation and/or other materials provided with the distribution.
+
+=item *
+
+Neither the name of Red Hat nor the names of its contributors may be
+used to endorse or promote products derived from this software without
+specific prior written permission.
+
+=back
+
+THIS SOFTWARE IS PROVIDED BY RED HAT AND CONTRIBUTORS ''AS IS'' AND
+ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO,
+THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A
+PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL RED HAT OR
+CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
+SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
+LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF
+USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND
+ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY,
+OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT
+OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
+SUCH DAMAGE.
diff --git a/configure.ac b/configure.ac
index 6025ce0..3fcc776 100644
--- a/configure.ac
+++ b/configure.ac
@@ -516,6 +516,7 @@ AC_CONFIG_FILES([Makefile
filters/cache/Makefile
filters/cow/Makefile
filters/delay/Makefile
+ filters/log/Makefile
filters/offset/Makefile
filters/partition/Makefile
src/Makefile
diff --git a/filters/log/log.c b/filters/log/log.c
new file mode 100644
index 0000000..58fd4f8
--- /dev/null
+++ b/filters/log/log.c
@@ -0,0 +1,365 @@
+/* nbdkit
+ * Copyright (C) 2018 Red Hat Inc.
+ * All rights reserved.
+ *
+ * Redistribution and use in source and binary forms, with or without
+ * modification, are permitted provided that the following conditions are
+ * met:
+ *
+ * * Redistributions of source code must retain the above copyright
+ * notice, this list of conditions and the following disclaimer.
+ *
+ * * Redistributions in binary form must reproduce the above copyright
+ * notice, this list of conditions and the following disclaimer in the
+ * documentation and/or other materials provided with the distribution.
+ *
+ * * Neither the name of Red Hat nor the names of its contributors may be
+ * used to endorse or promote products derived from this software without
+ * specific prior written permission.
+ *
+ * THIS SOFTWARE IS PROVIDED BY RED HAT AND CONTRIBUTORS ''AS IS'' AND
+ * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO,
+ * THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A
+ * PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL RED HAT OR
+ * CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
+ * SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
+ * LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF
+ * USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND
+ * ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY,
+ * OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT
+ * OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
+ * SUCH DAMAGE.
+ */
+
+#include <config.h>
+
+#include <stdio.h>
+#include <stdlib.h>
+#include <stdint.h>
+#include <string.h>
+#include <stdarg.h>
+#include <errno.h>
+#include <inttypes.h>
+#include <pthread.h>
+#include <sys/time.h>
+#include <assert.h>
+
+#include <nbdkit-filter.h>
+
+#define THREAD_MODEL NBDKIT_THREAD_MODEL_PARALLEL
+
+static uint64_t connections;
+static char *logfilename;
+static FILE *logfile;
+static pthread_mutex_t lock = PTHREAD_MUTEX_INITIALIZER;
+
+static void
+log_unload (void)
+{
+ if (logfilename)
+ fclose (logfile);
+ free (logfilename);
+}
+
+/* Called for each key=value passed on the command line. */
+static int
+log_config (nbdkit_next_config *next, void *nxdata,
+ const char *key, const char *value)
+{
+ if (strcmp (key, "logfile") == 0) {
+ free (logfilename);
+ logfilename = strdup (value);
+ if (!logfilename) {
+ nbdkit_error ("strdup: %m");
+ return -1;
+ }
+ return 0;
+ }
+ return next (nxdata, key, value);
+}
+
+/* Open the logfile. */
+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;
+ }
+ logfile = fopen (logfilename, "w");
+ if (!logfile) {
+ nbdkit_error ("fopen: %m");
+ return -1;
+ }
+
+ return next (nxdata);
+}
+
+#define log_config_help \
+ "logfile=<FILE> The file to place the log in."
+
+struct handle {
+ uint64_t connection;
+ uint64_t id;
+};
+
+/* Compute the next id number on the current connection. */
+static uint64_t
+get_id (struct handle *h)
+{
+ uint64_t r;
+
+ pthread_mutex_lock (&lock);
+ r = ++h->id;
+ pthread_mutex_unlock (&lock);
+ return r;
+}
+
+/* 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);
+ fflush (logfile);
+ funlockfile (logfile);
+}
+
+/* Shared code for a nicer log of return value */
+static void
+output_return (struct handle *h, const char *act, uint64_t id, int r, int *err)
+{
+ const char *s = "Other=>EINVAL";
+
+ /* Only decode what connections.c:nbd_errno() recognizes */
+ if (r == -1) {
+ switch (*err) {
+ case EROFS:
+ s = "EROFS=>EPERM";
+ break;
+ case EPERM:
+ s = "EPERM";
+ break;
+ case EIO:
+ s = "EIO";
+ break;
+ case ENOMEM:
+ s = "ENOMEM";
+ break;
+#ifdef EDQUOT
+ case EDQUOT:
+ s = "EDQUOT=>ENOSPC";
+ break;
+#endif
+ case EFBIG:
+ s = "EFBIG=>ENOSPC";
+ break;
+ case ENOSPC:
+ s = "ENOSPC";
+ break;
+#ifdef ESHUTDOWN
+ case ESHUTDOWN:
+ s = "ESHUTDOWN";
+ break;
+#endif
+ case EINVAL:
+ s = "EINVAL";
+ break;
+ }
+ }
+ else {
+ s = "Success";
+ }
+ output (h, act, id, "return=%d (%s)", r, s);
+}
+
+/* Open a connection. */
+static void *
+log_open (nbdkit_next_open *next, void *nxdata, int readonly)
+{
+ struct handle *h;
+
+ if (next (nxdata, readonly) == -1)
+ return NULL;
+
+ h = malloc (sizeof *h);
+ if (h == NULL) {
+ nbdkit_error ("malloc: %m");
+ return NULL;
+ }
+
+ pthread_mutex_lock (&lock);
+ h->connection = ++connections;
+ pthread_mutex_unlock (&lock);
+ h->id = 0;
+ return h;
+}
+
+static void
+log_close (void *handle)
+{
+ struct handle *h = handle;
+
+ free (h);
+}
+
+static int
+log_prepare (struct nbdkit_next_ops *next_ops, void *nxdata, void *handle)
+{
+ struct handle *h = handle;
+ int64_t size = next_ops->get_size (nxdata);
+ int w = next_ops->can_write (nxdata);
+ int f = next_ops->can_flush (nxdata);
+ int r = next_ops->is_rotational (nxdata);
+ int t = next_ops->can_trim (nxdata);
+
+ if (size < 0 || w < 0 || f < 0 || r < 0 || t < 0)
+ return -1;
+
+ /* TODO expose can_zero, can_fua to filters */
+ output (h, "Connect", 0, "size=0x%" PRIx64 " write=%d flush=%d
"
+ "rotational=%d trim=%d" /* zero=? fua=? */, size, w, f, r, t);
+ return 0;
+}
+
+static int
+log_finalize (struct nbdkit_next_ops *next_ops, void *nxdata, void *handle)
+{
+ struct handle *h = handle;
+
+ output (h, "Disconnect", 0, "transactions=%" PRId64, h->id);
+ return 0;
+}
+
+/* Read data. */
+static int
+log_pread (struct nbdkit_next_ops *next_ops, void *nxdata,
+ void *handle, void *buf, uint32_t count, uint64_t offs,
+ uint32_t flags, int *err)
+{
+ struct handle *h = handle;
+ uint64_t id = get_id (h);
+ int r;
+
+ assert (!flags);
+ output (h, "Read", id, "offset=0x%" PRIx64 " count=0x%x
...",
+ offs, count);
+ r = next_ops->pread (nxdata, buf, count, offs, flags, err);
+ output_return (h, "...Read", id, r, err);
+ return r;
+}
+
+/* Write data. */
+static int
+log_pwrite (struct nbdkit_next_ops *next_ops, void *nxdata,
+ void *handle, const void *buf, uint32_t count, uint64_t offs,
+ uint32_t flags, int *err)
+{
+ struct handle *h = handle;
+ uint64_t id = get_id (h);
+ int r;
+
+ assert (!(flags & ~NBDKIT_FLAG_FUA));
+ output (h, "Write", id, "offset=0x%" PRIx64 " count=0x%x
fua=%d ...",
+ offs, count, !!(flags & NBDKIT_FLAG_FUA));
+ r = next_ops->pwrite (nxdata, buf, count, offs, flags, err);
+ output_return (h, "...Write", id, r, err);
+ return r;
+}
+
+/* Flush. */
+static int
+log_flush (struct nbdkit_next_ops *next_ops, void *nxdata, void *handle,
+ uint32_t flags, int *err)
+{
+ struct handle *h = handle;
+ uint64_t id = get_id (h);
+ int r;
+
+ assert (!flags);
+ output (h, "Flush", id, "...");
+ r = next_ops->flush (nxdata, flags, err);
+ output_return (h, "...Flush", id, r, err);
+ return r;
+}
+
+/* Trim data. */
+static int
+log_trim (struct nbdkit_next_ops *next_ops, void *nxdata,
+ void *handle, uint32_t count, uint64_t offs, uint32_t flags,
+ int *err)
+{
+ struct handle *h = handle;
+ uint64_t id = get_id (h);
+ int r;
+
+ assert (!(flags & ~NBDKIT_FLAG_FUA));
+ output (h, "Trim", id, "offset=0x%" PRIx64 " count=0x%x fua=%d
...",
+ offs, count, !!(flags & NBDKIT_FLAG_FUA));
+ r = next_ops->trim (nxdata, count, offs, flags, err);
+ output_return (h, "...Trim", id, r, err);
+ return r;
+}
+
+/* Zero data. */
+static int
+log_zero (struct nbdkit_next_ops *next_ops, void *nxdata,
+ void *handle, uint32_t count, uint64_t offs, uint32_t flags,
+ int *err)
+{
+ struct handle *h = handle;
+ uint64_t id = get_id (h);
+ int r;
+
+ assert (!(flags & ~(NBDKIT_FLAG_FUA | NBDKIT_FLAG_MAY_TRIM)));
+ output (h, "Zero", id, "offset=0x%" PRIx64 " count=0x%x
trim=%d fua=%d ...",
+ offs, count, !!(flags & NBDKIT_FLAG_MAY_TRIM),
+ !!(flags & NBDKIT_FLAG_FUA));
+ r = next_ops->zero (nxdata, count, offs, flags, err);
+ output_return (h, "...Zero", id, r, err);
+ return r;
+}
+
+static struct nbdkit_filter filter = {
+ .name = "log",
+ .longname = "nbdkit log filter",
+ .version = PACKAGE_VERSION,
+ .config = log_config,
+ .config_complete = log_config_complete,
+ .config_help = log_config_help,
+ .unload = log_unload,
+ .open = log_open,
+ .close = log_close,
+ .prepare = log_prepare,
+ .finalize = log_finalize,
+ .pread = log_pread,
+ .pwrite = log_pwrite,
+ .flush = log_flush,
+ .trim = log_trim,
+ .zero = log_zero,
+};
+
+NBDKIT_REGISTER_FILTER(filter)
diff --git a/filters/Makefile.am b/filters/Makefile.am
index 9996d77..8e070e5 100644
--- a/filters/Makefile.am
+++ b/filters/Makefile.am
@@ -34,5 +34,6 @@ SUBDIRS = \
cache \
cow \
delay \
+ log \
offset \
partition
diff --git a/filters/log/Makefile.am b/filters/log/Makefile.am
new file mode 100644
index 0000000..18a0eba
--- /dev/null
+++ b/filters/log/Makefile.am
@@ -0,0 +1,62 @@
+# nbdkit
+# Copyright (C) 2018 Red Hat Inc.
+# All rights reserved.
+#
+# Redistribution and use in source and binary forms, with or without
+# modification, are permitted provided that the following conditions are
+# met:
+#
+# * Redistributions of source code must retain the above copyright
+# notice, this list of conditions and the following disclaimer.
+#
+# * Redistributions in binary form must reproduce the above copyright
+# notice, this list of conditions and the following disclaimer in the
+# documentation and/or other materials provided with the distribution.
+#
+# * Neither the name of Red Hat nor the names of its contributors may be
+# used to endorse or promote products derived from this software without
+# specific prior written permission.
+#
+# THIS SOFTWARE IS PROVIDED BY RED HAT AND CONTRIBUTORS ''AS IS'' AND
+# ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO,
+# THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A
+# PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL RED HAT OR
+# CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
+# SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
+# LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF
+# USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND
+# ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY,
+# OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT
+# OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
+# SUCH DAMAGE.
+
+EXTRA_DIST = nbdkit-log-filter.pod
+
+CLEANFILES = *~
+
+filterdir = $(libdir)/nbdkit/filters
+
+filter_LTLIBRARIES = nbdkit-log-filter.la
+
+nbdkit_log_filter_la_SOURCES = \
+ log.c \
+ $(top_srcdir)/include/nbdkit-filter.h
+
+nbdkit_log_filter_la_CPPFLAGS = \
+ -I$(top_srcdir)/include
+nbdkit_log_filter_la_CFLAGS = \
+ $(WARNINGS_CFLAGS)
+nbdkit_log_filter_la_LDFLAGS = \
+ -module -avoid-version -shared
+
+if HAVE_POD2MAN
+
+man_MANS = nbdkit-log-filter.1
+CLEANFILES += $(man_MANS)
+
+nbdkit-log-filter.1: nbdkit-log-filter.pod
+ $(POD2MAN) $(POD2MAN_ARGS) --section=1 --name=`basename $@ .1` $< $@.t && \
+ if grep 'POD ERROR' $@.t; then rm $@.t; exit 1; fi && \
+ mv $@.t $@
+
+endif
diff --git a/tests/Makefile.am b/tests/Makefile.am
index ec33109..2d6393d 100644
--- a/tests/Makefile.am
+++ b/tests/Makefile.am
@@ -51,6 +51,7 @@ EXTRA_DIST = \
test-help.sh \
test-help-plugin.sh \
test-ip.sh \
+ test-log.sh \
test_ocaml_plugin.ml \
test-ocaml.c \
test-parallel-file.sh \
@@ -427,6 +428,9 @@ test_delay_SOURCES = test-delay.c test.h
test_delay_CFLAGS = $(WARNINGS_CFLAGS) $(LIBGUESTFS_CFLAGS)
test_delay_LDADD = libtest.la $(LIBGUESTFS_LIBS)
+# log filter test.
+TESTS += test-log.sh
+
# offset filter test.
check_DATA += offset-data
MAINTAINERCLEANFILES += offset-data
diff --git a/tests/test-log.sh b/tests/test-log.sh
new file mode 100755
index 0000000..5d6a138
--- /dev/null
+++ b/tests/test-log.sh
@@ -0,0 +1,88 @@
+#!/bin/bash -
+# nbdkit
+# Copyright (C) 2018 Red Hat Inc.
+# All rights reserved.
+#
+# Redistribution and use in source and binary forms, with or without
+# modification, are permitted provided that the following conditions are
+# met:
+#
+# * Redistributions of source code must retain the above copyright
+# notice, this list of conditions and the following disclaimer.
+#
+# * Redistributions in binary form must reproduce the above copyright
+# notice, this list of conditions and the following disclaimer in the
+# documentation and/or other materials provided with the distribution.
+#
+# * Neither the name of Red Hat nor the names of its contributors may be
+# used to endorse or promote products derived from this software without
+# specific prior written permission.
+#
+# THIS SOFTWARE IS PROVIDED BY RED HAT AND CONTRIBUTORS ''AS IS'' AND
+# ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO,
+# THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A
+# PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL RED HAT OR
+# CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
+# SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
+# LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF
+# USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND
+# ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY,
+# OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT
+# OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
+# SUCH DAMAGE.
+
+set -e
+
+files="log.img log.log log.sock log.pid"
+rm -f $files
+
+: ${QEMU_IO=qemu-io}
+
+# Test that qemu-io works
+truncate --size 10M log.img
+if ! $QEMU_IO -f raw -c 'w 1M 2M' log.img; then
+ echo "$0: missing or broken qemu-io"
+ exit 77
+fi
+
+# Run nbdkit with logging enabled to file.
+nbdkit -P log.pid -U log.sock --filter=log file file=log.img logfile=log.log
+
+# We may have to wait a short time for the pid file to appear.
+for i in `seq 1 10`; do
+ if test -f log.pid; then
+ break
+ fi
+ sleep 1
+done
+if ! test -f log.pid; then
+ echo "$0: PID file was not created"
+ exit 1
+fi
+
+pid="$(cat log.pid)"
+
+# Kill the nbdkit process on exit.
+cleanup ()
+{
+ status=$?
+
+ kill $pid
+ # For easier debugging, dump the final log file before removing it.
+ echo "Log file contents:"
+ cat log.log
+ rm -f $files
+
+ exit $status
+}
+trap cleanup INT QUIT TERM EXIT ERR
+
+# Write, then read some data in the file.
+$QEMU_IO -f raw -c 'w -P 11 1M 2M' 'nbd+unix://?socket=log.sock'
+$QEMU_IO -r -f raw -c 'r -P 11 2M 1M' 'nbd+unix://?socket=log.sock'
+
+# The log should show a write on connection 1, and read on connection 2.
+grep 'connection=1 Write id=1 offset=0x100000 count=0x200000 ' log.log
+grep 'connection=2 Read id=1 offset=0x200000 count=0x100000 ' log.log
+
+# The cleanup() function is called implicitly on exit.
--
2.14.3