[
https://issues.apache.org/jira/browse/ARTEMIS-4217?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17733522#comment-17733522
]
Justin Bertram edited comment on ARTEMIS-4217 at 6/16/23 2:53 PM:
------------------------------------------------------------------
[~jbertram], thanks for looking at this and sorry for the long delay...
It looks like it is hard to reproduce it. I'm currently not able to reproduce
the problem on my local test machine. But I still see the problem on other
systems:
In this case, the problem occurred with a "large message". Could a large
message trigger some kind of conversion? Maybe during writing/reading from the
storage (file system)? The payload of the message is a 1mb chunk of a zip file.
The message also has some custom headers/properties which are visible in the
log below.
We only have AMQP consumers/producers on this system. I've also verified this
in the admin console:
!image-2023-06-16-15-59-25-689.png!!image-2023-06-16-15-59-25-721.png!
{noformat}
2023-06-16 15:44:48,301 WARN [org.apache.activemq.artemis.core.server]
AMQ222150: Sending message Reference[120978405]:NON-RELIABLE:LargeServerMessage
[messageID=120978405,durable=false,userID=f5eb19e9-0c4b-11ee-8c25-f44d30e2ecf9,priority=4,
timestamp=0,expiration=Mon Jun 19 15:44:46 CEST 2023, durable=false,
address=MyQName,
properties=TypedProperties[content-length=1000000,JMS_AMQP_ORIGINAL_ENCODING=6,content-version=2.0,AtmCommandTaskResultId=25160,
filename=MyBroker_2023-06-15_2243_12.0.0.6_Logisoft.7z,content-type=multipart/byteranges,x-version=7.9.45.349,AtmCommandTaskId=-1,_AMQ_LARGE_SIZE=1000000,extensions=1,
checksumrange=F4861070CFDFC33B7D77A74420AF25DF1FAFF4F57A01D75A1E0FB03047BF38C7,NATIVE_MESSAGE_ID=ID:AMQP_NO_PREFIX:MyQName_2023-06-16T15:44:46.8290577+02:00_97089137-6edd-49cd-a81a-0b40441f6be5,Issued=2023-06-16
15:44:46.824
+02:00,AtmJobId=15065,content-status=200,range=6000000-6999999,1773052136,process-id=Job_15065_MonitoringDataExchange_ssss_2023-06-16T15:38:58.0607859+02:00,atmid=CHE80000455,received-getrange=6000000-6999999,0]]@80507286
to Dead Letter Address, but there is no Dead Letter Address configured for
queue MyQName so dropping it
2023-06-16 15:44:48,338 WARN
[org.apache.activemq.artemis.protocol.amqp.logger] AMQ111005: Failed to convert
message. Sending it to Dead Letter Address.
org.apache.activemq.artemis.protocol.amqp.converter.coreWrapper.ConversionException:
java.nio.channels.AsynchronousCloseException
at
org.apache.activemq.artemis.protocol.amqp.converter.CoreAmqpConverter.fromCore(CoreAmqpConverter.java:318)
~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
at
org.apache.activemq.artemis.protocol.amqp.converter.CoreAmqpConverter.checkAMQP(CoreAmqpConverter.java:79)
~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
at
org.apache.activemq.artemis.protocol.amqp.proton.ProtonServerSenderContext.executeDelivery(ProtonServerSenderContext.java:561)
~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
at
org.apache.activemq.artemis.core.server.impl.MessageReferenceImpl.run(MessageReferenceImpl.java:131)
~[artemis-server-2.28.0.jar:2.28.0]
at
io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:174)
~[netty-common-4.1.86.Final.jar:4.1.86.Final]
at
io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:167)
~[netty-common-4.1.86.Final.jar:4.1.86.Final]
at
io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470)
~[netty-common-4.1.86.Final.jar:4.1.86.Final]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:569)
~[netty-transport-4.1.86.Final.jar:4.1.86.Final]
at
io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
~[netty-common-4.1.86.Final.jar:4.1.86.Final]
at
io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
~[netty-common-4.1.86.Final.jar:4.1.86.Final]
at
org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
~[artemis-commons-2.28.0.jar:?]
Caused by: java.lang.RuntimeException:
java.nio.channels.AsynchronousCloseException
at
org.apache.activemq.artemis.core.persistence.impl.journal.LargeBody.getBodyBufferSize(LargeBody.java:293)
~[artemis-server-2.28.0.jar:2.28.0]
at
org.apache.activemq.artemis.core.persistence.impl.journal.LargeServerMessageImpl.getBodyBufferSize(LargeServerMessageImpl.java:263)
~[artemis-server-2.28.0.jar:2.28.0]
at
org.apache.activemq.artemis.protocol.amqp.converter.coreWrapper.CoreBytesMessageWrapper.getBodyLength(CoreBytesMessageWrapper.java:98)
~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
at
org.apache.activemq.artemis.protocol.amqp.converter.coreWrapper.CoreBytesMessageWrapper.getBinaryFromMessageBody(CoreBytesMessageWrapper.java:68)
~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
at
org.apache.activemq.artemis.protocol.amqp.converter.coreWrapper.CoreBytesMessageWrapper.createAMQPSection(CoreBytesMessageWrapper.java:78)
~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
at
org.apache.activemq.artemis.protocol.amqp.converter.CoreAmqpConverter.fromCore(CoreAmqpConverter.java:106)
~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
... 10 more
Caused by: java.nio.channels.AsynchronousCloseException
at
java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:202)
~[?:?]
at sun.nio.ch.FileChannelImpl.endBlocking(FileChannelImpl.java:177)
~[?:?]
at sun.nio.ch.FileChannelImpl.size(FileChannelImpl.java:436) ~[?:?]
at
org.apache.activemq.artemis.core.io.nio.NIOSequentialFile.size(NIOSequentialFile.java:339)
~[artemis-journal-2.28.0.jar:2.28.0]
at
org.apache.activemq.artemis.core.persistence.impl.journal.LargeBody.getBodyBufferSize(LargeBody.java:285)
~[artemis-server-2.28.0.jar:2.28.0]
at
org.apache.activemq.artemis.core.persistence.impl.journal.LargeServerMessageImpl.getBodyBufferSize(LargeServerMessageImpl.java:263)
~[artemis-server-2.28.0.jar:2.28.0]
at
org.apache.activemq.artemis.protocol.amqp.converter.coreWrapper.CoreBytesMessageWrapper.getBodyLength(CoreBytesMessageWrapper.java:98)
~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
at
org.apache.activemq.artemis.protocol.amqp.converter.coreWrapper.CoreBytesMessageWrapper.getBinaryFromMessageBody(CoreBytesMessageWrapper.java:68)
~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
at
org.apache.activemq.artemis.protocol.amqp.converter.coreWrapper.CoreBytesMessageWrapper.createAMQPSection(CoreBytesMessageWrapper.java:78)
~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
at
org.apache.activemq.artemis.protocol.amqp.converter.CoreAmqpConverter.fromCore(CoreAmqpConverter.java:106)
~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
... 10 more{noformat}
was (Author: daves):
[~jbertram] Thanks for looking at this and sorry for the long delay...
It looks like it is hard to reproduce it. I'm currently not able to reproduce
the problem on my local test machine. But I still see the problem on other
systems:
In this case, the problem occurred with a "large message". Could a large
message trigger some kind of conversion? Maybe during writing/reading from the
storage (file system)? The payload of the message is a 1mb chunk of a zip file.
The message also has some custom headers/properties which are visible in the
log below.
We only have AMQP consumers/producers on this system. I've also verified this
in the admin console:
!image-2023-06-16-15-59-25-689.png!!image-2023-06-16-15-59-25-721.png!
{code:java}
2023-06-16 15:44:48,301 WARN [org.apache.activemq.artemis.core.server]
AMQ222150: Sending message Reference[120978405]:NON-RELIABLE:LargeServerMessage
[messageID=120978405,durable=false,userID=f5eb19e9-0c4b-11ee-
8c25-f44d30e2ecf9,priority=4, timestamp=0,expiration=Mon Jun 19 15:44:46 CEST
2023, durable=false, address=MyQName,
properties=TypedProperties[content-length=1000000,JMS_AMQP_ORIGINAL_ENCODING=6,content-version=2.0,AtmCommandTaskResultId=25160,
filename=MyBroker_2023-06-15_2243_12.0.0.6_Logisoft.7z,content-type=multipart/byteranges,x-version=7.9.45.349,AtmCommandTaskId=-1,_AMQ_LARGE_SIZE=1000000,extensions=1,
checksumrange=F4861070CFDFC33B7D77A74420AF25DF1FAFF4F57A01D75A1E0FB03047BF38C7,NATIVE_MESSAGE_ID=ID:AMQP_NO_PREFIX:MyQName_2023-06-16T15:44:46.8290577+02:00_97089137-6edd-49cd-a81a-0b40441f6be5,Issued=2023-06-16
15:44:46.824
+02:00,AtmJobId=15065,content-status=200,range=6000000-6999999,1773052136,process-id=Job_15065_MonitoringDataExchange_ssss_2023-06-16T15:38:58.0607859+02:00,atmid=CHE80000455,received-getrange=6000000-6999999,0]]@80507286
to Dead Letter Address, but there is no Dead Letter Address configured for
queue MyQName so dropping it 2023-06-16 15:44:48,338 WARN
[org.apache.activemq.artemis.protocol.amqp.logger] AMQ111005: Failed to convert
message. Sending it to Dead Letter Address.
org.apache.activemq.artemis.protocol.amqp.converter.coreWrapper.ConversionException:
java.nio.channels.AsynchronousCloseException at
org.apache.activemq.artemis.protocol.amqp.converter.CoreAmqpConverter.fromCore(CoreAmqpConverter.java:318)
~[artemis-amqp-protocol-2.28.0.jar:2.28.0] at
org.apache.activemq.artemis.protocol.amqp.converter.CoreAmqpConverter.checkAMQP(CoreAmqpConverter.java:79)
~[artemis-amqp-protocol-2.28.0.jar:2.28.0] at
org.apache.activemq.artemis.protocol.amqp.proton.ProtonServerSenderContext.executeDelivery(ProtonServerSenderContext.java:561)
~[artemis-amqp-protocol-2.28.0.jar:2.28.0] at
org.apache.activemq.artemis.core.server.impl.MessageReferenceImpl.run(MessageReferenceImpl.java:131)
~[artemis-server-2.28.0.jar:2.28.0] at
io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:174)
~[netty-common-4.1.86.Final.jar:4.1.86.Final] at
io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:167)
~[netty-common-4.1.86.Final.jar:4.1.86.Final] at
io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470)
~[netty-common-4.1.86.Final.jar:4.1.86.Final] at
io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:569)
~[netty-transport-4.1.86.Final.jar:4.1.86.Final] at
io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
~[netty-common-4.1.86.Final.jar:4.1.86.Final] at
io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
~[netty-common-4.1.86.Final.jar:4.1.86.Final] at
org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
~[artemis-commons-2.28.0.jar:?] Caused by: java.lang.RuntimeException:
java.nio.channels.AsynchronousCloseException at
org.apache.activemq.artemis.core.persistence.impl.journal.LargeBody.getBodyBufferSize(LargeBody.java:293)
~[artemis-server-2.28.0.jar:2.28.0] at
org.apache.activemq.artemis.core.persistence.impl.journal.LargeServerMessageImpl.getBodyBufferSize(LargeServerMessageImpl.java:263)
~[artemis-server-2.28.0.jar:2.28.0] at
org.apache.activemq.artemis.protocol.amqp.converter.coreWrapper.CoreBytesMessageWrapper.getBodyLength(CoreBytesMessageWrapper.java:98)
~[artemis-amqp-protocol-2.28.0.jar:2.28.0] at
org.apache.activemq.artemis.protocol.amqp.converter.coreWrapper.CoreBytesMessageWrapper.getBinaryFromMessageBody(CoreBytesMessageWrapper.java:68)
~[artemis-amqp-protocol-2.28.0.jar:2.28.0] at
org.apache.activemq.artemis.protocol.amqp.converter.coreWrapper.CoreBytesMessageWrapper.createAMQPSection(CoreBytesMessageWrapper.java:78)
~[artemis-amqp-protocol-2.28.0.jar:2.28.0] at
org.apache.activemq.artemis.protocol.amqp.converter.CoreAmqpConverter.fromCore(CoreAmqpConverter.java:106)
~[artemis-amqp-protocol-2.28.0.jar:2.28.0] ... 10 more Caused by:
java.nio.channels.AsynchronousCloseException at
java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:202)
~[?:?] at sun.nio.ch.FileChannelImpl.endBlocking(FileChannelImpl.java:177)
~[?:?] at sun.nio.ch.FileChannelImpl.size(FileChannelImpl.java:436) ~[?:?]
at
org.apache.activemq.artemis.core.io.nio.NIOSequentialFile.size(NIOSequentialFile.java:339)
~[artemis-journal-2.28.0.jar:2.28.0] at
org.apache.activemq.artemis.core.persistence.impl.journal.LargeBody.getBodyBufferSize(LargeBody.java:285)
~[artemis-server-2.28.0.jar:2.28.0] at
org.apache.activemq.artemis.core.persistence.impl.journal.LargeServerMessageImpl.getBodyBufferSize(LargeServerMessageImpl.java:263)
~[artemis-server-2.28.0.jar:2.28.0] at
org.apache.activemq.artemis.protocol.amqp.converter.coreWrapper.CoreBytesMessageWrapper.getBodyLength(CoreBytesMessageWrapper.java:98)
~[artemis-amqp-protocol-2.28.0.jar:2.28.0] at
org.apache.activemq.artemis.protocol.amqp.converter.coreWrapper.CoreBytesMessageWrapper.getBinaryFromMessageBody(CoreBytesMessageWrapper.java:68)
~[artemis-amqp-protocol-2.28.0.jar:2.28.0] at
org.apache.activemq.artemis.protocol.amqp.converter.coreWrapper.CoreBytesMessageWrapper.createAMQPSection(CoreBytesMessageWrapper.java:78)
~[artemis-amqp-protocol-2.28.0.jar:2.28.0] at
org.apache.activemq.artemis.protocol.amqp.converter.CoreAmqpConverter.fromCore(CoreAmqpConverter.java:106)
~[artemis-amqp-protocol-2.28.0.jar:2.28.0] ... 10 more{code}
> AMQ111005: Failed to convert message. Sending it to Dead Letter Address.
> ------------------------------------------------------------------------
>
> Key: ARTEMIS-4217
> URL: https://issues.apache.org/jira/browse/ARTEMIS-4217
> Project: ActiveMQ Artemis
> Issue Type: Bug
> Components: AMQP
> Affects Versions: 2.28.0
> Environment: Windows Server 2022 21H2
> openjdk 19.0.1 2022-10-18
> OpenJDK Runtime Environment (build 19.0.1+10-21)
> OpenJDK 64-Bit Server VM (build 19.0.1+10-21, mixed mode, sharing)
> Reporter: daves
> Priority: Major
> Attachments: ArtemisConvertError.zip,
> image-2023-06-16-15-59-25-689.png, image-2023-06-16-15-59-25-721.png
>
>
> Some of the AMQP messages sent by my client never arrive at the consumer. In
> the Artemis log I found the following exception:
> {noformat}
> 2023-03-23 18:06:58,084 WARN
> [org.apache.activemq.artemis.protocol.amqp.logger] AMQ111005: Failed to
> convert message. Sending it to Dead Letter Address.
> org.apache.activemq.artemis.protocol.amqp.converter.coreWrapper.ConversionException:
> java.nio.channels.ClosedChannelException
> at
> org.apache.activemq.artemis.protocol.amqp.converter.CoreAmqpConverter.fromCore(CoreAmqpConverter.java:318)
> ~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
> at
> org.apache.activemq.artemis.protocol.amqp.converter.CoreAmqpConverter.checkAMQP(CoreAmqpConverter.java:79)
> ~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
> at
> org.apache.activemq.artemis.protocol.amqp.proton.ProtonServerSenderContext.executeDelivery(ProtonServerSenderContext.java:561)
> ~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
> at
> org.apache.activemq.artemis.core.server.impl.MessageReferenceImpl.run(MessageReferenceImpl.java:131)
> ~[artemis-server-2.28.0.jar:2.28.0]
> at
> io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:174)
> ~[netty-common-4.1.86.Final.jar:4.1.86.Final]
> at
> io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:167)
> ~[netty-common-4.1.86.Final.jar:4.1.86.Final]
> at
> io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470)
> ~[netty-common-4.1.86.Final.jar:4.1.86.Final]
> at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:569)
> ~[netty-transport-4.1.86.Final.jar:4.1.86.Final]
> at
> io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
> ~[netty-common-4.1.86.Final.jar:4.1.86.Final]
> at
> io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
> ~[netty-common-4.1.86.Final.jar:4.1.86.Final]
> at
> org.apache.activemq.artemis.utils.ActiveMQThreadFactory$1.run(ActiveMQThreadFactory.java:118)
> ~[artemis-commons-2.28.0.jar:?] Caused by: java.lang.RuntimeException:
> java.nio.channels.ClosedChannelException
> at
> org.apache.activemq.artemis.core.persistence.impl.journal.LargeBody.getBodyBufferSize(LargeBody.java:293)
> ~[artemis-server-2.28.0.jar:2.28.0]
> at
> org.apache.activemq.artemis.core.persistence.impl.journal.LargeServerMessageImpl.getBodyBufferSize(LargeServerMessageImpl.java:263)
> ~[artemis-server-2.28.0.jar:2.28.0]
> at
> org.apache.activemq.artemis.protocol.amqp.converter.coreWrapper.CoreBytesMessageWrapper.getBodyLength(CoreBytesMessageWrapper.java:98)
> ~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
> at
> org.apache.activemq.artemis.protocol.amqp.converter.coreWrapper.CoreBytesMessageWrapper.getBinaryFromMessageBody(CoreBytesMessageWrapper.java:68)
> ~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
> at
> org.apache.activemq.artemis.protocol.amqp.converter.coreWrapper.CoreBytesMessageWrapper.createAMQPSection(CoreBytesMessageWrapper.java:78)
> ~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
> at
> org.apache.activemq.artemis.protocol.amqp.converter.CoreAmqpConverter.fromCore(CoreAmqpConverter.java:106)
> ~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
> ... 10 more
> Caused by: java.nio.channels.ClosedChannelException
> at sun.nio.ch.FileChannelImpl.ensureOpen(FileChannelImpl.java:165)
> ~[?:?]
> at sun.nio.ch.FileChannelImpl.size(FileChannelImpl.java:416) ~[?:?]
> at
> org.apache.activemq.artemis.core.io.nio.NIOSequentialFile.size(NIOSequentialFile.java:339)
> ~[artemis-journal-2.28.0.jar:2.28.0]
> at
> org.apache.activemq.artemis.core.persistence.impl.journal.LargeBody.getBodyBufferSize(LargeBody.java:285)
> ~[artemis-server-2.28.0.jar:2.28.0]
> at
> org.apache.activemq.artemis.core.persistence.impl.journal.LargeServerMessageImpl.getBodyBufferSize(LargeServerMessageImpl.java:263)
> ~[artemis-server-2.28.0.jar:2.28.0]
> at
> org.apache.activemq.artemis.protocol.amqp.converter.coreWrapper.CoreBytesMessageWrapper.getBodyLength(CoreBytesMessageWrapper.java:98)
> ~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
> at
> org.apache.activemq.artemis.protocol.amqp.converter.coreWrapper.CoreBytesMessageWrapper.getBinaryFromMessageBody(CoreBytesMessageWrapper.java:68)
> ~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
> at
> org.apache.activemq.artemis.protocol.amqp.converter.coreWrapper.CoreBytesMessageWrapper.createAMQPSection(CoreBytesMessageWrapper.java:78)
> ~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
> at
> org.apache.activemq.artemis.protocol.amqp.converter.CoreAmqpConverter.fromCore(CoreAmqpConverter.java:106)
> ~[artemis-amqp-protocol-2.28.0.jar:2.28.0]
> ... 10 more{noformat}
> I tried to reproduce the error with trace log level enabled, but the problem
> never occurs with trace enabled (same message payload). Maybe it is a timing
> issue which not occurs when Artemis processes messages much slower due to
> additional tracing...?
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
