One2OneBidiFlow$OutputTruncationException exception

[idzivinskyi]

With migrating to new akka-http (val akka = "2.5.13", val akkaHttp = "10.1.2") I got an error:

[system-akka.actor.default-dispatcher-3] ERROR a.a.ActorSystemImpl - Internal server error, sending 500 response
akka.http.impl.util.One2OneBidiFlow$OutputTruncationException: Inner flow was completed without producing result elements for 1 outstanding elements

Steps to reproduce:

1. Use code below
2. Open in chrome (or your favorite browser) http://localhost:8080
3. Reload tab 2 times

import akka.actor.{Actor, ActorRef, ActorSystem, Props}
import akka.http.scaladsl.Http
import akka.http.scaladsl.server.{Directives, Route}
import akka.pattern._
import akka.stream.ActorMaterializer
import akka.util.Timeout

import scala.concurrent.duration._
import scala.concurrent.{ExecutionContext, Future}
import scala.io.StdIn

object TestOne2OneBidiFlow extends App with Directives {

  implicit val system: ActorSystem = ActorSystem("system")

  implicit val executionContext: ExecutionContext = system.dispatcher

  implicit val materializer: ActorMaterializer = ActorMaterializer()

  implicit val timeout: Timeout = 2 seconds

  class Foo extends Actor {
    override def receive: Receive = {
      case _ =>
        Thread.sleep(1000)
        sender() ! Some(0)
    }
  }

  val foo: ActorRef = system.actorOf(Props(new Foo()))

  val route: Route = get {
    val future = foo ? "test"

    onSuccess(future) { _ =>
      complete("pong")
    }
  }

  val server: Future[Http.ServerBinding] = Http().bindAndHandle(Route.handlerFlow(route), "localhost", 8080)

  server.foreach { b =>
    println(s"Server started on ${b.localAddress.toString}")
  }

  println(s"Server online at http://localhost:8080/\nPress RETURN to stop...")
  StdIn.readLine()
  server.foreach(_.terminate(1 second))
}

Question: How handle this case properly?

[johanandren]

The trigger for the logged error is not actually reloading the page, but reloading before the previous one had completed, right?

[raboof]

My suspicion is that what's going on is when you reload the page before it has finished loading, the browser closes/cancels the previous request before the response has been sent, and we changed something between 10.1.1 and 10.1.2 that now causes that warning to be logged in that case. I assume you don't actually see a 500 error in the browser, is that correct?

(after a couple of refreshes you'll see a 500 error due to akka.pattern.AskTimeoutException, but that is to be expected)

[idzivinskyi]

@raboof I have the same assumption. The client does not see 500 (I hope so), but I see the increased rate of 500 on balancer site, which makes me think that something wrong going on.

Previous versions handled this situation by closing request before it finished on the server side. I think something changed there, but I could be wrong.

[3erikpotter]

We experience the same error, but with an included memory leak after version update from 10.1.1 to 10.1.2. So it's not only logging unfortunately.

[idzivinskyi]

@eerikpotter same for me with the memory leak, but I was not been able to find root cause yet.

[mr-git]

We have memory leak too - from heap dump it seems that memory leak originates in MasterServerTerminator, specifically GracefulTerminatorStage in AtomicReference.
It seems that these connection terminators are never removed from hashset of alive connections...

[ignasi35]

I think this issue is also what's failing Play's WSSpec which uses an AHC client to send a single POST request.

The WSSpec from Play seems a pretty good reproducer for it's simplicity (no load, proxy/gateway or browser required to see the failure).

[johanandren]

The memory leak is tracked in #2067

[raboof]

@ignasi35 thanks for that! It indeed seems related, and this is also a useful indication that this is something that also impacts non-error situations. What's worse, though, is that (looking with wireshark) it seems in this case it isn't triggered by the client closing the request side of the connection early... perhaps because the request body is chunked?

[ignasi35]

@raboof if it's of any help, @marcospereira pointed to other tests on Play's suite that also fail.

[raboof]

Thanks! All mentioned tests seem to pass with #2069 applied, so that's promising.