This service will be undergoing maintenance at 00:00 UTC, 2017-10-23 It is expected to last about 30 minutes
Bug 857903 - Healing and auto-subscribe work differently when date is set to exactly one year ahead from today
Healing and auto-subscribe work differently when date is set to exactly one y...
Status: CLOSED NOTABUG
Product: Red Hat Enterprise Linux 5
Classification: Red Hat
Component: subscription-manager (Show other bugs)
5.9
Unspecified Unspecified
unspecified Severity unspecified
: rc
: ---
Assigned To: Devan Goodwin
Entitlement Bugs
:
Depends On:
Blocks: 771748
  Show dependency treegraph
 
Reported: 2012-09-17 08:53 EDT by Shwetha Kallesh
Modified: 2012-09-21 10:01 EDT (History)
2 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2012-09-21 10:01:53 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Shwetha Kallesh 2012-09-17 08:53:30 EDT
Description of problem:
Healing and auto-subscribe work differently when date is set to exactly one year ahead from today

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

[root@dhcp201-110 pki]# rpm -qa | grep subscription-manager
subscription-manager-1.0.17-1.el5
subscription-manager-gui-1.0.17-1.el5
subscription-manager-firstboot-1.0.17-1.el5


How reproducible:


Steps to Reproduce:
1.[root@dhcp201-110 ~]# date
Tue Sep 17 18:03:49 IST 2013
2.[root@dhcp201-110 pki]# subscription-manager subscribe --auto
Installed Product Current Status:
Product Name:         	Awesome OS for S390 Bits
Status:               	Not Subscribed

Product Name:         	Stackable with Awesome OS for x86_64 Bits
Status:               	Not Subscribed

Product Name:         	Awesome OS Developer Basic
Status:               	Not Subscribed

Product Name:         	Awesome OS for x86_64/i686/ia64/ppc/ppc64/s390x/s390 Bits
Status:               	Expired

3.subscription-manager unsubscribe --all
This machine has been unsubscribed from 1 subscriptions

[root@dhcp201-110 ~]# service rhsmcertd restart
Stopping rhsmcertd...                                      [  OK  ]
Starting rhsmcertd...                                      [  OK  ]

[root@dhcp201-110 ~]# cat /etc/rhsm/rhsm.conf | grep heal
# Frequency of autoheal check (1440 min = 1 day):
healFrequency = 2

[root@dhcp201-110 ~]# subscription-manager list --installed
+-------------------------------------------+
    Installed Product Status
+-------------------------------------------+
Product Name:         	Awesome OS for S390 Bits
Product ID:           	100000000000060
Version:              	3.11
Arch:                 	s390
Status:               	Not Subscribed
Starts:               	
Ends:                 	

Product Name:         	Stackable with Awesome OS for x86_64 Bits
Product ID:           	1000000000000023
Version:              	3.11
Arch:                 	x86_64
Status:               	Not Subscribed
Starts:               	
Ends:                 	

Product Name:         	Awesome OS Developer Basic
Product ID:           	1144
Version:              	1.0
Arch:                 	ALL
Status:               	Not Subscribed
Starts:               	
Ends:                 	

Product Name:         	Awesome OS for x86_64/i686/ia64/ppc/ppc64/s390x/s390 Bits
Product ID:           	100000000000011
Version:              	3.11
Arch:                 	x86_64,i686,ia64,ppc,ppc64,s390x,s390
Status:               	Subscribed
Starts:               	09/07/2013
Ends:                 	09/07/2014


[root@dhcp201-110 pki]# tail -f /var/log/rhsm/rhsm.log 
[sn:3031328406376546834 (Large File Support Bits,) @ /etc/pki/entitlement/3031328406376546834.pem]
  [sn:1040761259097793097 (Shared File System Bits,) @ /etc/pki/entitlement/1040761259097793097.pem]
  [sn:3773718596640029167 (Awesome OS Modifier Bits,) @ /etc/pki/entitlement/3773718596640029167.pem]
  [sn:6264955410120325901 (Awesome OS Workstation Bits,) @ /etc/pki/entitlement/6264955410120325901.pem]
  [sn:1453930202572926692 (Awesome OS for x86 Bits,) @ /etc/pki/entitlement/1453930202572926692.pem]
Deleted (rogue):
  <NONE>
Expired (deleted):
  <NONE>
