emails not being sent to new users because send_interval=NULL

last_sent initially being 0 is correct. Whenever a notification is sent to a user, {subscriptions_user}.last_sent is set to the current time, and subsequently created {subscriptions_queue} items will have the new timestamp.

Are you saying that records get added to {subscriptions_queue} but not removed?

It doesn't matter whether you run cron manually or by the cron process — either way, records should be removed in creation order (by sqid) and each one should cause a notification to be sent.

Turn Display watchdog entries for successful mailings on at the bottom of admin/settings/subscriptions and check what is being written to the watchdog log.

Feel free to reopen if you want to pursue this further.

I have a similar problem, though problem is not with new users - it is random.
For some users subscription mails are going out, but for many the subscriptions_queue table grows enormously.
I found performance issue with the site and found the query
SELECT * FROM subscriptions_queue WHERE last_sent + send_interval < 1278973688 ORDER BY sqid LIMIT 0, 1
running slowly, i digged further and saw about 2.6M entries in subscriptions_queue table.
After that i purged the queue and noticed, how queue is being processed.

In this, i found that for some users mail is being sent and hence respective entry removed from the table,
But for others entry remains there and hence table grows.

I have syslog module enabled. that is not showing any error message from subscriptions module.
It only shows success messages like
Jul 14 05:58:18 web1 drupal: http://example.com|1279101498|subscriptions|00.00.00.00|http://example.com/cron.php||2696||notification for ABC at
NOTE: original values altered.

Turn on "Display summary watchdog entries per cron job" near the bottom of the Subscriptions Site Settings and tell us what it reports (three times).

I found this info right after the individual notifications.

Jul 14 11:18:03 web1 drupal: http://example.com|1279120683|cron|00.00.00.00|http://example.com||1||Subscriptions sent 9 single and 1 digest notifications in 1 of 240 seconds; 0 queue items remaining (plus 0 suspended), 223 seconds left for other cron client modules.

I still have 340 entries in subscriptions_queue table.
Please take a look.

Make a copy of your subscriptions_queue table, run cron, and compare the rows that were sent (and deleted) with those that are still there?

Check what last_sent + send_interval < 1278973688 does. What is last_sent, what send_interval?

The number is the current time. Notifications are not sent until the current time has advanced past last_sent+send_interval.

I am seeing that all those entries which are not sent (and hence not deleted) have send_interval = NULL and last_sent = 0.
All other entries have send_interval = 1 and last_sent = time of last cron run.
Seems like having send_interval = NULL is creating issue.

One more thing, i am seeing 5 entries for each user in subscriptions_last_sent table with send_interval values 1, 900, 3600, 10800, 86400. Is this normal behavior?

Hmm, yes, send_interval = NULL is not good. I wonder where those records come from.

Your entries on admin/settings/subscriptions/intervals should look like

1|As soon as possible
900|Every 15 minutes
3600|Hourly
10800|Every three hours
86400|Daily

I wonder whether it makes any difference if there is a newline after 'Daily' or not...

Having separate entries for each interval in subscriptions_last_sent is correct.

It looks like everything is ok, subscriptions_queue is getting populated with correct data.
The inconsistency is in the subscriptions table where for 50% of subscriptions send_interval IS NULL.

There was no option than to update these entries manually and then check how it works, so i updated the subscriptions table,
SET send_interval = [default interval] WHERE send_interval IS NULL

Now all the mails are going out and entries are getting removed from subscriptions_queue table.

I will closely monitor it for next couple of days and see where from this NULL value is coming, If i find something i will update you here.

Lastly, Thanks for your time and help.

Great, glad you were able to fix the immediate problem.

The inconsistency is in the subscriptions table where for 50% of subscriptions send_interval IS NULL.

I would really like to know where those NULLs came from. Please check the subscriptions_send_intervals variable to make sure that all intervals really do have a number of seconds with them.

Do you have any custom modules that contribute records to the {subscriptions} table or that implement hook_subscriptions_queue()? I think we should ultimately disallow NULL for the send_interval columns, but if there's a source that creates these NULLs, this could break the site until the source is fixed.

