Why is my stream being closed by peer?

Question

I have the following console program that listens to a destination (a queue or a topic, it doesn't matter) on an ActiveMQ Stomp server, and simply logs the messages it receives to the console:

using System;
using Apache.NMS.Stomp;
using Apache.NMS;
using Apache.NMS.Util;

namespace StompTest
{
    class Program
    {
        static void Main(string[] args)
        {
            try
            {
                var connectionFactory = new ConnectionFactory("stomp:tcp://mybroker:61613");

                var connection = connectionFactory.CreateConnection();
                connection.ExceptionListener += new ExceptionListener(connection_ExceptionListener);
                connection.Start();

                var session = connection.CreateSession(AcknowledgementMode.AutoAcknowledge);

                IDestination dest = SessionUtil.GetDestination(session, "queue://MyQueue");

                var consumer = session.CreateConsumer(dest);
                consumer.Listener += new MessageListener(consumer_Listener);

                Console.ReadKey();
            }
            catch (NMSException ex)
            {
                Console.WriteLine("NMSException !! ==> " + ex.Message);
            }
        }

        static void connection_ExceptionListener(Exception exception)
        {
            Console.WriteLine("Exception!! ==> " + exception.ToString());
        }

        static void consumer_Listener(IMessage message)
        {
            var textMessage = message as ITextMessage;
            if (textMessage == null)
                Console.WriteLine("No ITextMessage...");
            else
                Console.WriteLine("Received => " + textMessage.Text);
        }
    }
}

When I start it, it works fine, as long as I keep sending messages. But when there's 30 seconds of inactivity, I get an exception. This happens even without sending messages to the queue:

Exception!! ==> Apache.NMS.Stomp.IOException: Peer closed the stream.
   at Apache.NMS.Stomp.Protocol.StompFrame.ReadLine(BinaryReader dataIn) in c:\d
ev\NMS.Stomp\src\main\csharp\Protocol\StompFrame.cs:line 284
   at Apache.NMS.Stomp.Protocol.StompFrame.ReadCommandHeader(BinaryReader dataIn
) in c:\dev\NMS.Stomp\src\main\csharp\Protocol\StompFrame.cs:line 208
   at Apache.NMS.Stomp.Protocol.StompFrame.FromStream(BinaryReader dataIn) in c:
\dev\NMS.Stomp\src\main\csharp\Protocol\StompFrame.cs:line 197
   at Apache.NMS.Stomp.Protocol.StompWireFormat.Unmarshal(BinaryReader dataIn) i
n c:\dev\NMS.Stomp\src\main\csharp\Protocol\StompWireFormat.cs:line 121
   at Apache.NMS.Stomp.Transport.Tcp.TcpTransport.ReadLoop() in c:\dev\NMS.Stomp
\src\main\csharp\Transport\Tcp\TcpTransport.cs:line 279

From googling around, and reading the Apache.NMS source code, I figured out it had to do something with the ´InactivityMonitor´, and apparently, when I specify the parameter transport.useInactivityMonitor=false on the connection string, I don't get the exception, and everything runs fine.

But as far as I think I understand everything, that inactivityMonitor has a purpose: making sure that "dead" connections are detected and properly cleaned up.

So there must be something else wrong! I added a simple console tracer to the above code, and this is the output when connecting without the transport.useInactivityMonitor=false parameter:

Info: Connecting to: tcp://mybroker:61613/
Debug: Opening socket to: mybroker on port: 61613
Debug: Connected to mybroker:61613 using InterNetwork protocol.
Debug: Creating Inactivity Monitor: 1
Debug: StompWireFormat - Marshaling: ConnectionInfo[ConnectionId=ID:mypc-309
6-634896376801461632-0:0, Host=mybroker, MaxInactivityDuration=30000, ReadChec
kInterval=30000, WriteCheckInterval=10000, MaxInactivityDurationInitialDelay=0,
ClientId=ID:mypc-3096-634896376801461632-1:0, Password=, UserName=]
Debug: StompWireFormat - Writing StompFrame[ Command=CONNECT, Properties={ heart
-beat=10000,30000 client-id=ID:mypc-3096-634896376801461632-1:0 accept-versi
on=1.0,1.1 host=mybroker}, Content=]
Debug: StompWireFormat - Received StompFrame[ Command=CONNECTED, Properties={ ve
rsion=1.1 server=ActiveMQ/5.6.0 session=ID:mypc-3096-634896376801461632-1:0
heart-beat=0,0}, Content=System.Byte[]]
Debug: InactivityMonitor[1]: Read Check time interval: 30000
Debug: InactivityMonitor[1]: Initial Delay time interval: 10000
Debug: InactivityMonitor[1]: Write Check time interval: 10000
Debug: InactivityMonitor[1]: Starting the Monitor Timer.
Debug: StompWireFormat - Received StompFrame[ Command=KEEPALIVE, Properties={},
Content=]
Debug: InactivityMonitor[1]: New Keep Alive Received at -> 18:28:00.419
Debug: StompWireFormat - Marshaling: ConsumerInfo[ConsumerId=ID:mypc-3096-63
4896376801461632-0:0:1:1, Destination=queue://MyQueue, Ack Mode=AutoAcknowledge,
 PrefetchSize=1000, MaximumPendingMessageLimit=0, DispatchAsync=True, Selector=,
 SubscriptionName=, NoLocal=False, Exclusive=False, Retroactive=False, Priority=
0, Transformation]
Debug: StompWireFormat - Writing StompFrame[ Command=SUBSCRIBE, Properties={ id=
ID:mypc-3096-634896376801461632-0:0:1:1 receipt=2 activemq.dispatchAsync=Tru
e activemq.maximumPendingMessageLimit=0 activemq.priority=0 ack=client activemq.
prefetchSize=1000 transformation=jms-xml destination=/queue/MyQueue}, Content=]
Debug: StompWireFormat - Received StompFrame[ Command=RECEIPT, Properties={ rece
ipt-id=2}, Content=System.Byte[]]
Debug: StompWireFormat - Received StompFrame[ Command=KEEPALIVE, Properties={},
Content=]
Debug: InactivityMonitor[1]: New Keep Alive Received at -> 18:28:00.508
Debug: CheckConnection: Timer Elapsed at 27/11/2012 18:28:10
Debug: InactivityMonitor[1]: Message sent since last write check. Resetting flag
.
Debug: InactivityMonitor[1]: A receive is in progress or already failed.
Debug: CheckConnection: Timer Elapsed at 27/11/2012 18:28:20
Debug: InactivityMonitor[1]: No Message sent since last write check. Sending a K
eepAliveInfo.
Debug: InactivityMonitor[1]: A read check is not currently allowed.
Debug: InactivityMonitor[1] perparing for another Write Check
Debug: InactivityMonitor[1] Write Check required sending KeepAlive.
Debug: StompWireFormat - Marshaling: KeepAliveInfo[ commandId = 0, responseRequi
red = False,  ]
Debug: StompWireFormat - Writing StompFrame[ Command=KEEPALIVE, Properties={}, C
ontent=]
Debug: CheckConnection: Timer Elapsed at 27/11/2012 18:28:30
Debug: InactivityMonitor[1]: No Message sent since last write check. Sending a K
eepAliveInfo.
Debug: InactivityMonitor[1]: A read check is not currently allowed.
Debug: InactivityMonitor[1] perparing for another Write Check
Debug: InactivityMonitor[1] Write Check required sending KeepAlive.
Debug: StompWireFormat - Marshaling: KeepAliveInfo[ commandId = 0, responseRequi
red = False,  ]
Debug: StompWireFormat - Writing StompFrame[ Command=KEEPALIVE, Properties={}, C
ontent=]
Debug: Exception received in the Inactivity Monitor: Apache.NMS.Stomp.IOExceptio
n: Peer closed the stream.
   at Apache.NMS.Stomp.Protocol.StompFrame.ReadLine(BinaryReader dataIn) in c:\d
ev\NMS.Stomp\src\main\csharp\Protocol\StompFrame.cs:line 284
   at Apache.NMS.Stomp.Protocol.StompFrame.ReadCommandHeader(BinaryReader dataIn
) in c:\dev\NMS.Stomp\src\main\csharp\Protocol\StompFrame.cs:line 208
   at Apache.NMS.Stomp.Protocol.StompFrame.FromStream(BinaryReader dataIn) in c:
\dev\NMS.Stomp\src\main\csharp\Protocol\StompFrame.cs:line 197
   at Apache.NMS.Stomp.Protocol.StompWireFormat.Unmarshal(BinaryReader dataIn) i
n c:\dev\NMS.Stomp\src\main\csharp\Protocol\StompWireFormat.cs:line 121
   at Apache.NMS.Stomp.Transport.Tcp.TcpTransport.ReadLoop() in c:\dev\NMS.Stomp
\src\main\csharp\Transport\Tcp\TcpTransport.cs:line 279
Exception!! ==> Apache.NMS.Stomp.IOException: Peer closed the stream.
   at Apache.NMS.Stomp.Protocol.StompFrame.ReadLine(BinaryReader dataIn) in c:\d
ev\NMS.Stomp\src\main\csharp\Protocol\StompFrame.cs:line 284
   at Apache.NMS.Stomp.Protocol.StompFrame.ReadCommandHeader(BinaryReader dataIn
) in c:\dev\NMS.Stomp\src\main\csharp\Protocol\StompFrame.cs:line 208
   at Apache.NMS.Stomp.Protocol.StompFrame.FromStream(BinaryReader dataIn) in c:
\dev\NMS.Stomp\src\main\csharp\Protocol\StompFrame.cs:line 197
   at Apache.NMS.Stomp.Protocol.StompWireFormat.Unmarshal(BinaryReader dataIn) i
n c:\dev\NMS.Stomp\src\main\csharp\Protocol\StompWireFormat.cs:line 121
   at Apache.NMS.Stomp.Transport.Tcp.TcpTransport.ReadLoop() in c:\dev\NMS.Stomp
\src\main\csharp\Transport\Tcp\TcpTransport.cs:line 279
Debug: TransportFilter disposing of next Transport: MutexTransport
Debug: TransportFilter disposing of next Transport: InactivityMonitor
Debug: TransportFilter disposing of next Transport: TcpTransport
Info: Closing The Session with Id ID:mypc-3096-634896376801461632-0:0:1
Debug: Closing down the Consumer
Error: Error during session close: Apache.NMS.Stomp.IOException: Channel was ina
ctive for too long: tcp://mybroker:61613/
   at Apache.NMS.Stomp.Connection.Oneway(Command command) in c:\dev\NMS.Stomp\sr
c\main\csharp\Connection.cs:line 539
   at Apache.NMS.Stomp.MessageConsumer.DoClose() in c:\dev\NMS.Stomp\src\main\cs
harp\MessageConsumer.cs:line 252
   at Apache.NMS.Stomp.Session.DoClose() in c:\dev\NMS.Stomp\src\main\csharp\Ses
sion.cs:line 307
Info: Closed The Session with Id ID:mypc-3096-634896376801461632-0:0:1

So I think my client is being "kicked" by the broker, for being inactive for too long. But I don't really understand why, as from the above log, my client is actually sending "keepalive" messages, as it should. So it shouldn't be inactive.

I'm out of options as how to go ahead with this issue. If anybody has some insight into this, it would be mostly appreciated!

Update:
Version numbers:

library: Apache.NMS.Stomp v1.5.3
broker: Apache ActiveMQ 5.6.0

Should add details on the versions of the library and broker. — Tim Bish, Nov 29 '12 at 11:35
@fretje: Did you find a solution to this? I'm also experiencing this issue, and the connection doesn't recover from it. — PeterBelm, Jan 22 '14 at 11:00
@PeterBelm: I did get it to work yes, but I'm not sure anymore how exactly though. It know I implemented an "exception_listener" handler in which I re-created the connection. I also changed the port of the connectionstring to 61612 (iso 61613). Not sure if it was one of those, or the combination of the two (or something else I tried) that made it work. — fretje, Jan 23 '14 at 15:05

score 5 · Answer 1 · edited May 29 '14 at 21:40

Try using the stomp failover transport. So instead of...

var connectionFactory = new ConnectionFactory("stomp:tcp://mybroker:61613");

use...

var connectionFactory = new ConnectionFactory("failover:tcp://mybroker:61613");

Now instead of the ExceptionListener event being raised and it being up to you to sort out, the transport will automatically reconnect.

FYI: The ConnectionInterruptedListener and ConnectionResumedListener events on the Connection object will be raised should you need to be notified when the disconnect/reconnects occur.

Also:

I'd recommend using Session.CreateDurableConsumer rather than just Session.CreateConsumer. This way you won't lose any messages during the disconnect/reconnect period.

Hope this helps someone.

Why is my stream being closed by peer?

1 Answers1