Jules
Jules

Reputation: 559

Logging Errors and Timeouts in Warp

Some context: My Servant handler is executing a long-running computation. Due to me using a plain return statement in the handler, it returns immediately and the actual computation takes place lazily when Warp tries to send the response to the client. This causes Warp to trigger slowloris timeouts because there is no network progress for a long time.

I fixed it by forcing the result inside the service handler. However, this issue was difficult to diagnose with no indication as to what is happening at either compile time or runtime, so I would like to avoid that in the future.

I do not know if there is a way to catch this mistake at compile time, but I would like to at least trace it at runtime:

  1. All requests and responses should be logged
  2. Errors and timeouts should be indicated as such in the log
  3. Ideally, both the start and the completion of a request should be indicated in the log

I have looked at the wai-logger package, which I can use with Warp's own setLogger setting to install a logger. It seems like this only logs when a request is completed. In particular, there is no log entry at all if a request runs into an error or a timeout.

I have also looked at the RequestLogger module from wai-extra, which uses a middleware to do the logging. In the situation I described above, this results in an immediate log entry indicating success, even if the response has not been sent yet (because the response body is computed lazily). Again, there is no indication of an error or a timeout.

What is the best way to log all requests and responses, including errors and timeouts, in a Warp application?

Update #1

Since an example was requested:

{-# LANGUAGE DataKinds #-}
{-# LANGUAGE TypeApplications #-}

import Network.Wai.Handler.Warp
import Servant

type Service = Get '[JSON] Int

service :: Server Service
service = return $ sum [0..100000000000]

main :: IO ()
main = run 3000 $ serve @Service Proxy service

When using curl http://localhost:3000, I get curl: (52) Empty reply from server after exactly one minute (2x 30s default timeout).

Curiously, running curl http://localhost:3000 repeatedly eventually completes the request successfully. Maybe the sum [0..100000000000] results in a partially evaluated thunk whose evaluation can be resumed in subsequent requests? I am really not sure though.

The issue is fixed by using return $! sum [0..100000000000] instead.

Upvotes: 4

Views: 209

Answers (0)

Related Questions