Bug 993822

Summary: Can't get the host/guest association in the HYPER-V mode
Product: Red Hat Enterprise Linux 5 Reporter: Liushihui <shihliu>
Component: virt-whoAssignee: Radek Novacek <rnovacek>
Status: CLOSED ERRATA QA Contact: Entitlement Bugs <entitlement-bugs>
Severity: urgent Docs Contact:
Priority: unspecified    
Version: 5.10CC: liliu, ovasik, rnovacek, sgao
Target Milestone: rc   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: virt-who-0.9-1.el5 Doc Type: Bug Fix
Doc Text:
no docs needed
Story Points: ---
Clone Of: Environment:
Last Closed: 2014-09-16 00:29:20 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 2013-08-06 12:23:03 UTC
Description of problem:
Can't get the host/guest association in the HYPER-V  mode after host has registered to SAM server.

Version-Release number of selected component (if applicable):
virt-who-0.8-6.el5
RHEL5.10-Server-20130731.6(snapshot3)

How reproducible:
Always

Steps to Reproduce:
1.Configure virt-who
#vim /etc/sysconfig/virt-who, Update as the following:
VIRTWHO_DEBUG=1
VIRTWHO_INTERVAL=5
VIRTWHO_HYPERV=1

VIRTWHO_HYPERV_OWNER=ACME_Corporation
VIRTWHO_HYPERV_ENV=Library
VIRTWHO_HYPERV_SERVER=10.66.13.22
VIRTWHO_HYPERV_USERNAME=administrator
VIRTWHO_HYPERV_PASSWORD=qwer1234P
2.Register to SAM server
#subscription-manager register --username=admin --password=admin
3.Monitor the rhsm.log file
#tail -f /var/log/rhsm/rhsm.log
4.Restart virt-who service
# service virt-who restart
5 Check the rhsm.log in the step3

