IirfProxy_GenProxyRequestHeadersString throws an exception for pages that use authentication

Topics: Developer Forum, Project Management Forum, User Forum
Apr 29, 2011 at 8:20 PM

Hello,

 

   I've setup IIRF on my Win2k3 server and it's running as a reverse proxy for my apache server. However, we just added a logon form to the default page on the apache server. Whenever users try to login, IIRF throws an exception and dies. I downloaded the source code and tracked the problem to Proxy.c , on the method IirfProxy_GenProxyRequestHeadersString. I'm not a c++ programmer, but it seems the call rh=rh->Next on line 422 is blowing up. I tried fixing it by changing the line to: if(rh=>Next != NULL) rh=rh->Next.  I compiled it, and sure enough this did stop IIRF from blowing up, but now, I just get an access denied message back:

HTTP Error 401.3 - Unauthorized: Access is denied due to an ACL set on the requested resource.
Internet Information Services (IIS)

 

At this point, I'm out of ideas. Any help would be appreciated. I've included my ini and the log file below.


IIRI.ini file

-------------------------------------------------------------------------

# IIRF.ini

RewriteLog c:\inetpub\iirfLogs\iirf

RewriteLogLevel 4

IterationLimit 10

MaxMatchCount 10

RewriteEngine ON

StatusInquiry ON
 

RewriteRule  /eurl\.axd/ - [L]

RewriteCond %{HTTP_HOST}   ^aperio.TESTCOMPANY.com$  [I]

#RewriteRule ^/(.*)$        http://sip-dsr/$1      [QSA,P]

ProxyPass ^/(.*)$          http://sip-dsr/$1

ProxyPassReverse   /       http://sip-dsr/
 

-----------------------------------------------------------------------------------
 
 
 

IIRF Log file

-----------------------------------------------

Fri Apr 29 15:14:41 -  3928 - IsIniChainUpdated: C:\Inetpub\wwwroot\Iirf.ini NO

Fri Apr 29 15:14:41 -  3928 - IsIniChainUpdated: return FALSE

Fri Apr 29 15:14:41 -  3928 - IsIniChainUpdated: return FALSE

Fri Apr 29 15:14:41 -  3928 - GetVdirConfig: Obtain  vdir '/LM/W3SVC/265094861/Root' (era=2) (rc=1) (Expired=0) (ptr=0x0131CB60)...

Fri Apr 29 15:14:41 -  3928 - HttpFilterProc: SF_NOTIFY_URL_MAP

Fri Apr 29 15:14:41 -  3928 - HttpFilterProc: cfg= 0x0131CB60

Fri Apr 29 15:14:41 -  3928 - IsIniChainUpdated: C:\Inetpub\wwwroot\Iirf.ini NO

Fri Apr 29 15:14:41 -  3928 - IsIniChainUpdated: return FALSE

Fri Apr 29 15:14:41 -  3928 - IsIniChainUpdated: return FALSE

Fri Apr 29 15:14:41 -  3928 - GetVdirConfig: Obtain  vdir '/LM/W3SVC/265094861/Root' (era=2) (rc=2) (Expired=0) (ptr=0x0131CB60)...

Fri Apr 29 15:14:41 -  3928 - HttpFilterProc: SF_NOTIFY_URL_MAP

Fri Apr 29 15:14:41 -  3928 - HttpFilterProc: cfg= 0x0131CB60

Fri Apr 29 15:14:41 -  3928 - HttpFilterProc: SF_NOTIFY_AUTH_COMPLETE

Fri Apr 29 15:14:41 -  3928 - DoRewrites

Fri Apr 29 15:14:41 -  3928 - GetHeader_AutoFree: getting 'url'

Fri Apr 29 15:14:41 -  3928 - GetHeader_AutoFree: 18 bytes   ptr:0x00102F38

Fri Apr 29 15:14:41 -  3928 - GetHeader_AutoFree: 'url' = '/authenticate.php'

Fri Apr 29 15:14:41 -  3928 - GetServerVariable_AutoFree: getting 'QUERY_STRING'

Fri Apr 29 15:14:41 -  3928 - GetServerVariable_AutoFree: 1 bytes

Fri Apr 29 15:14:41 -  3928 - GetServerVariable_AutoFree: result ''

