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 1322160 - virt-who in debugging mode does not get logs from rhsm
Summary: virt-who in debugging mode does not get logs from rhsm
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 6
Classification: Red Hat
Component: virt-who
Version: 6.7
Hardware: All
OS: Linux
unspecified
medium
Target Milestone: rc
: ---
Assignee: Chris Snyder
QA Contact: gaoshang
URL:
Whiteboard:
Depends On:
Blocks: 1269194
TreeView+ depends on / blocked
 
Reported: 2016-03-29 23:16 UTC by Paul Wayper
Modified: 2019-10-10 11:42 UTC (History)
6 users (show)

Fixed In Version: virt-who-0.18-1.el6
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-03-21 10:29:47 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Product Errata RHBA-2017:0675 0 normal SHIPPED_LIVE virt-who bug fix update 2017-03-21 12:35:57 UTC

Description Paul Wayper 2016-03-29 23:16:21 UTC
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 :-)

Comment 2 Radek Novacek 2016-08-09 15:17:42 UTC
Chris,

the rhsm/connection.py python module is just a library that is used by both subscription-manager and virt-who.

I think that you don't see the log from subscription-manager because virt-who produces a lot of logs and those from sub-man are somewhere up in the log file.

Can you check if new logs are added to the log file if you ran:

subscription-manager refresh

Comment 4 Paul Wayper 2016-08-10 01:19:49 UTC
Hi Radek,

I think you have that the wrong way around.  There's no problem getting logs out of subscription-manager.  But virt-who, using the same rhsm/connection.py library, gives no log messages for the same operations that subscription-manager emits logs for.

Did you try my steps to reproduce the problem?  If so, what output did you get?

Hope this helps,

Paul

Comment 5 Radek Novacek 2016-08-16 07:04:07 UTC
Paul,

do you mean that virt-who should print out messages like:

@connection.py:727 - Connection built: host=subscription.rhn.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ verify=False

That could be enabled quite easily. I've added that upstream for now:

https://github.com/virt-who/virt-who/commit/ee482b783c938a1ca571d8f379f61806f1837c8b

Thanks for the tip.

Comment 6 Paul Wayper 2016-08-31 05:16:43 UTC
Hi Radek,

Sorry for the delay - yes, that looks like the right thing.

HTH,

Paul

Comment 7 Radek Novacek 2016-10-13 08:16:41 UTC
Fixed in virt-who-0.18-1.el6.

Comment 9 Eko 2016-12-06 02:28:45 UTC
verified in virt-who-0.18-1.el6.noarch,

2016-12-05 21:28:18,996 [rhsm.connection INFO] MainProcess(27890):MainThread @connection.py:__init__:758 - Connection built: host=subscription.rhsm.stage.redhat.com port=443 handler=/subscription auth=identity_cert ca_dir=/etc/rhsm/ca/ insecure=0
2016-12-05 21:28:18,997 [rhsm.connection DEBUG] MainProcess(27890):MainThread @connection.py:_request:490 - Making request: GET /subscription/status/
2016-12-05 21:28:18,995 [virtwho.main DEBUG] MainProcess(27890):MainThread @subscriptionmanager.py:_connect:124 - Authenticating with certificate: /etc/pki/consumer/cert.pem
2016-12-05 21:28:21,308 [rhsm.connection INFO] MainProcess(27890):MainThread @connection.py:_request:525 - Response: status=200, requestUuid=1aac6b8d-955a-4e16-b8c0-af69b831ac45, request="GET /subscription/status/"

Comment 11 errata-xmlrpc 2017-03-21 10:29:47 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-2017-0675.html


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