Issue with ActiveMQ and springboot app

[Jack Tauson]

I have a spring boot app which is deployed on tomcat on RHEL server which is trying to connect to ActiveMQ and it keeps on throwing following error in tomcat logs. Things were working fine till yesterday and today morning.

My application.properties of springboot app has following configuration:

 

 spring.activemq.broker-url=failover://tcp://localhost:61616
    spring.activemq.user=admin
    spring.activemq.password=admin
    jms.queue.destination=MyQueueName

   

2020-06-11 12:07:56.269  WARN 18092 --- [ActiveMQ Task-2] o.a.a.t.failover.FailoverTransport       : Failed to connect to [tcp://localhost:61616] after: 180 attempt(s) continuing to retry.
    2020-06-11 12:08:40.206  WARN 9914 --- [ActiveMQ Task-2] o.a.a.t.failover.FailoverTransport       : Failed to connect to [tcp://localhost:61616] after: 90 attempt(s) continuing to retry.
    2020-06-11 12:12:20.441  WARN 15290 --- [ActiveMQ Task-2] o.a.a.t.failover.FailoverTransport       : Failed to connect to [tcp://localhost:61616] after: 200 attempt(s) continuing to retry.
    2020-06-11 12:13:06.317  WARN 18092 --- [ActiveMQ Task-2] o.a.a.t.failover.FailoverTransport       : Failed to connect to [tcp://localhost:61616] after: 190 attempt(s) continuing to retry.
    2020-06-11 12:13:50.257  WARN 9914 --- [ActiveMQ Task-2] o.a.a.t.failover.FailoverTransport       : Failed to connect to [tcp://localhost:61616] after: 100 attempt(s) continuing to retry.
    2020-06-11 12:17:30.538  WARN 15290 --- [ActiveMQ Task-2] o.a.a.t.failover.FailoverTransport       : Failed to connect to [tcp://localhost:61616] after: 210 attempt(s) continuing to retry.
    2020-06-11 12:18:16.362  WARN 18092 --- [ActiveMQ Task-2] o.a.a.t.failover.FailoverTransport       : Failed to connect to [tcp://localhost:61616] after: 200 attempt(s) continuing to retry.
    2020-06-11 12:19:00.323  WARN 9914 --- [ActiveMQ Task-2] o.a.a.t.failover.FailoverTransport       : Failed to connect to [tcp://localhost:61616] after: 110 attempt(s) continuing to retry.
    2020-06-11 12:22:40.584  WARN 15290 --- [ActiveMQ Task-2] o.a.a.t.failover.FailoverTransport       : Failed to connect to [tcp://localhost:61616] after: 220 attempt(s) continuing to retry.
    2020-06-11 12:23:26.414  WARN 18092 --- [ActiveMQ Task-2] o.a.a.t.failover.FailoverTransport       : Failed to connect to [tcp://localhost:61616] after: 210 attempt(s) continuing to retry.
    2020-06-11 12:24:10.371  WARN 9914 --- [ActiveMQ Task-2] o.a.a.t.failover.FailoverTransport       : Failed to connect to [tcp://localhost:61616] after: 120 attempt(s) continuing to retry.
    2020-06-11 12:27:50.626  WARN 15290 --- [ActiveMQ Task-2] o.a.a.t.failover.FailoverTransport       : Failed to connect to [tcp://localhost:61616] after: 230 attempt(s) continuing to retry.
    2020-06-11 12:28:36.462  WARN 18092 --- [ActiveMQ Task-2] o.a.a.t.failover.FailoverTransport       : Failed to connect to [tcp://localhost:61616] after: 220 attempt(s) continuing to retry.
    2020-06-11 12:29:20.428  WARN 9914 --- [ActiveMQ Task-2] o.a.a.t.failover.FailoverTransport       : Failed to connect to [tcp://localhost:61616] after: 130 attempt(s) continuing to retry.

[Ron McLeod]

Jack Tauson wrote: spring.activemq.broker-url=failover://tcp://localhost:61616

Do you have ActiveMQ running on the local host?

You can see if there is anything listen on port 61616 with the command line: netstat -natp | grep 61616

[Jack Tauson]

Ron McLeod wrote:

Jack Tauson wrote: spring.activemq.broker-url=failover://tcp://localhost:61616

Do you have ActiveMQ running on the local host?

You can see if there is anything listen on port 61616 with the command line: netstat -natp | grep 61616

It was running before but not right now for some reason after I stopped it. How do I start it again since it's not starting? Here are few thing that I did:

[activemq@myservername servers]$ cd apache-activemq-5.15.11/

[activemq@myservername apache-activemq-5.15.11]$ bin/activemq start
INFO: Loading '/web/servers/apache-activemq-5.15.11//bin/env'
INFO: Using java '/bin/java'
INFO: Starting - inspect logfiles specified in logging.properties and log4j.properties to get details
INFO: pidfile created : '/web/servers/apache-activemq-5.15.11//data/activemq.pid' (pid '6996')
[activemq@myservername apache-activemq-5.15.11]$ bin/activemq start
INFO: Loading '/web/servers/apache-activemq-5.15.11//bin/env'
INFO: Using java '/bin/java'
INFO: Process with pid '6996' is already running

[activemq@myservername apache-activemq-5.15.11]$ bin/activemq start
INFO: Loading '/web/servers/apache-activemq-5.15.11//bin/env'
INFO: Using java '/bin/java'
INFO: Process with pid '6996' is already running

[activemq@myservername apache-activemq-5.15.11]$ bin/activemq stop
INFO: Loading '/web/servers/apache-activemq-5.15.11//bin/env'
INFO: Using java '/bin/java'
INFO: Waiting at least 30 seconds for regular process termination of pid '6996' :
Java Runtime: Oracle Corporation 1.8.0_242 /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.242.b08-1.el7.x86_64/jre
 Heap sizes: current=62976k  free=61991k  max=932352k
   JVM args: -Xms64M -Xmx1G -Djava.util.logging.config.file=logging.properties -Djava.security.auth.login.config=/web/servers/apache-activemq-5.15.11//conf/login.config -Dactivemq.classpath=/web/servers/apache-activemq-5.15.11//conf:/web/servers/apache-activemq-5.15.11//../lib/: -Dactivemq.home=/web/servers/apache-activemq-5.15.11/ -Dactivemq.base=/web/servers/apache-activemq-5.15.11/ -Dactivemq.conf=/web/servers/apache-activemq-5.15.11//conf -Dactivemq.data=/web/servers/apache-activemq-5.15.11//data
Extensions classpath:
 [/web/servers/apache-activemq-5.15.11/lib,/web/servers/apache-activemq-5.15.11/lib/camel,/web/servers/apache-activemq-5.15.11/lib/optional,/web/servers/apache-activemq-5.15.11/lib/web,/web/servers/apache-activemq-5.15.11/lib/extra]
ACTIVEMQ_HOME: /web/servers/apache-activemq-5.15.11
ACTIVEMQ_BASE: /web/servers/apache-activemq-5.15.11
ACTIVEMQ_CONF: /web/servers/apache-activemq-5.15.11/conf
ACTIVEMQ_DATA: /web/servers/apache-activemq-5.15.11/data
Connecting to pid: 6996
INFO: failed to resolve jmxUrl for pid:6996, using default JMX url
Connecting to JMX URL: service:jmx:rmi:///jndi/rmi://localhost:1099/jmxrmi
.INFO: Broker not available at: service:jmx:rmi:///jndi/rmi://localhost:1099/jmxrmi
..............................
INFO: Regular shutdown not successful,  sending SIGKILL to process
INFO: sending SIGKILL to pid '6996'

[activemq@myservername apache-activemq-5.15.11]$

So whenever I check whether its running or not using command  "bin/activemq start" I keep on getting "INFO: Process with pid '6996' is already running" as shown above. However, I am no longer seeing the admin console and also the command you mentioned "netstat -natp | grep 61616" is not returning any results. What might be the issue?



On my other server where it runs properly, it does show the following after running "netstat -natp | grep 61616"

(Not all processes could be identified, non-owned process info
 will not be shown, you would have to be root to see it all.)
tcp        0      0 0.0.0.0:61616           0.0.0.0:*               LISTEN      -
tcp        0      0 127.0.0.1:41290         127.0.0.1:61616         ESTABLISHED -
tcp        0      0 127.0.0.1:61616         127.0.0.1:41290         ESTABLISHED -

[Ron McLeod]

This is what I see ...

It was started when you tried the first time:
[activemq@myservername apache-activemq-5.15.11]$ bin/activemq start INFO: Loading '/web/servers/apache-activemq-5.15.11//bin/env' INFO: Using java '/bin/java' INFO: Starting - inspect logfiles specified in logging.properties and log4j.properties to get details INFO: pidfile created : '/web/servers/apache-activemq-5.15.11//data/activemq.pid' (pid '6996')
Then, while it was already running, you tried and start it again, and you are told that in-fact, it is already running:
[activemq@myservername apache-activemq-5.15.11]$ bin/activemq start INFO: Loading '/web/servers/apache-activemq-5.15.11//bin/env' INFO: Using java '/bin/java' INFO: Process with pid '6996' is already running
Same thing again:
[activemq@myservername apache-activemq-5.15.11]$ bin/activemq start INFO: Loading '/web/servers/apache-activemq-5.15.11//bin/env' INFO: Using java '/bin/java' INFO: Process with pid '6996' is already running

[Jack Tauson]

Ron McLeod wrote:This is what I see ...

It was started when you tried the first time:
[activemq@myservername apache-activemq-5.15.11]$ bin/activemq start INFO: Loading '/web/servers/apache-activemq-5.15.11//bin/env' INFO: Using java '/bin/java' INFO: Starting - inspect logfiles specified in logging.properties and log4j.properties to get details INFO: pidfile created : '/web/servers/apache-activemq-5.15.11//data/activemq.pid' (pid '6996')
Then, while it was already running, you tried and start it again, and you are told that in-fact, it is already running:
[activemq@myservername apache-activemq-5.15.11]$ bin/activemq start INFO: Loading '/web/servers/apache-activemq-5.15.11//bin/env' INFO: Using java '/bin/java' INFO: Process with pid '6996' is already running
Same thing again:
[activemq@myservername apache-activemq-5.15.11]$ bin/activemq start INFO: Loading '/web/servers/apache-activemq-5.15.11//bin/env' INFO: Using java '/bin/java' INFO: Process with pid '6996' is already running

Right. In spite of it telling me that it's already running, I am wondering why I'm not able to see it listening on port 61616?

The following command doesn't shows anything :

[activemq@myservername apache-activemq-5.15.11]$ netstat -a |grep 61616
[activemq@myservername apache-activemq-5.15.11]$ 

Whereas, on the other RHEL server, where it is running, I can see the following:

[jtauson@myservernam1 apache-activemq-5.15.8]$  netstat -natp | grep 61616
(Not all processes could be identified, non-owned process info
 will not be shown, you would have to be root to see it all.)
tcp        0      0 0.0.0.0:61616           0.0.0.0:*               LISTEN      -
tcp        0      0 127.0.0.1:41290         127.0.0.1:61616         ESTABLISHED -
tcp        0      0 127.0.0.1:61616         127.0.0.1:41290         ESTABLISHED -

[Ron McLeod]

Jack Tauson wrote:Right. In spite of it telling me that it's already running, I am wondering why I'm not able to see it listening on port 61616?

The following command doesn't shows anything :[activemq@myservername apache-activemq-5.15.11]$ netstat -a |grep 61616 [activemq@myservername apache-activemq-5.15.11]$
Whereas, on the other RHEL server, where it is running, I can see the following:
[jtauson@myservernam1 apache-activemq-5.15.8]$  netstat -natp | grep 61616 (Not all processes could be identified, non-owned process info will not be shown, you would have to be root to see it all.) tcp        0      0 0.0.0.0:61616           0.0.0.0:*               LISTEN      - tcp        0      0 127.0.0.1:41290         127.0.0.1:61616         ESTABLISHED - tcp        0      0 127.0.0.1:61616         127.0.0.1:41290         ESTABLISHED -

Well .. my first guess would be that it is not configured to use port 61616.  Check your configuration to verify (I think it is an attribute of the transportConnector element in the activemq.xml file).

[Jack Tauson]

Ron McLeod wrote:

Jack Tauson wrote:Right. In spite of it telling me that it's already running, I am wondering why I'm not able to see it listening on port 61616?

The following command doesn't shows anything :[activemq@myservername apache-activemq-5.15.11]$ netstat -a |grep 61616 [activemq@myservername apache-activemq-5.15.11]$
Whereas, on the other RHEL server, where it is running, I can see the following:
[jtauson@myservernam1 apache-activemq-5.15.8]$  netstat -natp | grep 61616 (Not all processes could be identified, non-owned process info will not be shown, you would have to be root to see it all.) tcp        0      0 0.0.0.0:61616           0.0.0.0:*               LISTEN      - tcp        0      0 127.0.0.1:41290         127.0.0.1:61616         ESTABLISHED - tcp        0      0 127.0.0.1:61616         127.0.0.1:41290         ESTABLISHED -

Well .. my first guess would be that it is not configured to use port 61616.  Check your configuration to verify (I think it is an attribute of the transportConnector element in the activemq.xml file).

I compared activemq.xml of both the server and they both are identical.

I noticed the following things though on both the server:

At myservername:

[jtauson@myservername servers]$ wget localhost:8161/admin --user admin --password admin
--2020-06-11 18:53:09--  http://localhost:8161/admin
Resolving localhost (localhost)... 127.0.0.1
Connecting to localhost (localhost)|127.0.0.1|:8161... failed: Connection refused.

Whereas, in other server, it connects fine as shown below:

[jtauson@myservername1 apache-activemq-5.15.8]$ wget localhost:8161/admin --user admin --password admin
--2020-06-11 18:52:54--  http://localhost:8161/admin
Resolving localhost (localhost)... 127.0.0.1
Connecting to localhost (localhost)|127.0.0.1|:8161... connected.
HTTP request sent, awaiting response... 302 Found
Location: http://localhost:8161/admin/ [following]
--2020-06-11 18:52:54--  http://localhost:8161/admin/
Reusing existing connection to localhost:8161.
HTTP request sent, awaiting response... 200 OK
Length: 8243 (8.0K) [text/html]
Saving to: ‘admin.4’

100%[======================================================================================================================================>] 8,243       --.-K/s   in 0s

2020-06-11 18:52:54 (42.6 MB/s) - ‘admin.4’ saved [8243/8243]

Could this be an issue?

[Ron McLeod]

Jack Tauson wrote:[jtauson@myservername servers]$ wget localhost:8161/admin --user admin --password admin --2020-06-11 18:53:09--  http://localhost:8161/admin Resolving localhost (localhost)... 127.0.0.1 Connecting to localhost (localhost)|127.0.0.1|:8161... failed: Connection refused.

Do you have a web server (Tomcat?) running on the local host and listening on port 8161?  What does netstat show?

[Ron McLeod]

Ron McLeod wrote:Well .. my first guess would be that it is not configured to use port 61616.  Check your configuration to verify (I think it is an attribute of the transportConnector element in the activemq.xml file).

Jack Tauson wrote:I compared activemq.xml of both the server and they both are identical.

Maybe it's picking-up its configuration from a different configuration file?

Can you enable detailed logging on ActiveMQ and see what configuration it being used when the broker starts?

[Jack Tauson]

Ron McLeod wrote:

Jack Tauson wrote:[jtauson@myservername servers]$ wget localhost:8161/admin --user admin --password admin --2020-06-11 18:53:09--  http://localhost:8161/admin Resolving localhost (localhost)... 127.0.0.1 Connecting to localhost (localhost)|127.0.0.1|:8161... failed: Connection refused.

Do you have a web server (Tomcat?) running on the local host and listening on port 8161?  What does netstat show?

Yes, I do have a tomcat running and this is what it shows with the server:

[tomcat@myservername servers]$ netstat -natp | grep 61616
(Not all processes could be identified, non-owned process info
 will not be shown, you would have to be root to see it all.)
[tomcat@myservername servers]$

and

[tomcat@myservername servers]$ netstat -natp | grep 8161
(Not all processes could be identified, non-owned process info
 will not be shown, you would have to be root to see it all.)
[tomcat@myservername servers]$

Is tomcat supposed to listnen on port 8161 & 61616. I have removed my apps from tomcat since it was messing up with the starting of other apps with the following error and was not letting other apps to start.

 2020-06-11 12:18:16.362  WARN 18092 --- [ActiveMQ Task-2] o.a.a.t.failover.FailoverTransport       : Failed to connect to [tcp://localhost:61616] after: 200 attempt(s) continuing to retry.

On the server where everything works fine, it shows like this:

[jtauson@myservername1 apache-tomcat-8.5.38]$ netstat -natp | grep 61616
(Not all processes could be identified, non-owned process info
 will not be shown, you would have to be root to see it all.)
tcp        0      0 0.0.0.0:61616           0.0.0.0:*               LISTEN      -
tcp        0      0 127.0.0.1:41290         127.0.0.1:61616         ESTABLISHED -
tcp        0      0 127.0.0.1:61616         127.0.0.1:41290         ESTABLISHED -
[jtauson@myservername1 apache-tomcat-8.5.38]$

and

[jtauson@myservername1 apache-tomcat-8.5.38]$ netstat -natp | grep 8161
(Not all processes could be identified, non-owned process info
 will not be shown, you would have to be root to see it all.)
tcp        0      0 0.0.0.0:8161            0.0.0.0:*               LISTEN      -
[jtauson@myservername1 apache-tomcat-8.5.38]$

[Jack Tauson]

Ron McLeod wrote:

Ron McLeod wrote:Well .. my first guess would be that it is not configured to use port 61616.  Check your configuration to verify (I think it is an attribute of the transportConnector element in the activemq.xml file).

Jack Tauson wrote:I compared activemq.xml of both the server and they both are identical.

Maybe it's picking-up its configuration from a different configuration file?

Can you enable detailed logging on ActiveMQ and see what configuration it being used when the broker starts?

How to enable detail logging?

I haveactivemq.log inside  /web/servers/apache-activemq-5.15.11/data. Is this enough?

[Ron McLeod]

Jack Tauson wrote:How to enable detail logging?

I don't know - what logging framwork are you using?

Jack Tauson wrote:I haveactivemq.log inside  /web/servers/apache-activemq-5.15.11/data. Is this enough?

I don't know that either - have you looked at the log to see if there are any clues about what might be going on?

[Ron McLeod]

Jack Tauson wrote:Is tomcat supposed to listnen on port 8161 & 61616

Tomcat and ActiveMQ listen on the ports as configured.  By default Tomcat will listen for HTTP traffic on port 8080; ActiveMQ's default port is 61616.

[Jack Tauson]

Ron McLeod wrote:

Jack Tauson wrote:How to enable detail logging?

I don't know - what logging framwork are you using?

Jack Tauson wrote:I haveactivemq.log inside  /web/servers/apache-activemq-5.15.11/data. Is this enough?

I don't know that either - have you looked at the log to see if there are any clues about what might be going on?

I enabled it like this "log4j.logger.org.apache.activemq=DEBUG" (https://activemq.apache.org/how-do-i-enable-debug-logging) but not sure if it made any difference.

When I went inside activemq.log, this is what I see for today. I stopped and started the server and did nothing else:

2020-06-12 08:10:49,029 | DEBUG | Using class path resource [activemq.xml] from activemq.xml | org.apache.activemq.xbean.XBeanBrokerFactory | main
2020-06-12 08:10:49,054 | INFO  | Refreshing org.apache.activemq.xbean.XBeanBrokerFactory$1@1a968a59: startup date [Fri Jun 12 08:10:49 CDT 2020]; root of context hierarchy | org.apache.activemq.xbean.XBeanBrokerFactory$1 | main
2020-06-12 08:10:49,513 | DEBUG | Bean factory for org.apache.activemq.xbean.XBeanBrokerFactory$1@1a968a59: org.springframework.beans.factory.support.DefaultListableBeanFactory@2aece37d: defining beans [org.springframework.beans.factory.config.PropertyPlaceholderConfigurer#0,logQuery,org.apache.activemq.xbean.XBeanBrokerService#0,securityLoginService,securityConstraint,adminSecurityConstraint,securityConstraintMapping,adminSecurityConstraintMapping,rewriteHandler,secHandlerCollection,securityHandler,contexts,jettyPort,Server,invokeConnectors,configureJetty,invokeStart]; root of factory hierarchy | org.apache.activemq.xbean.XBeanBrokerFactory$1 | main
2020-06-12 08:10:49,611 | DEBUG | Unable to locate MessageSource with name 'messageSource': using default [org.springframework.context.support.DelegatingMessageSource@f5ac9e4] | org.apache.activemq.xbean.XBeanBrokerFactory$1 | main
2020-06-12 08:10:49,612 | DEBUG | Unable to locate ApplicationEventMulticaster with name 'applicationEventMulticaster': using default [org.springframework.context.event.SimpleApplicationEventMulticaster@42e99e4a] | org.apache.activemq.xbean.XBeanBrokerFactory$1 | main
2020-06-12 08:10:49,873 | INFO  | Using Persistence Adapter: KahaDBPersistenceAdapter[/web/servers/apache-activemq-5.15.11/data/kahadb] | org.apache.activemq.broker.BrokerService | main
2020-06-12 08:10:49,883 | INFO  | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked by another server. This broker is now in slave mode waiting a lock to be acquired | org.apache.activemq.store.SharedFileLocker | main
2020-06-12 08:10:49,889 | DEBUG | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked... waiting 10 seconds for the database to be unlocked. Reason: java.io.FileNotFoundException: /web/servers/apache-activemq-5.15.11/data/kahadb/lock (Permission denied) | org.apache.activemq.store.SharedFileLocker | main
2020-06-12 08:10:59,890 | DEBUG | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked... waiting 10 seconds for the database to be unlocked. Reason: java.io.FileNotFoundException: /web/servers/apache-activemq-5.15.11/data/kahadb/lock (Permission denied) | org.apache.activemq.store.SharedFileLocker | main
2020-06-12 08:11:09,892 | DEBUG | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked... waiting 10 seconds for the database to be unlocked. Reason: java.io.FileNotFoundException: /web/servers/apache-activemq-5.15.11/data/kahadb/lock (Permission denied) | org.apache.activemq.store.SharedFileLocker | main
2020-06-12 08:11:19,894 | DEBUG | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked... waiting 10 seconds for the database to be unlocked. Reason: java.io.FileNotFoundException: /web/servers/apache-activemq-5.15.11/data/kahadb/lock (Permission denied) | org.apache.activemq.store.SharedFileLocker | main
2020-06-12 08:11:29,895 | DEBUG | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked... waiting 10 seconds for the database to be unlocked. Reason: java.io.FileNotFoundException: /web/servers/apache-activemq-5.15.11/data/kahadb/lock (Permission denied) | org.apache.activemq.store.SharedFileLocker | main
2020-06-12 08:11:39,897 | DEBUG | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked... waiting 10 seconds for the database to be unlocked. Reason: java.io.FileNotFoundException: /web/servers/apache-activemq-5.15.11/data/kahadb/lock (Permission denied) | org.apache.activemq.store.SharedFileLocker | main
2020-06-12 08:11:49,898 | DEBUG | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked... waiting 10 seconds for the database to be unlocked. Reason: java.io.FileNotFoundException: /web/servers/apache-activemq-5.15.11/data/kahadb/lock (Permission denied) | org.apache.activemq.store.SharedFileLocker | main
2020-06-12 08:11:59,900 | DEBUG | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked... waiting 10 seconds for the database to be unlocked. Reason: java.io.FileNotFoundException: /web/servers/apache-activemq-5.15.11/data/kahadb/lock (Permission denied) | org.apache.activemq.store.SharedFileLocker | main
2020-06-12 08:12:09,901 | DEBUG | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked... waiting 10 seconds for the database to be unlocked. Reason: java.io.FileNotFoundException: /web/servers/apache-activemq-5.15.11/data/kahadb/lock (Permission denied) | org.apache.activemq.store.SharedFileLocker | main
2020-06-12 08:12:19,903 | DEBUG | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked... waiting 10 seconds for the database to be unlocked. Reason: java.io.FileNotFoundException: /web/servers/apache-activemq-5.15.11/data/kahadb/lock (Permission denied) | org.apache.activemq.store.SharedFileLocker | main
2020-06-12 08:12:29,904 | DEBUG | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked... waiting 10 seconds for the database to be unlocked. Reason: java.io.FileNotFoundException: /web/servers/apache-activemq-5.15.11/data/kahadb/lock (Permission denied) | org.apache.activemq.store.SharedFileLocker | main
2020-06-12 08:12:39,906 | DEBUG | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked... waiting 10 seconds for the database to be unlocked. Reason: java.io.FileNotFoundException: /web/servers/apache-activemq-5.15.11/data/kahadb/lock (Permission denied) | org.apache.activemq.store.SharedFileLocker | main
2020-06-12 08:12:49,907 | DEBUG | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked... waiting 10 seconds for the database to be unlocked. Reason: java.io.FileNotFoundException: /web/servers/apache-activemq-5.15.11/data/kahadb/lock (Permission denied) | org.apache.activemq.store.SharedFileLocker | main
2020-06-12 08:12:59,909 | DEBUG | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked... waiting 10 seconds for the database to be unlocked. Reason: java.io.FileNotFoundException: /web/servers/apache-activemq-5.15.11/data/kahadb/lock (Permission denied) | org.apache.activemq.store.SharedFileLocker | main
2020-06-12 08:13:09,911 | DEBUG | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked... waiting 10 seconds for the database to be unlocked. Reason: java.io.FileNotFoundException: /web/servers/apache-activemq-5.15.11/data/kahadb/lock (Permission denied) | org.apache.activemq.store.SharedFileLocker | main
2020-06-12 08:13:19,912 | DEBUG | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked... waiting 10 seconds for the database to be unlocked. Reason: java.io.FileNotFoundException: /web/servers/apache-activemq-5.15.11/data/kahadb/lock (Permission denied) | org.apache.activemq.store.SharedFileLocker | main
2020-06-12 08:13:29,914 | DEBUG | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked... waiting 10 seconds for the database to be unlocked. Reason: java.io.FileNotFoundException: /web/servers/apache-activemq-5.15.11/data/kahadb/lock (Permission denied) | org.apache.activemq.store.SharedFileLocker | main
2020-06-12 08:13:39,915 | DEBUG | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked... waiting 10 seconds for the database to be unlocked. Reason: java.io.FileNotFoundException: /web/servers/apache-activemq-5.15.11/data/kahadb/lock (Permission denied) | org.apache.activemq.store.SharedFileLocker | main
2020-06-12 08:13:49,916 | DEBUG | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked... waiting 10 seconds for the database to be unlocked. Reason: java.io.FileNotFoundException: /web/servers/apache-activemq-5.15.11/data/kahadb/lock (Permission denied) | org.apache.activemq.store.SharedFileLocker | main
2020-06-12 08:13:59,918 | DEBUG | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked... waiting 10 seconds for the database to be unlocked. Reason: java.io.FileNotFoundException: /web/servers/apache-activemq-5.15.11/data/kahadb/lock (Permission denied) | org.apache.activemq.store.SharedFileLocker | main
2020-06-12 08:14:09,922 | DEBUG | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked... waiting 10 seconds for the database to be unlocked. Reason: java.io.FileNotFoundException: /web/servers/apache-activemq-5.15.11/data/kahadb/lock (Permission denied) | org.apache.activemq.store.SharedFileLocker | main
2020-06-12 08:14:19,923 | DEBUG | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked... waiting 10 seconds for the database to be unlocked. Reason: java.io.FileNotFoundException: /web/servers/apache-activemq-5.15.11/data/kahadb/lock (Permission denied) | org.apache.activemq.store.SharedFileLocker | main
2020-06-12 08:14:29,925 | DEBUG | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked... waiting 10 seconds for the database to be unlocked. Reason: java.io.FileNotFoundException: /web/servers/apache-activemq-5.15.11/data/kahadb/lock (Permission denied) | org.apache.activemq.store.SharedFileLocker | main
2020-06-12 08:14:39,926 | DEBUG | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked... waiting 10 seconds for the database to be unlocked. Reason: java.io.FileNotFoundException: /web/servers/apache-activemq-5.15.11/data/kahadb/lock (Permission denied) | org.apache.activemq.store.SharedFileLocker | main

[Jack Tauson]

Ron McLeod wrote:

Jack Tauson wrote:Is tomcat supposed to listnen on port 8161 & 61616

Tomcat and ActiveMQ listen on the ports as configured.  By default Tomcat will listen for HTTP traffic on port 8080; ActiveMQ's default port is 61616.

Yeah, and as soon as I start activemq, I would imagine that port 61616 should show up with the command netstat -a | grep 61616

[Paul Clapham]

Jack Tauson wrote:Yeah, and as soon as I start activemq, I would imagine that port 61616 should show up with the command netstat -a | grep 61616

And if it doesn't, there are two possibilities for that. One is that it's configured to start on some other port, and the other reason is that it failed to start for some reason other than something is already using port 61616. So you need to consider those, for a start.

[Ron McLeod]

Jack Tauson wrote:... When I went inside activemq.log, this is what I see for today. I stopped and started the server and did nothing else

This message seems to explain the problem:2020-06-12 08:10:49,883 | INFO  | Database /web/servers/apache-activemq-5.15.11/data/kahadb/lock is locked by another server. This broker is now in slave mode waiting a lock to be acquired | org.apache.activemq.store.SharedFileLocker | main
ActiveMQ Master/Slave behavior

[Jack Tauson]

Paul Clapham wrote:

Jack Tauson wrote:Yeah, and as soon as I start activemq, I would imagine that port 61616 should show up with the command netstat -a | grep 61616

And if it doesn't, there are two possibilities for that. One is that it's configured to start on some other port, and the other reason is that it failed to start for some reason other than something is already using port 61616. So you need to consider those, for a start.

Instead of figuring this out, I went ahead and asked my server team to install it fresh from the tar file. I'm now seeing the following :

[activemq@myserver apache-activemq-5.15.11]$ netstat -a | grep 61616
tcp6       0      0 [::]:61616              [::]:*                  LISTEN

However, I'm still not sure why it's picking up "tcp6" instead of "tcp" above.

And on my other server, I see two more items listed as shown below (two ESTABLISHED ones), which are not showing above for some reason:

[jtauson@myservername1 apache-tomcat-8.5.38]$ netstat -natp | grep 61616
(Not all processes could be identified, non-owned process info
 will not be shown, you would have to be root to see it all.)
tcp        0      0 0.0.0.0:61616           0.0.0.0:*               LISTEN      -
tcp        0      0 127.0.0.1:41290         127.0.0.1:61616         ESTABLISHED -
tcp        0      0 127.0.0.1:61616         127.0.0.1:41290         ESTABLISHED -

[Ron McLeod]

Jack Tauson wrote:Instead of figuring this out, I went ahead and asked my server team to install it fresh from the tar file.

Personally, I would have kept digging so it is happened again I would know what to do.  In your case, it could have just been a stale lock file(?).

Jack Tauson wrote:[activemq@myserver apache-activemq-5.15.11]$ netstat -a | grep 61616 tcp6       0      0 [::]:61616              [::]:*                  LISTEN
However, I'm still not sure why it's picking up "tcp6" instead of "tcp" above.

That server appears to be configured for IPv6 (as well as IPv4).

[Jack Tauson]

Personally, I would have kept digging so it is happened again I would know what to do.  In your case, it could have just been a stale lock file(?).

I agree. Not sure about the state lock file. I never did anything related to that so not sure why it was showing like that in previous installation.

I checked your post - https://coderanch.com/t/731494/frameworks/ActiveMQ-springboot-app#3403572

Someone mentioned in that post that it's normal. But again, I didn't do anything related to kahab stuff. I don't know what that even means.

That server appears to be configured for IPv6 (as well as IPv4).

Right. I hope it always shows tcp6 protocol while checking netstat ( I mean after several shutdown and restarts ) because for applications deployed on that server, I would have to configure my application.properties file  with "tcp6" instead of "tcp".

[Ron McLeod]

Jack Tauson wrote:

Ron McLeod wrote:That server appears to be configured for IPv6 (as well as IPv4).

Right. I hope it always shows tcp6 protocol while checking netstat ( I mean after several shutdown and restarts ) because for applications deployed on that server, I would have to configure my application.properties file  with "tcp6" instead of "tcp".

I would assume that it is listening for both IPv4 and IPv6 connections, so no need to change.

You can verify by either running your application as-is, or use something like curl to verify it is possible to make a connection with IPv4.

For example (the data transfer information is unimportant):$ curl -4 localhost:61616 > /dev/null  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current                                 Dload  Upload   Total   Spent    Left  Speed 100   402    0   402    0     0  54068      0 --:--:-- --:--:-- --:--:-- 67000 $ curl -4 localhost:61617 > /dev/null curl: (7) couldn't connect to host

[Jack Tauson]

I would assume that it is listening for both IPv4 and IPv6 connections, so no need to change.

But if my application tries to connect over "tcp" and on the server, it is listening over "tcp6", wouldn't it fail?

You can verify by either running your application as-is, or use something like curl to verify it is possible to make a connection with IPv4.

For example (the data transfer information is unimportant):$ curl -4 localhost:61616 > /dev/null  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current                                 Dload  Upload   Total   Spent    Left  Speed 100   402    0   402    0     0  54068      0 --:--:-- --:--:-- --:--:-- 67000 $ curl -4 localhost:61617 > /dev/null curl: (7) couldn't connect to host

Sorry I didn't understand this. Does the above information shows that the server is configured for IPV4 and 6?

[Ron McLeod]

Jack Tauson wrote:Sorry I didn't understand this. Does the above information shows that the server is configured for IPV4 and 6?

In the first example, a connection to the specified port is able to be successfully established using IPv4.  This is what you want to verify

In the second example, a connection to the specified port fails with: "couldn't connect to host" because there is nothing listening on the port.  I included this so you could see what a failed connection attempt with curl looks like.

Even though curl isn't really intended to be used in this way, I was suggesting to use it to determine if you can make an IPv4 connection because it is available on almost all distributions and I have no idea what other tools might be available to you.  If it is more confusing than helpful, then just run your application configured for IPv4 and verify that it can connect to the broker.

[Jack Tauson]

Ron McLeod wrote:

Jack Tauson wrote:Sorry I didn't understand this. Does the above information shows that the server is configured for IPV4 and 6?

In the first example, a connection to the specified port is able to be successfully established using IPv4.  This is what you want to verify

In the second example, a connection to the specified port fails with: "couldn't connect to host" because there is nothing listening on the port.  I included this so you could see what a failed connection attempt with curl looks like.

Even though curl isn't really intended to be used in this way, I was suggesting to use it to determine if you can make an IPv4 connection because it is available on almost all distributions and I have no idea what other tools might be available to you.  If it is more confusing than helpful, then just run your application configured for IPv4 and verify that it can connect to the broker.

Thanks. Could you also answer this question that I asked above :

But if my application tries to connect over "tcp" and on the server, it is listening over "tcp6", wouldn't it fail?

Thanks very much !

[Jack Tauson]

Ron McLeod wrote:

Jack Tauson wrote:Sorry I didn't understand this. Does the above information shows that the server is configured for IPV4 and 6?

In the first example, a connection to the specified port is able to be successfully established using IPv4.  This is what you want to verify

In the second example, a connection to the specified port fails with: "couldn't connect to host" because there is nothing listening on the port.  I included this so you could see what a failed connection attempt with curl looks like.

Even though curl isn't really intended to be used in this way, I was suggesting to use it to determine if you can make an IPv4 connection because it is available on almost all distributions and I have no idea what other tools might be available to you.  If it is more confusing than helpful, then just run your application configured for IPv4 and verify that it can connect to the broker.

I saw the following:

[activemq@myservername1 apache-activemq-5.15.11]$ curl -4 localhost:61616 > /dev/null
 % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                Dload  Upload   Total   Spent    Left  Speed
 0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
curl: (52) Empty reply from server

Does this mean that even though netstat is showing "tcp6" I should not change it to "tcp6" in my application.properties and keep it as "tcp" only?

[Ron McLeod]

Jack Tauson wrote:Thanks. Could you also answer this question that I asked above :
But if my application tries to connect over "tcp" and on the server, it is listening over "tcp6", wouldn't it fail?

Thanks very much !

I don't think I can answer that question any better than I already have.

Ron McLeod wrote:I would assume that it is listening for both IPv4 and IPv6 connections, so no need to change.

You can verify by either running your application as-is, or use something like curl to verify it is possible to make a connection with IPv4.

Since you have access to the platform - give it a try and see what happens.

[Jack Tauson]

I don't think I can answer that question any better than I already have.

Ok, and if I want to check connection establishment over IPv6, then I would just use number "6" instead of "4" in the curl request you used for testing IPv4?

[Ron McLeod]

Jack Tauson wrote:Ok, and if I want to check connection establishment over IPv6, then I would just use number "6" instead of "4" in the curl request you used for testing IPv4?

Yes.