Fri Apr 29 15:14:41 -  3928 - GetHeader_AutoFree: getting 'method'

Fri Apr 29 15:14:41 -  3928 - GetHeader_AutoFree: 5 bytes   ptr:0x000F8A00

Fri Apr 29 15:14:41 -  3928 - GetHeader_AutoFree: 'method' = 'POST'

Fri Apr 29 15:14:41 -  3928 - DoRewrites: New Url, before decoding: '/authenticate.php'

Fri Apr 29 15:14:41 -  3928 - DoRewrites: Url (decoded): '/authenticate.php'

Fri Apr 29 15:14:41 -  3928 - EvaluateRules: depth=0

Fri Apr 29 15:14:41 -  3928 - GetServerVariable: getting 'SCRIPT_NAME'

Fri Apr 29 15:14:41 -  3928 - GetServerVariable: 18 bytes

Fri Apr 29 15:14:41 -  3928 - GetServerVariable: result '/authenticate.php'

Fri Apr 29 15:14:41 -  3928 - EvaluateRules: no RewriteBase

Fri Apr 29 15:14:41 -  3928 - EvaluateRules: Rule 1: pattern: /eurl\.axd/  subject: /authenticate.php

Fri Apr 29 15:14:41 -  3928 - EvaluateRules: Rule 1: -1 (No match)

Fri Apr 29 15:14:41 -  3928 - EvaluateRules: Rule 2: pattern: ^/(.*)$  subject: /authenticate.php

Fri Apr 29 15:14:41 -  3928 - EvaluateRules: Rule 2: 2 matches

Fri Apr 29 15:14:41 -  3928 - EvaluateRules: Rule 2: evaluating condition

Fri Apr 29 15:14:41 -  3928 - EvalCondition: cond 0x0131BD40

Fri Apr 29 15:14:41 -  3928 - GetServerVariable: getting 'HTTP_HOST'

Fri Apr 29 15:14:41 -  3928 - GetServerVariable: 22 bytes

Fri Apr 29 15:14:41 -  3928 - GetServerVariable: result 'aperio.TESTCOMPANY.com'

Fri Apr 29 15:14:41 -  3928 - ReplaceServerVariables: alloc 22 bytes

Fri Apr 29 15:14:41 -  3928 - GetServerVariable: getting 'HTTP_HOST'

Fri Apr 29 15:14:41 -  3928 - GetServerVariable: 22 bytes

Fri Apr 29 15:14:41 -  3928 - GetServerVariable: result 'aperio.TESTCOMPANY.com'

Fri Apr 29 15:14:41 -  3928 - ReplaceServerVariables: vName(HTTP_HOST) value(aperio.TESTCOMPANY.com)

Fri Apr 29 15:14:41 -  3928 - ReplaceServerVariables: in='%{HTTP_HOST}' out='aperio.TESTCOMPANY.com'

Fri Apr 29 15:14:41 -  3928 - EvalCondition: ts1 'aperio.TESTCOMPANY.com'

Fri Apr 29 15:14:41 -  3928 - GenerateReplacementString: src='/authenticate.php','(null)' replacePattern='aperio.TESTCOMPANY.com' vec=[[  0, 17, 1, 17] [] ] counts=2,0

Fri Apr 29 15:14:41 -  3928 - GenerateReplacementString: alloc 23 bytes

Fri Apr 29 15:14:41 -  3928 - ApplyCaseConversion: before 'aperio.TESTCOMPANY.com'

Fri Apr 29 15:14:41 -  3928 - ApplyCaseConversion: after  'aperio.TESTCOMPANY.com'

Fri Apr 29 15:14:41 -  3928 - ApplyUrlEncoding: in 'aperio.TESTCOMPANY.com'

Fri Apr 29 15:14:41 -  3928 - ApplyUrlEncoding: out 'aperio.TESTCOMPANY.com'

Fri Apr 29 15:14:41 -  3928 - GenerateReplacementString: result 'aperio.TESTCOMPANY.com'

Fri Apr 29 15:14:41 -  3928 - EvalCondition: t(aperio.TESTCOMPANY.com) op(~) p(^aperio.TESTCOMPANY.com$)

Fri Apr 29 15:14:41 -  3928 - EvalCondition: match result: 1 (match)

