Return-Path: X-Original-To: apmail-activemq-dev-archive@www.apache.org Delivered-To: apmail-activemq-dev-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id C0F94C07C for ; Tue, 30 Dec 2014 06:31:13 +0000 (UTC) Received: (qmail 7144 invoked by uid 500); 30 Dec 2014 06:31:13 -0000 Delivered-To: apmail-activemq-dev-archive@activemq.apache.org Received: (qmail 7078 invoked by uid 500); 30 Dec 2014 06:31:13 -0000 Mailing-List: contact dev-help@activemq.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@activemq.apache.org Delivered-To: mailing list dev@activemq.apache.org Received: (qmail 7066 invoked by uid 99); 30 Dec 2014 06:31:13 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 30 Dec 2014 06:31:13 +0000 Date: Tue, 30 Dec 2014 06:31:13 +0000 (UTC) From: "siddeshwar_hiremath (JIRA)" To: dev@activemq.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Comment Edited] (AMQ-4986) tightEncoding=false + failover triggers Broker memory exhaust MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/AMQ-4986?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14260850#comment-14260850 ] siddeshwar_hiremath edited comment on AMQ-4986 at 12/30/14 6:30 AM: -------------------------------------------------------------------- Broker version 5.10.0 Client version 5.10.0 activemq.xml:- Client broker url:- failover:(nio:// 127.0.0.1:61616?keepAlive=true&wireFormat.maxFrameSize=104857600)?jms.blobTransferPolicy.defaultUploadUrl=http://127.0.0.1:8161/fileserver/&initialReconnectDelay=10000&useExponentialBackOff=false&randomize=false I have the above setting and experiencing following error:- nio protocol:- --------------- 2014-12-29 11:52:43,145 | DEBUG | Sending: WireFormatInfo { version=10, properties={MaxFrameSize=9223372036854775807, 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]} | org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ BrokerService[localhost] Task-4 2014-12-29 11:52:43,591 | DEBUG | Transport Connection to: tcp://127.0.0.1:51048 failed: java.io.IOException: Java heap space | org.apache.activemq.broker.TransportConnection.Transport | ActiveMQ NIO Worker 5 java.io.IOException: Java heap space at org.apache.activemq.util.IOExceptionSupport.create(IOExceptionSupport.java:39)[activemq-client-5.10.0.jar:5.10.0] at org.apache.activemq.transport.nio.NIOTransport.serviceRead(NIOTransport.java:151)[activemq-client-5.10.0.jar:5.10.0] at org.apache.activemq.transport.nio.NIOTransport$1.onSelect(NIOTransport.java:69)[activemq-client-5.10.0.jar:5.10.0] at org.apache.activemq.transport.nio.SelectorSelection.onSelect(SelectorSelection.java:94)[activemq-client-5.10.0.jar:5.10.0] at org.apache.activemq.transport.nio.SelectorWorker$1.run(SelectorWorker.java:119)[activemq-client-5.10.0.jar:5.10.0] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)[:1.7.0_40] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)[:1.7.0_40] at java.lang.Thread.run(Thread.java:724)[:1.7.0_40] 2014-12-29 11:52:43,592 | DEBUG | Unregistering MBean org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=nio_//localhost_61616&qe;transport.keepAlive&true&transport.wireFormat.maxFrameSize&104857600,connectionViewType=remoteAddress,connectionName=tcp_//127.0.0.1_51048 | org.apache.activemq.broker.jmx.ManagementContext | ActiveMQ NIO Worker 5 2014-12-29 11:52:43,605 | DEBUG | Stopping connection: tcp://127.0.0.1:51048 | org.apache.activemq.broker.TransportConnection | ActiveMQ BrokerService[localhost] Task-5 2014-12-29 11:52:43,609 | DEBUG | Stopping transport tcp:///127.0.0.1:51048@61616 | org.apache.activemq.transport.tcp.TcpTransport | ActiveMQ BrokerService[localhost] Task-5 2014-12-29 11:52:43,609 | DEBUG | Initialized TaskRunnerFactory[ActiveMQ Task] using ExecutorService: null | org.apache.activemq.thread.TaskRunnerFactory | ActiveMQ BrokerService[localhost] Task-5 2014-12-29 11:52:43,614 | DEBUG | Closed socket Socket[unconnected] | org.apache.activemq.transport.tcp.TcpTransport | ActiveMQ Task-1 2014-12-29 11:52:43,614 | DEBUG | Stopped transport: null | org.apache.activemq.broker.TransportConnection | ActiveMQ BrokerService[localhost] Task-5 2014-12-29 11:52:43,614 | DEBUG | Connection Stopped: null | org.apache.activemq.broker.TransportConnection | ActiveMQ BrokerService[localhost] Task-5 ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- With tcp protocol:- --------------------- ityDurationInitalDelay=10000, TcpNoDelayEnabled=true, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} | org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ BrokerService[localhost] Task-8 2014-12-29 11:22:42,797 | DEBUG | Transport Connection to: tcp://127.0.0.1:39382 failed: java.io.IOException: Unknown data type: 13 | org.apache.activemq.broker.TransportConnection.Transport | ActiveMQ Transport: tcp:///127.0.0.1:39382@61616 java.io.IOException: Unknown data type: 13 at org.apache.activemq.openwire.OpenWireFormat.looseUnmarshalNestedObject(OpenWireFormat.java:460)[activemq-client-5.10.0.jar:5.10.0] at org.apache.activemq.openwire.v10.BaseDataStreamMarshaller.looseUnmarsalNestedObject(BaseDataStreamMarshaller.java:466)[activemq-client-5.10.0.jar:5.10.0] at org.apache.activemq.openwire.v10.DataResponseMarshaller.looseUnmarshal(DataResponseMarshaller.java:113)[activemq-client-5.10.0.jar:5.10.0] at org.apache.activemq.openwire.OpenWireFormat.doUnmarshal(OpenWireFormat.java:356)[activemq-client-5.10.0.jar:5.10.0] at org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:268)[activemq-client-5.10.0.jar:5.10.0] at org.apache.activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.java:221)[activemq-client-5.10.0.jar:5.10.0] at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:213)[activemq-client-5.10.0.jar:5.10.0] at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)[activemq-client-5.10.0.jar:5.10.0] at java.lang.Thread.run(Thread.java:724)[:1.7.0_40] 2014-12-29 11:22:42,799 | DEBUG | Unregistering MBean org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=tcp_//localhost_61616&qe;transport.keepAlive&true&transport.wireFormat.maxFrameSize&104857600,connectionViewType=remoteAddress,connectionName=tcp_//127.0.0.1_39382 | org.apache.activemq.broker.jmx.ManagementContext | ActiveMQ Transport: tcp:///127.0.0.1:39382@61616 2014-12-29 11:22:42,804 | DEBUG | Stopping connection: tcp://127.0.0.1:39382 | org.apache.activemq.broker.TransportConnection | ActiveMQ BrokerService[localhost] Task-9 2014-12-29 11:22:42,805 | DEBUG | Stopping transport tcp:///127.0.0.1:39382@61616 | org.apache.activemq.transport.tcp.TcpTransport | ActiveMQ BrokerService[localhost] Task-9 2014-12-29 11:22:42,805 | DEBUG | Initialized TaskRunnerFactory[ActiveMQ Task] using ExecutorService: null | org.apache.activemq.thread.TaskRunnerFactory | ActiveMQ BrokerService[localhost] Task-9 2014-12-29 11:22:42,807 | DEBUG | Closed socket Socket[addr=/127.0.0.1,port=39382,localport=61616] | org.apache.activemq.transport.tcp.TcpTransport | ActiveMQ Task-1 2014-12-29 11:22:42,808 | DEBUG | Stopped transport: tcp://127.0.0.1:39382 | org.apache.activemq.broker.TransportConnection | ActiveMQ BrokerService[localhost] Task-9 2014-12-29 11:22:42,809 | DEBUG | Connection Stopped: tcp://127.0.0.1:39382 | org.apache.activemq.broker.TransportConnection | ActiveMQ BrokerService[localhost] Task-9 was (Author: siddeshwar_hiremath): Made following change:- activemq.xml:- connection.uri=nio://localhost:61616 Client broker url:- failover:(nio:// 127.0.0.1:61616?keepAlive=true&wireFormat.maxFrameSize=104857600)?jms.blobTransferPolicy.defaultUploadUrl=http://127.0.0.1:8161/fileserver/&initialReconnectDelay=10000&useExponentialBackOff=false&randomize=false I have the above setting and experiencing following error:- nio protocol:- --------------- 2014-12-29 11:52:43,145 | DEBUG | Sending: WireFormatInfo { version=10, properties={MaxFrameSize=9223372036854775807, 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]} | org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ BrokerService[localhost] Task-4 2014-12-29 11:52:43,591 | DEBUG | Transport Connection to: tcp://127.0.0.1:51048 failed: java.io.IOException: Java heap space | org.apache.activemq.broker.TransportConnection.Transport | ActiveMQ NIO Worker 5 java.io.IOException: Java heap space at org.apache.activemq.util.IOExceptionSupport.create(IOExceptionSupport.java:39)[activemq-client-5.10.0.jar:5.10.0] at org.apache.activemq.transport.nio.NIOTransport.serviceRead(NIOTransport.java:151)[activemq-client-5.10.0.jar:5.10.0] at org.apache.activemq.transport.nio.NIOTransport$1.onSelect(NIOTransport.java:69)[activemq-client-5.10.0.jar:5.10.0] at org.apache.activemq.transport.nio.SelectorSelection.onSelect(SelectorSelection.java:94)[activemq-client-5.10.0.jar:5.10.0] at org.apache.activemq.transport.nio.SelectorWorker$1.run(SelectorWorker.java:119)[activemq-client-5.10.0.jar:5.10.0] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)[:1.7.0_40] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)[:1.7.0_40] at java.lang.Thread.run(Thread.java:724)[:1.7.0_40] 2014-12-29 11:52:43,592 | DEBUG | Unregistering MBean org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=nio_//localhost_61616&qe;transport.keepAlive&true&transport.wireFormat.maxFrameSize&104857600,connectionViewType=remoteAddress,connectionName=tcp_//127.0.0.1_51048 | org.apache.activemq.broker.jmx.ManagementContext | ActiveMQ NIO Worker 5 2014-12-29 11:52:43,605 | DEBUG | Stopping connection: tcp://127.0.0.1:51048 | org.apache.activemq.broker.TransportConnection | ActiveMQ BrokerService[localhost] Task-5 2014-12-29 11:52:43,609 | DEBUG | Stopping transport tcp:///127.0.0.1:51048@61616 | org.apache.activemq.transport.tcp.TcpTransport | ActiveMQ BrokerService[localhost] Task-5 2014-12-29 11:52:43,609 | DEBUG | Initialized TaskRunnerFactory[ActiveMQ Task] using ExecutorService: null | org.apache.activemq.thread.TaskRunnerFactory | ActiveMQ BrokerService[localhost] Task-5 2014-12-29 11:52:43,614 | DEBUG | Closed socket Socket[unconnected] | org.apache.activemq.transport.tcp.TcpTransport | ActiveMQ Task-1 2014-12-29 11:52:43,614 | DEBUG | Stopped transport: null | org.apache.activemq.broker.TransportConnection | ActiveMQ BrokerService[localhost] Task-5 2014-12-29 11:52:43,614 | DEBUG | Connection Stopped: null | org.apache.activemq.broker.TransportConnection | ActiveMQ BrokerService[localhost] Task-5 ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- With tcp protocol:- --------------------- ityDurationInitalDelay=10000, TcpNoDelayEnabled=true, MaxInactivityDuration=30000, TightEncodingEnabled=true, StackTraceEnabled=true}, magic=[A,c,t,i,v,e,M,Q]} | org.apache.activemq.transport.WireFormatNegotiator | ActiveMQ BrokerService[localhost] Task-8 2014-12-29 11:22:42,797 | DEBUG | Transport Connection to: tcp://127.0.0.1:39382 failed: java.io.IOException: Unknown data type: 13 | org.apache.activemq.broker.TransportConnection.Transport | ActiveMQ Transport: tcp:///127.0.0.1:39382@61616 java.io.IOException: Unknown data type: 13 at org.apache.activemq.openwire.OpenWireFormat.looseUnmarshalNestedObject(OpenWireFormat.java:460)[activemq-client-5.10.0.jar:5.10.0] at org.apache.activemq.openwire.v10.BaseDataStreamMarshaller.looseUnmarsalNestedObject(BaseDataStreamMarshaller.java:466)[activemq-client-5.10.0.jar:5.10.0] at org.apache.activemq.openwire.v10.DataResponseMarshaller.looseUnmarshal(DataResponseMarshaller.java:113)[activemq-client-5.10.0.jar:5.10.0] at org.apache.activemq.openwire.OpenWireFormat.doUnmarshal(OpenWireFormat.java:356)[activemq-client-5.10.0.jar:5.10.0] at org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:268)[activemq-client-5.10.0.jar:5.10.0] at org.apache.activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.java:221)[activemq-client-5.10.0.jar:5.10.0] at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:213)[activemq-client-5.10.0.jar:5.10.0] at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196)[activemq-client-5.10.0.jar:5.10.0] at java.lang.Thread.run(Thread.java:724)[:1.7.0_40] 2014-12-29 11:22:42,799 | DEBUG | Unregistering MBean org.apache.activemq:type=Broker,brokerName=localhost,connector=clientConnectors,connectorName=tcp_//localhost_61616&qe;transport.keepAlive&true&transport.wireFormat.maxFrameSize&104857600,connectionViewType=remoteAddress,connectionName=tcp_//127.0.0.1_39382 | org.apache.activemq.broker.jmx.ManagementContext | ActiveMQ Transport: tcp:///127.0.0.1:39382@61616 2014-12-29 11:22:42,804 | DEBUG | Stopping connection: tcp://127.0.0.1:39382 | org.apache.activemq.broker.TransportConnection | ActiveMQ BrokerService[localhost] Task-9 2014-12-29 11:22:42,805 | DEBUG | Stopping transport tcp:///127.0.0.1:39382@61616 | org.apache.activemq.transport.tcp.TcpTransport | ActiveMQ BrokerService[localhost] Task-9 2014-12-29 11:22:42,805 | DEBUG | Initialized TaskRunnerFactory[ActiveMQ Task] using ExecutorService: null | org.apache.activemq.thread.TaskRunnerFactory | ActiveMQ BrokerService[localhost] Task-9 2014-12-29 11:22:42,807 | DEBUG | Closed socket Socket[addr=/127.0.0.1,port=39382,localport=61616] | org.apache.activemq.transport.tcp.TcpTransport | ActiveMQ Task-1 2014-12-29 11:22:42,808 | DEBUG | Stopped transport: tcp://127.0.0.1:39382 | org.apache.activemq.broker.TransportConnection | ActiveMQ BrokerService[localhost] Task-9 2014-12-29 11:22:42,809 | DEBUG | Connection Stopped: tcp://127.0.0.1:39382 | org.apache.activemq.broker.TransportConnection | ActiveMQ BrokerService[localhost] Task-9 > tightEncoding=false + failover triggers Broker memory exhaust > ------------------------------------------------------------- > > Key: AMQ-4986 > URL: https://issues.apache.org/jira/browse/AMQ-4986 > Project: ActiveMQ > Issue Type: Bug > Components: Broker > Affects Versions: 5.6.0, 5.7.0, 5.8.0, 5.9.0 > Environment: java 1.7 > Client library 5.5.1 > Reporter: Felix Ehm > Fix For: NEEDS_REVIEW > > > We experience this problem in combination with 5.5.1 client and the wireformat.tightEncodingEnabled=false+ failover: > Scenario: > 1. start standard broker > 2. start Client (with e.g. a MessageListener) with failover protocol: e.g. failover:(tcp://123.123.123.123:61616?wireformat.tightEncodingEnabled=false) > 3. wait around 30sec (default for inactivity check) > Result: > The client closes the connection and re-tries to the broker which in turn throws the following exception: > {code} > 2014-01-21 20:12:49,568 [ActiveMQ Transport: tcp:///123.123.123.123:60156@61616] DEBUG Transport Transport Connection to: tcp://124.124.124.124:60156 failed: java.io.IOException: Unexpected error occured: java.lang.OutOfMemoryError: Java heap space > java.io.IOException: Unexpected error occured: java.lang.OutOfMemoryError: Java heap space > at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:203) > at java.lang.Thread.run(Thread.java:722) > Caused by: java.lang.OutOfMemoryError: Java heap space > at org.apache.activemq.openwire.v8.BaseDataStreamMarshaller.looseUnmarshalByteSequence(BaseDataStreamMarshaller.java:638) > at org.apache.activemq.openwire.v8.WireFormatInfoMarshaller.looseUnmarshal(WireFormatInfoMarshaller.java:132) > at org.apache.activemq.openwire.OpenWireFormat.doUnmarshal(OpenWireFormat.java:373) > at org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:285) > at org.apache.activemq.transport.tcp.TcpTransport.readCommand(TcpTransport.java:221) > at org.apache.activemq.transport.tcp.TcpTransport.doRun(TcpTransport.java:213) > at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:196) > ... 1 more > {code} > The problem here is that the BaseDataStreamMarshaller reads an int from the buffer and re-uses it immediately to allocate a byte array: > {code} > protected byte[] looseUnmarshalByteArray(DataInput dataIn) throws IOException { > byte rc[] = null; > if (dataIn.readBoolean()) { > int size = dataIn.readInt(); > rc = new byte[size]; // PROBLEM! What happens if size has been read and interpreted wrongly ? > dataIn.readFully(rc); > } > return rc; > } > {code} > In our case the dadaIn.readInt() read an int number of 785.477.224 which triggers the broker to allocate blindly this amount of mem. > We do not know yet what triggers the wrong byte sequence from the client, but on the brokers side, there should be a protection against this case. -- This message was sent by Atlassian JIRA (v6.3.4#6332)