nbdkit/SOURCES/0003-server-Add-D-nbdkit.backend.controlpath-and-D-nbdkit.patch

From 83c72d9bf9d6a9ccf6939b4ebd0028b62673a78a Mon Sep 17 00:00:00 2001
From: "Richard W.M. Jones" <rjones@redhat.com>
Date: Thu, 12 Dec 2019 10:57:52 +0000
Subject: [PATCH 03/19] server: Add -D nbdkit.backend.controlpath and -D
 nbdkit.backend.datapath.

These can be used to suppress verbose debugging messages from the
backend.

BugLink: https://bugzilla.redhat.com/1782868

Cherry picked from commit 231717e8cd5f27d76631be6651062d5a5ccf7fdc.
Remove use of nofilter from the test.
---
 docs/nbdkit.pod                    | 35 ++++++++++++-
 server/backend.c                   | 83 ++++++++++++++++++------------
 tests/Makefile.am                  |  4 ++
 tests/test-nbdkit-backend-debug.sh | 70 +++++++++++++++++++++++++
 4 files changed, 158 insertions(+), 34 deletions(-)
 create mode 100755 tests/test-nbdkit-backend-debug.sh

diff --git a/docs/nbdkit.pod b/docs/nbdkit.pod
index 346d8332..38e6bfca 100644
--- a/docs/nbdkit.pod
+++ b/docs/nbdkit.pod
@@ -182,7 +182,7 @@ value C<N>.  See L<nbdkit-plugin(3)/Debug Flags>.
 =item B<--debug> nbdkit.FLAG=N
 
 Set the nbdkit server Debug Flag called C<FLAG> to the integer value
-C<N>.
+C<N>.  See L</SERVER DEBUG FLAGS> below.
 
 =item B<--dump-config>
 
@@ -527,6 +527,39 @@ languages.  The file should be executable.  For example:
 
 (see L<nbdkit-perl-plugin(3)> for a full example).
 
+=head1 SERVER DEBUG FLAGS
+
+As well as enabling or disabling debugging in the server using
+I<--verbose> you can control extra debugging in the server using the
+C<-D nbdkit.*> flags listed in this section.  Note these flags are an
+internal implementation detail of the server and may be changed or
+removed at any time in the future.
+
+=over 4
+
+=item B<-D nbdkit.backend.controlpath=0>
+
+=item B<-D nbdkit.backend.controlpath=1>
+
+=item B<-D nbdkit.backend.datapath=0>
+
+=item B<-D nbdkit.backend.datapath=1>
+
+These flags control the verbosity of nbdkit backend debugging messages
+(the ones which show every request processed by the server).  The
+default for both settings is C<1> (normal debugging) but you can set
+them to C<0> to suppress these messages.
+
+C<-D nbdkit.backend.datapath=0> is the more useful setting which lets you
+suppress messages about pread, pwrite, zero, trim, etc. commands.
+When transferring large amounts of data these messages are numerous
+and not usually very interesting.
+
+C<-D nbdkit.backend.controlpath=0> suppresses the non-datapath
+commands (config, open, close, can_write, etc.)
+
+=back
+
 =head1 SIGNALS
 
 nbdkit responds to the following signals:
diff --git a/server/backend.c b/server/backend.c
index b9fe2a21..208c07b1 100644
--- a/server/backend.c
+++ b/server/backend.c
@@ -46,6 +46,22 @@
 
 /* Helpers for registering a new backend. */
 
