Menu

quinta-feira, 16 de janeiro de 2014

org.jboss.as.clustering.lock.AbstractClusterLockSupport.lock exception


I spent two days trying to find out the source of this exception, so I think it's worth to share this solution with the community.

Background


First things first, this is my JBoss EAP 6.1 layout:

Hosts
dese-001 - domain controller + server-one
dese-002 - slave with server-one

Both are development servers using the main-server-group with full-ha profile and full-ha-sockets. They are meant to be an environment for tests before I deploy my applications to production.

And I also have a production environment with the same layout (prod-001 and prod-002 hosts). The production environment was made as a clone of the development one, so they were both sharing the same configurations.

All my servers were running on Suse Enterprise Linux with IBM JDK.

Problem


My servers were all very buggy and unreliable, often asking for reloads. My applications were quite slow and my deployments were frequently failing.

I had to restart my servers all the time, so I decided I should try to track down the root cause of my issues.

My first hunch was IBM JDK, which I replaced with openjdk6. Memory usage was improved, since IBM JDK loads permgen into heap memory, but my frequent restart issues were still present.

I upgraded from JBoss EAP 6.1 to 6.2. That's when I noticed this error log:

[Server:server-one] 09:50:04,687 ERROR [org.hornetq.core.server] (Old I/O server worker (parentId: 1675436606, [id: 0x63dd223e, /189.90.65.216:5445])) HQ224018: Failed to create session: HornetQException[errorType=SECURITY_EXCEPTION message=HQ119031: Unable to validate user: HORNETQ.CLUSTER.ADMIN.USER]
[Server:server-one]     at org.hornetq.core.security.impl.SecurityStoreImpl.authenticate(SecurityStoreImpl.java:146) [hornetq-server-2.3.12.Final-redhat-1.jar:2.3.12.Final-redhat-1]
[Server:server-one]     at org.hornetq.core.server.impl.HornetQServerImpl.createSession(HornetQServerImpl.java:964) [hornetq-server-2.3.12.Final-redhat-1.jar:2.3.12.Final-redhat-1]
[Server:server-one]     at org.hornetq.core.protocol.core.impl.HornetQPacketHandler.handleCreateSession(HornetQPacketHandler.java:151) [hornetq-server-2.3.12.Final-redhat-1.jar:2.3.12.Final-redhat-1]
[Server:server-one]     at org.hornetq.core.protocol.core.impl.HornetQPacketHandler.handlePacket(HornetQPacketHandler.java:78) [hornetq-server-2.3.12.Final-redhat-1.jar:2.3.12.Final-redhat-1]
[Server:server-one]     at org.hornetq.core.protocol.core.impl.ChannelImpl.handlePacket(ChannelImpl.java:631) [hornetq-core-client-2.3.12.Final-redhat-1.jar:2.3.12.Final-redhat-1]
[Server:server-one]     at org.hornetq.core.protocol.core.impl.RemotingConnectionImpl.doBufferReceived(RemotingConnectionImpl.java:547) [hornetq-core-client-2.3.12.Final-redhat-1.jar:2.3.12.Final-redhat-1]
[Server:server-one]     at org.hornetq.core.protocol.core.impl.RemotingConnectionImpl.bufferReceived(RemotingConnectionImpl.java:523) [hornetq-core-client-2.3.12.Final-redhat-1.jar:2.3.12.Final-redhat-1]
[Server:server-one]     at org.hornetq.core.remoting.server.impl.RemotingServiceImpl$DelegatingBufferHandler.bufferReceived(RemotingServiceImpl.java:564) [hornetq-server-2.3.12.Final-redhat-1.jar:2.3.12.Final-redhat-1]
[Server:server-one]     at org.hornetq.core.remoting.impl.netty.HornetQChannelHandler.messageReceived(HornetQChannelHandler.java:72) [hornetq-core-client-2.3.12.Final-redhat-1.jar:2.3.12.Final-redhat-1]
[Server:server-one]     at org.jboss.netty.channel.SimpleChannelHandler.handleUpstream(SimpleChannelHandler.java:88) [netty-3.6.6.Final-redhat-1.jar:3.6.6.Final-redhat-1]
[Server:server-one]     at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [netty-3.6.6.Final-redhat-1.jar:3.6.6.Final-redhat-1]
[Server:server-one]     at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) [netty-3.6.6.Final-redhat-1.jar:3.6.6.Final-redhat-1]
[Server:server-one]     at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:281) [netty-3.6.6.Final-redhat-1.jar:3.6.6.Final-redhat-1]
[Server:server-one]     at org.hornetq.core.remoting.impl.netty.HornetQFrameDecoder2.decode(HornetQFrameDecoder2.java:169) [hornetq-core-client-2.3.12.Final-redhat-1.jar:2.3.12.Final-redhat-1]
[Server:server-one]     at org.hornetq.core.remoting.impl.netty.HornetQFrameDecoder2.messageReceived(HornetQFrameDecoder2.java:134) [hornetq-core-client-2.3.12.Final-redhat-1.jar:2.3.12.Final-redhat-1]
[Server:server-one]     at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70) [netty-3.6.6.Final-redhat-1.jar:3.6.6.Final-redhat-1]
[Server:server-one]     at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [netty-3.6.6.Final-redhat-1.jar:3.6.6.Final-redhat-1]
[Server:server-one]     at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:559) [netty-3.6.6.Final-redhat-1.jar:3.6.6.Final-redhat-1]
[Server:server-one]     at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:268) [netty-3.6.6.Final-redhat-1.jar:3.6.6.Final-redhat-1]
[Server:server-one]     at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:255) [netty-3.6.6.Final-redhat-1.jar:3.6.6.Final-redhat-1]
[Server:server-one]     at org.jboss.netty.channel.socket.oio.OioWorker.process(OioWorker.java:71) [netty-3.6.6.Final-redhat-1.jar:3.6.6.Final-redhat-1]
[Server:server-one]     at org.jboss.netty.channel.socket.oio.AbstractOioWorker.run(AbstractOioWorker.java:73) [netty-3.6.6.Final-redhat-1.jar:3.6.6.Final-redhat-1]
[Server:server-one]     at org.jboss.netty.channel.socket.oio.OioWorker.run(OioWorker.java:51) [netty-3.6.6.Final-redhat-1.jar:3.6.6.Final-redhat-1]
[Server:server-one]     at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) [netty-3.6.6.Final-redhat-1.jar:3.6.6.Final-redhat-1]
[Server:server-one]     at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) [netty-3.6.6.Final-redhat-1.jar:3.6.6.Final-redhat-1]
[Server:server-one]     at org.jboss.netty.util.VirtualExecutorService$ChildExecutorRunnable.run(VirtualExecutorServic.java:175) [netty-3.6.6.Final-redhat-1.jar:3.6.6.Final-redhat-1]
[Server:server-one]     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146) [rt.jar:1.6.0_27]
[Server:server-one]     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.6.0_27]
[Server:server-one]     at java.lang.Thread.run(Thread.java:701) [rt.jar:1.6.0_27]

