CRM-17880 Schedule reminders not sent if there is an entry in the action_log with same action_schedule_id

Is this a regression of CRM-15461?

Actually no, it was introduced with https://issues.civicrm.org/jira/browse/CRM-15728. I've been monitoring a site since the first of the year, after repeat was turned off, and found every once and awhile someone would not receive their reminder and in every case it was because there was already an entry in the action log with that reminder id.

Edit: Actually it wasn't introduced with that issue (apologies). Though, the second PR changes the second query that was introduced in the issue I linked. However, Chris, the issue you linked may apply. But mostly I think the issue I linked didn't completely correct the problem it was trying to correct.

For the record, we've observed the same issue. Scheduled reminders only being sent out once. Upgrading to 4.7 is not an option at this stage.

This is a major issue as memberships will be lost due to no reminders being sent out.

Our plan is to create a CiviCRM extension to clear out the civicrm_action_log on a daily basis, forcing reminders to be sent.

I can't emphasize enough the value of adding unit tests on this code. We have historically had some fixes introduce other errors so tests lock in the fixes.

Note that the membership reminder schedule will not repeat unless you set it to be repeating. This is kind of confusing and the description of this ticket does not make it clear whether that has been set.

In 4.7 the code is

public function build() {
$this->buildRelFirstPass();

if ($this->prepareAddlFilter('c.id'))

if ($this->actionSchedule->is_repeat)

And the query you gave above comes from buildAddlFirstPass()

In the vein of the reminder schedule being repeating only when "Repeat" is checked, there may be a fairly major documentation issue. It is definitely not clear what the "Repeat" checkbox does in the Membership context (or any context, to be honest), and I've found no mention of repeat being needed for that situation in:

https://book.civicrm.org/user/current/email/scheduled-reminders/
https://book.civicrm.org/user/current/membership/renewals/
http://docs.civicrm.org/user/en/4.6/membership/renewals/#renewal-reminders

And explicit instructions to not select "Repeat" with no explanation given on:

http://docs.civicrm.org/user/en/4.6/email/scheduled-reminders/#using-scheduled-reminders-for-memberships

We also interpreted the outcome of #CRM-15728 and #CRM-15461 to indicate that enabling repetition for these reminders was no longer necessary.

Hmm, I can't find anything to support my reading of the code in the test suite

https://github.com/civicrm/civicrm-core/blob/fa938177202b0ef376e00b6cbe8be3814ef1cd28/tests/phpunit/CRM/Core/BAO/ActionScheduleTest.php#L32-32

So, let's assume I was wrong!

All good Eileen

Keen to get some more eyeballs on this issue to at least raise awareness, I think this is a real nasty gotcha.

Thanks for all the posts here, its good to see this issue is being discussed. It's been off my radar for a while but it's back because we are looking at updating our sites to 4.7.6 and scheduled reminders need to work before we can update several of our sites.

I would like to take some time to ask questions and make some comments on how the current code is working. I hope this is the appropriate place for this, please let me know if there is a better place. If I need to be more clear about where in the code I am referring, please let me know this as well.

To start, I am testing reminders setup to send 30 and 15 days before the membership end date. Also, these members received reminders last year. Repeat was not set. Current Drupal, Civi 4.7.6.

Looking at the \Civi\ActionSchedule\RecipientBuilder.php buildRelFirstPass() function, first there is a check to see if the membership end date changed. With the above conditions, this query wasn't run because the membership end date equals the reference date.

After this, again with the above conditions the if statement on line 207 evaluates as true and the $firstQuery is generated and run. None of the other conditions are met in the build() function so the query that is generated here is the one used. I am only interested in the WHERE clause (because I see no issues with the rest of the query):

WHERE (e.contribution_recur_id IS NOT NULL) AND (e.membership_type_id IN ("1", "4", "2", "3")) AND (( e.is_override IS NULL OR e.is_override = 0 )) AND (e.status_id IN (1, 2, 3, 4)) AND (reminder.id IS NULL) AND ('20160419134945' >= DATE_SUB(e.end_date, INTERVAL 15 day)) AND (DATE_SUB(20160419134945, INTERVAL 1 DAY ) <= DATE_SUB(e.end_date, INTERVAL 15 day))

Questions/Comments:
1) While the comments in this file do indicate that the processing assumes there have been no previous reminders sent, there isn't anything that checks if they have been. Is this where the repeat is supposed to be used to get them sent again? If so, I think the previous posts address the repeat. I think it should be removed all together, but I don't know what other reasons there might be for it to be in. If there are, I would welcome more information.

