All requests showing up twice in Trace.axd ?

Topics: User Forum
Mar 24, 2011 at 3:03 AM
Edited Mar 24, 2011 at 3:18 AM

(Edit: Resolved; see my reply.  Maybe this will be useful to somebody else.  Had to remove "ExtensionlessUrlHandler-Integrated-4.0" from the Handler Mappings)

I'm puzzled.  I think this is perhaps more of a "I'm not understanding the IIS request pipeline" issue than anything else, but I'm not sure where to turn.

Problem: My iirf.ini seems to be rewriting things correctly.  However, each request that gets rewritten to a .aspx shows up twice in trace.axd... the first request is the rewritten one (missing the Form collection!) and the second copy of the request is not rewritten (but it has the Form collection)

Info:

  • Windows 2008 R2 SP1, IIS7.5, ASP.NET 4

iirf.ini:

 

RewriteEngine ON
StatusInquiry ON

RewriteLog  c:\temp\iirfLog.out
RewriteLogLevel 2

# let me through! 
RewriteCond	%{URL}	\/trace.axd	[I]
RewriteRule	^(.*)$	- [U,I,L]

# assets - let'em through
RewriteCond %{URL}						\/assets\/(.*)$
RewriteRule ^(.*)$	- [U,I,L]

RewriteCond %{SERVER_NAME}			^([^\.]+)\.(xxx|xxx|)\.com$                [I]			
RewriteRule \/?([^\/]+)?\/?([^\/]+)?\/?([^\/]+)?\/?([^\/]+)?\/?([^\/]+)?$                  /xxx/xxx.aspx?purl=*1&domain=*2&action=$1¶m1=$2¶m2=$3¶m3=$4¶m4=$5    [U,I,L]

 

trace.axd

 

No.	Time of Request	File	Status Code	Verb	 
1	3/23/2011 9:47:15 PM	activation	200	GET	View Details
2	3/23/2011 9:47:15 PM	activation	200	GET	View Details

 

iirf log:

 

