I have had this happen a couple of times after updating to 7.x-1.1+11-dev (2013-Jun-05). The cron task will run and run and I get numerous errors that states "Attempting to re-run cron while it is already running." The only way I have been able to stop this is to disable portions of Subscription and then the cron will complete. Once cron is complete I can re-enable Subscriptions and all is well.

The modules I disabled to get cron to finish were:
subscriptions_mail
subscriptions_taxonomy
subscriptions_ui

I didn't try disabling just one of these at a time and perhaps I should have in order to track down exactly which module was causing the problem but it was one of those three for sure.

This has happened twice now. If it happens again I'll disable them one at a time to determine which module is causing the problem.

CommentFileSizeAuthor
#13 subscriptions-config1.png124.25 KBmajestixx
#13 subscriptions-config2.png95.5 KBmajestixx
#13 subscriptions-usersetting1.png38.94 KBmajestixx
#13 subscriptions-usersetting2.png24 KBmajestixx

Comments

salvis’s picture

salvis
he/his
commented

You did run update.php, right?

subscriptions_mail is the only one that implements hook_cron().

The cron task will run and run and I get numerous errors that states "Attempting to re-run cron while it is already running."

What do you mean with "numerous"? How often does your cron run? How often do you get those messages. Do you get any other messages that could be related to cron or mail?

Please go to admin/config/system/subscriptions and set all options under Mail Settings to the defaults. This should give you the following messages:
-- for each notification
---- for each user: Notification sent to... (user name)
-- finally: Subscriptions sent 4 single and 1 digest...
-- finally: Cron run completed.

What do you get?

If you have any module installed that has an influence on sending mail, then try disabling that module.

wimberb’s picture

wimberb commented

@salvis

Yes, I did run update.php. I have also cleared the cache several times.

By numerous I mean maybe 10 or 20 error messages in a row stating that "Attempting to re-run cron while it is already running." After disabling the portions of Subscriptions as indicated in the original post then cron will finish and I get a notice that cron is complete. I can then enable Subscriptions again and there are no problems with cron. This started immediately after updating to 7.x-1.1+11-dev (2013-Jun-05). A couple days later I started getting the errors again and was able to follow the same procedure to get cron to complete. Those are the only 2 occasions where this has happened so far.

Please go to admin/config/system/subscriptions and set all options under Mail Settings to the defaults. This should give you the following messages:

Since I don't know what the "default" settings should be I'm not sure how to proceed here. But under mail settings I have everything checked except "Display watchdog debug entries for all queued and ready notifications".

I think the only other modules that are sending out any mail are Logintoboggin for registration and Rules that sends me notices of any changes to the site.

wimberb’s picture

wimberb commented

I just realized that ever since updating to 7.x-1.1+11-dev (2013-Jun-05) subscriptions are not being sent out at all. Prior to the update everything was working just fine.

wimberb’s picture

wimberb commented

The cron errors started up again. This time I got the notice that "Attempting to re-run cron while it is already running." 4 times then 2 notices that "Cron run completed".

Additionally, checking for module updates returned the following error:
An AJAX HTTP error occurred. HTTP Result Code: 200 Debugging information follows. Path: /batch?render=overlay&id=4199&op=do StatusText: parsererror ResponseText: {"status":true,"percentage":"9","message":"Trying to check available update data ...\u003Cbr \/\u003EChecked available update data for \u003Cem class=\u0022placeholder\u0022\u003EDraggableviews\u003C\/em\u003E."} Fatal error: Call to undefined function dpm() in /home/wimberb/public_html/sites/all/modules/subscriptions/subscriptions_mail.cron.inc on line 351

Disabling Subscriptions Mail allowed me to check for module updates.

I never had any of these problems prior to updating to the latest dev version.

salvis’s picture

salvis
he/his
commented
Priority: Normal » Major

For every control with a default value the explanation says what the default is.

The stray dpm() call is definitely bad. I've fixed that and just pushed the change to the -dev version, which should be rebuilt within 12h. I'm very sorry about this bug.

You can fix it manually in the meantime if you want — just remove the three letters "dpm".

I have a hard time imagining how this (or anything else in that recent update) could cause the problems with cron calling itself recursively though.

checking for module updates returned [...] Fatal error: Call to undefined function dpm() in [...] subscriptions_mail.cron.inc on line 351

Do you mean checking for updates on admin/modules/update or with update.php?

Neither of these should ever call subscriptions_mail_cron(), which is the only way to get to that line 351!

Please let us know what happens after removing the "dpm". I suspect this will not make the problem go away. In that case, you'll need to do some debugging with the Devel module:
1. Install it
2. Insert the line "ddebug_backtrace();" above the fixed line 351.
3. As user 1, check for updates again.
4. Disable and uninstall the Devel module after you're done using it.

I'm hoping that this will display a stack trace (you'll know it when you see it). Post a screenshot of that.

wimberb’s picture

wimberb commented

Salvis, I appreciate you taking the time to look into this.

I haven't had a chance to do the Devel debugging yet. After my last message I tried completely uninstalling Subscriptions. Then I installed the latest dev version 7.x-1.1+13-dev (2013-Jun-12) so that I had a completely fresh install.

I then reconfigured in Configuration-->System-->Subscriptions. All seemed well so far.

Then I went to my user account and selected the Subscriptions tab then Settings. Without making any changes I expanded Settings, reviewed them, then selected Save. Upon save I got a message stating that "The website encountered an unexpected error. Please try again later." In the error log I found the following error messages:

Notice: Undefined index: secure_links in _subscriptions_user_settings_form_submit() (line 830 of /home/wimberb/public_html/sites/all/modules/subscriptions/subscriptions.admin.inc).