2) The contribution id shouldn't be in the query at all. Our experience has been that the reminders are needed for memberships that are not auto-renew and those that are auto-renew don't need reminders because the payment processors automatically bill them when appropriate.

3) reminder.id IS NULL - this is the part that enforces the "never been sent before" criterion. When I made a temporary fix to v4.6.9, I removed this part of the query (via custom php changes). Its been working great since then. But it does make sense if the intent was to use repeat to create new reminders when there have already been reminders sent.

I can understand that duplicate reminders need to be avoided. But if scheduled reminders are setup to go out once a day so that the check for 30, 15, whatever days before the end of the membership is run only once and if the membership end date is updated when its renewed, then there won't be any repeats. And if the membership expires, they still aren't sent.

Perhaps another use of the reference date? If the reference date is updated when the membership is renewed, then the memberships that have received previous reminders would have last years reference date. Then the first query in buildRelFirstPass() could be used to update both previously updated memberships along with the ones with changed end dates.

Like I said in my original post, I am not aware of everything at play here and may be over simplifying things. But it honestly seems like a simple function.

I am available to help solve this issue, as I said, we have a vested interest in this function working correctly and reliably.

I just tagged this 'reminders' so we can tag similar issues that - ie https://issues.civicrm.org/jira/browse/CRM-18236

I find this logic so incredibly forgettable Everytime I get my head around it it disolves out of my head - we should probably prioritise a documentation issue on it at the sprint

We have created a CiviCRM extension to clear out the civicrm_action_log on a daily basis, forcing reminders to be sent.

So far this is working for us. Happy to share it if you have a similar need.

Yes, we have a similar need and if you are willing/able to share that would be awesome. Thanks!

Closing this for now since the solutions are headed in the direction of documentation and extensions rather than core patches. Reopen if needed.

I do not think this issue should be closed. The extension is a band-aid. And if that is all it takes, then it should be implemented in the code.

If the repeat is taken out of it all together then it is a simple thing to implement the custom change I made originally and described in my more recent post. My change ignores what's already in the log which is essentially the same thing as clearing it. I can submit a pull request if that would help.

I've done some more digging in the code & the way it works is that in 4.6 the end_date is stored into the action_log table as the reference_date

The code here adds contacts with outdated reference dates to the action_log

https://github.com/eileenmcnaughton/civicrm-core/blob/sched_reminder/CRM/Core/BAO/ActionSchedule.php#L1278

And the bug I have recently been digging into is CRM-18236 fix for double send of reminders - where that code had been sending out too many under a date change scenario.

Anyway, the long & the short of it is that IF a membership has an end_date that changes it becomes eligible for another email to go out based on the changed end_date and that IS happening and there are tests that fail if it does not.

However, that doesn't mean it's happening without error in all circumstances. The fix agileware provided was really the only one that worked under 4.5 or earlier. In 4.6 I can vouch for the fact that scheduled reminders DO go out if there is an entry in the action_log with the same action_schedule_id if the relevant reference_date has changed. So, I think it's correct to close this.

But, anecdotally I think there are still some circumstances where the logic is not working and we need to get some more data about those cases & why & log a specific issue - is the reference_date clause failing or being skipped?

OK I have something else on this. Someone reported it to me & the emails were not going out according to the rules - ie. there was already a row in the action_log table with a reference_date that matched the current membership end date... but I think those rows pre-dated the upgrade to 4.6 & the reference_date was populated during the upgrade - seemingly incorrectly

To find dubious entries - ie the long date gap is suspicious

SELECT DATEDIFF(reference_date, action_date_time) as diff, id,
reference_date, action_date_time, action_schedule_id
FROM civicrm_action_log a

ORDER By DATEDIFF(reference_date, action_date_time) DESC

LIMIT 50

Eileen, can you explain more about the reference_date being populated during the 4.6 upgrade incorrectly? What would be correct? It was exactly that the rows predated the 4.6 upgrade and the reference_date was changed during the upgrade for one of our sites. Thanks.

The reference date should be the relevant date (e.g membership end_date) at the date the reminder went out. So, no more reminders should go out if the reference_date is the same. But if it's different then they should go. It seems that in the upgrade they were set to the current end_date and that was inappropriate

I encountered this today, thank you to both Eileen and Agileware for diagnosing and providing a solution respectively!

