NPE on Call Failed state

[hrosa]

During load tests for Hello-Play-One-Minute scenario, RestComm logs showed many entries of the following error:

21:49:11,041 ERROR [org.restcomm.connect.telephony.Call] (RestComm-akka.actor.default-dispatcher-280) java.lang.NullPointerException: org.restcomm.connect.commons.fsm.TransitionFailedException: java.lang.NullPointerException at org.restcomm.connect.commons.fsm.FiniteStateMachine.transition(FiniteStateMachine.java:89) [restcomm-connect.commons-8.0.0.issue1526-rms6-load-test.jar:8.0.0.issue1526-rms6-load-test] at org.restcomm.connect.telephony.Call.onMediaServerControllerStateChanged(Call.java:2179) [restcomm-connect.telephony-8.0.0.issue1526-rms6-load-test.jar:8.0.0.issue1526-rms6-load-test] at org.restcomm.connect.telephony.Call.onReceive(Call.java:515) [restcomm-connect.telephony-8.0.0.issue1526-rms6-load-test.jar:8.0.0.issue1526-rms6-load-test] at akka.actor.UntypedActor$$anonfun$receive$1.applyOrElse(UntypedActor.scala:159) [akka-actor_2.10-2.1.2.jar:] at akka.actor.ActorCell.receiveMessage(ActorCell.scala:425) [akka-actor_2.10-2.1.2.jar:] at akka.actor.ActorCell.invoke(ActorCell.scala:386) [akka-actor_2.10-2.1.2.jar:] at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:230) [akka-actor_2.10-2.1.2.jar:] at akka.dispatch.Mailbox.run(Mailbox.scala:212) [akka-actor_2.10-2.1.2.jar:] at akka.dispatch.ForkJoinExecutorConfigurator$MailboxExecutionTask.exec(AbstractDispatcher.scala:506) [akka-actor_2.10-2.1.2.jar:] at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:262) [scala-library-2.10.1.jar:] at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:975) [scala-library-2.10.1.jar:] at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1478) [scala-library-2.10.1.jar:] at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:104) [scala-library-2.10.1.jar:] Caused by: java.lang.NullPointerException at org.restcomm.connect.telephony.Call$Failed.execute(Call.java:1120) [restcomm-connect.telephony-8.0.0.issue1526-rms6-load-test.jar:8.0.0.issue1526-rms6-load-test] at org.restcomm.connect.commons.fsm.FiniteStateMachine.transition(FiniteStateMachine.java:87) [restcomm-connect.commons-8.0.0.issue1526-rms6-load-test.jar:8.0.0.issue1526-rms6-load-test] ... 12 more

Details: 500 concurrent calls, 50 calls per second, 10k calls (252 failed). restcomm_2017-02-10_21_51.tar.gz

[hrosa]

To add more context, this seems to happen when RMS is unable to execute more CRCX requests and returns an Error response back to RestComm:

2017-02-10 21:48:15,076 ERROR [CreateConnectionCommand] (mgcp-3) Unexpected error occurred during tx=147548894 execution. Reason: Address already in use. Rolling back.

Maybe RestComm cannot process the error response very well.

[hrosa]

User reported same issue on gitter:

https://gitter.im/RestComm/Restcomm-discuss?at=589d5dddf045df0a222be955

[gvagenas]

@hrosa I will try to reproduce locally and check the issue. Also, I can see that you are testing with 8.0.0 version. You have to merge with master and test with the latest

[hrosa]

@gvagenas I did merge with master yesterday for new batch of tests and problem persisted.

[gvagenas]

@hrosa what is the error response RMS will return to Restcomm? I want to try to reproduce in the testsuite