11:18 a.m.
Typical output:
2019-03-26 18:22:17.287434 connection=2 Extents id=2 offset=0x0 count=0x40000000 req_one=1
...
2019-03-26 18:22:17.290040 connection=2 ...Extents id=2 extents=[{ offset=0x0,
length=0x250000, type=0 }, { offset=0x250000, length=0x7db0000, type=3 }, {
offset=0x8000000, length=0x8000, type=0 }, { offset=0x8008000, length=0x38000, type=3 }, {
offset=0x8040000, length=0x208000, type=0 }, { offset=0x8248000, length=0x7db8000, type=3
}, { offset=0x10000000, length=0x208000, type=0 }, { offset=0x10208000, length=0x7df8000,
type=3 }, { offset=0x18000000, length=0x8000, type=0 }, { offset=0x18008000,
length=0x38000, type=3 }, { offset=0x18040000, length=0x208000, type=0 }, {
offset=0x18248000, length=0x7db8000, type=3 }, { offset=0x20000000, length=0x208000,
type=0 }, { offset=0x20208000, length=0x7df8000, type=3 }, { offset=0x28000000,
length=0x8000, type=0 }, { offset=0x28008000, length=0x38000, type=3 }, {
offset=0x28040000, length=0x208000, type=0 }, { offset=0x28248000, length=0x7db8000,
type=3 }, { offset=0x30000000, length=0x208000, type=0 }, { offset=0x30208000,
length=0x7df8000, type=3 }, { offset=0x38000000, length=0x8000, type=0 }, {
offset=0x38008000, length=0x38000, type=3 }, { offset=0x38040000, length=0x208000, type=0
}, { offset=0x38248000, length=0x7da8000, type=3 }, { offset=0x3fff0000, length=0x10000,
type=0 }] return=0
As you can see this is logging the complete information as generated
by the underlying plugin, not what is returned to the client (which is
rather hard for the log filter to discern). It's probably more useful
for debugging like this.
---
filters/log/nbdkit-log-filter.pod | 6 ++---
filters/log/log.c | 45 +++++++++++++++++++++++++++++++
2 files changed, 48 insertions(+), 3 deletions(-)
diff --git a/filters/log/nbdkit-log-filter.pod b/filters/log/nbdkit-log-filter.pod
index cff209e..e391046 100644
--- a/filters/log/nbdkit-log-filter.pod
+++ b/filters/log/nbdkit-log-filter.pod
@@ -46,9 +46,9 @@ the impact of the caching.
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
+Read, Write, Zero, Trim, Extents, 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).
diff --git a/filters/log/log.c b/filters/log/log.c
index 9f2e37d..b31d784 100644
--- a/filters/log/log.c
+++ b/filters/log/log.c
@@ -353,6 +353,50 @@ log_zero (struct nbdkit_next_ops *next_ops, void *nxdata,
return r;
}
+/* Extents. */
+static int
+log_extents (struct nbdkit_next_ops *next_ops, void *nxdata,
+ void *handle, uint32_t count, uint64_t offs, uint32_t flags,
+ struct nbdkit_extents *extents, int *err)
+{
+ struct handle *h = handle;
+ uint64_t id = get_id (h);
+ int r;
+
+ assert (!(flags & ~(NBDKIT_FLAG_REQ_ONE)));
+ output (h, "Extents", id,
+ "offset=0x%" PRIx64 " count=0x%x req_one=%d ...",
+ offs, count, !!(flags & NBDKIT_FLAG_REQ_ONE));
+ r = next_ops->extents (nxdata, count, offs, flags, extents, err);
+ if (r == -1)
+ output_return (h, "...Extents", id, r, err);
+ else {
+ FILE *fp;
+ char *extents_str = NULL;
+ size_t i, n, len = 0;
+
+ fp = open_memstream (&extents_str, &len);
+ if (fp != NULL) {
+ n = nbdkit_extents_count (extents);
+ for (i = 0; i < n; ++i) {
+ struct nbdkit_extent e = nbdkit_get_extent (extents, i);
+ if (i > 0)
+ fprintf (fp, ", ");
+ fprintf (fp, "{ offset=0x%" PRIx64 ", length=0x%" PRIx64
", "
+ "type=%" PRIu32 " }",
+ e.offset, e.length, e.type);
+ }
+
+ fclose (fp);
+ }
+
+ output (h, "...Extents", id, "extents=[%s] return=0",
+ extents_str ? extents_str : "(null)");
+ free (extents_str);
+ }
+ return r;
+}
+
static struct nbdkit_filter filter = {
.name = "log",
.longname = "nbdkit log filter",
@@ -370,6 +414,7 @@ static struct nbdkit_filter filter = {
.flush = log_flush,
.trim = log_trim,
.zero = log_zero,
+ .extents = log_extents,
};
NBDKIT_REGISTER_FILTER(filter)
--
2.20.1