2013-09-17 18:15:51,154 [INFO]  @certlib.py:148 - Auto-heal check complete.
2013-09-17 18:17:56,987 [INFO]  @connection.py:498 - Using certificate authentication: key = /etc/pki/consumer/key.pem, cert = /etc/pki/consumer/cert.pem, ca = /etc/rhsm/ca/, insecure = False
2013-09-17 18:17:56,987 [INFO]  @connection.py:511 - Connection Built: host: 10.70.35.91, port: 8443, handler: /candlepin
2013-09-17 18:17:57,078 [DEBUG]  @cert_sorter.py:106 - Sorting product and entitlement cert status for: 2013-09-17 12:47:57.077946+00:00
2013-09-17 18:17:57,098 [DEBUG]  @cert_sorter.py:160 - Installed product IDs: ['100000000000060', '1000000000000023', '1144', '100000000000011', '27060', '69', '1', '37069', '37068', '37080', '37065', '37067', '37060', '37062', '100000000000006', '100000000000005', '100000000000002', '100000000000003', '100000000000000', '100000000000001', '100000000000020', '88888', '917571', '37070']
2013-09-17 18:17:57,211 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 1453930202572926692
2013-09-17 18:17:57,211 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:17:57,211 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 1040761259097793097
2013-09-17 18:17:57,211 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 3773718596640029167
2013-09-17 18:17:57,211 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 3031328406376546834
2013-09-17 18:17:57,212 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:17:57,212 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 7593088917891695773
2013-09-17 18:17:57,212 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:17:57,212 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 2733618491049981613
2013-09-17 18:17:57,212 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:17:57,213 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 6264955410120325901
2013-09-17 18:17:57,213 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:17:57,213 [DEBUG]  @cert_sorter.py:113 - valid entitled products: ['100000000000005', '100000000000011', '100000000000020', '37060', '27060', '37069', '37068', '37080', '37065', '37067', '88888', '37070']
2013-09-17 18:17:57,213 [DEBUG]  @cert_sorter.py:114 - expired entitled products: []
2013-09-17 18:17:57,213 [DEBUG]  @cert_sorter.py:115 - partially entitled products: []
2013-09-17 18:17:57,214 [DEBUG]  @cert_sorter.py:116 - unentitled products: ['100000000000060', '100000000000006', '1000000000000023', '100000000000002', '100000000000003', '1144', '100000000000001', '1', '917571', '100000000000000', '69', '37062']
2013-09-17 18:17:57,214 [DEBUG]  @cert_sorter.py:117 - future products: []
2013-09-17 18:17:57,214 [DEBUG]  @cert_sorter.py:118 - partial stacks: []
2013-09-17 18:17:57,214 [DEBUG]  @cert_sorter.py:119 - valid stacks: []
2013-09-17 18:17:57,328 [DEBUG]  @connection.py:323 - Loading CA PEM certificates from: /etc/rhsm/ca/
2013-09-17 18:17:57,329 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem'
2013-09-17 18:17:57,329 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-ca.pem'
2013-09-17 18:17:57,329 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem'
2013-09-17 18:17:57,330 [DEBUG]  @connection.py:344 - Making request: GET /candlepin/consumers/1cb27354-3f5a-4908-8bdf-420d0cb56a6d/certificates/serials
2013-09-17 18:17:57,966 [DEBUG]  @connection.py:357 - Response status: 200
2013-09-17 18:17:57,966 [INFO]  @certlib.py:221 - certs updated:
Total updates: 0
Found (local) serial# [1453930202572926692L, 1040761259097793097L, 3773718596640029167L, 3031328406376546834L, 7593088917891695773L, 2733618491049981613L, 6264955410120325901L]
Expected (UEP) serial# [1040761259097793097L, 7593088917891695773L, 1453930202572926692L, 2733618491049981613L, 6264955410120325901L, 3031328406376546834L, 3773718596640029167L]
Added (new)
  <NONE>
Deleted (rogue):
  <NONE>
Expired (deleted):
  <NONE>
