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