[
https://issues.apache.org/jira/browse/AMQNET-370?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13250805#comment-13250805
]
Tom commented on AMQNET-370:
----------------------------
An example with Trace turned on. Apache.NMS.ActiveMq v1.5.3.
This was seen when running broker build apache-activemq-5.5.1-fuse-03-06 with 1
producer and 20 consumers, sending 2kb messages with the producer running flat
out at ~1100msg/s.
The failover transport was used with two brokers specified, the first
("bl-svr62:61616") was available and the second never available
("localhost:61617" below).
After stopping and starting the first broker a few times we see the error
message below.
The consumer never recovers from this failover. The more we repeat this the
more consumers fail. Interestingly when we tried this running the consumers on
the same machine as the broker using localhost we were unable to replicate the
issue.
I can provide more log context if required and if the code used to generate
this error would be of use I can provide that too.
{code}17:07:51 DEBUG Attempting sync connect to:
tcp://localhost:61617/?keepAlive=true&wireformat.maxInactivityDuration=0
17:07:51 DEBUG Opening socket to: localhost on port: 61617
17:07:51 DEBUG Inflight MessageAck being dropped as stale.
17:07:51 DEBUG Attempting sync connect to:
tcp://localhost:61617/?keepAlive=true&wireformat.maxInactivityDuration=0
17:07:51 DEBUG Opening socket to: localhost on port: 61617
17:07:51 DEBUG Attempting sync connect to:
tcp://localhost:61617/?keepAlive=true&wireformat.maxInactivityDuration=0
17:07:51 DEBUG Opening socket to: localhost on port: 61617
17:07:51 DEBUG ID:BLUE-00297-24875-634696743161508365-1:4:1:1 clearing
dispatched list (0) on transport interrupt
17:07:51 DEBUG transportInterruptionProcessingComplete for:
ID:BLUE-00297-24875-634696743161508365-1:4
17:07:51 ERROR Error during connection close: Apache.NMS.ActiveMQ.IOException:
Channel was inactive for too long:
tcp://localhost:61616/?keepalive=true&wireformat.maxinactivityduration=0
at Apache.NMS.ActiveMQ.Transport.InactivityMonitor.Oneway(Command command)
at Apache.NMS.ActiveMQ.Transport.WireFormatNegotiator.Oneway(Command command)
at Apache.NMS.ActiveMQ.Transport.TransportFilter.Oneway(Command command)
at Apache.NMS.ActiveMQ.Transport.MutexTransport.Oneway(Command command)
at Apache.NMS.ActiveMQ.Transport.ResponseCorrelator.Oneway(Command command)
at Apache.NMS.ActiveMQ.Connection.Close()
17:07:51 DEBUG Performing Async Clear of In Progress Messages on Consumer:
ID:BLUE-00297-24875-634696743161508365-1:18:1:1
17:07:51 DEBUG ID:BLUE-00297-24875-634696743161508365-1:18:1:1 clearing
dispatched list (0) on transport interrupt
17:07:51 DEBUG transportInterruptionProcessingComplete for:
ID:BLUE-00297-24875-634696743161508365-1:18
17:07:52 DEBUG Performing Async Clear of In Progress Messages on Consumer:
ID:BLUE-00297-24875-634696743161508365-1:20:1:1
17:07:52 DEBUG ID:BLUE-00297-24875-634696743161508365-1:20:1:1 clearing
dispatched list (0) on transport interrupt
17:07:52 DEBUG transportInterruptionProcessingComplete for:
ID:BLUE-00297-24875-634696743161508365-1:20
17:07:53 DEBUG Performing Async Clear of In Progress Messages on Consumer:
ID:BLUE-00297-24875-634696743161508365-1:11:1:1
17:07:53 DEBUG ID:BLUE-00297-24875-634696743161508365-1:11:1:1 clearing
dispatched list (0) on transport interrupt
17:07:53 DEBUG transportInterruptionProcessingComplete for:
ID:BLUE-00297-24875-634696743161508365-1:11
17:07:53 DEBUG Connect fail to:
tcp://localhost:61617/?keepAlive=true&wireformat.maxInactivityDuration=0,
reason: Error connecting to localhost:61617.
17:07:53 DEBUG Attempting sync connect to:
tcp://localhost:61616/?keepAlive=true&wireformat.maxInactivityDuration=0
17:07:53 DEBUG Opening socket to: localhost on port: 61616
17:07:53 DEBUG Connect fail to:
tcp://localhost:61617/?keepAlive=true&wireformat.maxInactivityDuration=0,
reason: Error connecting to localhost:61617.{code}
> Channel was inactive for too long does not recover
> --------------------------------------------------
>
> Key: AMQNET-370
> URL: https://issues.apache.org/jira/browse/AMQNET-370
> Project: ActiveMQ .Net
> Issue Type: Bug
> Components: ActiveMQ
> Affects Versions: 1.5.1
> Environment: Windows .NET
> Server is 5.4.2 on Windows server 2008.
> Reporter: Matthew Good
> Assignee: Jim Gomes
> Attachments: nms-inactivityexception.log
>
>
> I see many of these bugs about "Channel was inactive for too long" and they
> all get closed as incomplete because no one can determine the cause. So I
> won't ask for that.
> The biggest problem here isn't that this one call fails, it's that the client
> does not recover or failover after this occurs so once this happens once, it
> continues for every request until the client application is restarted. In a
> production environment, we can't be restarting services all the time.
> For services that are just listening, they stop receiving messages, no error
> is raised so we don't even know that it is in a bad state.
> So please fix the failover to re-establish the connection(s) or whatever it
> must do so that the next call works since that is the intention of the
> failover protocol.
> Apache.NMS.ActiveMQ.IOException: Channel was inactive for too long:
> tcp://ipc-393-pstg-05.ipcommerce.com:61616/
> at Apache.NMS.ActiveMQ.Connection.Oneway(Command command)
> at Apache.NMS.ActiveMQ.Session..ctor(Connection connection, SessionId
> sessionId, AcknowledgementMode acknowledgementMode)
> at Apache.NMS.ActiveMQ.Connection.CreateAtiveMQSession(AcknowledgementMode
> ackMode)
> at Apache.NMS.ActiveMQ.Connection.CreateSession(AcknowledgementMode
> sessionAcknowledgementMode)
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators:
https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira
