Update docs on working with STOMP subscriptions [SPR-16950]

[spring-projects-issues]

Marcus Held opened SPR-16950 and commented

While performance testing my application I figured out that I can only handle a handful of users when using Spring Websocket with RabbitMQ as a message broker. As soon as I replace the the message broker with the simple message broker I don't have anymore issues.

I was able to reproduce the behavior in a sample project, which you can find on github: https://github.com/mld-ger/spring-websocket-performance-issue/tree/master. In the repository is a second branch  called simple-broker where the issue does not occur ( see the diff here ). All instructions how to setup the project should be in the readme of the linked project.

Also, this issue is connected to this stackoverflow question which I opened last week: https://stackoverflow.com/questions/50833472/performance-issue-with-spring-websocket-rabbitmq-and-stomp/

---

Affects: 5.0.7

Attachments:

• flight_recording_websocket_bug.jfr (5.18 MB)
• recoring_with_broadcast.jfr (4.68 MB)
• response_times_with_broadcast.png (30.62 kB)
• Screen Shot 2018-06-25 at 10.33.39.png (41.19 kB)
• Screen Shot 2018-06-25 at 10.33.47.png (37.50 kB)
• threads_with_broadcast.png (33.77 kB)

Referenced from: commits 9b3d80c, 2fdb8c9

0 votes, 5 watchers

[spring-projects-issues]

Rossen Stoyanchev commented

Could you add a test or any Java code that shows the basic scenario under test? I have not used JMeter recently and that's getting in the way at the moment. I will spend some more time tomorrow.

On a first look I am wondering if you really mean for "/user" to be routed to controllers? That's normally handled transparently by the UserDestinationMessageHandler. 

 

[spring-projects-issues]

Marcus Held commented

I updated the repository and provided a unit test to reproduce the issue. What's interesting is that the single user test only works when it runs first or in isolation. As soon as the test with multiple user run you don't receive anymore messages.

When I remove the "/user" destination the method annotated with @SubscribeMapping is not invoked.

[spring-projects-issues]

Rossen Stoyanchev commented

Thanks, that helps!

This is a problem with the example actually. It fails even with 1 user. At the time when the test message is sent the subscription has not yet been seen by the broker. Using the simple broker masks the issue to a degree because the broker is in memory and there is no external hop to reach the broker and the timing is different.

In the logs I see the SEND and SUBSCRIBE intermixed because the await condition is based on a false premise:

2018-06-19 13:29:52.944 DEBUG 14940 --- [nboundChannel-7] o.s.m.s.s.StompBrokerRelayMessageHandler : Forwarding SEND /exchange/amq.direct/update-user1 session=_system_ text/plain;charset=UTF-8 payload=foo
2018-06-19 13:29:52.945 DEBUG 14940 --- [nboundChannel-5] o.s.m.s.s.StompBrokerRelayMessageHandler : Forwarding SUBSCRIBE /exchange/amq.direct/update-user1 id=0 session=1
2018-06-19 13:29:52.945 TRACE 14940 --- [nboundChannel-7] o.s.messaging.simp.stomp.StompEncoder    : Encoding STOMP SEND, headers={simpOrigDestination=[/user/exchange/amq.direct/update], destination=[/exchange/amq.direct/update-user1], content-type=[text/plain;charset=UTF-8]}
2018-06-19 13:29:52.945 TRACE 14940 --- [nboundChannel-5] o.s.messaging.simp.stomp.StompEncoder    : Encoding STOMP SUBSCRIBE, headers={destination=[/exchange/amq.direct/update-user1], id=[0], simpOrigDestination=[/user/exchange/amq.direct/update]} 

The controller detecting and responding to a "/user/" SUBSCRIBE frame is orthogonal to, and does not indicate when the subscription has been processed by the broker. The right way to do this is to get a receipt from the broker for the SUBSCRIBE.

@Autowired
private TaskScheduler messageBrokerTaskScheduler;

...

stompClient.setTaskScheduler(this.messageBrokerTaskScheduler);
...
StompHeaders stompHeaders = new StompHeaders();
stompHeaders.setDestination("/user/exchange/amq.direct/update");
stompHeaders.setReceipt("r1");
FrameHandler frameHandler = new FrameHandler();
StompSession.Subscription subscription = stompSession.subscribe(stompHeaders, frameHandler);

CountDownLatch latch = new CountDownLatch(1);
subscription.addReceiptTask(latch::countDown);
latch.await(5, TimeUnit.SECONDS);

//Send test request
stompSession.send("/app/test", null);

Also in the configuration, remove the mapping of "/user" as an application destination. Such destinations are stripped of the "/user" prefix and turned into broker destinations (in this case "/exchange" prefixed), and there is usually no good reason for a controller to process broker destinations.