Supposedly I just needed to fill out hornet's cluster-password property in the domain.xml file, just as recommended on many forum threads found on Google:

<hornetq-server>
    <persistence-enabled>true</persistence-enabled>
        <cluster-password>${jboss.messaging.cluster.password:password}</cluster-password>

I did that, but the error log was still present in the server log. I managed to make it disappear by filling out the same hornet password used by the prod environment (which is the same used in JBoss EAP 6.1 development environment as well).

I noticed that production servers were being registered by development ones. At first I thought that was normal since the host controllers broadcast through a few services.

I deployed and tested my applications, but then I would be faced with the following stacktrace:

java.lang.NullPointerException
 org.jboss.as.clustering.lock.AbstractClusterLockSupport.lock(AbstractClusterLockSupport.java:157)
 org.jboss.as.clustering.lock.SharedLocalYieldingClusterLockManager.lock(SharedLocalYieldingClusterLockManager.java:436)
 org.jboss.as.clustering.web.infinispan.DistributedCacheManager.acquireSessionOwnership(DistributedCacheManager.java:400)
 org.jboss.as.web.session.ClusteredSession.acquireSessionOwnership(ClusteredSession.java:520)
 org.jboss.as.web.session.ClusteredSession.access(ClusteredSession.java:488)
 org.apache.catalina.connector.Request.doGetSession(Request.java:2616)
 org.apache.catalina.connector.Request.getSession(Request.java:2361)
 org.apache.catalina.connector.RequestFacade.getSession(RequestFacade.java:790)
 org.jboss.weld.context.beanstore.http.LazySessionBeanStore.getSession(LazySessionBeanStore.java:73)
 org.jboss.weld.context.beanstore.http.LazySessionBeanStore.<init>(LazySessionBeanStore.java:59)
 org.jboss.weld.context.http.HttpSessionContextImpl.associate(HttpSessionContextImpl.java:28)
 org.jboss.weld.context.http.HttpSessionContextImpl.associate(HttpSessionContextImpl.java:16)
 org.jboss.weld.servlet.WeldListener.requestInitialized(WeldListener.java:145)
 org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:97)
 org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:336)
 org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:488)
 org.apache.coyote.ajp.AjpProtocol$AjpConnectionHandler.process(AjpProtocol.java:420)
 org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:920)
 java.lang.Thread.run(Thread.java:701)

This one was really hard to find out, until I realized that since both server environments were sharing the same hornet password, maybe they were affecting each other, so I decided to shutdown production.

That completely solved my issue.

Conclusion


Both server environments should not share the same hornet passwords, but if they are different, the connection error log will be displayed every few seconds, since they are broadcasting to each other.

You can raise hornet log level to avoid the display of connection error logs, but the best solution, in my opinion, is to configure a firewall to block each other.

Nenhum comentário :