Debugging WordPress PHP Errors

During my recent them upgrade I had some challenges with the Now Reading Reloaded plugin for WordPress and the frustrating “HTTP 500: Internal Server Error” messages. This took me on a journey of exploration into how the php modules used by WordPress and its plugins ended up as HTML on my browser and what logs were available to help me diagnose the 500 error.

The following article looks at how the pieces fit together in a typical Apache/PHP deployment (for WordPress and other PHP-based applications) and then shows how the pieces can be used to identify code problems….

Understanding the Apache/PHP Pieces

This part of the article looks at the major components involved in taking the PHP files and serving them up to your browser as HTML code.

Overview of the flow – php to browser

The following figure shows the major components involved in a typical Apache/PHP deployment on a Linux/UNIX system.

The components involved in the flow are across the middle of the figure:

• The user at the browser makes a request for some .php program (url, link etc.) and this is sent to the web server as a HTTP request.
• The main function of a web (or HTTP) server is to respond to HTTP requests and serve up HTML-based content; i.e. web pages. By default it will serve .html (or .htm etc.) files. However it can be configured to process other files. For php files an interpreter (or processor) is required to process the php code and pass the resulting HTML code back to the web server (and on to the browser). There are a number of ways this can be done, such as:
  • running a CGI binary to process the php code
  • using one of the Apache modules, such as mod_php or mod_suphp, which will process the php code.
• If mod_php is being used, it will execute the php_cgi executable directly. If mod_suphp is being used, a wrapper executable will execute php_cgi on behalf of the user.
• The php_cgi executable will process the appropriate php file and pass the resulting HTML code back to the web server which sends it on to the browser.

This is a very simplified view, but it’s enough info to help understanding of what’s going on when something breaks.

Logfiles

As can be seen in the above diagram, there are a number of logfiles written to by the components in the flow:

• Web server access log – this file is written by the HTTP (Web) server and contains a record of all traffic flowing through the web server. The name/location of this log may be defined in the httpd.conf file.
• Web server error log – this file contains all the error messages generated by the HTTP Server. It’s name/location and the level of logging is specified in the httpd.conf file. This may include errors from the php_cgi executable when it’s processing specific php files.
• suphp error log – this is written by the suphp executable (if used) and is unlikely to contain anything of use for php problem diagnosis.
• php_cgi error log – this is written by the php_cgi executable. It’s name/location is specified in the php.ini file and may go to the syslog (common system log) or the HTTP server error log.

Which Error Log is PHP Using?

As you can see from the previous section, there are a number of places that your PHP installation may write error messages to, depending on how it’s been installed and configured.

If you’re like me, you’ve got a hosting package and all of this has been done for you. In this case many of the configuration files are hidden, but there are still ways to check:

#1. The settings are defined in php.ini. In many PHP deployments, particularly in a hosted environment where many users may be sharing a common installation, there will be local php.ini files defined that override the system-wide settings. All you need to do is find your php.ini, open it up and look for the error_log setting. For example:

; Log errors to specified file.
error_log = /home/fred/logs/php_error_log;

#2. If you’re operating in a hosted environment, you may have an interface such as cPanel that provides an interface to view the php.ini settings.

#3. There is a phpinfo() function that can be run to dump out all php settings. This can be put into a simple php file and run by addressing it in the browser address bar. For example, create a file called phpinfo.php in the root of your webspace (such as the public_html directory) with the following code:

<?php
phpinfo();
?>

Then access the file in the browser…. http://mywebsite.com/phpinfo.php. You should be able to see the error_log value in the resulting output.

So now you know how to find the three most important files; the web server access log, the web server error log and the php error log (which may be the same as the web server error log). Now we’re ready to have a look at an example.

Exploring a HTTP 500 Internal Server Error

When working with php code, a 500 error is likely to mean there’s a problem with processing the php files or executing the php executable; a 500 error rarely indicates a problem with the HTTP server itself. We will look at the information provided by each of the logs for a HTTP 500 error.

I was hoping to use a real example from the problems I was having, but unfortunately I didn’t keep copies of all the logs and some of the archives have rolled over.

Web Server Access Log