2013-09-17 18:17:57,969 [DEBUG]  @connection.py:323 - Loading CA PEM certificates from: /etc/rhsm/ca/
2013-09-17 18:17:57,969 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem'
2013-09-17 18:17:57,970 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-ca.pem'
2013-09-17 18:17:57,970 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem'
2013-09-17 18:17:57,970 [DEBUG]  @connection.py:344 - Making request: GET /candlepin/consumers/1cb27354-3f5a-4908-8bdf-420d0cb56a6d
2013-09-17 18:17:58,923 [DEBUG]  @connection.py:357 - Response status: 200
2013-09-17 18:17:58,923 [INFO]  @certlib.py:111 - Checking if system requires healing.
2013-09-17 18:17:58,924 [DEBUG]  @cert_sorter.py:106 - Sorting product and entitlement cert status for: 2013-09-17 12:47:58.924099+00:00
2013-09-17 18:17:58,943 [DEBUG]  @cert_sorter.py:160 - Installed product IDs: ['100000000000060', '1000000000000023', '1144', '100000000000011', '27060', '69', '1', '37069', '37068', '37080', '37065', '37067', '37060', '37062', '100000000000006', '100000000000005', '100000000000002', '100000000000003', '100000000000000', '100000000000001', '100000000000020', '88888', '917571', '37070']
2013-09-17 18:17:59,056 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 1453930202572926692
2013-09-17 18:17:59,056 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:17:59,056 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 1040761259097793097
2013-09-17 18:17:59,057 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 3773718596640029167
2013-09-17 18:17:59,057 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 3031328406376546834
2013-09-17 18:17:59,057 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:17:59,057 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 7593088917891695773
2013-09-17 18:17:59,057 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:17:59,058 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 2733618491049981613
2013-09-17 18:17:59,058 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:17:59,058 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 6264955410120325901
2013-09-17 18:17:59,058 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:17:59,058 [DEBUG]  @cert_sorter.py:113 - valid entitled products: ['100000000000005', '100000000000011', '100000000000020', '37060', '27060', '37069', '37068', '37080', '37065', '37067', '88888', '37070']
2013-09-17 18:17:59,059 [DEBUG]  @cert_sorter.py:114 - expired entitled products: []
2013-09-17 18:17:59,059 [DEBUG]  @cert_sorter.py:115 - partially entitled products: []
2013-09-17 18:17:59,059 [DEBUG]  @cert_sorter.py:116 - unentitled products: ['100000000000060', '100000000000006', '1000000000000023', '100000000000002', '100000000000003', '1144', '100000000000001', '1', '917571', '100000000000000', '69', '37062']
2013-09-17 18:17:59,059 [DEBUG]  @cert_sorter.py:117 - future products: []
2013-09-17 18:17:59,059 [DEBUG]  @cert_sorter.py:118 - partial stacks: []
2013-09-17 18:17:59,059 [DEBUG]  @cert_sorter.py:119 - valid stacks: []
2013-09-17 18:17:59,060 [WARNING]  @certlib.py:124 - Found invalid entitlements for today: 2013-09-17 12:47:58.924099+00:00
2013-09-17 18:17:59,060 [DEBUG]  @connection.py:323 - Loading CA PEM certificates from: /etc/rhsm/ca/
2013-09-17 18:17:59,060 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem'
2013-09-17 18:17:59,061 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-ca.pem'
2013-09-17 18:17:59,061 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem'
2013-09-17 18:17:59,062 [DEBUG]  @connection.py:344 - Making request: POST /candlepin/consumers/1cb27354-3f5a-4908-8bdf-420d0cb56a6d/entitlements?entitle_date=2013-09-17T12%3A47%3A58.924099%2B00%3A00
2013-09-17 18:17:59,690 [DEBUG]  @connection.py:357 - Response status: 200
2013-09-17 18:17:59,804 [DEBUG]  @connection.py:323 - Loading CA PEM certificates from: /etc/rhsm/ca/
2013-09-17 18:17:59,804 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem'
2013-09-17 18:17:59,804 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-ca.pem'
2013-09-17 18:17:59,805 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem'
2013-09-17 18:17:59,805 [DEBUG]  @connection.py:344 - Making request: GET /candlepin/consumers/1cb27354-3f5a-4908-8bdf-420d0cb56a6d/certificates/serials
2013-09-17 18:18:00,406 [DEBUG]  @connection.py:357 - Response status: 200
2013-09-17 18:18:00,406 [INFO]  @certlib.py:221 - certs updated:
Total updates: 0
Found (local) serial# [1453930202572926692L, 1040761259097793097L, 3773718596640029167L, 3031328406376546834L, 7593088917891695773L, 2733618491049981613L, 6264955410120325901L]
Expected (UEP) serial# [1040761259097793097L, 7593088917891695773L, 1453930202572926692L, 2733618491049981613L, 6264955410120325901L, 3031328406376546834L, 3773718596640029167L]
Added (new)
  <NONE>
Deleted (rogue):
  <NONE>
Expired (deleted):
  <NONE>
2013-09-17 18:18:00,408 [INFO]  @certlib.py:148 - Auto-heal check complete.
2013-09-17 18:18:00,546 [INFO]  @connection.py:498 - Using certificate authentication: key = /etc/pki/consumer/key.pem, cert = /etc/pki/consumer/cert.pem, ca = /etc/rhsm/ca/, insecure = False
2013-09-17 18:18:00,546 [INFO]  @connection.py:511 - Connection Built: host: 10.70.35.91, port: 8443, handler: /candlepin
2013-09-17 18:18:00,635 [DEBUG]  @cert_sorter.py:106 - Sorting product and entitlement cert status for: 2013-09-17 12:48:00.635925+00:00
2013-09-17 18:18:00,656 [DEBUG]  @cert_sorter.py:160 - Installed product IDs: ['100000000000060', '1000000000000023', '1144', '100000000000011', '27060', '69', '1', '37069', '37068', '37080', '37065', '37067', '37060', '37062', '100000000000006', '100000000000005', '100000000000002', '100000000000003', '100000000000000', '100000000000001', '100000000000020', '88888', '917571', '37070']
2013-09-17 18:18:00,769 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 1453930202572926692
2013-09-17 18:18:00,769 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:18:00,770 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 1040761259097793097
2013-09-17 18:18:00,770 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 3773718596640029167
2013-09-17 18:18:00,770 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 3031328406376546834
2013-09-17 18:18:00,770 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:18:00,770 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 7593088917891695773
2013-09-17 18:18:00,771 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:18:00,771 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 2733618491049981613
2013-09-17 18:18:00,771 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:18:00,771 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 6264955410120325901
2013-09-17 18:18:00,771 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:18:00,772 [DEBUG]  @cert_sorter.py:113 - valid entitled products: ['100000000000005', '100000000000011', '100000000000020', '37060', '27060', '37069', '37068', '37080', '37065', '37067', '88888', '37070']
2013-09-17 18:18:00,772 [DEBUG]  @cert_sorter.py:114 - expired entitled products: []
2013-09-17 18:18:00,772 [DEBUG]  @cert_sorter.py:115 - partially entitled products: []
2013-09-17 18:18:00,772 [DEBUG]  @cert_sorter.py:116 - unentitled products: ['100000000000060', '100000000000006', '1000000000000023', '100000000000002', '100000000000003', '1144', '100000000000001', '1', '917571', '100000000000000', '69', '37062']
2013-09-17 18:18:00,772 [DEBUG]  @cert_sorter.py:117 - future products: []
2013-09-17 18:18:00,772 [DEBUG]  @cert_sorter.py:118 - partial stacks: []
2013-09-17 18:18:00,773 [DEBUG]  @cert_sorter.py:119 - valid stacks: []
2013-09-17 18:18:00,887 [DEBUG]  @connection.py:323 - Loading CA PEM certificates from: /etc/rhsm/ca/
2013-09-17 18:18:00,888 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem'
2013-09-17 18:18:00,888 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-ca.pem'
2013-09-17 18:18:00,888 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem'
2013-09-17 18:18:00,889 [DEBUG]  @connection.py:344 - Making request: GET /candlepin/consumers/1cb27354-3f5a-4908-8bdf-420d0cb56a6d/certificates/serials
2013-09-17 18:18:01,464 [DEBUG]  @connection.py:357 - Response status: 200
2013-09-17 18:18:01,465 [INFO]  @certlib.py:221 - certs updated:
Total updates: 0
Found (local) serial# [1453930202572926692L, 1040761259097793097L, 3773718596640029167L, 3031328406376546834L, 7593088917891695773L, 2733618491049981613L, 6264955410120325901L]
Expected (UEP) serial# [1040761259097793097L, 7593088917891695773L, 1453930202572926692L, 2733618491049981613L, 6264955410120325901L, 3031328406376546834L, 3773718596640029167L]
Added (new)
  <NONE>
