Tomcat/BlazeDS/ActiveMQ disconnect problem

Question

We are experiencing disconnects on our Tomcat/BlazeDS/ActiveMQ stack. Although our BlazeDS StreamingAMFChannel is configured with the default idle-timeout-minutes of 0, it seems to timeout after about 30 minutes of idle time (see log). The client does not do any requests during that time and we are also not pushing messages from the ActiveMQ topic.

We have enabled debug logging on activeMQ and BlazeDS and see that BlazeDS is removing the consumer. Unfortunately there is no log message prior to the disconnect message so we can't really trace when this is called within BlazeDS.

Has anyone else experienced this or can anyone provide a solution?

* ActiveMQ log *

11 Mar 2009 16:25:47,405 [ActiveMQ Transport: tcp:///127.0.0.1:49971] DEBUG activemq.broker.region.AbstractRegion  - Removing consumer: ID:TMSNEC02.traficon.int-52586-1236783284912-2:3:1:1
11 Mar 2009 16:25:47,406 [ActiveMQ Transport: tcp:///127.0.0.1:49971] DEBUG activemq.broker.region.AbstractRegion  - Removing consumer: ID:TMSNEC02.traficon.int-52586-1236783284912-2:3:-1:1
11 Mar 2009 16:25:47,407 [ContainerBackgroundProcessor[StandardEngine[Catalina]]] DEBUG activemq.transport.tcp.TcpTransport  - Stopping transport tcp://localhost/127.0.0.1:61616
11 Mar 2009 16:25:47,408 [ActiveMQ Transport Stopper: /127.0.0.1:49971] DEBUG apache.activemq.broker.TransportConnection  - Stopping connection: /127.0.0.1:49971
11 Mar 2009 16:25:47,409 [ActiveMQ Transport Stopper: /127.0.0.1:49971] DEBUG activemq.transport.tcp.TcpTransport  - Stopping transport tcp:///127.0.0.1:49971
11 Mar 2009 16:25:47,413 [ActiveMQ Transport Stopper: /127.0.0.1:49971] DEBUG apache.activemq.broker.TransportConnection  - Stopped connection: /127.0.0.1:49971
11 Mar 2009 16:25:47,417 [ActiveMQ Transport Stopper: /127.0.0.1:49971] DEBUG apache.activemq.broker.TransportConnection  - Connection Stopped: /127.0.0.1:49971
11 Mar 2009 16:25:47,427 [ActiveMQ Transport: tcp:///127.0.0.1:50680] DEBUG activemq.broker.region.AbstractRegion  - Removing consumer: ID:TMSNEC02.traficon.int-52586-1236783284912-2:4:1:1
11 Mar 2009 16:25:47,430 [ActiveMQ Transport: tcp:///127.0.0.1:50680] DEBUG activemq.broker.region.AbstractRegion  - Removing consumer: ID:TMSNEC02.traficon.int-52586-1236783284912-2:4:-1:1
11 Mar 2009 16:25:47,431 [ContainerBackgroundProcessor[StandardEngine[Catalina]]] DEBUG activemq.transport.tcp.TcpTransport  - Stopping transport tcp://localhost/127.0.0.1:61616
11 Mar 2009 16:25:47,431 [ActiveMQ Transport Stopper: /127.0.0.1:50680] DEBUG apache.activemq.broker.TransportConnection  - Stopping connection: /127.0.0.1:50680
11 Mar 2009 16:25:47,431 [ActiveMQ Transport Stopper: /127.0.0.1:50680] DEBUG activemq.transport.tcp.TcpTransport  - Stopping transport tcp:///127.0.0.1:50680
11 Mar 2009 16:25:47,435 [ActiveMQ Transport Stopper: /127.0.0.1:50680] DEBUG apache.activemq.broker.TransportConnection  - Stopped connection: /127.0.0.1:50680
11 Mar 2009 16:25:47,438 [ActiveMQ Transport Stopper: /127.0.0.1:50680] DEBUG apache.activemq.broker.TransportConnection  - Connection Stopped: /127.0.0.1:50680
11 Mar 2009 16:25:47,439 [ActiveMQ Transport: tcp:///127.0.0.1:50681] DEBUG activemq.broker.region.AbstractRegion  - Removing consumer: ID:TMSNEC02.traficon.int-52586-1236783284912-2:5:1:1
11 Mar 2009 16:25:47,439 [ActiveMQ Transport: tcp:///127.0.0.1:50681] DEBUG activemq.broker.region.AbstractRegion  - Removing consumer: ID:TMSNEC02.traficon.int-52586-1236783284912-2:5:-1:1
11 Mar 2009 16:25:47,440 [ContainerBackgroundProcessor[StandardEngine[Catalina]]] DEBUG activemq.transport.tcp.TcpTransport  - Stopping transport tcp://localhost/127.0.0.1:61616
11 Mar 2009 16:25:47,440 [ActiveMQ Transport Stopper: /127.0.0.1:50681] DEBUG apache.activemq.broker.TransportConnection  - Stopping connection: /127.0.0.1:50681
11 Mar 2009 16:25:47,441 [ActiveMQ Transport Stopper: /127.0.0.1:50681] DEBUG activemq.transport.tcp.TcpTransport  - Stopping transport tcp:///127.0.0.1:50681
11 Mar 2009 16:25:47,441 [ActiveMQ Transport Stopper: /127.0.0.1:50681] DEBUG apache.activemq.broker.TransportConnection  - Stopped connection: /127.0.0.1:50681
11 Mar 2009 16:25:47,441 [ActiveMQ Transport Stopper: /127.0.0.1:50681] DEBUG apache.activemq.broker.TransportConnection  - Connection Stopped: /127.0.0.1:50681

* BlazeDS log *

[BlazeDS]03/11/2009 15:55:39.776 [DEBUG] [Endpoint.AMF] Serializing AMF/HTTP response
Version: 3
  (Message #0 targetURI=/4/onResult, responseURI=)
    (Externalizable Object #0 'DSK')
      (Externalizable Object #1 'flex.messaging.io.ArrayCollection')
        (Array #2)
1.236783339776E12
(Byte Array #3, Length 16)
(Byte Array #4, Length 16)
(Byte Array #5, Length 16)

[BlazeDS]03/11/2009 16:25:47.391 [INFO] [Service.Message.JMS] JMS consumer for JMS destination 'java:comp/env/eventMessagesFlexTopic' is being removed from the JMS adapter
[BlazeDS]03/11/2009 16:25:47.392 [INFO] [Service.Message.JMS] JMS consumer for JMS destination 'java:comp/env/eventMessagesFlexTopic' is stopping.
[BlazeDS]03/11/2009 16:25:47.417 [DEBUG] [Client.MessageClient] MessageClient with clientId '7A98D7BC-F0B3-922C-A968-BE0BFB7D9080' for destination 'eventMessageFeed' has been invalidated.
[BlazeDS]03/11/2009 16:25:47.419 [INFO] [Service.Message.JMS] JMS consumer for JMS destination 'java:comp/env/detectorsFlexTopic' is being removed from the JMS adapter
[BlazeDS]03/11/2009 16:25:47.423 [INFO] [Service.Message.JMS] JMS consumer for JMS destination 'java:comp/env/detectorsFlexTopic' is stopping.
[BlazeDS]03/11/2009 16:25:47.435 [DEBUG] [Client.MessageClient] MessageClient with clientId '7A9BC826-2199-C772-0A1B-FE6FAE9F7402' for destination 'detectorsFeed' has been invalidated.
[BlazeDS]03/11/2009 16:25:47.438 [INFO] [Service.Message.JMS] JMS consumer for JMS destination 'java:comp/env/scenariosFlexTopic' is being removed from the JMS adapter
[BlazeDS]03/11/2009 16:25:47.438 [INFO] [Service.Message.JMS] JMS consumer for JMS destination 'java:comp/env/scenariosFlexTopic' is stopping.
[BlazeDS]03/11/2009 16:25:47.440 [DEBUG] [Client.MessageClient] MessageClient with clientId '7A9BCE40-A0DA-18D6-9FA1-6D6AA2088256' for destination 'scenarioMessageFeed' has been invalidated.
[BlazeDS]03/11/2009 16:25:47.441 [DEBUG] [Client.FlexClient] FlexClient with id '7A95FDE9-0091-B1CD-3660-D8E9CD6CD3E6' has been invalidated.
[BlazeDS]03/11/2009 16:25:47.441 [DEBUG] [Endpoint.StreamingAMF] Endpoint with id 'my-streaming-amf' is streaming message: Flex Message (flex.messaging.messages.CommandMessage)
operation = disconnect
clientId = null
correlationId = null
destination = null
messageId = 7ED1C45A-10A7-BFBB-E24E-94B9C03047EE
timestamp = 1236785147441
timeToLive = 0
body = null
[BlazeDS]03/11/2009 16:25:47.441 [DEBUG] [Endpoint.FlexSession] FlexSession with id '71A76CA22AC435285736F6DB0E38AC11' for an Http-based client connection has been invalidated.
[BlazeDS]03/11/2009 16:25:47.444 [DEBUG] [Client.FlexClient] FlexClient with id '7A941468-80E5-8343-A2AE-A3AFFA135734' has been invalidated.
[BlazeDS]03/11/2009 16:25:47.444 [DEBUG] [Endpoint.FlexSession] FlexSession with id '1238AA40EF8B016F3942C6D6BDBA29B9' for an Http-based client connection has been invalidated.
[BlazeDS]03/11/2009 16:25:47.444 [DEBUG] [Endpoint.StreamingAMF] Streaming thread 'http-8080-1' for endpoint with id 'my-streaming-amf' is releasing connection and returning to the request handler pool.
[BlazeDS]03/11/2009 16:25:47.444 [INFO] [Endpoint.FlexSession] Number of streaming clients for FlexSession with id '71A76CA22AC435285736F6DB0E38AC11' is 0.
[BlazeDS]03/11/2009 16:25:47.444 [DEBUG] [Endpoint.StreamingAMF] Number of streaming clients for endpoint with id 'my-streaming-amf' is 0.
[BlazeDS]03/11/2009 16:25:47.489 [DEBUG] [Endpoint.FlexSession] FlexSession created with id 'E5BCC7617F3937139CCAD377EEB85D45' for an Http-based client connection.
[BlazeDS]03/11/2009 16:25:47.489 [INFO] [Endpoint.General] Channel endpoint my-streaming-amf received request.

Answer 1

You can respond to a disconnect event and reconnect if you need to.

Answer 2

We solved this by sending a keep-alive message from the client to the server every 30 seconds. Apparently it was the FlexSession that was timing out since this follows Tomcat's default session timeout. Since the keep-alive message is sent at a low interval, we also set the session timeout to a low value on the server which results in improved memory consumptiom on the server.