The web server access log will show little information on the 500 error. The following is an extract of an access log showing a 500 error:

65.190.173.209 - - [07/Aug/2009:01:34:01 -0500] "GET /blog/2009/01/25/week-20-under-my-belt HTTP/1.1" 200 17910 "-" "Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; .NET CLR 1.1.4322)"
65.190.173.209 - - [07/Aug/2009:01:34:03 -0500] "POST /blog/wp-comments-post.php HTTP/1.1" 500 1195 "http://davidedwardsphotos.com/blog/2009/01/25/week-20-under-my-belt" "Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; .NET CLR 1.1.4322)"

In this case the browser at 65.190.173.209 is requesting the page /blog/2009/01/25/week-20-under-my-belt and the web server is returning the 500 error. It’s not really giving any useful information.

Web Server Error Log

Unfortunately I can’t see the error logs on my site, other than a very short set of recent errors, none of which indicate 500 errors.

PHP Error Log

The php error log has a wealth of information indicating problems. Here are some examples…

#1. Unexpected string error…

[07-Jul-2009 11:55:25] PHP Parse error:  syntax error, unexpected T_STRING in /home/fred/public_html/test_blog/wp-content/themes/kyoto-green-20/date.php on line 66

In this case you would need to explore what changes were made to the data.php file or if there was some corrupt data.

#2. Out of memory errors…

[08-Jul-2009 01:44:13] PHP Fatal error:  Out of memory (allocated 31719424) (tried to allocate 11632849 bytes) in /home/fred/public_html/test_blog/wp-includes/wp-db.php on line 445
[08-Jul-2009 01:59:42] PHP Fatal error:  Out of memory (allocated 31719424) (tried to allocate 11551107 bytes) in /home/fred/public_html/test_blog/wp-includes/wp-db.php on line 445
[08-Jul-2009 02:23:23] PHP Fatal error:  Out of memory (allocated 33816576) (tried to allocate 20639377 bytes) in /home/fred/public_html/test_blog/wp-includes/wp-db.php on line 445
[08-Jul-2009 03:48:17] PHP Fatal error:  Out of memory (allocated 33816576) (tried to allocate 20432709 bytes) in /home/fred/public_html/test_blog/wp-includes/wp-db.php on line 445
[08-Jul-2009 04:04:44] PHP Fatal error:  Out of memory (allocated 33816576) (tried to allocate 20436801 bytes) in /home/fred/public_html/test_blog/wp-includes/wp-db.php on line 445
[08-Jul-2009 04:05:54] PHP Fatal error:  Out of memory (allocated 31981568) (tried to allocate 11553151 bytes) in /home/fred/public_html/test_blog/wp-includes/wp-db.php on line 445
[08-Jul-2009 05:50:46] PHP Fatal error:  Out of memory (allocated 33816576) (tried to allocate 20436801 bytes) in /home/fred/public_html/test_blog/wp-includes/wp-db.php on line 445
[08-Jul-2009 05:57:27] PHP Fatal error:  Out of memory (allocated 33816576) (tried to allocate 20643469 bytes) in /home/fred/public_html/test_blog/wp-includes/wp-db.php on line 445
[08-Jul-2009 06:33:47] PHP Fatal error:  Out of memory (allocated 37486592) (tried to allocate 9399953 bytes) in /home/fred/public_html/test_blog/wp-content/plugins/bluetrait-event-viewer/btev.php on line 1398

In these cases you would check the PHP memory settings. However, for my environment the bluetrait event viewer was using too much memory and not leaving enough for the other php modules.

#3. Out of memory errors…

[03-Aug-2009 05:45:59] PHP Fatal error:  Class 'WP_Widget' not found in /home/fred/public_html/blog/wp-content/plugins/wp-email/wp-email.php on line 1312
[03-Aug-2009 05:46:00] PHP Fatal error:  Class 'WP_Widget' not found in /home/fred/public_html/blog/wp-content/plugins/wp-email/wp-email.php on line 1312

As above, I’d be checking whether that module had changed recently. Perhaps the plugin wasn’t installed correctly.

Hopefully this has given you an understanding of how a php file is processed and how to investigate HTTP 500 errors when they occur.