Hello
We recently updated our Coldfusion 10 server to update 18, which moved
us up to Tomcat 7.0.64, and we are now experiencing issues when
restarting a CF instance. I understand that this is not a coldfuison
forum, but since CF10 is based on top of a tomcat back end, which is
where the issue appears to be, I figured I would ask here. As best I
can figure, it appears that while under moderate load, DeltaManager
sessions dont replicate, and the servlet hangs and never fully starts
up. Without any load, the CF instance (servlet) starts up perfectly
fine without issue.
I have recently tested on a fresh install of CentOS 6.7 64 Bit, with
newly installed Coldfusion 10 update 18, and JDK 1.7.0_95, and can
confirm this issue happens out of the box.
I have set up my server.xml files for both instances using both dynamic
(multicast) as well as static members, but both hang in the same way.
It seems that Deltamanager is simply unable to send the sessions to the
restarted / recovered member while under load. If I remove the load
from the box, it restarts normally without any issue. I have set the
Transport and Receiver timeouts to as high as 120 seconds, without any
success.
Any suggestions on how to troubleshoot would be greatly appreciated.
Here's the error from the first instance:
Mar 25, 2016 2:46:47 AM org.apache.catalina.ha.tcp.SimpleTcpCluster send
SEVERE: Unable to send message through cluster sender.
org.apache.catalina.tribes.ChannelException: Operation has timed
out(30000 ms.).; Faulty members:tcp://{10, 10, 2, 84}:4002;
at
org.apache.catalina.tribes.transport.nio.ParallelNioSender.sendMessage(ParallelNioSender.java:109)
at
org.apache.catalina.tribes.transport.nio.PooledParallelSender.sendMessage(PooledParallelSender.java:54)
at
org.apache.catalina.tribes.transport.ReplicationTransmitter.sendMessage(ReplicationTransmitter.java:78)
at
org.apache.catalina.tribes.group.ChannelCoordinator.sendMessage(ChannelCoordinator.java:77)
at
org.apache.catalina.tribes.group.ChannelInterceptorBase.sendMessage(ChannelInterceptorBase.java:77)
at
org.apache.catalina.tribes.group.ChannelInterceptorBase.sendMessage(ChannelInterceptorBase.java:77)
at
org.apache.catalina.tribes.group.interceptors.MessageDispatchInterceptor.sendMessage(MessageDispatchInterceptor.java:77)
at
org.apache.catalina.tribes.group.ChannelInterceptorBase.sendMessage(ChannelInterceptorBase.java:77)
at
org.apache.catalina.tribes.group.interceptors.TcpFailureDetector.sendMessage(TcpFailureDetector.java:93)
at
org.apache.catalina.tribes.group.ChannelInterceptorBase.sendMessage(ChannelInterceptorBase.java:77)
at
org.apache.catalina.tribes.group.ChannelInterceptorBase.sendMessage(ChannelInterceptorBase.java:77)
at
org.apache.catalina.tribes.group.GroupChannel.send(GroupChannel.java:224)
at
org.apache.catalina.tribes.group.GroupChannel.send(GroupChannel.java:182)
at
org.apache.catalina.ha.tcp.SimpleTcpCluster.send(SimpleTcpCluster.java:837)
at
org.apache.catalina.ha.session.DeltaManager.sendSessions(DeltaManager.java:1429)
at
org.apache.catalina.ha.session.DeltaManager.handleGET_ALL_SESSIONS(DeltaManager.java:1357)
at
org.apache.catalina.ha.session.DeltaManager.messageReceived(DeltaManager.java:1183)
at
org.apache.catalina.ha.session.DeltaManager.messageDataReceived(DeltaManager.java:944)
at
org.apache.catalina.ha.session.ClusterSessionListener.messageReceived(ClusterSessionListener.java:91)
at
org.apache.catalina.ha.tcp.SimpleTcpCluster.messageReceived(SimpleTcpCluster.java:936)
at
org.apache.catalina.ha.tcp.SimpleTcpCluster.messageReceived(SimpleTcpCluster.java:917)
at
org.apache.catalina.tribes.group.GroupChannel.messageReceived(GroupChannel.java:278)
at
org.apache.catalina.tribes.group.ChannelInterceptorBase.messageReceived(ChannelInterceptorBase.java:82)
at
org.apache.catalina.tribes.group.interceptors.TcpPingInterceptor.messageReceived(TcpPingInterceptor.java:170)
at
org.apache.catalina.tribes.group.ChannelInterceptorBase.messageReceived(ChannelInterceptorBase.java:82)
at
org.apache.catalina.tribes.group.interceptors.TcpFailureDetector.messageReceived(TcpFailureDetector.java:117)
at
org.apache.catalina.tribes.group.ChannelInterceptorBase.messageReceived(ChannelInterceptorBase.java:82)
at
org.apache.catalina.tribes.group.ChannelInterceptorBase.messageReceived(ChannelInterceptorBase.java:82)
at
org.apache.catalina.tribes.group.ChannelInterceptorBase.messageReceived(ChannelInterceptorBase.java:82)
at
org.apache.catalina.tribes.group.ChannelCoordinator.messageReceived(ChannelCoordinator.java:252)
at
org.apache.catalina.tribes.transport.ReceiverBase.messageDataReceived(ReceiverBase.java:287)
at
org.apache.catalina.tribes.transport.nio.NioReplicationTask.drainChannel(NioReplicationTask.java:210)
at
org.apache.catalina.tribes.transport.nio.NioReplicationTask.run(NioReplicationTask.java:99)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Here's the output from the Second (Restarted) instance:
Mar 25, 2016 2:46:12 AM
org.apache.tomcat.util.digester.SetPropertiesRule begin
WARNING:
[SetPropertiesRule]{Server/Service/Engine/Host/Cluster/Channel/Interceptor/Member}
Setting property 'domain' to 'delta-static' did not find a matching
property.
Mar 25, 2016 2:46:12 AM org.apache.catalina.core.AprLifecycleListener
lifecycleEvent
INFO: The APR based Apache Tomcat Native library which allows optimal
performance in production environments was not found on the
java.library.path:
/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
Mar 25, 2016 2:46:12 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-bio-8504"]
Mar 25, 2016 2:46:12 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["ajp-bio-8016"]
Mar 25, 2016 2:46:12 AM org.apache.catalina.core.StandardService
startInternal
INFO: Starting service Catalina
Mar 25, 2016 2:46:12 AM org.apache.catalina.core.StandardEngine
startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.64
Mar 25, 2016 2:46:13 AM org.apache.catalina.ha.tcp.SimpleTcpCluster
startInternal
INFO: Cluster is about to start
Mar 25, 2016 2:46:13 AM
org.apache.catalina.tribes.transport.ReceiverBase bind
INFO: Receiver Server Socket bound to:/10.10.2.84:4002
Mar 25, 2016 2:46:13 AM org.apache.catalina.ha.tcp.SimpleTcpCluster
memberAdded
INFO: Replication member
added:org.apache.catalina.tribes.membership.StaticMember[tcp://10.10.2.84:4001,10.10.2.84,4001,
alive=0, securePort=-1, UDP Port=-1, id={1 2 3 4 5 6 7 8 9 10 11 12 13
14 15 0 }, payload={}, command={}, domain={100 101 108 116 97 45 115 116
97 ...(12)}, ]
Mar 25, 2016 2:46:13 AM org.apache.catalina.tribes.io.BufferPool
getBufferPool
INFO: Created a buffer pool with max size:104857600 bytes of
type:org.apache.catalina.tribes.io.BufferPool15Impl
Mar 25, 2016 2:46:13 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:13 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:13 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:13 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:13 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:13 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:13 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:13 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:13 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:13 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:13 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:13 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:14 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:14 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:14 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:14 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:14 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:14 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:14 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:14 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:14 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:14 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:14 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:14 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:14 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:14 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:14 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:14 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:14 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:14 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:14 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:14 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:15 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:15 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:15 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:15 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:15 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:15 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:15 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:15 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:15 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:15 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:15 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:15 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:15 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:15 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:15 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:16 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:16 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:16 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:16 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:16 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:16 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:16 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:16 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:16 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:16 AM
org.apache.catalina.ha.session.ClusterSessionListener messageReceived
WARNING: Context manager doesn't exist:
Mar 25, 2016 2:46:16 AM org.apache.catalina.startup.TldConfig execute
INFO: At least one JAR was scanned for TLDs yet contained no TLDs.
Enable debug logging for this logger for a complete list of JARs that
were scanned but no TLDs were found in them. Skipping unneeded JARs
during scanning can improve startup time and JSP compilation time.
Mar 25, 2016 2:46:16 AM org.apache.catalina.ha.session.DeltaManager
startInternal
INFO: Register manager to cluster element Host with name 10.10.2.84
Mar 25, 2016 2:46:16 AM org.apache.catalina.ha.session.DeltaManager
startInternal
INFO: Starting clustering manager at
Mar 25, 2016 2:46:16 AM org.apache.catalina.ha.session.DeltaManager
getAllClusterSessions
INFO: Manager [], requesting session state from
org.apache.catalina.tribes.membership.StaticMember[tcp://10.10.2.84:4001,10.10.2.84,4001,
alive=0, securePort=-1, UDP Port=-1, id={1 2 3 4 5 6 7 8 9 10 11 12 13
14 15 0 }, payload={}, command={}, domain={100 101 108 116 97 45 115 116
97 ...(12)}, ]. This operation will timeout if no session state has been
received within 60 seconds.
Mar 25, 2016 2:46:47 AM org.apache.catalina.ha.session.DeltaManager
waitForSendAllSessions
INFO: Manager []; session state send at 3/25/16 2:46 AM received in
30,171 ms.
Mar 25, 2016 2:46:47 AM org.apache.catalina.session.StandardSession tellNew
SEVERE: Session event listener threw exception
java.lang.NullPointerException
at
coldfusion.bootstrap.HttpFlexSessionBootstrap.getListener(HttpFlexSessionBootstrap.java:154)
at
coldfusion.bootstrap.HttpFlexSessionBootstrap.sessionCreated(HttpFlexSessionBootstrap.java:69)
at
org.apache.catalina.session.StandardSession.tellNew(StandardSession.java:422)
at
org.apache.catalina.session.StandardSession.setId(StandardSession.java:394)
at
org.apache.catalina.ha.session.DeltaSession.setId(DeltaSession.java:275)
at
org.apache.catalina.ha.session.DeltaManager.handleSESSION_CREATED(DeltaManager.java:1317)
at
org.apache.catalina.ha.session.DeltaManager.messageReceived(DeltaManager.java:1195)
at
org.apache.catalina.ha.session.DeltaManager.getAllClusterSessions(DeltaManager.java:803)
at
org.apache.catalina.ha.session.DeltaManager.startInternal(DeltaManager.java:756)
at
org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
at
org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5526)
at
org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
at
org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1574)
at
org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1564)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Mar 25, 2016 2:46:47 AM org.apache.catalina.session.StandardSession tellNew
SEVERE: Session event listener threw exception
java.lang.NullPointerException
at
coldfusion.bootstrap.HttpFlexSessionBootstrap.getListener(HttpFlexSessionBootstrap.java:154)
at
coldfusion.bootstrap.HttpFlexSessionBootstrap.sessionCreated(HttpFlexSessionBootstrap.java:69)
at
org.apache.catalina.session.StandardSession.tellNew(StandardSession.java:422)
at
org.apache.catalina.session.StandardSession.setId(StandardSession.java:394)
at
org.apache.catalina.ha.session.DeltaSession.setId(DeltaSession.java:275)
at
org.apache.catalina.ha.session.DeltaManager.handleSESSION_CREATED(DeltaManager.java:1317)
at
org.apache.catalina.ha.session.DeltaManager.messageReceived(DeltaManager.java:1195)
at
org.apache.catalina.ha.session.DeltaManager.getAllClusterSessions(DeltaManager.java:803)
at
org.apache.catalina.ha.session.DeltaManager.startInternal(DeltaManager.java:756)
at
org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
at
org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5526)
at
org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
at
org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1574)
at
org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1564)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
--
Thank you,
-Anthony
