cannot send two messages to client in quick succession

[timobaumann]

I'll take this here from e-mail:

there's now a test-case in my scratch repo git@bitbucket.org:timobaumann/mufswingscratch.git Please have a look at and run test/jav/edu.cmu.lti.articulab.movies.muf.TwoConsecutivePosts What should happen:

• muf startup, client connection, client sends first message (it's a separate bug that the client has to send the first message, imho), server sends two messages, client should receive two messages, ideally in order (that's a separate bug)

What happens instead:

• client receives only first message. See protocol below.

As this is a synchronization bug, please make sure that tests work many times in a row. The fact that a test works once does not tell us anything.

2017-12-05 09:28:33,154 INFO    Broker                         - creating broker: 5555
2017-12-05 09:28:33,189 INFO    SessionManager                 - Starting Multiuser framework...
2017-12-05 09:28:33,261 INFO    SessionManager                 - Creating session: myID
2017-12-05 09:28:33,267 INFO    SessionImpl                    - A new session has been created with id: myID
2017-12-05 09:28:33,269 INFO    SessionImpl                    - Initializing session: myID.
2017-12-05 09:28:33,282 INFO    TestOrchestrator               - myID   Creating Process Orchestrator for session: myID
2017-12-05 09:28:33,283 INFO    TestOrchestrator               - myID   Initializing ServiceManager for session: myID
client received: {"requestType":"SESSION_INITIATED","sessionId":"","url":"","payload":"tcp://127.0.0.1:5555"}
2017-12-05 09:28:33,305 INFO    TestComponent                  - myID   Starting up component: TestComponent on session: myID
2017-12-05 09:28:33,306 INFO    TestOrchestrator               - myID   Starting Process Orchestrator for session: myID
2017-12-05 09:28:33,307 INFO    TestOrchestrator               - myID   ServiceManager has initialized all the statefull components for session: myID
orchestrator received: {"requestType":"","sessionId":"","url":"","payload":"connect","messageId":"MSG_START_DM"}
posted helo1
seeing [status: ELEMENT_ADDED, id: MSG_TEST, element: helo1]
posted helo2
sending on [status: ELEMENT_ADDED, id: MSG_TEST, element: helo1]
seeing [status: ELEMENT_ADDED, id: MSG_TEST, element: helo2]
sending on [status: ELEMENT_ADDED, id: MSG_TEST, element: helo2]
client received: {"requestType":"","sessionId":"","url":"","payload":"\"helo1\"","messageId":"MSG_TEST"}
[{"requestType":"SESSION_INITIATED","sessionId":"","url":"","payload":"tcp://127.0.0.1:5555"}, {"requestType":"","sessionId":"","url":"","payload":"\"helo1\"","messageId":"MSG_TEST"}]

java.lang.AssertionError
    at org.junit.Assert.fail(Assert.java:86)
    at org.junit.Assert.assertTrue(Assert.java:41)
    at org.junit.Assert.assertTrue(Assert.java:52)
    at edu.cmu.lti.articulab.movies.muf.TwoConsecutivePosts.twoConsecutivePosts(TwoConsecutivePosts.java:88)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
    at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:298)
    at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:292)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.lang.Thread.run(Thread.java:748)

2017-12-05 09:28:39,333 INFO    SessionManager                 - Start closing all external services (slave MUF's)...
2017-12-05 09:28:39,337 INFO    SessionManager                 - Start closing all sessions...
2017-12-05 09:28:39,339 INFO    SessionImpl                    - Closing session: myID

[ojrlopez27]

I have made the following changes on repo git@bitbucket.org:timobaumann/mufswingscratch.git:

1. I replaced delays (Utils.sleep) by a proper synchronization condition (using awaitility IPA). Though it doesn't seem to be an evident issue, it is a potential cause of not getting the expected results, especially when you are asserting the number of received messages (which arrive asynchronously).
2. Now you can send multiple messages in a row. I have changes the scenario, so you can modify the number of messages sent (I tested with 2, 10, 100 more than 50 times in a row and it is working).
3. I moved sendToBB invocation inside the orchestrator itself. It doesn't make sense to invoke this method from the unit test nor the MUF is intended to work like this. The orchestrator will trigger actions once it receives a message from the client.
4. If you send multiple messages from the orchestrator, they will arrive in reverse order to the client (e.g., hello3 -> hello2 -> hello1). The reason for that is that the MUF uses a LIFO strategy (using a queue), so you will always get the most recent message. If you send so quickly messages from the orchestrator, then the queue will store the messages and then will post one by one starting from the last inserted. If you care about the order of this messages, then you have to implement a proper communication mechanism, that is, client sends start -> orchestrator sends the first message hello1 -> client receives hello1 and sends a confirmation to orchestrator -> once orchestrator receives the confirmation then it sends the second message hello2, and so on. I added a second scenario that demonstrate how to do that (TestOrchestrator2 and TwoConsecutivePosts2)