Bug 2174446

Summary: Logs are spammed with ' Domain id=7 is tainted: custom-ga-command' message
Product: Red Hat Enterprise Linux 9 Reporter: Peter Krempa <pkrempa>
Component: libvirtAssignee: Peter Krempa <pkrempa>
libvirt sub component: General QA Contact: Lili Zhu <lizhu>
Status: CLOSED ERRATA Docs Contact:
Severity: unspecified    
Priority: unspecified CC: jdenemar, jsuchane, lizhu, lmen, pvlasin, virt-maint, ymankad
Version: 9.0Keywords: Triaged
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: libvirt-9.0.0-8.el9_2 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
: 2174447 2176924 (view as bug list) Environment:
Last Closed: 2023-05-09 07:27:59 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 2174447, 2176924    

Description Peter Krempa 2023-03-01 16:18:25 UTC
Description of problem:
When a management APP is using agent command passhthrough the logs are spammed with:

 Domain id=7 is tainted: custom-ga-command

over and over again.

Version-Release number of selected component (if applicable):
introduced in libvirt 7.1

How reproducible:
always

Steps to Reproduce:
1. Start VM
2. repeatedly invoke command such as:
$ virsh qemu-agent-command ha '{"execute":"guest-get-vcpus"}'

3. observe logs being spammed

Actual results:


Expected results:


Additional info:

Comment 1 Peter Krempa 2023-03-06 13:53:31 UTC
Fixed upstream:

commit 9134b40d0b43a5e1a9928b0a0d948205941d9807
Author: Peter Krempa <pkrempa>
Date:   Wed Mar 1 17:09:42 2023 +0100

    qemu: domain: Fix logic when tainting domain
    
    Originally the code was skipping all repeated taints with the same taint
    flag but a logic bug introduced in commit 30626ed15b239c424ae inverted
    the condition. This caused that actually the first occurence was NOT
    logged but any subsequent was.
    
    This was noticed when going through oVirt logs as they use custom guest
    agent commands and the logs are totally spammed with this message.
    
    Fixes: 30626ed15b239c424ae891f096057a696eadd715
    Signed-off-by: Peter Krempa <pkrempa>
    Reviewed-by: Laine Stump <laine>

v9.1.0-11-g9134b40d0b

Comment 8 Lili Zhu 2023-03-11 07:22:10 UTC
Rreproduced this bug with:
libvirt-9.0.0-7.el9.x86_64

1. prepare a guest with guest agent
# virsh domtime vm1
Time: 1678509372

