Hi,
We are using ActiveMQ 5.10.0 with the replicated LevelDB store, with leader
election handled by ZooKeeper.
We have encountered an issue where the ZooKeeper session expired on all of
our 3 AMQ instances.
However, no leader election took place to elect a master after a new
session was established, so even though all AMQ nodes were up and running,
none of them were listening for messages on port 61616.
Has anyone else encountered this issue? Is this a bug? I have not attempted
to replicate this yet.
I pasted the relevant logs below. Notably, after 2014-10-18 09:04:47,585,
no leader election took place; we restarted the activemq process
at 2014-10-18 15:13:14,541
Thanks,
-Roman
2014-10-18 09:04:31,904 | WARN | [/activemq/leveldb-stores/00000000084]
[ZooKeeperTreeTracker@51987ed7] [Thread[main-EventThread,5,main]] Error in
treeWatcher (ignored) | org.linkedin.zookeeper.tracker.ZooKeeperTreeTracker
| main-EventThread
org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /activemq/leveldb-stores/00000000084
at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)[zookeeper-3.4.5.jar:3.4.5-1392090]
at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)[zookeeper-3.4.5.jar:3.4.5-1392090]
at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1151)[zookeeper-3.4.5.jar:3.4.5-1392090]
at
org.linkedin.zookeeper.client.ZooKeeperImpl.getData(ZooKeeperImpl.java:191)[org.linkedin.zookeeper-impl-1.4.0.jar:]
at
org.linkedin.zookeeper.client.AbstractZooKeeper.getData(AbstractZooKeeper.java:213)[org.linkedin.zookeeper-impl-1.4.0.jar:]
at
org.linkedin.zookeeper.client.AbstractZKClient.getZKByteData(AbstractZKClient.java:213)[org.linkedin.zookeeper-impl-1.4.0.jar:]
at
org.linkedin.zookeeper.tracker.ZKByteArrayDataReader.readData(ZKByteArrayDataReader.java:37)[org.linkedin.zookeeper-impl-1.4.0.jar:]
at
org.linkedin.zookeeper.tracker.ZooKeeperTreeTracker.trackNode(ZooKeeperTreeTracker.java:280)[org.linkedin.zookeeper-impl-1.4.0.jar:]
at
org.linkedin.zookeeper.tracker.ZooKeeperTreeTracker.handleNodeDeleted(ZooKeeperTreeTracker.java:359)[org.linkedin.zookeeper-impl-1.4.0.jar:]
at
org.linkedin.zookeeper.tracker.ZooKeeperTreeTracker.access$500(ZooKeeperTreeTracker.java:50)[org.linkedin.zookeeper-impl-1.4.0.jar:]
at
org.linkedin.zookeeper.tracker.ZooKeeperTreeTracker$TreeWatcher.process(ZooKeeperTreeTracker.java:94)[org.linkedin.zookeeper-impl-1.4.0.jar:]
at
org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)[zookeeper-3.4.5.jar:3.4.5-1392090]
at
org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)[zookeeper-3.4.5.jar:3.4.5-1392090]
2014-10-18 09:04:31,905 | WARN | unprocessed event state: AuthFailed |
org.apache.activemq.leveldb.replicated.groups.ZKClient | main-EventThread
2014-10-18 09:04:31,905 | WARN | Expiration detected: trying to restart...
| org.apache.activemq.leveldb.replicated.groups.ZKClient | main-EventThread
2014-10-18 09:04:31,906 | INFO | Initiating client connection,
connectString=cargo308:2181,cargo309:2181,cargo310:2181 sessionTimeout=2000
watcher=org.apache.activemq.leveldb.replicated.groups.ZKClient@512edb17 |
org.apache.zookeeper.ZooKeeper | main-EventThread
2014-10-18 09:04:31,909 | INFO | EventThread shut down |
org.apache.zookeeper.ClientCnxn | main-EventThread
2014-10-18 09:04:31,911 | WARN | SASL configuration failed:
javax.security.auth.login.LoginException: No JAAS configuration section
named 'Client' was found in specified JAAS configuration file:
'/home/apps/activemq/conf/login.config'. Will continue connection to
Zookeeper server without SASL authentication, if Zookeeper server allows
it. | org.apache.zookeeper.ClientCnxn | main-SendThread(cargo309:2181)
2014-10-18 09:04:31,911 | INFO | Opening socket connection to server
cargo309/10.3.30.59:2181 | org.apache.zookeeper.ClientCnxn |
main-SendThread(cargo309:2181)
2014-10-18 09:04:31,911 | WARN | unprocessed event state: AuthFailed |
org.apache.activemq.leveldb.replicated.groups.ZKClient | main-EventThread
2014-10-18 09:04:31,912 | INFO | Socket connection established to cargo309/
10.3.30.59:2181, initiating session | org.apache.zookeeper.ClientCnxn |
main-SendThread(cargo309:2181)
2014-10-18 09:04:31,927 | INFO | Session establishment complete on server
cargo309/10.3.30.59:2181, sessionid = 0x24893c5d5e6022f, negotiated timeout
= 4000 | org.apache.zookeeper.ClientCnxn | main-SendThread(cargo309:2181)
2014-10-18 09:04:37,283 | INFO | Client session timed out, have not heard
from server in 2668ms for sessionid 0x24893c5d5e6022f, closing socket
connection and attempting reconnect | org.apache.zookeeper.ClientCnxn |
main-SendThread(cargo309:2181)
2014-10-18 09:04:38,124 | WARN | SASL configuration failed:
javax.security.auth.login.LoginException: No JAAS configuration section
named 'Client' was found in specified JAAS configuration file:
'/home/apps/activemq/conf/login.config'. Will continue connection to
Zookeeper server without SASL authentication, if Zookeeper server allows
it. | org.apache.zookeeper.ClientCnxn | main-SendThread(cargo310:2181)
2014-10-18 09:04:38,124 | INFO | Opening socket connection to server
cargo310/10.3.30.60:2181 | org.apache.zookeeper.ClientCnxn |
main-SendThread(cargo310:2181)
2014-10-18 09:04:38,124 | WARN | unprocessed event state: AuthFailed |
org.apache.activemq.leveldb.replicated.groups.ZKClient | main-EventThread
2014-10-18 09:04:38,127 | INFO | Socket connection established to cargo310/
10.3.30.60:2181, initiating session | org.apache.zookeeper.ClientCnxn |
main-SendThread(cargo310:2181)
2014-10-18 09:04:39,462 | INFO | Client session timed out, have not heard
from server in 1335ms for sessionid 0x24893c5d5e6022f, closing socket
connection and attempting reconnect | org.apache.zookeeper.ClientCnxn |
main-SendThread(cargo310:2181)
2014-10-18 09:04:39,775 | WARN | SASL configuration failed:
javax.security.auth.login.LoginException: No JAAS configuration section
named 'Client' was found in specified JAAS configuration file:
'/home/apps/activemq/conf/login.config'. Will continue connection to
Zookeeper server without SASL authentication, if Zookeeper server allows
it. | org.apache.zookeeper.ClientCnxn | main-SendThread(cargo308:2181)
2014-10-18 09:04:39,775 | INFO | Opening socket connection to server
cargo308/10.3.30.58:2181 | org.apache.zookeeper.ClientCnxn |
main-SendThread(cargo308:2181)
2014-10-18 09:04:39,775 | WARN | unprocessed event state: AuthFailed |
org.apache.activemq.leveldb.replicated.groups.ZKClient | main-EventThread
2014-10-18 09:04:39,776 | INFO | Socket connection established to cargo308/
10.3.30.58:2181, initiating session | org.apache.zookeeper.ClientCnxn |
main-SendThread(cargo308:2181)
2014-10-18 09:04:41,111 | INFO | Client session timed out, have not heard
from server in 1335ms for sessionid 0x24893c5d5e6022f, closing socket
connection and attempting reconnect | org.apache.zookeeper.ClientCnxn |
main-SendThread(cargo308:2181)
2014-10-18 09:04:43,070 | WARN | SASL configuration failed:
javax.security.auth.login.LoginException: No JAAS configuration section
named 'Client' was found in specified JAAS configuration file:
'/home/apps/activemq/conf/login.config'. Will continue connection to
Zookeeper server without SASL authentication, if Zookeeper server allows
it. | org.apache.zookeeper.ClientCnxn | main-SendThread(cargo309:2181)
2014-10-18 09:04:43,070 | INFO | Opening socket connection to server
cargo309/10.3.30.59:2181 | org.apache.zookeeper.ClientCnxn |
main-SendThread(cargo309:2181)
2014-10-18 09:04:43,070 | WARN | unprocessed event state: AuthFailed |
org.apache.activemq.leveldb.replicated.groups.ZKClient | main-EventThread
2014-10-18 09:04:44,405 | INFO | Client session timed out, have not heard
from server in 3193ms for sessionid 0x24893c5d5e6022f, closing socket
connection and attempting reconnect | org.apache.zookeeper.ClientCnxn |
main-SendThread(cargo309:2181)
2014-10-18 09:04:44,698 | WARN | SASL configuration failed:
javax.security.auth.login.LoginException: No JAAS configuration section
named 'Client' was found in specified JAAS configuration file:
'/home/apps/activemq/conf/login.config'. Will continue connection to
Zookeeper server without SASL authentication, if Zookeeper server allows
it. | org.apache.zookeeper.ClientCnxn | main-SendThread(cargo310:2181)
2014-10-18 09:04:44,699 | INFO | Opening socket connection to server
cargo310/10.3.30.60:2181 | org.apache.zookeeper.ClientCnxn |
main-SendThread(cargo310:2181)
2014-10-18 09:04:44,699 | WARN | unprocessed event state: AuthFailed |
org.apache.activemq.leveldb.replicated.groups.ZKClient | main-EventThread
2014-10-18 09:04:44,699 | INFO | Socket connection established to cargo310/
10.3.30.60:2181, initiating session | org.apache.zookeeper.ClientCnxn |
main-SendThread(cargo310:2181)
2014-10-18 09:04:44,701 | INFO | Unable to read additional data from
server sessionid 0x24893c5d5e6022f, likely server has closed socket,
closing socket connection and attempting reconnect |
org.apache.zookeeper.ClientCnxn | main-SendThread(cargo310:2181)
2014-10-18 09:04:44,979 | WARN | SASL configuration failed:
javax.security.auth.login.LoginException: No JAAS configuration section
named 'Client' was found in specified JAAS configuration file:
'/home/apps/activemq/conf/login.config'. Will continue connection to
Zookeeper server without SASL authentication, if Zookeeper server allows
it. | org.apache.zookeeper.ClientCnxn | main-SendThread(cargo308:2181)
2014-10-18 09:04:44,979 | INFO | Opening socket connection to server
cargo308/10.3.30.58:2181 | org.apache.zookeeper.ClientCnxn |
main-SendThread(cargo308:2181)
2014-10-18 09:04:44,979 | WARN | unprocessed event state: AuthFailed |
org.apache.activemq.leveldb.replicated.groups.ZKClient | main-EventThread
2014-10-18 09:04:44,980 | INFO | Socket connection established to cargo308/
10.3.30.58:2181, initiating session | org.apache.zookeeper.ClientCnxn |
main-SendThread(cargo308:2181)
2014-10-18 09:04:44,981 | INFO | Unable to read additional data from
server sessionid 0x24893c5d5e6022f, likely server has closed socket,
closing socket connection and attempting reconnect |
org.apache.zookeeper.ClientCnxn | main-SendThread(cargo308:2181)
2014-10-18 09:04:47,076 | WARN | SASL configuration failed:
javax.security.auth.login.LoginException: No JAAS configuration section
named 'Client' was found in specified JAAS configuration file:
'/home/apps/activemq/conf/login.config'. Will continue connection to
Zookeeper server without SASL authentication, if Zookeeper server allows
it. | org.apache.zookeeper.ClientCnxn | main-SendThread(cargo309:2181)
2014-10-18 09:04:47,076 | INFO | Opening socket connection to server
cargo309/10.3.30.59:2181 | org.apache.zookeeper.ClientCnxn |
main-SendThread(cargo309:2181)
2014-10-18 09:04:47,076 | WARN | unprocessed event state: AuthFailed |
org.apache.activemq.leveldb.replicated.groups.ZKClient | main-EventThread
2014-10-18 09:04:47,077 | INFO | Socket connection established to cargo309/
10.3.30.59:2181, initiating session | org.apache.zookeeper.ClientCnxn |
main-SendThread(cargo309:2181)
2014-10-18 09:04:47,079 | INFO | Unable to read additional data from
server sessionid 0x24893c5d5e6022f, likely server has closed socket,
closing socket connection and attempting reconnect |
org.apache.zookeeper.ClientCnxn | main-SendThread(cargo309:2181)
2014-10-18 09:04:47,582 | WARN | SASL configuration failed:
javax.security.auth.login.LoginException: No JAAS configuration section
named 'Client' was found in specified JAAS configuration file:
'/home/apps/activemq/conf/login.config'. Will continue connection to
Zookeeper server without SASL authentication, if Zookeeper server allows
it. | org.apache.zookeeper.ClientCnxn | main-SendThread(cargo310:2181)
2014-10-18 09:04:47,582 | INFO | Opening socket connection to server
cargo310/10.3.30.60:2181 | org.apache.zookeeper.ClientCnxn |
main-SendThread(cargo310:2181)
2014-10-18 09:04:47,582 | WARN | unprocessed event state: AuthFailed |
org.apache.activemq.leveldb.replicated.groups.ZKClient | main-EventThread
2014-10-18 09:04:47,583 | INFO | Socket connection established to cargo310/
10.3.30.60:2181, initiating session | org.apache.zookeeper.ClientCnxn |
main-SendThread(cargo310:2181)
2014-10-18 09:04:47,585 | INFO | Session establishment complete on server
cargo310/10.3.30.60:2181, sessionid = 0x24893c5d5e6022f, negotiated timeout
= 4000 | org.apache.zookeeper.ClientCnxn | main-SendThread(cargo310:2181)
2014-10-18 15:13:14,541 | INFO | Refreshing
org.apache.activemq.xbean.XBeanBrokerFactory$1@476d7e38: startup date [Sat
Oct 18 15:13:14 EDT 2014]; root of context hierarchy |
org.apache.activemq.xbean.XBeanBrokerFactory$1 | main
