Akka message transmission time

I am working on artificial life modeling with Scala and Akka and so far I have been very happy with both. I have some timing issues however I cannot explain.

Currently every animal in my simulation is a pair of actors (animal + brain). As a rule, these two actors take turns (the animal sends a sensory signal to the brain, waits for the result, acts on it and starts over). From time to time, animals must interact with each other in order to eat each other or reproduce.

The only thing that is strange to me is the time. It turns out that sending a message from one animal to another is slower (about 100 times) than sending from an animal to the brain. This puts my poor predators and sexually active animals at a disadvantage compared to vegetarians and asexual creatures (disclaimer: I'm a vegetarian myself, but I think there are better reasons to be a vegetarian than to get stuck a little trying to hunt ..).

I extracted the minimal piece of code that demonstrates the problem:

package edu.blindworld.test

import java.util.concurrent.TimeUnit

import akka.actor.{ActorRef, ActorSystem, Props, Actor}
import akka.pattern.ask
import akka.util.Timeout

import scala.concurrent.Await
import scala.concurrent.duration.Duration
import scala.util.Random

class Animal extends Actor {
  val brain = context.actorOf(Props(classOf[Brain]))
  var animals: Option[List[ActorRef]] = None

  var brainCount = 0
  var brainRequestStartTime = 0L
  var brainNanos = 0L

  var peerCount = 0
  var peerRequestStartTime = 0L
  var peerNanos = 0L

  override def receive = {
    case Go(all) =>
      animals = Some(all)
      performLoop()
    case BrainResponse =>
      brainNanos += (System.nanoTime() - brainRequestStartTime)
      brainCount += 1
      // Animal interactions are rare
      if (Random.nextDouble() < 0.01) {
        // Send a ping to a random other one (or ourselves). Defer our own loop
        val randomOther = animals.get(Random.nextInt(animals.get.length))
        peerRequestStartTime = System.nanoTime()
        randomOther ! PeerRequest
      } else {
        performLoop()
      }
    case PeerResponse =>
      peerNanos += (System.nanoTime() - peerRequestStartTime)
      peerCount += 1
      performLoop()
    case PeerRequest =>
      sender() ! PeerResponse
    case Stop =>
      sender() ! StopResult(brainCount, brainNanos, peerCount, peerNanos)
      context.stop(brain)
      context.stop(self)
  }

  def performLoop() = {
    brain ! BrainRequest
    brainRequestStartTime = System.nanoTime()
  }
}

class Brain extends Actor {
  override def receive = {
    case BrainRequest =>
      sender() ! BrainResponse
  }
}

case class Go(animals: List[ActorRef])
case object Stop
case class StopResult(brainCount: Int, brainNanos: Long, peerCount: Int, peerNanos: Long)

case object BrainRequest
case object BrainResponse

case object PeerRequest
case object PeerResponse

object ActorTest extends App {
  println("Sampling...")
  val system = ActorSystem("Test")
  val animals = (0 until 50).map(i => system.actorOf(Props(classOf[Animal]))).toList
  animals.foreach(_ ! Go(animals))
  Thread.sleep(5000)
  implicit val timeout = Timeout(5, TimeUnit.SECONDS)
  val futureStats = animals.map(_.ask(Stop).mapTo[StopResult])
  val stats = futureStats.map(Await.result(_, Duration(5, TimeUnit.SECONDS)))
  val brainCount = stats.foldLeft(0)(_ + _.brainCount)
  val brainNanos = stats.foldLeft(0L)(_ + _.brainNanos)
  val peerCount = stats.foldLeft(0)(_ + _.peerCount)
  val peerNanos = stats.foldLeft(0L)(_ + _.peerNanos)
  println("Average time for brain request: " + (brainNanos / brainCount) / 1000000.0 + "ms (sampled from " + brainCount + " requests)")
  println("Average time for peer pings: " + (peerNanos / peerCount) / 1000000.0 + "ms (sampled from " + peerCount + " requests)")
  system.shutdown()
}

      

        
        
        
      

    

Here's what's going on here:

• I create 50 animal / brain actor pairs.
• All of them are up and running within 5 seconds.
• Each animal makes an endless cycle, taking turns with its brain.
• In 1% of all runs, the animal sends a ping to an arbitrary other animal and waits for a response. He then continues his loop with his brain.
• Every request to the brain and peer is measured so that we can get an average
• After 5 seconds, everything is stopped, and the timings for requests and pins for peers are compared.

On my dual core i7 I see these numbers:

Average time for a brain request: 0.004708 ms (taken from 21073859 requests)

Average time for peer-to-peer calls: 0.66866 ms (sampled from 211167 requests)

Thus, peer pings are 165 times slower than brain requests. I tried a lot to fix this (like priority mailboxes and JIT warming up) but couldn't figure out what was going on. Anyone have an idea?