activemq-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Ernest Wallace (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (AMQ-4050) Broker unable to distribute messages to consumers with NegativeArraySizeException loading message from JDBC Persistence
Date Fri, 14 Sep 2012 21:20:07 GMT

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

Ernest Wallace commented on AMQ-4050:
-------------------------------------

I stepped through the code and found the following scenario:
MessageMarshaller calls Message.setMarshalledProperties(looseUnmarshalByteSequence(dataIn)
Line 229

dataIn is a DataByteArrayInputStream which in this case is 65535 in length with a private
pos == 65535

readInt is used to get the size to set a local byte[] but readInt returns -16843009 based
on the fact that read() returns -1 since the end of the stream has been reached.

It would appear that the message is incomplete in the queue (corrupt) and the reading fails.

My guess is that readInt should understand when the end of the stream has been reached and
fail gracefully.

This would provide some level of corrupt message handling to protect the broker. 

I believe that the corrupt message get there to begin with due to an environmental issue.
 ie. two brokers trying to access the same message store.  This fix would nevertheless protect
the Broker from failing to distribute messages.

The fix to our production environment was just to delete the message from the ACTIVEMQ_MSGS
tables.  Once the message was removed the Broker started delivering messages about a minute
later.


                
> Broker unable to distribute messages to consumers with NegativeArraySizeException loading
message from JDBC Persistence
> -----------------------------------------------------------------------------------------------------------------------
>
>                 Key: AMQ-4050
>                 URL: https://issues.apache.org/jira/browse/AMQ-4050
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.5.1
>         Environment: Broker is running in JVM via java code initialization.  JDBC Persistence
Adapter to MySQL database.  Production is CentOS.  Replicable on MacOS 10.7, Java 1.6.0_35,
5.1.63 MySQL Community Server 
>            Reporter: Ernest Wallace
>         Attachments: ACTIVEMQ_MSGS.sql
>
>
> When trying to distribute messages to consumers a corrupted message causes the Broker
to stall and stop distributing messages with a NegativeArraySizeException.  While the broker
can no longer distribute messages it does in fact accept them and properly persists them to
the queue.  Attached is a sql dump of ACTIVEMQ_MSGS with the offending message to reproduce.
> StackTrace while running:
> [07:33:46:882]|[09-13-2012]|[SYSOUT]|[INFO]|[122]|: java.lang.NegativeArraySizeException|
> [07:33:46:882]|[09-13-2012]|[SYSOUT]|[INFO]|[122]|:     at org.apache.activemq.openwire.v6.BaseDataStreamMarshaller.looseUnmarshalByteSequence(BaseDataStreamMarshaller.java:639)|
> [07:33:46:882]|[09-13-2012]|[SYSOUT]|[INFO]|[122]|:     at org.apache.activemq.openwire.v6.MessageMarshaller.looseUnmarshal(MessageMarshaller.java:229)|
> [07:33:46:882]|[09-13-2012]|[SYSOUT]|[INFO]|[122]|:     at org.apache.activemq.openwire.v6.ActiveMQMessageMarshaller.looseUnmarshal(ActiveMQMessageMarshaller.java:101)|
> [07:33:46:882]|[09-13-2012]|[SYSOUT]|[INFO]|[122]|:     at org.apache.activemq.openwire.v6.ActiveMQTextMessageMarshaller.looseUnmarshal(ActiveMQTextMessageMarshaller.java:101)|
> [07:33:46:882]|[09-13-2012]|[SYSOUT]|[INFO]|[122]|:     at org.apache.activemq.openwire.OpenWireFormat.doUnmarshal(OpenWireFormat.java:364)|
> [07:33:46:882]|[09-13-2012]|[SYSOUT]|[INFO]|[122]|:     at org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:204)|
> [07:33:46:883]|[09-13-2012]|[SYSOUT]|[INFO]|[122]|:     at org.apache.activemq.store.jdbc.JDBCMessageStore$2.recoverMessage(JDBCMessageStore.java:256)|
> [07:33:46:883]|[09-13-2012]|[SYSOUT]|[INFO]|[122]|:     at org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter.doRecoverNextMessages(DefaultJDBCAdapter.java:938)|
> [07:33:46:883]|[09-13-2012]|[SYSOUT]|[INFO]|[122]|:     at org.apache.activemq.store.jdbc.JDBCMessageStore.recoverNextMessages(JDBCMessageStore.java:251)|
> [07:33:46:883]|[09-13-2012]|[SYSOUT]|[INFO]|[122]|:     at org.apache.activemq.store.ProxyMessageStore.recoverNextMessages(ProxyMessageStore.java:88)|
> [07:33:46:883]|[09-13-2012]|[SYSOUT]|[INFO]|[122]|:     at org.apache.activemq.broker.region.cursors.QueueStorePrefetch.doFillBatch(QueueStorePrefetch.java:97)|
> [07:33:46:883]|[09-13-2012]|[SYSOUT]|[INFO]|[122]|:     at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.fillBatch(AbstractStoreCursor.java:260)|
> [07:33:46:883]|[09-13-2012]|[SYSOUT]|[INFO]|[122]|:     at org.apache.activemq.broker.region.cursors.AbstractStoreCursor.reset(AbstractStoreCursor.java:108)|
> [07:33:46:883]|[09-13-2012]|[SYSOUT]|[INFO]|[122]|:     at org.apache.activemq.broker.region.cursors.StoreQueueCursor.reset(StoreQueueCursor.java:157)|
> [07:33:46:883]|[09-13-2012]|[SYSOUT]|[INFO]|[122]|:     at org.apache.activemq.broker.region.Queue.doPageInForDispatch(Queue.java:1712)|
> [07:33:46:883]|[09-13-2012]|[SYSOUT]|[INFO]|[122]|:     at org.apache.activemq.broker.region.Queue.pageInMessages(Queue.java:1932)|
> [07:33:46:883]|[09-13-2012]|[SYSOUT]|[INFO]|[122]|:     at org.apache.activemq.broker.region.Queue.iterate(Queue.java:1440)|
> [07:33:46:883]|[09-13-2012]|[SYSOUT]|[INFO]|[122]|:     at org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:127)|
> [07:33:46:883]|[09-13-2012]|[SYSOUT]|[INFO]|[122]|:     at org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:48)|
> [07:33:46:883]|[09-13-2012]|[SYSOUT]|[INFO]|[122]|:     at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)|
> [07:33:46:883]|[09-13-2012]|[SYSOUT]|[INFO]|[122]|:     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)|
> [07:33:46:883]|[09-13-2012]|[SYSOUT]|[INFO]|[122]|:     at java.lang.Thread.run(Thread.java:619)|
> StackTrace on Startup:
> 11:41:47:996]|[09-14-2012]|[SYSOUT]|[INFO]|[11]|: java.lang.NegativeArraySizeException|
> [11:41:47:996]|[09-14-2012]|[SYSOUT]|[INFO]|[11]|: 	at org.apache.activemq.openwire.v6.BaseDataStreamMarshaller.looseUnmarshalByteSequence(BaseDataStreamMarshaller.java:639)|
> [11:41:47:996]|[09-14-2012]|[SYSOUT]|[INFO]|[11]|: 	at org.apache.activemq.openwire.v6.MessageMarshaller.looseUnmarshal(MessageMarshaller.java:229)|
> [11:41:47:997]|[09-14-2012]|[SYSOUT]|[INFO]|[11]|: 	at org.apache.activemq.openwire.v6.ActiveMQMessageMarshaller.looseUnmarshal(ActiveMQMessageMarshaller.java:101)|
> [11:41:47:997]|[09-14-2012]|[SYSOUT]|[INFO]|[11]|: 	at org.apache.activemq.openwire.v6.ActiveMQTextMessageMarshaller.looseUnmarshal(ActiveMQTextMessageMarshaller.java:101)|
> [11:41:47:997]|[09-14-2012]|[SYSOUT]|[INFO]|[11]|: 	at org.apache.activemq.openwire.OpenWireFormat.doUnmarshal(OpenWireFormat.java:364)|
> [11:41:47:997]|[09-14-2012]|[SYSOUT]|[INFO]|[11]|: 	at org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:204)|
> [11:41:47:997]|[09-14-2012]|[SYSOUT]|[INFO]|[11]|: 	at org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.getLastMessageBrokerSequenceId(JDBCPersistenceAdapter.java:236)|
> [11:41:47:997]|[09-14-2012]|[SYSOUT]|[INFO]|[11]|: 	at org.apache.activemq.broker.region.DestinationFactoryImpl.getLastMessageBrokerSequenceId(DestinationFactoryImpl.java:145)|
> [11:41:47:998]|[09-14-2012]|[SYSOUT]|[INFO]|[11]|: 	at org.apache.activemq.broker.region.RegionBroker.<init>(RegionBroker.java:122)|
> [11:41:47:998]|[09-14-2012]|[SYSOUT]|[INFO]|[11]|: 	at org.apache.activemq.broker.jmx.ManagedRegionBroker.<init>(ManagedRegionBroker.java:99)|
> [11:41:47:998]|[09-14-2012]|[SYSOUT]|[INFO]|[11]|: 	at org.apache.activemq.broker.BrokerService.createRegionBroker(BrokerService.java:1830)|
> [11:41:47:998]|[09-14-2012]|[SYSOUT]|[INFO]|[11]|: 	at org.apache.activemq.broker.BrokerService.createRegionBroker(BrokerService.java:1824)|
> [11:41:47:998]|[09-14-2012]|[SYSOUT]|[INFO]|[11]|: 	at org.apache.activemq.broker.BrokerService.createBroker(BrokerService.java:1781)|
> [11:41:47:998]|[09-14-2012]|[SYSOUT]|[INFO]|[11]|: 	at org.apache.activemq.broker.BrokerService.getBroker(BrokerService.java:766)|
> [11:41:47:999]|[09-14-2012]|[SYSOUT]|[INFO]|[11]|: 	at org.apache.activemq.broker.BrokerService.getAdminConnectionContext(BrokerService.java:2037)|
> [11:41:47:999]|[09-14-2012]|[SYSOUT]|[INFO]|[11]|: 	at org.apache.activemq.broker.BrokerService.startDestinations(BrokerService.java:2024)|
> [11:41:47:999]|[09-14-2012]|[SYSOUT]|[INFO]|[11]|: 	at org.apache.activemq.broker.BrokerService.start(BrokerService.java:495)|
> [11:41:47:999]|[09-14-2012]|[SYSOUT]|[INFO]|[11]|: 	at com.myapp.server.jobqueue.broker.BrokerUtils$BrokerStart.run(BrokerUtils.java:111)|
> [11:41:47:999]|[09-14-2012]|[SYSOUT]|[INFO]|[11]|: 	at java.lang.Thread.run(Thread.java:680)|

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira

Mime
View raw message