If you want to get something from a controller in request-reply style, just do SUBSCRIBE to "/app/foo" and respond with Foo data from the @SubscribeMapping method. Again, though, that's completely orthogonal to broker-managed, user destinations.

 

[spring-projects-issues]

Marcus Held commented

Indeed this fixes the problem I have (y) Thank you very much for your analysis.

I actually got confused by the documentation that says:
This is useful for implementing one-off, request-reply message exchanges
But also in this paragraph it is clearly stated that the message will not be sent through the message broker. So a small notice how to implement this pattern would have been very useful for me and therefore highly appreciated :)

[spring-projects-issues]

Marcus Held commented

Unfortunately I need to retract my previous comment. After I applied the fix you described to our application I noticed that we still can not handle as much users as I would expect. So I tried reproducing it with the example app (I updated the linked repository with your fix) and I noticed that at around 2k users every websocket action is "dead" which means I don't get any answer at all. Doesn't matter if I try to connect, subscribe or send a message. This error also persists when I stop the test and try it with a single client. Only a restart of the application (not the rabbitmq) can vanish the error.

I attached a flight recording that I did for you to help finding the Problem. What's interesting is that the CPU goes up to 20% when the error occurs and stays there forever.

Also I tried to update the unit test to reproduce the issue but with my local machine I can not run the test due to resource limits, but maybe the updated unit test is helpful for you (w/o knowing if its actually reproducible with it). I reproduced it by running the JMeter test in the repository.

Also I think that the application is stuck in ChannelOperationsHandler.drain(), but I have a hard time confirming that.

!Screen Shot 2018-06-25 at 10.33.39.png|thumbnail! !Screen Shot 2018-06-25 at 10.33.47.png|thumbnail! [^flight_recording_websocket_bug.jfr]

[spring-projects-issues]

Rossen Stoyanchev commented

Is everything running on a single machine for these tests? There are multiple hops here and doing all on one machine skews the results significantly. 

[spring-projects-issues]

Rossen Stoyanchev commented

By the way I do plan to update the documentation, just haven't gotten around to it, which is why the ticket is still open.

[spring-projects-issues]

Marcus Held commented

That's also the problem I have reproducing it locally. Therefore the tests where running on a Jmeter cluster and the application was on its own machine with no other processes.

And thank you very much for giving the hint in the documentation :)

[spring-projects-issues]

Rossen Stoyanchev commented

the application was on its own machine with no other processes

1. Does the server application and RabbitMQ run on the same server or separate?

2. Can you try commenting out the following two lines from your configuration?

3. The attached images (3K threads) don't match the jfr file which shows only 60-80 threads, and is for a different time of the day, 10:48 vs 15:50. Can you attach a jfr file that reflects the high thread count?

[spring-projects-issues]

Marcus Held commented

1. The rabbitmq runs on a seperate machine.
2. I tried it and the performance looks very good without them, so you're assumption seems to be right that these two lines cause the problem. I tested it also with 3k JMeter threads.
3. Actually the 3k threads is the amount of the threads that JMeter spawned. I did another test and I attached the recording together with the matching images of the JMeter metrics.

edit: After I removed the two mentioned lines in my real application I still observe the same symptom. Could you provide some background information so I can get a clue what the issue is and maybe find a reproduction in a sample application?

[spring-projects-issues]

Rossen Stoyanchev commented

Sorry for taking so long. When the userRegistryBroadcast is set, by default a message is broadcast to the broker periodically with the content of the local user registry which allows other connected application servers to receive updates and know what users are connected to other servers (and possibly forward user messages to them). I did not verify how many users the sample generates under load, but it's probably a fairly large user registry and by default that's broadcast every 10 seconds. That's probably a little too frequent for a server under load.

The UserRegistryMessageHandler has a property to change to change the frequency, but I don't see it conveniently exposed in the Java config. We can change that as part of this. I also wonder if the feature is relevant to you?

[spring-projects-issues]

Marcus Held commented

Thanks for your answer Rossen Stoyanchev.

 

Actually I don't need that feature at the moment, because we can model our logic differently. But you might have overseen by edit in the previous post:

After I removed the two mentioned lines in my real application I still observe the same symptoms. I'll try to reproduce it in a sample app, but it would be helpful if you have already a idea what else could cause that symptoms.

[spring-projects-issues]

Marcus Held commented

Sry for the late answer.

I did discover the problem on our side now and it was a long running rest request we did in the cliendInboundChannel. So there seems to be no more issue on this front (beside the mentioned problem with the user registry and broadcast endpoints)

[spring-projects-issues]

Rossen Stoyanchev commented

Was that request made from a controller? @MessageMapping methods supports CompletableFuture as return values. 

[spring-projects-issues]

Marcus Held commented

Yes, it was made from a controller. But I also had to broadcast this request to another queue, so using CompletableFuture is not sufficient, but thank you very much for the hint.