Any way to log akka timeouts with more information about where the error is?

Question

---

Update Wed Oct 16th) There was a PullRequest today that gives target info on timeouts. https://github.com/akka/akka/pull/1780

---

Akka's timeout exceptions are horrendously unhelpful.

Is there some way to get a useful message about where/what is happening in the timeout?

exceptions like this are not helpful

java.util.concurrent.TimeoutException: Futures timed out after [5000] milliseconds
    at akka.dispatch.DefaultPromise.ready(Future.scala:834)
    at akka.dispatch.DefaultPromise.ready(Future.scala:811)
    at akka.dispatch.Await$.ready(Future.scala:64)
    at nl.cwi.crisp.examples.p2p.scala.Network.<init>(Node.scala:136)
    at nl.cwi.crisp.examples.p2p.scala.Main$$anonfun$11.apply(Node.scala:164)
    at nl.cwi.crisp.examples.p2p.scala.Main$$anonfun$11.apply(Node.scala:164)
    at akka.actor.ActorCell.newActor(ActorCell.scala:488)
    at akka.actor.ActorCell.create$1(ActorCell.scala:506)
    at akka.actor.ActorCell.systemInvoke(ActorCell.scala:591)
    at akka.dispatch.Mailbox.processAllSystemMessages(Mailbox.scala:191)
    at akka.dispatch.Mailbox.run(Mailbox.scala:160)
    at akka.dispatch.ForkJoinExecutorConfigurator$MailboxExecutionTask.exec(AbstractDispatcher.scala:505)
    at akka.jsr166y.ForkJoinTask.doExec(ForkJoinTask.java:259)
    at akka.jsr166y.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:997)
    at akka.jsr166y.ForkJoinPool.runWorker(ForkJoinPool.java:1495)
    at akka.jsr166y.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:104)

Answer 1

With the akka code the way it currently is, it's not going to happen. Let's start by taking a look at why. If you look at the PromiseActorRef object you can see:

def apply(provider: ActorRefProvider, timeout: Timeout): PromiseActorRef = {
  val result = Promise[Any]()
  val scheduler = provider.guardian.underlying.system.scheduler
  val a = new PromiseActorRef(provider, result)
  implicit val ec = a.internalCallingThreadExecutionContext
  val f = scheduler.scheduleOnce(timeout.duration) { result tryComplete Failure(new AskTimeoutException("Timed out")) }
  result.future onComplete { _ ‚áí try a.stop() finally f.cancel() }
  a
}

This is where the parallel (parallel to the actual actor call) timeout is scheduled. This class has no context of what message it's sending or to what actor ref it was sending it to. That's probably why it just says "Timed Out" which is not very helpful. I'm kinda hoping that the typesafe guys tweak this a little to provide more info, but in case they don't or if you want something in the interim, you could try something like this:

object NewAskPattern{
  implicit def ask(ref:ActorRef) = new BetterTimeoutMessageSupportAskableRef(ref)
}

class BetterTimeoutMessageSupportAskableRef(ref: ActorRef) {
  import akka.pattern.AskableActorRef
  val askRef = new AskableActorRef(ref)

  def ask(message: Any)(implicit timeout: Timeout, ec:ExecutionContext): Future[Any] = 
    (askRef ? message) recover{
      case to:TimeoutException => 
        val recip = askRef.actorRef.path
        val dur = timeout.duration
        throw new TimeoutException(s"Timed out sending message $message to recipient $recip using timeout of $dur") 
    }

  def ?(message: Any)(implicit timeout: Timeout, ec:ExecutionContext): Future[Any] = 
    ask(message)(timeout, ec)
} 

class MySlowActor extends Actor{
  def receive = {
    case any => 
      Thread.sleep(5000)
      sender ! "bar"
  }
}

object NewMessageTest{
  import NewAskPattern.ask

  def main(args: Array[String]) {
    implicit val timeout = Timeout(2 seconds)
    val sys = ActorSystem()
    import sys.dispatcher

    val slow = sys.actorOf(Props[MySlowActor])
    val fut = slow ? "foo"
    fut onComplete (println(_))
  }
}

The general idea here is to wrap the AskableActorRef from the Akka lib and enhance it a little. I'm taking the Future returned by ask and adding a recover combinator to it allowing me to tweak the message when we get a timeout. As this class has the context of what message was being sent and who it was being sent to, it can formulate a more helpful message. Then the NewAskPattern object contains the new implicit to give you the BetterTimeoutMessageSupportAskableRef that allows you to gain this enhanced behavior. Is this a perfect solution? Probably not, but it could be a good starting point for you if you really want this behavior.