Bug 737841 - Rhsm prints mktime argument out of range when listing subscriptions
Summary: Rhsm prints mktime argument out of range when listing subscriptions
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 6
Classification: Red Hat
Component: subscription-manager
Version: 6.3
Hardware: Unspecified
OS: Unspecified
urgent
urgent
Target Milestone: rc
: 6.3
Assignee: Bryan Kearney
QA Contact: IDM QE LIST
URL:
Whiteboard:
Depends On:
Blocks: 738066
TreeView+ depends on / blocked
 
Reported: 2011-09-13 08:52 UTC by Lukas Zapletal
Modified: 2012-06-20 13:03 UTC (History)
3 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2012-06-20 13:03:15 UTC


Attachments (Terms of Use)


Links
System ID Priority Status Summary Last Updated
Red Hat Product Errata RHBA-2012:0804 normal SHIPPED_LIVE subscription-manager bug fix and enhancement update 2012-06-19 19:51:31 UTC

Description Lukas Zapletal 2011-09-13 08:52:17 UTC
Description of problem:


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

$ rpm -q candlepin pulp subscription-manager python-rhsm
candlepin-0.4.10-1.fc15.noarch
pulp-0.0.223-4.fc15.noarch
subscription-manager-0.96.9-1.git.1.983fb44.fc15.i686
python-rhsm-0.96.11-1.git.6.0507fb7.fc15.noarch

How reproducible:

[lzap@lzapx src]$ sudo subscription-manager list --available
mktime argument out of range

2011-09-13 10:36:30,240 [DEBUG]  @connection.py:218 - Response status: 200
2011-09-13 10:36:30,242 [ERROR]  @managercli.py:63 - exception caught in subscription-manager
2011-09-13 10:36:30,242 [ERROR]  @managercli.py:64 - mktime argument out of range
Traceback (most recent call last):
  File "/usr/sbin/subscription-manager", line 78, in <module>
    sys.exit(abs(main() or 0))
  File "/usr/sbin/subscription-manager", line 69, in main
    return managercli.CLI().main()
  File "/usr/share/rhsm/subscription_manager/managercli.py", line 1287, in main
    cmd.main()
  File "/usr/share/rhsm/subscription_manager/managercli.py", line 222, in main
    self._do_command()
  File "/usr/share/rhsm/subscription_manager/managercli.py", line 1152, in _do_command
    self.facts, self.options.all, on_date)
  File "/usr/share/rhsm/subscription_manager/managerlib.py", line 444, in getAvailableEntitlements
    d['endDate'] = formatDate(parseDate(d['endDate']))
  File "/usr/share/rhsm/subscription_manager/managerlib.py", line 796, in parseDate
    posix_time = xml.utils.iso8601.parse(date)
  File "/usr/lib/python2.7/site-packages/_xmlplus/utils/iso8601.py", line 24, in parse
    return time.mktime(gmt) + __extract_tzd(m) - time.timezone
OverflowError: mktime argument out of range

Comment 1 Lukas Zapletal 2011-09-13 10:19:19 UTC
Hmmm looks like a bug in CP or RHSM because Katello is proxying this request. My candlepin returned this:


Sep 13 12:13:33 [http-8443-1] DEBUG org.fedoraproject.candlepin.servlet.filter.logging.LoggingFilter - 
====Response====
  Status: 200
  Content-type: application/json
====Response====
Sep 13 12:13:33 [http-8443-1] DEBUG org.fedoraproject.candlepin.servlet.filter.logging.LoggingFilter - ====ResponseBody====
Sep 13 12:13:33 [http-8443-1] DEBUG org.fedoraproject.candlepin.servlet.filter.logging.LoggingFilter - [{"id":"ff8080813261df3b013261dfc8950004","attributes":[],"owner":{"href":"/owners/ACME_Corporation","id":"ff8080813261df3b013261df64290001","key":"ACME_Corporation","displayName":"ACME_Corporation"},"providedProducts":[],"endDate":"2041-09-05T00:00:00.000+0000","startDate":"2011-09-13T00:00:00.000+0000","productName":"ypd_c0543","contractNumber":"","accountNumber":"","quantity":-1,"productId":"1315902047576","subscriptionId":"ff8080813261df3b013261dfc6090003","consumed":0,"sourceEntitlement":null,"href":"/pools/ff8080813261df3b013261dfc8950004","activeSubscription":true,"restrictedToUsername":null,"productAttributes":[],"updated":"2011-09-13T08:20:48.405+0000","created":"2011-09-13T08:20:48.405+0000"}]

Reformatted:

{
  "id": "ff8080813261df3b013261dfc8950004",
  "attributes": [

  ],
  "owner": {
    "href": "/owners/ACME_Corporation",
    "id": "ff8080813261df3b013261df64290001",
    "key": "ACME_Corporation",
    "displayName": "ACME_Corporation"
  },
  "providedProducts": [

  ],
  "endDate": "2041-09-05T00:00:00.000+0000",
  "startDate": "2011-09-13T00:00:00.000+0000",
  "productName": "ypd_c0543",
  "contractNumber": "",
  "accountNumber": "",
  "quantity": -1,
  "productId": "1315902047576",
  "subscriptionId": "ff8080813261df3b013261dfc6090003",
  "consumed": 0,
  "sourceEntitlement": null,
  "href": "/pools/ff8080813261df3b013261dfc8950004",
  "activeSubscription": true,
  "restrictedToUsername": null,
  "productAttributes": [

  ],
  "updated": "2011-09-13T08:20:48.405+0000",
  "created": "2011-09-13T08:20:48.405+0000"
}

