Re: FailoverTransport in 5.1 seems to make more noise...

[Rob Davies <ra...@gmail.com>]

On Jan 31, 2008, at 6:31 PM, Jason Rosenberg wrote:

>
> All,
>
> I've been testing with AMQ 5.1-SNAPSHOT, using the FailoverTransport.
>
> I'm using TcpTransport as the underyling transport.
>
> I've noticed that is seems to report more on the logging level,  
> items that
> might have previously been reported with [DEBUG] are now [INFO] or  
> [WARN].
> This is causing significant clutter in my logs.   I'd like to  
> normally not
> suppress [INFO] or [WARN] output....
>
> I have an application that needs to support very high throughput,  
> but also
> can be prone to extended down time.  So, tcp connections have a  
> tendency to
> timeout during the downtimes.  When a subsequent connection comes  
> through, I
> am seeing TCP exception level warns, that didn't used to appear when  
> the
> client is running with 4.1.1, e.g.
>
> I'm using a broker uri that looks like this:
>
> failover:(tcp://some.broker.com:61616? 
> wireFormat.maxInactivityDuration=0,tcp://some2.broker.com:61616? 
> wireFormat 
> .maxInactivityDuration 
> =0)&initialReconnectDelay=20&maxReconnectDelay=900&randomize=false
>
> Here's what I'm seeing with the client using 5.1:
>
> WARN  [2008-01-31 10:11:00,163] thread:ActiveMQ Transport:
> tcp://some.broker.com/10.82.67.59:61616               
> FailoverTransport --
> Transport failed, attempting to automatically reconnect due to:
> java.net.SocketException: Socket closed
> java.net.SocketException: Socket closed
>        at java.net.SocketInputStream.socketRead0(Native Method)
>        at java.net.SocketInputStream.read(SocketInputStream.java:129)
>        at
> org 
> .apache 
> .activemq 
> .transport 
> .tcp.TcpBufferedInputStream.fill(TcpBufferedInputStream.java:50)
>        at
> org 
> .apache 
> .activemq 
> .transport 
> .tcp.TcpBufferedInputStream.read(TcpBufferedInputStream.java:58)
>        at java.io.DataInputStream.readInt(DataInputStream.java:370)
>        at
> org 
> .apache 
> .activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:267)
>        at
> org 
> .apache 
> .activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.java: 
> 203)
>        at
> org 
> .apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java: 
> 195)
>        at
> org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java: 
> 183)
>        at java.lang.Thread.run(Thread.java:619)
> INFO  [2008-01-31 10:11:00,168] thread:ActiveMQ Task
> FailoverTransport -- Successfully reconnected to
> tcp://some.broker.com:61616?wireFormat.maxInactivityDuration=0
>
>
> The same scenario with AMQ 4.1.1 only outputs info at log-level  
> [DEBUG],
> which I can more routinely suppress:
>
> DEBUG [2008-01-31 13:23:29,288] thread:http-8080-exec-4
> FailoverTransport -- Stopped.
> DEBUG [2008-01-31 13:23:29,292] thread:http-8080-exec-4
> FailoverTransport -- Waking up reconnect task
> DEBUG [2008-01-31 13:23:29,292] thread:http-8080-exec-4
> FailoverTransport -- Started.
> DEBUG [2008-01-31 13:23:29,293] thread:ActiveMQ Task
> FailoverTransport -- Attempting connect to:
> tcp://some.broker.com:61616?wireFormat.maxInactivityDuration=0
> DEBUG [2008-01-31 13:23:29,297] thread:ActiveMQ Task
> WireFormatNegotiator -- Sending: WireFormatInfo { version=2,
> properties={CacheSize=1024, CacheEnabled=true,  
> SizePrefixDisabled=false,
> TcpNoDelayEnabled=true, MaxInactivityDuration=0,  
> TightEncodingEnabled=true,
> StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> DEBUG [2008-01-31 13:23:29,297] thread:ActiveMQ Task
> FailoverTransport -- Connection established
> DEBUG [2008-01-31 13:23:29,305] thread:ActiveMQ Transport:
> tcp://some.broker.com/10.82.67.99:61616            
> WireFormatNegotiator --
> Received WireFormat: WireFormatInfo { version=3,  
> properties={CacheSize=1024,
> CacheEnabled=true, SizePrefixDisabled=false, TcpNoDelayEnabled=true,
> MaxInactivityDuration=30000, TightEncodingEnabled=true,
> StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> DEBUG [2008-01-31 13:23:29,305] thread:ActiveMQ Transport:
> tcp://some.broker.com/10.82.67.99:61616            
> WireFormatNegotiator --
> tcp://some.broker.com/10.82.67.99:61616 before negotiation:
> OpenWireFormat{version=2, cacheEnabled=false, stackTraceEnabled=false,
> tightEncodingEnabled=false, sizePrefixDisabled=false}
> DEBUG [2008-01-31 13:23:29,305] thread:ActiveMQ Transport:
> tcp://some.broker.com/10.82.67.99:61616            
> WireFormatNegotiator --
> tcp://some.broker.com/10.82.67.99:61616 after negotiation:
> OpenWireFormat{version=2, cacheEnabled=true, stackTraceEnabled=true,
> tightEncodingEnabled=true, sizePrefixDisabled=false}
>
>
> Thoughts?  Is there a reason why in 5.1, the FailoverTransport  
> passes on the
> underlying tcp socket timeout due to inactivity?
>
> Thanks,
>
> Jason
> -- 
> View this message in context: http://www.nabble.com/FailoverTransport-in-5.1-seems-to-make-more-noise...-tp15211718s2354p15211718.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
>

due you want to add a jira issue so you can track ?

cheers,

Rob

Re: FailoverTransport in 5.1 seems to make more noise...

[Jason Rosenberg <jr...@shopzilla.com>]

I've logged an issue:

https://issues.apache.org/activemq/browse/AMQ-1574

Jason

-- 
View this message in context: http://www.nabble.com/FailoverTransport-in-5.1-seems-to-make-more-noise...-tp15211718s2354p15227526.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.