Actual results:
Can't get the host/guest association log , see the log as the following:
2013-08-06 08:11:55,767 [DEBUG]  @hyperv.py:165 - Hyper-V url: http://10.66.13.22:5985/wsman
2013-08-06 08:11:55,768 [DEBUG]  @hyperv.py:215 - Using NTLM authentication
2013-08-06 08:11:55,770 [ERROR]  @virt-who.py:189 - Unable to recover, retry in 5 seconds.
2013-08-06 08:11:55,835 [DEBUG]  @injection.py:54 - Registering provider for feature IDENTITY: <class 'subscription_manager.identity.Identity'>
2013-08-06 08:11:55,835 [DEBUG]  @injection.py:54 - Registering provider for feature PRODUCT_DATE_RANGE_CALCULATOR: <function factory at 0x24a3488>
2013-08-06 08:11:55,835 [DEBUG]  @injection.py:54 - Registering provider for feature ENT_DIR: <class 'subscription_manager.certdirectory.EntitlementDirectory'>
2013-08-06 08:11:55,835 [DEBUG]  @injection.py:54 - Registering provider for feature PROD_DIR: <class 'subscription_manager.certdirectory.ProductDirectory'>
2013-08-06 08:11:55,835 [DEBUG]  @injection.py:54 - Registering provider for feature STATUS_CACHE: <class 'subscription_manager.cache.StatusCache'>
2013-08-06 08:11:55,836 [DEBUG]  @injection.py:54 - Registering provider for feature PROD_STATUS_CACHE: <class 'subscription_manager.cache.ProductStatusCache'>
2013-08-06 08:11:55,836 [DEBUG]  @injection.py:54 - Registering provider for feature CP_PROVIDER: <class 'subscription_manager.cp_provider.CPProvider'>
2013-08-06 08:11:55,836 [DEBUG]  @injection.py:54 - Registering provider for feature CERT_SORTER: <class 'subscription_manager.cert_sorter.CertSorter'>
2013-08-06 08:11:55,836 [DEBUG]  @injection.py:54 - Registering provider for feature PLUGIN_MANAGER: <class 'subscription_manager.plugins.PluginManager'>
2013-08-06 08:11:55,836 [DEBUG]  @injection.py:54 - Registering provider for feature DBUS_IFACE: <class 'subscription_manager.dbus_interface.DbusIface'>
2013-08-06 08:11:55,838 [INFO]  @rhsmd:186 - rhsmd started
2013-08-06 08:11:55,842 [INFO]  @rhsmd:143 - D-Bus interface com.redhat.SubscriptionManager.EntitlementStatus.check_status called
2013-08-06 08:11:55,895 [DEBUG]  @injection.py:72 - Initializing singleton for feature CERT_SORTER
2013-08-06 08:11:55,895 [DEBUG]  @injection.py:72 - Initializing singleton for feature CP_PROVIDER
2013-08-06 08:11:55,896 [DEBUG]  @injection.py:80 - Returning instance for feature CP_PROVIDER
2013-08-06 08:11:55,896 [DEBUG]  @injection.py:72 - Initializing singleton for feature PROD_DIR
2013-08-06 08:11:55,896 [DEBUG]  @injection.py:80 - Returning instance for feature PROD_DIR
2013-08-06 08:11:55,896 [DEBUG]  @injection.py:72 - Initializing singleton for feature ENT_DIR
2013-08-06 08:11:55,896 [DEBUG]  @injection.py:80 - Returning instance for feature ENT_DIR
2013-08-06 08:11:55,896 [DEBUG]  @injection.py:72 - Initializing singleton for feature IDENTITY
2013-08-06 08:11:55,896 [DEBUG]  @identity.py:130 - Loading consumer info from identity certificates.
2013-08-06 08:11:55,897 [DEBUG]  @injection.py:80 - Returning instance for feature IDENTITY
2013-08-06 08:11:55,897 [DEBUG]  @injection.py:80 - Returning instance for feature PROD_DIR
2013-08-06 08:11:55,898 [DEBUG]  @profile.py:96 - Loading current RPM profile.
2013-08-06 08:11:55,993 [INFO]  @connection.py:583 - Using certificate authentication: key = /etc/pki/consumer/key.pem, cert = /etc/pki/consumer/cert.pem, ca = /etc/rhsm/ca/, insecure = False
2013-08-06 08:11:55,994 [INFO]  @connection.py:596 - Connection Built: host: samserv.redhat.com, port: 443, handler: /subscription
2013-08-06 08:11:55,994 [INFO]  @cache.py:165 - Checking current system info against cache: /var/lib/rhsm/cache/installed_products.json
2013-08-06 08:11:55,994 [INFO]  @cache.py:182 - No changes.
2013-08-06 08:11:55,994 [DEBUG]  @certdirectory.py:204 - Installed product IDs: ['69']
2013-08-06 08:11:55,994 [DEBUG]  @injection.py:72 - Initializing singleton for feature STATUS_CACHE
2013-08-06 08:11:55,994 [DEBUG]  @injection.py:80 - Returning instance for feature STATUS_CACHE
2013-08-06 08:11:55,995 [DEBUG]  @connection.py:394 - Loading CA PEM certificates from: /etc/rhsm/ca/
2013-08-06 08:11:55,995 [DEBUG]  @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem'
2013-08-06 08:11:55,995 [DEBUG]  @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem'
2013-08-06 08:11:55,995 [DEBUG]  @connection.py:376 - Loading CA certificate: '/etc/rhsm/ca/candlepin-local.pem'
2013-08-06 08:11:55,996 [DEBUG]  @connection.py:415 - Making request: GET /subscription/consumers/c26f3050-7939-496b-8d56-f14d629b2512/compliance
2013-08-06 08:11:56,172 [DEBUG]  @connection.py:434 - Response status: 200
2013-08-06 08:11:56,174 [DEBUG]  @cache.py:138 - Wrote cache: /var/lib/rhsm/cache/entitlement_status.json
2013-08-06 08:11:56,175 [DEBUG]  @cert_sorter.py:254 - valid entitled products: []
2013-08-06 08:11:56,175 [DEBUG]  @cert_sorter.py:255 - expired entitled products: []
2013-08-06 08:11:56,175 [DEBUG]  @cert_sorter.py:256 - partially entitled products: []
2013-08-06 08:11:56,175 [DEBUG]  @cert_sorter.py:257 - unentitled products: ['69']
2013-08-06 08:11:56,175 [DEBUG]  @cert_sorter.py:258 - future products: []
2013-08-06 08:11:56,176 [DEBUG]  @cert_sorter.py:259 - partial stacks: []
2013-08-06 08:11:56,176 [DEBUG]  @cert_sorter.py:260 - entitlements valid until: 2013-08-06 12:10:50.109999+00:00
2013-08-06 08:11:56,176 [DEBUG]  @injection.py:80 - Returning instance for feature CERT_SORTER
2013-08-06 08:11:56,176 [INFO]  @rhsmd:126 - D-Bus signal com.redhat.SubscriptionManager.EntitlementStatus.entitlement_status_changed emitted
2013-08-06 08:12:00,771 [DEBUG]  @hyperv.py:165 - Hyper-V url: http://10.66.13.22:5985/wsman
2013-08-06 08:12:00,773 [DEBUG]  @hyperv.py:215 - Using NTLM authentication
2013-08-06 08:12:00,776 [ERROR]  @virt-who.py:186 - Error in communication with virt backend, trying to recover:
Traceback (most recent call last):
  File "/usr/share/virt-who/virt-who.py", line 180, in _send
    virtualGuests = self.virt.getHostGuestMapping()
  File "/usr/share/virt-who/hyperv.py", line 267, in getHostGuestMapping
    connection, headers = self.connect()
  File "/usr/share/virt-who/hyperv.py", line 202, in connect
    self.ntlmAuth(connection, headers)
  File "/usr/share/virt-who/hyperv.py", line 235, in ntlmAuth
    headers["Authorization"] = "Negotiate %s" % ntlm.create_NTLM_AUTHENTICATE_MESSAGE(nonce, self.username, self.domainname, self.password, flags)
  File "/usr/share/virt-who/ntlm.py", line 316, in create_NTLM_AUTHENTICATE_MESSAGE
    NtChallengeResponse = calc_resp(create_NT_hashed_password_v1(password), nonce)
  File "/usr/share/virt-who/ntlm.py", line 434, in create_NT_hashed_password_v1
    digest = hashlib.new('md4', passwd.encode('utf-16le')).digest()
  File "/usr/lib64/python2.4/site-packages/hashlib.py", line 87, in __py_new
    return __get_builtin_constructor(name)(string)
  File "/usr/lib64/python2.4/site-packages/hashlib.py", line 80, in __get_builtin_constructor
    raise ValueError, "unsupported hash type"