as the line in rhsm is this one (managerlib.py:444):

        d['endDate'] = formatDate(parseDate(d['endDate']))

I guess the issue is with the endDate value "2041-09-05T00:00:00.000+0000"

Comment 2 Lukas Zapletal 2011-09-13 10:26:25 UTC
Btw this is the import file I had when I saw this error:

http://git.fedorahosted.org/git/?p=katello.git;a=tree;f=cli/test-system;h=960a0662682b4c284b2e39d44c263f06255e018b;hb=HEAD

(see the zip file). Changing product to "Entitlements", this is not Katello issue probably.

Comment 3 Lukas Zapletal 2011-09-14 14:39:55 UTC
BLOCKER for Katello. Could you guys look on it please? Thanks!

Comment 5 Devan Goodwin 2011-09-14 16:38:15 UTC
The import.zip file in the git link above does not appear to be involved, this loads fine in candlepin and subscription-manager can list --available without issues. It also does not seem to contain anything which expires in 2041.

lzap believes the subscription in question is a yum product defined in katello. The subscription json going to the client looks like:

Sending GET request to Candlepin: /owners/org_rhsm_3e66d7/pools?consumer=c11c1e9b-52de-46c3-8ec5-4a9e7a407290&listall=true
[{"id":"ff80808132675a060132688502eb0181","attributes":[],"owner":{"href":"/owners/org_rhsm_3e66d7","id":"ff80808132675a0601326884daca017e","key":"org_rhsm_3e66d7","displayName":"org_rhsm_3e66d7"},"providedProducts":[],"endDate":"2041-09-06T00:00:00.000+0000","startDate":"2011-09-14T00:00:00.000+0000","productName":"yum_product_3e66d7","contractNumber":"","accountNumber":"","quantity":-1,"productId":"1316013539685","subscriptionId":"ff80808132675a060132688501f20180","consumed":0,"sourceEntitlement":null,"href":"/pools/ff80808132675a060132688502eb0181","activeSubscription":true,"restrictedToUsername":null,"productAttributes":[],"updated":"2011-09-14T15:19:00.075+0000","created":"2011-09-14T15:19:00.075+0000"}]


The endDate does seem to be the problem, but again I cannot reproduce via a test for parseDate with this value:

parseDate("2041-09-06T00:00:00.000+0000")

lzap's system is in EST+2 timezone, I've tried setting my system to this and several others and I still cannot reproduce.

Still investigating.

Comment 6 Devan Goodwin 2011-09-14 16:47:46 UTC
From the mktime docs: 

If the input value cannot be represented as a valid time, either OverflowError or ValueError will be raised (which depends on whether the invalid value is caught by Python or the underlying C libraries). The earliest date for which it can generate a time is platform-dependent.

I'm on x86_65 and can't reproduce all the way up to year 9999. Any chance this is 32-bit and a smaller year fixes the issue? (can be edited in cp_pool table in db)

Comment 7 Devan Goodwin 2011-09-14 17:11:37 UTC
Script to try and reproduce (works fine on my system):

#!/usr/bin/env python
import sys
sys.path.insert(0, '/usr/share/rhsm')
from subscription_manager.managerlib import parseDate

print parseDate("2041-09-06T00:00:00.000+0000")

Comment 8 Devan Goodwin 2011-09-14 17:24:52 UTC
Reproduced on an i686 guest, set the year to anything less than 2038 and it will work, so we are quite likely dealing with: http://en.wikipedia.org/wiki/Year_2038_problem

Question is, what can we do about it?

Comment 9 Lukas Zapletal 2011-09-14 19:48:26 UTC
I am sorry I did not tell you that my client was i686.

Is there some quick fix that would unblock me for now?

Comment 10 Devan Goodwin 2011-09-16 16:51:30 UTC
Fixed in subscription-manager.git master branch: a0f3d37af5f0effba574751ec020ccac437a01c3

We're catching this overflow and instead returning a safe date in 2038. Such a system is obviously in big trouble come this date, but we can now keep them operational now if they somehow got a subscription with an date in this range.

Comment 11 Devan Goodwin 2011-09-16 16:52:40 UTC
QE: to reproduce, you would need an i686 system plus a subscription with start or end date beyond Feb 2038.

Using the script above in comment #7 however might be easier, just run on an i686 system.

Comment 12 J.C. Molet 2012-04-16 19:49:39 UTC
Testing in version:
subscription-manager-0.99.14-1.el6.i686

[root@cypher ~]# uname -m
i686
[root@cypher ~]# cat bugtest.py 
#!/usr/bin/env python
import sys
sys.path.insert(0, '/usr/share/rhsm')
from subscription_manager.managerlib import parseDate

print parseDate("2041-09-06T00:00:00.000+0000")


[root@cypher ~]# python bugtest.py 
No handlers could be found for logger "rhsm-app.subscription_manager.managerlib"
2038-01-01 00:00:00+00:00

^^ 
This seems to take larger dates and knocks them back to the max year (exactly as described).  There are no tracebacks.

Marking Verified

Comment 14 errata-xmlrpc 2012-06-20 13:03:15 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-2012-0804.html


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