So on the first CID we have

I did find some sign of deadlock but not on these

2024-09-25 20:54:28+0000 [info] Retrying after Database lock encountered hit on attempt 1 at query : INSERT INTO `civicrm_
contribution` (contact_id , financial_type_id , payment_instrument_id , receive_date , total_amount , `fee_amount
, net_amount` , currency , thankyou_date , source , contribution_status_id , check_number , tax_amount ) VAL
UES ( 3281034 , 9 , 4 , 20240918000000 , 600.00 , 0 , 600 , 'USD' , 20240925000000 , 'USD 600.00' , 1 , '4409193' ,

0 )

2024-09-25 20:54:32+0000 [info] Retrying after Database deadlock encountered hit on attempt 1 at query : INSERT INTO wmf_c
ontribution_extra ( gateway,gateway_txn_id,postmark_date,original_currency,original_amount,entity_id ) VALUES
( 'Engage','b5468d4146b8b0277c9a22535c11c638',20240806000000,'USD','2000.00',111994143 )

[2024-09-25T21:04:13.847199+00:00] civicrm.DEBUG: Running task: Snooze contact [] []
[2024-09-25T21:04:13.917558+00:00] civicrm.DEBUG: Running task: Processed 100 rows out of 292 [] []
2024-09-25 21:11:06+0000 [info] Retrying after Database deadlock encountered hit on attempt 1 at query : INSERT INTO wmf_c
ontribution_extra ( gateway,gateway_txn_id,postmark_date,original_currency,original_amount,entity_id ) VALUES
( 'Engage','37960ddfd52f887f1f06ee964d7c0730',20240907000000,'USD','100.00',111994628 )

looking at the 3rd one - it is the last of 89 in the set done under the connection - which suggests it crashed

select id,log_date FROM log_civicrm_contribution WHERE log_conn_id = '66f47acd79d9bKpRK';
+-----------+---------------------+

+-----------+---------------------+

+-----------+---------------------+
89 rows in set (0.002 sec)

select id, log_date FROM log_civicrm_contribution WHERE log_conn_id = '66f47b42f2d1enBGO';

select id,log_date FROM log_civicrm_contribution WHERE log_conn_id = '66f47ea664fa8KUZf';

@MDemosWMF I did some digging - I can't really conclude more than - 'let's monitor it' - I can see that a bit about what process created the contributions and I can see they were created in a process of 89 rows that finished at 2024-09-25 21:20:56 but the other processes that ALSO processed the rows started before that one finished.

I wonder if there is a possible race condition whereby one job starts while the last is still running and grabs the 'next 50 rows' but the original job is in the process of doing a row. Maybe at the start of processing a row if could be updated to 'in progress'

I've done some more pondering about this and the reason this does not happen all the time is the Queue.claimItem action should ensure the import task is only available to one process at a time. At this point it would appear the item was not correctly claimed - however, that currently has happened on one process - so I guess the question is whether it will happen again. If so there are 2 sides to this

1. can we figure out why claimItem did not work? Perhaps the siteBusy check was slow & that allows 2 jobs to grab the item at once?
2. we could probably harden the import code to cope if it doesn't - this would allow us to run imports in paralell but I suspect that would lead to more deadlocks.

Possibly connected to this is that it takes a long time for the files to process so we sometimes open the list of donations and select them to push through to import a page at a time. Would be great to increase the speed of the import like it was on the drupal platform! Can we look into that?

For now Ellen and I will not push through the import and just let it run in the background to avoid this. We will monitor, but I think the speed of the import would be great to look into and see if it's possible for it to process a bit quicker especially when volume is high during busy season.

@MDemosWMF we can look at whether there are are any bottlenecks in the code we can improve (maybe add a phab) - but I suspect the slow down is that we have set the import to pause when the server is under high load to reduce deadlocks both within the import and in our queue processing. If the drupal imports are faster under load it's probably because they are slowing down the main queue to achieve that

Thanks Eileen - I opened a new phab for that - T376337. I think it's worth taking a look and we will try to monitor speeds as best we can on our end!

@Eileenmcnaughton Wanted to update you that we ran the Engage imports today after your patch went out and there were no duplicate errors! Looks like some records have gone into the group you created as intended. There was only 1 DB deadlock that was easily reimported. Here are @Elbar53 's notes:

Wiki Organization - imported instantly and no errors
Wiki Individual (193 items) - import took 35 min and 1 error. Error was deadlock so it imported instantly
Endowment individual - import took 20 min and no errors

Things have definitely improved! Thank you!

@MDemosWMF you will work with @SHust on managing that group?

Those individual ones do seem slow

@SHust @krobinson Let me know if this works for your team! The idea is that dupes will funnel into this group after import and can be worked on by DR.

@Eileenmcnaughton I thought so too - and likely will get slower with higher volumes in the files.

@MDemosWMF the admin team can support this group dedupe, how often do imports happen?

@SHust Amazing! Thank you DR admin team. There are various weekly imports happening throughout the week based on when data entry is complete.