Make WordPress Core

Opened 13 years ago

Closed 13 years ago

#23736 closed defect (bug) (worksforme)

Transient running at incorrect intervals sometimes more often then set timeout

Reported by: keendev's profile keendev Owned by:
Milestone: Priority: normal
Severity: normal Version: 3.5.1
Component: Cache API Keywords:
Focuses: Cc:

Description

Hello all,

I have come across a bug where a transient I have running is actually being called more often then the 3600 second timeout I give it. Below is an example of my code:

<?php
function my_transient_function() {

	$final = get_transient('24_char_transient_id');
	
	if (empty($final)) $final = false;
	
	if($final === false) :
	
		/* I added the following line as i was scared the issue was the API i was calling was actually taking too long to return data
			so basically i set the transient to a value of 1, this will hopefully prevent race conditions.
		*/
		set_transient( '24_char_transient_id', '1', 3600 );
	
		/* The folowing is all my debugging efforts */
		$message = 'Message Prefix: ' . date('d-m-Y H:i:s') . PHP_EOL;
		
		ob_start();
		debug_print_backtrace();
		
		$message .= PHP_EOL;
		
		$message .= 'backtrace:' . PHP_EOL . ob_get_clean();
		$message .= PHP_EOL;
		$message .= PHP_EOL;
		
		$message .= 'server:' . PHP_EOL . print_r($_SERVER, true);

		$json_string = file_get_contents("URL_TO_API_WHICH_RETURNS_JSON_DATA"); 
		
		$message .= PHP_EOL;
		$message .= PHP_EOL;
		$message .= 'result:' . PHP_EOL . print_r($json_string, true);
		
		wp_mail( 'myemail', 'Subject Prefix: ' . date('d-m-Y H:i:s'), $message);

		
		if (empty($json_string)) {
		
			$result = array();
	
		} else {

			$parsed_json = json_decode($json_string); 
			
			// do json_parsing

			$result = $array_after_processing_parsed_json;
			
			
		}

		// $result is an array always
		$final = $result;
		
		set_transient( '24_char_transient_id', $final, 3600 );
		
	endif;
	
	return $final;
	
}
?>

So basically, I have transient calling an API service. I set the transient before calling the API to prevent a possible race condition. My debugging efforts include:

  1. First i emailed myself everytime the api call was fired. I found out due to the volume of emails I got sometimes, i would receive multiple emails in the same hour, sometimes in the same minute, this is where i knew there was a problem.
  2. Then i added the backtrace information which so far hasn't really given me enough information.
  3. Then i added the $_SERVER info too, again not much data that i can make any solid conclusions with.
  4. I then added the result of the API request inside the email too. This showed that when i received lets say 10 emails within an hour, each time i got a result back from the API, so the idea that the API is failing is out of the question.

Some of the emails I have received in the following order:

Subject Prefix: 11-03-2013 01:02:44 - Message Prefix: 11-03-2013 01:02:43 
Subject Prefix: 11-03-2013 00:01:31 - Message Prefix: 11-03-2013 00:01:30 	
Subject Prefix: 10-03-2013 23:57:16 - Message Prefix: 10-03-2013 23:57:14 	
Subject Prefix: 10-03-2013 23:52:11 - Message Prefix: 10-03-2013 23:52:09 	
Subject Prefix: 10-03-2013 23:47:33 - Message Prefix: 10-03-2013 23:47:32 
Subject Prefix: 10-03-2013 23:47:20 - Message Prefix: 10-03-2013 23:47:19 
Subject Prefix: 10-03-2013 23:47:17 - Message Prefix: 10-03-2013 23:47:16 
Subject Prefix: 10-03-2013 23:47:07 - Message Prefix: 10-03-2013 23:47:06 
Subject Prefix: 10-03-2013 23:47:03 - Message Prefix: 10-03-2013 23:47:02 
Subject Prefix: 10-03-2013 23:42:06 - Message Prefix: 10-03-2013 23:42:04 
Subject Prefix: 10-03-2013 23:37:02 - Message Prefix: 10-03-2013 23:37:00 
Subject Prefix: 10-03-2013 23:35:48 - Message Prefix: 10-03-2013 23:35:47 
Subject Prefix: 10-03-2013 23:34:12 - Message Prefix: 10-03-2013 23:34:11 
Subject Prefix: 10-03-2013 23:34:03 - Message Prefix: 10-03-2013 23:34:02 
Subject Prefix: 10-03-2013 23:34:00 - Message Prefix: 10-03-2013 23:33:59 
Subject Prefix: 10-03-2013 23:33:58 - Message Prefix: 10-03-2013 23:33:57 
Subject Prefix: 10-03-2013 23:33:08 - Message Prefix: 10-03-2013 23:33:06 
Subject Prefix: 10-03-2013 23:33:05 - Message Prefix: 10-03-2013 23:33:04 
Subject Prefix: 10-03-2013 23:31:58 - Message Prefix: 10-03-2013 23:31:56 
Subject Prefix: 10-03-2013 23:26:54 - Message Prefix: 10-03-2013 23:26:53 
Subject Prefix: 10-03-2013 23:21:51 - Message Prefix: 10-03-2013 23:21:50 
Subject Prefix: 10-03-2013 23:20:58 - Message Prefix: 10-03-2013 23:20:57 
Subject Prefix: 10-03-2013 23:16:49 - Message Prefix: 10-03-2013 23:16:48 
Subject Prefix: 10-03-2013 23:14:36 - Message Prefix: 10-03-2013 23:14:35 
Subject Prefix: 10-03-2013 23:14:34 - Message Prefix: 10-03-2013 23:14:32 
Subject Prefix: 10-03-2013 23:14:25 - Message Prefix: 10-03-2013 23:14:24 
Subject Prefix: 10-03-2013 23:11:47 - Message Prefix: 10-03-2013 23:11:45 
Subject Prefix: 10-03-2013 23:11:46 - Message Prefix: 10-03-2013 23:11:45 
Subject Prefix: 10-03-2013 23:10:27 - Message Prefix: 10-03-2013 23:10:26 
Subject Prefix: 10-03-2013 23:10:26 - Message Prefix: 10-03-2013 23:10:24 
Subject Prefix: 10-03-2013 23:09:50 - Message Prefix: 10-03-2013 23:09:49 
Subject Prefix: 10-03-2013 23:08:57 - Message Prefix: 10-03-2013 23:08:53 
Subject Prefix: 10-03-2013 23:08:52 - Message Prefix: 10-03-2013 23:08:48 
Subject Prefix: 10-03-2013 23:08:47 - Message Prefix: 10-03-2013 23:08:46 
Subject Prefix: 10-03-2013 23:06:43 - Message Prefix: 10-03-2013 23:06:42 
Subject Prefix: 10-03-2013 23:02:30 - Message Prefix: 10-03-2013 23:02:29 
Subject Prefix: 10-03-2013 23:02:27 - Message Prefix: 10-03-2013 23:02:25 
Subject Prefix: 10-03-2013 23:02:16 - Message Prefix: 10-03-2013 23:02:15 
Subject Prefix: 10-03-2013 23:01:40 - Message Prefix: 10-03-2013 23:01:38 
Subject Prefix: 08-03-2013 17:12:12 - Message Prefix: 08-03-2013 17:12:11 
Subject Prefix: 08-03-2013 16:11:46 - Message Prefix: 08-03-2013 16:11:45 
Subject Prefix: 08-03-2013 15:11:12 - Message Prefix: 08-03-2013 15:11:11 

You will notice the Subject Time does not match with the Message time as the message time is logged after the api call is made.

Notes::

  1. I would love to show the full code however it contains some sensitive data and code.
  2. Since i stripped out some code the code my not 100% work, however i checked it over and over to make sure everything looked the exact same. The only thing i did was rename some variables and remove the chunk of code which was based on what i actually did with that data.
  3. I have all these emails and there contents accessible so, if you guys need to ask me any question about emails contents i will be able to assist.

Thanks,

Change History (1)

#1 @markoheijnen
13 years ago

  • Milestone Awaiting Review deleted
  • Resolution set to worksforme
  • Status changed from new to closed

It's most likely a bug in your code. I see the result can be empty what would result in $final = false in the top of your code. So the code can run multiple times within the hour. If you only want once every hour then remove:

if (empty($final)) $final = false;

Closing as wont-fix since this seems more a support question that can be ask at http://wordpress.org/support/

Note: See TracTickets for help on using tickets.