2. check the some info about guest using qemu-agent-command
# virsh qemu-agent-command vm1 '{"execute":"guest-get-fsinfo"}'
{"return":[{"name":"vda1","total-bytes":627875840,...

3.check the log
# grep -ni tainted /var/log/libvirt/libvirtd.log 
(no output)

4. repeat step 2, check the log again
# grep -ni tainted /var/log/libvirt/libvirtd.log 
48494:2023-03-11 07:17:05.341+0000: 40743: warning : qemuDomainObjTaintMsg:6618 : Domain id=1 name='vm1' uuid=479df013-c11c-4109-98bf-461bb6a525bb is tainted: custom-ga-command
48496:2023-03-11 07:17:05.341+0000: 40743: debug : qemuDomainLogAppendMessage:6990 : Append log message (vm='vm1' message='2023-03-11 07:17:05.341+0000: Domain id=1 is tainted: custom-ga-command

5. repat step2, and check the log again
# grep -ni tainted /var/log/libvirt/libvirtd.log 
48494:2023-03-11 07:17:05.341+0000: 40743: warning : qemuDomainObjTaintMsg:6618 : Domain id=1 name='vm1' uuid=479df013-c11c-4109-98bf-461bb6a525bb is tainted: custom-ga-command
48496:2023-03-11 07:17:05.341+0000: 40743: debug : qemuDomainLogAppendMessage:6990 : Append log message (vm='vm1' message='2023-03-11 07:17:05.341+0000: Domain id=1 is tainted: custom-ga-command
[root@dell-per640-07 ~]# grep -ni tainted /var/log/libvirt/libvirtd.log 
48494:2023-03-11 07:17:05.341+0000: 40743: warning : qemuDomainObjTaintMsg:6618 : Domain id=1 name='vm1' uuid=479df013-c11c-4109-98bf-461bb6a525bb is tainted: custom-ga-command
48496:2023-03-11 07:17:05.341+0000: 40743: debug : qemuDomainLogAppendMessage:6990 : Append log message (vm='vm1' message='2023-03-11 07:17:05.341+0000: Domain id=1 is tainted: custom-ga-command
49475:2023-03-11 07:18:17.349+0000: 40740: warning : qemuDomainObjTaintMsg:6618 : Domain id=1 name='vm1' uuid=479df013-c11c-4109-98bf-461bb6a525bb is tainted: custom-ga-command
49477:2023-03-11 07:18:17.349+0000: 40740: debug : qemuDomainLogAppendMessage:6990 : Append log message (vm='vm1' message='2023-03-11 07:18:17.349+0000: Domain id=1 is tainted: custom-ga-command

8. repeat step2 for several times and check the log
# grep -ni tainted /var/log/libvirt/libvirtd.log 
48494:2023-03-11 07:17:05.341+0000: 40743: warning : qemuDomainObjTaintMsg:6618 : Domain id=1 name='vm1' uuid=479df013-c11c-4109-98bf-461bb6a525bb is tainted: custom-ga-command
48496:2023-03-11 07:17:05.341+0000: 40743: debug : qemuDomainLogAppendMessage:6990 : Append log message (vm='vm1' message='2023-03-11 07:17:05.341+0000: Domain id=1 is tainted: custom-ga-command
49475:2023-03-11 07:18:17.349+0000: 40740: warning : qemuDomainObjTaintMsg:6618 : Domain id=1 name='vm1' uuid=479df013-c11c-4109-98bf-461bb6a525bb is tainted: custom-ga-command
49477:2023-03-11 07:18:17.349+0000: 40740: debug : qemuDomainLogAppendMessage:6990 : Append log message (vm='vm1' message='2023-03-11 07:18:17.349+0000: Domain id=1 is tainted: custom-ga-command
50456:2023-03-11 07:19:35.177+0000: 40739: warning : qemuDomainObjTaintMsg:6618 : Domain id=1 name='vm1' uuid=479df013-c11c-4109-98bf-461bb6a525bb is tainted: custom-ga-command
50458:2023-03-11 07:19:35.177+0000: 40739: debug : qemuDomainLogAppendMessage:6990 : Append log message (vm='vm1' message='2023-03-11 07:19:35.177+0000: Domain id=1 is tainted: custom-ga-command
51437:2023-03-11 07:20:07.119+0000: 40741: warning : qemuDomainObjTaintMsg:6618 : Domain id=1 name='vm1' uuid=479df013-c11c-4109-98bf-461bb6a525bb is tainted: custom-ga-command
51439:2023-03-11 07:20:07.119+0000: 40741: debug : qemuDomainLogAppendMessage:6990 : Append log message (vm='vm1' message='2023-03-11 07:20:07.119+0000: Domain id=1 is tainted: custom-ga-command
52418:2023-03-11 07:20:21.750+0000: 40742: warning : qemuDomainObjTaintMsg:6618 : Domain id=1 name='vm1' uuid=479df013-c11c-4109-98bf-461bb6a525bb is tainted: custom-ga-command
52420:2023-03-11 07:20:21.750+0000: 40742: debug : qemuDomainLogAppendMessage:6990 : Append log message (vm='vm1' message='2023-03-11 07:20:21.750+0000: Domain id=1 is tainted: custom-ga-command
53399:2023-03-11 07:20:26.791+0000: 40743: warning : qemuDomainObjTaintMsg:6618 : Domain id=1 name='vm1' uuid=479df013-c11c-4109-98bf-461bb6a525bb is tainted: custom-ga-command
53401:2023-03-11 07:20:26.791+0000: 40743: debug : qemuDomainLogAppendMessage:6990 : Append log message (vm='vm1' message='2023-03-11 07:20:26.791+0000: Domain id=1 is tainted: custom-ga-command

(logs being spammed)

Comment 9 Lili Zhu 2023-03-11 07:56:27 UTC
Verify this bug with:
libvirt-9.0.0-8.el9_2.x86_64

1. prepare a guest with guest agent
# virsh domtime vm1
Time: 1678521142

2. check the some info about guest using qemu-agent-command
# virsh qemu-agent-command vm1 '{"execute":"guest-get-fsinfo"}'
{"return":[{"name":"vda1","total-bytes":627875840,...

3.check the log
# grep -ni tainted /var/log/libvirt/libvirtd.log 
549:2023-03-11 07:52:36.284+0000: 42237: warning : qemuDomainObjTaintMsg:6618 : Domain id=1 name='vm1' uuid=2fa63f27-2c87-4125-beaf-46d5d087c4e3 is tainted: custom-ga-command
551:2023-03-11 07:52:36.284+0000: 42237: debug : qemuDomainLogAppendMessage:6990 : Append log message (vm='vm1' message='2023-03-11 07:52:36.284+0000: Domain id=1 is tainted: custom-ga-command

4. repeat step 2 for 100 times
# for i in {1..100}; do virsh qemu-agent-command vm1 '{"execute":"guest-get-fsinfo"}'; done
....

5. check the log
# grep -ni tainted /var/log/libvirt/libvirtd.log 
549:2023-03-11 07:52:36.284+0000: 42237: warning : qemuDomainObjTaintMsg:6618 : Domain id=1 name='vm1' uuid=2fa63f27-2c87-4125-beaf-46d5d087c4e3 is tainted: custom-ga-command
551:2023-03-11 07:52:36.284+0000: 42237: debug : qemuDomainLogAppendMessage:6990 : Append log message (vm='vm1' message='2023-03-11 07:52:36.284+0000: Domain id=1 is tainted: custom-ga-command

(no new logs about tainted messages, logs are not spammed)

Comment 12 Lili Zhu 2023-03-23 03:18:24 UTC
According to Comment #9, mark the bug as verified.

Comment 14 errata-xmlrpc 2023-05-09 07:27:59 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (libvirt bug fix and enhancement update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2023:2171