Using Headers crashes IIS

Nov 14, 2008 at 4:34 PM
I'm trying to turn a URL like:
http://domain.tld/12345678-1234-1234-1234-123456789abc/index.asp into http://domain.tld/index.asp, while throwing the GUID into an HTTP header value.
When I try it on my local machine, attempting to do anything directly with HTTP headers causes IIS to hang.  Specifically, I need to kill and restart the World Wide Web Publishing service.
I'm using IIS Version: 5.1 on my local machine, though the webservers that will eventually be running this are on IIS 6.

Here is the file I'm using:
RewriteLog  C:\iirf.log
RewriteLogLevel 5

#Match a GUID as the first "directory"
RewriteCond URL ^/([0-9a-f]{8}(?:-[0-9a-f]{4}){3}-[0-9a-f]{12})/ [I]

#Overwrite whatever SESSION_KEY header there is already
RewriteHeader SESSION_KEY: .* %1

#Remove the GUID from the URI
RewriteRule ^/[0-9a-f]{8}(?:-[0-9a-f]{4}){3}-[0-9a-f]{12}/(.*)$ /$1 [I,U,L]

And here what I think is the relevant output from the log:
Fri Nov 14 11:13:41 -  1992 - ReadConfig: Done reading, found 2 rules (0 errors, 0 warnings) on 7 lines

--------------------------------------------
Fri Nov 14 11:13:41 - 1992 - LogFile re-opened.
Fri Nov 14 11:13:41 - 1992 - AwaitIniChangeAndReinit: TerminateWatch = FALSE
Fri Nov 14 11:13:41 - 1992 - FileChangeWatcher(): Await returns (TerminateWatch= FALSE)
Fri Nov 14 11:13:41 - 1992 - FileChangeWatcher: Await()...
Fri Nov 14 11:13:41 - 1992 - AwaitIniChangeAndReinit()...
Fri Nov 14 11:14:02 - 6012 - HttpFilterProc: SF_NOTIFY_URL_MAP
Fri Nov 14 11:14:02 - 6012 - OnUrlMap: storing physical path (c:\inetpub\wwwroot\aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaaa\pol_local\testing\tmcg\ASPPage3.asp), in ptr (0x00131d38)
Fri Nov 14 11:14:02 - 6012 - HttpFilterProc: SF_NOTIFY_AUTH_COMPLETE
Fri Nov 14 11:14:02 - 6012 - DoRewrites
Fri Nov 14 11:14:02 - 6012 - GetServerVariable_AutoFree: getting 'url'
Fri Nov 14 11:14:02 - 6012 - GetServerVariable_AutoFree - no joy (GetLastError()=1413)
Fri Nov 14 11:14:02 - 6012 - GetServerVariable_AutoFree: 128 bytes
Fri Nov 14 11:14:02 - 6012 - GetServerVariable_AutoFree: result ''
Fri Nov 14 11:14:02 - 6012 - GetHeader_AutoFree: getting 'url'
Fri Nov 14 11:14:02 - 6012 - GetHeader_AutoFree: 74 bytes, result '/aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaaa/pol_local/testing/tmcg/ASPPage3.asp'
Fri Nov 14 11:14:02 - 6012 - GetServerVariable_AutoFree: getting 'QUERY_STRING'
Fri Nov 14 11:14:02 - 6012 - GetServerVariable_AutoFree: 1 bytes
Fri Nov 14 11:14:02 - 6012 - GetServerVariable_AutoFree: result ''
Fri Nov 14 11:14:02 - 6012 - GetHeader_AutoFree: getting 'method'
Fri Nov 14 11:14:02 - 6012 - GetHeader_AutoFree: 4 bytes, result 'GET'
Fri Nov 14 11:14:02 - 6012 - DoRewrites: New Url: '/aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaaa/pol_local/testing/tmcg/ASPPage3.asp'
Fri Nov 14 11:14:02 - 6012 - EvaluateRules: depth=0
Fri Nov 14 11:14:02 - 6012 - GetHeader_AutoFree: getting 'SESSION_KEY:'
Fri Nov 14 11:14:02 - 6012 - GetHeader_AutoFree failed (GetLastError()=1413)
Fri Nov 14 11:14:02 - 6012 - GetHeader_AutoFree: 0 bytes, result '(null)'

Fri Nov 14 11:14:09 - 6012 - DllMain PROCESS_DETACH
Fri Nov 14 11:14:09 - 6012 - AwaitWatcherTermination: closing dir handle.
Fri Nov 14 11:14:09 - 6012 - AwaitWatcherTermination: Waiting 150 ms ...

a thought that occurred to me is that GetServerVariable_AutoFree failed with the same error number earlier, but recovered.  Could this be related to:
v1.2.12d

6. changed diagnostics in GetServerVariable_AutoFree() to handle
   case where the server var is not set yet.  This is to comply
   with URL normalization recommendations for IIS6 and 5.  First
   we try the IIS6 way, which will give us no joy on IIS5. The
   diagnostic (log) message now reflects this.

from the changelog in that it didn't get replicated to GetHeader_AutoFree?
Nov 14, 2008 at 4:37 PM
Now that I look over the logfile results again, should it be attempting:
GetHeader_AutoFree: getting 'SESSION_KEY:'
or
GetHeader_AutoFree: getting 'SESSION_KEY'
Coordinator
Dec 1, 2008 at 4:59 AM
The codepath mentioned in the releasenotes is in fact what we are seeing here.
I don't know if it is a bug or a problem, though.

The GetHeader_AutoFree statement should reflect the variable name WITHOUT the colon.
I believe this is a bug in v1.2.15.
are you still seeing this problem and would you be willing to test out a new build for me?

Thanks.
-Cheeso