trying to track down a 500 error, do these things look ok to you?

[jboy]

I'm (or more accurately, users of the site are) intermittently getting a 500 server error for two particular files. These files usually are served up fine but every now and then, 500 -- I can see this from the standard server log.

The two files in question are both php files but served up as css.

I have this in the .htaccess of the root directory of the subdomain (the css/php files are on a subdomain which is full of component files and set to cache indefinitely):

CookieTracking off

# stop auto index (which shows dir contents when there's no index.html/php file)
Options -Indexes

# caching -- start
Header unset ETag
FileETag None
Header unset Last-Modified
Header set Expires "Thu, 1 Jan 2030 00:00:00 GMT"
Header set Cache-Control "public, no-transform"
# caching -- end

RewriteEngine On
RewriteRule ^(.*)\.css$ \1.css.php [NC]

I guess the likely culprit is the RewriteRule?

The two css/php files are in a directory in the root directory. In that directory's .htaccess file is this:

# compression -- start
SetOutputFilter DEFLATE
# compression -- end

In the php/css files is this:
header('Content-type: text/css');

The pattern the log indicates is when the 500 error occurs that user has already been served up the now erroring file fine (why caching isn't working for them I'm not sure -- I mean once they get this file their browser shouldn't be asking for it again -- maybe that's a browser issue).

For one of the two intermittently erroring css/php files, the number of bytes served, as reported in the server log, is correct every time -- on error. The other one, not so. No error: 76160 bytes, error: 73630. I've looked in that file's output where 73630 is, and that hasn't helped at all.

Usually these two files are served up fine. I've not been able to get it to error for me. But obviously there is a problem and I can't work out what it is. Any ideas?

Thanks.

[g1smd]

Add the [L] flag to the RewriteRule.

The \1 is likely to be the problem. Did you mean /1 here?

What is found in the Server ERROR Log?

Additionally, delete the ^(.*) part. The .* is greedy. It will grab the whole incoming request and then have to "back off" at least four times retrying with <almost-everything>s, then <almost-everything>ss, then <almost-everything>css, then <almost-everything>.css until a match has been found.

Without the .* telling it to "grab everything", the request can be parsed from left to right in a single pass until the period is matched, then continue onwards, matching the c, s and s to finish.

[jboy]

> Add the [L] flag to the RewriteRule.

Like this?:

RewriteRule ^(.*)\.css$ \1.css.php [NC,L]

> The \1 is likely to be the problem. Did you mean /1 here?

That part is referring to/accessing what the (.*) part captures/remembers. Is \1 not the right way to do that? If not, it's strange it works at all. So should that be /1 ? I guess so, maybe.

> What is found in the Server ERROR Log?

I'm not sure how to access that. I'm on a shared host and don't think I have direct access. I'll write to the hosting company to ask them.

Thanks.

[jboy]

I've changed the rewrite line to this now:

RewriteRule ^(.*)\.css$ /1.css.php [NC,L]

and it's still working so fingers crossed -- I'll leave it like that and see if the 500's stop [edit: I've just noticed you've added a bit to your message, have yet to read properly that but I see you're suggesting changing (.*) bit -- will look at that further now, thanks]

I've also written to the hosting company about the error log, I'll report back if anything got from that.

Thanks.

[jboy]

> Additionally, delete the ^(.*) part. ....

Ok, thanks, but obviously something has to go there, what should that be? I want to internally rewrite any external css requests to exactly the same request but with .php on the end, e.g. external request:
/c/thefile-1.css
should be rewritten internally to
/c/thefile-1.css.php

Thanks.

[jboy]

Just a side question: Is it quite common for browsers to ignore "cache this -- don't keep asking the server for it" directives (like what is in my first post above) ? Either that or there's something wrong with that caching code.

[g1smd]

You might try /$1 in place of \1 here. I didn't realise you were using a backreference. The leading / is required to avoid a nasty flaw.

As above, the (.*) pattern is not the best way to do this. I would use ^([^.]+)\.css$ here, as it can be parsed from left to right in one pass.

[jboy]

OK, great, I've got:
RewriteRule ^([^.]+)\.css$ /$1.css.php [NC,L]
in now, and again it seems to work after emptying my browser's cache and accessing it, so hopefully that'll stop the 500 errors. Strange it was intermittent. Strange it worked at all in the first place (in particular \1 instead of /$1).
Thanks very much.

[jboy]

Hasn't fixed it. Got one 500 error yesterday from one of the two files (I can't access server logs until the next day). Any other ideas anyone? Thanks.

[jboy]

The two files which are erroring, nearly always the server log indicates the right amount of bytes have been output. 23977 is the right amount.

........ - - [25/Jan/2011:00:23:28 +0000] "GET /c/main-1.css HTTP/1.1" 500 23977 "htt....