The {subscriptions_user} table already has 'not null' => TRUE, so you shouldn't have any NULLs in there, but please do check. Are you perhaps missing the special record with uid=-2 in the {subscriptions_user} table?

Yes, i will try to find it out and let you know.

Variable subscriptions_send_intervals is ok, below is the serialized value taken from variables table.

a:5:{i:1;s:20:"As soon as possible
";i:900;s:17:"Every 15 minutes
";i:3600;s:7:"Hourly
";i:10800;s:18:"Every three hours
";i:86400;s:6:"Daily
";}

Yes we have custom module for author subscriptions.
Yup, that is a better option, having send_interval default to 1 - will make sure that nobody lands in situation like mine
where subscriptions_queue gets accumulated (2.6M records) and then slows down the site.

Yes, subscriptions_user has no issue. It has default value of -1.

uid = -2 record is there, i was thinking that i should delete this record.
There is a coincidence, uid=2 was deleted in our case,
It looked to me as if module may be turning value to negative for a deleted account with active subscriptions.
But thought to do bit of research before going for deletion.
Anyway, is there any specific purpose of this?

Thank you for your followup!

No, DON'T delete that record!

Negative uids are interpreted as rids (role IDs) by Subscriptions. 2 is the DRUPAL_AUTHENTICATED_RID. That record in {subscriptions_user} has the site defaults. In the {subscriptions} table there may be other rids, too.

No, records are removed when a user is deleted.

After your additional information and...

Yes we have custom module for author subscriptions.

... I'm beginning to suspect that that module may be inserting the NULLs. Is it here on d.o? Please check for subscriptions_write() and subscriptions_write_subscription() calls. Could these be passing NULL for the $send_interval?

Ok, thanks for the info - role IDs, good way to avoid additional table :)

Somebody had written the module for 5.x, but never reached release mode.
We have modified this a bit. http://drupal.org/project/subscriptions_author
You can download it from here, http://ftp.drupal.org/files/projects/subscriptions_author-5.x-1.x-dev.ta...

This module was modified by one of my colleague, so i am not sure if the bug is caused due to subscriptions_author module,
but i will definitely check,

I looked through subscriptions_author.module, but I couldn't find any problems with it.

Can you still identify a {subscriptions} record that had a NULL? What type (module/field/value) was it? subscriptions_author produces subscriptions of type 'node'/'uid'/uid.

There are quite good number of subscriptions added since yesterday and around 1200 mails sent out.
But i am not able to find any record with NULL value.

Checked the subscription author records, could not find any thing.
And they are only less than 1% of total subscriptions, so difficult to attribute it to the problem with 50% subscriptions.

I will work further on it and try to reproduce the bug, and eventually the source.
Will keep you posted in case i make some progress.

In MySQL, subtracting an unsigned INT produces an unsigned INT.

So

last_sent + send_interval

will produce a wrong value ('18446744073709551615') if send_interval is the default value of -1 and last_sent is 0 (quickly becomes high numbers of queued messages because no more messages are sent).

You should cast 'last_sent' as signed in every query showing

last_sent + send_interval

to get the correct value:

SELECT * FROM {subscriptions_queue} WHERE suspended = 0 AND cast(last_sent as signed) + send_interval < %d ORDER BY sqid

Maybe it could be the origin of the problem...

send_interval should never ever be -1. Having -1 in the {subscriptions_user} table means 'use the site default', which should always be >= 1.

What makes you think that send_interval could be -1?

You always took -1 as site defaults. I assumed you use this value until you really need the send_interval (ie: cron and co).
And in function subscriptions_write you never check if send_interval is >0 (in fact you never check it or indicate/document it's a wrong value), so I assumed it could be possible.

But after a deeper inspection, you use _subscriptions_get_setting('send_interval', $user) when necessary.

Maybe you should document this a little bit or include the send_interval check when writing the subscription (and replace by the default if =-1), or a warning in your code that it should not be possible.

I did call some functions of your module (mainly subscriptions_write) from my modules to add some "algo" subscriptions but it was not obvious that only the subscription_user table could have -1 values.

Thanks for you're answer. Now it's crystal clear!

Ok, I've documented the subscriptions_write() function in D6 and D7.

Thanks.