Bug 1415050 - virt-who will show many redundant debug info in rhsm log when migrate/start/stop vm on xen host
Summary: virt-who will show many redundant debug info in rhsm log when migrate/start/s...
Keywords:
Status: CLOSED WONTFIX
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: virt-who
Version: 7.0
Hardware: x86_64
OS: Linux
medium
low
Target Milestone: pre-dev-freeze
: ---
Assignee: Chris Snyder
QA Contact: Eko
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-01-20 06:02 UTC by Liushihui
Modified: 2019-10-28 07:21 UTC (History)
7 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2018-06-13 15:13:46 UTC
Target Upstream Version:


Attachments (Terms of Use)

Description Liushihui 2017-01-20 06:02:35 UTC
Description of problem:
It will show many redundant debug info in rhsm log at the same time  if migrate/add/delete guest on xen host.

Version-Release number of selected component (if applicable):
virt-who-0.17-10.el7sat.noarch
subscription-manager-1.17.15-1.el7.x86_64
python-rhsm-1.17.9-1.el7.x86_64
Satellite6.2.7-sp2.0

How reproducible:
Always

Steps to Reproduce:
1. Register system to satellite6.2.7
2. Configure virt-who run at xen mode and restart virt-who service ,virt-who send xen mapping info to satellite successfully.
3. On xenserver, migrate vm from xen host1 to xen host2, check virt-who's log in rhsm.log

Actual results:
It will show many redundant debug info in rhsm.log. please see detail info as the following:

==================The first time=======================
2017-01-20 00:44:21,866 [virtwho.env_cmdline DEBUG] Xen-1(25705):MainThread @xen.py:getHostGuestMapping:80 - Control Domain 7a20400e-06ed-4b90-93e8-5f8a2f415ac9 is ignored
2017-01-20 00:44:21,930 [virtwho.env_cmdline DEBUG] Xen-1(25705):MainThread @xen.py:getHostGuestMapping:80 - Control Domain b8b4312d-d70a-4709-8c7a-5500e746432f is ignored
2017-01-20 00:44:21,930 [virtwho.env_cmdline DEBUG] Xen-1(25705):MainThread @virt.py:enqueue:357 - Report for config "env/cmdline" gathered, putting to queue for sending
2017-01-20 00:44:21,934 [virtwho.main DEBUG] MainProcess(25698):MainThread @subscriptionmanager.py:_connect:123 - Authenticating with certificate: /etc/pki/consumer/cert.pem

==================The second time=======================
2017-01-20 00:44:22,031 [virtwho.env_cmdline DEBUG] Xen-1(25705):MainThread @xen.py:getHostGuestMapping:80 - Control Domain 7a20400e-06ed-4b90-93e8-5f8a2f415ac9 is ignored
2017-01-20 00:44:22,095 [virtwho.env_cmdline DEBUG] Xen-1(25705):MainThread @xen.py:getHostGuestMapping:80 - Control Domain b8b4312d-d70a-4709-8c7a-5500e746432f is ignored
2017-01-20 00:44:22,095 [virtwho.env_cmdline DEBUG] Xen-1(25705):MainThread @virt.py:enqueue:357 - Report for config "env/cmdline" gathered, putting to queue for sending

==================The third time=======================
2017-01-20 00:44:22,168 [virtwho.env_cmdline DEBUG] Xen-1(25705):MainThread @xen.py:getHostGuestMapping:80 - Control Domain 7a20400e-06ed-4b90-93e8-5f8a2f415ac9 is ignored
2017-01-20 00:44:22,231 [virtwho.env_cmdline DEBUG] Xen-1(25705):MainThread @xen.py:getHostGuestMapping:80 - Control Domain b8b4312d-d70a-4709-8c7a-5500e746432f is ignored
2017-01-20 00:44:22,231 [virtwho.env_cmdline DEBUG] Xen-1(25705):MainThread @virt.py:enqueue:357 - Report for config "env/cmdline" gathered, putting to queue for sending

==================The fourth time=======================
2017-01-20 00:44:22,297 [virtwho.env_cmdline DEBUG] Xen-1(25705):MainThread @xen.py:getHostGuestMapping:80 - Control Domain 7a20400e-06ed-4b90-93e8-5f8a2f415ac9 is ignored
2017-01-20 00:44:22,363 [virtwho.env_cmdline DEBUG] Xen-1(25705):MainThread @xen.py:getHostGuestMapping:80 - Control Domain b8b4312d-d70a-4709-8c7a-5500e746432f is ignored
2017-01-20 00:44:22,363 [virtwho.env_cmdline DEBUG] Xen-1(25705):MainThread @virt.py:enqueue:357 - Report for config "env/cmdline" gathered, putting to queue for sending

