Why does my Akka FSM event time out?

Question

As a learning exercise for Akka FSM, I modeled a simplified order processing flow at a coffee shop. Attached is the state transition diagram. However, one of the test cases I wrote times out and I don't understand why.

FSM (case classes not shown for brevity):

class OrderSystem extends Actor with ActorLogging with LoggingFSM[State, Data] {
  startWith(OrderPending, Data(OrderPending, PaymentPending))

  when(OrderPending) {
    case Event(BaristaIsBusy, _) => stay
    case Event(BaristaIsAvailable(_, PaymentPending), _) => goto(OrderPlaced) using Data(stateName, PaymentPending)
    case Event(b: BaristaIsAvailable, _) => goto(OrderReady)
  }

  val waiting = Data(OrderPlaced, PaymentAccepted)

  when(OrderPlaced) {
    case Event(b: BaristaIsAvailable, `waiting`) => println("1"); goto(OrderReady)
    case Event(b: BaristaIsBusy, `waiting`) => println("2"); goto(OrderPending) using `waiting`
    case Event(_, Data(_, PaymentDeclined)) => println("3"); goto(OrderClosed)
    case Event(_, Data(_, PaymentPending)) => println("4"); stay
  }

  when(OrderReady) {
    case Event(HappyWithOrder, _) => goto(OrderClosed)
    case Event(NotHappyWithOrder, _) => goto(OrderPending) using Data(stateName, PaymentAccepted)
  }

  when(OrderClosed) {
    case _ => stay
  }

  whenUnhandled {
    case Event(e, s) => {
      // state name is available as 'stateName'
      log.warning("Received unhandled request {} in state {}/{}", e, stateName, s)
      stay
    }
  }

  // previous state data is available as 'stateData' and next state data as 'nextStateData'
  // not necessary as LoggingFSM (if configured) will take care of logging
  onTransition {
    case _ -> nextState => log.info("Entering state: {} with payment activity: {} from state: {} with payment activity: {}.",
      nextState, stateData.paymentActivity, nextStateData.fromState, nextStateData.paymentActivity)
  }

  initialize()
}

Failing test:

it should "stay in OrderPlaced state as long as customer has not paid" in {
    val orderSystem = system.actorOf(Props[OrderSystem])
    orderSystem ! BaristaIsAvailable(OrderPending, PaymentPending)

    orderSystem ! SubscribeTransitionCallBack(testActor)

    expectMsg(CurrentState(orderSystem, OrderPlaced))

    orderSystem ! BaristaIsAvailable(OrderPlaced, PaymentPending)

    expectMsg(CurrentState(orderSystem, OrderPlaced))
}

Logs:

2015-09-22 23:29:15.236 [order-system-akka.actor.default-dispatcher-2] [DEBUG] n.a.s.o.OrderSystem - processing Event(BaristaIsAvailable(OrderPending,PaymentPending),Data(OrderPending,PaymentPending)) from Actor[akka://order-system/system/testActor1#-2143558060]
2015-09-22 23:29:15.238 [order-system-akka.actor.default-dispatcher-2] [INFO ] n.a.s.o.OrderSystem - Entering state: OrderPlaced with payment activity: PaymentPending from state: OrderPending with payment activity: PaymentPending.
2015-09-22 23:29:15.239 [order-system-akka.actor.default-dispatcher-2] [DEBUG] n.a.s.o.OrderSystem - transition OrderPending -> OrderPlaced
4
2015-09-22 23:29:15.242 [order-system-akka.actor.default-dispatcher-2] [DEBUG] n.a.s.o.OrderSystem - processing Event(BaristaIsAvailable(OrderPlaced,PaymentPending),Data(OrderPending,PaymentPending)) from Actor[akka://order-system/system/testActor1#-2143558060]
[31m- should stay in OrderPlaced state as long as customer has not paid *** FAILED ***[0m
[31m  java.lang.AssertionError: assertion failed: timeout (3 seconds)

Answer 1

SubscribeTransitionCallBack will only deliver a CurrentState once, and then only Transition callbacks.

You could try to do this:

it should "stay in OrderPlaced state as long as customer has not paid" in {

  val orderSystem = TestFSMRef(new OrderSystem)

  orderSystem ! SubscribeTransitionCallBack(testActor)
  // fsm first answers with current state
  expectMsgPF(1.second. s"OrderPending as current state for $orderSystem") { 
    case CurrentState('orderSystem', OrderPending) => ok 
  }

  // from now on the subscription will yield 'Transition' messages
  orderSystem ! BaristaIsAvailable(OrderPending, PaymentPending)
  expectMsgPF(1.second, s"Transition from OrderPending to OrderPlaced for $orderSystem") { 
    case Transition(`orderSystem`, OrderPending, OrderPlaced) => ok 
  }

  orderSystem ! BaristaIsAvailable(OrderPlaced, PaymentPending)
  // there is no transition, so there should not be a callback.
  expectNoMsg(1.second)

/*
  // alternatively, if your state data changes, using TestFSMRef, you could check state data blocking for some time
  awaitCond(
    p = orderSystem.stateData == ???, 
    max = 2.seconds, 
    interval = 200.millis,
    message = "waiting for expected state data..."
  )
  // awaitCond will throw an exception if the condition is not met within max timeout
*/
  success
}