1216278 – "Error in communication with subscription manager as BadStatusLine" when unregister system

RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.

Bug 1216278 - "Error in communication with subscription manager as BadStatusLine" when unregister system

Summary: "Error in communication with subscription manager as BadStatusLine" when unre...

Keywords:
Status:	CLOSED ERRATA
Alias:	None
Product:	Red Hat Enterprise Linux 6
Classification:	Red Hat
Component:	virt-who
Sub Component:
Version:	6.7
Hardware:	x86_64
OS:	Linux
Priority:	unspecified
Severity:	medium
Target Milestone:	rc
Target Release:	---
Assignee:	Radek Novacek
QA Contact:	xingge
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+	depends on / blocked

Reported:	2015-04-29 02:03 UTC by Liushihui
Modified:	2016-12-01 00:34 UTC (History)
CC List:	7 users (show)
Fixed In Version:	virt-who-0.16-1.el6
Doc Type:	Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed:	2016-05-10 23:55:01 UTC
Target Upstream Version:
Embargoed:

Attachments	(Terms of Use)

Links
System	ID	Private	Priority	Status	Summary	Last Updated
Red Hat Product Errata	RHEA-2016:0859	0	normal	SHIPPED_LIVE	virt-who bug fix and enhancement update	2016-05-10 22:44:47 UTC

Description Liushihui 2015-04-29 02:03:21 UTC

Description of problem:
During register system, virt-who will show error info when communication with subscription manager 

Version-Release number of selected component (if applicable):
subscription-manager-1.14.5-1.el6.x86_64
python-rhsm-1.14.2-1.el6.x86_64
virt-who-0.12-5.el6.noarch
candlepin-0.9.48-1.el7.noarch
katello-2.2.0.8-1.el7sat.noarch
foreman-1.7.2.17-1.el7sat.noarch
Satellite-6.1.0-20150424.0

How reproducible:
80%

Steps to Reproduce:
1.Register system to Satellite 
2.Configure virt-who run at libvirt mode and restart virt-who service
# vim /etc/sysconfig/virt-who
VIRTWHO_BACKGROUND=1
VIRTWHO_DEBUG=1
VIRTWHO_INTERVAL=5
[root@hp-z220-04 ~]# service virt-who restart
Stopping virt-who:                                         [  OK  ]
Starting virt-who:                                         [  OK  ]
3.Unreigster system and check the virt-who's log
[root@hp-z220-04 ~]# subscription-manager unregister
[root@hp-z220-04 ~]# tail -f /var/log/rhsm/rhsm.log
2015-04-29 09:42:19,521 [DEBUG] subscription-manager:16602 @utils.py:284 - Restarted virt-who
2015-04-29 09:42:19,521 [WARNING]  @virtwho.py:202 - virt-who reload
2015-04-29 09:42:19,522 [ERROR]  @virtwho.py:111 - Error in communication with subscription manager:
Traceback (most recent call last):
  File "/usr/share/virt-who/virtwho.py", line 102, in send
    self._sendGuestList(report)
  File "/usr/share/virt-who/virtwho.py", line 117, in _sendGuestList
    manager.sendVirtGuests(report.guests)
  File "/usr/share/virt-who/manager/subscriptionmanager/subscriptionmanager.py", line 120, in sendVirtGuests
    self.connection.updateConsumer(self.uuid(), guest_uuids=domains)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 839, in updateConsumer
    params['guestIds'] = self.sanitizeGuestIds(guest_uuids)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 883, in sanitizeGuestIds
    return [self.sanitizeGuestId(guestId) for guestId in guestIds or []]
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 889, in sanitizeGuestId
    if self.supports_resource('guestids'):
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 753, in supports_resource
    self._load_supported_resources()
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 740, in _load_supported_resources
    resources_list = self.conn.request_get("/")
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 602, in request_get
    return self._request("GET", method)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 512, in _request
    response = conn.getresponse()
  File "/usr/lib64/python2.6/httplib.py", line 1012, in getresponse
    response.begin()
  File "/usr/lib64/python2.6/httplib.py", line 404, in begin
    version, status, reason = self._read_status()
  File "/usr/lib64/python2.6/httplib.py", line 368, in _read_status
    raise BadStatusLine(line)
