Problem with message delivery or connectivity

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

Problem with message delivery or connectivity

dajood
Hi there,

I've got a problem with ActiveMQ and I'd like to ask you for help as I'm
too new to the whole matter to find out what's going on by myself.

The situation is as follows. There's a server in a datacenter, running a
software I've developed, using ActiveMQ 5.12.0 as an embedded broker.

Also, there are several JavaFX clients connecting to it. I'm dropping
text messages to an according topic as a heatbeat for these clients to
see that the server does its work properly. Childishly, this heartbeat
makes a green heart blink if it arrives and a broken heart blink if it
doesn't. All clients, including the problematic one, are running on a 64
bit JRE 1.8.0u66.

The main use of ActiveMQ is that business data is sent from the server
to all clients(using another topic than the heartbeat one) to update
some tables and charts.

Everything works as expected on several different machines and operating
systems, but there's one system that shows behaviour which I can find a
reason for. It's like this: My customer describes, that he actually sees
the green heart blinking, but there's no data arriving in the described
charts and tables.

First, I've put some debug output to the message listener for the
business data topic. It seems that it doesn't fire at all at this machine.

My second idea was to make sure the server is even reachable via network
from this PC. The machine is out of reach for me, remotely deployed at a
customers office. So I've asked their network admin to check the
connectivity. He could connect to the server and port (running on 5010,
using putty) successfully.

The customer wasn't able to provide my applications log so I gave him a
possibility to send me an excerpt via email. The output looks to me like
what I see when I just prevent internet connections and start the client
on my own machine. I'll put an excerpt to the end of this email.

How can I continue debugging this problem(especially without any access
to the customers machine)? What do those log entries tell an experienced
user?

I'm thankful for each hint.

Kind regards,

David



