pukos

I also wait for this feature

Hi @vmarko
First of all, thank you for taking care of this problem. I know this is a free product anyway there is more people than you expect with the same problem and this should be a good occasion to investigate togheter.

Repliyng to you…

1. It does not depend on the time because I left object enable for 2 hours and none of the task has been executed. (according to my Cron events plugin)

2. Same as above. Even if in the debug I can see some specific hook has been executed, it is still pending in queue.

3. Not very sure to had understood this sentence 🙂

Please don’t give up, maybe together we can understand the problem.

[24-Oct-2019 15:10:08 UTC] im return from line 75
[24-Oct-2019 15:10:08 UTC] im return from line 81
[24-Oct-2019 15:10:08 UTC] im return from line 83
[24-Oct-2019 15:10:08 UTC] im return from line 86
[24-Oct-2019 15:10:08 UTC] im return from line 100
[24-Oct-2019 15:10:08 UTC] im return from line 109
[24-Oct-2019 15:10:08 UTC] im return from line 126
[24-Oct-2019 15:10:08 UTC] im return from line 128 action_scheduler_run_queue
[24-Oct-2019 15:10:08 UTC] im return from line 139
[24-Oct-2019 15:10:08 UTC] im return from line 71
[24-Oct-2019 15:10:08 UTC] im return from line 126
[24-Oct-2019 15:10:08 UTC] im return from line 128 nxs_querypost_event
[24-Oct-2019 15:10:08 UTC] im return from line 139
[24-Oct-2019 15:10:08 UTC] im return from line 71
[24-Oct-2019 15:10:08 UTC] im return from line 126
[24-Oct-2019 15:10:08 UTC] im return from line 128 wpdiscuz_gravatars_cache_add
[24-Oct-2019 15:10:11 UTC] im return from line 139
[24-Oct-2019 15:10:11 UTC] im return from line 71
[24-Oct-2019 15:10:11 UTC] im return from line 126
[24-Oct-2019 15:10:11 UTC] im return from line 128 newsletter_bounce_run
[24-Oct-2019 15:10:11 UTC] im return from line 139
[24-Oct-2019 15:10:11 UTC] im return from line 71
[24-Oct-2019 15:10:11 UTC] im return from line 126
[24-Oct-2019 15:10:11 UTC] im return from line 128 newsletter
[24-Oct-2019 15:10:11 UTC] im return from line 139
[24-Oct-2019 15:10:11 UTC] im return from line 71
[24-Oct-2019 15:10:11 UTC] im return from line 126
[24-Oct-2019 15:10:11 UTC] im return from line 128 advanced-ads-placement-tests-emails
[24-Oct-2019 15:10:11 UTC] im return from line 139
[24-Oct-2019 15:10:11 UTC] im return from line 71
[24-Oct-2019 15:10:11 UTC] im return from line 126
[24-Oct-2019 15:10:11 UTC] im return from line 128 jetpack_sync_full_cron
[24-Oct-2019 15:10:11 UTC] im return from line 139
[24-Oct-2019 15:10:11 UTC] im return from line 71
[24-Oct-2019 15:10:11 UTC] im return from line 126
[24-Oct-2019 15:10:11 UTC] im return from line 128 jetpack_sync_cron
[24-Oct-2019 15:10:11 UTC] im return from line 139
[24-Oct-2019 15:10:11 UTC] im return from line 71
[24-Oct-2019 15:10:11 UTC] im return from line 126
[24-Oct-2019 15:10:11 UTC] im return from line 128 wptelegram_widget_cron_pull_updates
[24-Oct-2019 15:10:11 UTC] im return from line 139
[24-Oct-2019 15:10:11 UTC] im return from line 71
[24-Oct-2019 15:10:11 UTC] im return from line 148
[24-Oct-2019 15:10:11 UTC] im return from line 71
[24-Oct-2019 15:10:11 UTC] im return from line 152

Thank you @vmarko
I didn’t understood very well where/how to put your “simple script”, anyway I added a lot of “error_log(‘im return from line XXX’);” and I could finally log them.
I attached both the code and the log. I hope you have enough clues to understand why the object cache causes this problem.

THIS IS WP-CRON.PHP

<?php
/**
 * A pseudo-CRON daemon for scheduling WordPress tasks
 *
 * WP Cron is triggered when the site receives a visit. In the scenario
 * where a site may not receive enough visits to execute scheduled tasks
 * in a timely manner, this file can be called directly or via a server
 * CRON daemon for X number of times.
 *
 * Defining DISABLE_WP_CRON as true and calling this file directly are
 * mutually exclusive and the latter does not rely on the former to work.
 *
 * The HTTP request to this file will not slow down the visitor who happens to
 * visit when the cron job is needed to run.
 *
 * @package WordPress
 */

ignore_user_abort( true );

/* Don't make the request block till we finish, if possible. */
if ( function_exists( 'fastcgi_finish_request' ) && version_compare( phpversion(), '7.0.16', '>=' ) ) {
	error_log('im return from line 23');
	fastcgi_finish_request();
}

if ( ! empty( $_POST ) || defined( 'DOING_AJAX' ) || defined( 'DOING_CRON' ) ) {
	error_log('im return from line 27');
	die();
}

/**
 * Tell WordPress we are doing the CRON task.
 *
 * @var bool
 */
define( 'DOING_CRON', true );

if ( ! defined( 'ABSPATH' ) ) {
	/** Set up WordPress environment */
	require_once( dirname( __FILE__ ) . '/wp-load.php' );
}