What does that say? Does that make it clear the problem is not in the code (it is actually a php file not css, so there's code executing in the main-1.css files)? Does that make it clear it's some server related thing (mod_rewrite, or some server set up, .htaccess etc.) not the PHP code?

[jboy]

This is what the hosting company said about the error log:

There are no errors in the server error log that coincide in time with
when you get the 500 error from your site, so it isn't a normal error as
far as I can tell.

[jboy]

anyone?

[jboy]

I've found something out. In the first post above I described the .htaccess set up on this subdomain where the two files erroring are. As described above, the two files are in a directory in the subdomain, and along with those two files is a further .htaccess which contains SetOutputFilter DEFLATE which I've now found out isn't working. The files aren't being compresssed (so maybe this is a source of the 500?).

The exact same line of code to make the files get compressed is also in the .htaccess of the main domain -- and it's working fine there. So the server is OK with SetOutputFilter DEFLATE in one place but not where the two erroring files are. Any thoughts on that? Thanks.

[jboy]

So just to make things clearer, this describes the set up a bit more:

subdomain.domain.com/.htaccess << the first .htaccess described in first post starting with CookieTracking off

subdomain.domain.com/dir/ << the directory where the two erroring files are

subdomain.domain.com/dir/.htaccess << SetOutputFilter DEFLATE -- not working.

domain.com/.htaccess << a bunch of things including SetOutputFilter DEFLATE which works fine

[jdMorgan]

Without access to a server error log, this is going to be something you'll have to pay your host to debug for you... or get a better hosting set-up.

Look at the php script that is producing the css file. Since you say that the byte count is correct even on error, this would indicate a possible error in the script *after* the css file has been output. At this point, the script could throw an error and write a 500 error code in your access log, and yet the css "file" content would be correct.

Jim

[jboy]

Thanks very much for that. The hosting company has checked the error log for me and says there's nothing there; So I suppose the error reporting setup is falling short. Which amounts to the same thing you suggest; "get a better hosting set-up".

Look at the php script that is producing the css file. Since you say that the byte count is correct even on error, this would indicate a possible error in the script *after* the css file has been output. At this point, the script could throw an error and write a 500 error code in your access log, and yet the css "file" content would be correct.

You're the first person to comment on that (the possible meaning of transferred bytes being correct even on error) in any way, and I've asked several people/places, so thanks very much for that.

So it's quite possible for the PHP to be incorrect and still output the right number of bytes and cause a 500 error after the output.

I guess, it's also possible for the PHP script to be fine, output the right number of bytes, and for the error to come from the .htaccess or server set up.

The guy at the hosting company said he feels (a gut instinct kind of thing) the compression (which was in the .htaccess which was in a sub folder, which was on the subdmain) is a likely culprit. So I've removed that and am waiting and seeing. No 500 errors yet but that isn't saying much, it's only been like that a short time.

So I'll see if that turns out to be the source of the 500 errors or not.

Thanks.

[g1smd]

Run 7 days at a time with the setting on, then 7 with it off.

Repeat until there is a clear pattern of errors.

[jboy]

And just to add, I found that, while doing a few tests, removing the comression line from
subdomain.domain.com/dir/.htaccess
(therefore deleting that .htaccess file as the compression line was the only thing in it) and putting the compression line in
subdomain.domain.com/.htaccess
made the compression work. (I haven't left it like that, I've left it without any compression line to see if that's the source).

The reason the compression line wasn't working in subdomain.domain.com/dir/.htaccess may have been something to do with the rewrite which is being applied to files in subdomain.domain.com/dir/

Also, I had I think oddness (which may be a clue to why the compression wasn't working and maybe the 500 errors) when trying to use
<FileMatch "....">
SetOutputFilter DEFLATE
</FileMatch>
(where .... means a whole bunch of attempts)

All the basic examples I found of FileMatch has this kind of regex pattern: "\.(php|css|js)$" which makes sense to me. Nothing with \. on the front, nor $ on the end worked to get the
subdomain.domain.com/dir/file.css.php
files to compress (remember, the external accessses coming in are subdomain.domain.com/dir/file.css and the rewrite as described above puts .php on the end)
The only regex pattern that worked in the FileMatch to get those files compressed was "php". As soon as I added anything to that, like \. before it, or $ after it, it then failed to work. What on earth is going on there? Using <FileMatch "php"> is surely not good enough? Maybe it is, but even if it is, this all doesn't make any sense to me. Any thoughts? Thanks.

[edited by: jboy at 2:36 pm (utc) on Feb 1, 2011]

[jboy]

Run 7 days at a time with the setting on, then 7 with it off.

Repeat until there is a clear pattern of errors.

that's what i'm going to do. in fact i'm going to make the amount of time two weeks because previously about a week went by without any 500 error.

thanks.

[jboy]

something I've noticed: all the 500 errors are from Internet Explorer. Here's a bunch of user agents which all had 500 errors from the server access log:

"Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; .NET4.0C; .NET4.0E)"
"Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; GTB6.6; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; eMusic DLM/4)"
"Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 6.0; WOW64; Trident/4.0; GTB6.6; SLCC1; .NET CLR 2.0.50727; Media Center PC 5.0; .NET CLR 3.5.30729; .NET CLR 3.0.30729; .NET4.0C)"
"Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; tco2; GTB6; .NET CLR 1.1.4322)"
"Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 6.1; WOW64; Trident/4.0; GTB6.6; SLCC2; .NET CLR 2.0.50727; .NET CLR 3.5.30729; .NET CLR 3.0.30729; Media Center PC 6.0; .NET4.0C; .NET4.0E)"
"Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 6.1; WOW64; Trident/4.0; GTB6.6; SLCC2; .NET CLR 2.0.50727; .NET CLR 3.5.30729; .NET CLR 3.0.30729; Media Center PC 6.0; .NET4.0C; .NET4.0E)"
"Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; GTB6.6; InfoPath.2)"
"Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; GTB6.6; InfoPath.2)"
"Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; GTB6.6; InfoPath.2)"
"Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; GTB6.6; InfoPath.2)"
"Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729)"
"Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 6.0; Win64; x64; Trident/4.0; .NET CLR 2.0.50727; SLCC1; .NET CLR 3.5.30729; .NET CLR 3.0.30729; .NET4.0C; .NET4.0E)"
"Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; GTB6.6; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; WinTSI 03.01.2010)"

No 500 error has occurred for any other type of browser. Any thoughts? I suppose it could be a coincidence but I think it's unlikely.

[jboy]

The PHP code which is called from within the two files which are giving errors calls get_browser(). The code does something different for MSIE 7 or less. But for MSIE 8 it behaves the same as all other browsers -- and there's been many 500 errors for MSIE 8.

[jboy]

Could multiple calls to get_browser be a cause? I now realise it's stupid to call it multiple times but that's what was happening. I'm going to leave it for now while I'm testing to see if it's the compression line in the .htaccess file or not. But after that test I will modify the code so it only calls get_browser once. But irrispective of how wasteful it is to call get_browser multiple times in one php script execution, could that be the source of 500 errors? (when I say multiple, I mean 18 to be precise)

[jboy]

In the headers of the files giving 500 status errors is a header like this:

Content-Location: file.css.php

even though the URL being accessed is

subdomain.domain.com/dir/file.css

-- there is an internal rewrite from file.css to file.css.php. Could this be a source of a 500 error? I doubt it but seems odd that that info is being made public.

[jdMorgan]

If these .css.php filepaths are being 'exposed' as URLs, that indicates that your redirect and rewrite directives are not in the correct order. All redirects must execute before any internal rewrites can execute.

If you are attempting to match real files named .css.php, then "\.css\.php$ would be the correct pattern for a FilesMatch directive.

However, if these are not physically-existing files, then FilesMatch can't be used at all, and you'll need to use a different method to enable or disable compression.

Jim

[jboy]

If these .css.php filepaths are being 'exposed' as URLs, that indicates that your redirect and rewrite directives are not in the correct order. All redirects must execute before any internal rewrites can execute.

I've found out what was going on there: it wasn't the order of rewrites, it was MultiViews getting in and doing its thing (whatever exactly its thing is) before the rewrite got a look in. Options -MultiViews sorts out the unwanted headers and gets it so the rewrite is responsible for the rewrite. So no unset needed. I've got to the root of that problem thankfully.

I suspect (*hope*) bloody MultiViews might be the culprit for my original 500 status errors, which sparked all this off in the first place.

I've left it with MultiViews off, and it's just a case of waiting to see if it fixes it. Hopefully it will. I've got a good feeling, I think it just might. I came across someone saying they were experiencing an intermittent 500 error caused by MultiViews... so fingers crossed.

About the compression bit and targetting subdomain.domain.com/css/file.css.php (and another similar file in the same directory), that is still a mystery...

If you are attempting to match real files named .css.php, then "\.css\.php$ would be the correct pattern for a FilesMatch directive.

Yup, the .css.php files are real files on the server,
subdomain.domain.com/css/file.css.php

<FileMatch "\.css\.php$">
SetOutputFilter DEFLATE
</FileMatch>

definitely doesn't work. This works, as in it gets subdomain.domain.com/css/file.css.php compressed, but I'm not sure if it's specific enough, that is it might get other things compressed which shouldn't be:

<FileMatch "php">
SetOutputFilter DEFLATE 
</FileMatch>

Adding anything else to that pattern fails to get the subdomain.domain.com/css/file.css.php compressed. So what on earth is going on there? Doesn't seem right at all.

However, if these are not physically-existing files, then FilesMatch can't be used at all, and you'll need to use a different method to enable or disable compression.

subdomain.domain.com/css/file.css.php
is a real file on the server.

Thanks.