14:56:49.576 [main] DEBUG o.a.a.transport.WireFormatNegotiator -
Sending: WireFormatInfo { version=11,
properties={TcpNoDelayEnabled=true, SizePrefixDisabled=false,
CacheSize=1024, StackTraceEnabled=true, CacheEnabled=true,
TightEncodingEnabled=true, MaxFrameSize=9223372036854775807,
Host=80.xx.xx.76, MaxInactivityDuration=30000,
MaxInactivityDurationInitalDelay=10000}, magic=[A,c,t,i,v,e,M,Q]}
14:56:49.581 [ActiveMQ NIO Worker 2] DEBUG
o.a.a.transport.InactivityMonitor - Using min of local: WireFormatInfo {
version=11, properties={TcpNoDelayEnabled=true,
SizePrefixDisabled=false, CacheSize=1024, StackTraceEnabled=true,
CacheEnabled=true, TightEncodingEnabled=true,
MaxFrameSize=9223372036854775807, Host=80.xx.xx.76,
MaxInactivityDuration=30000, MaxInactivityDurationInitalDelay=10000},
magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo { version=11,
properties={TcpNoDelayEnabled=true, SizePrefixDisabled=false,
CacheSize=1024, StackTraceEnabled=true, CacheEnabled=true,
TightEncodingEnabled=true, MaxFrameSize=9223372036854775807,
MaxInactivityDuration=30000, MaxInactivityDurationInitalDelay=10000},
magic=[A,c,t,i,v,e,M,Q]}
14:56:49.583 [ActiveMQ NIO Worker 2] DEBUG
o.a.a.transport.WireFormatNegotiator - Received WireFormat:
WireFormatInfo { version=11, properties={TcpNoDelayEnabled=true,
SizePrefixDisabled=false, CacheSize=1024, StackTraceEnabled=true,
CacheEnabled=true, TightEncodingEnabled=true,
MaxFrameSize=9223372036854775807, MaxInactivityDuration=30000,
MaxInactivityDurationInitalDelay=10000}, magic=[A,c,t,i,v,e,M,Q]}
14:56:49.583 [ActiveMQ NIO Worker 2] DEBUG
o.a.a.transport.WireFormatNegotiator - tcp:///80.xx.xx.76:5010@57046
before negotiation: OpenWireFormat{version=11, cacheEnabled=false,
stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
14:56:49.584 [ActiveMQ NIO Worker 2] DEBUG
o.a.a.transport.WireFormatNegotiator - tcp:///80.xx.xx.76:5010@57046
after negotiation: OpenWireFormat{version=11, cacheEnabled=true,
stackTraceEnabled=true, tightEncodingEnabled=true,
sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
14:56:49.668 [main] DEBUG o.a.a.thread.TaskRunnerFactory - Initialized
TaskRunnerFactory[ActiveMQ Session Task] using ExecutorService:
java.util.concurrent.ThreadPoolExecutor@13df2a8c[Running, pool size = 0,
active threads = 0, queued tasks = 0, completed tasks = 0]
14:56:57.111 [actionTimer] DEBUG o.a.activemq.util.ThreadPoolUtils -
Shutdown of ExecutorService:
java.util.concurrent.ThreadPoolExecutor@13df2a8c[Terminated, pool size =
0, active threads = 0, queued tasks = 0, completed tasks = 73] is
shutdown: true and terminated: false took: 0.000 seconds.
14:56:57.111 [actionTimer] DEBUG o.a.activemq.util.ThreadPoolUtils -
Shutdown of ExecutorService:
java.util.concurrent.ThreadPoolExecutor@5e8c55c9[Terminated, pool size =
0, active threads = 0, queued tasks = 0, completed tasks = 0] is
shutdown: true and terminated: true took: 0.000 seconds.
14:56:57.112 [actionTimer] DEBUG o.a.a.transport.tcp.TcpTransport -
Stopping transport tcp:///80.xx.xx.76:5010@57046
14:56:57.113 [actionTimer] DEBUG o.a.a.thread.TaskRunnerFactory -
Initialized TaskRunnerFactory[ActiveMQ Task] using ExecutorService:
java.util.concurrent.ThreadPoolExecutor@908a851[Running, pool size = 0,
active threads = 0, queued tasks = 0, completed tasks = 0]
14:56:57.113 [ActiveMQ Task-1] DEBUG o.a.a.transport.tcp.TcpTransport -
Closed socket Socket[unconnected]
14:56:57.113 [actionTimer] DEBUG o.a.activemq.util.ThreadPoolUtils -
Forcing shutdown of ExecutorService:
java.util.concurrent.ThreadPoolExecutor@908a851[Running, pool size = 1,
active threads = 0, queued tasks = 0, completed tasks = 1]
14:56:57.122 [actionTimer] DEBUG o.a.a.transport.WireFormatNegotiator -
Sending: WireFormatInfo { version=11,
properties={TcpNoDelayEnabled=true, SizePrefixDisabled=false,
CacheSize=1024, StackTraceEnabled=true, CacheEnabled=true,
TightEncodingEnabled=true, MaxFrameSize=9223372036854775807,
Host=80.xx.xx.76, MaxInactivityDuration=30000,
MaxInactivityDurationInitalDelay=10000}, magic=[A,c,t,i,v,e,M,Q]}
14:56:57.146 [ActiveMQ NIO Worker 1] DEBUG
o.a.a.transport.InactivityMonitor - Using min of local: WireFormatInfo {
version=11, properties={TcpNoDelayEnabled=true,
SizePrefixDisabled=false, CacheSize=1024, StackTraceEnabled=true,
CacheEnabled=true, TightEncodingEnabled=true,
MaxFrameSize=9223372036854775807, Host=80.xx.xx.76,
MaxInactivityDuration=30000, MaxInactivityDurationInitalDelay=10000},
magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo { version=11,
properties={TcpNoDelayEnabled=true, SizePrefixDisabled=false,
CacheSize=1024, StackTraceEnabled=true, CacheEnabled=true,
TightEncodingEnabled=true, MaxFrameSize=9223372036854775807,
MaxInactivityDuration=30000, MaxInactivityDurationInitalDelay=10000},
magic=[A,c,t,i,v,e,M,Q]}
14:56:57.146 [ActiveMQ NIO Worker 1] DEBUG
o.a.a.transport.WireFormatNegotiator - Received WireFormat:
WireFormatInfo { version=11, properties={TcpNoDelayEnabled=true,
SizePrefixDisabled=false, CacheSize=1024, StackTraceEnabled=true,
CacheEnabled=true, TightEncodingEnabled=true,
MaxFrameSize=9223372036854775807, MaxInactivityDuration=30000,
MaxInactivityDurationInitalDelay=10000}, magic=[A,c,t,i,v,e,M,Q]}
14:56:57.147 [ActiveMQ NIO Worker 1] DEBUG
o.a.a.transport.WireFormatNegotiator - tcp:///80.xx.xx.76:5010@57135
before negotiation: OpenWireFormat{version=11, cacheEnabled=false,
stackTraceEnabled=false, tightEncodingEnabled=false,
sizePrefixDisabled=false, maxFrameSize=9223372036854775807}





Reply | Threaded
Open this post in threaded view
|

Re: Problem with message delivery or connectivity

Tim Bain
You can use a JMX viewer such as JConsole to look at the state of the
problematic consumer's subscription to the topic.  That will let you see if
the client is connected and if it's consuming messages.
On Nov 14, 2015 3:38 PM, "dajood" <[hidden email]> wrote:

> Hi there,
>
> I've got a problem with ActiveMQ and I'd like to ask you for help as I'm
> too new to the whole matter to find out what's going on by myself.
>
> The situation is as follows. There's a server in a datacenter, running a
> software I've developed, using ActiveMQ 5.12.0 as an embedded broker.
>
> Also, there are several JavaFX clients connecting to it. I'm dropping
> text messages to an according topic as a heatbeat for these clients to
> see that the server does its work properly. Childishly, this heartbeat
> makes a green heart blink if it arrives and a broken heart blink if it
> doesn't. All clients, including the problematic one, are running on a 64
> bit JRE 1.8.0u66.
>
> The main use of ActiveMQ is that business data is sent from the server
> to all clients(using another topic than the heartbeat one) to update
> some tables and charts.
>
> Everything works as expected on several different machines and operating
> systems, but there's one system that shows behaviour which I can find a
> reason for. It's like this: My customer describes, that he actually sees
> the green heart blinking, but there's no data arriving in the described
> charts and tables.
>
> First, I've put some debug output to the message listener for the
> business data topic. It seems that it doesn't fire at all at this machine.
>
> My second idea was to make sure the server is even reachable via network
> from this PC. The machine is out of reach for me, remotely deployed at a
> customers office. So I've asked their network admin to check the
> connectivity. He could connect to the server and port (running on 5010,
> using putty) successfully.
>
> The customer wasn't able to provide my applications log so I gave him a
> possibility to send me an excerpt via email. The output looks to me like
> what I see when I just prevent internet connections and start the client
> on my own machine. I'll put an excerpt to the end of this email.
>
> How can I continue debugging this problem(especially without any access
> to the customers machine)? What do those log entries tell an experienced
> user?
>
> I'm thankful for each hint.
>
> Kind regards,
>
> David
>
>
>
> 14:56:49.576 [main] DEBUG o.a.a.transport.WireFormatNegotiator -
> Sending: WireFormatInfo { version=11,
> properties={TcpNoDelayEnabled=true, SizePrefixDisabled=false,
> CacheSize=1024, StackTraceEnabled=true, CacheEnabled=true,
> TightEncodingEnabled=true, MaxFrameSize=9223372036854775807,
> Host=80.xx.xx.76, MaxInactivityDuration=30000,
> MaxInactivityDurationInitalDelay=10000}, magic=[A,c,t,i,v,e,M,Q]}
> 14:56:49.581 [ActiveMQ NIO Worker 2] DEBUG
> o.a.a.transport.InactivityMonitor - Using min of local: WireFormatInfo {
> version=11, properties={TcpNoDelayEnabled=true,
> SizePrefixDisabled=false, CacheSize=1024, StackTraceEnabled=true,
> CacheEnabled=true, TightEncodingEnabled=true,
> MaxFrameSize=9223372036854775807, Host=80.xx.xx.76,
> MaxInactivityDuration=30000, MaxInactivityDurationInitalDelay=10000},
> magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo { version=11,
> properties={TcpNoDelayEnabled=true, SizePrefixDisabled=false,
> CacheSize=1024, StackTraceEnabled=true, CacheEnabled=true,
> TightEncodingEnabled=true, MaxFrameSize=9223372036854775807,
> MaxInactivityDuration=30000, MaxInactivityDurationInitalDelay=10000},
> magic=[A,c,t,i,v,e,M,Q]}
> 14:56:49.583 [ActiveMQ NIO Worker 2] DEBUG
> o.a.a.transport.WireFormatNegotiator - Received WireFormat:
> WireFormatInfo { version=11, properties={TcpNoDelayEnabled=true,
> SizePrefixDisabled=false, CacheSize=1024, StackTraceEnabled=true,
> CacheEnabled=true, TightEncodingEnabled=true,
> MaxFrameSize=9223372036854775807, MaxInactivityDuration=30000,
> MaxInactivityDurationInitalDelay=10000}, magic=[A,c,t,i,v,e,M,Q]}
> 14:56:49.583 [ActiveMQ NIO Worker 2] DEBUG
> o.a.a.transport.WireFormatNegotiator - tcp:///80.xx.xx.76:5010@57046
> before negotiation: OpenWireFormat{version=11, cacheEnabled=false,
> stackTraceEnabled=false, tightEncodingEnabled=false,
> sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
> 14:56:49.584 [ActiveMQ NIO Worker 2] DEBUG
> o.a.a.transport.WireFormatNegotiator - tcp:///80.xx.xx.76:5010@57046
> after negotiation: OpenWireFormat{version=11, cacheEnabled=true,
> stackTraceEnabled=true, tightEncodingEnabled=true,
> sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
> 14:56:49.668 [main] DEBUG o.a.a.thread.TaskRunnerFactory - Initialized
> TaskRunnerFactory[ActiveMQ Session Task] using ExecutorService:
> java.util.concurrent.ThreadPoolExecutor@13df2a8c[Running, pool size = 0,
> active threads = 0, queued tasks = 0, completed tasks = 0]
> 14:56:57.111 [actionTimer] DEBUG o.a.activemq.util.ThreadPoolUtils -
> Shutdown of ExecutorService:
> java.util.concurrent.ThreadPoolExecutor@13df2a8c[Terminated, pool size =
> 0, active threads = 0, queued tasks = 0, completed tasks = 73] is
> shutdown: true and terminated: false took: 0.000 seconds.
> 14:56:57.111 [actionTimer] DEBUG o.a.activemq.util.ThreadPoolUtils -
> Shutdown of ExecutorService:
> java.util.concurrent.ThreadPoolExecutor@5e8c55c9[Terminated, pool size =
> 0, active threads = 0, queued tasks = 0, completed tasks = 0] is
> shutdown: true and terminated: true took: 0.000 seconds.
> 14:56:57.112 [actionTimer] DEBUG o.a.a.transport.tcp.TcpTransport -
> Stopping transport tcp:///80.xx.xx.76:5010@57046
> 14:56:57.113 [actionTimer] DEBUG o.a.a.thread.TaskRunnerFactory -
> Initialized TaskRunnerFactory[ActiveMQ Task] using ExecutorService:
> java.util.concurrent.ThreadPoolExecutor@908a851[Running, pool size = 0,
> active threads = 0, queued tasks = 0, completed tasks = 0]
> 14:56:57.113 [ActiveMQ Task-1] DEBUG o.a.a.transport.tcp.TcpTransport -
> Closed socket Socket[unconnected]
> 14:56:57.113 [actionTimer] DEBUG o.a.activemq.util.ThreadPoolUtils -
> Forcing shutdown of ExecutorService:
> java.util.concurrent.ThreadPoolExecutor@908a851[Running, pool size = 1,
> active threads = 0, queued tasks = 0, completed tasks = 1]
> 14:56:57.122 [actionTimer] DEBUG o.a.a.transport.WireFormatNegotiator -
> Sending: WireFormatInfo { version=11,
> properties={TcpNoDelayEnabled=true, SizePrefixDisabled=false,
> CacheSize=1024, StackTraceEnabled=true, CacheEnabled=true,
> TightEncodingEnabled=true, MaxFrameSize=9223372036854775807,
> Host=80.xx.xx.76, MaxInactivityDuration=30000,
> MaxInactivityDurationInitalDelay=10000}, magic=[A,c,t,i,v,e,M,Q]}
> 14:56:57.146 [ActiveMQ NIO Worker 1] DEBUG
> o.a.a.transport.InactivityMonitor - Using min of local: WireFormatInfo {
> version=11, properties={TcpNoDelayEnabled=true,
> SizePrefixDisabled=false, CacheSize=1024, StackTraceEnabled=true,
> CacheEnabled=true, TightEncodingEnabled=true,
> MaxFrameSize=9223372036854775807, Host=80.xx.xx.76,
> MaxInactivityDuration=30000, MaxInactivityDurationInitalDelay=10000},
> magic=[A,c,t,i,v,e,M,Q]} and remote: WireFormatInfo { version=11,
> properties={TcpNoDelayEnabled=true, SizePrefixDisabled=false,
> CacheSize=1024, StackTraceEnabled=true, CacheEnabled=true,
> TightEncodingEnabled=true, MaxFrameSize=9223372036854775807,
> MaxInactivityDuration=30000, MaxInactivityDurationInitalDelay=10000},
> magic=[A,c,t,i,v,e,M,Q]}
> 14:56:57.146 [ActiveMQ NIO Worker 1] DEBUG
> o.a.a.transport.WireFormatNegotiator - Received WireFormat:
> WireFormatInfo { version=11, properties={TcpNoDelayEnabled=true,
> SizePrefixDisabled=false, CacheSize=1024, StackTraceEnabled=true,
> CacheEnabled=true, TightEncodingEnabled=true,
> MaxFrameSize=9223372036854775807, MaxInactivityDuration=30000,
> MaxInactivityDurationInitalDelay=10000}, magic=[A,c,t,i,v,e,M,Q]}
> 14:56:57.147 [ActiveMQ NIO Worker 1] DEBUG
> o.a.a.transport.WireFormatNegotiator - tcp:///80.xx.xx.76:5010@57135
> before negotiation: OpenWireFormat{version=11, cacheEnabled=false,
> stackTraceEnabled=false, tightEncodingEnabled=false,
> sizePrefixDisabled=false, maxFrameSize=9223372036854775807}
>
>
>
>
>
>
>
>
>
> --
> View this message in context:
> http://activemq.2283324.n4.nabble.com/Problem-with-message-delivery-or-connectivity-tp4703964.html
> Sent from the ActiveMQ - User mailing list archive at Nabble.com.
Reply | Threaded
Open this post in threaded view
|

Re: Problem with message delivery or connectivity

artnaseef
JMX is a good tool here.  I would also start with some basics.

First, determine whether the client is actually connected to the broker box - the "netstat" command is a good one for that.  You'll need to know the client's IP address.

Second, if the client connection is confirmed at the network level, check the broker for a broker connection from that client, and see to what the client is subscribed.

Third, if subscriptions are found, check their statistics for messages being dispatched to the client.

Another approach to diagnosis of this problem - stand up another broker dedicated to diagnosing this one problem and configure the client to connect to the new broker only.  That will simplify the things to verify.