Fri Apr 29 15:14:41 -  3928 - EvalCondition: Cond t(%{HTTP_HOST}) op(~) p(^aperio.TESTCOMPANY.com$) => TRUE

Fri Apr 29 15:14:41 -  3928 - EvalCondition: Child is NULL

Fri Apr 29 15:14:41 -  3928 - EvalConditionList: rule 2, TRUE, Rule will apply

Fri Apr 29 15:14:41 -  3928 - ReplaceServerVariables: alloc 18 bytes

Fri Apr 29 15:14:41 -  3928 - ReplaceServerVariables: in='http://sip-dsr/$1' out='http://sip-dsr/$1'

Fri Apr 29 15:14:41 -  3928 - GenerateReplacementString: src='/authenticate.php','aperio.TESTCOMPANY.com' replacePattern='http://sip-dsr/$1' vec=[[  0, 17, 1, 17] [  0, 21] ] counts=2,1

Fri Apr 29 15:14:41 -  3928 - GenerateReplacementString: alloc 33 bytes

Fri Apr 29 15:14:41 -  3928 - GenerateReplacementString: replacing ($1) with 'authenticate.php'

Fri Apr 29 15:14:41 -  3928 - ApplyCaseConversion: before 'http://sip-dsr/authenticate.php'

Fri Apr 29 15:14:41 -  3928 - ApplyCaseConversion: after  'http://sip-dsr/authenticate.php'

Fri Apr 29 15:14:41 -  3928 - ApplyUrlEncoding: in 'http://sip-dsr/authenticate.php'

Fri Apr 29 15:14:41 -  3928 - ApplyUrlEncoding: out 'http://sip-dsr/authenticate.php'

Fri Apr 29 15:14:41 -  3928 - GenerateReplacementString: result 'http://sip-dsr/authenticate.php'

Fri Apr 29 15:14:41 -  3928 - EvaluateRules: Result (length 31): http://sip-dsr/authenticate.php

Fri Apr 29 15:14:41 -  3928 - EvaluateRules: returning 999

Fri Apr 29 15:14:41 -  3928 - DoRewrites: Proxy to: 'http://sip-dsr/authenticate.php'

Fri Apr 29 15:14:41 -  3928 - GetServerVariable_AutoFree: getting 'ALL_RAW'

Fri Apr 29 15:14:41 -  3928 - GetServerVariable_AutoFree: 522 bytes

Fri Apr 29 15:14:41 -  3928 - GetServerVariable_AutoFree: result 'Connection: keep-alive Keep-Alive: 115 Content-Length: 78 Content-Type: application/x-www-form-urlencoded Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8 Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7 Accept-Encoding: gzip, deflate Accept-Language: en-us,en;q=0.5 Cookie: isCookie=NHT6R; PHPSESSID=71b63883b6a909b905a760d0ea3351fa Host: aperio.TESTCOMPANY.com Referer: http://aperio.TESTCOMPANY.com/ User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:2.0.1) Gecko/20100101 Firefox/4.0.1 '

Fri Apr 29 15:14:41 -  3928 - GetServerVariable_AutoFree: getting 'REQUEST_METHOD'

Fri Apr 29 15:14:41 -  3928 - GetServerVariable_AutoFree: 5 bytes

Fri Apr 29 15:14:41 -  3928 - GetServerVariable_AutoFree: result 'POST'

Fri Apr 29 15:14:41 -  3928 - IirfProxy_TryRelayEmptyBodyRequest: http://sip-dsr/authenticate.php

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: Connection: keep-alive Keep-Alive: 115 Content-Length: 78 Content-Type: application/x-www-form-urlencoded Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8 Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7 Accept-Encoding: gzip, deflate Accept-Language: en-us,en;q=0.5 Cookie: isCookie=NHT6R; PHPSESSID=71b63883b6a909b905a760d0ea3351fa Host: aperio.TESTCOMPANY.com Referer: http://aperio.TESTCOMPANY.com/ User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:2.0.1) Gecko/20100101 Firefox/4.0.1 Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: hdr Connection: keep-alive

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: hdr Keep-Alive: 115

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: hdr Content-Length: 78

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: hdr Content-Type: application/x-www-form-urlencoded

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: hdr Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: hdr Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: hdr Accept-Encoding: gzip, deflate

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: hdr Accept-Language: en-us,en;q=0.5

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: hdr Cookie: isCookie=NHT6R; PHPSESSID=71b63883b6a909b905a760d0ea3351fa

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: hdr Host: aperio.TESTCOMPANY.com

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: hdr Referer: http://aperio.TESTCOMPANY.com/

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: hdr User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:2.0.1) Gecko/20100101 Firefox/4.0.1

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: found 12 headers

