%{REQUEST_FILENAME} confusion between different requests

Topics: User Forum
Jan 4, 2007 at 12:48 AM
I'm trying to rewrite URLs only when the requested file does not exist. I'm using 1.2.10 (http://cheeso.members.winisp.net/dl/IonicIsapiRewriter-1.2.10.zip), along with IIS 5.1 from XP Pro.

My config is as follows:
RewriteLog c:\inetpub\isapi\ionics\logs\iirfLog.out
RewriteLogLevel 100
MaxMatchCount 10
RewriteCond %{REQUEST_FILENAME} !-f
RewriteCond %{REQUEST_FILENAME} !-d
RewriteRule ^/(.*)/$ /index.php?url=/$1 L
RewriteCond %{REQUEST_FILENAME} !-f
RewriteCond %{REQUEST_FILENAME} !-d
RewriteRule ^/(.*)$ /index.php?url=/$1 L

A request for /pages/aboutus.html (which does not exist as a file) should be rewritten as a request for /index.php?url=/pages/aboutus.html and often it works, generating a log entry something like:
Thu Jan 04 11:49:42 2007 - HttpFilterProc SFNOTIFYURL_MAP
Thu Jan 04 11:49:42 2007 - HttpFilterProc SFNOTIFYURL_MAP
Thu Jan 04 11:49:42 2007 - HttpFilterProc SFNOTIFYURL_MAP
Thu Jan 04 11:49:43 2007 - HttpFilterProc SFNOTIFYURL_MAP
Thu Jan 04 11:49:43 2007 - OnUrlMap: storing physical path (C:\Inetpub\cake\app\webroot\pages\about_us.html), in ptr (0x00129798)
Thu Jan 04 11:49:43 2007 - HttpFilterProc SFNOTIFYAUTH_COMPLETE
Thu Jan 04 11:49:43 2007 - DoRewrites
Thu Jan 04 11:49:43 2007 - New Url: '/pages/about_us.html'
Thu Jan 04 11:49:43 2007 - ApplyRules (depth=0)
Thu Jan 04 11:49:43 2007 - Rule 1 : -1 (No match)
Thu Jan 04 11:49:43 2007 - Rule 2 : 2 matches
Thu Jan 04 11:49:43 2007 - GetServerVariable: getting 'REQUEST_FILENAME'
Thu Jan 04 11:49:43 2007 - GetServerVariable: special variable name
Thu Jan 04 11:49:43 2007 - GetServerVariable: xferred 47 bytes
Thu Jan 04 11:49:43 2007 - GetServerVariable: result 'C:\Inetpub\cake\app\webroot\pages\about_us.html'
Thu Jan 04 11:49:43 2007 - ReplaceServerVariables: VariableName='REQUESTFILENAME' Value='C:\Inetpub\cake\app\webroot\pages\aboutus.html'
Thu Jan 04 11:49:43 2007 - ReplaceServerVariables: TestString='%{REQUESTFILENAME}' out='C:\Inetpub\cake\app\webroot\pages\aboutus.html'
Thu Jan 04 11:49:43 2007 - GenerateReplacementString: src='/pages/aboutus.html','(null)' ReplacePattern='C:\Inetpub\cake\app\webroot\pages\aboutus.html' vec=[[ [ 0, 20, 1, 20] [] ] counts=2,0
Thu Jan 04 11:49:43 2007 - EvaluateCondition: checking 'C:\Inetpub\cake\app\webroot\pages\about_us.html' against pattern '!-f'
Thu Jan 04 11:49:43 2007 - EvaluateCondition: cond->SpecialConditionType= 'f'
Thu Jan 04 11:49:43 2007 - EvaluateCondition: Special: it is not a file; not a directory
Thu Jan 04 11:49:43 2007 - EvaluateCondition: Special, retVal= True
Thu Jan 04 11:49:43 2007 - Cond : Child is non NULL
Thu Jan 04 11:49:43 2007 - Cond : Current condition evaluates to TRUE
Thu Jan 04 11:49:43 2007 - Cond : Logical AND, ergo we evaluate the Child
Thu Jan 04 11:49:43 2007 - GetServerVariable: getting 'REQUEST_FILENAME'
Thu Jan 04 11:49:43 2007 - GetServerVariable: special variable name
Thu Jan 04 11:49:43 2007 - GetServerVariable: xferred 47 bytes
Thu Jan 04 11:49:43 2007 - GetServerVariable: result 'C:\Inetpub\cake\app\webroot\pages\about_us.html'
Thu Jan 04 11:49:43 2007 - ReplaceServerVariables: VariableName='REQUESTFILENAME' Value='C:\Inetpub\cake\app\webroot\pages\aboutus.html'
Thu Jan 04 11:49:43 2007 - ReplaceServerVariables: TestString='%{REQUESTFILENAME}' out='C:\Inetpub\cake\app\webroot\pages\aboutus.html'
Thu Jan 04 11:49:43 2007 - GenerateReplacementString: src='/pages/aboutus.html','(null)' ReplacePattern='C:\Inetpub\cake\app\webroot\pages\aboutus.html' vec=[[ [ 0, 20, 1, 20] [] ] counts=2,0
Thu Jan 04 11:49:43 2007 - EvaluateCondition: checking 'C:\Inetpub\cake\app\webroot\pages\about_us.html' against pattern '!-d'
Thu Jan 04 11:49:43 2007 - EvaluateCondition: cond->SpecialConditionType= 'd'
Thu Jan 04 11:49:43 2007 - EvaluateCondition: Special: it is not a file; not a directory
Thu Jan 04 11:49:43 2007 - EvaluateCondition: Special, retVal= True
Thu Jan 04 11:49:43 2007 - Cond : Child is NULL
Thu Jan 04 11:49:43 2007 - EvaluateConditionList: TRUE, Rule will apply
Thu Jan 04 11:49:43 2007 - GenerateReplacementString: src='/pages/about_us.html','(null)' ReplacePattern='/index.php?url=/$1' vec=[[ [ 0, 20, 1, 20] [] ] counts=2,0
Thu Jan 04 11:49:43 2007 - Result (length 35): /index.php?url=/pages/about_us.html
Thu Jan 04 11:49:43 2007 - Last if Match
Thu Jan 04 11:49:43 2007 - ApplyRules: returning 1
Thu Jan 04 11:49:43 2007 - Rewrite Url to: '/index.php?url=/pages/about_us.html'


Regularly, but intermittently (say 1 page hit out of 10 that should be rewritten), the RewriteCond doesn't behave as expected. I end up with something like the following in my log:
Thu Jan 04 12:11:45 2007 - HttpFilterProc SFNOTIFYLOG
Thu Jan 04 12:11:46 2007 - HttpFilterProc SFNOTIFYURL_MAP
Thu Jan 04 12:11:46 2007 - HttpFilterProc SFNOTIFYAUTH_COMPLETE
Thu Jan 04 12:11:46 2007 - DoRewrites
Thu Jan 04 12:11:46 2007 - New Url: '/pages/about_us.html'
Thu Jan 04 12:11:46 2007 - ApplyRules (depth=0)
Thu Jan 04 12:11:46 2007 - Rule 1 : -1 (No match)
Thu Jan 04 12:11:46 2007 - Rule 2 : 2 matches
Thu Jan 04 12:11:46 2007 - GetServerVariable: getting 'REQUEST_FILENAME'
Thu Jan 04 12:11:46 2007 - GetServerVariable: special variable name
Thu Jan 04 12:11:46 2007 - GetServerVariable: xferred 62 bytes
Thu Jan 04 12:11:46 2007 - GetServerVariable: result 'C:\Inetpub\cake\app\webroot\img\navigation\menucontacton.png'
Thu Jan 04 12:11:46 2007 - ReplaceServerVariables: VariableName='REQUESTFILENAME' Value='C:\Inetpub\cake\app\webroot\img\navigation\menucontact_on.png'
Thu Jan 04 12:11:46 2007 - ReplaceServerVariables: TestString='%{REQUESTFILENAME}' out='C:\Inetpub\cake\app\webroot\img\navigation\menucontact_on.png'
Thu Jan 04 12:11:46 2007 - GenerateReplacementString: src='/pages/aboutus.html','(null)' ReplacePattern='C:\Inetpub\cake\app\webroot\img\navigation\menucontact_on.png' vec=[[ [ 0, 20, 1, 20] [] ] counts=2,0
Thu Jan 04 12:11:46 2007 - EvaluateCondition: checking 'C:\Inetpub\cake\app\webroot\img\navigation\menucontacton.png' against pattern '!-f'
Thu Jan 04 12:11:46 2007 - EvaluateCondition: cond->SpecialConditionType= 'f'
Thu Jan 04 12:11:46 2007 - EvaluateCondition: Special: is it a file? (yes)
Thu Jan 04 12:11:46 2007 - EvaluateCondition: Special, retVal= false
Thu Jan 04 12:11:46 2007 - Cond : Child is non NULL
Thu Jan 04 12:11:46 2007 - Cond : Current condition evaluates to FALSE
Thu Jan 04 12:11:46 2007 - Cond : Logical AND, ergo no need to evaluate Child condition
Thu Jan 04 12:11:46 2007 - EvaluateConditionList: FALSE, Rule does not apply
Thu Jan 04 12:11:46 2007 - ApplyRules: returning 0
Thu Jan 04 12:11:46 2007 - No Rewrite
Thu Jan 04 12:11:46 2007 - HttpFilterProc SFNOTIFYLOG

"menucontacton.png" does exist, and seems to be carried over from a previous request (but not the request immediately prior).

Is this a known issue with what I'm trying to do? Are there any workarounds?
Jan 4, 2007 at 12:51 AM
Oops, no preview button, no edit button, and no idea how to escape code segments in this forum. :) I won't repost that mess, but hopefully it didn't end up too unreadable.
Aug 25, 2009 at 9:16 AM

I'm having the same issue with REQUEST_FILENAME. I'm running version 1.2.16 on Vista with IIS 7.0.

My ini file is as follows:

RewriteCond %{REQUEST_FILENAME} !-f
RewriteCond %{REQUEST_FILENAME} !-d
RewriteRule ^/(.+).html$ /index.php?page=$1 [L,QSA]

50% of the time it works and 50% of the time it fails.

When it fails, the log file shows that the request_filename result is not the original request "test.html" but the "index.php" file and hence the rewrite conditions fails. 

Tue Aug 25 17:00:22 -  5880 - GetServerVariable_AutoFree: getting 'url'
Tue Aug 25 17:00:22 -  5880 - GetServerVariable_AutoFree - no joy (GetLastError()=1413)
Tue Aug 25 17:00:22 -  5880 - GetServerVariable_AutoFree: 128 bytes
Tue Aug 25 17:00:22 -  5880 - GetServerVariable_AutoFree: result ''
Tue Aug 25 17:00:22 -  5880 - GetHeader_AutoFree: getting 'url'
Tue Aug 25 17:00:22 -  5880 - GetHeader_AutoFree: 11 bytes   ptr:0x01D40468
Tue Aug 25 17:00:22 -  5880 - GetHeader_AutoFree: 'url' = '/test.html'
Tue Aug 25 17:00:22 -  5880 - GetServerVariable_AutoFree: getting 'QUERY_STRING'
Tue Aug 25 17:00:22 -  5880 - GetServerVariable_AutoFree: 1 bytes
Tue Aug 25 17:00:22 -  5880 - GetServerVariable_AutoFree: result ''
Tue Aug 25 17:00:22 -  5880 - GetHeader_AutoFree: getting 'method'
Tue Aug 25 17:00:22 -  5880 - GetHeader_AutoFree: 4 bytes   ptr:0x01D40578
Tue Aug 25 17:00:22 -  5880 - GetHeader_AutoFree: 'method' = 'GET'
Tue Aug 25 17:00:22 -  5880 - DoRewrites: Url: '/test.html'
Tue Aug 25 17:00:22 -  5880 - EvaluateRules: depth=0
Tue Aug 25 17:00:22 -  5880 - EvaluateRules: Rule 1 : 2 matches
Tue Aug 25 17:00:22 -  5880 - GetServerVariable: getting 'REQUEST_FILENAME'
Tue Aug 25 17:00:22 -  5880 - GetServerVariable: special variable name
Tue Aug 25 17:00:22 -  5880 - GetServerVariable: 34 bytes
Tue Aug 25 17:00:22 -  5880 - GetServerVariable: result 'D:\wwwroot\iirf-testcase\index.php'
Tue Aug 25 17:00:22 -  5880 - ReplaceServerVariables: VariableName='REQUEST_FILENAME' Value='D:\wwwroot\iirf-testcase\index.php'
Tue Aug 25 17:00:22 -  5880 - ReplaceServerVariables: InputString='%{REQUEST_FILENAME}' out='D:\wwwroot\iirf-testcase\index.php'
Tue Aug 25 17:00:22 -  5880 - EvalCondition: ts1 'D:\wwwroot\iirf-testcase\index.php'

And when it works, the log shows:

Tue Aug 25 17:00:21 -  5880 - GetServerVariable_AutoFree: getting 'url'
Tue Aug 25 17:00:21 -  5880 - GetServerVariable_AutoFree - no joy (GetLastError()=1413)
Tue Aug 25 17:00:21 -  5880 - GetServerVariable_AutoFree: 128 bytes
Tue Aug 25 17:00:21 -  5880 - GetServerVariable_AutoFree: result ''
Tue Aug 25 17:00:21 -  5880 - GetHeader_AutoFree: getting 'url'
Tue Aug 25 17:00:21 -  5880 - GetHeader_AutoFree: 11 bytes   ptr:0x01D3FF18
Tue Aug 25 17:00:21 -  5880 - GetHeader_AutoFree: 'url' = '/test.html'
Tue Aug 25 17:00:21 -  5880 - GetServerVariable_AutoFree: getting 'QUERY_STRING'
Tue Aug 25 17:00:21 -  5880 - GetServerVariable_AutoFree: 1 bytes
Tue Aug 25 17:00:21 -  5880 - GetServerVariable_AutoFree: result ''
Tue Aug 25 17:00:21 -  5880 - GetHeader_AutoFree: getting 'method'
Tue Aug 25 17:00:21 -  5880 - GetHeader_AutoFree: 4 bytes   ptr:0x01D40248
Tue Aug 25 17:00:21 -  5880 - GetHeader_AutoFree: 'method' = 'GET'
Tue Aug 25 17:00:21 -  5880 - DoRewrites: Url: '/test.html'
Tue Aug 25 17:00:21 -  5880 - EvaluateRules: depth=0
Tue Aug 25 17:00:21 -  5880 - EvaluateRules: Rule 1 : 2 matches
Tue Aug 25 17:00:21 -  5880 - GetServerVariable: getting 'REQUEST_FILENAME'
Tue Aug 25 17:00:21 -  5880 - GetServerVariable: special variable name
Tue Aug 25 17:00:21 -  5880 - GetServerVariable: 34 bytes
Tue Aug 25 17:00:21 -  5880 - GetServerVariable: result 'D:\wwwroot\iirf-testcase\test.html'
Tue Aug 25 17:00:21 -  5880 - ReplaceServerVariables: VariableName='REQUEST_FILENAME' Value='D:\wwwroot\iirf-testcase\test.html'
Tue Aug 25 17:00:21 -  5880 - ReplaceServerVariables: InputString='%{REQUEST_FILENAME}' out='D:\wwwroot\iirf-testcase\test.html'
Tue Aug 25 17:00:21 -  5880 - EvalCondition: ts1 'D:\wwwroot\iirf-testcase\test.html'

It seems to alternate between working and failing. I couldn't see any errors in the rules in the ini file. Is this an issue with the latest release? Are they any workarounds?

 

Coordinator
Aug 25, 2009 at 6:19 PM
This discussion has been copied to a work item. Click here to go to the work item and continue the discussion.