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

[Maxime Coquelin <maxime.coquelin@redhat.com>]

On 7/1/22 09:13, David Marchand wrote:
> 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?


Sounds good!

Thanks,
Maxime