Re: [PATCH] 9pfs: improve v9fs_open() tracing

[Christian Schoenebeck <qemu_oss@crudebyte.com>]

On Monday, December 16, 2024 11:30:09 AM CET Christian Schoenebeck wrote:
> Improve tracing of 9p 'Topen' request type by showing open() flags as
> human-readable text.
> 
> E.g. trace output:
> 
>   v9fs_open tag 0 id 12 fid 2 mode 100352
> 
> would become:
> 
>   v9fs_open tag=0 id=12 fid=2 mode=100352(RDONLY|NONBLOCK|DIRECTORY|
>   TMPFILE|NDELAY)
> 
> Therefor add a new utility function qemu_open_flags_tostr() that converts
> numeric open() flags from host's native O_* flag constants to a string
> presentation.
> 
> 9p2000.L and 9p2000.u protocol variants use different numeric 'mode'
> constants for 'Topen' requests. Instead of writing string conversion code
> for both protocol variants, use the already existing conversion functions
> that convert the mode flags from respective protocol constants to host's
> native open() numeric flag constants and pass that result to the new
> string conversion function qemu_open_flags_tostr().
> 
> Signed-off-by: Christian Schoenebeck <qemu_oss@crudebyte.com>
> ---
>  hw/9pfs/9p-util-generic.c | 44 +++++++++++++++++++++++++++++++++++++++
>  hw/9pfs/9p-util.h         |  6 ++++++
>  hw/9pfs/9p.c              |  9 +++++++-
>  hw/9pfs/meson.build       |  1 +
>  hw/9pfs/trace-events      |  2 +-
>  5 files changed, 60 insertions(+), 2 deletions(-)
>  create mode 100644 hw/9pfs/9p-util-generic.c
> 
> diff --git a/hw/9pfs/9p-util-generic.c b/hw/9pfs/9p-util-generic.c
> new file mode 100644
> index 0000000000..dff9a42d97
> --- /dev/null
> +++ b/hw/9pfs/9p-util-generic.c
> @@ -0,0 +1,44 @@
> +/* SPDX-License-Identifier: GPL-2.0-or-later */
> +
> +#include "qemu/osdep.h"
> +#include "9p-util.h"
> +#include <glib/gstrfuncs.h>
> +

Peter, I assume GPL 2.0 is still the recommended license to go for with QEMU?
Just asking because Gitlab project page says LGPLv2.1:

https://gitlab.com/qemu-project/qemu/

Greg, I added this code as separate file 9p-util-generic.c instead of
9p-util.h, because this code pulls a glib header and 9p-util.h is pulled
almost everywhere.

