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