BadStatusLine

Actual results:
It will show some error log when virt-who communicate with subscription-manager

Expected results:
It should communicate with subscription-manager normally, it shouldn't show any error info.

Additional info:
It is easier to reproduce this problem after setting VIRTWHO_INTERVAL to a small value

Comment 2 Liushihui 2015-05-04 03:43:43 UTC

Sometimes, it will show the following two kinds of error info:
2015-05-04 11:26:14,117 [DEBUG] subscription-manager:16376 @utils.py:284 - Restarted virt-who
2015-05-04 11:26:14,117 [WARNING]  @virtwho.py:202 - virt-who reload
2015-05-04 11:26:21,318 [ERROR]  @virtwho.py:111 - Error in communication with subscription manager:
Traceback (most recent call last):
  File "/usr/share/virt-who/virtwho.py", line 104, in send
    self._sendGuestAssociation(report)
  File "/usr/share/virt-who/virtwho.py", line 121, in _sendGuestAssociation
    result = manager.hypervisorCheckIn(report.config, report.association, report.config.type)
  File "/usr/share/virt-who/manager/subscriptionmanager/subscriptionmanager.py", line 133, in hypervisorCheckIn
    return self.connection.hypervisorCheckIn(config.owner, config.env, mapping)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 815, in hypervisorCheckIn
    return self.conn.request_post(url, host_guest_mapping)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 605, in request_post
    return self._request("POST", method, params)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 530, in _request
    self.validateResponse(result, request_type, handler)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 572, in validateResponse
    raise RestlibException(response['status'], error_msg)