Fri Apr 29 15:14:41 -  3928 - DoRewrites: internal rewrite to: '/proxy.iirf?path=/LM/W3SVC/265094861/Root&url=http://sip-dsr/authenticate.php'

Fri Apr 29 15:14:41 -  3928 - HttpFilterProc: SF_NOTIFY_AUTH_COMPLETE

Fri Apr 29 15:14:41 -  3928 - DoRewrites

Fri Apr 29 15:14:41 -  3928 - GetHeader_AutoFree: getting 'url'

Fri Apr 29 15:14:41 -  3928 - GetHeader_AutoFree: 78 bytes   ptr:0x000FEF40

Fri Apr 29 15:14:41 -  3928 - GetHeader_AutoFree: 'url' = '/proxy.iirf?path=/LM/W3SVC/265094861/Root&url=http://sip-dsr/authenticate.php'

Fri Apr 29 15:14:41 -  3928 - GetServerVariable_AutoFree: getting 'QUERY_STRING'

Fri Apr 29 15:14:41 -  3928 - GetServerVariable_AutoFree: 66 bytes

Fri Apr 29 15:14:41 -  3928 - GetServerVariable_AutoFree: result 'path=/LM/W3SVC/265094861/Root&url=http://sip-dsr/authenticate.php'

Fri Apr 29 15:14:41 -  3928 - GetHeader_AutoFree: getting 'method'

Fri Apr 29 15:14:41 -  3928 - GetHeader_AutoFree: 5 bytes   ptr:0x00101AF0

Fri Apr 29 15:14:41 -  3928 - GetHeader_AutoFree: 'method' = 'POST'

Fri Apr 29 15:14:41 -  3928 - DoRewrites: New Url, before decoding: '/proxy.iirf?path=/LM/W3SVC/265094861/Root&url=http://sip-dsr/authenticate.php'

Fri Apr 29 15:14:41 -  3928 - DoRewrites: Url (decoded): '/proxy.iirf?path=/LM/W3SVC/265094861/Root&url=http://sip-dsr/authenticate.php'

Fri Apr 29 15:14:41 -  3928 - EvaluateRules: depth=0

Fri Apr 29 15:14:41 -  3928 - GetServerVariable: getting 'SCRIPT_NAME'

Fri Apr 29 15:14:41 -  3928 - GetServerVariable: 18 bytes

Fri Apr 29 15:14:41 -  3928 - GetServerVariable: result '/authenticate.php'

Fri Apr 29 15:14:41 -  3928 - EvaluateRules: no RewriteBase

Fri Apr 29 15:14:41 -  3928 - EvaluateRules: Rule 1: pattern: /eurl\.axd/  subject: /proxy.iirf?path=/LM/W3SVC/265094861/Root&url=http://sip-dsr/authenticate.php

Fri Apr 29 15:14:41 -  3928 - EvaluateRules: Rule 1: -1 (No match)

Fri Apr 29 15:14:41 -  3928 - EvaluateRules: Rule 2: pattern: ^/(.*)$  subject: /proxy.iirf?path=/LM/W3SVC/265094861/Root&url=http://sip-dsr/authenticate.php

Fri Apr 29 15:14:41 -  3928 - EvaluateRules: Rule 2: 2 matches

Fri Apr 29 15:14:41 -  3928 - EvaluateRules: Rule 2: evaluating condition

Fri Apr 29 15:14:41 -  3928 - EvalCondition: cond 0x0131BD40

Fri Apr 29 15:14:41 -  3928 - GetServerVariable: getting 'HTTP_HOST'

Fri Apr 29 15:14:41 -  3928 - GetServerVariable: 22 bytes

Fri Apr 29 15:14:41 -  3928 - GetServerVariable: result 'aperio.TESTCOMPANY.com'

