[wp-trac] [WordPress Trac] #57924: Cron fires twice

[WordPress Trac]

#57924: Cron fires twice
-------------------------------------------+------------------------------
 Reporter:  j3gaming                       |       Owner:  j3gaming
     Type:  defect (bug)                   |      Status:  assigned
 Priority:  normal                         |   Milestone:  Awaiting Review
Component:  Cron API                       |     Version:  6.1.1
 Severity:  normal                         |  Resolution:
 Keywords:  changes-requested 2nd-opinion  |     Focuses:
-------------------------------------------+------------------------------
Changes (by j3gaming):

 * keywords:   => changes-requested 2nd-opinion


Comment:

 It's not the same microsecond, and it doesn't have to be.
 I recorded the $doing_cron_transient variable.

 My cron is triggered twice, in just the same second. With different
 microtimes.

 Here are the logs:


 {{{
 [17-Mar-2023 00:40:01 UTC] ['1679013601.6444039344787597656250'] START ---
 --- --- --- --- --- --- --- --- --- --- --- --- --- --- --- --- --- ---
 --- --- --- --- --- --- --- --- --- --- --- --- --- --- --- --- --- ---
 --- ---
 [17-Mar-2023 00:40:01 UTC] ['1679013601.6444039344787597656250'] Jobs
 ready: 1
 [17-Mar-2023 00:40:01 UTC] ['1679013601.6447730064392089843750'] START ---
 --- --- --- --- --- --- --- --- --- --- --- --- --- --- --- --- --- ---
 --- --- --- --- --- --- --- --- --- --- --- --- --- --- --- --- --- ---
 --- ---
 [17-Mar-2023 00:40:01 UTC] ['1679013601.6447730064392089843750'] Jobs
 ready: 1
 [17-Mar-2023 00:40:01 UTC] Cron reschedule event error for hook:
 crontrol_cron_job, Error code: could_not_set, Error message: The cron
 event list could not be saved. true false, Data:
 {"schedule":"minutely","args":{"code":"require_once('wp-
 content\/cron\/email_send.php');","name":"Send Emails"},"interval":"60"}
 [17-Mar-2023 00:40:01 UTC] Cron unschedule event error for hook:
 crontrol_cron_job, Error code: could_not_set, Error message: The cron
 event list could not be saved. true false, Data:
 {"schedule":"minutely","args":{"code":"require_once('wp-
 content\/cron\/email_send.php');","name":"Send Emails"},"interval":"60"}
 [17-Mar-2023 00:40:01 UTC] Started email_send
 [17-Mar-2023 00:40:01 UTC] Started email_send
 [17-Mar-2023 00:40:01 UTC] Ended email_send
 [17-Mar-2023 00:40:01 UTC] Ended email_send
 [17-Mar-2023 00:40:01 UTC] ['1679013601.6447730064392089843750']  --- ---
 --- --- --- --- --- --- --- --- --- --- --- --- --- --- --- --- --- ---
 --- --- --- --- --- --- --- --- --- --- --- --- --- --- --- --- --- ---
 --- END
 }}}

 Job # 1679013601.6444039344787597656250
 and
 Job # 1679013601.6447730064392089843750

 Starts at nearly the same time. Notice it's not exactly the same. It's
 quick enough that both are set before either script can check if something
 is set.

 Notice how I only have 1 "end"? That's because of this code near the
 bottom of the loop:


 {{{
 // If the hook ran too long and another cron process stole the lock, quit.
 if ( _get_cron_lock() !== $doing_wp_cron ) {
         return;
 }
 }}}

 The bottom of the loop detected that there was 2 running. It quit one of
 them (after executing 1 job twice). The one that quit, was the unix
 microtime that was not in the database. The one that made it into the
 database gets to continue.

 **My fix. wp-config.php**


 {{{
 // The cron lock: a unix timestamp from when the cron was spawned.
 $doing_cron_transient = get_transient( 'doing_cron' );

 // Use global $doing_wp_cron lock, otherwise use the GET lock. If no lock,
 try to grab a new lock.
 if ( empty( $doing_wp_cron ) ) {
         if ( empty( $_GET['doing_wp_cron'] ) ) {
                 // Called from external script/job. Try setting a lock.
                 if ( $doing_cron_transient && ( $doing_cron_transient +
 WP_CRON_LOCK_TIMEOUT > $gmt_time ) ) {
                         return;
                 }
                 $doing_wp_cron        = sprintf( '%.22F', microtime( true
 ) );
                 $doing_cron_transient = $doing_wp_cron;
                 set_transient( 'doing_cron', $doing_wp_cron );
         } else {
                 $doing_wp_cron = $_GET['doing_wp_cron'];
         }
 }

 // Wait x seconds before checking the database.
 sleep(2); // Could be WP_CONFIG configurable. Default could be 0, anyone
 complaining about crons running could set this to 1 or more.

 // Grab the true database value after possible racing conditions.
 $doing_cron_transient = get_transient( 'doing_cron' );

 /*
  * The cron lock (a unix timestamp set when the cron was spawned),
  * must match $doing_wp_cron (the "key").
  */
 if ( $doing_cron_transient !== $doing_wp_cron ) {
         return;
 }
 }}}

-- 
Ticket URL: <https://core.trac.wordpress.org/ticket/57924#comment:15>
WordPress Trac <https://core.trac.wordpress.org/>
WordPress publishing platform