Hello,
I'm struggling to debug an issue that seems to affect two different and
unrelated PHP scripts on a given website.
The essence of the issue is that the scripts in question (and only those
scripts) return status code 500 responses, but only some small
percentage of the time.
The effective php.ini is configured to report nearly all types of
messages (error_reporting = 6143), yet nothing is logged when this
occurs. I have confirmed that other types of PHP errors are indeed
logged, which leads me to believe that PHP is not causing these 500
responses, directly.
Here's a sample Apache log entry, from the vhost-specific log file,
e.g., /var/www/example.com/log/access.log:
X.X.X.X - - [22/Oct/2012:07:37:29 -0700] "GET
/auxiliary/css.php?file=global.css HTTP/1.1" 500 15501
"http://example.com/product/"; "Mozilla/5.0 (compatible; MSIE 9.0;
Windows NT 6.1; WOW64; Trident/5.0)"
More often than not, I see a subsequent log entry with the same
timestamp and URL, but this time, the status code is 200 (instead of
500). Sometimes a couple of seconds elapse between the 500 response (and
often there is more than one consecutive 500 response) and the 200
response. Here is an example, given the above entry:
X.X.X.X - - [22/Oct/2012:07:37:29 -0700] "GET
/auxiliary/css.php?file=global.css HTTP/1.1" 200 15481
"http://example.com/product/"; "Mozilla/5.0 (compatible; MSIE 9.0;
Windows NT 6.1; WOW64; Trident/5.0)"
There are two differences between these entries: the status code and the
content length (that's the integer value immediately after the status
code, right?). With a 500 response, the length is 15501. With a 200
response, the length is 15481. Does this tell us anything useful? In
php.ini, display_errors = off, so if a PHP error was the cause, I would
expect the content length to be *smaller* when the error occurred (given
that no error message is appended to the output), not larger.
Given that there is only one reference to the URL
"/auxiliary/css.php?file=global.css" in my source HTML, why are there
two entries in access.log?
Is Apache automatically re-requesting the file, internally, when a 500
error occurs? This seems unlikely to me, but I don't know how else to
interpret this. Also, it seems unlikely that the user-agent could make
two separate requests in such rapid succession (within the same second),
especially before it has any way to know that the first request resulted
in a 500 response.
Another curious fact is that the corresponding entries in the
server-wide log file (/var/log/apache2/other_vhosts_access.log) show
zero for the content length:
example.com:80 X.X.X.X - - [22/Oct/2012:07:37:29 -0700] "GET
/auxiliary/css.php?file=global.css HTTP/1.1" 500 0
"http://example.com/product/"; "Mozilla/5.0 (compatible; MSIE 9.0;
Windows NT 6.1; WOW64; Trident/5.0)"
Here are my log-related Apache directives:
-----------------------------
LogLevel warn
#
# The following directives define some format nicknames for use with
# a CustomLog directive (see below).
# If you are behind a reverse proxy, you might want to change %h into
%{X-Forwarded-For}i
#
LogFormat "%v:%p %h %l %u %t \"%r\" %>s %O \"%{Referer}i\"
\"%{User-Agent}i\"" vhost_combined
LogFormat "%h %l %u %t \"%r\" %>s %O \"%{Referer}i\" \"%{User-Agent}i\""
combined
LogFormat "%h %l %u %t \"%r\" %>s %O" common
LogFormat "%{Referer}i -> %U" referer
LogFormat "%{User-agent}i" agent
#
# Define an access log for VirtualHosts that don't define their own logfile
CustomLog /var/log/apache2/other_vhosts_access.log vhost_combined
-----------------------------
Is there any means by which to acquire more information about the root
cause of a 500 response? Should I increase the LogLevel value? Or is
that pointless here?
As stated above, there isn't a single entry in the vhost-specific Apache
error log (to which all PHP errors are logged) for the same 24-hour
period in question, so I don't expect PHP to be able to tell us anything
more.
Maybe somebody else is able to derive additional meaning from the log
entries and content lengths.
Apache/2.2.14 (Ubuntu)
PHP 5.3.2-1ubuntu4.18
Server API CGI/FastCGI
Thanks for any help!
-Ben
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@xxxxxxxxxxxxxxxx
For additional commands, e-mail: users-help@xxxxxxxxxxxxxxxx
|