Page MenuHomePhabricator

Recurring processing failing due to "Two recurring charges within 23 days" error
Closed, ResolvedPublic

Description

We've had a wave of failmail relating to the error in the subject. Let's see if we can make this a non-blocking error and then figure out why it happened.

/var/log/process-control/recurring_smashpig_charge/recurring_smashpig_charge-20230709-222101.log                                      
2023-07-09 22:21:01,179 INFO    ===========
2023-07-09 22:21:01,179 INFO    /usr/local/bin/drush @wmff -vv cvapi job.process_smashpig_recurring time_limit_in_seconds=1620 (2517510)
2023-07-09 22:21:01,179 INFO    -----------
2023-07-09 22:21:01,312 ERROR   Loaded alias @wmff from file                                            [notice]
2023-07-09 22:21:01,312 ERROR   /etc/drush/site-aliases/aliases.drushrc.php
2023-07-09 22:21:01,345 ERROR   Executing: mysql --defaults-extra-file=/tmp/drush_NhpqiU --database=drupal --host=fundraisingdb-write.wmnet --silent  < /tmp/drush_OzYImW
2023-07-09 22:21:01,379 ERROR   Executing: mysql --defaults-extra-file=/tmp/drush_oxZEOV --database=drupal --host=fundraisingdb-write.wmnet --silent  < /tmp/drush_LMBj9T
2023-07-09 22:21:04,049 ERROR   Two recurring charges within 23 days. recurring_id: 1529945              [error]
2023-07-09 22:21:04,049 INFO    
2023-07-09 22:21:04,049 ERROR   Undefined variable: result civicrm.drush.inc:1619                       [notice]
2023-07-09 22:21:04,050 ERROR   Command dispatch complete                                               [notice]
2023-07-09 22:21:04,061 INFO    ----------- end command output

Event Timeline

jgleeson triaged this task as Unbreak Now! priority.Jul 10 2023, 10:25 AM
jgleeson moved this task from Backlog to In Progress on the Fundraising Tech - Chaos Crew board.

Change 936693 had a related patch set uploaded (by Jgleeson; author: Jgleeson):

[wikimedia/fundraising/crm@master] Skip recurring payment attempts that happenin too early.

https://gerrit.wikimedia.org/r/936693

From IRC:

13:55 <jgleeson> fr-tech. the recurring charge failmail starting over the weekend was due to us attempting to charge the donor too soon. The subscription was set up to be recharged on the 8th day of the month. However, for some reason we charged the donor on the 8th and the 29th of June so the charge attempt over the weekend tripped the built in no-charges-earlier-than-23-days-apart for THIS attempt. I'm not sure
13:55 <jgleeson> why the charge on the 29th a) happened and b)  didn't also trip the same check. I wonder if we charge it manually for some reason? cstone did you test any one off recharges with dlocal last month? 
13:59 <jgleeson> wrt fixing it, I've moved the affected donors next subscription charge out a month, so it will retry next on August 8th which should stop the current failures due to the aforementioned check. I've also pushed up a patch to skip payment attempts in future which also trip the same check. This changes the current behaviour which is to throw an exception, exiting early and preventing any other
13:59 <jgleeson> subscription charges happening. That patch is here https://gerrit.wikimedia.org/r/c/wikimedia/fundraising/crm/+/936693/

Useful SQL queries to see recurring subscriptions and previous charges:

select * from civicrm_contribution_recur where id = 1529945 \G
select * from civicrm_contribution where contribution_recur_id = 1529945 \G

\G displays the result vertically

Change 936693 merged by jenkins-bot:

[wikimedia/fundraising/crm@master] Skip recurring payment attempts which happen before 23-day window.

https://gerrit.wikimedia.org/r/936693

@jgleeson I just pushed out a patch on this -so pushing to done on the assumption that is it

XenoRyet set Final Story Points to 2.