Bug 861443

Summary:	rhsmcertd logging of Healing shows "Certificates updated." when it should fail.
Product:	Red Hat Enterprise Linux 5	Reporter:	John Sefler <jsefler>
Component:	subscription-manager	Assignee:	Michael Stead <mstead>
Status:	CLOSED ERRATA	QA Contact:	Entitlement Bugs <entitlement-bugs>
Severity:	low	Docs Contact:
Priority:	unspecified
Version:	5.9	CC:	mstead, skallesh
Target Milestone:	rc
Target Release:	---
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:		Doc Type:	Bug Fix
Doc Text:	Cause: The exception was being ignored after it was thrown. Consequence: Errors for healing were never making it to the rhsmcertd log file. Fix: Properly handle any exceptions so that they are logged by the daemon. Result: Proper exit status logged for healing run.	Story Points:	---
Clone Of:		Environment:
Last Closed:	2013-01-08 04:03:55 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:
Bug Depends On:
Bug Blocks:	771748

Description John Sefler 2012-09-28 15:39:26 UTC

Description of problem:
I believe this is a minor regression...

The rhsmcertd service logs the success or failure of the "Healing" and "Cert Check" update.  In the case that a consumer has been deleted server side, it would seem to me that both the "Healing" and "Cert Check" would fail on the next trigger of rhsmcertd, but the "Healing" update appears to pass (seems wrong to me) while the "Cert Check" fails (seems correct to me).


Version-Release number of selected component (if applicable):
[root@rhsm-accept-rhel5 ~]# rpm -q subscription-manager python-rhsm
subscription-manager-1.0.20-1.el5
python-rhsm-1.0.9-1.el5


How reproducible:


Steps to Reproduce:
[root@rhsm-accept-rhel5 ~]# subscription-manager register --username stage_test_12 --serverurl=subscription.rhn.stage.redhat.com:443/subscription
Password: 
The system has been registered with id: 17527ce8-d2df-438e-92aa-efcbcf88e119 
[root@rhsm-accept-rhel5 ~]# service rhsmcertd restart
Stopping rhsmcertd...                                      [  OK  ]
Starting rhsmcertd...                                      [  OK  ]

[root@rhsm-accept-rhel5 ~]# tail -f /var/log/rhsm/rhsmcertd.log
Fri Sep 28 11:19:16 2012 [INFO] rhsmcertd is shutting down...
Fri Sep 28 11:19:16 2012 [INFO] Starting rhsmcertd...
Fri Sep 28 11:19:16 2012 [INFO] Healing interval: 1440.0 minute(s) [86400 second(s)]
Fri Sep 28 11:19:16 2012 [INFO] Cert check interval: 240.0 minute(s) [14400 second(s)]
Fri Sep 28 11:19:16 2012 [INFO] Waiting 120 second(s) [2.0 minute(s)] before running updates.
Fri Sep 28 11:21:23 2012 [INFO] (Healing) Certificates updated.
Fri Sep 28 11:21:38 2012 [INFO] (Cert Check) Certificates updated.

^^ THESE LAST TWO LINES WITH "Certificates updated." IS CORRECT.
 
[root@rhsm-accept-rhel5 ~]# curl --stderr /dev/null --insecure --user stage_test_12:redhat --request DELETE http://rubyvip.web.stage.ext.phx2.redhat.com/clonepin/candlepin/consumers/17527ce8-d2df-438e-92aa-efcbcf88e119
[root@rhsm-accept-rhel5 ~]# subscription-manager identity
Consumer 17527ce8-d2df-438e-92aa-efcbcf88e119 has been deleted
[root@rhsm-accept-rhel5 ~]# service rhsmcertd restart
Stopping rhsmcertd...                                      [  OK  ]
Starting rhsmcertd...                                      [  OK  ]

