[adding Stefan as trace maintainer]

On 05/30/2017 09:30 AM, Vladimir Sementsov-Ogievskiy wrote:
> Signed-off-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
> ---
>  Makefile.objs      |  1 +
>  nbd/client.c       | 77 ++++++++++++++++++++++++----------------------------
>  nbd/nbd-internal.h | 19 -------------
>  nbd/server.c       | 79 ++++++++++++++++++++++++++----------------------------
>  nbd/trace-events   | 67 +++++++++++++++++++++++++++++++++++++++++++++
>  5 files changed, 141 insertions(+), 102 deletions(-)
>  create mode 100644 nbd/trace-events

I like where you're headed with this one.

Can you please include an example command line usage in the commit
message of how you are enabling the traces (the old way was to recompile
with CFLAGS=-DDEBUG_NBD; the new way no longer requires recompilation,
but listing a formula for easy tracing as part of the commit message
can't hurt).  And if I'm correct, we already have the same command-line
tracing framework hooked up for all of qemu-nbd, qemu-io, and qemu
proper, right?

> @@ -453,8 +452,7 @@ int nbd_receive_negotiate(QIOChannel *ioc, const char *name, uint16_t *flags,
>      int rc;
>      bool zeroes = true;
>  
> -    TRACE("Receiving negotiation tlscreds=%p hostname=%s.",

Most trace messages don't have a trailing '.'; you can remove this one
as part of moving it to trace-events.

> @@ -477,7 +475,7 @@ int nbd_receive_negotiate(QIOChannel *ioc, const char *name, uint16_t *flags,
>          goto fail;
>      }
>  
> -    TRACE("Magic is %s", nbd_magic_to_string(print_buf, buf, 9));
> +    trace_nbd_receive_negotiate_magic(nbd_magic_to_string(print_buf, buf, 9));
>  
>      if (memcmp(buf, "NBDMAGIC", 8) != 0) {

See my review on 18/19; I think it is sufficient to trace an 8-byte hex
number, instead of trying to string-ize things.  Yeah, the magic number
happens to be an ASCII string, but treating it as a number is no real
loss of information.

>          error_setg(errp, "Invalid magic received");
> @@ -489,7 +487,7 @@ int nbd_receive_negotiate(QIOChannel *ioc, const char *name, uint16_t *flags,
>          goto fail;
>      }
>      magic = be64_to_cpu(magic);
> -    TRACE("Magic is 0x%" PRIx64, magic);
> +    trace_nbd_receive_negotiate_magic2(magic);

In fact, I think you only need one trace function for tracing an 8-byte
magic number, that can be called from more than one spot.

> @@ -501,15 +499,16 @@ int nbd_receive_negotiate(QIOChannel *ioc, const char *name, uint16_t *flags,
>              goto fail;
>          }
>          globalflags = be16_to_cpu(globalflags);
> -        TRACE("Global flags are %" PRIx32, globalflags);
> +        trace_nbd_receive_negotiate_server_flags(
> +            globalflags,
> +            !!(globalflags & NBD_FLAG_FIXED_NEWSTYLE),
> +            !!(globalflags & NBD_FLAG_NO_ZEROES));

Why do we have to trace particular bits within the flags, when we are
already tracing the flags as a whole?  It is just redundant information
(yes, it makes it a bit harder to read the trace to learn whether a
given flag is set when you only have the hex number, but I don't think
that is a real loss).

>          if (globalflags & NBD_FLAG_FIXED_NEWSTYLE) {
>              fixedNewStyle = true;
> -            TRACE("Server supports fixed new style");
>              clientflags |= NBD_FLAG_C_FIXED_NEWSTYLE;
>          }
>          if (globalflags & NBD_FLAG_NO_ZEROES) {
>              zeroes = false;
> -            TRACE("Server supports no zeroes");
>              clientflags |= NBD_FLAG_C_NO_ZEROES;
>          }

I agree with dropping these two TRACE() in favor of the overall trace of
the flags above (this exercise is a good place to figure out where
TRACE() was too chatty).

> @@ -580,7 +579,7 @@ int nbd_receive_negotiate(QIOChannel *ioc, const char *name, uint16_t *flags,
>              goto fail;
>          }
>          *size = be64_to_cpu(s);
> -        TRACE("Size is %" PRIu64, *size);
> +        trace_nbd_receive_negotiate_export_size(*size);
>  
>          if (read_sync(ioc, &oldflags, sizeof(oldflags), errp) < 0) {
>              error_prepend(errp, "Failed to read export flags");
> @@ -597,7 +596,7 @@ int nbd_receive_negotiate(QIOChannel *ioc, const char *name, uint16_t *flags,
>          goto fail;
>      }
>  
> -    TRACE("Size is %" PRIu64 ", export flags %" PRIx16, *size, *flags);
> +    trace_nbd_receive_negotiate_size_flags(*size, *flags);

Can we share the same trace for these two callers, by having the first
one use trace_nbd_receive_negotiate_size_flags(*size, 0)?

-- 
Eric Blake, Principal Software Engineer
Red Hat, Inc.           +1-919-301-3266
Virtualization:  qemu.org | libvirt.org