RestlibException: undefined method `admin?' for nil:NilClass


2015-05-04 11:30:11,304 [DEBUG] subscription-manager:16456 @utils.py:284 - Restarted virt-who
2015-05-04 11:30:11,304 [WARNING]  @virtwho.py:202 - virt-who reload
2015-05-04 11:30:11,307 [ERROR]  @virtwho.py:111 - Error in communication with subscription manager:
Traceback (most recent call last):
  File "/usr/share/virt-who/virtwho.py", line 104, in send
    self._sendGuestAssociation(report)
  File "/usr/share/virt-who/virtwho.py", line 121, in _sendGuestAssociation
    result = manager.hypervisorCheckIn(report.config, report.association, report.config.type)
  File "/usr/share/virt-who/manager/subscriptionmanager/subscriptionmanager.py", line 133, in hypervisorCheckIn
    return self.connection.hypervisorCheckIn(config.owner, config.env, mapping)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 815, in hypervisorCheckIn
    return self.conn.request_post(url, host_guest_mapping)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 605, in request_post
    return self._request("POST", method, params)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 514, in _request
    "content": response.read(),
  File "/usr/lib64/python2.6/httplib.py", line 538, in read
    return self._read_chunked(amt)
  File "/usr/lib64/python2.6/httplib.py", line 587, in _read_chunked
    value.append(self._safe_read(chunk_left))
  File "/usr/lib64/python2.6/httplib.py", line 641, in _safe_read
    raise IncompleteRead(''.join(s), amt)
IncompleteRead: IncompleteRead(0 bytes read, 7351 more expected)

Comment 3 Radek Novacek 2015-05-05 15:38:36 UTC

There are some improvements of the unregistration handling in the virt-who-0.12-7.el6. Could you please retry it with that version of virt-who?

Comment 4 Liushihui 2015-05-11 09:15:36 UTC

In the virt-who-0.12-7.el6, Unregister system to Satellite6.1.0, it will generate "error: [Errno 4] Interrupted system call" when reload virt-who. Meanwhile, it will generate too many "Error in communication with subscription manager" messages at the same time.
[NOTE]: It has not this problem when virt-who unregister to SAM 1.4.1 

2015-05-11 17:07:08,882 [ERROR]  @virtwho.py:115 - Error in communication with subscription manager:
Traceback (most recent call last):
  File "/usr/share/virt-who/virtwho.py", line 102, in send
    self._sendGuestList(report)
  File "/usr/share/virt-who/virtwho.py", line 121, in _sendGuestList
    manager.sendVirtGuests(report.guests)
  File "/usr/share/virt-who/manager/subscriptionmanager/subscriptionmanager.py", line 119, in sendVirtGuests
    self.connection.updateConsumer(self.uuid(), guest_uuids=domains)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 858, in updateConsumer
    ret = self.conn.request_put(method, params)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 611, in request_put
    return self._request("PUT", method, params)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 505, in _request
    conn.request(request_type, handler, body=body, headers=headers)
  File "/usr/lib64/python2.6/httplib.py", line 936, in request
    self._send_request(method, url, body, headers)
  File "/usr/lib64/python2.6/httplib.py", line 973, in _send_request
    self.endheaders()
  File "/usr/lib64/python2.6/httplib.py", line 930, in endheaders
    self._send_output()
  File "/usr/lib64/python2.6/httplib.py", line 802, in _send_output
    self.send(msg)
  File "/usr/lib64/python2.6/httplib.py", line 761, in send
    self.connect()
  File "/usr/lib64/python2.6/site-packages/M2Crypto/httpslib.py", line 73, in connect
    raise error
error: [Errno 4] Interrupted system call

Test version:
virt-who-0.12-7.el6.noarch
subscription-manager-1.14.6-1.el6.x86_64
python-rhsm-1.14.2-1.el6.x86_64
candlepin-0.9.49.0-1.el7.noarch
katello-2.2.0.8-1.el7sat.noarch
foreman-1.7.2.19-1.el7sat.noarch

Comment 5 Liushihui 2015-05-12 08:49:02 UTC

It is easier to reproduce it when virt-who refresh too frequently . For example. setting VIRTWHO_INTERVAL= 5 is easier to reproduce it than setting VIRTWHO_INTERVAL= 30

Comment 6 Radek Novacek 2015-05-14 08:57:55 UTC

I can't reproduce it, but I think I made a workaround (catching that exception - it only occurs when virt-who gets the SIGHUP signal from subscription-manager).

Comment 7 Radek Novacek 2015-05-14 12:34:11 UTC

Fixed in virt-who-0.12-8.el6.

Comment 9 Liushihui 2015-05-20 07:22:30 UTC

Verified it on virt-who-0.12-8.el6.noarch since it won't generate any error when virt-who communication with subscription manager.Therefore, verify it.

Comment 10 Liushihui 2015-06-04 07:30:36 UTC

The same problem has been reproduced on virt-who-0.12-9.el6.noarch, Therefore reopen it. 
When unregistering system, it will generate error info of "BadStatusLine" when communicate with subscription-manager, please see the detail log as the following:
2015-06-04 06:13:17,012 [WARNING]  @virtwho.py:242 - virt-who reload
2015-06-04 06:13:17,012 [ERROR]  @virtwho.py:123 - Error in communication with subscription manager:
Traceback (most recent call last):
  File "/usr/share/virt-who/virtwho.py", line 105, in send
    self._sendGuestAssociation(report)
  File "/usr/share/virt-who/virtwho.py", line 134, in _sendGuestAssociation
    result = manager.hypervisorCheckIn(report.config, report.association, report.config.type)
  File "/usr/share/virt-who/manager/subscriptionmanager/subscriptionmanager.py", line 132, in hypervisorCheckIn
    return self.connection.hypervisorCheckIn(config.owner, config.env, mapping)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 815, in hypervisorCheckIn
    return self.conn.request_post(url, host_guest_mapping)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 605, in request_post
    return self._request("POST", method, params)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 512, in _request
    response = conn.getresponse()
  File "/usr/lib64/python2.6/httplib.py", line 1012, in getresponse
    response.begin()
  File "/usr/lib64/python2.6/httplib.py", line 404, in begin
    version, status, reason = self._read_status()
  File "/usr/lib64/python2.6/httplib.py", line 368, in _read_status
    raise BadStatusLine(line)
BadStatusLine

Comment 11 Radek Novacek 2015-06-04 14:33:36 UTC

Fixed in virt-who-0.12-10.el6.

Comment 12 Liushihui 2015-06-11 08:51:55 UTC

Verified it on virt-who-0.12-10.el6 since it won't generate any error log when unregister to SAM-1.4.1-RHEL-6-20141113.0 or Satellite-6.1.0-RHEL-7-20150603.1. Therefore, verify it.

Verified version:
virt-who-0.12-10.el6.noarch
subscription-manager-1.14.10-1.el6.x86_64
python-rhsm-1.14.3-1.el6.x86_64

Comment 13 Liushihui 2015-06-16 02:16:31 UTC

It has been reproduced on  virt-who-0.12-10.el6 against Satellite-6.1.0-RHEL-7-20150612.0, Therefore, reopen it.

2015-06-16 10:14:06,704 [DEBUG] rhsmd:28107 @identity.py:143 - Reload of consumer identity cert /etc/pki/consumer/cert.pem raised an exception with msg: [Errno 2] No such file or directory: '/etc/pki/consumer/key.pem'
2015-06-16 10:14:06,704 [DEBUG] rhsmd:28107 @rhsmd:148 - D-Bus signal com.redhat.SubscriptionManager.EntitlementStatus.entitlement_status_changed emitted
2015-06-16 10:14:06,704 [DEBUG] subscription-manager:28096 @utils.py:284 - Restarted virt-who
2015-06-16 10:14:06,704 [WARNING]  @virtwho.py:242 - virt-who reload
2015-06-16 10:14:06,706 [ERROR]  @virtwho.py:123 - Error in communication with subscription manager:
Traceback (most recent call last):
  File "/usr/share/virt-who/virtwho.py", line 103, in send
    self._sendGuestList(report)
  File "/usr/share/virt-who/virtwho.py", line 129, in _sendGuestList
    manager.sendVirtGuests(report.guests)
  File "/usr/share/virt-who/manager/subscriptionmanager/subscriptionmanager.py", line 105, in sendVirtGuests
    self._connect()
  File "/usr/share/virt-who/manager/subscriptionmanager/subscriptionmanager.py", line 83, in _connect
    if not self.connection.ping()['result']:
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 762, in ping
    return self.conn.request_get("/status/")
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 602, in request_get
    return self._request("GET", method)
  File "/usr/lib64/python2.6/site-packages/rhsm/connection.py", line 512, in _request
    response = conn.getresponse()
  File "/usr/lib64/python2.6/httplib.py", line 1012, in getresponse
    response.begin()
  File "/usr/lib64/python2.6/httplib.py", line 404, in begin
    version, status, reason = self._read_status()
  File "/usr/lib64/python2.6/httplib.py", line 368, in _read_status
    raise BadStatusLine(line)
BadStatusLine
2015-06-16 10:14:06,709 [INFO]  @virtwho.py:576 - Reloading
2015-06-16 10:14:06,709 [DEBUG]  @virtwho.py:151 - Starting infinite loop with 10 seconds interval

Comment 15 Radek Novacek 2015-06-18 14:15:58 UTC

The problem is very minor, it's just a harmless error message that happens only when the machine is unregistered. I'll move this bug to the next release.

Comment 17 Radek Novacek 2015-12-15 12:07:48 UTC

I can't reproduce this with current upstream version, so it seems to be resolved.

Comment 18 Radek Novacek 2015-12-17 12:30:28 UTC

Fixed by rebase to virt-who-0.16-1.el6.

Comment 20 Eko 2016-01-19 08:49:53 UTC

Verified, can't be duplicated on virt-who-0.16-1.el6

Comment 22 errata-xmlrpc 2016-05-10 23:55:01 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/RHEA-2016-0859.html

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