1503573 – virt-who hangs on @subscriptionmanager.py:check_report_state:247 - Job hypervisor_update_871b285b-d2fc-4e3b-ab69-90b9b3dbfedd not finished

Red Hat Satellite engineering is moving the tracking of its product development work on Satellite 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 "Satellite project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs will be migrated starting at the end of May. 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 "Satellite project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/SAT-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 1503573 - virt-who hangs on @subscriptionmanager.py:check_report_state:247 - Job hypervisor_update_871b285b-d2fc-4e3b-ab69-90b9b3dbfedd not finished

Summary: virt-who hangs on @subscriptionmanager.py:check_report_state:247 - Job hyperv...

Keywords:
Status:	CLOSED WORKSFORME
Alias:	None
Product:	Red Hat Satellite
Classification:	Red Hat
Component:	Subscriptions - virt-who
Sub Component:
Version:	6.3.0
Hardware:	Unspecified
OS:	Unspecified
Priority:	unspecified
Severity:	high
Target Milestone:	Unspecified
Assignee:	Barnaby Court
QA Contact:	Katello QA List
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:	1286684
TreeView+	depends on / blocked

Reported:	2017-10-18 12:17 UTC by Jan Hutař
Modified:	2017-11-08 11:12 UTC (History)
CC List:	6 users (show)
Fixed In Version:
Doc Type:	If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed:	2017-11-08 11:12:20 UTC
Target Upstream Version:
Embargoed:

Attachments	(Terms of Use)

Description Jan Hutař 2017-10-18 12:17:03 UTC

Description of problem:
virt-who hangs on @subscriptionmanager.py:check_report_state:247 - Job hypervisor_update_871b285b-d2fc-4e3b-ab69-90b9b3dbfedd not finished


Version-Release number of selected component (if applicable):
Satelite: satellite-6.3.0-20.0.beta.el7sat.noarch
Client: virt-who-0.19-6.el7_4.noarch


How reproducible:
2 of 2


Steps to Reproduce:
1. Have Satellite 6.3.0 snap 20 with registered RHEL7 client
2. Client have virt-who installed and configured to upload ESX data
3. # virt-who --one-shot --debug


Actual results:
# virt-who --one-shot --debug
[...]
2017-10-18 08:10:14,644 [rhsm.connection INFO] MainProcess(23021):Thread-3 @connection.py:_request:552 - Response: status=200, request="POST /rhsm/hypervisors/Default_Organization?reporter_id=client.example.com-5d7c29a73d8c46dcad7672f741a28be0&cloaked=False&env=Library"
2017-10-18 08:10:14,647 [rhsm.connection INFO] MainProcess(23021):Thread-3 @connection.py:__init__:822 - Connection built: host=sat.example.com port=443 handler=/rhsm auth=identity_cert ca_dir=/etc/rhsm/ca/ insecure=0
2017-10-18 08:10:14,648 [rhsm.connection DEBUG] MainProcess(23021):Thread-3 @connection.py:_request:516 - Making request: GET /rhsm/status/
2017-10-18 08:10:14,646 [virtwho.destination_-7426371236027194430 DEBUG] MainProcess(23021):Thread-3 @subscriptionmanager.py:_connect:131 - Authenticating with certificate: /etc/pki/consumer/cert.pem
2017-10-18 08:10:15,636 [rhsm.connection INFO] MainProcess(23021):Thread-3 @connection.py:_request:552 - Response: status=200, request="GET /rhsm/status/"
2017-10-18 08:10:15,638 [rhsm.connection DEBUG] MainProcess(23021):Thread-3 @connection.py:_request:516 - Making request: GET /rhsm/jobs/hypervisor_update_83ce6988-5a37-4037-8538-a67f01ea97f7?result_data=True
2017-10-18 08:10:15,637 [virtwho.destination_-7426371236027194430 DEBUG] MainProcess(23021):Thread-3 @subscriptionmanager.py:check_report_state:233 - Checking status of job hypervisor_update_83ce6988-5a37-4037-8538-a67f01ea97f7
2017-10-18 08:10:16,636 [rhsm.connection INFO] MainProcess(23021):Thread-3 @connection.py:_request:552 - Response: status=200, request="GET /rhsm/jobs/hypervisor_update_83ce6988-5a37-4037-8538-a67f01ea97f7?result_data=True"
2017-10-18 08:10:16,637 [virtwho.destination_-7426371236027194430 DEBUG] MainProcess(23021):Thread-3 @subscriptionmanager.py:check_report_state:247 - Job hypervisor_update_83ce6988-5a37-4037-8538-a67f01ea97f7 not finished


Expected results:
Should work


Additional info:
On Satellite, that job is really not finished:

# curl -X GET -s -k -u <user>:<pass> https://localhost/rhsm/jobs/hypervisor_update_83ce6988-5a37-4037-8538-a67f01ea97f7?result_data=true | json_reformat 
{
    "id": "hypervisor_update_83ce6988-5a37-4037-8538-a67f01ea97f7",
    "state": "CREATED",
    "startTime": null,
    "finishTime": null,
    "result": null,
    "principalName": "foreman_admin",
    "targetType": "owner",
    "targetId": "Default_Organization",
    "ownerId": "Default_Organization",
    "correlationId": "d10b6f70",
    "resultData": null,
    "statusPath": "/jobs/hypervisor_update_83ce6988-5a37-4037-8538-a67f01ea97f7",
    "done": false,
    "group": "async group",
    "created": "2017-10-18T12:10:14+0000",
    "updated": "2017-10-18T12:10:14+0000"
}