==================The fifth time=======================
2017-01-20 00:44:22,876 [virtwho.env_cmdline DEBUG] Xen-1(25705):MainThread @xen.py:getHostGuestMapping:80 - Control Domain 7a20400e-06ed-4b90-93e8-5f8a2f415ac9 is ignored
2017-01-20 00:44:22,965 [virtwho.env_cmdline DEBUG] Xen-1(25705):MainThread @xen.py:getHostGuestMapping:80 - Control Domain b8b4312d-d70a-4709-8c7a-5500e746432f is ignored
2017-01-20 00:44:22,965 [virtwho.env_cmdline DEBUG] Xen-1(25705):MainThread @virt.py:enqueue:357 - Report for config "env/cmdline" gathered, putting to queue for sending

==================The sixth time=======================
2017-01-20 00:44:23,030 [virtwho.env_cmdline DEBUG] Xen-1(25705):MainThread @xen.py:getHostGuestMapping:80 - Control Domain 7a20400e-06ed-4b90-93e8-5f8a2f415ac9 is ignored
2017-01-20 00:44:23,090 [virtwho.env_cmdline DEBUG] Xen-1(25705):MainThread @xen.py:getHostGuestMapping:80 - Control Domain b8b4312d-d70a-4709-8c7a-5500e746432f is ignored
2017-01-20 00:44:23,091 [virtwho.env_cmdline DEBUG] Xen-1(25705):MainThread @virt.py:enqueue:357 - Report for config "env/cmdline" gathered, putting to queue for sending

==================The seventh time=======================
2017-01-20 00:44:23,162 [virtwho.env_cmdline DEBUG] Xen-1(25705):MainThread @xen.py:getHostGuestMapping:80 - Control Domain 7a20400e-06ed-4b90-93e8-5f8a2f415ac9 is ignored
2017-01-20 00:44:23,228 [virtwho.env_cmdline DEBUG] Xen-1(25705):MainThread @xen.py:getHostGuestMapping:80 - Control Domain b8b4312d-d70a-4709-8c7a-5500e746432f is ignored
2017-01-20 00:44:23,228 [virtwho.env_cmdline DEBUG] Xen-1(25705):MainThread @virt.py:enqueue:357 - Report for config "env/cmdline" gathered, putting to queue for sending

==================The eighth time=======================
2017-01-20 00:44:24,073 [virtwho.env_cmdline DEBUG] Xen-1(25705):MainThread @xen.py:getHostGuestMapping:80 - Control Domain 7a20400e-06ed-4b90-93e8-5f8a2f415ac9 is ignored
2017-01-20 00:44:24,133 [virtwho.env_cmdline DEBUG] Xen-1(25705):MainThread @xen.py:getHostGuestMapping:80 - Control Domain b8b4312d-d70a-4709-8c7a-5500e746432f is ignored
2017-01-20 00:44:24,133 [virtwho.env_cmdline DEBUG] Xen-1(25705):MainThread @virt.py:enqueue:357 - Report for config "env/cmdline" gathered, putting to queue for sending
2017-01-20 00:44:24,280 [virtwho.main DEBUG] MainProcess(25698):MainThread @subscriptionmanager.py:hypervisorCheckIn:171 - Checking if server has capability 'hypervisor_async'
2017-01-20 00:44:26,621 [virtwho.main DEBUG] MainProcess(25698):MainThread @subscriptionmanager.py:hypervisorCheckIn:183 - Server does not have 'hypervisors_async' capability
2017-01-20 00:44:26,621 [virtwho.main INFO] MainProcess(25698):MainThread @subscriptionmanager.py:hypervisorCheckIn:194 - Sending update in hosts-to-guests mapping for config "env/cmdline": 2 hypervisors and 2 guests found
2017-01-20 00:44:26,621 [virtwho.main DEBUG] MainProcess(25698):MainThread @subscriptionmanager.py:hypervisorCheckIn:195 - Host-to-guest mapping: {
    "a8eb67c5-4a34-4596-995f-4a2fac7bf626": [
        {
            "guestId": "267cea79-3d51-2569-fb40-05b60466009a", 
            "state": 1, 
            "attributes": {
                "active": 1, 
                "virtWhoType": "xen"
            }
        }, 
        {
            "guestId": "c8351dab-dae9-4e48-137a-8eb5f2998758", 
            "state": 1, 
            "attributes": {
                "active": 1, 
                "virtWhoType": "xen"
            }
        }
    ], 
    "7f35e72b-d43b-45b7-b562-152e751b5262": []
}
2017-01-20 00:44:30,649 [virtwho.main DEBUG] MainProcess(25698):MainThread @executor.py:send_report:101 - Report for config "env/cmdline" sent


