NMS ActiveMQ provider infinite loop on disposal?

classic Classic list List threaded Threaded
3 messages Options
Reply | Threaded
Open this post in threaded view
|

NMS ActiveMQ provider infinite loop on disposal?

magellings
I have a windows service using the Apache NMS ActiveMQ 1.4.1 provider and when trying to stop the service it appears to have gotten in an infinite loop.  When the service stops, the session and connection are disposed.  Any ideas why the EndianBinaryReader would be doing this?

2010-11-23 14:33:53,987 [218192] [ERROR] Apache.NMS.Tracer - RECEIVED Exception: System.IO.EndOfStreamException: Unable to read beyond the end of the stream.
   at System.IO.BinaryReader.FillBuffer(Int32 numBytes)
   at System.IO.BinaryReader.ReadInt32()
   at Apache.NMS.Util.EndianBinaryReader.ReadInt32() in c:\dev\NMS.1.4.x\src\main\csharp\Util\EndianBinaryReader.cs:line 135
   at Apache.NMS.ActiveMQ.OpenWire.OpenWireFormat.Unmarshal(BinaryReader dis) in c:\dev\NMS.ActiveMQ.1.4.x\src\main\csharp\OpenWire\OpenWireFormat.cs:line 246
   at Apache.NMS.ActiveMQ.Transport.Tcp.TcpTransport.ReadLoop() in c:\dev\NMS.ActiveMQ.1.4.x\src\main\csharp\Transport\Tcp\TcpTransport.cs:line 278