And Foreman still seems to query state of that Candlepin job:

# tail -n 0 -f /var/log/candlepin/*.log
==> /var/log/candlepin/audit.log <==

==> /var/log/candlepin/candlepin.log <==

==> /var/log/candlepin/cpdb.log <==

==> /var/log/candlepin/cpinit.log <==

==> /var/log/candlepin/error.log <==

==> /var/log/candlepin/candlepin.log <==
2017-10-18 08:14:53,851 [thread=http-bio-8443-exec-8] [req=da44db59-8a90-43b4-a873-4ddad4b1671c, org=, csid=d10b6f70] INFO  org.candlepin.common.filter.LoggingFilter - Request: verb=GET, uri=/candlepin/jobs/hypervisor_update_83ce6988-5a37-4037-8538-a67f01ea97f7?result_data=true
2017-10-18 08:14:53,854 [thread=http-bio-8443-exec-8] [req=da44db59-8a90-43b4-a873-4ddad4b1671c, org=, csid=d10b6f70] INFO  org.candlepin.common.filter.LoggingFilter - Response: status=200, content-type="application/json", time=3
2017-10-18 08:14:53,861 [thread=http-bio-8443-exec-9] [req=6c802178-4369-4828-83b7-4fecaa09bbb5, org=, csid=f03bf638] INFO  org.candlepin.common.filter.LoggingFilter - Request: verb=GET, uri=/candlepin/jobs/hypervisor_update_871b285b-d2fc-4e3b-ab69-90b9b3dbfedd?result_data=true
2017-10-18 08:14:53,864 [thread=http-bio-8443-exec-9] [req=6c802178-4369-4828-83b7-4fecaa09bbb5, org=, csid=f03bf638] INFO  org.candlepin.common.filter.LoggingFilter - Response: status=200, content-type="application/json", time=3
2017-10-18 08:15:09,901 [thread=http-bio-8443-exec-1] [req=d430ee3c-ebc4-45c4-882d-f4d6b950e994, org=, csid=d10b6f70] INFO  org.candlepin.common.filter.LoggingFilter - Request: verb=GET, uri=/candlepin/jobs/hypervisor_update_83ce6988-5a37-4037-8538-a67f01ea97f7?result_data=true
2017-10-18 08:15:09,904 [thread=http-bio-8443-exec-1] [req=d430ee3c-ebc4-45c4-882d-f4d6b950e994, org=, csid=d10b6f70] INFO  org.candlepin.common.filter.LoggingFilter - Response: status=200, content-type="application/json", time=3
2017-10-18 08:15:09,909 [thread=http-bio-8443-exec-4] [req=85859cb2-9e66-4010-b210-4116395f7cbf, org=, csid=f03bf638] INFO  org.candlepin.common.filter.LoggingFilter - Request: verb=GET, uri=/candlepin/jobs/hypervisor_update_871b285b-d2fc-4e3b-ab69-90b9b3dbfedd?result_data=true
2017-10-18 08:15:09,912 [thread=http-bio-8443-exec-4] [req=85859cb2-9e66-4010-b210-4116395f7cbf, org=, csid=f03bf638] INFO  org.candlepin.common.filter.LoggingFilter - Response: status=200, content-type="application/json", time=3
2017-10-18 08:15:25,953 [thread=http-bio-8443-exec-3] [req=2c4ce6ad-236d-48ac-97f9-2759ab308889, org=, csid=d10b6f70] INFO  org.candlepin.common.filter.LoggingFilter - Request: verb=GET, uri=/candlepin/jobs/hypervisor_update_83ce6988-5a37-4037-8538-a67f01ea97f7?result_data=true
2017-10-18 08:15:25,957 [thread=http-bio-8443-exec-3] [req=2c4ce6ad-236d-48ac-97f9-2759ab308889, org=, csid=d10b6f70] INFO  org.candlepin.common.filter.LoggingFilter - Response: status=200, content-type="application/json", time=4
2017-10-18 08:15:25,959 [thread=http-bio-8443-exec-10] [req=e52da085-5a56-443b-b445-a15312e0e30d, org=, csid=f03bf638] INFO  org.candlepin.common.filter.LoggingFilter - Request: verb=GET, uri=/candlepin/jobs/hypervisor_update_871b285b-d2fc-4e3b-ab69-90b9b3dbfedd?result_data=true
2017-10-18 08:15:25,962 [thread=http-bio-8443-exec-10] [req=e52da085-5a56-443b-b445-a15312e0e30d, org=, csid=f03bf638] INFO  org.candlepin.common.filter.LoggingFilter - Response: status=200, content-type="application/json", time=3

Comment 1 Jan Hutař 2017-10-18 12:23:29 UTC

There was discussion about this on upstream #theforeman channel:

    https://botbot.me/freenode/theforeman/search/?q=hypervisor_update_

and this issue was reported:

    http://projects.theforeman.org/issues/21110

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