Fri Apr 29 15:14:41 -  3928 - ReplaceServerVariables: alloc 22 bytes

Fri Apr 29 15:14:41 -  3928 - GetServerVariable: getting 'HTTP_HOST'

Fri Apr 29 15:14:41 -  3928 - GetServerVariable: 22 bytes

Fri Apr 29 15:14:41 -  3928 - GetServerVariable: result 'aperio.TESTCOMPANY.com'

Fri Apr 29 15:14:41 -  3928 - ReplaceServerVariables: vName(HTTP_HOST) value(aperio.TESTCOMPANY.com)

Fri Apr 29 15:14:41 -  3928 - ReplaceServerVariables: in='%{HTTP_HOST}' out='aperio.TESTCOMPANY.com'

Fri Apr 29 15:14:41 -  3928 - EvalCondition: ts1 'aperio.TESTCOMPANY.com'

Fri Apr 29 15:14:41 -  3928 - GenerateReplacementString: src='/proxy.iirf?path=/LM/W3SVC/265094861/Root&url=http://sip-dsr/authenticate.php','(null)' replacePattern='aperio.TESTCOMPANY.com' vec=[[  0, 77, 1, 77] [] ] counts=2,0

Fri Apr 29 15:14:41 -  3928 - GenerateReplacementString: alloc 23 bytes

Fri Apr 29 15:14:41 -  3928 - ApplyCaseConversion: before 'aperio.TESTCOMPANY.com'

Fri Apr 29 15:14:41 -  3928 - ApplyCaseConversion: after  'aperio.TESTCOMPANY.com'

Fri Apr 29 15:14:41 -  3928 - ApplyUrlEncoding: in 'aperio.TESTCOMPANY.com'

Fri Apr 29 15:14:41 -  3928 - ApplyUrlEncoding: out 'aperio.TESTCOMPANY.com'

Fri Apr 29 15:14:41 -  3928 - GenerateReplacementString: result 'aperio.TESTCOMPANY.com'

Fri Apr 29 15:14:41 -  3928 - EvalCondition: t(aperio.TESTCOMPANY.com) op(~) p(^aperio.TESTCOMPANY.com$)

Fri Apr 29 15:14:41 -  3928 - EvalCondition: match result: 1 (match)

Fri Apr 29 15:14:41 -  3928 - EvalCondition: Cond t(%{HTTP_HOST}) op(~) p(^aperio.TESTCOMPANY.com$) => TRUE

Fri Apr 29 15:14:41 -  3928 - EvalCondition: Child is NULL

Fri Apr 29 15:14:41 -  3928 - EvalConditionList: rule 2, TRUE, Rule will apply

Fri Apr 29 15:14:41 -  3928 - ReplaceServerVariables: alloc 18 bytes

Fri Apr 29 15:14:41 -  3928 - ReplaceServerVariables: in='http://sip-dsr/$1' out='http://sip-dsr/$1'

Fri Apr 29 15:14:41 -  3928 - GenerateReplacementString: src='/proxy.iirf?path=/LM/W3SVC/265094861/Root&url=http://sip-dsr/authenticate.php','aperio.TESTCOMPANY.com' replacePattern='http://sip-dsr/$1' vec=[[  0, 77, 1, 77] [  0, 21] ] counts=2,1

Fri Apr 29 15:14:41 -  3928 - GenerateReplacementString: alloc 93 bytes

Fri Apr 29 15:14:41 -  3928 - GenerateReplacementString: replacing ($1) with 'proxy.iirf?path=/LM/W3SVC/265094861/Root&url=http://sip-dsr/authenticate.php'

Fri Apr 29 15:14:41 -  3928 - ApplyCaseConversion: before 'http://sip-dsr/proxy.iirf?path=/LM/W3SVC/265094861/Root&url=http://sip-dsr/authenticate.php'

Fri Apr 29 15:14:41 -  3928 - ApplyCaseConversion: after  'http://sip-dsr/proxy.iirf?path=/LM/W3SVC/265094861/Root&url=http://sip-dsr/authenticate.php'

Fri Apr 29 15:14:41 -  3928 - ApplyUrlEncoding: in 'http://sip-dsr/proxy.iirf?path=/LM/W3SVC/265094861/Root&url=http://sip-dsr/authenticate.php'

