Bug 1362351

Summary: Virt-who can't detect unregistered system until 90s when it work at xen mode
Product: Red Hat Enterprise Linux 7 Reporter: Liushihui <shihliu>
Component: virt-whoAssignee: Radek Novacek <rnovacek>
Status: CLOSED ERRATA QA Contact: Eko <hsun>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 7.3CC: ldai, ovasik, sgao
Target Milestone: rc   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: virt-who-0.17-8.el7 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-11-04 05:10:23 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:

Description Liushihui 2016-08-02 03:23:28 UTC
Description of problem:
When virt-who run at xen mode, although system has been unregistered, virt-who can't detect system has been unregistered in the rhsm.log and virt-who processes which PPID is not 1 can not be killed until 90s

Version-Release number of selected component (if applicable):
virt-who-0.17-7.el7.noarch
subscription-manager-1.17.9-1.el7.x86_64
python-rhsm-1.17.5-1.el7.x86_64

How reproducible:
Always

Steps to Reproduce:
1. Register system to Satellite6. make virt-who run at xen mode, refresh interval is default.
[root@hp-z220-05 ~]# subscription-manager  register --username=admin --password=admin
Registering to: ent-02-vm-04.lab.eng.nay.redhat.com:443/rhsm
The system has been registered with ID: 6fb49c5c-e2e9-4b50-9f54-4ea4ba353ba0
[root@hp-z220-05 ~]# cat /etc/sysconfig/virt-who  | grep -v ^# | grep -v ^$
VIRTWHO_DEBUG=1
VIRTWHO_XEN=1
VIRTWHO_XEN_OWNER=ACME_Corporation
VIRTWHO_XEN_ENV=Library
VIRTWHO_XEN_SERVER=10.73.5.210
VIRTWHO_XEN_USERNAME=root
VIRTWHO_XEN_PASSWORD=Welcome1

2. Start virt-who service, virt-who send h/g mapping to server successfully.
[root@hp-z220-05 ~]# systemctl restart virt-who
[root@hp-z220-05 ~]# ps -ef|grep virt-who
root     14224     1  0 23:04 ?        00:00:00 /usr/bin/python2 /usr/bin/virt-who
root     14291 14224  1 23:08 ?        00:00:00 /usr/bin/python2 /usr/bin/virt-who
root     14302 13965  0 23:08 pts/0    00:00:00 grep --color=auto virt-who

3. Unregister system. check virt-who's log and threads.
[root@hp-z220-05 ~]# ps -ef|grep virt-who
root     14224     1  0 23:04 ?        00:00:00 /usr/bin/python2 /usr/bin/virt-who
root     14291 14224  1 23:08 ?        00:00:00 /usr/bin/python2 /usr/bin/virt-who
root     14302 13965  0 23:08 pts/0    00:00:00 grep --color=auto virt-who

[root@hp-z220-05 ~]# tail -f /var/log/rhsm/rhsm.log
2016-08-01 23:08:38,798 [INFO] subscription-manager:14303 @managercli.py:384 - Client Versions: {'python-rhsm': '1.17.5-1.el7', 'subscription-manager': '1.17.9-1.el7'}
2016-08-01 23:08:38,798 [INFO] subscription-manager:14303 @connection.py:830 - Connection built: host=ent-02-vm-04.lab.eng.nay.redhat.com port=443 handler=/rhsm auth=identity_cert ca_dir=/etc/rhsm/ca/ verify=False
2016-08-01 23:08:38,799 [INFO] subscription-manager:14303 @connection.py:830 - Connection built: host=ent-02-vm-04.lab.eng.nay.redhat.com port=443 handler=/rhsm auth=none
2016-08-01 23:08:38,799 [INFO] subscription-manager:14303 @managercli.py:359 - Consumer Identity name=hp-z220-05.qe.lab.eng.nay.redhat.com uuid=6fb49c5c-e2e9-4b50-9f54-4ea4ba353ba0
2016-08-01 23:08:42,922 [INFO] subscription-manager:14303 @managerlib.py:793 - Successfully un-registered.
2016-08-01 23:08:42,923 [INFO] subscription-manager:14303 @managerlib.py:879 - Cleaned local data
2016-08-01 23:08:42,924 [INFO] subscription-manager:14303 @entcertlib.py:131 - certs updated:
Total updates: 0
Found (local) serial# []
Expected (UEP) serial# []
Added (new)
  <NONE>
Deleted (rogue):
  <NONE>
2016-08-01 23:08:42,926 [INFO] subscription-manager:14303 @repolib.py:303 - repos updated: Repo updates

Total repo updates: 0
Updated
    <NONE>
Added (new)
    <NONE>
Deleted
    <NONE>