I think I am experiencing what Eileen described 26/Apr - even after updating to 4.7, older members are not receiving renewal reminders they already received in their previous membership.

It would be nice to have a solution for that. From what I read, I'm unclear if I could

• clear out the civicrm_action_log, once
• install an extension to do that .. daily
• update or delete particular rows or columns in the action log (like, based on the datediff)
• upgrade to 4.7.11 or wait for a future version (would a future update recheck the action log ?)

I think clearing out the action_log once is pretty OK for membership schedules - the only risk I think is that mailings that already went out today might go out again in the next run today.

FYI: Public repo with our extension to workaround this problem is available here, https://bitbucket.org/agileware/au.com.agileware.removeactionlog

This persists as an issue, and deleting the action log table periodically is not a suitable fix.

Torrance - can you confirm it persists in latest 4.7, as opposed to just 4.6

This is with 4.7, yes. Whether it's a holdover from 4.6 I can't comment.

@Torrance, as mentioned above, this may be due to a bug in the update script from 4.6 to 4.7 . But I, too, am facing this problem again exactly one year after I cleaned up the action log (in 4.7.22). 

Can someone confirm this is totally safe:

DELETE FROM civicrm_action_log WHERE action_date_time  <= NOW() - INTERVAL 1 DAY

I don't like it, throws away a lot of history. Last year, I was more cautious in my cleanup activities.

Doesn't this have sideeffects, like, break the contact activity history in the GUI ? Or anything else ?

Actually, in the last year we've done a minor upgrade from 4.7.10 to 4.7.22, and it looks like existing records in the action log have had their reference date changed again at some point. I'm not sure if the update did this or what else might have. It looks like the reference date was again set to the current membership end date - so they are now mostly in the future. 

One existing example record from a backup that had a date diff of 61, which matches a reminder two months ahead of the membership end date, now  has a date diff of 770 days, which is nearly exactly 2 years and 2 months. Only the reference date has changed.

I believe the only risks / issues when deleting from action_log are

1) if you delete logs that relate to emails that have gone out today then those will resend.

2) people doing forensic digging through that table will not see them (they are not in the UI)

Just an note for completeness: the issues we have this year with membership reminders after all seem not to be related to the action_log. We don't know what it is yet.

As mentioned, there were indeed strange reference dates in the action log. It seemed however as if the reminders seemed to ignore them. That is, reminders of a specific membership and entity_id that were already in the action log with a reference date in the future and an action date in the past, were being sent again this year at the right time - seemingly ignoring the broken entries.

Other reminders however, that have no entry in the action_log whatsoever, are not being sent.  It's very annoying, but alltogether probably not related to this bug.

Experienced the same issue - some reminders stopped being sent.  Didn't see any issues in action log either (i.e. duplicate IDs).    Our issue started in July IMMEDIATELY  after upgrading to 4.7.22.  (didn't realize it until recently) Recreating one of the reminders restarted those so workaround may be to delete and recreate a reminder.  If you try this please report back.

This ticket is a bit stale; happy to move it somewhere else if appropriate. I've searched gitlab and don't see anything related to this; StackExchange brought me here.

We've had missing reminder emails for months on CiviCRM 4.7.31 on top of WordPress 4.9.5, and it largely - but not completely - matches the patterns above,

In every case I can find when looking in action_log, the same date has the same activity_id for some other user, though I've found enough cases of the same activity_id on the same day that makes it not the same issue.

I cannot find any pattern here: the missing emails appear to be random, it's not a case of a reminder being configured wrong or (I don't think) a user being configured wrong: a missing email will show up correctly for the next reminder in the list.

We have not tried cleaning out the action_log yet, in part because we're not sure this is the same issue and don't want to blow our history if that's not the issue.

Steve - there is a big move away from JIRA going on so best if you create a ticket in GitLab if you haven't already, and link to this

Has this been fixed yet? It's now well over two years old, and if scheduled reminders aren't working for membership renewals after the first time out (probably the major use of the scheduled reminder functionality), it sort of breaks the whole point of having scheduled reminders in the first place. I'm seeing what looks like this problems on a couple of sites that I look after, and having to manually organise all the reminders is a major headache. 

Graham Mitchell my understanding is that it's been fixed, but is not (and can not) be fixed for memberships which started before this bug appeared.

I've used fancy SQL to fix this - but the easiest solution is to simply recreate your scheduled reminders, and this should go away for good.