Deleted (rogue):
  <NONE>
Expired (deleted):
  <NONE>
2013-09-17 18:18:01,468 [DEBUG]  @connection.py:323 - Loading CA PEM certificates from: /etc/rhsm/ca/
2013-09-17 18:18:01,468 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem'
2013-09-17 18:18:01,468 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-ca.pem'
2013-09-17 18:18:01,468 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem'
2013-09-17 18:18:01,469 [DEBUG]  @connection.py:344 - Making request: GET /candlepin/consumers/1cb27354-3f5a-4908-8bdf-420d0cb56a6d
2013-09-17 18:18:02,318 [DEBUG]  @connection.py:357 - Response status: 200
2013-09-17 18:18:02,318 [INFO]  @certlib.py:111 - Checking if system requires healing.
2013-09-17 18:18:02,319 [DEBUG]  @cert_sorter.py:106 - Sorting product and entitlement cert status for: 2013-09-17 12:48:02.319102+00:00
2013-09-17 18:18:02,338 [DEBUG]  @cert_sorter.py:160 - Installed product IDs: ['100000000000060', '1000000000000023', '1144', '100000000000011', '27060', '69', '1', '37069', '37068', '37080', '37065', '37067', '37060', '37062', '100000000000006', '100000000000005', '100000000000002', '100000000000003', '100000000000000', '100000000000001', '100000000000020', '88888', '917571', '37070']
2013-09-17 18:18:02,451 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 1453930202572926692
2013-09-17 18:18:02,451 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:18:02,452 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 1040761259097793097
2013-09-17 18:18:02,452 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 3773718596640029167
2013-09-17 18:18:02,452 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 3031328406376546834
2013-09-17 18:18:02,452 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:18:02,452 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 7593088917891695773
2013-09-17 18:18:02,453 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:18:02,453 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 2733618491049981613
2013-09-17 18:18:02,453 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:18:02,453 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 6264955410120325901
2013-09-17 18:18:02,453 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:18:02,454 [DEBUG]  @cert_sorter.py:113 - valid entitled products: ['100000000000005', '100000000000011', '100000000000020', '37060', '27060', '37069', '37068', '37080', '37065', '37067', '88888', '37070']
2013-09-17 18:18:02,454 [DEBUG]  @cert_sorter.py:114 - expired entitled products: []
2013-09-17 18:18:02,454 [DEBUG]  @cert_sorter.py:115 - partially entitled products: []
2013-09-17 18:18:02,454 [DEBUG]  @cert_sorter.py:116 - unentitled products: ['100000000000060', '100000000000006', '1000000000000023', '100000000000002', '100000000000003', '1144', '100000000000001', '1', '917571', '100000000000000', '69', '37062']
2013-09-17 18:18:02,454 [DEBUG]  @cert_sorter.py:117 - future products: []
2013-09-17 18:18:02,454 [DEBUG]  @cert_sorter.py:118 - partial stacks: []
2013-09-17 18:18:02,455 [DEBUG]  @cert_sorter.py:119 - valid stacks: []
2013-09-17 18:18:02,455 [WARNING]  @certlib.py:124 - Found invalid entitlements for today: 2013-09-17 12:48:02.319102+00:00
2013-09-17 18:18:02,455 [DEBUG]  @connection.py:323 - Loading CA PEM certificates from: /etc/rhsm/ca/
2013-09-17 18:18:02,456 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem'
2013-09-17 18:18:02,456 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-ca.pem'
2013-09-17 18:18:02,456 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem'
2013-09-17 18:18:02,457 [DEBUG]  @connection.py:344 - Making request: POST /candlepin/consumers/1cb27354-3f5a-4908-8bdf-420d0cb56a6d/entitlements?entitle_date=2013-09-17T12%3A48%3A02.319102%2B00%3A00
2013-09-17 18:18:03,823 [DEBUG]  @connection.py:357 - Response status: 200
2013-09-17 18:18:03,937 [DEBUG]  @connection.py:323 - Loading CA PEM certificates from: /etc/rhsm/ca/
2013-09-17 18:18:03,937 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem'
2013-09-17 18:18:03,937 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-ca.pem'
2013-09-17 18:18:03,937 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem'
2013-09-17 18:18:03,938 [DEBUG]  @connection.py:344 - Making request: GET /candlepin/consumers/1cb27354-3f5a-4908-8bdf-420d0cb56a6d/certificates/serials
2013-09-17 18:18:04,939 [DEBUG]  @connection.py:357 - Response status: 200
2013-09-17 18:18:04,940 [INFO]  @certlib.py:221 - certs updated:
Total updates: 0
Found (local) serial# [1453930202572926692L, 1040761259097793097L, 3773718596640029167L, 3031328406376546834L, 7593088917891695773L, 2733618491049981613L, 6264955410120325901L]
Expected (UEP) serial# [1040761259097793097L, 7593088917891695773L, 1453930202572926692L, 2733618491049981613L, 6264955410120325901L, 3031328406376546834L, 3773718596640029167L]
Added (new)
  <NONE>
