Multiple copies of the same message sent to the same user
jwarner - September 11, 2009 - 18:08
| Project: | Messaging |
| Version: | 6.x-2.1 |
| Component: | Code |
| Category: | bug report |
| Priority: | normal |
| Assigned: | Unassigned |
| Status: | active |
Description
For a small percentage of messages sent, duplicate messages are being generated and sent to users.
I have yet to reproduce the problem, but my messaging store table shows that is happening.
SELECT COUNT(*), params, uid, FROM_UNIXTIME(sent) FROM messaging_store
GROUP BY params, uid, sent
HAVING COUNT(*) > 1 ORDER BY COUNT(*)...returns 124 rows, of the approximately 3,200 messages I sent yesterday.
I host my site on a SiteGround shared hosting account which limits the amount of time cron can run. I don't know if that's related, but thought I would include it just in case it can shed any light on the problem.
#1
#2
---[accidentally posted same comment twice - sorry, flaky net here]---
#3
Ok I'm pretty sure this is a real bug now.
Whereas it only affected a small percentage of the messages I sent last time, now it's affecting about half the messages I send.
I can reproduce it (simply start sending messages, either with a limit of 1, a higher limit, or no limit to messages processing) but I have yet to be able to identify the conditions to reproduce it reliably (or I'd likely have this fixed by now!).
Some more information:
When the duplicates are being created, sure enough, records indicating that duplicate messages were sent are in the messaging_store table, either with exactly the same timestamp, or timestamps very close to one another.
The duplicates seems to be being generating within the notifications module, from this watchdog entry:
Duplicate entry '307527-1209600-phpmailer' for key 1 query: INSERT INTO notifications_sent(uid, send_interval, send_method, sent) VALUES(307527, '1209600', 'phpmailer', 1254517220) in /home/rateafla/public_html/earthtrendsdelivered.org/sites/all/modules/notifications/notifications.cron.inc on line 386.
I can't identify any differences in the data for users who get duplicate messages as opposed to those who receive a single digested message.
Any tips would be appreciated, but as for now, I guess it's back to trying to figure this out.
#4
Do you think it may be the same issue as #548744: Prevent duplicate notifications on page reload of 'process immediate sending' ?
#5
I don't think it's the same problem, I have this too but the message contains the commentid #comment1234
and its the same in the mails sent to the same user, so i guess it's not a duplicate comment post
After someone replied on the thread he got up to 5times the same mail, looking into it now.
now i turned off: "Immediate sending"
#6
#7
This is truly perplexing, and the problem is getting worse.
For a subset of my users, initially a minority but now a majority, 2 or more messages are sent. Furthermore, the messaging_store table reflects this - unique mqid's (of course) but everything else is EXACTLY the same! Even the 'created' and 'sent' fields display the exact same timestamps.
I haven't customized or patched this module in any way, and I have been trying everything I can think of to try to catch this problem as it is happening with no luck. I have inspected all the notifications tables to try to see if there is a difference between the data for a user who gets duplicate emails and one who does not, but there doesn't seem to be one.
I keep hoping I can add something constructive to this thread but this is as far as I've been able to get.
Ok, back at it for a while longer.
#8
And it isn't #548744: Prevent duplicate notifications on page reload of 'process immediate sending' because I do not use the 'immediate sending' option anywhere - it's not enabled.
My source is available on sourceforge and the site is http://earthtrendsdelivered.org
#9
More info:
I am only able to reproduce the problem with large(r) amounts of data.
For example, I have a user in my production database who received 3 copies of the same email.
I can also manage to "send" duplicate messages in my development environment.
However, when I set the notification module to only send email for that single user:
update notifications_queue set cron = 0;update notifications_queue set cron = 1 where uid = 311402;
...even though that exact same user with that exact same data received 3 duplicate emails in my production instance where 30,000+ records are set for processing in the notifications_queue table, when user 311402 is the only user to be processed, he/she only receives a single digested email.
#10
More information:
I started the technique of sending messages to one user, then two, then three, and so on (by setting cron =1 for the users I wished to send messages to) to see if/when I would start seeing duplicates.
Once I got to four users, a total of 64 records in my notifications_queue table, I saw duplicates again.
Ratcheting it back down to just 3 users and 30-40 records in my notifications_queue table, I was able to send ~40 digested emails without a single duplicate.
#11
After establishing that I can only seem to send digests to ~3 users at a time, I added this not-so-sophisticated hack (which I don't recommend others using) to my notifications.cron.inc:
/**
* Function to be called on cron by the main notifications_cron
*
* It will call each subscription_process for each interval a number of times
*
* This should send out messages starting with immediate delivery. We send first immediate delivery
* because the other ones can be added up for each period.
* Assumption: The bigger the interval, the longer delay it may admit (?) I.e. sending hourly email
* after 1 hour 15 mins may be ok if the system is overloaded.
*/
function notifications_process_run($cron = TRUE) {
/*
* Crazy 'throttle' hack to ensure that duplicate emails are not sent
*/
// first, log errors (this assumes you have stored your sent messages)
$err_sql = "SELECT COUNT(*) mcount, uid, params FROM messaging_store
GROUP BY params, uid
HAVING COUNT(*) > 1
ORDER BY COUNT(*) desc";
$results = db_query($err_sql);
while ($fields = db_fetch_array($results)) { // Get the next result as an associative array
watchdog('notifications', 'Duplicate emails (%value) sent to: %user', array('%value' => $fields['mcount'], '%user' => $fields['uid']), WATCHDOG_CRITICAL);
}
$throttle = 3;
$clean_sql = "DELETE FROM notifications_queue WHERE sent != 0";
db_query($clean_sql);
$next_group = "SELECT DISTINCT uid FROM notifications_queue WHERE cron = 0 and sent = 0 ORDER BY uid LIMIT $throttle";
//echo $next_group;
$results2 = db_query($next_group);
$uid_array = array();
while ($fields = db_fetch_array($results2)) { // Get the next result as an associative array
$uid_array[] = $fields['uid'];
}
$sql_next_round = "update notifications_queue set cron = 1 where uid in (".implode(",",$uid_array).")";
//echo $sql_next_round;
db_query($sql_next_round);
/* end crazy hack */
notifications_log('Starting notifications process');
My purpose in sharing this is not to propose it as a solution, but rather to judge it's effectiveness as a last resort measure, and just to add to general information on this module if others experience a similar problem.
So far, the workaround is 100% effective at avoiding message duplication. I'll let you know how that holds up after all my digests are sent, about 20 hours from now :)
#12
The suspense is over!
My ugly hack dramatically reduced the occurrence of the problem.
Before the hack, 604 of 670 (90%) of users got 2 or more emails - duplicates maxed out at 3 duplicate emails per user.
After the workaround, 4 of 3583 (0.1%) of users got 2 emails - none got more than 2 emails.
Thus far I've still been unable to catch this issue as it's happening, which makes it difficult to track down the cause, but I hope this gives the community a lot more information to work with.