Websocket Error 1006: http4s Backend Timout After 60 Secs

[nekrondev]

Runtime

Version: Docspell 0.41.0 (via docspell/restserver:latest) Browser: Firefox 108 / Chrome 120 Reverse proxy: Lighttpd 1.4.52 with mod_proxy and long-running websocket timeouts using the following config

$HTTP["host"] == "subdomain.mydomain.com" {
  $HTTP["url"] == "/api/v1/sec/ws" {
        proxy.server  = ("" => (("host" => "docspell-restserver", "port" => 7880)))
        proxy.header = ( "upgrade" => "enable", "connect" => "enable")
        server.max-read-idle = 86400
        server.max-write-idle = 86400
        server.max-keep-alive-idle = 86400
      }
      else {
          $HTTP["url"] =~ "^/([^.](.*))$|^/$" {
          proxy.server  = ("" => (("host" => "docspell-restserver", "port" => 7880)))
      }
    }
        accesslog.filename = "/var/log/lighttpd/docspell.log"
}

Expected behavior

Websocket connection working and pushing messages between frontend and backend.

Actual behavior

Websocket connection timed out after 60 seconds after connection had been upgraded. The previous release v0.40.0 didn't run into this issue with same reverse proxy setup.

Logs

2024.02.15 13:09:30:0000 [io-comp...] [ERROR] org.http4s.ember.server.EmberServerBuilderCompanionPlatform - WebSocket connection terminated with exception
java.util.concurrent.TimeoutException: 60 seconds
        at timeout @ org.http4s.ember.core.Util$.timeoutMaybe(Util.scala:106)
        at main$ @ docspell.restserver.Main$.main(Main.scala:14)
        at timeout @ org.http4s.ember.core.Util$.timeoutMaybe(Util.scala:106)
        at timeout @ org.http4s.ember.core.Util$.timeoutMaybe(Util.scala:106)

[nekrondev]

As far as I can see Eike changed from BlazeServerBuilder to EmberServerBuilder implementation using the servers defaults.

https://github.com/eikek/docspell/blob/50dadad48e85d25a8127a3bae2c53110663d90c5/modules/restserver/src/main/scala/docspell/restserver/RestServer.scala#L63

EmberServerBuilder is using a 60 second idle timeout on socket reads that will be raised because there is currently no incoming websocket traffic from the frontend.

https://github.com/http4s/http4s/blob/v0.23.18/server/shared/src/main/scala/org/http4s/server/package.scala#L84

As lighttpd isn't sending pings between http server and REST backend the connection will be idle terminated by backend service after 60 seconds. I'm not sure why this behavior isn't the same as with the previous BlazeServerBuilder initialization that seems to ignore the default idle setting.

[nekrondev]

To fix this issue the idleTimeout should be user-defined like responseTimeout that can be configured through the startup env vars. The now fixed idle timeout behavior will break reverse proxies that don't send keep alive pings between proxy and backend connection. With the addition of user-defined idleTimeout one can configure a long lasting idle timeout to prevent this.

[nekrondev]

Actually there is an even better and much more easier solution to this by returning the keep-alive events from client downstream to backend as seen in #2500.

The websocket connection isn't killed after 60s idle timeout with this ping-pong loop.

[eikek]

@nekrondev thank you very much for taking a deep look into this! I wasn't aware about the changes in timeouts bewteen blaze and ember.