Deleted (rogue):
  <NONE>
Expired (deleted):
  <NONE>
2013-09-17 18:18:04,942 [INFO]  @certlib.py:148 - Auto-heal check complete.
2013-09-17 18:18:05,079 [INFO]  @connection.py:498 - Using certificate authentication: key = /etc/pki/consumer/key.pem, cert = /etc/pki/consumer/cert.pem, ca = /etc/rhsm/ca/, insecure = False
2013-09-17 18:18:05,079 [INFO]  @connection.py:511 - Connection Built: host: 10.70.35.91, port: 8443, handler: /candlepin
2013-09-17 18:18:05,169 [DEBUG]  @cert_sorter.py:106 - Sorting product and entitlement cert status for: 2013-09-17 12:48:05.169696+00:00
2013-09-17 18:18:05,189 [DEBUG]  @cert_sorter.py:160 - Installed product IDs: ['100000000000060', '1000000000000023', '1144', '100000000000011', '27060', '69', '1', '37069', '37068', '37080', '37065', '37067', '37060', '37062', '100000000000006', '100000000000005', '100000000000002', '100000000000003', '100000000000000', '100000000000001', '100000000000020', '88888', '917571', '37070']
2013-09-17 18:18:05,303 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 1453930202572926692
2013-09-17 18:18:05,303 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:18:05,303 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 1040761259097793097
2013-09-17 18:18:05,303 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 3773718596640029167
2013-09-17 18:18:05,304 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 3031328406376546834
2013-09-17 18:18:05,304 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:18:05,304 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 7593088917891695773
2013-09-17 18:18:05,304 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:18:05,304 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 2733618491049981613
2013-09-17 18:18:05,304 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:18:05,305 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 6264955410120325901
2013-09-17 18:18:05,305 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:18:05,305 [DEBUG]  @cert_sorter.py:113 - valid entitled products: ['100000000000005', '100000000000011', '100000000000020', '37060', '27060', '37069', '37068', '37080', '37065', '37067', '88888', '37070']
2013-09-17 18:18:05,305 [DEBUG]  @cert_sorter.py:114 - expired entitled products: []
2013-09-17 18:18:05,305 [DEBUG]  @cert_sorter.py:115 - partially entitled products: []
2013-09-17 18:18:05,306 [DEBUG]  @cert_sorter.py:116 - unentitled products: ['100000000000060', '100000000000006', '1000000000000023', '100000000000002', '100000000000003', '1144', '100000000000001', '1', '917571', '100000000000000', '69', '37062']
2013-09-17 18:18:05,306 [DEBUG]  @cert_sorter.py:117 - future products: []
2013-09-17 18:18:05,306 [DEBUG]  @cert_sorter.py:118 - partial stacks: []
2013-09-17 18:18:05,306 [DEBUG]  @cert_sorter.py:119 - valid stacks: []
2013-09-17 18:18:05,421 [DEBUG]  @connection.py:323 - Loading CA PEM certificates from: /etc/rhsm/ca/
2013-09-17 18:18:05,421 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem'
2013-09-17 18:18:05,422 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-ca.pem'
2013-09-17 18:18:05,422 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem'
2013-09-17 18:18:05,423 [DEBUG]  @connection.py:344 - Making request: GET /candlepin/consumers/1cb27354-3f5a-4908-8bdf-420d0cb56a6d/certificates/serials
2013-09-17 18:18:06,553 [DEBUG]  @connection.py:357 - Response status: 200
2013-09-17 18:18:06,553 [INFO]  @certlib.py:221 - certs updated:
Total updates: 0
Found (local) serial# [1453930202572926692L, 1040761259097793097L, 3773718596640029167L, 3031328406376546834L, 7593088917891695773L, 2733618491049981613L, 6264955410120325901L]
Expected (UEP) serial# [1040761259097793097L, 7593088917891695773L, 1453930202572926692L, 2733618491049981613L, 6264955410120325901L, 3031328406376546834L, 3773718596640029167L]
Added (new)
  <NONE>
