activemq-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Chris Robison <chrisdrobi...@gmail.com>
Subject Re: Client consumer exception and disconnection
Date Sat, 07 Apr 2012 18:37:47 GMT
I'm assuming you mean set it on the connection factory. I've tried that,
but no go. The only way I've found to recover from this is to delete the
KahaDB on the activemq server and restart all services.

On Sat, Apr 7, 2012 at 11:59 AM, Timothy Bish <tabish121@gmail.com> wrote:

> On Sat, 2012-04-07 at 11:56 -0600, Chris Robison wrote:
> > I'm running into an interesting issue. I have a client connecting to an
> > activemq server, trying to consume messages and reply to a temporary
> > destination set. The ActiveMQ server debug is showing the following:
> >
> > 2012-04-07 13:20:25,708 | DEBUG | Received WireFormat: WireFormatInfo {
> > version=6, properties={CacheSize=0, CacheEnabled=false,
> > MaxInactivityDurationInitialDelay=10000, SizePrefixDisabled=false,
> > TcpNoDelayEnabled=true, MaxInactivityDuration=30000,
> > TightEncodingEnabled=false, StackTraceEnabled=false},
> > magic=[A,c,t,i,v,e,M,Q]} |
> > org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ Transport:
> > ssl:///172.17.5.16:52657
> > 2012-04-07 13:20:25,708 | DEBUG | ssl:///172.17.5.16:52657 before
> > negotiation: OpenWireFormat{version=9, cacheEnabled=false,
> > stackTraceEnabled=false, tightEncodingEnabled=false,
> > sizePrefixDisabled=false, maxFrameSize=104857600} |
> > org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ Transport:
> > ssl:///172.17.5.16:52657
> > 2012-04-07 13:20:25,709 | DEBUG | ssl:///172.17.5.16:52657 after
> > negotiation: OpenWireFormat{version=6, cacheEnabled=false,
> > stackTraceEnabled=false, tightEncodingEnabled=false,
> > sizePrefixDisabled=false, maxFrameSize=104857600} |
> > org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ Transport:
> > ssl:///172.17.5.16:52657
> > 2012-04-07 13:20:25,725 | DEBUG | Setting up new connection id:
> > ID:WIIPAP101-52658-634694015719174302-1:0, address: tcp://
> 172.17.5.16:52657,
> > info: ConnectionInfo {commandId = 1, responseRequired = true,
> connectionId
> > = ID:WIIPAP101-52658-634694015719174302-1:0, clientId =
> > ID:WIIPAP101-52658-634694015719174302-0:0, clientIp = null, userName =
> > mqipauser, password = *****, brokerPath = null, brokerMasterConnector =
> > false, manageable = false, clientMaster = false, faultTolerant = false,
> > failoverReconnect = false} |
> org.apache.activemq.broker.TransportConnection
> > | ActiveMQ Transport: ssl:///172.17.5.16:52657
> > 2012-04-07 13:20:25,727 | DEBUG | Create the LDAP initial context. |
> > org.apache.activemq.jaas.LDAPLoginModule | ActiveMQ Transport: ssl:///
> > 172.17.5.16:52657
> > 2012-04-07 13:20:25,739 | DEBUG | Get the user DN. |
> > org.apache.activemq.jaas.LDAPLoginModule | ActiveMQ Transport: ssl:///
> > 172.17.5.16:52657
> > 2012-04-07 13:20:25,739 | DEBUG | Looking for the user in LDAP with  |
> > org.apache.activemq.jaas.LDAPLoginModule | ActiveMQ Transport: ssl:///
> > 172.17.5.16:52657
> > 2012-04-07 13:20:25,740 | DEBUG |   base DN:
> > OU=Users,OU=ActiveMQ,DC=VOSH,DC=NET |
> > org.apache.activemq.jaas.LDAPLoginModule | ActiveMQ Transport: ssl:///
> > 172.17.5.16:52657
> > 2012-04-07 13:20:25,740 | DEBUG |   filter: (sAMAccountName=mqipauser) |
> > org.apache.activemq.jaas.LDAPLoginModule | ActiveMQ Transport: ssl:///
> > 172.17.5.16:52657
> > 2012-04-07 13:20:25,743 | DEBUG | Binding the user. |
> > org.apache.activemq.jaas.LDAPLoginModule | ActiveMQ Transport: ssl:///
> > 172.17.5.16:52657
> > 2012-04-07 13:20:25,750 | DEBUG | User CN=MQ IPA
> > User,OU=Users,OU=ActiveMQ,DC=VOSH,DC=NET successfully bound. |
> > org.apache.activemq.jaas.LDAPLoginModule | ActiveMQ Transport: ssl:///
> > 172.17.5.16:52657
> > 2012-04-07 13:20:25,751 | DEBUG | Get user roles. |
> > org.apache.activemq.jaas.LDAPLoginModule | ActiveMQ Transport: ssl:///
> > 172.17.5.16:52657
> > 2012-04-07 13:20:25,751 | DEBUG | Looking for the user roles in LDAP with
> >  | org.apache.activemq.jaas.LDAPLoginModule | ActiveMQ Transport: ssl:///
> > 172.17.5.16:52657
> > 2012-04-07 13:20:25,751 | DEBUG |   base DN:
> > OU=Groups,OU=ActiveMQ,DC=VOSH,DC=NET |
> > org.apache.activemq.jaas.LDAPLoginModule | ActiveMQ Transport: ssl:///
> > 172.17.5.16:52657
> > 2012-04-07 13:20:25,751 | DEBUG |   filter: (member=CN=MQ IPA
> > User,OU=Users,OU=ActiveMQ,DC=VOSH,DC=NET) |
> > org.apache.activemq.jaas.LDAPLoginModule | ActiveMQ Transport: ssl:///
> > 172.17.5.16:52657
> > 2012-04-07 13:20:25,762 | DEBUG | Roles [MQIPAUsers, MQUsers] for user
> > mqipauser | org.apache.activemq.jaas.LDAPLoginModule | ActiveMQ
> Transport:
> > ssl:///172.17.5.16:52657
> > 2012-04-07 13:20:25,789 | DEBUG | msipap101.vosh.net adding consumer:
> > ID:WIIPAP101-52658-634694015719174302-1:0:1:1 for destination:
> > queue://SolidCloud.Requests.Desktops.IPA |
> > org.apache.activemq.broker.region.AbstractRegion | ActiveMQ Transport:
> > ssl:///172.17.5.16:52657
> > 2012-04-07 13:20:25,797 | DEBUG |
> queue://SolidCloud.Requests.Desktops.IPA
> > add sub: QueueSubscription:
> > consumer=ID:WIIPAP101-52658-634694015719174302-1:0:1:1, destinations=0,
> > dispatched=0, delivered=0, pending=0, dequeues: 1, dispatched: 1,
> inflight:
> > 0 | org.apache.activemq.broker.region.Queue | ActiveMQ Transport: ssl:///
> > 172.17.5.16:52657
> > 2012-04-07 13:20:25,798 | DEBUG | SolidCloud.Requests.Desktops.IPA
> > toPageIn: 0, Inflight: 0, pagedInMessages.size 9, enqueueCount: 3,
> > dequeueCount: 1 | org.apache.activemq.broker.region.Queue |
> > Queue:SolidCloud.Requests.Desktops.IPA
> > 2012-04-07 13:20:25,810 | DEBUG | bridging (msipap101.vosh.net ->
> > mstmip101.vosh.net) ID:MSIPAP101-36535-1333817412870-1:1:0:0:33,
> consumer:
> > ID:MSIPAP101-36535-1333817412870-2:2:1:1, destination
> >
> topic://ActiveMQ.Advisory.Consumer.Queue.SolidCloud.Requests.Desktops.IPA,
> > brokerPath: [ID:MSIPAP101-36535-1333817412870-0:1], message:
> > ActiveMQMessage {commandId = 0, responseRequired = false, messageId =
> > ID:MSIPAP101-36535-1333817412870-1:1:0:0:33, originalDestination = null,
> > originalTransactionId = null, producerId =
> > ID:MSIPAP101-36535-1333817412870-2:1:1:1, destination =
> >
> topic://ActiveMQ.Advisory.Consumer.Queue.SolidCloud.Requests.Desktops.IPA,
> > transactionId = null, expiration = 0, timestamp = 0, arrival = 0,
> > brokerInTime = 1333819225809, brokerOutTime = 1333819225810,
> correlationId
> > = null, replyTo = null, persistent = false, type = Advisory, priority =
> 0,
> > groupID = null, groupSequence = 0, targetConsumerId = null, compressed =
> > false, userID = null, content = null, marshalledProperties = null,
> > dataStructure = ConsumerInfo {commandId = 3, responseRequired = true,
> > consumerId = ID:WIIPAP101-52658-634694015719174302-1:0:1:1, destination =
> > queue://SolidCloud.Requests.Desktops.IPA, prefetchSize = 1000,
> > maximumPendingMessageLimit = 0, browser = false, dispatchAsync = true,
> > selector = null, subscriptionName = null, noLocal = false, exclusive =
> > false, retroactive = false, priority = 0, brokerPath = null,
> > optimizedAcknowledge = false, noRangeAcks = false, additionalPredicate =
> > null}, redeliveryCounter = 0, size = 1024, properties = {consumerCount=2,
> > originBrokerURL=ssl://MSIPAP101:61616,
> > originBrokerId=ID:MSIPAP101-36535-1333817412870-0:1, originBrokerName=
> > msipap101.vosh.net}, readOnlyProperties = false, readOnlyBody = false,
> > droppable = false} |
> > org.apache.activemq.network.DemandForwardingBridgeSupport | ActiveMQ
> > Connection Dispatcher: vm://msipap101.vosh.net#0
> > 2012-04-07 13:20:26,912 | DEBUG | Error occured while processing sync
> > command: ActiveMQTextMessage {commandId = 5, responseRequired = true,
> > messageId = ID:WIIPAP101-52658-634694015719174302-1:0:1:1:1,
> > originalDestination = null, originalTransactionId = null, producerId =
> > ID:WIIPAP101-52658-634694015719174302-1:0:1:1, destination =
> > temp-queue://ID:POTMIP102-60127-634693656236343522-1:38:1, transactionId
> =
> > null, expiration = 0, timestamp = 1333819173524, arrival = 0,
> brokerInTime
> > = 1333819226907, brokerOutTime = 0, correlationId = null, replyTo = null,
> > persistent = true, type = null, priority = 4, groupID = null,
> groupSequence
> > = 0, targetConsumerId = null, compressed = false, userID = null, content
> =
> > null, marshalledProperties = null, dataStructure = null,
> redeliveryCounter
> > = 0, size = 0, properties = null, readOnlyProperties = false,
> readOnlyBody
> > = false, droppable = false, text = []}, exception:
> javax.jms.JMSException:
> > The destination temp-queue://ID:POTMIP102-60127-634693656236343522-1:38:1
> > does not exist. | org.apache.activemq.broker.TransportConnection.Service
> |
> > ActiveMQ Transport: ssl:///172.17.5.16:52657
> > javax.jms.JMSException: The destination
> > temp-queue://ID:POTMIP102-60127-634693656236343522-1:38:1 does not exist.
> > at
> >
> org.apache.activemq.broker.region.AbstractRegion.addDestination(AbstractRegion.java:149)
> > at
> >
> org.apache.activemq.broker.region.RegionBroker.addDestination(RegionBroker.java:314)
> > at
> >
> org.apache.activemq.broker.BrokerFilter.addDestination(BrokerFilter.java:145)
> > at
> >
> org.apache.activemq.advisory.AdvisoryBroker.addDestination(AdvisoryBroker.java:161)
> > at
> >
> org.apache.activemq.broker.BrokerFilter.addDestination(BrokerFilter.java:145)
> > at
> >
> org.apache.activemq.broker.BrokerFilter.addDestination(BrokerFilter.java:145)
> > at
> >
> org.apache.activemq.broker.BrokerFilter.addDestination(BrokerFilter.java:145)
> > at
> >
> org.apache.activemq.broker.BrokerFilter.addDestination(BrokerFilter.java:145)
> > at
> >
> org.apache.activemq.security.AuthorizationBroker.addDestination(AuthorizationBroker.java:81)
> > at
> >
> org.apache.activemq.broker.MutableBrokerFilter.addDestination(MutableBrokerFilter.java:151)
> > at
> >
> org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:506)
> > at
> >
> org.apache.activemq.broker.jmx.ManagedRegionBroker.send(ManagedRegionBroker.java:305)
> > at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129)
> > at
> >
> org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:96)
> > at
> >
> org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:306)
> > at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129)
> > at org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:129)
> > at
> >
> org.apache.activemq.security.AuthorizationBroker.send(AuthorizationBroker.java:192)
> > at
> >
> org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:135)
> > at
> >
> org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:452)
> > at
> >
> org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:681)
> > at
> >
> org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:291)
> > at
> >
> org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:149)
> > at
> >
> org.apache.activemq.transport.MutexTransport.onCommand(MutexTransport.java:50)
> > at
> >
> org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:113)
> > at
> >
> org.apache.activemq.transport.AbstractInactivityMonitor.onCommand(AbstractInactivityMonitor.java:229)
> > at
> >
> org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:83)
> > at
> >
> org.apache.activemq.transport.tcp.SslTransport.doConsume(SslTransport.java:91)
> > at
> >
> org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:222)
> > at
> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:204)
> > at java.lang.Thread.run(Thread.java:679)
> > 2012-04-07 13:20:26,943 | DEBUG | Transport Connection to: tcp://
> > 172.17.5.16:52657 failed: java.io.EOFException |
> > org.apache.activemq.broker.TransportConnection.Transport | ActiveMQ
> > Transport: ssl:///172.17.5.16:52657
> > java.io.EOFException
> > at java.io.DataInputStream.readInt(DataInputStream.java:392)
> > at
> >
> org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:275)
> > at
> >
> org.apache.activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.java:229)
> > at
> >
> org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:221)
> > at
> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:204)
> > at java.lang.Thread.run(Thread.java:679)
> > 2012-04-07 13:20:26,947 | DEBUG | Stopping connection: tcp://
> > 172.17.5.16:52657 | org.apache.activemq.broker.TransportConnection |
> > StopAsync:tcp://172.17.5.16:52657-14
> > 2012-04-07 13:20:26,948 | DEBUG | Stopping transport ssl:///
> > 172.17.5.16:52657 | org.apache.activemq.transport.tcp.TcpTransport |
> > StopAsync:tcp://172.17.5.16:52657-14
> > 2012-04-07 13:20:26,949 | DEBUG | Stopped transport:
> > tcp://172.17.5.16:52657|
> > org.apache.activemq.broker.TransportConnection |
> > StopAsync:tcp://172.17.5.16:52657-14
> > 2012-04-07 13:20:26,950 | DEBUG | Cleaning up connection resources:
> tcp://
> > 172.17.5.16:52657 | org.apache.activemq.broker.TransportConnection |
> > StopAsync:tcp://172.17.5.16:52657-14
> > 2012-04-07 13:20:26,950 | DEBUG | remove connection id:
> > ID:WIIPAP101-52658-634694015719174302-1:0 |
> > org.apache.activemq.broker.TransportConnection |
> > StopAsync:tcp://172.17.5.16:52657-14
> > 2012-04-07 13:20:26,951 | DEBUG | msipap101.vosh.net removing consumer:
> > ID:WIIPAP101-52658-634694015719174302-1:0:1:1 for destination:
> > queue://SolidCloud.Requests.Desktops.IPA |
> > org.apache.activemq.broker.region.AbstractRegion |
> > StopAsync:tcp://172.17.5.16:52657-14
> >
> > For some reason the client is being disconnected. The log on the client
> is
> > showing the following:
> >
> > 2012-04-07
> > 13:06:22.0000|ERROR|VOAuto.Services.Citrix.RequestInvoker|Channel was
> > inactive for too long:
> > ssl://
> msipap101.vosh.net:61616/EXCEPTIONOCCURRED:Apache.NMS.ActiveMQ.IOException
> > Channel was inactive for too long:
> > ssl://msipap101.vosh.net:61616/ Apache.NMS.ActiveMQ.Commands.Response
> > SyncRequest(Apache.NMS.ActiveMQ.Commands.Command, System.TimeSpan)    at
> > Apache.NMS.ActiveMQ.Connection.SyncRequest(Command command, TimeSpan
> > requestTimeout) in c:\dev\NMS.ActiveMQ\src\main\csharp\Connection.cs:line
> > 667
> >    at Apache.NMS.ActiveMQ.Session.DoSend(ActiveMQDestination destination,
> > ActiveMQMessage message, MessageProducer producer, MemoryUsage
> > producerWindow, TimeSpan sendTimeout) in
> > c:\dev\NMS.ActiveMQ\src\main\csharp\Session.cs:line 716
> >    at Apache.NMS.ActiveMQ.MessageProducer.Send(IDestination destination,
> > IMessage message, MsgDeliveryMode deliveryMode, MsgPriority priority,
> > TimeSpan timeToLive, Boolean specifiedTimeToLive) in
> > c:\dev\NMS.ActiveMQ\src\main\csharp\MessageProducer.cs:line 258
> >    at Apache.NMS.ActiveMQ.MessageProducer.Send(IDestination destination,
> > IMessage message) in
> > c:\dev\NMS.ActiveMQ\src\main\csharp\MessageProducer.cs:line 170
> >    at
> >
> VirtualOffice.Automation.Messaging.Impl.ActiveMqMessagingProvider.<>c__DisplayClassd.<RegisterRequestReceiver>b__c(IMessage
> > message)
> >
> > I'm sort of at a loss because the client is being disconnected and is not
> > reconnecting. Any suggestions?
> >
> > Chris
>
> Try turning off watchTopicAdvisories for the connection, there is a bug
> in v 1.5.3 related to this.
>
> --
> Tim Bish
> Sr Software Engineer | FuseSource Corp
> tim.bish@fusesource.com | www.fusesource.com
> skype: tabish121 | twitter: @tabish121
> blog: http://timbish.blogspot.com/
>
>

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message