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