Mailing-List: contact dev-help@activemq.apache.org; run by ezmlm
Precedence: bulk
Reply-To: dev@activemq.apache.org
Message-ID: <17331851.1202159856070.JavaMail.jira@brutus>
Date: Mon, 4 Feb 2008 13:17:36 -0800 (PST)
From: "Jason Rosenberg (JIRA)" <jira@apache.org>
To: dev@activemq.apache.org
Subject: [jira] Commented: (AMQ-1574) FailoverTransport logs routine
 reconnects at INFO/WARN instead of DEBUG
In-Reply-To: <5154126.1201876896758.JavaMail.jira@brutus>
MIME-Version: 1.0
Content-Type: text/plain; charset=ISO-8859-1
Content-Transfer-Encoding: 7bit


    [ https://issues.apache.org/activemq/browse/AMQ-1574?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=41222#action_41222 ] 

Jason Rosenberg commented on AMQ-1574:
--------------------------------------

Note, by using workarounds, described in AMQ-1577 and AMQ-1578, this problem has been resolved in my environment.

I'm thinking that resolution of those 2 issues will reduce the spamming of these exceptions every 30 seconds, etc.

The problem in my case stems directly from using PooledConnections (see AMQ-1578)....

> FailoverTransport logs routine reconnects at INFO/WARN instead of DEBUG
> -----------------------------------------------------------------------
>
>                 Key: AMQ-1574
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1574
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Transport
>    Affects Versions: 5.0.0
>         Environment: I'm using a recent 5.1 snapshot:
> 5.1-20080124.044610-8
>            Reporter: Jason Rosenberg
>
> Logged originally in the user forum here:
> http://www.nabble.com/FailoverTransport-in-5.1-seems-to-make-more-noise...-to15211718s2354.html#a15221625
> Here's the text of that again:
> 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

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.