cPanel error log shows "File does not exist" but it does, sort of

.htaccess issue?

[Patrick Taylor]

Looking at my error log in cPanel there is a list of errors. Typically:

[Fri Oct 17 12:45:59 2014] [error] [client 207.46.13.8] File does not exist: /home/etc/public_html/1308

The point is, the URL www.example.com/1308 does exist on my site and the page is served (receiving header: HTTP/1.1·200·OK). Other files listed in the error log are the same. The URLs work but give rise to entries in the error log. Of course there is no such file as /1308 but there is a URL /1308

I have looked this up and not found an answer except a suggestion it may be .htaccess-related.

I'm a bit stumped. My .htaccess file seems okay to me, so why are these "errors" being logged (as if there should be a file: 1308)?

The context: the page.php files are located in a folder /cms/ so they would be accessible with a URL such as:

www.example.com/cms/page.php

But my .htaccess file rewrites www.example.com/page to www.example.com/cms/page.php so that the URL is (eg) www.example.com/page

The .htaccess file is shown below.

# Block direct access to scripts, text files and images folder
RewriteCond %{REQUEST_URI} ^/cms/inc/menu\.php$ [OR]
RewriteCond %{REQUEST_URI} ^/cms/inc/inmenu\.txt$ [OR]
RewriteCond %{REQUEST_URI} ^/cms/siteadmin/list\.php$ [OR]
RewriteCond %{REQUEST_URI} ^/cms/([^/.]+)\.txt$ [OR]
RewriteCond %{REQUEST_URI} ^/cms/comments/([^/.]+)\.txt$ [OR]
RewriteCond %{REQUEST_URI} ^/img/$
RewriteRule .* - [F]
#
# (1) Intercept and redirect requests that are not for the '/admin/' pages
#
# EXTERNAL REDIRECT 1
# If '/cms/' is at the END of the requested path, redirect to '/'
RewriteCond %{REQUEST_URI} ^/cms/$
RewriteRule ^cms/$ http://example.com/ [R=301,L]
#
# EXTERNAL REDIRECT 2
# If request is 'GET /cms/page.php HTTP/1.1' redirect to '/page'
RewriteCond %{THE_REQUEST} ^[A-Z]{3,9}\ /cms/([^/.]+)\.php\ HTTP/
RewriteRule ^cms/([^/.]+)\.php$ http://example.com/$1 [R=301,L]
#
# EXTERNAL REDIRECT 3 (ONLY FOR WEB ROOT)
# For websites beginning with www
# If request does not include www, redirect to URLs with www
# (reversible for non-www websites: redirect from with-www to without)
RewriteCond %{REQUEST_URI} !^/cms/admin/
RewriteCond %{HTTP_HOST} ^example\.com$ [NC]
RewriteRule ^(.*)$ http://www.example.com/$1 [R=301,L]
#
# (2) Internal rewrites
#
# INTERNAL REWRITE 1 (home page)
# If request is '/' internal rewrite to '/cms/index.php'
RewriteCond %{REQUEST_URI} ^/$
RewriteRule ^$ /cms/index.php [L]
#
# INTERNAL REWRITE 2 (search page)
# If request is 'search?terms=anything' internal rewrite...
# to '/cms/search.php?terms=anything'
RewriteCond %{REQUEST_URI} ^/search$
RewriteCond %{QUERY_STRING} ^terms=(.*)$
RewriteRule ^search(.*)$ /cms/search.php?%1 [L]
#
# INTERNAL REWRITE 3 (other pages)
# If the request is 'GET /page HTTP/1.1' internal rewrite to '/cms/page.php'
RewriteCond %{REQUEST_URI} !^/index$
RewriteCond %{THE_REQUEST} ^[A-Z]{3,9}\ /([^/.]+)\ HTTP/
RewriteRule ^([^/.]+)$ /cms/$1.php [L]

[penders]

I can't see anything obvious in your .htaccess file that would cause. Is this your entire .htaccess file?

I would also check your access log for the same time period. There should be a 404 for the same request. Is it a standard GET request? Are there other 200 OK responses in the same time period?

I wonder if there was something strange with the HTTP request headers that resulted in your last Rewrite block to fail? Your access log should clarify this.