+/* Use:
+ * -D nbdkit.backend.controlpath=0 to suppress control path debugging.
+ * -D nbdkit.backend.datapath=0 to suppress data path debugging.
+ */
+int nbdkit_debug_backend_controlpath = 1;
+int nbdkit_debug_backend_datapath = 1;
+
+#define controlpath_debug(fs, ...)                                     \
+  do {                                                                 \
+    if (nbdkit_debug_backend_controlpath) debug ((fs), ##__VA_ARGS__); \
+  } while (0)
+#define datapath_debug(fs, ...)                                        \
+  do {                                                                 \
+    if (nbdkit_debug_backend_datapath) debug ((fs), ##__VA_ARGS__);    \
+  } while (0)
+
 void
 backend_init (struct backend *b, struct backend *next, size_t index,
               const char *filename, void *dl, const char *type)
@@ -108,7 +124,7 @@ backend_load (struct backend *b, const char *name, void (*load) (void))
   apply_debug_flags (b->dl, name);
 
   /* Call the on-load callback if it exists. */
-  debug ("%s: load", name);
+  controlpath_debug ("%s: load", name);
   if (load)
     load ();
 }
@@ -121,7 +137,7 @@ backend_unload (struct backend *b, void (*unload) (void))
    */
   lock_unload ();
 
-  debug ("%s: unload %s", b->name, b->type);
+  controlpath_debug ("%s: unload %s", b->name, b->type);
   if (unload)
     unload ();
 
@@ -139,7 +155,7 @@ backend_open (struct backend *b, struct connection *conn, int readonly)
 {
   struct b_conn_handle *h = &conn->handles[b->i];
 
-  debug ("%s: open readonly=%d", b->name, readonly);
+  controlpath_debug ("%s: open readonly=%d", b->name, readonly);
 
   assert (h->handle == NULL);
   assert ((h->state & HANDLE_OPEN) == 0);
@@ -151,7 +167,7 @@ backend_open (struct backend *b, struct connection *conn, int readonly)
    * inner-to-outer ordering.
    */
   h->handle = b->open (b, conn, readonly);
-  debug ("%s: open returned handle %p", b->name, h->handle);
+  controlpath_debug ("%s: open returned handle %p", b->name, h->handle);
 
   if (h->handle == NULL) {
     if (b->i) /* Do not strand backend if this layer failed */
@@ -179,7 +195,7 @@ backend_prepare (struct backend *b, struct connection *conn)
   if (b->i && backend_prepare (b->next, conn) == -1)
     return -1;
 
-  debug ("%s: prepare readonly=%d", b->name, h->can_write == 0);
+  controlpath_debug ("%s: prepare readonly=%d", b->name, h->can_write == 0);
 
   if (b->prepare (b, conn, h->handle, h->can_write == 0) == -1)
     return -1;
@@ -196,7 +212,7 @@ backend_finalize (struct backend *b, struct connection *conn)
    * filter furthest away from the plugin, and matching .close order.
    */
 
-  debug ("%s: finalize", b->name);
+  controlpath_debug ("%s: finalize", b->name);
 
   /* Once finalize fails, we can do nothing further on this connection */
   if (h->state & HANDLE_FAILED)
@@ -223,7 +239,7 @@ backend_close (struct backend *b, struct connection *conn)
   struct b_conn_handle *h = &conn->handles[b->i];
 
   /* outer-to-inner order, opposite .open */
-  debug ("%s: close", b->name);
+  controlpath_debug ("%s: close", b->name);
 
   if (h->handle) {
     assert (h->state & HANDLE_OPEN);
@@ -252,7 +268,7 @@ backend_valid_range (struct backend *b, struct connection *conn,
 int
 backend_reopen (struct backend *b, struct connection *conn, int readonly)
 {
-  debug ("%s: reopen readonly=%d", b->name, readonly);
+  controlpath_debug ("%s: reopen readonly=%d", b->name, readonly);
 
   if (backend_finalize (b, conn) == -1)
     return -1;
@@ -274,7 +290,7 @@ backend_get_size (struct backend *b, struct connection *conn)
 {
   struct b_conn_handle *h = &conn->handles[b->i];
 
-  debug ("%s: get_size", b->name);
+  controlpath_debug ("%s: get_size", b->name);
 
   assert (h->handle && (h->state & HANDLE_CONNECTED));
   if (h->exportsize == -1)
@@ -287,7 +303,7 @@ backend_can_write (struct backend *b, struct connection *conn)
 {
   struct b_conn_handle *h = &conn->handles[b->i];
 
-  debug ("%s: can_write", b->name);
+  controlpath_debug ("%s: can_write", b->name);
 
   assert (h->handle && (h->state & HANDLE_CONNECTED));
   if (h->can_write == -1)
@@ -300,7 +316,7 @@ backend_can_flush (struct backend *b, struct connection *conn)
 {
   struct b_conn_handle *h = &conn->handles[b->i];
 
-  debug ("%s: can_flush", b->name);
+  controlpath_debug ("%s: can_flush", b->name);
 
   assert (h->handle && (h->state & HANDLE_CONNECTED));
   if (h->can_flush == -1)
@@ -313,7 +329,7 @@ backend_is_rotational (struct backend *b, struct connection *conn)
 {
   struct b_conn_handle *h = &conn->handles[b->i];
 
-  debug ("%s: is_rotational", b->name);
+  controlpath_debug ("%s: is_rotational", b->name);
 
   assert (h->handle && (h->state & HANDLE_CONNECTED));
   if (h->is_rotational == -1)
@@ -327,7 +343,7 @@ backend_can_trim (struct backend *b, struct connection *conn)
   struct b_conn_handle *h = &conn->handles[b->i];
   int r;
 
-  debug ("%s: can_trim", b->name);
+  controlpath_debug ("%s: can_trim", b->name);
 
   assert (h->handle && (h->state & HANDLE_CONNECTED));
   if (h->can_trim == -1) {
@@ -347,7 +363,7 @@ backend_can_zero (struct backend *b, struct connection *conn)
   struct b_conn_handle *h = &conn->handles[b->i];
   int r;
 
-  debug ("%s: can_zero", b->name);
+  controlpath_debug ("%s: can_zero", b->name);
 
   assert (h->handle && (h->state & HANDLE_CONNECTED));
   if (h->can_zero == -1) {
@@ -367,7 +383,7 @@ backend_can_fast_zero (struct backend *b, struct connection *conn)
   struct b_conn_handle *h = &conn->handles[b->i];
   int r;
 
-  debug ("%s: can_fast_zero", b->name);
+  controlpath_debug ("%s: can_fast_zero", b->name);
 
   assert (h->handle && (h->state & HANDLE_CONNECTED));
   if (h->can_fast_zero == -1) {
@@ -386,7 +402,7 @@ backend_can_extents (struct backend *b, struct connection *conn)
 {
   struct b_conn_handle *h = &conn->handles[b->i];
 
-  debug ("%s: can_extents", b->name);
+  controlpath_debug ("%s: can_extents", b->name);
 
   assert (h->handle && (h->state & HANDLE_CONNECTED));
   if (h->can_extents == -1)
@@ -400,7 +416,7 @@ backend_can_fua (struct backend *b, struct connection *conn)
   struct b_conn_handle *h = &conn->handles[b->i];
   int r;
 
-  debug ("%s: can_fua", b->name);
+  controlpath_debug ("%s: can_fua", b->name);
 
   assert (h->handle && (h->state & HANDLE_CONNECTED));
   if (h->can_fua == -1) {
@@ -420,7 +436,7 @@ backend_can_multi_conn (struct backend *b, struct connection *conn)
   struct b_conn_handle *h = &conn->handles[b->i];
 
   assert (h->handle && (h->state & HANDLE_CONNECTED));
-  debug ("%s: can_multi_conn", b->name);
+  controlpath_debug ("%s: can_multi_conn", b->name);
 
   if (h->can_multi_conn == -1)
     h->can_multi_conn = b->can_multi_conn (b, conn, h->handle);
@@ -432,7 +448,7 @@ backend_can_cache (struct backend *b, struct connection *conn)
 {
   struct b_conn_handle *h = &conn->handles[b->i];
 
-  debug ("%s: can_cache", b->name);
+  controlpath_debug ("%s: can_cache", b->name);
 
   assert (h->handle && (h->state & HANDLE_CONNECTED));
   if (h->can_cache == -1)
@@ -451,8 +467,8 @@ backend_pread (struct backend *b, struct connection *conn,
   assert (h->handle && (h->state & HANDLE_CONNECTED));
   assert (backend_valid_range (b, conn, offset, count));
   assert (flags == 0);
-  debug ("%s: pread count=%" PRIu32 " offset=%" PRIu64,
-         b->name, count, offset);
+  datapath_debug ("%s: pread count=%" PRIu32 " offset=%" PRIu64,
+                  b->name, count, offset);
 
   r = b->pread (b, conn, h->handle, buf, count, offset, flags, err);
   if (r == -1)
@@ -475,8 +491,8 @@ backend_pwrite (struct backend *b, struct connection *conn,
   assert (!(flags & ~NBDKIT_FLAG_FUA));
   if (fua)
     assert (h->can_fua > NBDKIT_FUA_NONE);
-  debug ("%s: pwrite count=%" PRIu32 " offset=%" PRIu64 " fua=%d",
-         b->name, count, offset, fua);
+  datapath_debug ("%s: pwrite count=%" PRIu32 " offset=%" PRIu64 " fua=%d",
+                  b->name, count, offset, fua);
 
   r = b->pwrite (b, conn, h->handle, buf, count, offset, flags, err);
   if (r == -1)
@@ -494,7 +510,7 @@ backend_flush (struct backend *b, struct connection *conn,
   assert (h->handle && (h->state & HANDLE_CONNECTED));
   assert (h->can_flush == 1);
   assert (flags == 0);
-  debug ("%s: flush", b->name);
+  datapath_debug ("%s: flush", b->name);
 
   r = b->flush (b, conn, h->handle, flags, err);
   if (r == -1)
@@ -518,8 +534,8 @@ backend_trim (struct backend *b, struct connection *conn,
   assert (!(flags & ~NBDKIT_FLAG_FUA));
   if (fua)
     assert (h->can_fua > NBDKIT_FUA_NONE);
-  debug ("%s: trim count=%" PRIu32 " offset=%" PRIu64 " fua=%d",
-         b->name, count, offset, fua);
+  datapath_debug ("%s: trim count=%" PRIu32 " offset=%" PRIu64 " fua=%d",
+                  b->name, count, offset, fua);
 
   r = b->trim (b, conn, h->handle, count, offset, flags, err);
   if (r == -1)
@@ -547,9 +563,10 @@ backend_zero (struct backend *b, struct connection *conn,
     assert (h->can_fua > NBDKIT_FUA_NONE);
   if (fast)
     assert (h->can_fast_zero == 1);
-  debug ("%s: zero count=%" PRIu32 " offset=%" PRIu64
-         " may_trim=%d fua=%d fast=%d",
-         b->name, count, offset, !!(flags & NBDKIT_FLAG_MAY_TRIM), fua, fast);
+  datapath_debug ("%s: zero count=%" PRIu32 " offset=%" PRIu64
+                  " may_trim=%d fua=%d fast=%d",
+                  b->name, count, offset,
+                  !!(flags & NBDKIT_FLAG_MAY_TRIM), fua, fast);
 
   r = b->zero (b, conn, h->handle, count, offset, flags, err);
   if (r == -1) {
@@ -572,8 +589,8 @@ backend_extents (struct backend *b, struct connection *conn,
   assert (h->can_extents >= 0);
   assert (backend_valid_range (b, conn, offset, count));
   assert (!(flags & ~NBDKIT_FLAG_REQ_ONE));
-  debug ("%s: extents count=%" PRIu32 " offset=%" PRIu64 " req_one=%d",
-         b->name, count, offset, !!(flags & NBDKIT_FLAG_REQ_ONE));
+  datapath_debug ("%s: extents count=%" PRIu32 " offset=%" PRIu64 " req_one=%d",
+                  b->name, count, offset, !!(flags & NBDKIT_FLAG_REQ_ONE));
 
   if (h->can_extents == 0) {
     /* By default it is safe assume that everything in the range is
@@ -602,8 +619,8 @@ backend_cache (struct backend *b, struct connection *conn,
   assert (h->can_cache > NBDKIT_CACHE_NONE);
   assert (backend_valid_range (b, conn, offset, count));
   assert (flags == 0);
-  debug ("%s: cache count=%" PRIu32 " offset=%" PRIu64,
-         b->name, count, offset);
+  datapath_debug ("%s: cache count=%" PRIu32 " offset=%" PRIu64,
+                  b->name, count, offset);
 
   if (h->can_cache == NBDKIT_CACHE_EMULATE) {
     static char buf[MAX_REQUEST_SIZE]; /* data sink, never read */
diff --git a/tests/Makefile.am b/tests/Makefile.am
index 01341973..d225cc63 100644
--- a/tests/Makefile.am
+++ b/tests/Makefile.am
@@ -135,6 +135,7 @@ EXTRA_DIST = \
 	test-nbd-extents.sh \
 	test-nbd-tls.sh \
 	test-nbd-tls-psk.sh \
+	test-nbdkit-backend-debug.sh \
 	test-nozero.sh \
 	test-null-extents.sh \
 	test_ocaml_plugin.ml \
@@ -746,6 +747,9 @@ endif HAVE_VDDK
 # zero plugin test.
 TESTS += test-zero.sh
 
+# -D nbdkit.backend.* settings.
+TESTS += test-nbdkit-backend-debug.sh
+
 #----------------------------------------------------------------------
 # Tests of language plugins.
 
diff --git a/tests/test-nbdkit-backend-debug.sh b/tests/test-nbdkit-backend-debug.sh
new file mode 100755
index 00000000..69a69a7c
--- /dev/null
+++ b/tests/test-nbdkit-backend-debug.sh
@@ -0,0 +1,70 @@
+#!/usr/bin/env bash
+# nbdkit
+# Copyright (C) 2019 Red Hat Inc.
+#
+# 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.
+
+source ./functions.sh
+set -x
+set -e
+
+requires qemu-img --version
+
+out="test-nbdkit-backend-debug.out"
+debug="test-nbdkit-backend-debug.debug"
+files="$out $debug"
+rm -f $files
+cleanup_fn rm -f $files
+
+nbdkit -U - \
+       -v \
+       memory 10M \
+       --run "qemu-img convert \$nbd $out" |& tee $debug
+
+# Should contain all debugging messages.
+grep '^nbdkit:.*debug: memory: open' $debug
+grep '^nbdkit:.*debug: memory: pread' $debug
+
+nbdkit -U - \
+       -v -D nbdkit.backend.controlpath=0 \
+       memory 10M \
+       --run "qemu-img convert \$nbd $out" |& tee $debug
+
+# Should contain only datapath messages.
+grep -v '^nbdkit:.*debug: memory: open' $debug
+grep '^nbdkit:.*debug: memory: pread' $debug
+
+nbdkit -U - \
+       -v -D nbdkit.backend.datapath=0 \
+       memory 10M \
+       --run "qemu-img convert \$nbd $out" |& tee $debug
+
+# Should contain only controlpath messages.
+grep '^nbdkit:.*debug: memory: open' $debug
+grep -v '^nbdkit:.*debug: memory: pread' $debug
-- 
2.18.2