> +char *qemu_open_flags_tostr(int flags)
> +{
> +    int acc = flags & O_ACCMODE;
> +    return g_strconcat(
> +        (acc == O_WRONLY) ? "WRONLY" : (acc == O_RDONLY) ? "RDONLY" : "RDWR",
> +        (flags & O_CREAT) ? "|CREAT" : "",
> +        (flags & O_EXCL) ? "|EXCL" : "",
> +        (flags & O_NOCTTY) ? "|NOCTTY" : "",
> +        (flags & O_TRUNC) ? "|TRUNC" : "",
> +        (flags & O_APPEND) ? "|APPEND" : "",
> +        (flags & O_NONBLOCK) ? "|NONBLOCK" : "",
> +        (flags & O_DSYNC) ? "|DSYNC" : "",
> +        #ifdef O_DIRECT
> +        (flags & O_DIRECT) ? "|DIRECT" : "",
> +        #endif
> +        (flags & O_LARGEFILE) ? "|LARGEFILE" : "",
> +        (flags & O_DIRECTORY) ? "|DIRECTORY" : "",
> +        (flags & O_NOFOLLOW) ? "|NOFOLLOW" : "",
> +        #ifdef O_NOATIME
> +        (flags & O_NOATIME) ? "|NOATIME" : "",
> +        #endif
> +        #ifdef O_CLOEXEC
> +        (flags & O_CLOEXEC) ? "|CLOEXEC" : "",
> +        #endif
> +        (flags & O_SYNC) ? "|SYNC" : "",
> +        #ifdef O_PATH
> +        (flags & O_PATH) ? "|PATH" : "",
> +        #endif
> +        #ifdef O_TMPFILE
> +        (flags & O_TMPFILE) ? "|TMPFILE" : "",
> +        #endif
> +        /* O_NDELAY is usually just an alias of O_NONBLOCK */
> +        #ifdef O_NDELAY
> +        (flags & O_NDELAY) ? "|NDELAY" : "",
> +        #endif
> +        NULL /* always last (required NULL termination) */
> +    );
> +}
> diff --git a/hw/9pfs/9p-util.h b/hw/9pfs/9p-util.h
> index 51c94b0116..a24d572407 100644
> --- a/hw/9pfs/9p-util.h
> +++ b/hw/9pfs/9p-util.h
> @@ -260,4 +260,10 @@ int pthread_fchdir_np(int fd) __attribute__((weak_import));
>  #endif
>  int qemu_mknodat(int dirfd, const char *filename, mode_t mode, dev_t dev);
>  
> +/*
> + * Returns a newly allocated string presentation of open() flags, intended
> + * for debugging (tracing) purposes only.
> + */
> +char *qemu_open_flags_tostr(int flags);
> +
>  #endif
> diff --git a/hw/9pfs/9p.c b/hw/9pfs/9p.c
> index 6f24c1abb3..7cad2bce62 100644
> --- a/hw/9pfs/9p.c
> +++ b/hw/9pfs/9p.c
> @@ -2008,6 +2008,7 @@ static void coroutine_fn v9fs_open(void *opaque)
>      V9fsFidState *fidp;
>      V9fsPDU *pdu = opaque;
>      V9fsState *s = pdu->s;
> +    g_autofree char *trace_oflags = NULL;
>  
>      if (s->proto_version == V9FS_PROTO_2000L) {
>          err = pdu_unmarshal(pdu, offset, "dd", &fid, &mode);
> @@ -2019,7 +2020,13 @@ static void coroutine_fn v9fs_open(void *opaque)
>      if (err < 0) {
>          goto out_nofid;
>      }
> -    trace_v9fs_open(pdu->tag, pdu->id, fid, mode);
> +    if (trace_event_get_state_backends(TRACE_V9FS_OPEN)) {
> +        trace_oflags = qemu_open_flags_tostr(
> +            (s->proto_version == V9FS_PROTO_2000L) ?
> +                dotl_to_open_flags(mode) : omode_to_uflags(mode)
> +        );
> +        trace_v9fs_open(pdu->tag, pdu->id, fid, mode, trace_oflags);
> +    }

While writing this, I noticed that the previously discussed O_PATH flag is
silently filtered out by both dotl_to_open_flags() and omode_to_uflags().

Not that I am suggesting to change this. In fact it would probably break
use-after-unlink behaviour if server would obey client's open request with
O_PATH. Just saying.

/Christian

>  
>      fidp = get_fid(pdu, fid);
>      if (fidp == NULL) {
> diff --git a/hw/9pfs/meson.build b/hw/9pfs/meson.build
> index eceffdb81e..d35d4f44ff 100644
> --- a/hw/9pfs/meson.build
> +++ b/hw/9pfs/meson.build
> @@ -3,6 +3,7 @@ fs_ss.add(files(
>    '9p-local.c',
>    '9p-posix-acl.c',
>    '9p-synth.c',
> +  '9p-util-generic.c',
>    '9p-xattr-user.c',
>    '9p-xattr.c',
>    '9p.c',
> diff --git a/hw/9pfs/trace-events b/hw/9pfs/trace-events
> index ed9f4e7209..0e0fc37261 100644
> --- a/hw/9pfs/trace-events
> +++ b/hw/9pfs/trace-events
> @@ -13,7 +13,7 @@ v9fs_getattr(uint16_t tag, uint8_t id, int32_t fid, uint64_t request_mask) "tag
>  v9fs_getattr_return(uint16_t tag, uint8_t id, uint64_t result_mask, uint32_t mode, uint32_t uid, uint32_t gid) "tag %d id %d getattr={result_mask %"PRId64" mode %u uid %u gid %u}"
>  v9fs_walk(uint16_t tag, uint8_t id, int32_t fid, int32_t newfid, uint16_t nwnames, const char* wnames) "tag=%d id=%d fid=%d newfid=%d nwnames=%d wnames={%s}"
>  v9fs_walk_return(uint16_t tag, uint8_t id, uint16_t nwnames, void* qids) "tag %d id %d nwnames %d qids %p"
> -v9fs_open(uint16_t tag, uint8_t id, int32_t fid, int32_t mode) "tag %d id %d fid %d mode %d"
> +v9fs_open(uint16_t tag, uint8_t id, int32_t fid, int32_t mode, const char* oflags) "tag=%d id=%d fid=%d mode=%d(%s)"
>  v9fs_open_return(uint16_t tag, uint8_t id, uint8_t type, uint32_t version, uint64_t path, int iounit) "tag %u id %u qid={type %u version %u path %"PRIu64"} iounit %d"
>  v9fs_lcreate(uint16_t tag, uint8_t id, int32_t dfid, int32_t flags, int32_t mode, uint32_t gid) "tag %d id %d dfid %d flags %d mode %d gid %u"
>  v9fs_lcreate_return(uint16_t tag, uint8_t id, uint8_t type, uint32_t version, uint64_t path, int32_t iounit) "tag %u id %u qid={type %u version %u path %"PRIu64"} iounit %d"
>