Wed Mar 23 21:47:15 -  1096 - -------------------------------------------------------
Wed Mar 23 21:47:15 -  1096 - Ionic ISAPI Rewriting Filter (IIRF) 2.1.1.25 x64 RELEASE
Wed Mar 23 21:47:15 -  1096 - IIRF was built on: Jan  7 2011 07:30:50
Wed Mar 23 21:47:15 -  1096 - Cached: DLL_PROCESS_ATTACH
Wed Mar 23 21:47:15 -  1096 - Cached: Process ID: 1916
Wed Mar 23 21:47:15 -  1096 - Cached: ReadServerConfig: C:\Program Files (x86)\iirf\IirfGlobal.ini(1): StatusInquiry setting is now: ON
Wed Mar 23 21:47:15 -  1096 - Cached: DLL_PROCESS_ATTACH - complete
Wed Mar 23 21:47:15 -  1096 - Cached: GetFilterVersion
Wed Mar 23 21:47:15 -  1096 - GetLogFile: app:'/LM/W3SVC/1/ROOT'  new log:'c:\temp\iirfLog.out.1916.log'
Wed Mar 23 21:47:15 -  1096 - ReadVdirConfig: actual log file 'c:\temp\iirfLog.out.1916.log'
Wed Mar 23 21:47:15 -  1096 - ReadVdirConfig: ini file: 'C:\inetpub\wwwroot\yourmysite\Mymysite\Mymysite\Iirf.ini'
Wed Mar 23 21:47:15 -  1096 - ReadVdirConfig: ini file timestamp: 2011/03/23 21:47:04 Eastern Daylight Time
Wed Mar 23 21:47:15 -  1096 - ReadVdirConfig: cfg(0x02C2FDB0)
Wed Mar 23 21:47:15 -  1096 - ReadVdirConfig: LogLevel = 2
Wed Mar 23 21:47:15 -  1096 - ReadVdirConfig: C:\inetpub\wwwroot\yourmysite\Mymysite\Mymysite\Iirf.ini(1): WARNING: unrecognized directive, ignoring it: '#'
Wed Mar 23 21:47:15 -  1096 - ReadVdirConfig: C:\inetpub\wwwroot\yourmysite\Mymysite\Mymysite\Iirf.ini(8): RewriteEngine will be enabled.
Wed Mar 23 21:47:15 -  1096 - ReadVdirConfig: C:\inetpub\wwwroot\yourmysite\Mymysite\Mymysite\Iirf.ini(9): StatusInquiry ON (--) (--)
Wed Mar 23 21:47:15 -  1096 - ReadVdirConfig: C:\inetpub\wwwroot\yourmysite\Mymysite\Mymysite\Iirf.ini(9): IIRF Status Inquiry is enabled at path '/iirfStatus' for local requests only.
Wed Mar 23 21:47:15 -  1096 - ReadVdirConfig: C:\inetpub\wwwroot\yourmysite\Mymysite\Mymysite\Iirf.ini(15): RewriteCond   %{URL}  \/trace.axd '[I]'
Wed Mar 23 21:47:15 -  1096 - ReadVdirConfig: C:\inetpub\wwwroot\yourmysite\Mymysite\Mymysite\Iirf.ini(16): RewriteRule (rule 1)  '^(.*)$'  '-'  [U,I,L]
Wed Mar 23 21:47:15 -  1096 - ReadVdirConfig: C:\inetpub\wwwroot\yourmysite\Mymysite\Mymysite\Iirf.ini(19): RewriteCond   %{URL}  \/assets\/(.*)$ '(null)'
Wed Mar 23 21:47:15 -  1096 - ReadVdirConfig: C:\inetpub\wwwroot\yourmysite\Mymysite\Mymysite\Iirf.ini(20): RewriteRule (rule 2)  '^(.*)$'  '-'  [U,I,L]
Wed Mar 23 21:47:15 -  1096 - ReadVdirConfig: C:\inetpub\wwwroot\yourmysite\Mymysite\Mymysite\Iirf.ini(23): RewriteCond   %{SERVER_NAME}  ^([^\.]+)\.(yourmysite|mymysite|)\.com$ '[I]'
Wed Mar 23 21:47:15 -  1096 - ReadVdirConfig: C:\inetpub\wwwroot\yourmysite\Mymysite\Mymysite\Iirf.ini(24): RewriteRule (rule 3)  '\/?([^\/]+)?\/?([^\/]+)?\/?([^\/]+)?\/?([^\/]+)?\/?([^\/]+)?$'  '/mysite/mysite.aspx?purl=*1&domain=*2&action=$1¶m1=$2¶m2=$3¶m3=$4¶m4=$5'  [U,I,L]
Wed Mar 23 21:47:15 -  1096 - ReadVdirConfig: INFO: [U] flag in use, with global NotifyLog - Unmangled URIs will be logged.
Wed Mar 23 21:47:15 -  1096 - ReadVdirConfig: Done reading INI for the root vdir, found 3 rules (0 errors, 1 warnings) on 25 lines
Wed Mar 23 21:47:15 -  1096 - DoRewrites: Url (no decoding): '/activation'
Wed Mar 23 21:47:15 -  1096 - EvaluateRules: Last Rule
Wed Mar 23 21:47:15 -  1096 - DoRewrites: Rewrite Url to: '/mysite/mysite.aspx?purl=tarasmith&domain=mymysite&action=activation¶m1=¶m2=¶m3=¶m4='
Wed Mar 23 21:47:16 -  2104 - DoRewrites: Url (no decoding): '/assets/mysite/v1/css/giftpak.css'
Wed Mar 23 21:47:16 -  2104 - EvaluateRules: Last Rule
Wed Mar 23 21:47:16 -  2104 - DoRewrites: Rewrite Url to: '/assets/mysite/v1/css/giftpak.css'
Wed Mar 23 21:47:16 -  2104 - DoRewrites: Url (no decoding): '/assets/mysite/v1/js/jquery-1.4.4.min.js'
Wed Mar 23 21:47:16 -  2104 - EvaluateRules: Last Rule
Wed Mar 23 21:47:16 -  2104 - DoRewrites: Rewrite Url to: '/assets/mysite/v1/js/jquery-1.4.4.min.js'
Wed Mar 23 21:47:16 -  2104 - DoRewrites: Url (no decoding): '/assets/mysite/v1/js/mysite.js'
Wed Mar 23 21:47:16 -  2104 - EvaluateRules: Last Rule
Wed Mar 23 21:47:16 -  2104 - DoRewrites: Rewrite Url to: '/assets/mysite/v1/js/mysite.js'
Wed Mar 23 21:48:03 -  2444 - DoRewrites: Url (no decoding): '/trace.axd'
Wed Mar 23 21:48:03 -  2444 - EvaluateRules: Last Rule
Wed Mar 23 21:48:03 -  2444 - DoRewrites: Rewrite Url to: '/trace.axd'
Troubleshooting steps taken so far:
  1. I looked at things in Fiddler and in IIS's log files, and only one request is being sent to the server.  So I don't think there's a redirect happening somewhere?
  2. When I set "RewriteEngine" to "OFF" the double requests disappear... (however of course the app no longer works :-P)


Mar 24, 2011 at 3:16 AM

Ah.  OK.  This is resolved now.

I had to remove "ExtensionlessUrlHandler-Integrated-4.0" from the Handler Mappings.

 

Boy, was I stumped for a long time!