[prev in list] [next in list] [prev in thread] [next in thread] 

List:       libvir-list
Subject:    Re: [libvirt] [PATCH 0/4] virtlogd: timestamp option to prepend timestamp
From:       Michal Prívozník <mprivozn () redhat ! com>
Date:       2024-02-29 15:03:54
Message-ID: 35a96ee6-0837-419f-8772-ab6dad9b0741 () redhat ! com
[Download RAW message or body]

On 2/29/24 07:46, Shaleen Bathla wrote:
> Description
> ====================================================
> Add timestamp option to virtlogd.conf
> When timestamp=1, let virtlogd prepend timestamps at start of line,
> i.e. append timestamp after '\n' character.
> This can be a useful debugging feature to help us see timestamp along
> with commands/operations run inside the VM
> 
> Previous discussion link :
> https://listman.redhat.com/archives/libvir-list/2023-August/241562.html
> 
> Test
> =====================================================
> Set timestamp = 1 in virtlogd.conf
> systemctl restart libvirtd
> If VM's xml has something like :
>   <devices>
>     ...
>     <console type='pty'>
>       <log file='/var/log/libvirt/vm-serial0.log' append='on'/>
>       <target type='serial' port='0'/>
>     </console>
>   </devices>
> 
> 
> Sample Output of /var/log/libvirt/vm-serial0.log:
> ...
> 2024-02-22 09:36:33.898+0000 Last login: Sat Feb 10 10:48:00 on ttyS0^M
> 2024-02-22 09:36:33.953+0000 [root@localhost ~]# ll^H^[[K^H^[[K^M
> 2024-02-22 09:36:36.930+0000 [root@localhost ~]# ls^M
> 2024-02-22 09:36:38.224+0000 anaconda-ks.cfg  original-ks.cfg  test.py  tmp     x.txt^M
> 2024-02-22 09:36:38.226+0000 [root@localhost ~]# ^M
> 2024-02-22 09:36:40.062+0000 [root@localhost ~]# l^H^[[Kyo^M
> 2024-02-22 09:36:44.292+0000 -bash: yo: command not found^M
> 2024-02-22 09:36:44.293+0000 [root@localhost ~]#
> 
> 
> Shaleen Bathla (4):
>   logging: virtlogd: Add option to append timestamp to domain logs
>   util: virrotatingfile: Introduce virRotatingFileWriterAppendTimestamp
>   util: virrotatingfile: virtlogd timestamp appending logic
>   tests: virrotatingfiletest: update virRotatingFileWriterAppend
> 
>  src/logging/log_daemon_config.c  |  3 ++
>  src/logging/log_daemon_config.h  |  1 +
>  src/logging/log_handler.c        | 10 +++--
>  src/logging/test_virtlogd.aug.in |  1 +
>  src/logging/virtlogd.aug         |  1 +
>  src/logging/virtlogd.conf        |  4 ++
>  src/util/virrotatingfile.c       | 69 +++++++++++++++++++++++++++++++-
>  src/util/virrotatingfile.h       |  3 +-
>  tests/virrotatingfiletest.c      | 34 ++++++++--------
>  9 files changed, 104 insertions(+), 22 deletions(-)
> 

Couple of points:

1) We require that after every single commit the code base compiles and
all tests pass. This is a non-negotiable requirement and it's because
when bisceting something, we want to be able to compile libvirt and
focus on the bug we're after. Not fight a broken build. The feature is
not required to be available from the very first commit. For large
series we often have patches that refactor something, prepare the code
base, then implement it in various areas of the code, and only as the
last commit the feature is turned on.

2) Be aware that logging code you're touching is also used for
/var/log/libvirt/qemu/$VM.log. After this series I'm seeing some weird
behavior:

# tail -n3 /var/log/libvirt/qemu/fedora.log
2024-02-29 14:48:33.785+000 2024-02-29 14:48:33.857+0000: 9562: debug :
virCommandHandshakeChild:431 : Handshake with parent is done
2024-02-29 14:48:33.857+000 char device redirected to /dev/pts/41 (label
charserial0)
2024-02-29 14:48:33.876+000

IOW, the timestamp is printed twice. Also, the log file ends with a
timestamp and no other message.

Michal
_______________________________________________
Devel mailing list -- devel@lists.libvirt.org
To unsubscribe send an email to devel-leave@lists.libvirt.org

[prev in list] [next in list] [prev in thread] [next in thread]