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 <mark.gelli...@qg.com> 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.
>
