Make WordPress Core

Opened 14 years ago

Last modified 3 years ago

#11800 new defect (bug)

doubled execution of cron jobs

Reported by: neoxx's profile neoxx Owned by: westi's profile westi
Milestone: Future Release Priority: normal
Severity: normal Version: 2.9.1
Component: Cron API Keywords: dev-feedback needs-patch
Focuses: Cc:

Description

Hi,

as I've already mentioned in ticket #11505 , cron-jobs occasionally get executed twice (e.g. daily backup arrives two times).

I've changed the code according to the patch attachment:ticket:11505:ticket-11505-stop-gap.patch (which derives from http://wpengineer.com/ping-problem/) after my comment:ticket:11505:49 and had no doubles within this time period. This week I've upgraded to WP 2.9.1 and since then backups arrive two, sometimes three times, again.

Looking at the changes from 2.9 to 2.9.1, I have no other explanation for this behavior. - Maybe we should consider having a closer look again on this patch attachment:ticket:11505:ticket-11505-stop-gap.patch .

Greetz,
Berny

Change History (9)

#1 follow-up: @miqrogroove
14 years ago

Idea for a fix: Create a proper token for each future job. In wp-cron.php, consume that token at the top of the script. Since the token can only be used once, any races are broken and the concurrent jobs may self-quit.

#2 @dd32
14 years ago

Since the token can only be used once

How do you mark a token as expired?

By setting it in the database? A flag is already set that cron is in progress, If thats true when the new script starts, it should bail from memory. unforunately, multiple scripts can try that check at the same time and all end up running..

#3 in reply to: ↑ 1 @westi
14 years ago

  • Milestone changed from 2.9.2 to Future Release

Replying to miqrogroove:

Idea for a fix: Create a proper token for each future job. In wp-cron.php, consume that token at the top of the script. Since the token can only be used once, any races are broken and the concurrent jobs may self-quit.

This means we can only process on cron task per page load of wp-cron.php.

For me one of the biggest problems with cron at the moment is that it is all stored in a single option.

This makes it hard to do atomic actions on the data - especially if people are using an object cache / running across multiple servers.

You can't atomically add/remove a cron task at the moment.

I think it would be best to look into fixing this problem rather than papering over the cracks.

The best solution here is probably to split the cron jobs off so they are stored as single job per row in the db.

Moving out of 2.9.2 as I think this needs a structural fix.
Moving to Future Release for now as there is no patch and no guarantee it will be fixed in the 3.0 dev cycle.

If someone wants to attempt this I would be happy to review patches and discuss ideas.

#4 @miqrogroove
14 years ago

How do you mark a token as expired?

Tokens are consumed by deleting them. Expired usually implies that the token becomes invalid after a certain time.

This means we can only process on cron task per page load of wp-cron.php.

No it doesn't.

#5 @mintindeed
13 years ago

  • Cc gabriel.koen@… added

The patch I created for #15148 creates a cron table with one row per job. The primary key field is a token using a hash of the timestamp, hook, and arguments. The schedule cron function will blindly try and insert any job you tell it, but since the primary key is a hash of those params, duplicate entries will simply fail to be inserted into the database (without a separate query to check if they already exist).

There's also a status field, so theoretically wp-cron.php could be modified to spawn off multiple processes (1 for each job) which would then update the status of the job they're working on (pending, processing, completed). Basically laying the groundwork for a real job queue, if that's the direction you want to take it.

#6 @agupta_pmc
13 years ago

  • Cc agupta_pmc added

#7 @chriscct7
9 years ago

  • Keywords dev-feedback added

Core devs: thoughts on this and the related ticket/patch on #15148?

#8 @chriscct7
8 years ago

  • Keywords needs-patch added; cron removed

#9 @opajaap
3 years ago

This is especially annoying when the cron process sends emails.

Here is a proof of evidence that this bug still exists.
What you see is a logfile from plugin wp photo album plus (last message on top) that shows that process ids 1965 and 1975 are doing the same job simultaneously.
The processes can not communicate through a wp option indicating what they are doing because the options table is not updated immediately. So saving the hashvalues in an option does not work here.
My solution to this is to write essential data indicating the job in a file and call clearstatcache(). If there is a second process attempting to do the same, it sees that in the file and can abort its execution. This kind of 'locking' is safe as such that it can not hang up the system (the 'lock' does not need to be released, it will be overwritten by the next email job).

It took me only a week to find this out.

