Messages ends in wrong queue [artemis 2.7.0]

classic Classic list List threaded Threaded
6 messages Options
Reply | Threaded
Open this post in threaded view
|

Messages ends in wrong queue [artemis 2.7.0]

pholik1
Hello,

recently I've been investigating strange behavior. Messages which are sent
to topic ends in unrelated queue.
This happens only whe there are no consumer on topic. When I subscibe to
topic it prevents it from occuring.

My question is: Can the message in artemis queue have JMSDestination
property that doesn't match queue that they are in? For example message
originally sent to MESSAGE_REPORTER_TOPIC(which is topic with no subscriber)
ends uiEventQueue-cbe34f1-902b-s991-9c9e-c746c9488db1 and have
JMSDestination propeperty set to MESSAGE_REPORTER_TOPIC?

There is no special configuration like diverts, bridges, DLQ in setings.
The described behevior occurs on multiple same environments.

Any ideas?

Sincerely
Petr Holik



--
Sent from: http://activemq.2283324.n4.nabble.com/ActiveMQ-User-f2341805.html
Reply | Threaded
Open this post in threaded view
|

Re: Messages ends in wrong queue [artemis 2.7.0]

pholik1
<http://activemq.2283324.n4.nabble.com/file/t379193/messages_in_wrong_queue.png>

There is attached image which shows the situation decribed in my previous
post.



--
Sent from: http://activemq.2283324.n4.nabble.com/ActiveMQ-User-f2341805.html
Reply | Threaded
Open this post in threaded view
|

Re: Messages ends in wrong queue [artemis 2.7.0]

