activemq-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Timothy Bish <tabish...@gmail.com>
Subject Re: ActiveMQBytesMessage decompress throws DataFormatException incorrect header check
Date Thu, 21 Jan 2016 16:23:36 GMT
There have been no reports of such an error, if you can isolate the case
into a JUnit test I'd recommend opening a new JIRA issue and attaching
it there.

On 01/21/2016 11:18 AM, Claudio Tagliola wrote:
> We are trying to upgrade our ActiveMQ dependency from 5.8.0 to
> something newer. In our environment, we use an embedded broker with
> useCompression set to true. After the upgrade to any version after
> 5.9.1, we see some unfortunate side effects on a test client which is
> listening on a topic where ActiveMQBytesMessages are posted. The
> following exception is thrown while running a test suite which
> publishes around 100k ActiveMQBytesMessages on a non persistent topic.
> It is very reproducible on about 95% of all runs, but only once or
> maybe a few times per run:
>
> 11:04:21.075 [ActiveMQ Session Task-1] ERROR 
> o.a.activemq.ActiveMQMessageConsumer -
> ID:hostname-43481-1453197809985-15:1:12:1 Exception while processing
> message: ID:hostname-57271-1453197780850-6:2:1:3:95106
> java.lang.RuntimeException: Failed to deserialize a message
> (ActiveMQBytesMessage {commandId = 3702, responseRequired = false,
> messageId = ID:office388-44548-1453286940386-5:1:1:3:1229,
> originalDestination = null, originalTransactionId = null, producerId =
> ID:office388-44548-1453286940386-5:1:1:3, destination =
> topic://com.foo.bar, transactionId = null, expiration = 1453287566063,
> timestamp = 1453286966063, arrival = 0, brokerInTime = 1453286966064,
> brokerOutTime = 1453286966064, correlationId = null, replyTo = null,
> persistent = false, type = null, priority = 4, groupID = null,
> groupSequence = 0, targetConsumerId = null, compressed = true, userID
> = null, content = org.apache.activemq.util.ByteSequence@7ec950bb,
> marshalledProperties = org.apache.activemq.util.ByteSequence@3e90d35e,
> dataStructure = null, redeliveryCounter = 0, size = 0, properties =
> {mapped=1453286966034, received=1453286965865, source=3,
> published=1453286959733, type=TEST, class=2884, party=TEST},
> readOnlyProperties = true, readOnlyBody = true, droppable = false,
> jmsXGroupFirstForConsumer = false} ActiveMQBytesMessage{ bytesOut =
> null, dataOut = null, dataIn = null }).
>        at
> com.foo.bar.PersistEntityMessageHandlerServiceListener.onMessage(PersistEntityMessageHandlerServiceListener.java:57)
> ~[foobar.jar:amq513-SNAPSHOT]
>        at
> org.apache.activemq.ActiveMQMessageConsumer.dispatch(ActiveMQMessageConsumer.java:1393)
> ~[activemq-client.jar:5.13.0]
>        at
> org.apache.activemq.ActiveMQSessionExecutor.dispatch(ActiveMQSessionExecutor.java:131)
> [activemq-client.jar:5.13.0]
>        at
> org.apache.activemq.ActiveMQSessionExecutor.iterate(ActiveMQSessionExecutor.java:202)
> [activemq-client.jar:5.13.0]
>        at
> org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:133)
> [activemq-client.jar:5.13.0]
>        at
> org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:48)
> [activemq-client.jar:5.13.0]
>        at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> [na:1.8.0_45]
>        at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> [na:1.8.0_45]
>        at java.lang.Thread.run(Thread.java:745) [na:1.8.0_45]
> Caused by: javax.jms.JMSException: java.util.zip.DataFormatException:
> incorrect header check
>        at
> org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:72)
> ~[activemq-client.jar:5.13.0]
>        at
> org.apache.activemq.command.ActiveMQBytesMessage.initializeReading(ActiveMQBytesMessage.java:884)
> ~[activemq-client.jar:5.13.0]
>        at
> org.apache.activemq.command.ActiveMQBytesMessage.getBodyLength(ActiveMQBytesMessage.java:198)
> ~[activemq-client.jar:5.13.0]
>        at
> com.foo.bar.JmsSerializerHelper.deserialize(JmsSerializerHelper.java:52)
> ~[foobar-client.jar:1761]
>        at
> com.foo.bar.PersistEntityMessageHandlerServiceListener.onMessage(PersistEntityMessageHandlerServiceListener.java:53)
> ~[foobar.jar:amq513-SNAPSHOT]
>        ... 8 common frames omitted
> Caused by: java.io.IOException: java.util.zip.DataFormatException:
> incorrect header check
>        at
> org.apache.activemq.command.ActiveMQBytesMessage.decompress(ActiveMQBytesMessage.java:902)
> ~[activemq-client.jar:5.13.0]
>        at
> org.apache.activemq.command.ActiveMQBytesMessage.initializeReading(ActiveMQBytesMessage.java:876)
> ~[activemq-client.jar:5.13.0]
>        ... 11 common frames omitted
> Caused by: java.util.zip.DataFormatException: incorrect header check
>        at java.util.zip.Inflater.inflateBytes(Native Method)
> ~[na:1.8.0_45]
>        at java.util.zip.Inflater.inflate(Inflater.java:259)
> ~[na:1.8.0_45]
>        at java.util.zip.Inflater.inflate(Inflater.java:280)
> ~[na:1.8.0_45]
>        at
> org.apache.activemq.command.ActiveMQBytesMessage.decompress(ActiveMQBytesMessage.java:898)
> ~[activemq-client.jar:5.13.0]
>        ... 12 common frames omitted
>
> In one occasion, a different cause was shown:
>
> Caused by: java.lang.NegativeArraySizeException: null
>        at
> org.apache.activemq.command.ActiveMQBytesMessage.decompress(ActiveMQBytesMessage.java:897)
> ~[activemq-client.jar:5.13.0]
>
> I have reproduced this with 5.10.0, 5.10.1, 5.10.2, 5.11.3 and 5.13.0.
> It is not reproducible on 5.8.0 (our current version) and 5.9.1. The
> stacktrace on 5.10.0 is slightly different:
>
> java.lang.RuntimeException: Failed to deserialize a message
> (ActiveMQBytesMessage {commandId = 3702, responseRequired = false,
> messageId = ID:office388-44548-1453286940386-5:1:1:3:1229,
> originalDestination = null, originalTransactionId = null, producerId =
> ID:office388-44548-1453286940386-5:1:1:3, destination =
> topic://com.foo.bar, transactionId = null, expiration = 1453287566063,
> timestamp = 1453286966063, arrival = 0, brokerInTime = 1453286966064,
> brokerOutTime = 1453286966064, correlationId = null, replyTo = null,
> persistent = false, type = null, priority = 4, groupID = null,
> groupSequence = 0, targetConsumerId = null, compressed = true, userID
> = null, content = org.apache.activemq.util.ByteSequence@7ec950bb,
> marshalledProperties = org.apache.activemq.util.ByteSequence@3e90d35e,
> dataStructure = null, redeliveryCounter = 0, size = 0, properties =
> {mapped=1453286966034, received=1453286965865, source=3,
> published=1453286959733, type=TEST, class=2884, party=TEST},
> readOnlyProperties = true, readOnlyBody = true, droppable = false,
> jmsXGroupFirstForConsumer = false} ActiveMQBytesMessage{ bytesOut =
> null, dataOut = null, dataIn = null })
>    at
> com.foo.bar.PersistEntityMessageHandlerServiceListener.onMessage(PersistEntityMessageHandlerServiceListener.java:57)
> ~[classes/:na]
>    at
> org.apache.activemq.ActiveMQMessageConsumer.dispatch(ActiveMQMessageConsumer.java:1390)
> ~[activemq-client-5.10.0.jar:5.10.0]
>    at
> org.apache.activemq.ActiveMQSessionExecutor.dispatch(ActiveMQSessionExecutor.java:131)
> [activemq-client-5.10.0.jar:5.10.0]
>    at
> org.apache.activemq.ActiveMQSessionExecutor.iterate(ActiveMQSessionExecutor.java:202)
> [activemq-client-5.10.0.jar:5.10.0]
>    at
> org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:133)
> [activemq-client-5.10.0.jar:5.10.0]
>    at
> org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:48)
> [activemq-client-5.10.0.jar:5.10.0]
>    at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> [na:1.8.0_66]
>    at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> [na:1.8.0_66]
>    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_66]
> Caused by: javax.jms.JMSException: java.lang.NegativeArraySizeException
>    at
> org.apache.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:72)
> ~[activemq-client-5.10.0.jar:5.10.0]
>    at
> org.apache.activemq.command.ActiveMQBytesMessage.initializeReading(ActiveMQBytesMessage.java:890)
> ~[activemq-client-5.10.0.jar:5.10.0]
>    at
> org.apache.activemq.command.ActiveMQBytesMessage.getBodyLength(ActiveMQBytesMessage.java:199)
> ~[activemq-client-5.10.0.jar:5.10.0]
>    at
> com.foo.ba.rJmsSerializerHelper.deserialize(JmsSerializerHelper.java:52)
> ~[foundations-rpc-client-70.1761.jar:70.1761]
>    at
> com.foo.bar.PersistEntityMessageHandlerServiceListener.onMessage(PersistEntityMessageHandlerServiceListener.java:53)
> ~[classes/:na]
>    ... 8 common frames omitted
> Caused by: java.io.IOException: java.lang.NegativeArraySizeException
>    at
> org.apache.activemq.command.ActiveMQBytesMessage.decompress(ActiveMQBytesMessage.java:908)
> ~[activemq-client-5.10.0.jar:5.10.0]
>    at
> org.apache.activemq.command.ActiveMQBytesMessage.initializeReading(ActiveMQBytesMessage.java:882)
> ~[activemq-client-5.10.0.jar:5.10.0]
>    ... 11 common frames omitted
> Caused by: java.lang.NegativeArraySizeException: null
>    at
> org.apache.activemq.command.ActiveMQBytesMessage.decompress(ActiveMQBytesMessage.java:903)
> ~[activemq-client-5.10.0.jar:5.10.0]
>    ... 12 common frames omitted
>
> This points me towards
> AMQ-4887<https://issues.apache.org/jira/browse/AMQ-4887> and
> AMQ-5381<https://issues.apache.org/jira/browse/AMQ-5381> which
> correlate with the versions when it starts failing and the code
> changes that have been made in ActiveMQBytesMessage.
>
> Halting the process with a debugger does not give me much extra
> information, there is content in the Inflater buffer, but the native
> method Inflater.inflateBytes just throws the exception. Both client
> and server are running on the same machine, same JDK. Running with
> 1.8.0_66 has the same effect. What I did see was that the actual
> compressed bytes at that point were different between what the server
> sent and what the client received, which points to client side buffer
> corruption. Both the compress on the server side as well as the
> decompress methods were always called from the same thread, so there
> does not seem to be a multi-threaded race condition at that location,
> although it might be somewhere else in the stack.
>
> Disabling compression on the server side will make the error go away.
> I have not found any other flag that has effect on this yet.
>
> I could not find any recent issues logged, is this something other
> people also encountered? I'm currently trying to isolate the code and
> create a test setup, but that's quite an undertaking so please bear
> with me.
>
> Thank you,
> Claudio
>
> ________________________________
>
> The information in this e-mail is intended only for the person or
> entity to which it is addressed.
>
> It may contain confidential and /or privileged material. If someone
> other than the intended recipient should receive this e-mail, he / she
> shall not be entitled to read, disseminate, disclose or duplicate it.
>
> If you receive this e-mail unintentionally, please inform us
> immediately by "reply" and then delete it from your system. Although
> this information has been compiled with great care, neither IMC
> Financial Markets & Asset Management nor any of its related entities
> shall accept any responsibility for any errors, omissions or other
> inaccuracies in this information or for the consequences thereof, nor
> shall it be bound in any way by the contents of this e-mail or its
> attachments. In the event of incomplete or incorrect transmission,
> please return the e-mail to the sender and permanently delete this
> message and any attachments.
>
> Messages and attachments are scanned for all known viruses. Always
> scan attachments before opening them.
>


-- 
Tim Bish
twitter: @tabish121
blog: http://timbish.blogspot.com/


Mime
View raw message