Many thanks Jon, I'll follow your advice.

Jon K Goldberg Thanks for your message. We have just encountered this with some newly migrated customers. Can you please clarify a little bit?

• do you know when this was fixed in core (version number or commit)?
• when you say it cannot be fixed for memberships, do you mean 'memberships' or 'scheduled reminders for memberships'?
• if memberships, is it the start_date or the member_since dates that are relevant in 'started before this bug appeared'? Also, how do you define 'when this bug appeared'? Is it the date the client's CRM instance was upgraded to 4.7?
• why does re-creating the scheduled reminders fix the issue? Is it just because the membership reminder will hen get a new id? If so, could we not simply then re-number the membership reminders with a few SQL queries (ie. copy to temp table, delete, insert from copy)?
• will re-creating the scheduled reminders for memberships cause duplicate emails to be sent?
• can you paste or provide a link to the query you used? Is it generic and can be used on any database or specific to your customer? If your query is run, will this fix the bug for memberships that started before the bug appeared without having to re-create the scheduled reminders?

Sorry there's a lot of questions, but this seems like a serious issue that affected many users over a long period of time.

Thanks.

Nicolas Ganivet I've forgotten more than I recall on this issue, but I'll answer to the best of my ability.

Note: There are "reminder templates" (`civicrm_action_schedule`), which is what you create in the UI.  Then there's the reminders themselves (`civicrm_action_log`).  Many reminders might exist for each template.  I try to keep my language clear below.

• do you know when this was fixed in core (version number or commit)?

The root of this problem is CRM-15728, as Ellen Hendricks points out above, which came in version 4.6.  Pre-4.6, reminders would generate an entry in `civicrm_action_log`, and queries to generate new reminders would check to see if one was already sent by querying this table.  If a match already existed (matching on contact_id, entity_id, entity_table, and action_schedule_id), then a reminder already had been sent and no new reminder was created.

Unfortunately, this structure caused memberships not to send scheduled reminders on renewal, because none of the values I mentioned above had changed.

To address this, CRM-17528 added a `reference_date` column.  When a reminder is sent, the reference date is set (IIRC, to membership end date if the reminder triggers on membership end date, etc.).  So from 4.6 on, queries in the future can tell if a reminder has gone out for THIS renewal.

• when you say it cannot be fixed for memberships, do you mean 'memberships' or 'scheduled reminders for memberships'?

For scheduled reminders.  Because the `reference_date` field didn't exist before 4.6, there was no good way to populate it.  So pre-4.6 reminders still exhibit this behavior.

• Also, how do you define 'when this bug appeared'? Is it the date the client's CRM instance was upgraded to 4.7?

My understanding is that this bug exists for any membership that received a reminder while the site was on 4.5.x and below.

• why does re-creating the scheduled reminders fix the issue? Is it just because the membership reminder will hen get a new id? If so, could we not simply then re-number the membership reminders with a few SQL queries (ie. copy to temp table, delete, insert from copy)?

Yes, I suppose you could. Note that in both scenarios you risk sending out double reminders - basically, any reminders sent earlier today will send again later, based on the logic outlined above.

• will re-creating the scheduled reminders for memberships cause duplicate emails to be sent?

Potentially; see above.  I'm also not considering other permutations, such as if "repeating reminders" are enabled.

• can you paste or provide a link to the query you used? Is it generic and can be used on any database or specific to your customer? If your query is run, will this fix the bug for memberships that started before the bug appeared without having to re-create the scheduled reminders?

I have the SQL query in my notes, and I'll paste it below, but I'm afraid I'm not going to parse out WHY this was the right query.  Mainly because I don't support this methodology anymore; I think fixing `civicrm_action_schedule` is a lot easier than fixing `civicrm_action_log`.  Nonetheless:

select cal.*, cm.start_date, cm.end_date from civicrm_action_log cal
 JOIN civicrm_membership cm ON cal.entity_id = cm.id WHERE cm.end_date >
 '2018-05-10' AND cal.reference_date = cm.end_date AND action_date_time <
 '2018-04-13' ORDER BY action_date_time;

Jon K Goldberg Thanks so much for this explanation - it's been by far the most complete and gives a great overview of this issue.

So, it seems that the query at https://github.com/civicrm/civicrm-core/blame/master/Civi/ActionSchedule/RecipientBuilder.php#L194 does not catch pre-4.6. civicrm_action_log records (ie. reminders) that were sent prior to 4.6 because their reference_date is null.