Fri Apr 29 15:14:41 -  3928 - ApplyUrlEncoding: out 'http://sip-dsr/proxy.iirf?path=/LM/W3SVC/265094861/Root&url=http://sip-dsr/authenticate.php'

Fri Apr 29 15:14:41 -  3928 - GenerateReplacementString: result 'http://sip-dsr/proxy.iirf?path=/LM/W3SVC/265094861/Root&url=http://sip-dsr/authenticate.php'

Fri Apr 29 15:14:41 -  3928 - EvaluateRules: Result (length 91): http://sip-dsr/proxy.iirf?path=/LM/W3SVC/265094861/Root&url=http://sip-dsr/authenticate.php

Fri Apr 29 15:14:41 -  3928 - EvaluateRules: returning 999

Fri Apr 29 15:14:41 -  3928 - DoRewrites: Proxy to: 'http://sip-dsr/proxy.iirf?path=/LM/W3SVC/265094861/Root&url=http://sip-dsr/authenticate.php'

Fri Apr 29 15:14:41 -  3928 - GetServerVariable_AutoFree: getting 'ALL_RAW'

Fri Apr 29 15:14:41 -  3928 - GetServerVariable_AutoFree: 522 bytes

Fri Apr 29 15:14:41 -  3928 - GetServerVariable_AutoFree: result 'Connection: keep-alive Keep-Alive: 115 Content-Length: 78 Content-Type: application/x-www-form-urlencoded Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8 Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7 Accept-Encoding: gzip, deflate Accept-Language: en-us,en;q=0.5 Cookie: isCookie=NHT6R; PHPSESSID=71b63883b6a909b905a760d0ea3351fa Host: aperio.TESTCOMPANY.com Referer: http://aperio.TESTCOMPANY.com/ User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:2.0.1) Gecko/20100101 Firefox/4.0.1 '

Fri Apr 29 15:14:41 -  3928 - GetServerVariable_AutoFree: getting 'REQUEST_METHOD'

Fri Apr 29 15:14:41 -  3928 - GetServerVariable_AutoFree: 5 bytes

Fri Apr 29 15:14:41 -  3928 - GetServerVariable_AutoFree: result 'POST'

Fri Apr 29 15:14:41 -  3928 - IirfProxy_TryRelayEmptyBodyRequest: http://sip-dsr/proxy.iirf?path=/LM/W3SVC/265094861/Root&url=http://sip-dsr/authenticate.php

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: Connection: keep-alive Keep-Alive: 115 Content-Length: 78 Content-Type: application/x-www-form-urlencoded Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8 Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7 Accept-Encoding: gzip, deflate Accept-Language: en-us,en;q=0.5 Cookie: isCookie=NHT6R; PHPSESSID=71b63883b6a909b905a760d0ea3351fa Host: aperio.TESTCOMPANY.com Referer: http://aperio.TESTCOMPANY.com/ User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:2.0.1) Gecko/20100101 Firefox/4.0.1 Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: hdr Connection: keep-alive

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: hdr Keep-Alive: 115

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: hdr Content-Length: 78

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: hdr Content-Type: application/x-www-form-urlencoded

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: hdr Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: hdr Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: hdr Accept-Encoding: gzip, deflate

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: hdr Accept-Language: en-us,en;q=0.5

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: hdr Cookie: isCookie=NHT6R; PHPSESSID=71b63883b6a909b905a760d0ea3351fa

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: hdr Host: aperio.TESTCOMPANY.com

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: hdr Referer: http://aperio.TESTCOMPANY.com/

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: hdr User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:2.0.1) Gecko/20100101 Firefox/4.0.1

Fri Apr 29 15:14:41 -  3928 - ParseAllRaw: found 12 headers

Fri Apr 29 15:14:41 -  3928 - DoRewrites: internal rewrite to: '/proxy.iirf?path=/LM/W3SVC/265094861/Root&url=http://sip-dsr/proxy.iirf?path=/LM/W3SVC/265094861/Root&url=http://sip-dsr/authenticate.php'

Fri Apr 29 15:14:41 -  3928 - HttpFilterProc: SF_NOTIFY_URL_MAP

Fri Apr 29 15:14:41 -  3928 - HttpFilterProc: cfg= 0x0131CB60

