Prematurely closed connections do not include request information

[centromere]

If an HTTP client (such as curl) receives an HTTP error while it's sending the body of a request, it will immediately close the connection. If this happens, Warp will call the exception handler, but the Maybe Request will be Nothing.

This is bad because it becomes impossible to audit these requests.

[snoyberg]

I cannot reproduce, I used the following script:

#!/usr/bin/env stack
-- stack --resolver lts-8.8 script
{-# LANGUAGE OverloadedStrings #-}
import Network.Wai
import Network.Wai.Handler.Warp
import Network.HTTP.Types
import Data.Conduit
import Data.Conduit.Network

main :: IO ()
main = withApplicationSettings settings (return app) $ \port ->
  runTCPClient (clientSettings port "localhost") $ \ad -> do
    runConduit
      $ yield "POST / HTTP/1.1\r\ncontent-length: 100\r\n\r\n"
     .| appSink ad
  where
    settings = setOnException onExc defaultSettings
    onExc (Just req) _ = putStrLn "got a request"

app :: Application
app _req send = send $ responseLBS status200 [] "Hello World!"

And I got the output:

$ ./foo.hs 
No packages provided, using experimental import parser
got a request

[centromere]

I fully acknowledge that this test case uses Scotty, and that the problem may lie within it and not WAI/Warp:

#!/usr/bin/env stack
-- stack --system-ghc --resolver lts-8.9 script --package warp --package wai --package scotty --package http-types
{-# LANGUAGE OverloadedStrings #-}
import Control.Exception
import Network.HTTP.Types
import Network.Wai.Handler.Warp
import Network.Wai
import Web.Scotty

exHandler :: Maybe Request -> SomeException -> IO ()
exHandler Nothing    _ = putStrLn "got nothing"
exHandler (Just req) _ = putStrLn "got a request"

app :: ScottyM ()
app = do
  post "/" $ do
    status status400

main :: IO ()
main = do
  let warpSettings = setOnException exHandler
                   $ setPort 3000 defaultSettings
      opts         = Options 0 warpSettings

  scottyOpts opts app

$ curl -v http://localhost:3000/ -F 'x=y'
*   Trying 127.0.0.1...
* Connected to localhost (127.0.0.1) port 3000 (#0)
> POST / HTTP/1.1
> Host: localhost:3000
> User-Agent: curl/7.47.0
> Accept: */*
> Content-Length: 137
> Expect: 100-continue
> Content-Type: multipart/form-data; boundary=------------------------85eb5e97ec166f40
> 
< HTTP/1.1 100 Continue
< HTTP/1.1 400 Bad Request
< Transfer-Encoding: chunked
< Date: Mon, 10 Apr 2017 13:00:38 GMT
< Server: Warp/3.2.11.1
* HTTP error before end of send, stop sending
< 
* Closing connection 0

$ ./server.hs 
got nothing

[snoyberg]

Alright, I think I've identified what's going on here:

• curl is initiating a chunked request body, and not sending any content
• Your application is not trying to read the request body at all, so it gets no exception
• After your application finishes, Warp tries to flush the body
• Warp should notice that there is no request body data and close the connection, but it is not doing that right now
• As a result, Warp thinks it has flushed the body correctly, and tries to read another request off of the connection
• Next request fails because the connection is already closed, and Warp does not have a request to report (since the previous request completed successfully as far as it's concerned)

Still investigating...

EDIT Scratch that about the chunked request body, it's clearly not. The rest of the analysis still seems to apply.

[snoyberg]

OK, this turned out to be quite a bit simpler: when keep-alive connections were failing, it was generating an exception, which it shouldn't do. I've added a commit to master to avoid that, can you test it out?

[centromere]

I've tested it out and Warp now behaves as expected. Thank you.

[snoyberg]

Cool, thanks for confirming. @kazu-yamamoto any objection to me cutting a release with this change?

[kazu-yamamoto]

LGTM.

@snoyberg Thank you for your work!