Comment 0 for bug 597754

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.