Activity log for bug #597754

Date Who What changed Old value New value Message
2010-06-23 15:59:27 Brad Crittenden bug added bug
2010-06-23 15:59:39 Brad Crittenden visibility public private
2010-06-23 16:00:37 Brad Crittenden visibility private public
2010-06-23 16:01:01 Brad Crittenden bug task added canonical-isd
2010-06-23 16:01:13 Brad Crittenden visibility public private
2010-06-23 16:06:03 Brad Crittenden bug added subscriber Joey Stanford
2010-06-23 17:12:20 Ursula Junque tags oops
2010-06-23 17:13:20 Ursula Junque description The process that imports newly purchased items from the shop and creates them in Salesforce was converted last Friday. Since then Launchpad users have complained about errors stating ""The voucher could not be redeemed at this time." 2010-06-23 14:38:50+0000 [HTTPChannel,43,91.189.90.221] Getting vouchers for openid xxxx 2010-06-23 14:38:50+0000 [HTTPChannel,43,91.189.90.221] INFO: Starting getVouchers 2010-06-23 14:38:51+0000 [HTTPChannel,43,91.189.90.221] INFO: Finished getVouchers 2010-06-23 14:38:51+0000 [HTTPChannel,43,91.189.90.221] Got 1 vouchers for openid xxxx 2010-06-23 14:38:51+0000 [HTTPChannel,43,91.189.90.221] 91.189.90.221 - - [23/Jun/2010:14:38:50 +0000] "POST /RPC2 HTTP/1.0" 200 745 "-" "xmlrpclib.py/1.0.1 (by www.pythonware.com)" 2010-06-23 14:38:51+0000 [HTTPChannel,44,91.189.90.221] INFO: Starting getVouchers 2010-06-23 14:38:52+0000 [HTTPChannel,44,91.189.90.221] INFO: Finished getVouchers 2010-06-23 14:38:54+0000 [HTTPChannel,44,91.189.90.221] Unhandled Error Traceback (most recent call last): Failure: canonical.salesforce.voucher.VoucherNotActiveError: Voucher LPCSB12-9xxxx is not an active asset 2010-06-23 14:38:54+0000 [HTTPChannel,44,91.189.90.221] Traceback (most recent call last): File "/srv/salesforce/production/production/sfi-salesforce/canonical/salesforce/sfi_proxy/svcutil.py", line 74, in callImpl call_response = method_ref(*args) File "/srv/salesforce/production/production/sfi-salesforce/canonical/salesforce/sfi_proxy/svc_lpsub.py", line 163, in redeemVoucher success = voucher.redeem(redeemer_openid) File "/srv/salesforce/production/production/sfi-salesforce/canonical/salesforce/voucher.py", line 98, in redeem raise VoucherNotActiveError(msg) VoucherNotActiveError: Voucher LPCSB12-9xxxx is not an active asset According to JamesJ the new shop process is the same as the old. It loops through new assets and creates them in SF. Later it loops over those new assets and activates them. The failure is likely occurring because the request for the voucher happens between creation and activation. While the process may be the same the timing has changed. The shop import is now being run every 30 minutes where it was run at least every 15 minutes before. Perhaps the processing of more items less frequently has increased the time between creation and activation that is now causing the errors to occur more frequently. I do see that the same error did occur once in April. We have seen four such errors since Friday. The process that imports newly purchased items from the shop and creates them in Salesforce was converted last Friday. Since then Launchpad users have complained about errors stating ""The voucher could not be redeemed at this time." 2010-06-23 14:38:50+0000 [HTTPChannel,43,91.189.90.221] Getting vouchers for openid xxxx 2010-06-23 14:38:50+0000 [HTTPChannel,43,91.189.90.221] INFO: Starting getVouchers 2010-06-23 14:38:51+0000 [HTTPChannel,43,91.189.90.221] INFO: Finished getVouchers 2010-06-23 14:38:51+0000 [HTTPChannel,43,91.189.90.221] Got 1 vouchers for openid xxxx 2010-06-23 14:38:51+0000 [HTTPChannel,43,91.189.90.221] 91.189.90.221 - - [23/Jun/2010:14:38:50 +0000] "POST /RPC2 HTTP/1.0" 200 745 "-" "xmlrpclib.py/1.0.1 (by www.pythonware.com)" 2010-06-23 14:38:51+0000 [HTTPChannel,44,91.189.90.221] INFO: Starting getVouchers 2010-06-23 14:38:52+0000 [HTTPChannel,44,91.189.90.221] INFO: Finished getVouchers 2010-06-23 14:38:54+0000 [HTTPChannel,44,91.189.90.221] Unhandled Error         Traceback (most recent call last):         Failure: canonical.salesforce.voucher.VoucherNotActiveError: Voucher LPCSB12-9xxxx is not an active asset 2010-06-23 14:38:54+0000 [HTTPChannel,44,91.189.90.221] Traceback (most recent call last):           File "/srv/salesforce/production/production/sfi-salesforce/canonical/salesforce/sfi_proxy/svcutil.py", line 74, in callImpl             call_response = method_ref(*args)           File "/srv/salesforce/production/production/sfi-salesforce/canonical/salesforce/sfi_proxy/svc_lpsub.py", line 163, in redeemVoucher             success = voucher.redeem(redeemer_openid)           File "/srv/salesforce/production/production/sfi-salesforce/canonical/salesforce/voucher.py", line 98, in redeem             raise VoucherNotActiveError(msg)         VoucherNotActiveError: Voucher LPCSB12-9xxxx is not an active asset According to JamesJ the new shop process is the same as the old. It loops through new assets and creates them in SF. Later it loops over those new assets and activates them. The failure is likely occurring because the request for the voucher happens between creation and activation. While the process may be the same the timing has changed. The shop import is now being run every 30 minutes where it was run at least every 15 minutes before. Perhaps the processing of more items less frequently has increased the time between creation and activation that is now causing the errors to occur more frequently. I do see that the same error did occur once in April. We have seen four such errors since Friday. Related OOPS: OOPS-1633H1081, OOPS-1633O1095
2010-06-23 17:44:53 Brad Crittenden launchpad-registry: status New Triaged
2010-06-23 17:45:05 Brad Crittenden launchpad-registry: importance Undecided Low
2010-06-29 20:49:28 Brad Crittenden bug added subscriber Henrik Nilsen Omma
2010-07-01 08:55:27 Neil Messenbird affects canonical-isd canonical-salesforce
2010-07-01 08:57:28 Neil Messenbird canonical-salesforce: importance Undecided Medium
2010-07-01 08:57:28 Neil Messenbird canonical-salesforce: status New Triaged
2010-07-01 08:57:28 Neil Messenbird canonical-salesforce: milestone 10-07
2010-07-01 08:57:28 Neil Messenbird canonical-salesforce: assignee Neil Messenbird (neil-messenbird)
2010-07-03 01:56:22 Martin Albisetti removed subscriber Martin Albisetti
2010-07-03 09:50:07 Brad Crittenden launchpad-registry: milestone 10.07
2010-07-03 10:03:16 Launchpad Janitor branch linked lp:~bac/launchpad/bug-597754
2010-07-06 17:24:14 Curtis Hovey launchpad-registry: milestone 10.07 10.08
2010-07-08 10:57:45 Neil Messenbird canonical-salesforce: status Triaged In Progress
2010-07-10 07:48:02 Ursula Junque launchpad-registry: assignee Brad Crittenden (bac)
2010-07-10 07:48:04 Ursula Junque tags oops oops qa-needstesting
2010-07-10 07:48:05 Ursula Junque launchpad-registry: status Triaged Fix Committed
2010-07-12 08:44:39 Neil Messenbird canonical-salesforce: assignee Neil Messenbird (neil-messenbird) James Jesudason (jamesj)
2010-07-12 10:05:13 Brad Crittenden tags oops qa-needstesting oops qa-bad
2010-07-14 08:03:55 Brad Crittenden tags oops qa-bad oops qa-ok
2010-07-27 13:08:34 Neil Messenbird canonical-salesforce: status In Progress Fix Released
2010-08-12 14:29:23 Curtis Hovey launchpad-registry: status Fix Committed Fix Released
2011-10-19 19:07:47 Curtis Hovey removed subscriber alejandro
2011-10-19 19:08:57 Curtis Hovey visibility private public
2011-10-25 13:45:44 Curtis Hovey tags lp-registry oops qa-ok oops projects qa-ok salesforce