Re: [PATCH] log: Send identifier string in log messages, openlog() won't work for us

[Stefano Brivio <sbrivio@redhat.com>]

On Thu, 23 Feb 2023 10:15:15 -0800
Andrea Bolognani <abologna@redhat.com> wrote:

> On Thu, Feb 23, 2023 at 06:35:55PM +0100, Stefano Brivio wrote:
> > openlog() can be used to set "ident" and have all the log messages
> > prefixed by it, but only if we call syslog() -- this is implemented
> > by C libraries.
> >
> > We don't log messages with syslog(), though, as we have a custom
> > implementation to ensure we don't need dynamic memory allocation.
> > This means that it's perfectly useless to call openlog(), and that we
> > have to prefix every message we log by the identifier on our own.
> >
> > Reported-by: Andrea Bolognani <abologna@redhat.com>
> > Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
> > ---
> >  log.c | 12 +++++-------
> >  1 file changed, 5 insertions(+), 7 deletions(-)  
> 
> With this patch applied, the entries I see in the journal after
> starting a VM go from
> 
>   passt.avx2[519959]:  No external routable interface for IPv6
>   passt.avx2[519959]:  Outbound interface (IPv4): enp5s0
>   MAC[519959]:
>   host[519959]: xx:xx:xx:xx:xx:xx
>   DHCP[519959]:
>   assign[519959]: 192.168.1.62
>   mask[519959]: 255.255.255.0
>   router[519959]: 192.168.1.1
>   DNS[519959]:
>   passt.avx2[519959]:      192.168.1.1
>   passt.avx2[519959]:  DNS search list:
>   passt.avx2[519959]:      xxx
>   passt.avx2[519959]:  UNIX domain socket bound at
> /run/libvirt/qemu/passt/12-xxx-net0.socket
>   passt.avx2[519959]:  You can now start qemu (>= 7.2, with commit
> 13c6be96618c):
>   passt.avx2[519959]:      kvm ... -device virtio-net-pci,netdev=s
> -netdev stream,id=s,server=off,addr.type=unix,addr.path=/run/libvirt/qemu/passt/12-xxx-net0.socket
>   passt.avx2[519959]:  or qrap, for earlier qemu versions:
>   passt.avx2[519959]:      ./qrap 5 kvm ... -net socket,fd=5 -net
> nic,model=virtio
>   passt.avx2[519960]:  accepted connection from PID 0
>   DHCP[519960]: ack to request
>   passt.avx2[519960]:      from xx:xx:xx:xx:xx:xx
> 
> to
> 
>   passt[523786]: No external routable interface for IPv6
>   passt[523786]: Outbound interface (IPv4): enp5s0
>   passt[523786]: MAC:
>   passt[523786]:     host: xx:xx:xx:xx:xx:xx
>   passt[523786]: DHCP:
>   passt[523786]:     assign: 192.168.1.62
>   passt[523786]:     mask: 255.255.255.0
>   passt[523786]:     router: 192.168.1.1
>   passt[523786]: DNS:
>   passt[523786]:     192.168.1.1
>   passt[523786]: DNS search list:
>   passt[523786]:     xxx
>   passt[523786]: UNIX domain socket bound at
> /run/libvirt/qemu/passt/13-xxx-net0.socket
>   passt[523786]: You can now start qemu (>= 7.2, with commit 13c6be96618c):
>   passt[523786]:     kvm ... -device virtio-net-pci,netdev=s -netdev
> stream,id=s,server=off,addr.type=unix,addr.path=/run/libvirt/qemu/passt/13-xxx-net0.socket
>   passt[523786]: or qrap, for earlier qemu versions:
>   passt[523786]:     ./qrap 5 kvm ... -net socket,fd=5 -net nic,model=virtio
>   passt[523789]: accepted connection from PID 0
>   passt[523789]: DHCP: ack to request
>   passt[523789]:     from xx:xx:xx:xx:xx:xx
> 
> which is clearly much better.
> 
>   Tested-by: Andrea Bolognani <abologna@redhat.com>
>   Reviewed-by: Andrea Bolognani <abologna@redhat.com>

Thanks for the tests and review!

> Note the change from passt.avx2 to passt. Looking at the process
> listing, plain passt was used in both cases, so I assume that the
> passt.avx2 mention is journald trying to fill in the blanks and
> getting it wrong?

Yes, it's your system logger filling in the blanks, but it didn't
really get it wrong, as the process name is actually "passt.avx2" if
the AVX2-enabled build starts. Look at this, cough cough, beauty in
arch.c:

  https://passt.top/passt/tree/arch.c#n21

"passt.avx2" wasn't intended in any case.

-- 
Stefano