Deleted (rogue):
  <NONE>
Expired (deleted):
  <NONE>
2013-09-17 18:18:06,556 [DEBUG]  @connection.py:323 - Loading CA PEM certificates from: /etc/rhsm/ca/
2013-09-17 18:18:06,557 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem'
2013-09-17 18:18:06,557 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-ca.pem'
2013-09-17 18:18:06,557 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem'
2013-09-17 18:18:06,558 [DEBUG]  @connection.py:344 - Making request: GET /candlepin/consumers/1cb27354-3f5a-4908-8bdf-420d0cb56a6d
2013-09-17 18:18:08,034 [DEBUG]  @connection.py:357 - Response status: 200
2013-09-17 18:18:08,036 [DEBUG]  @connection.py:323 - Loading CA PEM certificates from: /etc/rhsm/ca/
2013-09-17 18:18:08,036 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem'
2013-09-17 18:18:08,036 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-ca.pem'
2013-09-17 18:18:08,037 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem'
2013-09-17 18:18:08,037 [DEBUG]  @connection.py:344 - Making request: GET /candlepin/consumers/1cb27354-3f5a-4908-8bdf-420d0cb56a6d/release
2013-09-17 18:18:09,278 [DEBUG]  @connection.py:357 - Response status: 200
2013-09-17 18:18:09,423 [DEBUG]  @repolib.py:190 - Missing required tag 'TAG1', skipping content: tagged-content
2013-09-17 18:18:09,423 [DEBUG]  @repolib.py:190 - Missing required tag 'TAG2', skipping content: tagged-content
2013-09-17 18:18:09,453 [INFO]  @repolib.py:156 - repos updated: 72
2013-09-17 18:18:09,482 [DEBUG]  @cert_sorter.py:106 - Sorting product and entitlement cert status for: 2013-09-17 12:48:09.482747+00:00
2013-09-17 18:18:09,502 [DEBUG]  @cert_sorter.py:160 - Installed product IDs: ['100000000000060', '1000000000000023', '1144', '100000000000011', '27060', '69', '1', '37069', '37068', '37080', '37065', '37067', '37060', '37062', '100000000000006', '100000000000005', '100000000000002', '100000000000003', '100000000000000', '100000000000001', '100000000000020', '88888', '917571', '37070']
2013-09-17 18:18:09,615 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 1453930202572926692
2013-09-17 18:18:09,615 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:18:09,616 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 1040761259097793097
2013-09-17 18:18:09,616 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 3773718596640029167
2013-09-17 18:18:09,616 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 3031328406376546834
2013-09-17 18:18:09,616 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:18:09,616 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 7593088917891695773
2013-09-17 18:18:09,617 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:18:09,617 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 2733618491049981613
2013-09-17 18:18:09,617 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:18:09,617 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 6264955410120325901
2013-09-17 18:18:09,618 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:18:09,618 [DEBUG]  @cert_sorter.py:113 - valid entitled products: ['100000000000005', '100000000000011', '100000000000020', '37060', '27060', '37069', '37068', '37080', '37065', '37067', '88888', '37070']
2013-09-17 18:18:09,618 [DEBUG]  @cert_sorter.py:114 - expired entitled products: []
2013-09-17 18:18:09,618 [DEBUG]  @cert_sorter.py:115 - partially entitled products: []
2013-09-17 18:18:09,618 [DEBUG]  @cert_sorter.py:116 - unentitled products: ['100000000000060', '100000000000006', '1000000000000023', '100000000000002', '100000000000003', '1144', '100000000000001', '1', '917571', '100000000000000', '69', '37062']
2013-09-17 18:18:09,618 [DEBUG]  @cert_sorter.py:117 - future products: []
2013-09-17 18:18:09,619 [DEBUG]  @cert_sorter.py:118 - partial stacks: []
2013-09-17 18:18:09,619 [DEBUG]  @cert_sorter.py:119 - valid stacks: []
2013-09-17 18:18:09,619 [INFO]  @factlib.py:52 - Facts have not changed, skipping upload.
2013-09-17 18:18:09,620 [DEBUG]  @connection.py:323 - Loading CA PEM certificates from: /etc/rhsm/ca/
2013-09-17 18:18:09,621 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem'
2013-09-17 18:18:09,621 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-ca.pem'
2013-09-17 18:18:09,621 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem'
2013-09-17 18:18:09,622 [DEBUG]  @connection.py:344 - Making request: GET /candlepin/
2013-09-17 18:18:11,396 [DEBUG]  @connection.py:357 - Response status: 200
2013-09-17 18:18:11,396 [DEBUG]  @connection.py:528 - Server supports the following resources:
2013-09-17 18:18:11,396 [DEBUG]  @connection.py:529 - {'': '/', 'hypervisors': '/hypervisors', 'serials': '/serials', 'consumers': '/consumers', 'migrations': '/migrations', 'content': '/content', 'entitlements': '/entitlements', 'statistics/generate': '/statistics/generate', 'status': '/status', 'jobs': '/jobs', 'users': '/users', 'subscriptions': '/subscriptions', 'rules': '/rules', 'consumertypes': '/consumertypes', 'activation_keys': '/activation_keys', 'atom': '/atom', 'owners': '/owners', 'roles': '/roles', 'admin': '/admin', 'events': '/events', 'products': '/products', 'pools': '/pools', 'crl': '/crl'}
2013-09-17 18:18:11,396 [INFO]  @cache.py:215 - Server does not support packages, skipping profile upload.
2013-09-17 18:18:11,417 [INFO]  @cache.py:160 - Checking current system info against cache: /var/lib/rhsm/cache/installed_products.json
2013-09-17 18:18:11,417 [INFO]  @cache.py:175 - No changes.
2013-09-17 18:19:20,845 [DEBUG]  @profile.py:95 - Loading current RPM profile.
2013-09-17 18:19:20,928 [INFO]  @managercli.py:252 - Client Versions: {'python-rhsm': '1.0.6-1.el5', 'subscription-manager': '1.0.17-1.el5'} 
2013-09-17 18:19:20,929 [INFO]  @connection.py:498 - Using certificate authentication: key = /etc/pki/consumer/key.pem, cert = /etc/pki/consumer/cert.pem, ca = /etc/rhsm/ca/, insecure = False
2013-09-17 18:19:20,929 [INFO]  @connection.py:511 - Connection Built: host: 10.70.35.91, port: 8443, handler: /candlepin
2013-09-17 18:19:20,930 [DEBUG]  @connection.py:323 - Loading CA PEM certificates from: /etc/rhsm/ca/
2013-09-17 18:19:20,931 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem'
2013-09-17 18:19:20,931 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-ca.pem'
2013-09-17 18:19:20,931 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem'
2013-09-17 18:19:20,932 [DEBUG]  @connection.py:344 - Making request: GET /candlepin/
2013-09-17 18:19:21,922 [DEBUG]  @connection.py:357 - Response status: 200
2013-09-17 18:19:21,922 [DEBUG]  @connection.py:528 - Server supports the following resources:
2013-09-17 18:19:21,922 [DEBUG]  @connection.py:529 - {'': '/', 'hypervisors': '/hypervisors', 'serials': '/serials', 'consumers': '/consumers', 'migrations': '/migrations', 'content': '/content', 'entitlements': '/entitlements', 'statistics/generate': '/statistics/generate', 'status': '/status', 'jobs': '/jobs', 'users': '/users', 'subscriptions': '/subscriptions', 'rules': '/rules', 'consumertypes': '/consumertypes', 'activation_keys': '/activation_keys', 'atom': '/atom', 'owners': '/owners', 'roles': '/roles', 'admin': '/admin', 'events': '/events', 'products': '/products', 'pools': '/pools', 'crl': '/crl'}
2013-09-17 18:19:21,923 [DEBUG]  @connection.py:323 - Loading CA PEM certificates from: /etc/rhsm/ca/
2013-09-17 18:19:21,923 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem'
2013-09-17 18:19:21,923 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-ca.pem'
2013-09-17 18:19:21,924 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem'
2013-09-17 18:19:21,924 [DEBUG]  @connection.py:344 - Making request: GET /candlepin/status
2013-09-17 18:19:23,250 [DEBUG]  @connection.py:357 - Response status: 200
2013-09-17 18:19:23,290 [DEBUG]  @connection.py:323 - Loading CA PEM certificates from: /etc/rhsm/ca/
2013-09-17 18:19:23,290 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-stage.pem'
2013-09-17 18:19:23,291 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/candlepin-ca.pem'
2013-09-17 18:19:23,291 [DEBUG]  @connection.py:305 - Loading CA certificate: '/etc/rhsm/ca/redhat-uep.pem'
2013-09-17 18:19:23,292 [DEBUG]  @connection.py:344 - Making request: GET /candlepin/status
2013-09-17 18:19:26,694 [DEBUG]  @connection.py:357 - Response status: 200
2013-09-17 18:19:26,694 [INFO]  @managercli.py:267 - Server Versions: {'candlepin': '0.7.9-1', 'server-type': 'subscription management service'} 
2013-09-17 18:19:26,729 [DEBUG]  @cert_sorter.py:106 - Sorting product and entitlement cert status for: 2013-09-17 12:49:26.729623+00:00
2013-09-17 18:19:26,749 [DEBUG]  @cert_sorter.py:160 - Installed product IDs: ['100000000000060', '1000000000000023', '1144', '100000000000011', '27060', '69', '1', '37069', '37068', '37080', '37065', '37067', '37060', '37062', '100000000000006', '100000000000005', '100000000000002', '100000000000003', '100000000000000', '100000000000001', '100000000000020', '88888', '917571', '37070']
2013-09-17 18:19:26,862 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 1453930202572926692
2013-09-17 18:19:26,862 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:19:26,862 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 1040761259097793097
2013-09-17 18:19:26,862 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 3773718596640029167
2013-09-17 18:19:26,862 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 3031328406376546834
2013-09-17 18:19:26,863 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:19:26,863 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 7593088917891695773
2013-09-17 18:19:26,863 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:19:26,863 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 2733618491049981613
2013-09-17 18:19:26,863 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:19:26,864 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 6264955410120325901
2013-09-17 18:19:26,864 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:19:26,864 [DEBUG]  @cert_sorter.py:113 - valid entitled products: ['100000000000005', '100000000000011', '100000000000020', '37060', '27060', '37069', '37068', '37080', '37065', '37067', '88888', '37070']
2013-09-17 18:19:26,864 [DEBUG]  @cert_sorter.py:114 - expired entitled products: []
2013-09-17 18:19:26,864 [DEBUG]  @cert_sorter.py:115 - partially entitled products: []
2013-09-17 18:19:26,865 [DEBUG]  @cert_sorter.py:116 - unentitled products: ['100000000000060', '100000000000006', '1000000000000023', '100000000000002', '100000000000003', '1144', '100000000000001', '1', '917571', '100000000000000', '69', '37062']
2013-09-17 18:19:26,865 [DEBUG]  @cert_sorter.py:117 - future products: []
2013-09-17 18:19:26,865 [DEBUG]  @cert_sorter.py:118 - partial stacks: []
2013-09-17 18:19:26,865 [DEBUG]  @cert_sorter.py:119 - valid stacks: []
2013-09-17 18:19:26,865 [DEBUG]  @cert_sorter.py:106 - Sorting product and entitlement cert status for: 2013-09-17 12:49:26.865670+00:00
2013-09-17 18:19:26,865 [DEBUG]  @cert_sorter.py:160 - Installed product IDs: ['100000000000060', '1000000000000023', '1144', '100000000000011', '27060', '69', '1', '37069', '37068', '37080', '37065', '37067', '37060', '37062', '100000000000006', '100000000000005', '100000000000002', '100000000000003', '100000000000000', '100000000000001', '100000000000020', '88888', '917571', '37070']
2013-09-17 18:19:26,866 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 1453930202572926692
2013-09-17 18:19:26,866 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:19:26,866 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 1040761259097793097
2013-09-17 18:19:26,866 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 3773718596640029167
2013-09-17 18:19:26,866 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 3031328406376546834
2013-09-17 18:19:26,867 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:19:26,867 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 7593088917891695773
2013-09-17 18:19:26,867 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:19:26,867 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 2733618491049981613
2013-09-17 18:19:26,867 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:19:26,868 [DEBUG]  @cert_sorter.py:176 - Checking certificate: 6264955410120325901
2013-09-17 18:19:26,868 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:19:26,868 [DEBUG]  @cert_sorter.py:113 - valid entitled products: ['100000000000005', '100000000000011', '100000000000020', '37060', '27060', '37069', '37068', '37080', '37065', '37067', '88888', '37070']
2013-09-17 18:19:26,868 [DEBUG]  @cert_sorter.py:114 - expired entitled products: []
2013-09-17 18:19:26,868 [DEBUG]  @cert_sorter.py:115 - partially entitled products: []
2013-09-17 18:19:26,868 [DEBUG]  @cert_sorter.py:116 - unentitled products: ['100000000000060', '100000000000006', '1000000000000023', '100000000000002', '100000000000003', '1144', '100000000000001', '1', '917571', '100000000000000', '69', '37062']
2013-09-17 18:19:26,869 [DEBUG]  @cert_sorter.py:117 - future products: []
2013-09-17 18:19:26,869 [DEBUG]  @cert_sorter.py:118 - partial stacks: []
2013-09-17 18:19:26,869 [DEBUG]  @cert_sorter.py:119 - valid stacks: []
2013-09-17 18:19:26,869 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:19:26,869 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:19:26,870 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:19:26,870 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:19:26,870 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:19:26,871 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:19:26,871 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:19:26,871 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:19:26,872 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:19:26,872 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:19:26,872 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:19:26,872 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:19:26,873 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:19:26,873 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:19:26,873 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:19:26,874 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:19:26,874 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:19:26,874 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 16 covered by entitlement
2013-09-17 18:19:26,875 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement
2013-09-17 18:19:26,875 [DEBUG]  @cert_sorter.py:286 -   system has 1 sockets, 2 covered by entitlement


  
Actual results:


Expected results:


Additional info:
Comment 1 Devan Goodwin 2012-09-21 10:01:53 EDT
Ok I think I've figured out why this is. The server figures out what we need for both autosubscribe and for healing. For example the request we make to server for autosubscribe:

POST  https://192.168.1.25:8443/candlepin/consumers/fd7f384e-c983-48ca-913b-3e04912e107f/entitlements

Because the server still thinks it's 2012, this is why the system is given an expired certificate.

However the client can also specify a date in that request and if specified, the server will check compliance and repair it for that date instead of right now. This was implemented specifically for healing where we do two things, (1) fix compliance (right now), and (2) check compliance for tomorrow and get certificates for then if anything will be broken in 24 hours.

The healing requests go through with a specific date as set on the client:

POST  https://192.168.1.25:8443/candlepin/consumers/fd7f384e-c983-48ca-913b-3e04912e107f/entitlements?entitle_date=2012-09-21T13%3A55%3A42.189188%2B00%3A00

So in the autosubscribe case, the server is using it's own date and sending the client a cert it thinks is expired. In the healing case, the client is saying "heal me for this date" which the server does.

Seeing why this is happening I think everything is working as intended here, no real issue and client/server should be in sync in terms of date for any real world usage.  Going to close as notabug for now.

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