Page MenuHomePhabricator

CiviCRM log is showing errors relating to importing bounces
Closed, ResolvedPublic2 Estimated Story Points

Description

I spotted errors like this in the log

"SELECT count(civicrm_mailing_event_bounce.id) as bounces,

            civicrm_mailing_bounce_type.hold_threshold as threshold
FROM        civicrm_mailing_event_bounce
INNER JOIN  civicrm_mailing_bounce_type
        ON  civicrm_mailing_event_bounce.bounce_type_id = civicrm_mailing_bounce_type.id
INNER JOIN  civicrm_mailing_event_queue
        ON  civicrm_mailing_event_bounce.event_queue_id = civicrm_mailing_event_queue.id
INNER JOIN  civicrm_email
        ON  civicrm_mailing_event_queue.email_id = civicrm_email.id
WHERE       civicrm_email.id = 
    AND     (civicrm_email.reset_date IS NULL
        OR  civicrm_mailing_event_bounce.time_stamp >= civicrm_email.reset_date)
GROUP BY    civicrm_mailing_event_bounce.bounce_type_id
ORDER BY    threshold, bounces desc [nativecode=1064 ** You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near 'AND     (civicrm_email.reset_date IS NULL
        OR  civicrm_ma' at line 11]"

I believe they are triggered by a jenkins drush job

Event Timeline

I wonder if this is what happens when the bounce processing tries to record a bounce without Civi's VERP headers.

I think it only processes them when the headers are there - but have pushed a patch to try to get some details from it when it fails

I've managed to find out when this is happening.

When a bounce is received to an email that has been deleted we get a fatal error.

Here is the sequence of events

  1. person makes donation
  2. we send a thank you message
  3. the person makes another donation, creating another donor record
  4. the 2 donors are merged, resulting in the first email being deleted and the email_id in the civicrm_mailing_event_queue table being set to null
  5. the bounce is received - it can't be matched as the email_id is deleted & throws an error

The impact here turns out to be very small - because the second instance donor has also been sent an email and when it bounces they are updated.

It seems reasonable & sensible to fix the code to fail without a mysql error and perhaps tidy up the code a little in core.

We could also consider updating the email_id in the civicrm_mailing_event_queue table where the contact is deleted by merge. I hesitate a little on this as I'm not sure about the return on effort here. I would make sense when already in that code possibly & I could log a ticket or just 'keep it in mind' for when I'm in that code.

Lastly - it seems most/all the contacts involved in this particular sequence are fraudsters. I have sent @MBeat33 the output of this query. @MBeat33 - please log a follow up ticket if you think we should try to leverage this to help you identify fraudsters

SELECT c.id, c.display_name, email.email, c.created_date, c.modified_date FROM civicrm_mailing_event_queue e LEFT JOIN civicrm_contact c ON c.id = e.contact_id LEFT JOIN civicrm_email email ON email.contact_id = c.id AND email.is_primary = 1 WHERE email_id IS NULL AND email.on_hold = 1 GROUP BY e.contact_id ORDER BY c.created_date DESC  LIMIT 200;

So, I think in summary - I don't think this has a significant impact on us. It may be worth taking some of the follow up actions above but I will resolve this ticket by making CiviCRM handle a null email_id without a fatal error.

Seems fine to just shut up the error. Somewhere down the line, it would be nice if core recognized that all email records with the same address should be considered equivalent in the process of counting bounces and marking on_hold.

Many thanks, @Eileenmcnaughton that's a neat query. We'd have likely found the fraudsters through the usual scans, and though I won't make a followup ticket it never hurts to have another tool in the kit.

Eileenmcnaughton set the point value for this task to 2.