This seems to be affecting a small number of donors. For example, cid 10448807 had a recurring processed on Jan 15. At that point, the recurring was marked as failing and so the next scheduled contribution date was set to 24 hours in the future. That second donation was processed 24 hours later, resetting the recurring status to In Progress as normal. Net result is the donor was charged twice in two days for their recurring donation.
Relevant log entries:
Jan 15 12:44:51 civi1002 civicrm.wmf[243921]: civicrm.wmf.INFO: Error: 1000011 invoice_id:238491027.4 [] []
civi1002 SmashPig-Gravy-QueueJobRunner: SPCID-1878534593 | (corr_id-gravy-238491027.4) Could not find donor details for authorization Reference '5d625e9a-4c9b-459a-acaf-bc41fd70502d' and order ID '238491027.4'. | |
Raw response: {"type":"error","code":"server_error","status":500,"message":"Request could not be processed","details":[]}
Looks like this is coming from the catch in CRM_Core_Payment_SmashPigRecurringProcessor::run, which is covering a lot of code. Not sure how we want to handle this specific case, but in general maybe we shouldn't be moving the next scheduled date to tomorrow for exceptions that happen anywhere in there, as they could potentially be other issues?
Other affected cids from the first half of January: 11387385, 69254563, 48042218, 33996709, 68966936, 40702630, 12852049
There also appears to be a worse related issue, where the recurring is cancelled even though the actual contributions did not fail and we charged them twice, see cids 29466083, 69242387, 69258334
Many of these appear to have happened with Venmo, particularly on Jan 4, but they aren't exclusively Venmo.
SK used to find these (adjusting dates).