Are there a range of different IP addresses listed that cause this? Or all from a particular source?

The IP address listed above (207.46.13.8) verifies as the msnbot. Was the msnbot perhaps hammering your site with too many requests, or your site/server having a slow down?!

Are you aware of any interruptions to your server? Was it rebooted?!

Is this an isolated incident, or has the same thing occurred on several different occasions?

[phranque]

perhaps the CMS script is checking for filename existence prior to generating the content.

[lucy24]

The IP address listed above (207.46.13.8) verifies as the msnbot.

Oh, ###. The bingbot has a rare and special talent for learning the "real" URL of files it isn't even supposed to know about. For the past year and a half it's been religiously asking for one custom 410 page and I've never for the life of me figured out how they learned its name. And the bingbot, even more than the googlebot, never forgets a name.

perhaps the CMS script is checking for filename existence prior to generating the content.

All together now: D'oh! You've nailed it, phranque, because that's exactly what a CMS does. Every occurrence of

!-f

in the built-in htaccess means a preceding server call to verify that the file does not exist. And, like all good error logs, it will list the non-existence as an "error" even if the file wasn't supposed to exist.

Now, whether that

!-f

test is really the optimal way of doing things is a whole nother matter ;)

[Patrick Taylor]

The entire .htaccess file is shown.

The access log appears to show Http Code: 404 only for requests where the resource doesn't exist. The cPanel error log shows "[error] [client xx.xx.xx.xx] File does not exist: etc" for resources that DO exist (plus the ones that don't). There is no real pattern there, and they are GET requests. No particular IPs nor, as far as I know, any server issues, and this has been going on since I noticed it a week or so ago.

This issue arises on all websites where my CMS is installed (all on the same server). But on this same server I also have a WordPress install and that shows nothing in the error log. That's why I suspect my CMS's .htaccess file.

At one point the last block of the file included:

RewriteCond %{REQUEST_FILENAME} !-f
RewriteCond %{REQUEST_FILENAME} !-d

but I removed it to see what would happen, but it made no difference. Still getting the errors.

@phranque and lucy24... does that mean there is no problem with the .htaccess file, or the logged errors can't be fixed? (it's annoying if nothing else)

BTW it doesn't happen for every page view request, just some. A couple of hours can go by with no additions to the error log but normal regular visits are occurring during that time - then the errors resume. In other words sometimes it happens, other times it doesn't.

[penders]

perhaps the CMS script is checking for filename existence prior to generating the content.

Well, in PHP, simply checking the existence of a file (file_exists(), is_file(), etc.) won't trigger an error condition. If, however, you request that non-existent file and suppress any error condition (with the @ operator - bad practise) then maybe that could make it's way to the error log?

And, like all good error logs, it [!-f] will list the non-existence as an "error"...

What?! That would be insane! Is this something that is server configurable perhaps? Most sites (not just CMSs) use these type of mod_rewrite file checks and I have never come across a server that logs these as errors. (Although it doesn't appear the OP is doing this particular check anyway.)

[lucy24]

Is this something that is server configurable perhaps?

It must be, although I was being satirical. I can only say that in my MAMP installation, any check for a nonexistent file (for example "is such-and-such cookie present?") will show up in error logs. That is: it doesn't throw an error in script execution, but it's definitely there in logs.

If you're on shared hosting, you can't change your error logging level, as this is set in the config file. So the default may be set a little higher (that is, more detailed) than what you'd set in your own server. Definitely not to "Debug" though ;)

On my configuration (vanilla shared hosting on one of the major hosts), internal requests leading to a 40x don't show up in access logs, but they do in error logs.

:: detour to MAMP directory for comparison purposes ::

Yeah, just a steady stream of "undefined index" (it's a parameter that may or may not be present, depending on which page called the function). No genuine errors except when I'm testing stuff. White Screen Of Death, that kind of thing

[Patrick Taylor]

I've now tested the scripts on a different server and looked at the cPanel error_log and there are no errors listed except when I request a resource I know does not exist (404). So perhaps my normal server (these are shared) has a higher error reporting setting than the 'different' one.

So I have to assume something in my scripts - or the .htaccess file - is causing those "File does not exist" errors, which are reported on one server but not on the other. I doubt if any files are missing so it can't be that.