Trying to fix this query seems to carry a very high level of risk due to the logic present in that process (very well explained by the comments at the top of the file).

So why not just selectively delete these 'reminders' (ie.  DELETE FROM civicrm_action_log WHERE entity_table = 'civicrm_membership' AND reference_date IS NULL) as has been previously suggested?

What exactly is the fix to `civicrm_action_schedule` you are recommending in your last paragraph? Wouldn't re-creating the 'reminder templates' invalidate all previous 'reminders' rather than just the ones that have reference_date as null?

Nicolas Ganivet - the fix to `civicrm_action_schedule` is to delete, renumber, copy/paste etc. the reminder templates.  Fixes to `civicrm_action_log` would involve deleting old reminders or adding a reference date.  I think both are viable solutions, and you should do whichever you prefer.  I was just saying that having taken both approaches, I now prefer fixes to `civicrm_action_schedule`.  Nothing you've suggested about alternative fixes is wrong, and will work just as well; in my experience it's more work, but YMMV.

Thank you Jon K Goldberg, very clear.

I agree with Jon K Goldberg's assessment that it is better to fix `civicrm_action_schedule` by recreating or renumbering the reminders rather than try to fix `civicrm_action_log`. 

However I would like to add some additional information based on my CiviCRM site as the problems with the `civicrm_action_log` may not be as simple as he suggests.

Our site was running 4.4 when it was upgraded to 4.7 in mid-May last year. I had been recreating our 16 membership renewal scheduled reminders for the last four years to ensure they were sent out, so I decided to 'fix' the  `civicrm_action_log` instead.

My experience during the upgrade to 4.7 was that for most, but not all, exisitng entries in  `civicrm_action_log` the reference_date was not set to NULL but was populated with the expiry_date at time of upgrade for that membership as Eileen McNaughton noted in https://issues.civicrm.org/jira/browse/CRM-17880?focusedCommentId=88464&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-88464.

I thought I had fixed the problem in November 2017 when I went through and changed the reference dates back to the 'prior' membership end date for all reminders sent out between November 2017 when I had re-created the membership reminders and May, when we upgraded to 4.7.

However, the problem has appeared again. The reference dates for reminders run between May and August last year have been updated to the current membership end dates, so reminders are not going out again.  My guess is that this happened during a an upgrade to a higher 4.7 version early September last year.  I am checking the the company that actually does our updates to confirm when updates were run to see if that is a reasonable hypothesis. I will post back when I know more.

this may be an entirely spurious note but the Transactional Mail extension does at least provide a front-end way of checking what went out for whom and when - obviously too late for any of these use cases and adds more data of course - but this was one of the scenarios where having an actual record as an Activity of what went out (or didn't) could be very helpful

I've just been made aware of problems with sending scheduled reminders for membership renewal on another site that I work with. As these reminders were only created in the spring of 2018 I'm pretty sure (although I can't be certain as I've not kept records on precisely when and which CiviCRM updates were run) that the site was running 4.7.x at the time when the reminders were created. 

civicrm_action_log shows that about twenty reminders were sent during March 2018, but none since. As I generally aim to keep CiviCRM up to date on this site it's likely that I updated to version 5.0 in April, which may, just may, be a reason why no further reminders were sent from April on.

Reference dates show what look to be the correct expiry dates for the memberships concerned.

Can I safely truncate table civicrm_action_log to diagnose if this CRM is my problem?

Bari Pollard truncating the `civicrm_action_log` table will cause you to lose your history of who received what - which is a problem if you're using the "repeating reminders" feature. I believe in some circumstances this will also cause certain messages to be resent (e.g. "send a message x days before an event" checks to see if such a message has gone out).  So I'd advise against it unless you know for sure that you won't come across any such issues.

I think the resends happen if you delete the current day's records. The calculation is 'what reminders do I need to send today' & it looks to see if the resend has happened

Hi,

This issue is one of the few active JIRA issues. I will soon be making JIRA completely read-only / static HTML. Can someone migrate a recap of this issue to Gitlab? https://lab.civicrm.org/dev/core

Thanks!

Mathieu Lutfy - long time! Hope all is well!

I posted a summary to  https://lab.civicrm.org/dev/core/issues/285 which is essentially a duplicate of this ticket.

Since I can't mark this as a duplicate I'm setting it to 'wont do' and we can track progress in gitlab =]