We have a site that is shared with another. It has 100k nodes. Notifications are largely disabled (e.g., nothing should go out) so it should finish in a second, right?

Nope, takes 1+ hour to complete, this the culprit:

mysql> show processlist;
+---------+------+---------------------+--------------+---------+------+--------------+------------------------------------------------------------------------------------------------------+
| Id      | User | Host                | db           | Command | Time | State        | Info                                                                                                 |
+---------+------+---------------------+--------------+---------+------+--------------+------------------------------------------------------------------------------------------------------+
| 5056656 | mc   | 10.17.171.186:50920 | mothersclick | Query   | 1168 | Sending data | DELETE FROM mbn_notifications_event WHERE created < 1223512145 AND eid NOT IN (SELECT eid FROM mbn_n | 
CommentFileSizeAuthor
#1 slow_query.patch975 bytesScott Reynolds

Comments

Scott Reynolds’s picture

StatusFileSize
new975 bytes

so this query was removing events from the event table that were past there time and thus no need to save the event. The problem with this query is it sub-queries the queue table which is larger. The query would benefit from a DISTINCT(eid) on the sub query but that still isn't desirable.

The attach patch operates on the following principle
remove old events that where created at such a time ago that there couldn't be anything in the queue.

Basically, creation time < time() - max_interval then delete that event. Haven't tested this patch throughly but I believe, at least in spirit, it is the best way to go.

another way would be to start select 200 eids from the event order by creation ASC. then ask queue if it has any thing for that eid, if it does allow the even to live on. This way this query is controllable and can't run rampant.

jose reyero’s picture

Status: Active » Patch (to be ported)

Yes, you catched some bad query.

The proposed solution looks good in principle but I'm afraid there may be some race conditions that make it fail. One of them is when you have a lot of processing to be done, that timeout may not be reliable. Also if you have only an interval, and it is inmediate (=0), this may delete all queries.

Here's some tentative solution I've already committed into the module, let me know whether it works. If so it is to be ported to 6.x too.

function notifications_process_prepare($module = 'notifications') {
  // Clean up event table. As events are created sequentially, we use this fact to speed up the query
  // This expiretime will prevent some race condition that occurs when the event is saved but the subs queue not yet populated  
  $expiretime = time() - 60;  
  db_query("DELETE FROM {notifications_event} WHERE created < %d AND eid < (SELECT MIN(eid) FROM {notifications_queue})", $expiretime);
....
}
m3avrck’s picture

Jose this looks great. Significantly faster query :)

We're still a little curious about this "race" issue if you could shed some more light on that. Otherwise this works for us.

jose reyero’s picture

About that race condition, well, I'm not sure that's the word, but the issue is like this:

With the first query we were deleting all the events queued before [max time interval] + some safety margin (which was 60 secs but could be any). That will work if all pending notifications are sent out on each cron run, but because of time constraints, depending on server load, that may not be always the case, it is possible that you have a huge number of queued notifications for an event that take a few cron runs to complete, then you'd be losing these ones.

Worst case scenario: you have only an interval that is inmediate sending, time = 0. Then [max time interval] + [60 secs] = 60 secs. If you run cron every 5 minutes and drop all the events queued more than 60 seconds ago, then you'll be deleting most of them before sending out the notifications...

Whatever, thanks for pointing out these bad queries, it's really helpful to have real performance data from huge sites.

jose reyero’s picture

Status: Patch (to be ported) » Fixed

Ported to 6.x

christefano’s picture

Status: Fixed » Patch (to be ported)

Will this be ported to the D5 version?

jose reyero’s picture

Status: Patch (to be ported) » Closed (fixed)

It was already in 5.x, please read the thread

christefano’s picture

Of course, sorry about that.