Bug 1322160

Description of problem:

When subscription-manager is run by itself, the rhsm components used to talk to the Satellite or RHN servers provide logs of the requests to and responses from the server:

2016-03-01 06:19:34,703 [DEBUG] rhsmcertd-worker:14057 @base_action_client.py:85 - running lib: <subscription_manager.entcertlib.EntCertActionInvoker object at 0x1990c50>
2016-03-01 06:19:34,704 [INFO] rhsmcertd-worker:14057 @connection.py:727 - Connection built: host=subscription.rhn.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ verify=False
2016-03-01 06:19:34,704 [DEBUG] rhsmcertd-worker:14057 @identity.py:131 - Loading consumer info from identity certificates.
2016-03-01 06:19:34,711 [DEBUG] rhsmcertd-worker:14057 @connection.py:446 - Loaded CA certificates from /etc/rhsm/ca/: redhat-uep.pem, candlepin-stage.pem
2016-03-01 06:19:34,711 [DEBUG] rhsmcertd-worker:14057 @connection.py:494 - Making request: GET /subscription/consumers/0391ead4-7bd8-4f26-9df2-400d64ea440f/certificates/serials
2016-03-01 06:19:35,769 [DEBUG] rhsmcertd-worker:14057 @connection.py:521 - Response: status=200, requestUuid=1ba16f59-a314-4f8f-9a0d-ee3dd40dc749

However, when virt-who is run with debugging turned on, the rhsm components do not generate similar logs, even though they are clearly in use:

2016-03-01 06:15:57,548 [INFO]  @subscriptionmanager.py:124 - Sending update in hosts-to-guests mapping: {**elided**}
2016-03-01 06:15:57,549 [DEBUG]  @subscriptionmanager.py:76 - Authenticating with certificate: /etc/pki/consumer/cert.pem
2016-03-01 06:15:59,387 [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 134, 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: Organization with id 1 could not be found.

(The exception here is not the cause of this bug report, but it indicates that we were using rhsm/connection.py during this operation).

Version-Release number of selected component (if applicable):

subscription-manager-1.14.10-1.el6.x86_64
python-rhsm-1.14.3-1.el6.x86_64

How reproducible:

Always

Steps to Reproduce:
1. Ensure debugging is turned on in virt-who:

$ grep VIRTWHO_DEBUG etc/sysconfig/virt-who 
VIRTWHO_DEBUG=1

2. Run virt-who
3. Observe logs in /var/log/rhsm/

Actual results:

4. Logs do not indicate what URL was requested of the server, nor what its response was.

Expected results:

4. Logs indicate the request to and response from the server.

Additional info:

This log information will be very useful in debugging the above exception :-)