0

Our app runs on IIS 7.5 with Windows Authentication enabled. When uploading files via POST, some users are reporting intermittent Error 400s from IIS with an "Invalid Verb" message.

I was able to reproduce this myself by completing the same form as the user with the same uploaded file and it failed twice in a row, but then succeeded the third.

Using Chrome's Network tab I was able to copy the request and response headers from both the failed and successful attempts.

My interpretation of the difference suggests that it's failing at the authentication step, but I could be wrong. Any suggestions as to what I need to look into?

Success

POST <redacted> HTTP/1.1
Host: <redacted>
Connection: keep-alive
Content-Length: 26636
Cache-Control: max-age=0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8
Origin: <redacted>
User-Agent: Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/43.0.2357.124 Safari/537.36
Content-Type: multipart/form-data; boundary=----WebKitFormBoundaryQ6KIItP6Z7A76guk
Referer: <redacted>
Accept-Encoding: gzip, deflate
Accept-Language: en-US,en;q=0.8
Cookie: <redacted>
X-CookiesOK: I explicitly accept all cookies

HTTP/1.1 302 Found
Content-Type: text/html; charset=UTF-8
Location: <redacted>
Server: Microsoft-IIS/7.5
X-Powered-By: PHP/5.6.6
X-Powered-By: ASP.NET
Date: Wed, 17 Jun 2015 10:37:42 GMT
Content-Length: 164

Fail

POST <redacted> HTTP/1.1
Host: <redacted>
Connection: keep-alive
Content-Length: 46013
Cache-Control: max-age=0
Authorization: NTLM <redacted>==
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8
Origin: <redacted>
User-Agent: Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/43.0.2357.124 Safari/537.36
Content-Type: multipart/form-data; boundary=----WebKitFormBoundaryY5kiMQ9SHsqAoBjs
Referer: <redacted>
Accept-Encoding: gzip, deflate
Accept-Language: en-US,en;q=0.8
Cookie: <redacted>
X-CookiesOK: I explicitly accept all cookies

HTTP/1.1 400 Bad Request
Content-Type: text/html; charset=us-ascii
Server: Microsoft-HTTPAPI/2.0
Date: Wed, 17 Jun 2015 10:43:50 GMT
Connection: close
Content-Length: 326

http.sys trace:

<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
    <System>
        <Provider Name="Microsoft-Windows-HttpService" Guid="{dd5ef90a-6398-47a4-ad34-4dcecdef795f}" />
        <EventID>52</EventID>
        <Version>0</Version>
        <Level>2</Level>
        <Task>1</Task>
        <Opcode>62</Opcode>
        <Keywords>0x8000000000000002</Keywords>
        <TimeCreated SystemTime="2015-06-17T13:14:10.558152100Z" />
        <Correlation ActivityID="{80000507-0000-7000-b63f-84710c7967bb}" />
        <Execution ProcessID="4" ThreadID="1376" ProcessorID="0" KernelTime="32565" UserTime="0" />
        <Channel>Microsoft-Windows-HttpService/Trace</Channel>
        <Computer />
    </System>
    <EventData>
        <Data Name="Status">0xC0000010</Data>
        <Data Name="RequestId">0x7000000080000507</Data>
        <Data Name="Reason">VerbLookupFailed</Data>
        <Data Name="ErrorCode">       2</Data>
        <Data Name="HintLength">       8</Data>
        <Data Name="HintData">0x535541696A6A5648</Data>
    </EventData>
    <RenderingInfo Culture="en-US">
        <Level>Error </Level>
        <Opcode>ParseRequestFailed </Opcode>
        <Keywords>
            <Keyword>Flagged on all HTTP events dealing with request processing </Keyword>
        </Keywords>
        <Task>HTTP Request Trace Task </Task>
        <Message>Parsing of request (request ID 0x7000000080000507) failed due to reason: VerbLookupFailed. Request may not be compliant with HTTP/1.1. </Message>
        <Channel>HTTP Service Channel </Channel>
        <Provider>Microsoft-Windows-HttpService </Provider>
    </RenderingInfo>
</Event>
gazareth
  • 101
  • 4
  • Interestingly, the failed request's response comes from `Microsoft-HTTPAPI/2.0` which is the kernel part of IIS, that request doesn't even make it into the user mode part where authentication happens. Have you checked the http.sys log files at `%SystemRoot%\System32\LogFiles\HTTPERR`? If you can reproduce the problem, you may want to enable http.sys tracing to get more inside. – Peter Hahndorf Jun 17 '15 at 11:49
  • I turned on tracing and it looks like it's getting the App Pool and back: `Server application passed response (request ID 0x7000000080000506, connection ID 0x7000000060000505, method POST, header length 4294965376, number of entity chunks 1, cache policy 0) with status code 401.` – gazareth Jun 17 '15 at 12:29
  • But that's a 401, not a 400 as above. I'm not sure what to make of it. – Peter Hahndorf Jun 17 '15 at 13:38
  • My bad. I've just added the full log entry for the 400 response above. – gazareth Jun 17 '15 at 16:27
  • This suggests that it might be some sort of networking issue: https://social.technet.microsoft.com/Forums/en-US/cbef2131-5e86-4cea-ae70-520c6f610652/intermittent-400-bad-request-invalid-verb-sharepont-2010?forum=sharepointgeneralprevious I wonder if the request is getting cut off before the server, is there a way to capture the request headers/body on the server end? – gazareth Jun 18 '15 at 17:01

0 Answers0