PDOException: SQLSTATE[23000]: Integrity constraint violation: 1048 Column 'secure_links' cannot be null: UPDATE {subscriptions_user} SET digest=:db_update_placeholder_0, secure_links=:db_update_placeholder_1, send_interval=:db_update_placeholder_2, send_updates=:db_update_placeholder_3, send_comments=:db_update_placeholder_4, send_interval_visible=:db_update_placeholder_5, send_updates_visible=:db_update_placeholder_6, send_comments_visible=:db_update_placeholder_7, autosub_on_post=:db_update_placeholder_8, autosub_on_update=:db_update_placeholder_9, autosub_on_comment=:db_update_placeholder_10, send_self=:db_update_placeholder_11 WHERE (uid = :db_condition_placeholder_0) ; Array ( [:db_update_placeholder_0] => 0 [:db_update_placeholder_1] => [:db_update_placeholder_2] => 1 [:db_update_placeholder_3] => 1 [:db_update_placeholder_4] => 1 [:db_update_placeholder_5] => 0 [:db_update_placeholder_6] => 0 [:db_update_placeholder_7] => 0 [:db_update_placeholder_8] => 0 [:db_update_placeholder_9] => 0 [:db_update_placeholder_10] => 0 [:db_update_placeholder_11] => 1 [:db_condition_placeholder_0] => 1 ) in _subscriptions_user_settings_form_submit() (line 843 of /home/wimberb/public_html/sites/all/modules/subscriptions/subscriptions.admin.inc).

Does this give some clue to what is going on here?

salvis’s picture

salvis
he/his
commented

I need to test the new 'secure_links' options more thoroughly, but I've pushed a quick fix that should work around this issue (give it up to 12h to be repackaged).

I'm sorry this is so painful, especially because we haven't even gotten down to the real issue with cron yet...

Thank you for hanging in there!

salvis’s picture

salvis
he/his
commented

I believe with the June 13 fix this is stable now. Have you found any other issues?

wimberb’s picture

wimberb commented

Everything appears to be working fine now. I appreciate all your help.

shaneonabike’s picture

shaneonabike commented

Has anyone run into this one #2065271: Add support for multiple 'data_function's with the latest dev?

salvis’s picture

salvis
he/his
commented
Status: Active » Fixed

Thank you for your feedback, wimberb!

#10 is off-topic, let's close this.

Status: Fixed » Closed (fixed)

Automatically closed -- issue fixed for 2 weeks with no activity.

majestixx’s picture

majestixx commented
Title: Subscriptions causing Cron to run endlessly » Subscriptions causing cron to run endlessly
Status: Closed (fixed) » Active
StatusFileSize
new subscriptions-usersetting2.png24 KB
new subscriptions-usersetting1.png38.94 KB
new subscriptions-config2.png95.5 KB
new subscriptions-config1.png124.25 KB

I am having the same issue as described above in the latest version (7.x-1.1+20-dev).

If I disable the subscription module the cron is working well. Otherwise it breaks with the message "Attempting to re-run cron while it is already running."

In my scenario 3 users are subscribed to forum topics.
Screenshots of my configuration are attached. Despite of simplenews there are not mailing-module installed.

Let me know if I can provide any additional information.

salvis’s picture

salvis
he/his
commented

Sorry for the late reply.

Please try turning digest mode off and watchdog listings on.

What does that give you?

majestixx’s picture

majestixx commented

Unfortunately, nothing happens.

I checked the options "Display summary watchdog entries per cron job", "Display watchdog entries for successful mailings", and " Display watchdog debug entries for all queued and ready notifications"
Disabled digest mode for all users (and checked in the users' profiles)
Then I added new content (with automatic subscription).

The next run of the cron failed, but the log is empty:

	cron	11/05/2013 - 15:22	Attempting to re-run cron while it is already running.	Anonymous (not verified)	
	content	11/05/2013 - 15:17	forum: added Mal wieder ein Subscription-Test.	Admin Istrator	view
salvis’s picture

salvis
he/his
commented

Attempting to re-run cron while it is already running.

Is this a permanent error, i.e. does it show every time that cron runs?

How often does your cron run?

This message is generated by the drupal_cron_run() core function, if it cannot acquire the 'cron' lock in the {semaphore} table. The only situation I can think of where this can happen is if a cron run is triggered before the previous one has finished.

Depending on what cron needs to do on your system, one run can take up to 4 minutes and times out after that time. Timing out is unhealthy, and Subscriptions has code to keep that from happening, but we still need to look at that possibility.

How many items are in your Subscriptions queue (on the Settings page)? As an experiment, set Maximum number of notifications to send per cron run to 1 (and keep logging to watchdog). Can you at least send out one notification?

majestixx’s picture

majestixx commented

It is a permanent error as long as the subscriptions module is activated. As soon as the module is deactivated the cron is running as usual (e.g. the i18n update module loads new translations).
At the moment the cron is executed as a poor-mans cron and does not run on a regular basis. When I am testing the subscriptions module, I am executing the cron manually.

You are right, the cron is locked in the semaphore-table and is not removed (I've waited for multiple hours). I have to delete it manually from the db table. The next time the cron is executed (while the subscriptions module is activated) the semaphore is set again.

I have tested the subscription with 1 to 4 elements in the queue. Even with a single element the error occurs.
After setting the "maximum notifications" to 1 the same happens. The watchdog is empty (same as above) and also the apache errorlog has no (new) entries.

Can I do some debugging in the cron hook? Do you have any advice where to look?