Multiple copies of the same message sent to the same user

---[accidentally posted same comment twice - sorry, flaky net here]---

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.

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.

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

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.

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.

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 :)

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.