ValueError: unsupported hash type


Expected results:
It should get the correct host/guest association log in the rhsm.log

Additional info:
It hasn't this problem under the ESX mode and Rhevm mode

Comment 1 Radek Novacek 2013-08-07 08:34:35 UTC
It seems that python-hashlib in RHEL-5 is missing the MD4 hashing algorithm. It's possible to workaround this issue by using MD4 from openssl.

Comment 2 RHEL Program Management 2014-01-22 16:28:09 UTC
This request was evaluated by Red Hat Product Management for inclusion
in a Red Hat Enterprise Linux release.  Product Management has
requested further review of this request by Red Hat Engineering, for
potential inclusion in a Red Hat Enterprise Linux release for currently
deployed products.  This request is not yet committed for inclusion in
a release.

Comment 3 Radek Novacek 2014-03-13 13:40:29 UTC
Fixed in virt-who-0.9-1.el5.

Comment 5 Liushihui 2014-04-24 08:46:08 UTC
Verified it on virt-who-0.9-2.el5

Verified steps:
1.Configure virt-who
#vim /etc/sysconfig/virt-who, Update as the following:
VIRTWHO_DEBUG=1
VIRTWHO_INTERVAL=5
VIRTWHO_HYPERV=1

VIRTWHO_HYPERV_OWNER=ACME_Corporation
VIRTWHO_HYPERV_ENV=Library
VIRTWHO_HYPERV_SERVER=10.66.128.173
VIRTWHO_HYPERV_USERNAME=administrator
VIRTWHO_HYPERV_PASSWORD=qwer1234P
2.Register to SAM server
#subscription-manager register --username=admin --password=admin
3.Restart virt-who service
# service virt-who restart
4.Monitor the rhsm.log file, 
#tail -f /var/log/rhsm/rhsm.log

2014-04-24 03:32:53,067 [WARNING]  @virt-who.py:515 - Listening for events is not available in VDSM, ESX, RHEV-M or Hyper-V mode
2014-04-24 03:32:53,457 [DEBUG]  @hyperv.py:172 - Hyper-V url: http://10.66.128.173:5985/wsman
2014-04-24 03:32:53,457 [DEBUG]  @virt-who.py:528 - Virt-who is running in hyperv mode
2014-04-24 03:32:53,457 [DEBUG]  @virt-who.py:535 - Starting infinite loop with 5 seconds interval and event handling
2014-04-24 03:32:53,461 [DEBUG]  @hyperv.py:222 - Using NTLM authentication
2014-04-24 03:32:53,527 [DEBUG]  @hyperv.py:249 - NTLM authentication successful
2014-04-24 03:32:54,409 [DEBUG]  @subscriptionmanager.py:89 - Sending update in hosts-to-guests mapping: {'60D30E26-6409-0EA6-6C0E-0ED223510F02': ['A9204F8B-0312-DD4F-8286-819B6CA7E554']}
2014-04-24 03:33:08,414 [INFO]  @virt-who.py:217 - Created host: 4e44af87-e7f0-427e-b494-7116cfcd7a8d with guests: [A9204F8B-0312-DD4F-8286-819B6CA7E554]
2014-04-24 03:33:13,416 [DEBUG]  @hyperv.py:222 - Using NTLM authentication
2014-04-24 03:33:13,430 [DEBUG]  @hyperv.py:249 - NTLM authentication successful
2014-04-24 03:33:14,267 [DEBUG]  @subscriptionmanager.py:89 - Sending update in hosts-to-guests mapping: {'60D30E26-6409-0EA6-6C0E-0ED223510F02': ['A9204F8B-0312-DD4F-8286-819B6CA7E554']}

Result: virt-who send the right host/guest association to SAM server, Therefore, verify it on virt-who-0.9-2.el5.

Comment 7 errata-xmlrpc 2014-09-16 00:29:20 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.

http://rhn.redhat.com/errata/RHBA-2014-1206.html