/**
 * Retrieves the cron lock.
 *
 * Returns the uncached <code>doing_cron</code> transient.
 *
 * @ignore
 * @since 3.3.0
 *
 * @global wpdb $wpdb WordPress database abstraction object.
 *
 * @return string|false Value of the <code>doing_cron</code> transient, 0|false otherwise.
 */
function _get_cron_lock() {
	global $wpdb;

	$value = 0;
	if ( wp_using_ext_object_cache() ) {
		/*
		 * Skip local cache and force re-fetch of doing_cron transient
		 * in case another process updated the cache.
		 */
		$value = wp_cache_get( 'doing_cron', 'transient', true );
	} else {
		$row = $wpdb->get_row( $wpdb->prepare( "SELECT option_value FROM $wpdb->options WHERE option_name = %s LIMIT 1", '_transient_doing_cron' ) );
		if ( is_object( $row ) ) {
			$value = $row->option_value;
		}
	}
	error_log('im return from line 71');
	return $value;
}
error_log('im return from line 75');
$crons = wp_get_ready_cron_jobs();
if ( empty( $crons ) ) {
	error_log('im return from line 77');
	die();
}
error_log('im return from line 81');
$gmt_time = microtime( true );
error_log('im return from line 83');
// The cron lock: a unix timestamp from when the cron was spawned.
$doing_cron_transient = get_transient( 'doing_cron' );
error_log('im return from line 86');
// Use global $doing_wp_cron lock otherwise use the GET lock. If no lock, trying grabbing 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_cron_transient = $doing_wp_cron = sprintf( '%.22F', microtime( true ) );
		set_transient( 'doing_cron', $doing_wp_cron );
	} else {
		$doing_wp_cron = $_GET['doing_wp_cron'];
	}
}
error_log('im return from line 100');
/*
 * 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 ) {
	error_log('im return from line 106');
	return;
}
error_log('im return from line 109');
foreach ( $crons as $timestamp => $cronhooks ) {
	if ( $timestamp > $gmt_time ) {
		error_log('im return from line 112');
		break;
	}

	foreach ( $cronhooks as $hook => $keys ) {

		foreach ( $keys as $k => $v ) {

			$schedule = $v['schedule'];

			if ( $schedule != false ) {
				$new_args = array( $timestamp, $schedule, $hook, $v['args'] );
				call_user_func_array( 'wp_reschedule_event', $new_args );
			}
error_log('im return from line 126');
			wp_unschedule_event( $timestamp, $hook, $v['args'] );
error_log('im return from line 128');
			/**
			 * Fires scheduled events.
			 *
			 * @ignore
			 * @since 2.1.0
			 *
			 * @param string $hook Name of the hook that was scheduled to be fired.
			 * @param array  $args The arguments to be passed to the hook.
			 */
			do_action_ref_array( $hook, $v['args'] );
error_log('im return from line 139');
			// If the hook ran too long and another cron process stole the lock, quit.
			if ( _get_cron_lock() != $doing_wp_cron ) {
				error_log('im return from line 141');
				return;
			}
		}
	}
}
error_log('im return from line 148');
if ( _get_cron_lock() == $doing_wp_cron ) {
	delete_transient( 'doing_cron' );
}
error_log('im return from line 152');
die();

THIS IS THE ACTIONS LOGGED

[19-Oct-2019 06:30:02 UTC] im return from line 75
[19-Oct-2019 06:30:02 UTC] im return from line 81
[19-Oct-2019 06:30:02 UTC] im return from line 83
[19-Oct-2019 06:30:02 UTC] im return from line 86
[19-Oct-2019 06:30:02 UTC] im return from line 100
[19-Oct-2019 06:30:02 UTC] im return from line 109
[19-Oct-2019 06:30:02 UTC] im return from line 126
[19-Oct-2019 06:30:02 UTC] im return from line 128
[19-Oct-2019 06:30:02 UTC] im return from line 139
[19-Oct-2019 06:30:02 UTC] im return from line 71
[19-Oct-2019 06:30:02 UTC] im return from line 126
[19-Oct-2019 06:30:02 UTC] im return from line 128
[19-Oct-2019 06:30:02 UTC] im return from line 139
[19-Oct-2019 06:30:02 UTC] im return from line 71
[19-Oct-2019 06:30:02 UTC] im return from line 126
[19-Oct-2019 06:30:02 UTC] im return from line 128
[19-Oct-2019 06:30:02 UTC] im return from line 139
[19-Oct-2019 06:30:02 UTC] im return from line 71
[19-Oct-2019 06:30:02 UTC] im return from line 126
[19-Oct-2019 06:30:02 UTC] im return from line 128
[19-Oct-2019 06:30:02 UTC] im return from line 139
[19-Oct-2019 06:30:02 UTC] im return from line 71
[19-Oct-2019 06:30:02 UTC] im return from line 126
[19-Oct-2019 06:30:02 UTC] im return from line 128
[19-Oct-2019 06:30:02 UTC] im return from line 139
[19-Oct-2019 06:30:02 UTC] im return from line 71
[19-Oct-2019 06:30:02 UTC] im return from line 126
[19-Oct-2019 06:30:02 UTC] im return from line 128
[19-Oct-2019 06:30:02 UTC] im return from line 139
[19-Oct-2019 06:30:02 UTC] im return from line 71
[19-Oct-2019 06:30:02 UTC] im return from line 126
[19-Oct-2019 06:30:02 UTC] im return from line 128
[19-Oct-2019 06:30:02 UTC] im return from line 139
[19-Oct-2019 06:30:02 UTC] im return from line 71
[19-Oct-2019 06:30:02 UTC] im return from line 148
[19-Oct-2019 06:30:02 UTC] im return from line 71
[19-Oct-2019 06:30:02 UTC] im return from line 152