The logfile (the process ids are from getmypid() and placed between brackets):

Eml: on:01.04.2021 17:06:25: cron-job (1965): Done mailing commentnotify
Eml: on:01.04.2021 17:06:25: cron-job (1965): Mailinglist commentprevious scheduled for run in 120 seconds. Args: 0, 0, 252247, , 0
Eml: on:01.04.2021 17:06:25: cron-job (1965): Hash: ffb88919f374158d5ec5a63184939d1d added to sent mails
Eml: on:01.04.2021 17:06:25: cron-job (1965): Hash: ffb88919f374158d5ec5a63184939d1d, Mail sent to: [redacted] (105190) subject: [iPhotography] Comment on photo Monday's Photoshoot, photo: 183876
Eml: on:01.04.2021 17:06:25: cron-job (1965): Hash: ca4194fbb23e7fd80c1d31750555f1e9 added to sent mails
Eml: on:01.04.2021 17:06:25: cron-job (1965): Hash: ca4194fbb23e7fd80c1d31750555f1e9, Mail sent to: [redacted] (101488) subject: [iPhotography] Comment on photo Monday's Photoshoot, photo: 183876
Eml: on:01.04.2021 17:06:25: cron-job (1965): Hash: 3080ce36ffc367958b991b97abc20427 added to sent mails
Eml: on:01.04.2021 17:06:25: cron-job (1965): Hash: 3080ce36ffc367958b991b97abc20427, Mail sent to: [redacted] (100641) subject: [iPhotography] Comment on photo Monday's Photoshoot, photo: 183876
Eml: on:01.04.2021 17:06:25: cron-job (1965): Hash: b9fba1d0496a9b715a96a0906899d5d6 added to sent mails
Eml: on:01.04.2021 17:06:25: cron-job (1965): Hash: b9fba1d0496a9b715a96a0906899d5d6, Mail sent to: [redacted] (98553) subject: [iPhotography] Comment on photo Monday's Photoshoot, photo: 183876
Eml: on:01.04.2021 17:06:25: cron-job (1965): Hash: 622cbf03952ce0489f532d3d352037ab added to sent mails
Eml: on:01.04.2021 17:06:25: cron-job (1965): Hash: 622cbf03952ce0489f532d3d352037ab, Mail sent to: [redacted] (95781) subject: [iPhotography] Comment on photo Monday's Photoshoot, photo: 183876
Eml: on:01.04.2021 17:06:24: cron-job (1965): Hash: 4452147011a8668325abec4fc0a51582 added to sent mails
Eml: on:01.04.2021 17:06:24: cron-job (1965): Hash: 4452147011a8668325abec4fc0a51582, Mail sent to: [redacted] (84625) subject: [iPhotography] Comment on photo Monday's Photoshoot, photo: 183876
Eml: on:01.04.2021 17:06:24: cron-job (1975): Done mailing commentnotify
Eml: on:01.04.2021 17:06:24: cron-job (1975): Mailinglist commentprevious scheduled for run in 120 seconds. Args: 0, 0, 252247, , 0
Eml: on:01.04.2021 17:06:24: cron-job (1975): Hash: ffb88919f374158d5ec5a63184939d1d added to sent mails
Eml: on:01.04.2021 17:06:24: cron-job (1975): Hash: ffb88919f374158d5ec5a63184939d1d, Mail sent to: [redacted] (105190) subject: [iPhotography] Comment on photo Monday's Photoshoot, photo: 183876
Eml: on:01.04.2021 17:06:24: cron-job (1965): Hash: a476d22a0401eaf26deb4e04430ebba0 added to sent mails
Eml: on:01.04.2021 17:06:24: cron-job (1965): Hash: a476d22a0401eaf26deb4e04430ebba0, Mail sent to: [redacted] (80305) subject: [iPhotography] Comment on photo Monday's Photoshoot, photo: 183876
Eml: on:01.04.2021 17:06:24: cron-job (1975): Hash: ca4194fbb23e7fd80c1d31750555f1e9 added to sent mails
Eml: on:01.04.2021 17:06:24: cron-job (1975): Hash: ca4194fbb23e7fd80c1d31750555f1e9, Mail sent to: [redacted] (101488) subject: [iPhotography] Comment on photo Monday's Photoshoot, photo: 183876
Eml: on:01.04.2021 17:06:24: cron-job (1965): Hash: 0985dd7ea9637e2c46f75137250267c9 added to sent mails
Eml: on:01.04.2021 17:06:24: cron-job (1965): Hash: 0985dd7ea9637e2c46f75137250267c9, Mail sent to: [redacted] (36855) subject: [iPhotography] Comment on photo Monday's Photoshoot, photo: 183876
Eml: on:01.04.2021 17:06:24: cron-job (1975): Hash: 3080ce36ffc367958b991b97abc20427 added to sent mails
Eml: on:01.04.2021 17:06:24: cron-job (1975): Hash: 3080ce36ffc367958b991b97abc20427, Mail sent to: [redacted] (100641) subject: [iPhotography] Comment on photo Monday's Photoshoot, photo: 183876
Eml: on:01.04.2021 17:06:24: cron-job (1965): Potential receipients: 3643,36855,80305,84625,95781,101488,104541,105190,98553,100641, all subscribed potential: 36855,80305,84625,95781,98553,100641,101488,105190
Eml: on:01.04.2021 17:06:24: cron-job (1975): Hash: b9fba1d0496a9b715a96a0906899d5d6 added to sent mails
Eml: on:01.04.2021 17:06:24: cron-job (1975): Hash: b9fba1d0496a9b715a96a0906899d5d6, Mail sent to: [redacted] (98553) subject: [iPhotography] Comment on photo Monday's Photoshoot, photo: 183876
Eml: on:01.04.2021 17:06:24: cron-job (1965): superusers
Eml: on:01.04.2021 17:06:24: cron-job (1965): comment owner 100641, JoKayaks
Eml: on:01.04.2021 17:06:24: cron-job (1965): photo owner 98553, happyhannah
Eml: on:01.04.2021 17:06:24: cron-job (1965): admins 3643,36855,80305,84625,95781,101488,104541,105190
Eml: on:01.04.2021 17:06:24: cron-job (1975): Hash: 622cbf03952ce0489f532d3d352037ab added to sent mails
Eml: on:01.04.2021 17:06:24: cron-job (1975): Hash: 622cbf03952ce0489f532d3d352037ab, Mail sent to: [redacted] (95781) subject: [iPhotography] Comment on photo Monday's Photoshoot, photo: 183876
Eml: on:01.04.2021 17:06:24: cron-job (1975): Hash: 4452147011a8668325abec4fc0a51582 added to sent mails
Eml: on:01.04.2021 17:06:24: cron-job (1975): Hash: 4452147011a8668325abec4fc0a51582, Mail sent to: [redacted] (84625) subject: [iPhotography] Comment on photo Monday's Photoshoot, photo: 183876
Eml: on:01.04.2021 17:06:24: cron-job (1975): Hash: a476d22a0401eaf26deb4e04430ebba0 added to sent mails
Eml: on:01.04.2021 17:06:24: cron-job (1975): Hash: a476d22a0401eaf26deb4e04430ebba0, Mail sent to: [redacted] (80305) subject: [iPhotography] Comment on photo Monday's Photoshoot, photo: 183876
Eml: on:01.04.2021 17:06:24: cron-job (1975): Hash: 0985dd7ea9637e2c46f75137250267c9 added to sent mails
Eml: on:01.04.2021 17:06:24: cron-job (1975): Hash: 0985dd7ea9637e2c46f75137250267c9, Mail sent to: [redacted] (36855) subject: [iPhotography] Comment on photo Monday's Photoshoot, photo: 183876
Eml: on:01.04.2021 17:06:24: cron-job (1975): Potential receipients: 3643,36855,80305,84625,95781,101488,104541,105190,98553,100641, all subscribed potential: 36855,80305,84625,95781,98553,100641,101488,105190
Eml: on:01.04.2021 17:06:24: cron-job (1975): superusers
Eml: on:01.04.2021 17:06:24: cron-job (1975): comment owner 100641, JoKayaks
Eml: on:01.04.2021 17:06:24: cron-job (1975): photo owner 98553, happyhannah
Eml: on:01.04.2021 17:06:24: cron-job (1975): admins 3643,36855,80305,84625,95781,101488,104541,105190
Eml: on:01.04.2021 17:06:24: cron-job (1965): Doing mailing commentnotify for 103408 recipients. Starting id = 0
Eml: on:01.04.2021 17:06:24: cron-job (1975): Doing mailing commentnotify for 103408 recipients. Starting id = 0

Last edited 3 years ago by johnbillion (previous) (diff)
Note: See TracTickets for help on using tickets.