Re: [PATCH 4/4] vhost: prefix logs with context

[David Marchand <david.marchand@redhat.com>]

On Thu, Jun 30, 2022 at 6:13 PM Maxime Coquelin
<maxime.coquelin@redhat.com> wrote:
> On 6/27/22 11:27, David Marchand wrote:
> > We recently improved the log messages in the vhost library, adding some
> > context that helps filtering for a given vhost-user device.
> > However, some parts of the code were missed, and some later code changes
> > broke this new convention (fixes were sent previous to this patch).
> >
> > Change the VHOST_LOG_CONFIG/DATA helpers and always ask for a string
> > used as context. This should help limit regressions on this topic.
> >
> > Most of the time, the context is the vhost-user device socket path.
> > For the rest when a vhost-user device can not be related, generic
> > names were chosen:
> > - "dma", for vhost-user async DMA operations,
> > - "device", for vhost-user device creation and lookup,
> > - "thread", for threads management,
> >
> > Signed-off-by: David Marchand <david.marchand@redhat.com>
> > ---
> >   lib/vhost/iotlb.c      |  30 +-
> >   lib/vhost/socket.c     | 129 ++++-----
> >   lib/vhost/vdpa.c       |   4 +-
> >   lib/vhost/vhost.c      | 144 ++++-----
> >   lib/vhost/vhost.h      |  20 +-
> >   lib/vhost/vhost_user.c | 642 +++++++++++++++++++++--------------------
> >   lib/vhost/virtio_net.c | 258 +++++++++--------
> >   7 files changed, 634 insertions(+), 593 deletions(-)
> >
>
> > diff --git a/lib/vhost/vhost.h b/lib/vhost/vhost.h
> > index 810bc71c9d..310aaf88ff 100644
> > --- a/lib/vhost/vhost.h
> > +++ b/lib/vhost/vhost.h
> > @@ -625,14 +625,14 @@ vhost_log_write_iova(struct virtio_net *dev, struct vhost_virtqueue *vq,
> >   extern int vhost_config_log_level;
> >   extern int vhost_data_log_level;
> >
> > -#define VHOST_LOG_CONFIG(level, fmt, args...)                        \
> > +#define VHOST_LOG_CONFIG(prefix, level, fmt, args...)                \
> >       rte_log(RTE_LOG_ ## level, vhost_config_log_level,      \
> > -             "VHOST_CONFIG: " fmt, ##args)
> > +             "VHOST_CONFIG: (%s): " fmt, prefix, ##args)
> >
> > -#define VHOST_LOG_DATA(level, fmt, args...) \
> > +#define VHOST_LOG_DATA(prefix, level, fmt, args...)          \
> >       (void)((RTE_LOG_ ## level <= RTE_LOG_DP_LEVEL) ?        \
> >        rte_log(RTE_LOG_ ## level,  vhost_data_log_level,      \
> > -             "VHOST_DATA : " fmt, ##args) :                  \
> > +             "VHOST_DATA: (%s):" fmt, prefix, ##args) :      \
> >        0)
>
> As discussed off-list, adding the function will break OVS tests once
> again. I propose to pick the first 3 patches for now.

The issue with OVS tests is that they match the log message content,
and this current patch changes the format.

For example, before we have:
VHOST_CONFIG: (vhost0.sock) vhost-user server: socket created, fd: 57
VHOST_CONFIG: (vhost0.sock) binding succeeded
After:
VHOST_CONFIG: (vhost0.sock): vhost-user server: socket created, fd: 56
VHOST_CONFIG: (vhost0.sock): binding succeeded

I can respin, removing the extra ':' in VHOST_* macros.
WDYT?


-- 
David Marchand