2016-08-01 23:08:43,030 [INFO] rhsmd:14305 @rhsmd:232 - rhsmd started
2016-08-01 23:08:43,069 [virtwho.main WARNING] MainProcess(14224):MainThread @executor.py:reload:326 - virt-who reload

2016-08-01 23:09:13,984 [virtwho.env_cmdline DEBUG] Xen-3(14291):MainThread @xen.py:getHostGuestMapping:80 - Control Domain 0e57a500-1ff6-464e-b863-fd8ee93f2738 is ignored
2016-08-01 23:09:13,986 [virtwho.main INFO] MainProcess(14224):MainThread @main.py:main:180 - Reloading
2016-08-01 23:09:13,986 [virtwho.main DEBUG] MainProcess(14224):MainThread @executor.py:run:171 - Starting infinite loop with 60 seconds interval
2016-08-01 23:09:13,988 [virtwho.env_cmdline DEBUG] Xen-4(14308):MainThread @virt.py:run:364 - Virt backend 'env/cmdline' started
2016-08-01 23:09:13,988 [virtwho.env_cmdline DEBUG] Xen-4(14308):MainThread @xen.py:_prepare:42 - Logging into XEN pools https://10.73.5.210
2016-08-01 23:09:14,065 [virtwho.env_cmdline DEBUG] Xen-4(14308):MainThread @xen.py:login:52 - XEN pool login successful with user root
2016-08-01 23:09:14,555 [virtwho.env_cmdline DEBUG] Xen-4(14308):MainThread @xen.py:getHostGuestMapping:80 - Control Domain 0e57a500-1ff6-464e-b863-fd8ee93f2738 is ignored
2016-08-01 23:09:14,555 [virtwho.env_cmdline DEBUG] Xen-4(14308):MainThread @virt.py:enqueue:357 - Report for config "env/cmdline" gathered, putting to queue for sending
2016-08-01 23:09:14,558 [virtwho.main DEBUG] MainProcess(14224):MainThread @subscriptionmanager.py:_connect:123 - Authenticating with certificate: /etc/pki/consumer/cert.pem

=============================================================================
========After about 90s, it will show "system is not registered "===
=============================================================================

2016-08-01 23:10:15,200 [virtwho.env_cmdline DEBUG] Xen-4(14308):MainThread @xen.py:getHostGuestMapping:80 - Control Domain 0e57a500-1ff6-464e-b863-fd8ee93f2738 is ignored
2016-08-01 23:10:15,202 [virtwho.main ERROR] MainProcess(14224):MainThread @main.py:_main:189 - Fatal error:
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/virtwho/main.py", line 186, in _main
    result = executor.run()
  File "/usr/lib/python2.7/site-packages/virtwho/executor.py", line 256, in run
    self.send_report(report.config.name, report)
  File "/usr/lib/python2.7/site-packages/virtwho/executor.py", line 95, in send_report
    if self.send(report):
  File "/usr/lib/python2.7/site-packages/virtwho/executor.py", line 139, in send
    self._sendGuestAssociation(report)
  File "/usr/lib/python2.7/site-packages/virtwho/executor.py", line 166, in _sendGuestAssociation
    manager.hypervisorCheckIn(report, self.options)
  File "/usr/lib/python2.7/site-packages/virtwho/manager/subscriptionmanager/subscriptionmanager.py", line 170, in hypervisorCheckIn
    self._connect(report.config)
  File "/usr/lib/python2.7/site-packages/virtwho/manager/subscriptionmanager/subscriptionmanager.py", line 126, in _connect
    "Unable to read certificate, system is not registered or you are not root")
SubscriptionManagerUnregisteredError: Unable to read certificate, system is not registered or you are not root
2016-08-01 23:10:15,202 [virtwho.main INFO] MainProcess(14224):MainThread @main.py:_main:191 - Waiting for reload signal

Actual results:
It still show two virt-who threads after unregister system.
It can't show system is unregistered until about 90s.

Expected results:
It should keep only one virt-who(PPID=1) process after unregister system. system has been unregistered should be shown on rhsm log immediately.

Additional info:
It hasn't this problem

Comment 1 Liushihui 2016-08-02 03:24:32 UTC
Additional info:
It hasn't this problem when virt-who work at hyperv and esx mode

Comment 3 Radek Novacek 2016-08-11 14:27:38 UTC
Fixed in virt-who-0.17-8.el7.

Comment 5 Liushihui 2016-08-16 08:41:59 UTC
Verified it on virt-who-0.17-8.el7 since virt-who(!PPID=1) process is disappeared and "system has been unregistered" info will show immediately after unregister system. Therefore, verify it.

Comment 7 errata-xmlrpc 2016-11-04 05:10:23 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, 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://rhn.redhat.com/errata/RHBA-2016-2387.html