New IIS Install - working except login hang - HTTP 400?

After pulling my hair out trying to get TWiki to work on IIS6 I discovered Foswiki and followed the instructions at FoswikiOnWindowsIISAndPerl. I have restructured slightly and added some information, including the fact that perl 5.12 doesn't seem to be working, the fact that in IIS you need to use the ".pl" extension, etc.

For login manager I am using TemplateLogin, and for password manager HtPasswdUser.

Eventually I seemed to get everything working, including registration; if a new user registers they get logged in during the registration process and everything works great.

The problem is when you're not logged in - clicking "Log In" or clicking "Edit" causes the HTTP request to simply hang for a long time, and eventually give a "bad request" error. If I sniff the HTTP traffic (using microsoft's Fiddler2 proxy) I can see that the "HTTP 400" response comes back pretty fast - but the Content-Length response header is set to a high value (eg 7258) and the content never arrives. Eventually the HTTP client (browser or HTTP proxy) gives up waiting and displays an error response.

I believe this is the same behaviour I was getting when I had not yet set up the SMTP mail settings and Foswiki was failing to send email during registration (see Support.Question207). Now that I've fixed the SMTP part registration is working fine though, and it logs users in - but the Login page/feature itself still does the strange hang thing.

Environment:

Windows 2003, IIS 6
Followed and updated / filled out instructions in FoswikiOnWindowsIISAndPerl
Foswiki 1.0.9 straight ZIP file (not a setup package)
Active Perl 5.10.1 Build 1007
Not using ApacheLogin / AD integration

I have normal log files building up ("configurationlog.txt" and "log201006.txt"), but no debug or warning files (although my configure settings look right, eg "C:/OrderMotion/Foswiki/data/debug.txt").

I have tried running the script manually from the command line, eg c:\Perl\bin\perl.exe -T "bin/login.pl" /Sandbox/WebTopicList, but when I do this I get a perfectly valid-looking response, eg the response contains a title "(Foswiki login) WebTopicList < Sandbox < Foswiki". The only suspicious thing I can see is that there are no HTTP headers in the response that is printed to the command-line.

Does anyone know what could cause this hang in login only? Alternatively, does anyone know how I can dig deeper into what is going on between perl.exe and IIS 6? I don't know of any pertinent logs in IIS, or any such capability in the Perl environment - what I'd really like, I guess, is a full streaming log of the commandline, stdin, stdout, and stderr for any request that IIS6 passes on to Perl.exe; does anyone know whether this is possible?

Any help would be hugely appreciated!

-- TaoKlerks - 07 Jun 2010

UPDATE: Following the suggestions at http://jdporter.perlmonk.org/cgi_course/appendix1.html#D, I forced out a response to the browser by adding two extra lines to the top of the login.pl script:

$|=1; #apparently to stop buffering
print "Content-type: text/html\n\n"; #to force out the response by lying to IIS, telling it EVERYTHING afterwards is just content

By doing this I was able to make login.pl functional (though ugly); I still don't know why the http status is being returned as "400" (or whether that's even the issue), but here's the raw HTTP output:

HTTP/1.1 200 OK
Content-Type: text/html
Server: Microsoft-IIS/6.0
X-Powered-By: ASP.NET
Date: Mon, 07 Jun 2010 13:27:20 GMT
Connection: close

X-Foswikiuri: /bin/login.pl/Main/WebHome?origurl=/bin/view.pl/
Content-Length: 7225
X-Foswikiaction: login
Status: 400
Content-Type: text/html; charset=iso-8859-1
Set-Cookie: FOSWIKISTRIKEONE=f172cd14d5f16c97bdcecbe1063be516; path=/
Set-Cookie: FOSWIKISID=1ea015ef5abccab51dd0f4868bc3c542; path=/; HttpOnly

<!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.0 Transitional//EN" "http://www.w3.org/TR/xhtml1/DTD/xhtml1-transitional.dtd"><html xmlns="http://www.w3.org/1999/xhtml" xml:lang="en_US" lang="en_US"><head>
<title>(Foswiki login) WebHome &lt; Main &lt; Foswiki</title>

<meta http-equiv="Content-Type" content="text/html; charset=iso-8859-1" />
<link rel="icon" href="/pub/System/ProjectLogos/favicon.ico" type="image/x-icon" />
<link rel="shortcut icon" href="/pub/System/ProjectLogos/favicon.ico" type="image/x-icon" />
<link rel="alternate" href="http://wiki3.ordermotion.com/bin/edit.pl/Main/WebHome?t=1275917240" type="application/x-wiki" title="edit WebHome" />
<meta name="WEBTOPIC" content="WebHome" />
<meta name="WEB" content="Main" />
<meta name="SCRIPTURLPATH" content="/bin" />
<meta name="SCRIPTSUFFIX" content=".pl" />

[SNIP - the rest is just  normal login.pl output]

This "solution" is only temporary, because it's also breaking the 302 redirect after successful login (which makes sense):

HTTP/1.1 200 OK
Content-Type: text/html
Server: Microsoft-IIS/6.0
X-Powered-By: ASP.NET
Date: Mon, 07 Jun 2010 13:30:07 GMT
Connection: close

X-Foswikiuri: /bin/login.pl/Main/WebHome
X-Foswikiaction: login
Status: 302
Content-Type: text/html; charset=ISO-8859-1
Set-Cookie: FOSWIKISID=1ea015ef5abccab51dd0f4868bc3c542; path=/; HttpOnly
Location: /bin/edit.pl/Main/WebHome?foswiki_redirect_cache=cb9b6362bbda6d5a34b47d9b57d3aaf9
Date: Mon, 07 Jun 2010 13:30:08 GMT

again, any thoughts would be hugely appreciated.

-- TaoKlerks - 07 Jun 2010

ANOTHER UPDATE: I eventually found the task item 1029 that also referenced the number "400", and was able to connect the dots. There is a bug in Foswiki (since 1.0.1??) that causes IIS to misbehave under some circumstances, because the Foswiki-initiated HTTP Response status of 400 is unexpected to IIS (maybe IIS does not expect there ever to be response content... it's not clear). I have added the workaround to the instructions at FoswikiOnWindowsIISAndPerl.

I don't know how the "Status" field is supposed to work here, so I guess I'll leave this question as "Asked" for now - whoever knows, feel free to change it to a more sensible status like "Answered" if that makes sense.

-- TaoKlerks - 07 Jun 2010

Well done for answering your own question! Yes, that 400 status wasn't well thought out.

-- CrawfordCurrie - 07 Jun 2010