====================These info are also redundant=====================
2017-01-20 00:44:30,650 [virtwho.main INFO] MainProcess(25698):MainThread @executor.py:run:250 - Report for config "env/cmdline" hasn't changed, not sending
2017-01-20 00:44:30,650 [virtwho.main INFO] MainProcess(25698):MainThread @executor.py:run:250 - Report for config "env/cmdline" hasn't changed, not sending
2017-01-20 00:44:30,651 [virtwho.main INFO] MainProcess(25698):MainThread @executor.py:run:250 - Report for config "env/cmdline" hasn't changed, not sending
2017-01-20 00:44:30,652 [virtwho.main INFO] MainProcess(25698):MainThread @executor.py:run:250 - Report for config "env/cmdline" hasn't changed, not sending
2017-01-20 00:44:30,653 [virtwho.main INFO] MainProcess(25698):MainThread @executor.py:run:250 - Report for config "env/cmdline" hasn't changed, not sending
2017-01-20 00:44:30,653 [virtwho.main INFO] MainProcess(25698):MainThread @executor.py:run:250 - Report for config "env/cmdline" hasn't changed, not sending
2017-01-20 00:44:30,654 [virtwho.main INFO] MainProcess(25698):MainThread @executor.py:run:250 - Report for config "env/cmdline" hasn't changed, not sending

Expected results:
It should show the debug info once when there is updating on xen host.

Additional info:
It hasn't this problem on rhevm/esx mode.

Comment 2 yuefliu 2017-01-23 08:20:24 UTC
For kvm mode:
when migrate or add vm to rhel6.9 kvm host, virt-who also will show redundant debug info in rhsm log, like below:

***rhsm.log***
2017-01-23 03:13:39,891 [virtwho.env_cmdline DEBUG] Libvirtd-1(3065):libvirtEventLoop @libvirtd.py:_listDomains:271 - Libvirt domains found: 5a008ae6-0089-ce1c-cd75-25c4f1c5fe95, 5dec7221-310a-1a1f-96f2-de68f1cd0ee6
2017-01-23 03:13:39,891 [virtwho.env_cmdline DEBUG] Libvirtd-1(3065):libvirtEventLoop @virt.py:enqueue:356 - Report for config "env/cmdline" gathered, putting to queue for sending
2017-01-23 03:13:40,462 [virtwho.env_cmdline DEBUG] Libvirtd-1(3065):libvirtEventLoop @libvirtd.py:_listDomains:271 - Libvirt domains found: 5a008ae6-0089-ce1c-cd75-25c4f1c5fe95, 5dec7221-310a-1a1f-96f2-de68f1cd0ee6
2017-01-23 03:13:40,463 [virtwho.env_cmdline DEBUG] Libvirtd-1(3065):libvirtEventLoop @virt.py:enqueue:356 - Report for config "env/cmdline" gathered, putting to queue for sending

Comment 5 yuefliu 2017-02-15 02:46:02 UTC
add to comment 2:
for kvm mode, when pause/resume vm on rhel6.9, virt-who also will show redundant debug info in rhsm log, like below:

*******rhsm.log*****
2017-02-14 21:45:11,047 [virtwho.sate-libvirt DEBUG] Libvirtd-1(1074):libvirtEventLoop @libvirtd.py:_listDomains:271 - Libvirt domains found: d2896382-cfba-9c66-c3b3-92fc2b470667, d56d91c1-1848-32a9-ac46-c6e05009bd98, dee244af-fe27-9172-5d47-594c1c029072
2017-02-14 21:45:11,047 [virtwho.sate-libvirt DEBUG] Libvirtd-1(1074):libvirtEventLoop @virt.py:enqueue:356 - Report for config "sate-libvirt" gathered, putting to queue for sending
2017-02-14 21:45:11,053 [virtwho.sate-libvirt DEBUG] Libvirtd-1(1074):libvirtEventLoop @libvirtd.py:_listDomains:271 - Libvirt domains found: d2896382-cfba-9c66-c3b3-92fc2b470667, d56d91c1-1848-32a9-ac46-c6e05009bd98, dee244af-fe27-9172-5d47-594c1c029072
2017-02-14 21:45:11,053 [virtwho.sate-libvirt DEBUG] Libvirtd-1(1074):libvirtEventLoop @virt.py:enqueue:356 - Report for config "sate-libvirt" gathered, putting to queue for sending

Comment 6 yuefliu 2017-04-06 08:32:30 UTC
the bug still exists on RHEL-7.4-20170330.n.1 with xen and kvm mode.

package:
virt-who-0.19-2.el7.noarch
subscription-manager-1.19.4-1.el7.x86_64
python-rhsm-1.19.2-1.el7.x86_64

Comment 8 Kevin Howell 2018-06-13 15:13:46 UTC
Given that the logging is at debug level, we want to keep as-is. Closing wontfix.


Note You need to log in before you can comment on or make changes to this bug.