A broken pipe means that the other side of the socket closed it and then
your side tried to write to it. So the question is then, what do you see in
the broker's logs when this is happening? That might indicate why it's
disconnecting you right after sending the ConnectionControl message to you.
Tim
On Aug 31, 2017 2:18 PM, "Steve Hill" <sh...@futurelogix.co.uk> wrote:
> We are running ActiveMQ in Master/Slave configuration. Currently
> mqarms02p is the Master. Earlier today we ran into a situation where we
> lost access to ActiveMQ and on reviewing the client side logs we see the
> information below cycle continuously.
>
> Is there anything we can enable on the server side to better log what
> happened from the server perspective? Unfortunately in this instance the
> logs had already rolled so we could not see anything, however from
> previously experience we know almost nothing shows up.
>
> The server was online and other clients were using it without incident
>
> Any ideas as to what happened and how we can prevent this occurring in
> future?
>
> 08-31 11:46:02 DEBUG - Attempting 0th connect to: tcp://mqarms01p:61616
> 08-31 11:46:02 TRACE - Starting connection check task for:
> tcp://mqarms01p:61616
> 08-31 11:46:02 DEBUG - Connect fail to: tcp://mqarms01p:61616, reason:
> java.net.ConnectException: Connection refused
> 08-31 11:46:02 TRACE - Stopping connection check task for:
> tcp://mqarms01p:61616
> 08-31 11:46:02 DEBUG - Stopping transport tcp://mqarms01p:61616
> 08-31 11:46:02 DEBUG - Initialized TaskRunnerFactory[ActiveMQ Task] using
> ExecutorService: java.util.concurrent.ThreadPoolExecutor@1f0f564[Running,
> pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0]
> 08-31 11:46:02 TRACE - Execute[ActiveMQ Task] runnable:
> org.apache.activemq.transport.tcp.TcpTransport$1@727e793a
> 08-31 11:46:02 TRACE - Created thread[ActiveMQ Task-1]: Thread[ActiveMQ
> Task-1,5,main]
> 08-31 11:46:02 TRACE - Closing socket Socket[unconnected]
> 08-31 11:46:02 DEBUG - Closed socket Socket[unconnected]
> 08-31 11:46:02 DEBUG - Forcing shutdown of ExecutorService:
> java.util.concurrent.ThreadPoolExecutor@1f0f564[Running, pool size = 1,
> active threads = 0, queued tasks = 0, completed tasks = 1]
> 08-31 11:46:02 TRACE - Shutdown of ExecutorService:
> java.util.concurrent.ThreadPoolExecutor@1f0f564[Shutting down, pool size
> = 1, active threads = 0, queued tasks = 0, completed tasks = 1] is
> shutdown: true and terminated: false.
> 08-31 11:46:02 DEBUG - Attempting 0th connect to: tcp://mqarms02p:61616
> 08-31 11:46:02 TRACE - Starting connection check task for:
> tcp://mqarms02p:61616
> 08-31 11:46:02 DEBUG - Sending: WireFormatInfo { version=12,
> properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
> ProviderVersion=5.14.3, CacheEnabled=true, ProviderName=ActiveMQ,
> SizePrefixDisabled=false, PlatformDetails=JVM: 1.7.0_80, 24.80-b11, Oracle
> Corporation, OS: Linux, 2.6.32-358.6.2.el6.x86_64, amd64,
> MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
> MaxInactivityDuration=30000, TightEncodingEnabled=true,
> StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 08-31 11:46:02 TRACE - Starting connection check task for: tcp://mqarms02p/
> 172.16.101.116:61616@47626
> 08-31 11:46:02 TRACE - TCP consumer thread for tcp://mqarms02p/172.16.101.
> 116:61616@47626 starting
> 08-31 11:46:02 TRACE - Stopping connection check task for: tcp://mqarms02p/
> 172.16.101.116:61616@47626
> 08-31 11:46:02 DEBUG - Using min of local: WireFormatInfo { version=12,
> properties={MaxFrameSize=9223372036854775807, CacheSize=1024,
> ProviderVersion=5.14.3, CacheEnabled=true, ProviderName=ActiveMQ,
> SizePrefixDisabled=false, PlatformDetails=JVM: 1.7.0_80, 24.80-b11, Oracle
> Corporation, OS: Linux, 2.6.32-358.6.2.el6.x86_64, amd64,
> MaxInactivityDurationInitalDelay=10000, TcpNoDelayEnabled=true,
> MaxInactivityDuration=30000, TightEncodingEnabled=true,
> StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} and remote:
> WireFormatInfo { version=12, properties={MaxFrameSize=104857600,
> CacheSize=1024, ProviderVersion=5.14.3, CacheEnabled=true,
> ProviderName=ActiveMQ, SizePrefixDisabled=false,
> MaxInactivityDurationInitalDelay=10000, PlatformDetails=JVM: 1.8.0_111,
> 25.111-b15, Oracle Corporation, OS: Linux, 3.8.13-68.3.3.el6uek.x86_64,
> amd64, TcpNoDelayEnabled=true, MaxInactivityDuration=30000,
> TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 08-31 11:46:02 DEBUG - Received WireFormat: WireFormatInfo { version=12,
> properties={MaxFrameSize=104857600, CacheSize=1024,
> ProviderVersion=5.14.3, CacheEnabled=true, ProviderName=ActiveMQ,
> SizePrefixDisabled=false, MaxInactivityDurationInitalDelay=10000,
> PlatformDetails=JVM: 1.8.0_111, 25.111-b15, Oracle Corporation, OS: Linux,
> 3.8.13-68.3.3.el6uek.x86_64, amd64, TcpNoDelayEnabled=true,
> MaxInactivityDuration=30000, TightEncodingEnabled=true,
> StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]}
> 08-31 11:46:02 DEBUG - tcp://mqarms02p/172.16.101.116:61616@47626 before
> negotiation: OpenWireFormat{version=12, cacheEnabled=false,
> stackTraceEnabled=false, tightEncodingEnabled=false,
> sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
> 08-31 11:46:02 DEBUG - tcp://mqarms02p/172.16.101.116:61616@47626 after
> negotiation: OpenWireFormat{version=12, cacheEnabled=true,
> stackTraceEnabled=true, tightEncodingEnabled=true,
> sizePrefixDisabled=false, maxFrameSize=104857600}
> 08-31 11:46:02 DEBUG - conn: ID:tnsags01p.xxxx.com-53927-1504137796960-5:1
> 08-31 11:46:02 DEBUG - session: ID:tnsags01p.xxxx.com-53927-15
> 04137796960-5:1:1441358
> 08-31 11:46:02 DEBUG - restore consumer:
> ID:tnsags01p.xxxx.com-53927-1504137796960-5:1:1441358:1
> in pull mode pending recovery, overriding prefetch: 1000
> 08-31 11:46:02 DEBUG - consumer: ID:tnsags01p.xxxx.com-53927-15
> 04137796960-5:1:1441358:1
> 08-31 11:46:02 DEBUG - session: ID:tnsags01p.xxxx.com-53927-15
> 04137796960-5:1:-1
> 08-31 11:46:02 DEBUG - restore consumer:
> ID:tnsags01p.xxxx.com-53927-1504137796960-5:1:-1:1
> in pull mode pending recovery, overriding prefetch: 1000
> 08-31 11:46:02 DEBUG - consumer: ID:tnsags01p.xxxx.com-53927-15
> 04137796960-5:1:-1:1
> 08-31 11:46:02 DEBUG - session: ID:tnsags01p.xxxx.com-53927-15
> 04137796960-5:1:1442703
> 08-31 11:46:02 DEBUG - producer: ID:tnsags01p.xxxx.com-53927-15
> 04137796960-5:1:1442703:1
> 08-31 11:46:02 DEBUG - Connection established
> 08-31 11:46:02 INFO - Successfully reconnected to tcp://mqarms02p:61616
> 08-31 11:46:02 TRACE - Running task iteration 0 -
> org.apache.activemq.transport.failover.FailoverTransport$2@112605fd
> 08-31 11:46:02 TRACE - Run task done: org.apache.activemq.transport.
> failover.FailoverTransport$2@112605fd
> 08-31 11:46:02 TRACE - Run task done: org.apache.activemq.transport.
> failover.FailoverTransport$2@112605fd
> 08-31 11:46:02 TRACE - Received ConnectionControl: ConnectionControl
> {commandId = 0, responseRequired = false, suspend = false, resume = false,
> close = false, exit = false, faultTolerant = false, connectedBrokers = ,
> reconnectTo = , token = null, rebalanceConnection = false}
> 08-31 11:46:02 DEBUG - Send oneway attempt: 17752 failed for command:
> ActiveMQObjectMessage {commandId = 7234566, responseRequired = true,
> messageId = ID:tnsags01p.xxxx.com-53927-1504137796960-5:1:1442703:1:1,
> originalDestination = null, originalTransactionId = null, producerId =
> ID:tnsags01p.xxxx.com-53927-1504137796960-5:1:1442703:1, destination =
> queue://routing_mia_client, transactionId = null, expiration = 0, timestamp
> = 1504192175689, arrival = 0, brokerInTime = 0, brokerOutTime = 0,
> correlationId = null, replyTo = null, persistent = true, type = null,
> priority = 4, groupID = null, groupSequence = 0, targetConsumerId = null,
> compressed = false, userID = null, content = org.apache.activemq.util.ByteS
> equence@1558c374, marshalledProperties = null, dataStructure = null,
> redeliveryCounter = 0, size = 0, properties = null, readOnlyProperties =
> true, readOnlyBody = true, droppable = false, jmsXGroupFirstForConsumer =
> false}
> 08-31 11:46:02 TRACE - tcp://mqarms02p:61616 handleTransportFailure:
> java.net.SocketException: Broken pipe
> java.net.SocketException: Broken pipe
> at java.net.SocketOutputStream.socketWrite0(Native Method)
> at java.net.SocketOutputStream.socketWrite(SocketOutputStream.
> java:113)
> at java.net.SocketOutputStream.write(SocketOutputStream.java:159)
> at org.apache.activemq.transport.tcp.TcpBufferedOutputStream.wr
> ite(TcpBufferedOutputStream.java:96)
> at java.io.DataOutputStream.write(DataOutputStream.java:107)
> at org.apache.activemq.openwire.v12.BaseDataStreamMarshaller.ti
> ghtMarshalByteSequence2(BaseDataStreamMarshaller.java:431)
> at org.apache.activemq.openwire.v12.MessageMarshaller.tightMars
> hal2(MessageMarshaller.java:182)
> at org.apache.activemq.openwire.v12.ActiveMQMessageMarshaller.t
> ightMarshal2(ActiveMQMessageMarshaller.java:89)
> at org.apache.activemq.openwire.v12.ActiveMQObjectMessageMarsha
> ller.tightMarshal2(ActiveMQObjectMessageMarshaller.java:89)
> at org.apache.activemq.openwire.OpenWireFormat.marshal(OpenWire
> Format.java:235)
> at org.apache.activemq.transport.tcp.TcpTransport.oneway(TcpTra
> nsport.java:193)
> at org.apache.activemq.transport.AbstractInactivityMonitor.doOn
> ewaySend(AbstractInactivityMonitor.java:335)
> at org.apache.activemq.transport.AbstractInactivityMonitor.onew
> ay(AbstractInactivityMonitor.java:317)
> at org.apache.activemq.transport.TransportFilter.oneway(Transpo
> rtFilter.java:94)
> at org.apache.activemq.transport.WireFormatNegotiator.oneway(Wi
> reFormatNegotiator.java:116)
> at org.apache.activemq.transport.failover.FailoverTransport.one
> way(FailoverTransport.java:668)
>
>