[root@rhsm-accept-rhel5 ~]# tail -f /var/log/rhsm/rhsmcertd.log
Fri Sep 28 11:23:15 2012 [INFO] rhsmcertd is shutting down...
Fri Sep 28 11:23:15 2012 [INFO] Starting rhsmcertd...
Fri Sep 28 11:23:15 2012 [INFO] Healing interval: 1440.0 minute(s) [86400 second(s)]
Fri Sep 28 11:23:15 2012 [INFO] Cert check interval: 240.0 minute(s) [14400 second(s)]
Fri Sep 28 11:23:15 2012 [INFO] Waiting 120 second(s) [2.0 minute(s)] before running updates.
Fri Sep 28 11:25:26 2012 [INFO] (Healing) Certificates updated.
Fri Sep 28 11:25:26 2012 [WARN] (Cert Check) Update failed (255), retry will occur on next run.

^^ THE LAST LINE WITH "(Cert Check) Update failed" LOOKS CORRECT.
^^ THE PRIOR LINE WITH "(Healing) Certificates updated." LOOKS WRONG.  SEEMS TO ME THAT THIS SHOULD HAVE FAILED TOO SINCE THE LOCAL CONSUMER CERT HAS BEEN DELETED ON THE SERVER.

Comment 1 RHEL Program Management 2012-09-28 15:50:07 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 2 Michael Stead 2012-10-04 13:32:19 UTC

Fixed in:
master - f6fa801acb34a79f7ba6f12b07384c79c1b9c34d
internal - 02f57d6df62ad6bb809fec2e4e7e9cb7bb5d759b

Comment 4 Shwetha Kallesh 2012-10-11 10:12:57 UTC

Marking verified!!

[root@localhost ~]# subscription-manager version
registered to: 0.7.13-1
server type: subscription management service
subscription-manager: 1.0.22-1.el5
python-rhsm: 1.0.10-1.el5



[root@localhost ~]# curl -k -u admin:admin --request DELETE https://10.70.35.91:8443/candlepin/consumers/4ac9fa9b-f5fa-4c6d-9d51-812ace2eb24e
[root@localhost ~]# subscription-manager identity
Consumer 4ac9fa9b-f5fa-4c6d-9d51-812ace2eb24e has been deleted
[root@localhost ~]# service rhsmcertd restart
Stopping rhsmcertd...                                      [  OK  ]
Starting rhsmcertd...                                      [  OK  ]


[root@localhost entitlement]# tail -f /var/log/rhsm/rhsmcertd.log
Thu Oct 11 20:54:14 2012 [INFO] Healing interval: 1440.0 minute(s) [86400 second(s)]
Thu Oct 11 20:54:14 2012 [INFO] Cert check interval: 240.0 minute(s) [14400 second(s)]
Thu Oct 11 20:54:14 2012 [INFO] Waiting 120 second(s) [2.0 minute(s)] before running updates.
Thu Oct 11 20:56:15 2012 [INFO] (Healing) Certificates updated.
Thu Oct 11 20:56:16 2012 [INFO] (Cert Check) Certificates updated.
Thu Oct 11 20:58:58 2012 [INFO] rhsmcertd is shutting down...
Thu Oct 11 20:58:58 2012 [INFO] Starting rhsmcertd...
Thu Oct 11 20:58:58 2012 [INFO] Healing interval: 1440.0 minute(s) [86400 second(s)]
Thu Oct 11 20:58:58 2012 [INFO] Cert check interval: 240.0 minute(s) [14400 second(s)]
Thu Oct 11 20:58:58 2012 [INFO] Waiting 120 second(s) [2.0 minute(s)] before running updates.
Thu Oct 11 21:00:58 2012 [WARN] (Healing) Update failed (255), retry will occur on next run.
Thu Oct 11 21:00:59 2012 [WARN] (Cert Check) Update failed (255), retry will occur on next run.

Comment 6 errata-xmlrpc 2013-01-08 04:03:55 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-2013-0033.html