Max execution time exceeded in a strange place

[SpookTech]

Hi, I have the following PHP code

#Load the user preference types from the database
$sql="
	SELECT `typeID`, `type`, `typeType`, `typeDefault`
	FROM `usr_preftypes`
";
$sql_prefTypes=sqlQuery($sql,'sys:loadPrefTypes');

#Loop through the preference types and create the preference array and an array of preference data
$prefData=array();
$system['user']['prefs']=array();
while($prefType=mysql_fetch_assoc($sql_prefTypes)){

$prefData[$prefType['typeID']]=Array(
	'type'=>$prefType['type'],
	'typeType'=>$prefType['typeType']
);

#Check what type of setting it is
switch($prefType['typeType']){

	case 'boolean':

		$prefValue=($prefType['typeDefault']=='1');
		break;

	case 'integer':

		$prefValue=intval($prefType['typeDefault']);
		break;

	default:
		$prefValue=$prefType['typeDefault'];
}

$system['user']['prefs'][$prefType['type']]=$prefValue;
}

The code works perfectly but roughly once a week I get the following error
[14-May-2011 16:31:32] PHP Fatal error: Maximum execution time of 30 seconds exceeded in /var/www/.........../system.php on line 706.

Line 706 is "$prefValue=$prefType['typeDefault'];" after "default:". This entire file (862) lines consistently loads in a fraction of a second. I thought it's possible that something occasionally gets delayed such as one of the SQL queries further up the code but everytime I get this error it's on the exact same line. This file has around 10 queries so if that were the case I would expect the error to be in a random place.

Once I got the following error
[06-May-2011 05:04:00] PHP Fatal error: Invalid opcode 49/8/8. in /var/www/.........../system.php on line 707

That makes even less sense as line 707 is only a "}".

Is there anything wrong with my code that could cause this strange behaviour or could this be a bug in PHP?

PHP Version: 5.1.6
System: Redhat Linux 2.6.18-53.el5PAE #1
Apache Version: 2.2.17

[NogDog]

First thing to check is that the source code you are looking at is exactly what is on your host, i.e.: not a stale copy on your development machine, on the off chance that either the two are out of sync or someone has injected malicious code into the live version. (I'm not saying you have to view it on your production host, but make sure you've FTP'd the production host version or otherwise copied it to ensure that is the exact version you're looking at.)

If that's not the issue, I'm afraid I have no "Eureka" insight for you at this time. 🙁

[SpookTech]

Unfortunately it's not a stale copy issue. I'm on the same network as the server and loading the file through samba.

[jgetner]

you can extend your max execution time in your php.ini or you can use the set_time_limit() function to set how long the script should run.

[SpookTech]

The max execution time itself is not a problem. 30 seconds is more than enough time for the script to run as I've never seen it take more than a second even under high load.

[jgetner]

this here makes little sense to be honest could work but from what i can see its your loading problem.

       $prefData[$prefType['typeID']]=Array('type'=>$prefType['type'], 'typeType'=>$prefType['typeType']

to walk through each thing is your create an array $prefData and then fill all the keys with your results from table IDs and make those keys equal an array then in those array's you have 2 keys that pertian to your results set.

so depending on the results the load time could vary and you run this in a while loop so this code runs over and over on every execution of the script .

[SpookTech]

The reason for that line is to create an array of the data returned from the SQL query. This data doesn't need the typeDefault field at all and it needs to be indexed using the typeID. Currently there are only about 5 rows returned from that SQL query and each field is only a few bytes.

I don't think there is a speed issue with anything in this file since it always loads almost instantly. If it were a line higher up than where I get the error then surely the error would appear on different lines.

I've read somewhere that PHP's max execution time excludes SQL queries so even if a query is delayed it should not affect the script. Even assuming this is not true then you would expect to see the error appearing on the line that runs the query (or at least inside the sqlQuery() function).

In the past I have had errors similar to this that always appear on the same line and they have been caused by infinite loops. I don't see how an infinite loop is possible in this code though unless there is a bug in mysql_fetch_assoc() that prevents it from moving to the next record.

[SpookTech]

I have a little more information on this. Yesterday the error log was flooded with even stranger errors.

[05-Jun-2011 05:44:01] PHP Warning: main() [<a href='function.main'>function.main</a>]: php_network_getaddresses: getaddrinfo failed: ai_socktype not supported in /var/www/.........../system.php on line 706

Almost 140,000 errors were logged in the space of 10 seconds eventually followed by:-

[05-Jun-2011 05:44:10] PHP Fatal error: Allowed memory size of 33554432 bytes exhausted (tried to allocate 10240 bytes) in /var/www/.........../system.php on line 706

This is the exact same line number as the original error and I have edited that file since. Line 706 is now unset($prefType); (the code has been moved up slightly and this line is after the original code I posted).

I really don't know what is happening here. As far as I know there has never been a call to main() in the entire site nor is getaddrinfo mentioned anywhere. I'm pretty confident that the error is not in system.php and it is just picking up the wrong filename. system.php is the main include file that is loaded before everything.

I hope someone will have some ideas of where to start looking or how to track this one down.

[NogDog]

The "php_network_getaddresses: getaddrinfo failed" error appears to be related to some sort of DNS error, possibly when trying to fopen(), file(), include(), etc. to a URL or IP address. As to why it would point to that line number I have no idea, unless it's a bug in the PHP error reporting?

Anyway, if it is, in fact, some kind of server hiccup causing the DNS issue, it might be "interesting" to change any place in your script where you are accessing a file by URL to instead use the [man]cURL[/man] functions to get it instead of PHP's file*() functions. (You might still have errors if the server does any DNS barfing again, but maybe not PHP out of memory errors.) But no guarantees at all. 😉

[SpookTech]

I've done a lot of searching through files and I think I may have tracked down where it's coming from. This may be a little hard to follow but I will try to explain it well.

The file that gets called is /modules/stock-update.php. This file (along with every other callable file in the system) includes /resources/system.php. This is done using the normal include() function.

system.php includes a number of other files. 2 of these other files are /resources/functions/console.php and /resources/functions.php.

stock-update.php also includes /modules/stock-update.class.php using includeFile() which is a wrapper for include() and is defined in functions.php.

In stock-update.class.php on line 705 there is the following line.
addConsoleMessage('stockupdate','I8003',$server['serverID']);

The addConsoleMessage() function is defined in console.php and calls consoleConnect() in the same file which then calls socket_create(), socket_set_nonblock(), gethostbyname(), socket_connect() and stocket_last_error(). All of these are above line 45 in the file.

This is the only place any of these functions are used in the entire system. All local files are included using include() or includeFile() and all remote requests (except console messages) use cURL. It does seem a little complicated but I can't see anything else it could be. It seems as though PHPs error system is getting confused somewhere due to the includes.

The console host is a fixed constant and it is listed in /etc/hosts so it shouldn't be a lookup error. The host is on the same network but it is a Windows server which does have a habit of restarting for Windows update around the time of the last set of errors.

Thanks for your help. Unless you think I've got it wrong I'm just going to ignore these errors as the console connection is only for debugging.

[NogDog]

Sounds like a good guess to me, at least that would certainly be something that might respond badly to a DNS hiccup on the server.