Some more information after having enabled logging within ActiveMQ. Here's my
application log:
2009-01-19 09:11:27,837 [ActiveMQ Task ] DEBUG FailoverTransport
- Attempting connect to: tcp://127.0.0.1:61616
2009-01-19 09:11:27,954 [ActiveMQ Task ] DEBUG WireFormatNegotiator
- Sending: WireFormatInfo { version=3, properties={CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
You can see that it takes 117ms from attempting to connect to having
connected and acknowledging the openwire protocol. Interestingly, looking
back through the logs it commonly appears to take around 120ms...
coincidence?
Within the ActiveMQ log I see:
2009-01-19 09:11:27,955 [127.0.0.1:47647] DEBUG WireFormatNegotiator
- Sending: WireFormatInfo { version=3, properties={CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
Another example from my app:
2009-01-19 09:15:27,895 [ActiveMQ Task ] DEBUG FailoverTransport
- Attempting connect to: tcp://127.0.0.1:61616
2009-01-19 09:15:28,014 [ActiveMQ Task ] DEBUG WireFormatNegotiator
- Sending: WireFormatInfo { version=3, properties={CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
...and the broker around that time:
2009-01-19 09:15:28,015 [127.0.0.1:47673] DEBUG WireFormatNegotiator
- Sending: WireFormatInfo { version=3, properties={CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
That's 119ms from attempting the connect to starting the protocol...
There's nothing much else in the broker log around that time, for example:
2009-01-19 09:15:27,329 [rContainer-1388] DEBUG
efaultMessageListenerContainer - Consumer [ActiveMQMessageConsumer {
value=ID:<my host>-35464-1232315533252-2:0:1:1, started=true }] of
session [PooledSession { ActiveMQSession {id=ID:<my
host>-35464-1232315533252-2:0:1,started=true} }] did not receive a
message
2009-01-19 09:15:28,015 [127.0.0.1:47673] DEBUG WireFormatNegotiator
- Sending: WireFormatInfo { version=3, properties={CacheSize=1024,
CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
2009-01-19 09:15:28,018 [127.0.0.1:47673] DEBUG WireFormatNegotiator
- Received WireFormat: WireFormatInfo { version=3,
properties={CacheSize=1024, CacheEnabled=true, SizePrefixDisabled=false,
MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
MaxInactivityDuration=30000, TightEncodingEnabled=true,
StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
Help!
Kind regards,
Christopher
--
View this message in context:
http://www.nabble.com/Broker-connection-taking-much-longer-on-one-machine-tp21515748p21533995.html
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