2010-11-23 14:33:53,987 [35936] [INFO ] Apache.NMS.Tracer - RECEIVED: Response[ commandId = 0, responseRequired = False, CorrelationId = 1 ]
2010-11-23 14:33:53,987 [35936] [DEBUG] Apache.NMS.Tracer - Unknown response ID: 0 for response: Response[ commandId = 0, responseRequired = False, CorrelationId = 1 ]
2010-11-23 14:33:54,972 [tcp://qgmqbeta1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true] [DEBUG] Apache.NMS.Tracer - Connect fail to: tcp://qgmqbeta1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true, reason: Error connecting to qgmqbeta1:10200.
2010-11-23 14:33:54,972 [311324] [DEBUG] Apache.NMS.Tracer - Send Oneway attempt: 3080 failed: Message = The given key was not present in the dictionary.
2010-11-23 14:33:54,972 [311324] [DEBUG] Apache.NMS.Tracer - Failed Message Was: ProducerInfo[ commandId = 465, responseRequired = False, ProducerId = ID:SXALPHA3-53063-634261156397986117-1:0:1:3, Destination = queue://nms.keepAlive, BrokerPath = , DispatchAsync = False, WindowSize = 0 ]
2010-11-23 14:33:54,972 [311324] [WARN ] Apache.NMS.Tracer - Transport failed to tcp://qgmqdev1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true, attempting to automatically reconnect due to: The given key was not present in the dictionary.
2010-11-23 14:33:54,972 [311324] [DEBUG] Apache.NMS.Tracer - Connection: Transport has been Interrupted.
2010-11-23 14:33:54,972 [311324] [DEBUG] Apache.NMS.Tracer - transport interrupted, dispatchers: 0
2010-11-23 14:33:54,972 [311324] [INFO ] Apache.NMS.Tracer - Waiting for transport to reconnect.
2010-11-23 14:33:54,972 [219716] [DEBUG] Apache.NMS.Tracer - Attempting async connect to: tcp://qgmqbeta1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true
2010-11-23 14:33:54,972 [219716] [DEBUG] Apache.NMS.Tracer - Attempting async connect to: tcp://qgmqdev1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true
2010-11-23 14:33:54,972 [tcp://qgmqbeta1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true] [DEBUG] Apache.NMS.Tracer - Opening socket to: qgmqbeta1 on port: 10200
2010-11-23 14:33:54,972 [tcp://qgmqdev1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true] [DEBUG] Apache.NMS.Tracer - Opening socket to: qgmqdev1 on port: 10200
2010-11-23 14:33:54,972 [tcp://qgmqdev1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true] [DEBUG] Apache.NMS.Tracer - Connected to qgmqdev1:10200 using InterNetwork protocol.
2010-11-23 14:33:54,972 [219716] [INFO ] Apache.NMS.Tracer - SENDING: WireFormatInfo[ Magic=ActiveMQ Version=6 MarshalledProperties={CacheEnabled=False, StackTraceEnabled=False, TcpNoDelayEnabled=True, MaxInactivityDuration=30000, TightEncodingEnabled=False, CacheSize=0, SizePrefixDisabled=False, MaxInactivityDurationInitialDelay=10000} ]
2010-11-23 14:33:54,972 [219716] [INFO ] Apache.NMS.Tracer - Restoring previous transport connection.
2010-11-23 14:33:54,972 [187132] [INFO ] Apache.NMS.Tracer - RECEIVED: WireFormatInfo[ Magic=ActiveMQ Version=6 MarshalledProperties={StackTraceEnabled=True, CacheEnabled=True, TcpNoDelayEnabled=True, MaxInactivityDuration=30000, MaxInactivityDurationInitalDelay=10000, TightEncodingEnabled=True, CacheSize=1024, SizePrefixDisabled=False} ]
2010-11-23 14:33:54,972 [219716] [INFO ] Apache.NMS.Tracer - SENDING: ConnectionControl[ commandId = 0, responseRequired = False, Close = False, Exit = False, FaultTolerant = True, Resume = False, Suspend = False, ConnectedBrokers = , ReconnectTo = , RebalanceConnection = False ]
2010-11-23 14:33:54,972 [219716] [INFO ] Apache.NMS.Tracer - SENDING: ConnectionInfo[ commandId = 1, responseRequired = True, ConnectionId = ID:SXALPHA3-53063-634261156397986117-1:0, ClientId = QuadNMSConsumer-t11, Password = destination, UserName = GL$ACTIVEMQ_QUADNMS, BrokerPath = , BrokerMasterConnector = False, Manageable = False, ClientMaster = False, FaultTolerant = True, FailoverReconnect = True ]
2010-11-23 14:33:54,972 [219716] [INFO ] Apache.NMS.Tracer - SENDING: SessionInfo[ commandId = 0, responseRequired = False, SessionId = ID:SXALPHA3-53063-634261156397986117-1:0:-1 ]
2010-11-23 14:33:54,972 [219716] [INFO ] Apache.NMS.Tracer - Sending queued commands...
2010-11-23 14:33:54,972 [219716] [DEBUG] Apache.NMS.Tracer - Transport has resumed normal operation.
2010-11-23 14:33:54,972 [219716] [DEBUG] Apache.NMS.Tracer - Connection established
2010-11-23 14:33:54,972 [219716] [INFO ] Apache.NMS.Tracer - Successfully reconnected to: tcp://qgmqdev1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true
2010-11-23 14:33:54,972 [187132] [INFO ] Apache.NMS.Tracer - RECEIVED: BrokerInfo[ commandId = 0, responseRequired = False, BrokerId = ID:WAMQDEV1-64082-1290541558376-0:0, BrokerURL = tcp://WAMQDEV1:10200, PeerBrokerInfos = Apache.NMS.ActiveMQ.Commands.BrokerInfo[], BrokerName = WAMQDEV1QuadNMS541, SlaveBroker = False, MasterBroker = False, FaultTolerantConfiguration = False, DuplexConnection = False, NetworkConnection = False, ConnectionId = 0, BrokerUploadUrl = , NetworkProperties =  ]
2010-11-23 14:33:54,987 [35936] [ERROR] Apache.NMS.Tracer - RECEIVED Exception: System.IO.EndOfStreamException: Unable to read beyond the end of the stream.
   at System.IO.BinaryReader.FillBuffer(Int32 numBytes)
   at System.IO.BinaryReader.ReadInt32()
   at Apache.NMS.Util.EndianBinaryReader.ReadInt32() in c:\dev\NMS.1.4.x\src\main\csharp\Util\EndianBinaryReader.cs:line 135
   at Apache.NMS.ActiveMQ.OpenWire.OpenWireFormat.Unmarshal(BinaryReader dis) in c:\dev\NMS.ActiveMQ.1.4.x\src\main\csharp\OpenWire\OpenWireFormat.cs:line 246
   at Apache.NMS.ActiveMQ.Transport.Tcp.TcpTransport.ReadLoop() in c:\dev\NMS.ActiveMQ.1.4.x\src\main\csharp\Transport\Tcp\TcpTransport.cs:line 278
2010-11-23 14:33:54,987 [187132] [INFO ] Apache.NMS.Tracer - RECEIVED: Response[ commandId = 0, responseRequired = False, CorrelationId = 1 ]
2010-11-23 14:33:54,987 [187132] [DEBUG] Apache.NMS.Tracer - Unknown response ID: 0 for response: Response[ commandId = 0, responseRequired = False, CorrelationId = 1 ]
2010-11-23 14:33:55,972 [tcp://qgmqbeta1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true] [DEBUG] Apache.NMS.Tracer - Connect fail to: tcp://qgmqbeta1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true, reason: Error connecting to qgmqbeta1:10200.
2010-11-23 14:33:55,972 [311324] [DEBUG] Apache.NMS.Tracer - Send Oneway attempt: 3081 failed: Message = The given key was not present in the dictionary.
2010-11-23 14:33:55,972 [311324] [DEBUG] Apache.NMS.Tracer - Failed Message Was: ProducerInfo[ commandId = 465, responseRequired = False, ProducerId = ID:SXALPHA3-53063-634261156397986117-1:0:1:3, Destination = queue://nms.keepAlive, BrokerPath = , DispatchAsync = False, WindowSize = 0 ]
2010-11-23 14:33:55,972 [311324] [WARN ] Apache.NMS.Tracer - Transport failed to tcp://qgmqdev1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true, attempting to automatically reconnect due to: The given key was not present in the dictionary.
2010-11-23 14:33:55,972 [311324] [DEBUG] Apache.NMS.Tracer - Connection: Transport has been Interrupted.
2010-11-23 14:33:55,972 [311324] [DEBUG] Apache.NMS.Tracer - transport interrupted, dispatchers: 0
2010-11-23 14:33:55,972 [311324] [INFO ] Apache.NMS.Tracer - Waiting for transport to reconnect.
2010-11-23 14:33:55,972 [219716] [DEBUG] Apache.NMS.Tracer - Attempting async connect to: tcp://qgmqbeta1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true
2010-11-23 14:33:55,972 [tcp://qgmqbeta1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true] [DEBUG] Apache.NMS.Tracer - Opening socket to: qgmqbeta1 on port: 10200
2010-11-23 14:33:55,972 [219716] [DEBUG] Apache.NMS.Tracer - Attempting async connect to: tcp://qgmqdev1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true
2010-11-23 14:33:55,972 [tcp://qgmqdev1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true] [DEBUG] Apache.NMS.Tracer - Opening socket to: qgmqdev1 on port: 10200
2010-11-23 14:33:55,972 [tcp://qgmqdev1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true] [DEBUG] Apache.NMS.Tracer - Connected to qgmqdev1:10200 using InterNetwork protocol.
2010-11-23 14:33:55,972 [219716] [INFO ] Apache.NMS.Tracer - SENDING: WireFormatInfo[ Magic=ActiveMQ Version=6 MarshalledProperties={CacheEnabled=False, StackTraceEnabled=False, TcpNoDelayEnabled=True, MaxInactivityDuration=30000, TightEncodingEnabled=False, CacheSize=0, SizePrefixDisabled=False, MaxInactivityDurationInitialDelay=10000} ]
2010-11-23 14:33:55,972 [219716] [INFO ] Apache.NMS.Tracer - Restoring previous transport connection.
2010-11-23 14:33:55,972 [158776] [INFO ] Apache.NMS.Tracer - RECEIVED: WireFormatInfo[ Magic=ActiveMQ Version=6 MarshalledProperties={StackTraceEnabled=True, CacheEnabled=True, TcpNoDelayEnabled=True, MaxInactivityDuration=30000, MaxInactivityDurationInitalDelay=10000, TightEncodingEnabled=True, CacheSize=1024, SizePrefixDisabled=False} ]
2010-11-23 14:33:55,972 [219716] [INFO ] Apache.NMS.Tracer - SENDING: ConnectionControl[ commandId = 0, responseRequired = False, Close = False, Exit = False, FaultTolerant = True, Resume = False, Suspend = False, ConnectedBrokers = , ReconnectTo = , RebalanceConnection = False ]
2010-11-23 14:33:55,972 [219716] [INFO ] Apache.NMS.Tracer - SENDING: ConnectionInfo[ commandId = 1, responseRequired = True, ConnectionId = ID:SXALPHA3-53063-634261156397986117-1:0, ClientId = QuadNMSConsumer-t11, Password = destination, UserName = GL$ACTIVEMQ_QUADNMS, BrokerPath = , BrokerMasterConnector = False, Manageable = False, ClientMaster = False, FaultTolerant = True, FailoverReconnect = True ]
2010-11-23 14:33:55,972 [219716] [INFO ] Apache.NMS.Tracer - SENDING: SessionInfo[ commandId = 0, responseRequired = False, SessionId = ID:SXALPHA3-53063-634261156397986117-1:0:-1 ]
2010-11-23 14:33:55,972 [219716] [INFO ] Apache.NMS.Tracer - Sending queued commands...
2010-11-23 14:33:55,972 [219716] [DEBUG] Apache.NMS.Tracer - Transport has resumed normal operation.
2010-11-23 14:33:55,972 [219716] [DEBUG] Apache.NMS.Tracer - Connection established
2010-11-23 14:33:55,972 [219716] [INFO ] Apache.NMS.Tracer - Successfully reconnected to: tcp://qgmqdev1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true
2010-11-23 14:33:55,972 [158776] [INFO ] Apache.NMS.Tracer - RECEIVED: BrokerInfo[ commandId = 0, responseRequired = False, BrokerId = ID:WAMQDEV1-64082-1290541558376-0:0, BrokerURL = tcp://WAMQDEV1:10200, PeerBrokerInfos = Apache.NMS.ActiveMQ.Commands.BrokerInfo[], BrokerName = WAMQDEV1QuadNMS541, SlaveBroker = False, MasterBroker = False, FaultTolerantConfiguration = False, DuplexConnection = False, NetworkConnection = False, ConnectionId = 0, BrokerUploadUrl = , NetworkProperties =  ]
2010-11-23 14:33:55,987 [187132] [ERROR] Apache.NMS.Tracer - RECEIVED Exception: System.IO.EndOfStreamException: Unable to read beyond the end of the stream.
   at System.IO.BinaryReader.FillBuffer(Int32 numBytes)
   at System.IO.BinaryReader.ReadInt32()
   at Apache.NMS.Util.EndianBinaryReader.ReadInt32() in c:\dev\NMS.1.4.x\src\main\csharp\Util\EndianBinaryReader.cs:line 135
   at Apache.NMS.ActiveMQ.OpenWire.OpenWireFormat.Unmarshal(BinaryReader dis) in c:\dev\NMS.ActiveMQ.1.4.x\src\main\csharp\OpenWire\OpenWireFormat.cs:line 246
   at Apache.NMS.ActiveMQ.Transport.Tcp.TcpTransport.ReadLoop() in c:\dev\NMS.ActiveMQ.1.4.x\src\main\csharp\Transport\Tcp\TcpTransport.cs:line 278
2010-11-23 14:33:55,987 [158776] [INFO ] Apache.NMS.Tracer - RECEIVED: Response[ commandId = 0, responseRequired = False, CorrelationId = 1 ]
2010-11-23 14:33:55,987 [158776] [DEBUG] Apache.NMS.Tracer - Unknown response ID: 0 for response: Response[ commandId = 0, responseRequired = False, CorrelationId = 1 ]
Reply | Threaded
Open this post in threaded view
|

Re: NMS ActiveMQ provider infinite loop on disposal?

jgomes
I haven't seen that particular problem.  I also have some Windows services
that connect to AMQ, but they shut down without hanging.  Can you try
running with the latest trunk version to see if you can reproduce this
problem?  It might also be interesting too see a sample of your connection
URI.  Feel free to modify any sensitive info in your URI string, as long as
all of the options are represented.

It might also be interesting to try to reproduce with a small sample that
connects and then shuts down.  There might be a shutdown ordering bug
somewhere.

On Tue, Nov 23, 2010 at 12:43 PM, magellings <[hidden email]> wrote:

>
> I have a windows service using the Apache NMS ActiveMQ 1.4.1 provider and
> when trying to stop the service it appears to have gotten in an infinite
> loop.  When the service stops, the session and connection are disposed.
>  Any
> ideas why the EndianBinaryReader would be doing this?
>
> 2010-11-23 14:33:53,987 [218192] [ERROR] Apache.NMS.Tracer - RECEIVED
> Exception: System.IO.EndOfStreamException: Unable to read beyond the end of
> the stream.
>   at System.IO.BinaryReader.FillBuffer(Int32 numBytes)
>   at System.IO.BinaryReader.ReadInt32()
>   at Apache.NMS.Util.EndianBinaryReader.ReadInt32() in
> c:\dev\NMS.1.4.x\src\main\csharp\Util\EndianBinaryReader.cs:line 135
>   at Apache.NMS.ActiveMQ.OpenWire.OpenWireFormat.Unmarshal(BinaryReader
> dis) in
> c:\dev\NMS.ActiveMQ.1.4.x\src\main\csharp\OpenWire\OpenWireFormat.cs:line
> 246
>   at Apache.NMS.ActiveMQ.Transport.Tcp.TcpTransport.ReadLoop() in
>
> c:\dev\NMS.ActiveMQ.1.4.x\src\main\csharp\Transport\Tcp\TcpTransport.cs:line
> 278
> 2010-11-23 14:33:53,987 [35936] [INFO ] Apache.NMS.Tracer - RECEIVED:
> Response[ commandId = 0, responseRequired = False, CorrelationId = 1 ]
> 2010-11-23 14:33:53,987 [35936] [DEBUG] Apache.NMS.Tracer - Unknown
> response
> ID: 0 for response: Response[ commandId = 0, responseRequired = False,
> CorrelationId = 1 ]
> 2010-11-23 14:33:54,972
>
> [tcp://qgmqbeta1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true]
> [DEBUG] Apache.NMS.Tracer - Connect fail to:
>
> tcp://qgmqbeta1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true,
> reason: Error connecting to qgmqbeta1:10200.
> 2010-11-23 14:33:54,972 [311324] [DEBUG] Apache.NMS.Tracer - Send Oneway
> attempt: 3080 failed: Message = The given key was not present in the
> dictionary.
> 2010-11-23 14:33:54,972 [311324] [DEBUG] Apache.NMS.Tracer - Failed Message
> Was: ProducerInfo[ commandId = 465, responseRequired = False, ProducerId =
> ID:SXALPHA3-53063-634261156397986117-1:0:1:3, Destination =
> queue://nms.keepAlive, BrokerPath = , DispatchAsync = False, WindowSize = 0
> ]
> 2010-11-23 14:33:54,972 [311324] [WARN ] Apache.NMS.Tracer - Transport
> failed to
>
> tcp://qgmqdev1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true,
> attempting to automatically reconnect due to: The given key was not present
> in the dictionary.
> 2010-11-23 14:33:54,972 [311324] [DEBUG] Apache.NMS.Tracer - Connection:
> Transport has been Interrupted.
> 2010-11-23 14:33:54,972 [311324] [DEBUG] Apache.NMS.Tracer - transport
> interrupted, dispatchers: 0
> 2010-11-23 14:33:54,972 [311324] [INFO ] Apache.NMS.Tracer - Waiting for
> transport to reconnect.
> 2010-11-23 14:33:54,972 [219716] [DEBUG] Apache.NMS.Tracer - Attempting
> async connect to:
>
> tcp://qgmqbeta1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true
> 2010-11-23 14:33:54,972 [219716] [DEBUG] Apache.NMS.Tracer - Attempting
> async connect to:
>
> tcp://qgmqdev1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true
> 2010-11-23 14:33:54,972
>
> [tcp://qgmqbeta1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true]
> [DEBUG] Apache.NMS.Tracer - Opening socket to: qgmqbeta1 on port: 10200
> 2010-11-23 14:33:54,972
>
> [tcp://qgmqdev1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true]
> [DEBUG] Apache.NMS.Tracer - Opening socket to: qgmqdev1 on port: 10200
> 2010-11-23 14:33:54,972
>
> [tcp://qgmqdev1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true]
> [DEBUG] Apache.NMS.Tracer - Connected to qgmqdev1:10200 using InterNetwork
> protocol.
> 2010-11-23 14:33:54,972 [219716] [INFO ] Apache.NMS.Tracer - SENDING:
> WireFormatInfo[ Magic=ActiveMQ Version=6
> MarshalledProperties={CacheEnabled=False, StackTraceEnabled=False,
> TcpNoDelayEnabled=True, MaxInactivityDuration=30000,
> TightEncodingEnabled=False, CacheSize=0, SizePrefixDisabled=False,
> MaxInactivityDurationInitialDelay=10000} ]
> 2010-11-23 14:33:54,972 [219716] [INFO ] Apache.NMS.Tracer - Restoring
> previous transport connection.
> 2010-11-23 14:33:54,972 [187132] [INFO ] Apache.NMS.Tracer - RECEIVED:
> WireFormatInfo[ Magic=ActiveMQ Version=6
> MarshalledProperties={StackTraceEnabled=True, CacheEnabled=True,
> TcpNoDelayEnabled=True, MaxInactivityDuration=30000,
> MaxInactivityDurationInitalDelay=10000, TightEncodingEnabled=True,
> CacheSize=1024, SizePrefixDisabled=False} ]
> 2010-11-23 14:33:54,972 [219716] [INFO ] Apache.NMS.Tracer - SENDING:
> ConnectionControl[ commandId = 0, responseRequired = False, Close = False,
> Exit = False, FaultTolerant = True, Resume = False, Suspend = False,
> ConnectedBrokers = , ReconnectTo = , RebalanceConnection = False ]
> 2010-11-23 14:33:54,972 [219716] [INFO ] Apache.NMS.Tracer - SENDING:
> ConnectionInfo[ commandId = 1, responseRequired = True, ConnectionId =
> ID:SXALPHA3-53063-634261156397986117-1:0, ClientId = QuadNMSConsumer-t11,
> Password = destination, UserName = GL$ACTIVEMQ_QUADNMS, BrokerPath = ,
> BrokerMasterConnector = False, Manageable = False, ClientMaster = False,
> FaultTolerant = True, FailoverReconnect = True ]
> 2010-11-23 14:33:54,972 [219716] [INFO ] Apache.NMS.Tracer - SENDING:
> SessionInfo[ commandId = 0, responseRequired = False, SessionId =
> ID:SXALPHA3-53063-634261156397986117-1:0:-1 ]
> 2010-11-23 14:33:54,972 [219716] [INFO ] Apache.NMS.Tracer - Sending queued
> commands...
> 2010-11-23 14:33:54,972 [219716] [DEBUG] Apache.NMS.Tracer - Transport has
> resumed normal operation.
> 2010-11-23 14:33:54,972 [219716] [DEBUG] Apache.NMS.Tracer - Connection
> established
> 2010-11-23 14:33:54,972 [219716] [INFO ] Apache.NMS.Tracer - Successfully
> reconnected to:
>
> tcp://qgmqdev1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true
> 2010-11-23 14:33:54,972 [187132] [INFO ] Apache.NMS.Tracer - RECEIVED:
> BrokerInfo[ commandId = 0, responseRequired = False, BrokerId =
> ID:WAMQDEV1-64082-1290541558376-0:0, BrokerURL = tcp://WAMQDEV1:10200,
> PeerBrokerInfos = Apache.NMS.ActiveMQ.Commands.BrokerInfo[], BrokerName =
> WAMQDEV1QuadNMS541, SlaveBroker = False, MasterBroker = False,
> FaultTolerantConfiguration = False, DuplexConnection = False,
> NetworkConnection = False, ConnectionId = 0, BrokerUploadUrl = ,
> NetworkProperties =  ]
> 2010-11-23 14:33:54,987 [35936] [ERROR] Apache.NMS.Tracer - RECEIVED
> Exception: System.IO.EndOfStreamException: Unable to read beyond the end of
> the stream.
>   at System.IO.BinaryReader.FillBuffer(Int32 numBytes)
>   at System.IO.BinaryReader.ReadInt32()
>   at Apache.NMS.Util.EndianBinaryReader.ReadInt32() in
> c:\dev\NMS.1.4.x\src\main\csharp\Util\EndianBinaryReader.cs:line 135
>   at Apache.NMS.ActiveMQ.OpenWire.OpenWireFormat.Unmarshal(BinaryReader
> dis) in
> c:\dev\NMS.ActiveMQ.1.4.x\src\main\csharp\OpenWire\OpenWireFormat.cs:line
> 246
>   at Apache.NMS.ActiveMQ.Transport.Tcp.TcpTransport.ReadLoop() in
>
> c:\dev\NMS.ActiveMQ.1.4.x\src\main\csharp\Transport\Tcp\TcpTransport.cs:line
> 278
> 2010-11-23 14:33:54,987 [187132] [INFO ] Apache.NMS.Tracer - RECEIVED:
> Response[ commandId = 0, responseRequired = False, CorrelationId = 1 ]
> 2010-11-23 14:33:54,987 [187132] [DEBUG] Apache.NMS.Tracer - Unknown
> response ID: 0 for response: Response[ commandId = 0, responseRequired =
> False, CorrelationId = 1 ]
> 2010-11-23 14:33:55,972
>
> [tcp://qgmqbeta1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true]
> [DEBUG] Apache.NMS.Tracer - Connect fail to:
>
> tcp://qgmqbeta1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true,
> reason: Error connecting to qgmqbeta1:10200.
> 2010-11-23 14:33:55,972 [311324] [DEBUG] Apache.NMS.Tracer - Send Oneway
> attempt: 3081 failed: Message = The given key was not present in the
> dictionary.
> 2010-11-23 14:33:55,972 [311324] [DEBUG] Apache.NMS.Tracer - Failed Message
> Was: ProducerInfo[ commandId = 465, responseRequired = False, ProducerId =
> ID:SXALPHA3-53063-634261156397986117-1:0:1:3, Destination =
> queue://nms.keepAlive, BrokerPath = , DispatchAsync = False, WindowSize = 0
> ]
> 2010-11-23 14:33:55,972 [311324] [WARN ] Apache.NMS.Tracer - Transport
> failed to
>
> tcp://qgmqdev1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true,
> attempting to automatically reconnect due to: The given key was not present
> in the dictionary.
> 2010-11-23 14:33:55,972 [311324] [DEBUG] Apache.NMS.Tracer - Connection:
> Transport has been Interrupted.
> 2010-11-23 14:33:55,972 [311324] [DEBUG] Apache.NMS.Tracer - transport
> interrupted, dispatchers: 0
> 2010-11-23 14:33:55,972 [311324] [INFO ] Apache.NMS.Tracer - Waiting for
> transport to reconnect.
> 2010-11-23 14:33:55,972 [219716] [DEBUG] Apache.NMS.Tracer - Attempting
> async connect to:
>
> tcp://qgmqbeta1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true
> 2010-11-23 14:33:55,972
>
> [tcp://qgmqbeta1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true]
> [DEBUG] Apache.NMS.Tracer - Opening socket to: qgmqbeta1 on port: 10200
> 2010-11-23 14:33:55,972 [219716] [DEBUG] Apache.NMS.Tracer - Attempting
> async connect to:
>
> tcp://qgmqdev1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true
> 2010-11-23 14:33:55,972
>
> [tcp://qgmqdev1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true]
> [DEBUG] Apache.NMS.Tracer - Opening socket to: qgmqdev1 on port: 10200
> 2010-11-23 14:33:55,972
>
> [tcp://qgmqdev1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true]
> [DEBUG] Apache.NMS.Tracer - Connected to qgmqdev1:10200 using InterNetwork
> protocol.
> 2010-11-23 14:33:55,972 [219716] [INFO ] Apache.NMS.Tracer - SENDING:
> WireFormatInfo[ Magic=ActiveMQ Version=6
> MarshalledProperties={CacheEnabled=False, StackTraceEnabled=False,
> TcpNoDelayEnabled=True, MaxInactivityDuration=30000,
> TightEncodingEnabled=False, CacheSize=0, SizePrefixDisabled=False,
> MaxInactivityDurationInitialDelay=10000} ]
> 2010-11-23 14:33:55,972 [219716] [INFO ] Apache.NMS.Tracer - Restoring
> previous transport connection.
> 2010-11-23 14:33:55,972 [158776] [INFO ] Apache.NMS.Tracer - RECEIVED:
> WireFormatInfo[ Magic=ActiveMQ Version=6
> MarshalledProperties={StackTraceEnabled=True, CacheEnabled=True,
> TcpNoDelayEnabled=True, MaxInactivityDuration=30000,
> MaxInactivityDurationInitalDelay=10000, TightEncodingEnabled=True,
> CacheSize=1024, SizePrefixDisabled=False} ]
> 2010-11-23 14:33:55,972 [219716] [INFO ] Apache.NMS.Tracer - SENDING:
> ConnectionControl[ commandId = 0, responseRequired = False, Close = False,
> Exit = False, FaultTolerant = True, Resume = False, Suspend = False,
> ConnectedBrokers = , ReconnectTo = , RebalanceConnection = False ]
> 2010-11-23 14:33:55,972 [219716] [INFO ] Apache.NMS.Tracer - SENDING:
> ConnectionInfo[ commandId = 1, responseRequired = True, ConnectionId =
> ID:SXALPHA3-53063-634261156397986117-1:0, ClientId = QuadNMSConsumer-t11,
> Password = destination, UserName = GL$ACTIVEMQ_QUADNMS, BrokerPath = ,
> BrokerMasterConnector = False, Manageable = False, ClientMaster = False,
> FaultTolerant = True, FailoverReconnect = True ]
> 2010-11-23 14:33:55,972 [219716] [INFO ] Apache.NMS.Tracer - SENDING:
> SessionInfo[ commandId = 0, responseRequired = False, SessionId =
> ID:SXALPHA3-53063-634261156397986117-1:0:-1 ]
> 2010-11-23 14:33:55,972 [219716] [INFO ] Apache.NMS.Tracer - Sending queued
> commands...
> 2010-11-23 14:33:55,972 [219716] [DEBUG] Apache.NMS.Tracer - Transport has
> resumed normal operation.
> 2010-11-23 14:33:55,972 [219716] [DEBUG] Apache.NMS.Tracer - Connection
> established
> 2010-11-23 14:33:55,972 [219716] [INFO ] Apache.NMS.Tracer - Successfully
> reconnected to:
>
> tcp://qgmqdev1:10200/?transport.UseInactivityMonitor=false&transport.UseLogging=true
> 2010-11-23 14:33:55,972 [158776] [INFO ] Apache.NMS.Tracer - RECEIVED:
> BrokerInfo[ commandId = 0, responseRequired = False, BrokerId =
> ID:WAMQDEV1-64082-1290541558376-0:0, BrokerURL = tcp://WAMQDEV1:10200,
> PeerBrokerInfos = Apache.NMS.ActiveMQ.Commands.BrokerInfo[], BrokerName =
> WAMQDEV1QuadNMS541, SlaveBroker = False, MasterBroker = False,
> FaultTolerantConfiguration = False, DuplexConnection = False,
> NetworkConnection = False, ConnectionId = 0, BrokerUploadUrl = ,
> NetworkProperties =  ]
> 2010-11-23 14:33:55,987 [187132] [ERROR] Apache.NMS.Tracer - RECEIVED
> Exception: System.IO.EndOfStreamException: Unable to read beyond the end of
> the stream.
>   at System.IO.BinaryReader.FillBuffer(Int32 numBytes)
>   at System.IO.BinaryReader.ReadInt32()
>   at Apache.NMS.Util.EndianBinaryReader.ReadInt32() in
> c:\dev\NMS.1.4.x\src\main\csharp\Util\EndianBinaryReader.cs:line 135
>   at Apache.NMS.ActiveMQ.OpenWire.OpenWireFormat.Unmarshal(BinaryReader
> dis) in
> c:\dev\NMS.ActiveMQ.1.4.x\src\main\csharp\OpenWire\OpenWireFormat.cs:line
> 246
>   at Apache.NMS.ActiveMQ.Transport.Tcp.TcpTransport.ReadLoop() in
>
> c:\dev\NMS.ActiveMQ.1.4.x\src\main\csharp\Transport\Tcp\TcpTransport.cs:line
> 278
> 2010-11-23 14:33:55,987 [158776] [INFO ] Apache.NMS.Tracer - RECEIVED:
> Response[ commandId = 0, responseRequired = False, CorrelationId = 1 ]
> 2010-11-23 14:33:55,987 [158776] [DEBUG] Apache.NMS.Tracer - Unknown
> response ID: 0 for response: Response[ commandId = 0, responseRequired =
> False, CorrelationId = 1 ]
>
> --
> View this message in context:
> http://activemq.2283324.n4.nabble.com/NMS-ActiveMQ-provider-infinite-loop-on-disposal-tp3056196p3056196.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>
Reply | Threaded
Open this post in threaded view
|

Re: NMS ActiveMQ provider infinite loop on disposal?

magellings
Here's a sample URI.

failover:(tcp://QGMQDEV1:10200?transport.UseInactivityMonitor=false&transport.UseLogging=true,tcp://QGMQBETA1:10200?transport.UseInactivityMonitor=false&transport.UseLogging=true)?transport.AsyncConnect=true&transport.AsyncTimeout=20000

I had this just happen to me again.  I'm testing a fix against trunk right now so I will keep an eye on this while using trunk.  As far as replicating it with a small example I'm not exactly sure how to do it, as generally the services shut down fine.