title: Spring WebSocket - messages lost after being sent by controller
body: <p>I have a problem with WebSocket messages not getting sent with Spring WebSocket version 4.1.1.RELEASE. It does not happen to every message, just some are not sent for a reason I do not understand. The content of the messages takes some time to load but I am not sure if that is the reason for the issue since sometimes it works but most of the time it does not.</p>
  
  <p>My web application successfully subscribes to a channel <code>/user/queue/overview/reqinfo/events</code> and then sends four messages to request information. My controller class fires a COUNT() statement on a database via spring-data-jpa and Hibernate and returns the result as a message to the user the request came from. All four messages are handled by the same controller method but only two responses get delivered to the sender. I extracted the relevant information from the Spring logs and attached them here. As you can see the last two messages are not being processed by the <code>SimpleBrokerMessageHandler</code> and are thus not sent to the user. Creating the content of these messages takes more than a minute.</p>
  
  <pre><code>12:50:54,953 DEBUG clientInboundChannel-12 user.UserDestinationMessageHandler:187 - Translated /user/queue/overview/reqinfo/events -&gt; [/queue/overview/reqinfo/events-user8178efnd]
  12:50:54,953 DEBUG clientInboundChannel-12 broker.SimpleBrokerMessageHandler:175 - Processing SUBSCRIBE /queue/overview/reqinfo/events-user8178efnd id=sub-7 session=8178efnd
  [...]
  12:50:54,957 DEBUG clientInboundChannel-2 support.SimpAnnotationMethodMessageHandler:348 - Searching methods to handle SEND /app/overview/reqinfo/events session=8178efnd
  12:50:54,957 DEBUG clientInboundChannel-1 support.SimpAnnotationMethodMessageHandler:348 - Searching methods to handle SEND /app/overview/reqinfo/events session=8178efnd
  12:50:54,957 DEBUG clientInboundChannel-16 support.SimpAnnotationMethodMessageHandler:348 - Searching methods to handle SEND /app/overview/reqinfo/events session=8178efnd
  12:50:54,959 DEBUG clientInboundChannel-10 support.SimpAnnotationMethodMessageHandler:348 - Searching methods to handle SEND /app/overview/reqinfo/events session=8178efnd
  [...]
  12:50:54,959 DEBUG clientInboundChannel-16 support.SimpAnnotationMethodMessageHandler:446 - Invoking de.d.i.g.websocket.OverviewController#requestOverviewEvents[2 args]
  12:50:54,959 DEBUG clientInboundChannel-10 support.SimpAnnotationMethodMessageHandler:446 - Invoking de.d.i.g.websocket.OverviewController#requestOverviewEvents[2 args]
  12:50:54,959 DEBUG clientInboundChannel-2 support.SimpAnnotationMethodMessageHandler:446 - Invoking de.d.i.g.websocket.OverviewController#requestOverviewEvents[2 args]
  12:50:54,959 DEBUG clientInboundChannel-1 support.SimpAnnotationMethodMessageHandler:446 - Invoking de.d.i.g.websocket.OverviewController#requestOverviewEvents[2 args]
  [...]
  12:50:55,006 DEBUG clientInboundChannel-1 websocket.OverviewController:196 - requestOverviewEvents, incoming message: MsgOverviewEventsRequest(timeframe=THIS_WEEK)
  12:50:55,006 DEBUG clientInboundChannel-10 websocket.OverviewController:196 - requestOverviewEvents, incoming message: MsgOverviewEventsRequest(timeframe=LAST_WEEK)
  12:50:55,006 DEBUG clientInboundChannel-2 websocket.OverviewController:196 - requestOverviewEvents, incoming message: MsgOverviewEventsRequest(timeframe=YESTERDAY)
  12:50:55,006 DEBUG clientInboundChannel-16 websocket.OverviewController:196 - requestOverviewEvents, incoming message: MsgOverviewEventsRequest(timeframe=TODAY)
  [...]
  12:50:55,032 DEBUG clientInboundChannel-16 websocket.OverviewController:225 - requestOverviewEvents, outgoing message: MsgOverviewEvents(timeframe=TODAY, count=31, error=false)
  12:50:55,035 DEBUG clientInboundChannel-16 broker.SimpleBrokerMessageHandler:152 - Processing MESSAGE destination=/queue/overview/reqinfo/events-user8178efnd session=null payload={"timeframe":"TODAY","count":31,"error":false}
  12:50:55,035 DEBUG clientInboundChannel-16 broker.SimpleBrokerMessageHandler:196 - Broadcasting to 1 sessions.
  [...]
  12:51:01,018 DEBUG clientInboundChannel-2 websocket.OverviewController:225 - requestOverviewEvents, outgoing message: MsgOverviewEvents(timeframe=YESTERDAY, count=190292, error=false)
  12:51:01,020 DEBUG clientInboundChannel-2 broker.SimpleBrokerMessageHandler:152 - Processing MESSAGE destination=/queue/overview/reqinfo/events-user8178efnd session=null payload={"timeframe":"YESTERDAY","count":190292,"error":false}
  12:51:01,020 DEBUG clientInboundChannel-2 broker.SimpleBrokerMessageHandler:196 - Broadcasting to 1 sessions.
  [...]
  12:51:19,081 DEBUG clientInboundChannel-1 websocket.OverviewController:225 - requestOverviewEvents, outgoing message: MsgOverviewEvents(timeframe=THIS_WEEK, count=845956, error=false)
  12:51:19,088 DEBUG clientInboundChannel-10 websocket.OverviewController:225 - requestOverviewEvents, outgoing message: MsgOverviewEvents(timeframe=LAST_WEEK, count=1421118, error=false)
  </code></pre>
  
  <p>This is a sample case where the problem occurs often. I have other views with other messages and controllers that suffer by the same issue and their messages do not take a minute to build, only some seconds or even less. I am using the <code>SimpleMessageBroker</code> with SockJS support (using SockJS 0.3.4). While trying to fix this issue I added this bean to my WebSocket configuration class to manually set timeouts on the connecton but it did not solve the problem:</p>
  
  <pre><code>@Bean
  public ServletServerContainerFactoryBean createWebSocketContainer() {
      long tenMinutesInMillis = 10 * 60 * 1000;
  
      ServletServerContainerFactoryBean container = new ServletServerContainerFactoryBean();
      container.setAsyncSendTimeout(tenMinutesInMillis);
      container.setMaxSessionIdleTimeout(tenMinutesInMillis);
  
      return container;
  }
  </code></pre>
  
  <p>How can it be that some messages are just dropped while other get sent properly? If you need any more information from the logs or source code please ask.</p>
  
  <p>[UPDATE] Some additional information on the behavior:</p>
  
  <p>The first message that counts the smallest number of items always returns. The second message returns most of the time and the last two fail to be sent about 90% of the time. After they failed to load other views won't load as well, the response messages are just not sent to the web interface even though the subscription is received and processed. After hitting refresh in the browser to reload the page everything works fine until a message gets stuck again.</p>
  
  <p>However, the heartbeat system that runs in the background and uses the WebSocket as well for its messages to the users works all the time. It seems to be completely unaffected by the issue.</p>
  
  <p>[UPDATE 2]</p>
  
  <p>When the issue occurs it seems that the <code>sockJsScheduler</code> is not processing all requests. The INFO message that the <code>WebSocketMessageBrokerStats</code> logs gives the following output:</p>
  
  <pre><code>INFO MessageBrokerSockJS-2 config.WebSocketMessageBrokerStats:113 - WebSocketSession[1 current WS(1)-HttpStream(0)-HttpPoll(0), 1 total, 0 closed abnormally (0 connect failure, 0 send limit, 0 transport error)], stompSubProtocol[processed CONNECT(1)-CONNECTED(1)-DISCONNECT(0)], stompBrokerRelay[null], inboundChannel[pool size = 16, active threads = 0, queued tasks = 0, completed tasks = 120], outboundChannelpool size = 16, active threads = 0, queued tasks = 0, completed tasks = 16], sockJsScheduler[pool size = 8, active threads = 1, queued tasks = 4, completed tasks = 18]
  </code></pre>
  
  <p>It says that there are four queued tasks for the <code>sockJsScheduler</code> that are not being processed, maybe these are the messages that are not sent properly? Unfortunately there is no further information on why they are not processed in the logs.</p>