jbertram
It's hard to say for sure without more details, but it seems to me that
you're seeing the expected behavior. As the address model documentation [1]
describes, there are 3 main components in the broker - addresses, queues,
and routing types. In your JMS use-case you have a "topic" which is
represented by an address named "MESSAGE_REPORTER_TOPIC". Each JMS
subscription on that topic is represented by a queue with the multicast
routing type. Any message sent to MESSAGE_REPORTER_TOPIC will therefore go
to all the subscribers. In that case the name of the topic to which the JMS
message was sent (i.e. the message's JMSDestination property) will not be
the same as the name of the queue (i.e. JMS subscription) where it is
routed.

Hope that helps.


Justin

[1]
http://activemq.apache.org/components/artemis/documentation/latest/address-model.html

On Fri, Nov 1, 2019 at 5:11 AM pholik1 <[hidden email]> wrote:

> <
> http://activemq.2283324.n4.nabble.com/file/t379193/messages_in_wrong_queue.png>
>
>
> There is attached image which shows the situation decribed in my previous
> post.
>
>
>
> --
> Sent from:
> http://activemq.2283324.n4.nabble.com/ActiveMQ-User-f2341805.html
>
Reply | Threaded
Open this post in threaded view
|

Re: Messages ends in wrong queue [artemis 2.7.0]

pholik1
Hello Justin,
thnaks for reply.
Unfortunately this is not the case I've checked few times.

I've dumped artemis data journal and there was no bindings on this topic.

There is shortened and commented log what happend(and/or is happening):

16:37:14,419 TRACE
[org.apache.activemq.artemis.core.server.impl.ServerSessionImpl]
send(message=CoreMessage[messageID=*17179879120*,durable=true,userID=7a683996-fcbd-11e9-9dce-0a58c0a80837,priority=4,
timestamp=Fri Nov 01 16:37:14 CET 2019,expiration=0, durable=true,
address=*MESSAGE_REPORTER_TOPIC*,size=4037,...SHORTENED...@792769859,
direct=true) being called
16:37:14,419 DEBUG
[org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl] *Couldn't
find any bindings for address=MESSAGE_REPORTER_TOPIC* on
message=CoreMessage[messageID=*17179879120*,durable=true,userID=7a683996-fcbd-11e9-9dce-0a58c0a80837,priority=4,
timestamp=Fri Nov 01 16:37:14 CET 2019,expiration=0, durable=true,
address=MESSAGE_REPORTER_TOPIC,size=4037,...SHORTENED...@792769859

16:37:14,419 DEBUG [org.apache.activemq.artemis.core.server.plugin.impl]
AMQ843010: beforeMessageRoute called with message:
CoreMessage[messageID=*17179879120*,durable=true,userID=7a683996-fcbd-11e9-9dce-0a58c0a80837,priority=4,
timestamp=Fri Nov 01 16:37:14 CET 2019,expiration=0, durable=true,
address=MESSAGE_REPORTER_TOPIC,size=4037,...SHORTENED...@792769859, context:
org.apache.activemq.artemis.core.server.impl.RoutingContextImpl@520310bf,
direct: true, rejectDuplicates: true
16:37:14,419 TRACE
[org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl] Message
after
routed=CoreMessage[messageID=*17179879120*,durable=true,userID=7a683996-fcbd-11e9-9dce-0a58c0a80837,priority=4,
timestamp=Fri Nov 01 16:37:14 CET 2019,expiration=0, durable=true,
address=MESSAGE_REPORTER_TOPIC,size=4037,...SHORTENED...@792769859

Message is appended to journal:

16:37:14,419 TRACE
[org.apache.activemq.artemis.core.journal.impl.JournalImpl] scheduling
appendAddRecord::id=17179879120, userRecordType=45, record =
CoreMessage[messageID=*17179879120*,durable=true,userID=7a683996-fcbd-11e9-9dce-0a58c0a80837,priority=4,
timestamp=Fri Nov 01 16:37:14 CET 2019,expiration=0, durable=true,
address=MESSAGE_REPORTER_TOPIC,size=4037,...SHORTENED...@792769859
16:37:14,419 TRACE
[org.apache.activemq.artemis.core.journal.impl.JournalImpl] scheduling
appendUpdateRecord::id=*17179879120*, userRecordType=32
16:37:14,419 DEBUG [org.apache.activemq.artemis.core.server.plugin.impl]
AMQ843011: afterMessageRoute message:
CoreMessage[messageID=*17179879120*,durable=true,userID=7a683996-fcbd-11e9-9dce-0a58c0a80837,priority=4,
timestamp=Fri Nov 01 16:37:14 CET 2019,expiration=0, durable=true,
address=MESSAGE_REPORTER_TOPIC,size=4037,...SHORTENED...@792769859, with
context:
org.apache.activemq.artemis.core.server.impl.RoutingContextImpl@520310bf,
direct: true, rejectDuplicates: true
16:37:14,419 INFO  [org.apache.activemq.artemis.core.server.plugin.impl]
AMQ841010: routed message with ID: *17179879120*, result: *OK*

Skipped few log lines about confirmation of recieved message,
and now delivering message to wrong queue:

16:37:14,425 TRACE [org.apache.activemq.artemis.core.server.impl.QueueImpl]
Queue *uiEventQueue-d336918f-fc37-44b9-9aeb-7e09fa90ad86 is delivering
reference
Reference[17179879120]*:RELIABLE:CoreMessage[messageID=17179879120,durable=true,userID=7a683996-fcbd-11e9-9dce-0a58c0a80837,priority=4,
timestamp=Fri Nov 01 16:37:14 CET 2019,expiration=0, durable=true,
address=MESSAGE_REPORTER_TOPIC,size=4037,...SHORTENED...@792769859

(Log is filtered for messageID=17179879120)

It still seems to me as wrong behaviour. I am trying with debugger to
issolate issue, but it's quite complex.
Any suggestions how to solve this?



--
Sent from: http://activemq.2283324.n4.nabble.com/ActiveMQ-User-f2341805.html
Reply | Threaded
Open this post in threaded view
|

Re: Messages ends in wrong queue [artemis 2.7.0]

jbertram
Do you have a way that I can reproduce what you're seeing?

FWIW, the log message saying "Queue
uiEventQueue-d336918f-fc37-44b9-9aeb-7e09fa90ad86 is delivering
reference..." happens when the broker delivers a message from a queue to a
consumer, not when a message is routed to a queue.


Justin

On Tue, Nov 5, 2019 at 7:45 AM pholik1 <[hidden email]> wrote:

> Hello Justin,
> thnaks for reply.
> Unfortunately this is not the case I've checked few times.
>
> I've dumped artemis data journal and there was no bindings on this topic.
>
> There is shortened and commented log what happend(and/or is happening):
>
> 16:37:14,419 TRACE
> [org.apache.activemq.artemis.core.server.impl.ServerSessionImpl]
>
> send(message=CoreMessage[messageID=*17179879120*,durable=true,userID=7a683996-fcbd-11e9-9dce-0a58c0a80837,priority=4,
> timestamp=Fri Nov 01 16:37:14 CET 2019,expiration=0, durable=true,
> address=*MESSAGE_REPORTER_TOPIC*,size=4037,...SHORTENED...@792769859,
> direct=true) being called
> 16:37:14,419 DEBUG
> [org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl] *Couldn't
> find any bindings for address=MESSAGE_REPORTER_TOPIC* on
>
> message=CoreMessage[messageID=*17179879120*,durable=true,userID=7a683996-fcbd-11e9-9dce-0a58c0a80837,priority=4,
> timestamp=Fri Nov 01 16:37:14 CET 2019,expiration=0, durable=true,
> address=MESSAGE_REPORTER_TOPIC,size=4037,...SHORTENED...@792769859
>
> 16:37:14,419 DEBUG [org.apache.activemq.artemis.core.server.plugin.impl]
> AMQ843010: beforeMessageRoute called with message:
>
> CoreMessage[messageID=*17179879120*,durable=true,userID=7a683996-fcbd-11e9-9dce-0a58c0a80837,priority=4,
> timestamp=Fri Nov 01 16:37:14 CET 2019,expiration=0, durable=true,
> address=MESSAGE_REPORTER_TOPIC,size=4037,...SHORTENED...@792769859,
> context:
> org.apache.activemq.artemis.core.server.impl.RoutingContextImpl@520310bf,
> direct: true, rejectDuplicates: true
> 16:37:14,419 TRACE
> [org.apache.activemq.artemis.core.postoffice.impl.PostOfficeImpl] Message
> after
>
> routed=CoreMessage[messageID=*17179879120*,durable=true,userID=7a683996-fcbd-11e9-9dce-0a58c0a80837,priority=4,
> timestamp=Fri Nov 01 16:37:14 CET 2019,expiration=0, durable=true,
> address=MESSAGE_REPORTER_TOPIC,size=4037,...SHORTENED...@792769859
>
> Message is appended to journal:
>
> 16:37:14,419 TRACE
> [org.apache.activemq.artemis.core.journal.impl.JournalImpl] scheduling
> appendAddRecord::id=17179879120, userRecordType=45, record =
>
> CoreMessage[messageID=*17179879120*,durable=true,userID=7a683996-fcbd-11e9-9dce-0a58c0a80837,priority=4,
> timestamp=Fri Nov 01 16:37:14 CET 2019,expiration=0, durable=true,
> address=MESSAGE_REPORTER_TOPIC,size=4037,...SHORTENED...@792769859
> 16:37:14,419 TRACE
> [org.apache.activemq.artemis.core.journal.impl.JournalImpl] scheduling
> appendUpdateRecord::id=*17179879120*, userRecordType=32
> 16:37:14,419 DEBUG [org.apache.activemq.artemis.core.server.plugin.impl]
> AMQ843011: afterMessageRoute message:
>
> CoreMessage[messageID=*17179879120*,durable=true,userID=7a683996-fcbd-11e9-9dce-0a58c0a80837,priority=4,
> timestamp=Fri Nov 01 16:37:14 CET 2019,expiration=0, durable=true,
> address=MESSAGE_REPORTER_TOPIC,size=4037,...SHORTENED...@792769859, with
> context:
> org.apache.activemq.artemis.core.server.impl.RoutingContextImpl@520310bf,
> direct: true, rejectDuplicates: true
> 16:37:14,419 INFO  [org.apache.activemq.artemis.core.server.plugin.impl]
> AMQ841010: routed message with ID: *17179879120*, result: *OK*
>
> Skipped few log lines about confirmation of recieved message,
> and now delivering message to wrong queue:
>
> 16:37:14,425 TRACE [org.apache.activemq.artemis.core.server.impl.QueueImpl]
> Queue *uiEventQueue-d336918f-fc37-44b9-9aeb-7e09fa90ad86 is delivering
> reference
>
> Reference[17179879120]*:RELIABLE:CoreMessage[messageID=17179879120,durable=true,userID=7a683996-fcbd-11e9-9dce-0a58c0a80837,priority=4,
> timestamp=Fri Nov 01 16:37:14 CET 2019,expiration=0, durable=true,
> address=MESSAGE_REPORTER_TOPIC,size=4037,...SHORTENED...@792769859
>
> (Log is filtered for messageID=17179879120)
>
> It still seems to me as wrong behaviour. I am trying with debugger to
> issolate issue, but it's quite complex.
> Any suggestions how to solve this?
>
>
>
> --
> Sent from:
> http://activemq.2283324.n4.nabble.com/ActiveMQ-User-f2341805.html
>
Reply | Threaded
Open this post in threaded view
|

Re: Messages ends in wrong queue [artemis 2.7.0]

pholik1
Hello Justin,

 It happens in quite complex setup of 50+ microservices(which send JMS and
STOMP messages) in Kubernetes cluster. About 20 messages arrives OK and 2
not.

But I've switched back and forth from 2.7.0 to 2.10.1 and it does not
happend on new version.

So we will promote our artemis.


Thanks for help.

Sincerely
Petr Holik



--
Sent from: http://activemq.2283324.n4.nabble.com/ActiveMQ-User-f2341805.html