[
https://issues.apache.org/jira/browse/ARTEMIS-4993?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Arno Schuerhoff updated ARTEMIS-4993:
-------------------------------------
Description:
Our backbone application uses OpenWire client to connect to ArtemisMQ because
only ActiveMQ Classic JMS client is supported by vendor. We experience several
times in a week a message is rejected by broker with an
ActiveMQIOErrorException AMQ149005.
We found out this issue is caused by a divert with a transformer, what adds
properties to the message. If incoming message has these characteristics:
# Message is durable.
# Message is not a large message, so body shall be persisted in journal.
# Message encoded size is near journal record size.
Then if adding properties pushes message encoding size above journal record
size broker still tries to persist complete message in journal and exception
comes up.
*Steps to Reproduce the Error*
We plan to upgrade ArtemisMQ from 2.31.2 to 2.36.0. Issue on 2.36.0 is even
worser, because connection hangs if using replicating broker pair:
1.) Create primary broker:
{noformat}
apache-artemis-2.36.0\bin\artemis.cmd create --host=localhost
--default-port=61611 --http-port=8111 --clustered --cluster-user=cls
--cluster-password=cls --replicated --name=br11 --user=usr --password=usr
--allow-anonymous --no-autotune --no-amqp-acceptor --no-hornetq-acceptor
--no-mqtt-acceptor --no-stomp-acceptor br11{noformat}
2.) Create backup broker:
{noformat}
apache-artemis-2.36.0\bin\artemis.cmd create --host=localhost
--default-port=61612 --http-port=8112 --clustered --cluster-user=cls
--cluster-password=cls --replicated --backup --name=br12 --user=usr
--password=usr --allow-anonymous --no-autotune --no-amqp-acceptor
--no-hornetq-acceptor --no-mqtt-acceptor --no-stomp-acceptor br12{noformat}
3.) Start brokers
4.) Add test addresses primary broker.xml:
{code:xml}
<address name="TEST.IN">
<anycast>
<queue name="TEST.IN"/>
</anycast>
</address>
<address name="TEST.OUT">
<anycast>
<queue name="TEST.OUT"/>
</anycast>
</address>{code}
5.) Add divert with transformer to primary broker.xml:
{code:xml}
<diverts>
<divert name="TEST-DIVERT">
<address>TEST.IN</address>
<forwarding-address>TEST.OUT</forwarding-address>
<filter string="LABEL='Test'"/>
<transformer>
<class-name>org.apache.activemq.artemis.core.server.transformer.AddHeadersTransformer</class-name>
<property key="Property01" value="0123456789abcdef"/>
<property key="Property02" value="0123456789abcdef"/>
<property key="Property03" value="0123456789abcdef"/>
<property key="Property04" value="0123456789abcdef"/>
<property key="Property05" value="0123456789abcdef"/>
</transformer>
</divert>
</diverts>{code}
6.) Use this Java code to reproduce issue:
{code:java}
public class Client {
private static final Logger logger =
LoggerFactory.getLogger(MethodHandles.lookup().lookupClass());
private static final int numberChars = 250270;
public static void main(final String[] args) throws Exception {
ActiveMQConnectionFactory connectionFactory = new
ActiveMQConnectionFactory("tcp://localhost:61611");
logger.info("Connecting to tcp://localhost:61611");
Connection connection = connectionFactory.createConnection("usr",
"usr");
Session session = connection.createSession(true, 0);
Queue queue = session.createQueue("TEST.IN");
MessageProducer messageProducer = session.createProducer(queue);
StringBuilder stringBuilder = new StringBuilder();
for (int i = 0; i < numberChars; ++i) {
stringBuilder.append('x');
}
Message message = session.createTextMessage(stringBuilder.toString());
message.setStringProperty("LABEL", "Test");
logger.info("Sending message with body of {} characters to queue
TEST.IN", numberChars);
messageProducer.send(message);
session.commit();
logger.info("Cleaning...");
session.close();
connection.close();
logger.info("Done!");
}
}
{code}
I have attached Maven project,
{code:java}
mvn exec:java{code}
will compile and start that java code.
*Result*
Client connection hangs, no broker response. Log of primary broker:
{noformat}
2024-08-15 08:29:55,259 WARN [org.apache.activemq.artemis.journal] AMQ144012:
Journal Record sized at 501800, which is too close to the max record Size at
501760. Record = CoreMessage[messageID=2928, durable=true,
userID=c93af8c6-5acf-11ef-9eca-00155d1c6e82, priority=4, timestamp=Thu Aug 15
08:29:55 CEST 2024, expiration=0, durable=true, address=TEST.OUT, size=501735,
properties=TypedProperties[_AMQ_GROUP_SEQUENCE=0, Property05=0123456789abcdef,
__HDR_BROKER_IN_TIME=1723703395259, Property04=0123456789abcdef,
__HDR_COMMAND_ID=6, _AMQ_ORIG_MESSAGE_ID=2927, Property03=0123456789abcdef,
Property02=0123456789abcdef,
__HDR_MESSAGE_ID=ID:D-6T3WW14-58398-1723703395079-1:1:1:1:1,
Property01=0123456789abcdef, __HDR_DROPPABLE=false,
__AMQ_CID=ID:D-6T3WW14-58398-1723703395079-0:1, __HDR_ARRIVAL=0,
_AMQ_ORIG_QUEUE=TEST-DIVERT, _AMQ_ORIG_ROUTING_TYPE=1, LABEL=Test,
_AMQ_ORIG_ADDRESS=TEST.IN,
__HDR_PRODUCER_ID=ID:D-6T3WW14-58398-1723703395079-1:1:1:1]]@531753705.
Internal broker operations such as redistribution and DLQ may be compromised.
Move large headers into the body of messages.
2024-08-15 08:29:55,271 WARN
[org.apache.activemq.artemis.core.protocol.openwire.OpenWireConnection] Errors
occurred during the buffering operation
org.apache.activemq.artemis.api.core.ActiveMQIOErrorException: AMQ149005:
Message of 501800 bytes is bigger than the max record size of 501760 bytes. You
should try to move large application properties to the message body.
at
org.apache.activemq.artemis.core.journal.impl.JournalImpl.checkRecordSize(JournalImpl.java:1011)
~[artemis-journal-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendAddRecordTransactional(JournalImpl.java:1269)
~[artemis-journal-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.replication.ReplicatedJournal.appendAddRecordTransactional(ReplicatedJournal.java:192)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.persistence.impl.journal.AbstractJournalStorageManager.storeMessageTransactional(AbstractJournalStorageManager.java:524)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.storeDurableReference(PostOfficeImpl.java:1772)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.processRouteToDurableQueues(PostOfficeImpl.java:1752)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.processRoute(PostOfficeImpl.java:1688)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.route(PostOfficeImpl.java:1242)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.route(PostOfficeImpl.java:1136)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.server.impl.DivertImpl.route(DivertImpl.java:147)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.DivertBinding.route(DivertBinding.java:103)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.BindingsImpl.lambda$simpleRouting$0(BindingsImpl.java:418)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.CopyOnWriteBindings.forEachBindings(CopyOnWriteBindings.java:175)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.BindingsImpl.simpleRouting(BindingsImpl.java:408)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.BindingsImpl.route(BindingsImpl.java:355)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.BindingsImpl.route(BindingsImpl.java:305)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.simpleRoute(PostOfficeImpl.java:1304)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.route(PostOfficeImpl.java:1206)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.route(PostOfficeImpl.java:1136)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.doSend(ServerSessionImpl.java:2368)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.send(ServerSessionImpl.java:1963)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.send(ServerSessionImpl.java:1902)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.send(ServerSessionImpl.java:1893)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.protocol.openwire.amq.AMQSession.send(AMQSession.java:427)
~[artemis-openwire-protocol-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.protocol.openwire.OpenWireConnection$CommandProcessor.processMessage(OpenWireConnection.java:1740)
~[artemis-openwire-protocol-2.36.0.jar:2.36.0]
at
org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:769)
~[activemq-client-5.18.5.jar:5.18.5]
at
org.apache.activemq.artemis.core.protocol.openwire.OpenWireConnection.act(OpenWireConnection.java:366)
~[artemis-openwire-protocol-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.utils.actors.ThresholdActor.doTask(ThresholdActor.java:68)
~[artemis-commons-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:68)
~[artemis-commons-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:57)
~[artemis-commons-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:32)
~[artemis-commons-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:68)
~[artemis-commons-2.36.0.jar:2.36.0]
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
[?:?]
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
[?:?]
at
org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
[artemis-commons-2.36.0.jar:2.36.0]
2024-08-15 08:29:55,291 WARN
[org.apache.activemq.artemis.core.protocol.openwire.OpenWireConnection] Errors
occurred during the buffering operation
org.apache.activemq.artemis.api.core.ActiveMQException: AMQ149005: Message of
501800 bytes is bigger than the max record size of 501760 bytes. You should try
to move large application properties to the message body.
at
org.apache.activemq.artemis.core.protocol.openwire.OpenWireConnection$CommandProcessor.processMessage(OpenWireConnection.java:1743)
~[artemis-openwire-protocol-2.36.0.jar:2.36.0]
at
org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:769)
~[activemq-client-5.18.5.jar:5.18.5]
at
org.apache.activemq.artemis.core.protocol.openwire.OpenWireConnection.act(OpenWireConnection.java:366)
~[artemis-openwire-protocol-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.utils.actors.ThresholdActor.doTask(ThresholdActor.java:68)
~[artemis-commons-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:68)
~[artemis-commons-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:57)
~[artemis-commons-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:32)
~[artemis-commons-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:68)
~[artemis-commons-2.36.0.jar:2.36.0]
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
[?:?]
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
[?:?]
at
org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
[artemis-commons-2.36.0.jar:2.36.0]{noformat}
Log of backup broker:
{noformat}
2024-08-15 08:29:55,269 WARN [org.apache.activemq.artemis.journal] AMQ144012:
Journal Record sized at 501800, which is too close to the max record Size at
501760. Record =
org.apache.activemq.artemis.core.journal.impl.dataformat.ByteArrayEncoding@55dd046c.
Internal broker operations such as redistribution and DLQ may be compromised.
Move large headers into the body of messages.
2024-08-15 08:29:55,290 WARN
[org.apache.activemq.artemis.core.replication.ReplicationEndpoint] AMQ149005:
Message of 501800 bytes is bigger than the max record size of 501760 bytes. You
should try to move large application properties to the message body.
org.apache.activemq.artemis.api.core.ActiveMQIOErrorException: AMQ149005:
Message of 501800 bytes is bigger than the max record size of 501760 bytes. You
should try to move large application properties to the message body.
at
org.apache.activemq.artemis.core.journal.impl.JournalImpl.checkRecordSize(JournalImpl.java:1011)
~[artemis-journal-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendAddRecordTransactional(JournalImpl.java:1269)
~[artemis-journal-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.journal.Journal.appendAddRecordTransactional(Journal.java:188)
~[artemis-journal-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.journal.impl.JournalBase.appendAddRecordTransactional(JournalBase.java:115)
~[artemis-journal-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendAddRecordTransactional(JournalImpl.java:105)
~[artemis-journal-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.replication.ReplicationEndpoint.handleAppendAddTXRecord(ReplicationEndpoint.java:766)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.replication.ReplicationEndpoint.handlePacket(ReplicationEndpoint.java:210)
[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl.handlePacket(ChannelImpl.java:835)
[artemis-core-client-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl.doBufferReceived(RemotingConnectionImpl.java:419)
[artemis-core-client-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl.bufferReceived(RemotingConnectionImpl.java:392)
[artemis-core-client-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl$DelegatingBufferHandler.bufferReceived(ClientSessionFactoryImpl.java:1355)
[artemis-core-client-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.remoting.impl.netty.ActiveMQChannelHandler.channelRead(ActiveMQChannelHandler.java:73)
[artemis-core-client-2.36.0.jar:2.36.0]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:346)
[netty-codec-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:318)
[netty-codec-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1407)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:918)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:788)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:724)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:650)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:994)
[netty-common-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
[netty-common-4.1.112.Final.jar:4.1.112.Final]
at
org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
[artemis-commons-2.36.0.jar:2.36.0]
2024-08-15 08:29:55,300 WARN [org.apache.activemq.artemis.core.server]
AMQ222086: error handling packet ReplicationAddTXMessage[type=92, channelID=2,
responseAsync=false, requiresResponse=false, correlationID=-1] for replication
org.apache.activemq.artemis.api.core.ActiveMQIOErrorException: AMQ149005:
Message of 501800 bytes is bigger than the max record size of 501760 bytes. You
should try to move large application properties to the message body.
at
org.apache.activemq.artemis.core.journal.impl.JournalImpl.checkRecordSize(JournalImpl.java:1011)
~[artemis-journal-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendAddRecordTransactional(JournalImpl.java:1269)
~[artemis-journal-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.journal.Journal.appendAddRecordTransactional(Journal.java:188)
~[artemis-journal-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.journal.impl.JournalBase.appendAddRecordTransactional(JournalBase.java:115)
~[artemis-journal-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendAddRecordTransactional(JournalImpl.java:105)
~[artemis-journal-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.replication.ReplicationEndpoint.handleAppendAddTXRecord(ReplicationEndpoint.java:766)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.replication.ReplicationEndpoint.handlePacket(ReplicationEndpoint.java:210)
[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl.handlePacket(ChannelImpl.java:835)
[artemis-core-client-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl.doBufferReceived(RemotingConnectionImpl.java:419)
[artemis-core-client-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl.bufferReceived(RemotingConnectionImpl.java:392)
[artemis-core-client-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl$DelegatingBufferHandler.bufferReceived(ClientSessionFactoryImpl.java:1355)
[artemis-core-client-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.remoting.impl.netty.ActiveMQChannelHandler.channelRead(ActiveMQChannelHandler.java:73)
[artemis-core-client-2.36.0.jar:2.36.0]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:346)
[netty-codec-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:318)
[netty-codec-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1407)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:918)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:788)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:724)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:650)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:994)
[netty-common-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
[netty-common-4.1.112.Final.jar:4.1.112.Final]
at
org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
[artemis-commons-2.36.0.jar:2.36.0]{noformat}
Stopping backup broker frees connection to client . Output on client after
stopping backup is:
{noformat}
[client.Client.main()] INFO org.apache.activemq.TransactionContext - commit
failed for transaction TX:ID:D-6T3WW14-58398-1723703395079-1:1:1
javax.jms.JMSException: org.apache.activemq.artemis.api.core.ActiveMQException:
AMQ149005: Message of 501800 bytes is bigger than the max record size of 501760
bytes. You should try to move large application properties to the message
body.{noformat}
*Further Analysis*
1.)
This issue affects OpenWire clients only. For Core clients the parameter
_amqpMinLargeMessageSize=102400_ in acceptor configuration avoids creating such
messages on the edge as used in my example. A similar parameter for OpenWire
protocol would be appreciated.
2.)
Class DivertImpl has a reference to used StorageManager. I did add a check
after transform if StorageManager is candidate for using journal and forced
conversion of too big messages to LargeMessage if so:
{code:java}
if (transformer != null) {
copy = transformer.transform(copy);
if (this.storageManager instanceof
AbstractJournalStorageManager) {
copy = LargeServerMessageImpl.checkLargeMessage(copy,
this.storageManager);
}
}
{code}
Testing ArtemisMQ 2.36.0 with patched DivertImpl gives this particular issue
has disappeared, but it's a hack and I cannot judge the consequences for
overall broker.
3.)
LargeServerMessageImpl uses hard coded value _ESTIMATE_RECORD_TRAIL = 512_ as
size for reserve buffer for possible added headers. This is eaten up rather
fast, because this is 256 characters for properties names and values. Divert
also add some properties prefixed by _{_}AMQ_ORIG{_} by default, what also need
some of the reserve buffer. Increasing to 2048 or making that to a parameter in
broker.xml would also be appreciated.
was:
Our backbone application uses OpenWire client to connect to ArtemisMQ because
only ActiveMQ Classic JMS client is supported by vendor. We experience several
times in a week a message is rejected by broker with an
ActiveMQIOErrorException AMQ149005.
We found out this issue is caused by a divert with a transformer, what adds
properties to the message. If incoming message has these characteristics:
# Message is durable.
# Message is not a large message, so body shall be persisted in journal.
# Message encoded size is near journal record size.
Then if adding properties pushes message encoding size above journal record
size broker still tries to persist complete message in journal and exception
comes up.
*Steps to Reproduce the Error*
We plan to upgrade ArtemisMQ from 2.31.2 to 2.36.0. Issue on 2.36.0 is even
worser, because connection hangs if using replicating broker pair:
1.) Create primary broker:
{code:java}
apache-artemis-2.36.0\bin\artemis.cmd create --host=localhost
--default-port=61611 --http-port=8111 --clustered --cluster-user=cls
--cluster-password=cls --replicated --name=br11 --user=usr --password=usr
--allow-anonymous --no-autotune --no-amqp-acceptor --no-hornetq-acceptor
--no-mqtt-acceptor --no-stomp-acceptor br11{code}
2.) Create backup broker:
{code:java}
apache-artemis-2.36.0\bin\artemis.cmd create --host=localhost
--default-port=61612 --http-port=8112 --clustered --cluster-user=cls
--cluster-password=cls --replicated --backup --name=br12 --user=usr
--password=usr --allow-anonymous --no-autotune --no-amqp-acceptor
--no-hornetq-acceptor --no-mqtt-acceptor --no-stomp-acceptor br12{code}
3.) Start brokers
4.) Add test addresses primary broker.xml:
{code:xml}
<address name="TEST.IN">
<anycast>
<queue name="TEST.IN"/>
</anycast>
</address>
<address name="TEST.OUT">
<anycast>
<queue name="TEST.OUT"/>
</anycast>
</address>{code}
5.) Add divert with transformer to primary broker.xml:
{code:xml}
<diverts>
<divert name="TEST-DIVERT">
<address>TEST.IN</address>
<forwarding-address>TEST.OUT</forwarding-address>
<filter string="LABEL='Test'"/>
<transformer>
<class-name>org.apache.activemq.artemis.core.server.transformer.AddHeadersTransformer</class-name>
<property key="Property01" value="0123456789abcdef"/>
<property key="Property02" value="0123456789abcdef"/>
<property key="Property03" value="0123456789abcdef"/>
<property key="Property04" value="0123456789abcdef"/>
<property key="Property05" value="0123456789abcdef"/>
</transformer>
</divert>
</diverts>{code}
6.) Use this Java code to reproduce issue:
{code:java}
public class Client {
private static final Logger logger =
LoggerFactory.getLogger(MethodHandles.lookup().lookupClass());
private static final int numberChars = 250270;
public static void main(final String[] args) throws Exception {
ActiveMQConnectionFactory connectionFactory = new
ActiveMQConnectionFactory("tcp://localhost:61611");
logger.info("Connecting to tcp://localhost:61611");
Connection connection = connectionFactory.createConnection("usr",
"usr");
Session session = connection.createSession(true, 0);
Queue queue = session.createQueue("TEST.IN");
MessageProducer messageProducer = session.createProducer(queue);
StringBuilder stringBuilder = new StringBuilder();
for (int i = 0; i < numberChars; ++i) {
stringBuilder.append('x');
}
Message message = session.createTextMessage(stringBuilder.toString());
message.setStringProperty("LABEL", "Test");
logger.info("Sending message with body of {} characters to queue
TEST.IN", numberChars);
messageProducer.send(message);
session.commit();
logger.info("Cleaning...");
session.close();
connection.close();
logger.info("Done!");
}
}
{code}
I have attached Maven project,
{code:java}
mvn exec:java{code}
will compile and start that java code.
*Result*
Client connection hangs, no broker response. Log of primary broker:
{code:java}
2024-08-15 08:29:55,259 WARN [org.apache.activemq.artemis.journal] AMQ144012:
Journal Record sized at 501800, which is too close to the max record Size at
501760. Record = CoreMessage[messageID=2928, durable=true,
userID=c93af8c6-5acf-11ef-9eca-00155d1c6e82, priority=4, timestamp=Thu Aug 15
08:29:55 CEST 2024, expiration=0, durable=true, address=TEST.OUT, size=501735,
properties=TypedProperties[_AMQ_GROUP_SEQUENCE=0, Property05=0123456789abcdef,
__HDR_BROKER_IN_TIME=1723703395259, Property04=0123456789abcdef,
__HDR_COMMAND_ID=6, _AMQ_ORIG_MESSAGE_ID=2927, Property03=0123456789abcdef,
Property02=0123456789abcdef,
__HDR_MESSAGE_ID=ID:D-6T3WW14-58398-1723703395079-1:1:1:1:1,
Property01=0123456789abcdef, __HDR_DROPPABLE=false,
__AMQ_CID=ID:D-6T3WW14-58398-1723703395079-0:1, __HDR_ARRIVAL=0,
_AMQ_ORIG_QUEUE=TEST-DIVERT, _AMQ_ORIG_ROUTING_TYPE=1, LABEL=Test,
_AMQ_ORIG_ADDRESS=TEST.IN,
__HDR_PRODUCER_ID=ID:D-6T3WW14-58398-1723703395079-1:1:1:1]]@531753705.
Internal broker operations such as redistribution and DLQ may be compromised.
Move large headers into the body of messages.
2024-08-15 08:29:55,271 WARN
[org.apache.activemq.artemis.core.protocol.openwire.OpenWireConnection] Errors
occurred during the buffering operation
org.apache.activemq.artemis.api.core.ActiveMQIOErrorException: AMQ149005:
Message of 501800 bytes is bigger than the max record size of 501760 bytes. You
should try to move large application properties to the message body.
at
org.apache.activemq.artemis.core.journal.impl.JournalImpl.checkRecordSize(JournalImpl.java:1011)
~[artemis-journal-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendAddRecordTransactional(JournalImpl.java:1269)
~[artemis-journal-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.replication.ReplicatedJournal.appendAddRecordTransactional(ReplicatedJournal.java:192)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.persistence.impl.journal.AbstractJournalStorageManager.storeMessageTransactional(AbstractJournalStorageManager.java:524)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.storeDurableReference(PostOfficeImpl.java:1772)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.processRouteToDurableQueues(PostOfficeImpl.java:1752)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.processRoute(PostOfficeImpl.java:1688)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.route(PostOfficeImpl.java:1242)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.route(PostOfficeImpl.java:1136)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.server.impl.DivertImpl.route(DivertImpl.java:147)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.DivertBinding.route(DivertBinding.java:103)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.BindingsImpl.lambda$simpleRouting$0(BindingsImpl.java:418)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.CopyOnWriteBindings.forEachBindings(CopyOnWriteBindings.java:175)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.BindingsImpl.simpleRouting(BindingsImpl.java:408)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.BindingsImpl.route(BindingsImpl.java:355)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.BindingsImpl.route(BindingsImpl.java:305)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.simpleRoute(PostOfficeImpl.java:1304)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.route(PostOfficeImpl.java:1206)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.route(PostOfficeImpl.java:1136)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.doSend(ServerSessionImpl.java:2368)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.send(ServerSessionImpl.java:1963)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.send(ServerSessionImpl.java:1902)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.send(ServerSessionImpl.java:1893)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.protocol.openwire.amq.AMQSession.send(AMQSession.java:427)
~[artemis-openwire-protocol-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.protocol.openwire.OpenWireConnection$CommandProcessor.processMessage(OpenWireConnection.java:1740)
~[artemis-openwire-protocol-2.36.0.jar:2.36.0]
at
org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:769)
~[activemq-client-5.18.5.jar:5.18.5]
at
org.apache.activemq.artemis.core.protocol.openwire.OpenWireConnection.act(OpenWireConnection.java:366)
~[artemis-openwire-protocol-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.utils.actors.ThresholdActor.doTask(ThresholdActor.java:68)
~[artemis-commons-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:68)
~[artemis-commons-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:57)
~[artemis-commons-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:32)
~[artemis-commons-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:68)
~[artemis-commons-2.36.0.jar:2.36.0]
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
[?:?]
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
[?:?]
at
org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
[artemis-commons-2.36.0.jar:2.36.0]
2024-08-15 08:29:55,291 WARN
[org.apache.activemq.artemis.core.protocol.openwire.OpenWireConnection] Errors
occurred during the buffering operation
org.apache.activemq.artemis.api.core.ActiveMQException: AMQ149005: Message of
501800 bytes is bigger than the max record size of 501760 bytes. You should try
to move large application properties to the message body.
at
org.apache.activemq.artemis.core.protocol.openwire.OpenWireConnection$CommandProcessor.processMessage(OpenWireConnection.java:1743)
~[artemis-openwire-protocol-2.36.0.jar:2.36.0]
at
org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:769)
~[activemq-client-5.18.5.jar:5.18.5]
at
org.apache.activemq.artemis.core.protocol.openwire.OpenWireConnection.act(OpenWireConnection.java:366)
~[artemis-openwire-protocol-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.utils.actors.ThresholdActor.doTask(ThresholdActor.java:68)
~[artemis-commons-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:68)
~[artemis-commons-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:57)
~[artemis-commons-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:32)
~[artemis-commons-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:68)
~[artemis-commons-2.36.0.jar:2.36.0]
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
[?:?]
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
[?:?]
at
org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
[artemis-commons-2.36.0.jar:2.36.0]{code}
Log of backup broker:
{code:java}
2024-08-15 08:29:55,269 WARN [org.apache.activemq.artemis.journal] AMQ144012:
Journal Record sized at 501800, which is too close to the max record Size at
501760. Record =
org.apache.activemq.artemis.core.journal.impl.dataformat.ByteArrayEncoding@55dd046c.
Internal broker operations such as redistribution and DLQ may be compromised.
Move large headers into the body of messages.
2024-08-15 08:29:55,290 WARN
[org.apache.activemq.artemis.core.replication.ReplicationEndpoint] AMQ149005:
Message of 501800 bytes is bigger than the max record size of 501760 bytes. You
should try to move large application properties to the message body.
org.apache.activemq.artemis.api.core.ActiveMQIOErrorException: AMQ149005:
Message of 501800 bytes is bigger than the max record size of 501760 bytes. You
should try to move large application properties to the message body.
at
org.apache.activemq.artemis.core.journal.impl.JournalImpl.checkRecordSize(JournalImpl.java:1011)
~[artemis-journal-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendAddRecordTransactional(JournalImpl.java:1269)
~[artemis-journal-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.journal.Journal.appendAddRecordTransactional(Journal.java:188)
~[artemis-journal-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.journal.impl.JournalBase.appendAddRecordTransactional(JournalBase.java:115)
~[artemis-journal-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendAddRecordTransactional(JournalImpl.java:105)
~[artemis-journal-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.replication.ReplicationEndpoint.handleAppendAddTXRecord(ReplicationEndpoint.java:766)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.replication.ReplicationEndpoint.handlePacket(ReplicationEndpoint.java:210)
[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl.handlePacket(ChannelImpl.java:835)
[artemis-core-client-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl.doBufferReceived(RemotingConnectionImpl.java:419)
[artemis-core-client-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl.bufferReceived(RemotingConnectionImpl.java:392)
[artemis-core-client-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl$DelegatingBufferHandler.bufferReceived(ClientSessionFactoryImpl.java:1355)
[artemis-core-client-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.remoting.impl.netty.ActiveMQChannelHandler.channelRead(ActiveMQChannelHandler.java:73)
[artemis-core-client-2.36.0.jar:2.36.0]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:346)
[netty-codec-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:318)
[netty-codec-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1407)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:918)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:788)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:724)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:650)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:994)
[netty-common-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
[netty-common-4.1.112.Final.jar:4.1.112.Final]
at
org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
[artemis-commons-2.36.0.jar:2.36.0]
2024-08-15 08:29:55,300 WARN [org.apache.activemq.artemis.core.server]
AMQ222086: error handling packet ReplicationAddTXMessage[type=92, channelID=2,
responseAsync=false, requiresResponse=false, correlationID=-1] for replication
org.apache.activemq.artemis.api.core.ActiveMQIOErrorException: AMQ149005:
Message of 501800 bytes is bigger than the max record size of 501760 bytes. You
should try to move large application properties to the message body.
at
org.apache.activemq.artemis.core.journal.impl.JournalImpl.checkRecordSize(JournalImpl.java:1011)
~[artemis-journal-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendAddRecordTransactional(JournalImpl.java:1269)
~[artemis-journal-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.journal.Journal.appendAddRecordTransactional(Journal.java:188)
~[artemis-journal-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.journal.impl.JournalBase.appendAddRecordTransactional(JournalBase.java:115)
~[artemis-journal-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendAddRecordTransactional(JournalImpl.java:105)
~[artemis-journal-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.replication.ReplicationEndpoint.handleAppendAddTXRecord(ReplicationEndpoint.java:766)
~[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.replication.ReplicationEndpoint.handlePacket(ReplicationEndpoint.java:210)
[artemis-server-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl.handlePacket(ChannelImpl.java:835)
[artemis-core-client-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl.doBufferReceived(RemotingConnectionImpl.java:419)
[artemis-core-client-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl.bufferReceived(RemotingConnectionImpl.java:392)
[artemis-core-client-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl$DelegatingBufferHandler.bufferReceived(ClientSessionFactoryImpl.java:1355)
[artemis-core-client-2.36.0.jar:2.36.0]
at
org.apache.activemq.artemis.core.remoting.impl.netty.ActiveMQChannelHandler.channelRead(ActiveMQChannelHandler.java:73)
[artemis-core-client-2.36.0.jar:2.36.0]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:346)
[netty-codec-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:318)
[netty-codec-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1407)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:918)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:788)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:724)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:650)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562)
[netty-transport-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:994)
[netty-common-4.1.112.Final.jar:4.1.112.Final]
at
io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
[netty-common-4.1.112.Final.jar:4.1.112.Final]
at
org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
[artemis-commons-2.36.0.jar:2.36.0]{code}
Stopping backup broker frees connection to client . Output on client after
stopping backup is:
{code:java}
[client.Client.main()] INFO org.apache.activemq.TransactionContext - commit
failed for transaction TX:ID:D-6T3WW14-58398-1723703395079-1:1:1
javax.jms.JMSException: org.apache.activemq.artemis.api.core.ActiveMQException:
AMQ149005: Message of 501800 bytes is bigger than the max record size of 501760
bytes. You should try to move large application properties to the message
body.{code}
*Further Analysis*
1.)
This issue affects OpenWire clients only. For Core clients the parameter
_amqpMinLargeMessageSize=102400_ in acceptor configuration avoids creating such
messages on the edge as used in my example. A similar parameter for OpenWire
protocol would be appreciated.
2.)
Class DivertImpl has a reference to used StorageManager. I did add a check
after transform if StorageManager is candidate for using journal and forced
conversion of too big messages to LargeMessage if so:
{code:java}
if (transformer != null) {
copy = transformer.transform(copy);
if (this.storageManager instanceof
AbstractJournalStorageManager) {
copy = LargeServerMessageImpl.checkLargeMessage(copy,
this.storageManager);
}
}
{code}
Testing ArtemisMQ 2.36.0 with patched DivertImpl gives this particular issue
has disappeared, but it's a hack and I cannot judge the consequences for
overall broker.
3.)
LargeServerMessageImpl uses hard coded value _ESTIMATE_RECORD_TRAIL = 512_ as
size for reserve buffer for possible added headers. This is eaten up rather
fast, because this is 256 characters for properties names and values. Divert
also add some properties prefixed by _{_}AMQ_ORIG{_} by default, what also need
some of the reserve buffer. Increasing to 2048 or making that to a parameter in
broker.xml would also be appreciated.
> ActiveMQIOErrorException for transformed messages
> -------------------------------------------------
>
> Key: ARTEMIS-4993
> URL: https://issues.apache.org/jira/browse/ARTEMIS-4993
> Project: ActiveMQ Artemis
> Issue Type: Bug
> Components: Broker, OpenWire
> Affects Versions: 2.36.0
> Reporter: Arno Schuerhoff
> Priority: Major
> Attachments: client.zip
>
>
> Our backbone application uses OpenWire client to connect to ArtemisMQ because
> only ActiveMQ Classic JMS client is supported by vendor. We experience
> several times in a week a message is rejected by broker with an
> ActiveMQIOErrorException AMQ149005.
> We found out this issue is caused by a divert with a transformer, what adds
> properties to the message. If incoming message has these characteristics:
> # Message is durable.
> # Message is not a large message, so body shall be persisted in journal.
> # Message encoded size is near journal record size.
> Then if adding properties pushes message encoding size above journal record
> size broker still tries to persist complete message in journal and exception
> comes up.
> *Steps to Reproduce the Error*
> We plan to upgrade ArtemisMQ from 2.31.2 to 2.36.0. Issue on 2.36.0 is even
> worser, because connection hangs if using replicating broker pair:
> 1.) Create primary broker:
> {noformat}
> apache-artemis-2.36.0\bin\artemis.cmd create --host=localhost
> --default-port=61611 --http-port=8111 --clustered --cluster-user=cls
> --cluster-password=cls --replicated --name=br11 --user=usr --password=usr
> --allow-anonymous --no-autotune --no-amqp-acceptor --no-hornetq-acceptor
> --no-mqtt-acceptor --no-stomp-acceptor br11{noformat}
>
> 2.) Create backup broker:
> {noformat}
> apache-artemis-2.36.0\bin\artemis.cmd create --host=localhost
> --default-port=61612 --http-port=8112 --clustered --cluster-user=cls
> --cluster-password=cls --replicated --backup --name=br12 --user=usr
> --password=usr --allow-anonymous --no-autotune --no-amqp-acceptor
> --no-hornetq-acceptor --no-mqtt-acceptor --no-stomp-acceptor br12{noformat}
>
> 3.) Start brokers
> 4.) Add test addresses primary broker.xml:
>
> {code:xml}
> <address name="TEST.IN">
> <anycast>
> <queue name="TEST.IN"/>
> </anycast>
> </address>
> <address name="TEST.OUT">
> <anycast>
> <queue name="TEST.OUT"/>
> </anycast>
> </address>{code}
>
> 5.) Add divert with transformer to primary broker.xml:
> {code:xml}
> <diverts>
> <divert name="TEST-DIVERT">
> <address>TEST.IN</address>
> <forwarding-address>TEST.OUT</forwarding-address>
> <filter string="LABEL='Test'"/>
> <transformer>
>
> <class-name>org.apache.activemq.artemis.core.server.transformer.AddHeadersTransformer</class-name>
> <property key="Property01" value="0123456789abcdef"/>
> <property key="Property02" value="0123456789abcdef"/>
> <property key="Property03" value="0123456789abcdef"/>
> <property key="Property04" value="0123456789abcdef"/>
> <property key="Property05" value="0123456789abcdef"/>
> </transformer>
> </divert>
> </diverts>{code}
> 6.) Use this Java code to reproduce issue:
> {code:java}
>
> public class Client {
>
> private static final Logger logger =
> LoggerFactory.getLogger(MethodHandles.lookup().lookupClass());
> private static final int numberChars = 250270;
> public static void main(final String[] args) throws Exception {
> ActiveMQConnectionFactory connectionFactory = new
> ActiveMQConnectionFactory("tcp://localhost:61611");
> logger.info("Connecting to tcp://localhost:61611");
> Connection connection = connectionFactory.createConnection("usr",
> "usr");
> Session session = connection.createSession(true, 0);
> Queue queue = session.createQueue("TEST.IN");
> MessageProducer messageProducer = session.createProducer(queue);
> StringBuilder stringBuilder = new StringBuilder();
> for (int i = 0; i < numberChars; ++i) {
> stringBuilder.append('x');
> }
> Message message = session.createTextMessage(stringBuilder.toString());
> message.setStringProperty("LABEL", "Test");
> logger.info("Sending message with body of {} characters to queue
> TEST.IN", numberChars);
> messageProducer.send(message);
> session.commit();
> logger.info("Cleaning...");
> session.close();
> connection.close();
> logger.info("Done!");
> }
> }
> {code}
> I have attached Maven project,
> {code:java}
> mvn exec:java{code}
> will compile and start that java code.
>
> *Result*
> Client connection hangs, no broker response. Log of primary broker:
> {noformat}
> 2024-08-15 08:29:55,259 WARN [org.apache.activemq.artemis.journal]
> AMQ144012: Journal Record sized at 501800, which is too close to the max
> record Size at 501760. Record = CoreMessage[messageID=2928, durable=true,
> userID=c93af8c6-5acf-11ef-9eca-00155d1c6e82, priority=4, timestamp=Thu Aug 15
> 08:29:55 CEST 2024, expiration=0, durable=true, address=TEST.OUT,
> size=501735, properties=TypedProperties[_AMQ_GROUP_SEQUENCE=0,
> Property05=0123456789abcdef, __HDR_BROKER_IN_TIME=1723703395259,
> Property04=0123456789abcdef, __HDR_COMMAND_ID=6, _AMQ_ORIG_MESSAGE_ID=2927,
> Property03=0123456789abcdef, Property02=0123456789abcdef,
> __HDR_MESSAGE_ID=ID:D-6T3WW14-58398-1723703395079-1:1:1:1:1,
> Property01=0123456789abcdef, __HDR_DROPPABLE=false,
> __AMQ_CID=ID:D-6T3WW14-58398-1723703395079-0:1, __HDR_ARRIVAL=0,
> _AMQ_ORIG_QUEUE=TEST-DIVERT, _AMQ_ORIG_ROUTING_TYPE=1, LABEL=Test,
> _AMQ_ORIG_ADDRESS=TEST.IN,
> __HDR_PRODUCER_ID=ID:D-6T3WW14-58398-1723703395079-1:1:1:1]]@531753705.
> Internal broker operations such as redistribution and DLQ may be compromised.
> Move large headers into the body of messages.
> 2024-08-15 08:29:55,271 WARN
> [org.apache.activemq.artemis.core.protocol.openwire.OpenWireConnection]
> Errors occurred during the buffering operation
> org.apache.activemq.artemis.api.core.ActiveMQIOErrorException: AMQ149005:
> Message of 501800 bytes is bigger than the max record size of 501760 bytes.
> You should try to move large application properties to the message body.
> at
> org.apache.activemq.artemis.core.journal.impl.JournalImpl.checkRecordSize(JournalImpl.java:1011)
> ~[artemis-journal-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendAddRecordTransactional(JournalImpl.java:1269)
> ~[artemis-journal-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.replication.ReplicatedJournal.appendAddRecordTransactional(ReplicatedJournal.java:192)
> ~[artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.persistence.impl.journal.AbstractJournalStorageManager.storeMessageTransactional(AbstractJournalStorageManager.java:524)
> ~[artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.storeDurableReference(PostOfficeImpl.java:1772)
> ~[artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.processRouteToDurableQueues(PostOfficeImpl.java:1752)
> ~[artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.processRoute(PostOfficeImpl.java:1688)
> ~[artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.route(PostOfficeImpl.java:1242)
> ~[artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.route(PostOfficeImpl.java:1136)
> ~[artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.server.impl.DivertImpl.route(DivertImpl.java:147)
> ~[artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.postoffice.impl.DivertBinding.route(DivertBinding.java:103)
> ~[artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.postoffice.impl.BindingsImpl.lambda$simpleRouting$0(BindingsImpl.java:418)
> ~[artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.postoffice.impl.CopyOnWriteBindings.forEachBindings(CopyOnWriteBindings.java:175)
> ~[artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.postoffice.impl.BindingsImpl.simpleRouting(BindingsImpl.java:408)
> ~[artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.postoffice.impl.BindingsImpl.route(BindingsImpl.java:355)
> ~[artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.postoffice.impl.BindingsImpl.route(BindingsImpl.java:305)
> ~[artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.simpleRoute(PostOfficeImpl.java:1304)
> ~[artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.route(PostOfficeImpl.java:1206)
> ~[artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl.route(PostOfficeImpl.java:1136)
> ~[artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.doSend(ServerSessionImpl.java:2368)
> ~[artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.send(ServerSessionImpl.java:1963)
> ~[artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.send(ServerSessionImpl.java:1902)
> ~[artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.server.impl.ServerSessionImpl.send(ServerSessionImpl.java:1893)
> ~[artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.protocol.openwire.amq.AMQSession.send(AMQSession.java:427)
> ~[artemis-openwire-protocol-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.protocol.openwire.OpenWireConnection$CommandProcessor.processMessage(OpenWireConnection.java:1740)
> ~[artemis-openwire-protocol-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:769)
> ~[activemq-client-5.18.5.jar:5.18.5]
> at
> org.apache.activemq.artemis.core.protocol.openwire.OpenWireConnection.act(OpenWireConnection.java:366)
> ~[artemis-openwire-protocol-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.utils.actors.ThresholdActor.doTask(ThresholdActor.java:68)
> ~[artemis-commons-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:68)
> ~[artemis-commons-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:57)
> ~[artemis-commons-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:32)
> ~[artemis-commons-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:68)
> ~[artemis-commons-2.36.0.jar:2.36.0]
> at
> java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
> [?:?]
> at
> java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
> [?:?]
> at
> org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
> [artemis-commons-2.36.0.jar:2.36.0]
> 2024-08-15 08:29:55,291 WARN
> [org.apache.activemq.artemis.core.protocol.openwire.OpenWireConnection]
> Errors occurred during the buffering operation
> org.apache.activemq.artemis.api.core.ActiveMQException: AMQ149005: Message of
> 501800 bytes is bigger than the max record size of 501760 bytes. You should
> try to move large application properties to the message body.
> at
> org.apache.activemq.artemis.core.protocol.openwire.OpenWireConnection$CommandProcessor.processMessage(OpenWireConnection.java:1743)
> ~[artemis-openwire-protocol-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:769)
> ~[activemq-client-5.18.5.jar:5.18.5]
> at
> org.apache.activemq.artemis.core.protocol.openwire.OpenWireConnection.act(OpenWireConnection.java:366)
> ~[artemis-openwire-protocol-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.utils.actors.ThresholdActor.doTask(ThresholdActor.java:68)
> ~[artemis-commons-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:68)
> ~[artemis-commons-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:57)
> ~[artemis-commons-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:32)
> ~[artemis-commons-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:68)
> ~[artemis-commons-2.36.0.jar:2.36.0]
> at
> java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
> [?:?]
> at
> java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
> [?:?]
> at
> org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
> [artemis-commons-2.36.0.jar:2.36.0]{noformat}
> Log of backup broker:
> {noformat}
> 2024-08-15 08:29:55,269 WARN [org.apache.activemq.artemis.journal]
> AMQ144012: Journal Record sized at 501800, which is too close to the max
> record Size at 501760. Record =
> org.apache.activemq.artemis.core.journal.impl.dataformat.ByteArrayEncoding@55dd046c.
> Internal broker operations such as redistribution and DLQ may be
> compromised. Move large headers into the body of messages.
> 2024-08-15 08:29:55,290 WARN
> [org.apache.activemq.artemis.core.replication.ReplicationEndpoint] AMQ149005:
> Message of 501800 bytes is bigger than the max record size of 501760 bytes.
> You should try to move large application properties to the message body.
> org.apache.activemq.artemis.api.core.ActiveMQIOErrorException: AMQ149005:
> Message of 501800 bytes is bigger than the max record size of 501760 bytes.
> You should try to move large application properties to the message body.
> at
> org.apache.activemq.artemis.core.journal.impl.JournalImpl.checkRecordSize(JournalImpl.java:1011)
> ~[artemis-journal-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendAddRecordTransactional(JournalImpl.java:1269)
> ~[artemis-journal-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.journal.Journal.appendAddRecordTransactional(Journal.java:188)
> ~[artemis-journal-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.journal.impl.JournalBase.appendAddRecordTransactional(JournalBase.java:115)
> ~[artemis-journal-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendAddRecordTransactional(JournalImpl.java:105)
> ~[artemis-journal-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.replication.ReplicationEndpoint.handleAppendAddTXRecord(ReplicationEndpoint.java:766)
> ~[artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.replication.ReplicationEndpoint.handlePacket(ReplicationEndpoint.java:210)
> [artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl.handlePacket(ChannelImpl.java:835)
> [artemis-core-client-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl.doBufferReceived(RemotingConnectionImpl.java:419)
> [artemis-core-client-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl.bufferReceived(RemotingConnectionImpl.java:392)
> [artemis-core-client-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl$DelegatingBufferHandler.bufferReceived(ClientSessionFactoryImpl.java:1355)
> [artemis-core-client-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.remoting.impl.netty.ActiveMQChannelHandler.channelRead(ActiveMQChannelHandler.java:73)
> [artemis-core-client-2.36.0.jar:2.36.0]
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:346)
> [netty-codec-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:318)
> [netty-codec-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1407)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:918)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:788)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:724)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:650)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:994)
> [netty-common-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
> [netty-common-4.1.112.Final.jar:4.1.112.Final]
> at
> org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
> [artemis-commons-2.36.0.jar:2.36.0]
> 2024-08-15 08:29:55,300 WARN [org.apache.activemq.artemis.core.server]
> AMQ222086: error handling packet ReplicationAddTXMessage[type=92,
> channelID=2, responseAsync=false, requiresResponse=false, correlationID=-1]
> for replication
> org.apache.activemq.artemis.api.core.ActiveMQIOErrorException: AMQ149005:
> Message of 501800 bytes is bigger than the max record size of 501760 bytes.
> You should try to move large application properties to the message body.
> at
> org.apache.activemq.artemis.core.journal.impl.JournalImpl.checkRecordSize(JournalImpl.java:1011)
> ~[artemis-journal-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendAddRecordTransactional(JournalImpl.java:1269)
> ~[artemis-journal-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.journal.Journal.appendAddRecordTransactional(Journal.java:188)
> ~[artemis-journal-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.journal.impl.JournalBase.appendAddRecordTransactional(JournalBase.java:115)
> ~[artemis-journal-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendAddRecordTransactional(JournalImpl.java:105)
> ~[artemis-journal-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.replication.ReplicationEndpoint.handleAppendAddTXRecord(ReplicationEndpoint.java:766)
> ~[artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.replication.ReplicationEndpoint.handlePacket(ReplicationEndpoint.java:210)
> [artemis-server-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.protocol.core.impl.ChannelImpl.handlePacket(ChannelImpl.java:835)
> [artemis-core-client-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl.doBufferReceived(RemotingConnectionImpl.java:419)
> [artemis-core-client-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.protocol.core.impl.RemotingConnectionImpl.bufferReceived(RemotingConnectionImpl.java:392)
> [artemis-core-client-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.client.impl.ClientSessionFactoryImpl$DelegatingBufferHandler.bufferReceived(ClientSessionFactoryImpl.java:1355)
> [artemis-core-client-2.36.0.jar:2.36.0]
> at
> org.apache.activemq.artemis.core.remoting.impl.netty.ActiveMQChannelHandler.channelRead(ActiveMQChannelHandler.java:73)
> [artemis-core-client-2.36.0.jar:2.36.0]
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:346)
> [netty-codec-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:318)
> [netty-codec-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1407)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:918)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:788)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:724)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:650)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562)
> [netty-transport-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:994)
> [netty-common-4.1.112.Final.jar:4.1.112.Final]
> at
> io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
> [netty-common-4.1.112.Final.jar:4.1.112.Final]
> at
> org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
> [artemis-commons-2.36.0.jar:2.36.0]{noformat}
> Stopping backup broker frees connection to client . Output on client after
> stopping backup is:
> {noformat}
> [client.Client.main()] INFO org.apache.activemq.TransactionContext - commit
> failed for transaction TX:ID:D-6T3WW14-58398-1723703395079-1:1:1
> javax.jms.JMSException:
> org.apache.activemq.artemis.api.core.ActiveMQException: AMQ149005: Message of
> 501800 bytes is bigger than the max record size of 501760 bytes. You should
> try to move large application properties to the message body.{noformat}
>
> *Further Analysis*
> 1.)
> This issue affects OpenWire clients only. For Core clients the parameter
> _amqpMinLargeMessageSize=102400_ in acceptor configuration avoids creating
> such messages on the edge as used in my example. A similar parameter for
> OpenWire protocol would be appreciated.
>
> 2.)
> Class DivertImpl has a reference to used StorageManager. I did add a check
> after transform if StorageManager is candidate for using journal and forced
> conversion of too big messages to LargeMessage if so:
>
> {code:java}
> if (transformer != null) {
> copy = transformer.transform(copy);
> if (this.storageManager instanceof
> AbstractJournalStorageManager) {
> copy = LargeServerMessageImpl.checkLargeMessage(copy,
> this.storageManager);
> }
> }
> {code}
>
> Testing ArtemisMQ 2.36.0 with patched DivertImpl gives this particular issue
> has disappeared, but it's a hack and I cannot judge the consequences for
> overall broker.
>
> 3.)
> LargeServerMessageImpl uses hard coded value _ESTIMATE_RECORD_TRAIL = 512_ as
> size for reserve buffer for possible added headers. This is eaten up rather
> fast, because this is 256 characters for properties names and values. Divert
> also add some properties prefixed by _{_}AMQ_ORIG{_} by default, what also
> need some of the reserve buffer. Increasing to 2048 or making that to a
> parameter in broker.xml would also be appreciated.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
For further information, visit: https://activemq.apache.org/contact