Fri Apr 29 15:14:41 -  3928 - HttpFilterProc: SF_NOTIFY_URL_MAP

Fri Apr 29 15:14:41 -  3928 - HttpFilterProc: cfg= 0x0131CB60

Fri Apr 29 15:14:41 -  3928 - HttpFilterProc: SF_NOTIFY_URL_MAP

Fri Apr 29 15:14:41 -  3928 - HttpFilterProc: cfg= 0x0131CB60

Fri Apr 29 15:14:41 -  3928 - HttpFilterProc: SF_NOTIFY_URL_MAP

Fri Apr 29 15:14:41 -  3928 - HttpFilterProc: cfg= 0x0131CB60

Fri Apr 29 15:14:41 -  3928 - HttpFilterProc: SF_NOTIFY_LOG

Fri Apr 29 15:14:41 -  3928 - ReleaseOrExpireVdirConfig: vdir '/LM/W3SVC/265094861/Root' (era=2) (rc=3) (Expired=0) (ptr=0x0131CB60)...

Fri Apr 29 15:14:41 -  3928 - HttpFilterProc: SF_NOTIFY_LOG

Fri Apr 29 15:14:41 -  3928 - ReleaseOrExpireVdirConfig: vdir '/LM/W3SVC/265094861/Root' (era=2) (rc=2) (Expired=0) (ptr=0x0131CB60)...

May 1, 2011 at 3:09 PM

Okay,

   after a little work, I was able to fix this problem. First of, I rolled back the c++ changes I made and instead I aoplied the changes as described in http://iirf.codeplex.com/workitem/30604  . Doing that brought me to the point where anytime I had to do an HTTP POST, I would get a response from the target server saying : http://targethost/proxy.iirf was not found. This was confusing to me as I did not understand why the proxypass was actually passing a huge string with proxy.iirf in it. Using Wireshark on the target server, I could see that the http post was infact the entire path of the internal representation of he POST concatenated twice. So, what that means is, IIRF internally represents my proxy post as: (you can find this in the log file I initailly attached)

DoRewrites: internal rewrite to: '/proxy.iirf?path=/LM/W3SVC/265094861/Root&url=http://sip-dsr/authenticate.php'

 

Now, if that was the end of it, the ISAPI Extension would have processed the line correctly and send out an HTTP POST to http://sip-dsr/authenticate. Unfortunately, for some strange reason, the ISAPI filter passes that line through a second round of rewrites and it ends up producing: (again, you can find this in the log)

 

DoRewrites: internal rewrite to: '/proxy.iirf?path=/LM/W3SVC/265094861/Root&url=http://sip-dsr/proxy.iirf?path=/LM/W3SVC/265094861/Root&url=http://sip-dsr/authenticate.php'

Notice the repeat of the proxy.iifr in the line. This was what was being sent out and causing the problem. Now I thought that maybe because I had the Iifri.ini setting of IterationLimit set to 10, that maybe it kept rereading the line and rewriting the URL, so I switched it to 1, but the same problem persisted. After staring at the log file little more, I could simply shortcircuit the second rewrite if I simply add the rule:

RewriteRule ^/proxy.iirf - [L] 

This stops any further processing of the initially generated proxy string. Once I did that, I was able to successfully authenticate via HTTP POST.

 

Hope this long winded explination was helpful. If Anyone can shed some light on why the second round of Rewrites was occuring, I would appreciate it.

 

\

Coordinator
May 2, 2011 at 7:35 PM

Thanks for the explanation and for your efforts at diagnosis.

I fixed the bug described in the workitem 30604. That should take care of the crash.

As for the doubling of the data - I don't understand how that is happening.  This was raised previously, a long time ago, and there is a stanza of code in the Rewriter.c module (See line 2522) that aims to specially handle URLs that begin with proxy.iirf.  If you are getting two rewrites in succession, that indicates that somehow  that particular stanza is not working properly. At this moment, based solely on code analysis, I cannot imagine how that could be true.  But this is software, and I have often been surprised in the past.

I'd like to diagnose this further.  I can instrument Rewriter.c to emit extra log messages specifically for diagnosing that situation. I'd need you to run it and test it on your system.

If you are willing, let me know.  For your part, It would mean installing a special one-off build of IIRF, running one or two URLs through it, and sending me the log file.