ColdFusion 11 Instances not starting properly after server restart

Report · Oct 13, 2015

Hello, we have following situation and can't seem to find a fix or workaround for it. Could you help?

On all 4 of our Windows Server 2012 R2 servers running on vitrual machines with 8 vcpu cores each, we have 10 instances running ColdFusion 11 update 6, the instances are the same on all 4 servers, 2 servers are used for test/qa and 2 for production. On all of those servers, after servers are restarted some instances don't start properly and need to be manually restarted to start working; it seems that on average at any time 2 to 4 instances won't start and those are not the same instances every time. We were looking at the log files and we think we found what the issue is, but not sure how to go around it or fix it. When instances are starting, the following error shows up in the logs files of the instances that don't start properly (see down this post for actual log entries):

Oct 13, 2015 7:52:25 AM org.eclipse.jetty.util.log.JavaUtilLog warn

WARNING: FAILED ServerConnector@69f41e78{HTTP/1.1}{0.0.0.0:5500}: java.net.BindException: Address already in use: bind

As you can see in the log files below, the instances actually start, but when someone goes to CF Admin or tries to do anything with ColdFusion on those instances, all they see is 500 error. Restarting the instances manually, starts them properly. I think the issue is that the org.eclipse.jetty.util.log.JavaUtilLog's ServerConnector is being started with port 5500 instead of a random port (in the log files you are see an argument AVAILABLE is used by ColdFusion when it's calling the constructor). I suspect what is happening is that during restart of the server, all services try to start at the same time and all of them try port 5500 first to see if it's available for use. Since there are 8 cpu cores being used, I think some instances on different cpu cores "sense" port 5500 is available and try to use it, but in the meantime different instances on onother cpu core is actually claiming the port and then other instances are getting an exception and cannot recover from it. Restarting those manually, gives them a new random number since port 5500 is already used by one instance.

The question that we have is: can we force particular ColdFusion instance to use different port for this particular org.eclipse.jetty.util.log.JavaUtilLog's ServerConnector and if not, is there some other workaround? We tried the below things so far, but not of them semm to help. Our testing included stopping all instances and trying to change below settings on one instance to see if it will use different port for the org.eclipse.jetty.util.log.JavaUtilLog's ServerConnectorm after start, but it always tries to claim port 5500 first:

Tried changing jvm arguments to the below. We tried all of those because we're not even sure which one is correct, different documentation we found online didn't say specifically this can be done with ColdFusion servers and we're not very familiar with how Jetty operates or what it's job is in ColdFusion server. None of these help our issue:
-Djetty.http.port=20003
-Dorg.eclipse.jetty.http.port=20003
-Dorg.eclipse.jetty.server.Server.port=20003
-Dorg.eclipse.jetty.Server.port=20003
Also, tried changing the jetty.xml file in D:\CF11\cfusion\jetty\etc folder (it only exists in the main cfusion instance but the other instances), line 139, changed port to 0. This didn't make a difference either:
<Set name="port"><Property name="jetty.port" default="0" /></Set>

This log file is from one of the instances having issue during last server restart:

Oct 13, 2015 7:52:02 AM org.apache.catalina.core.AprLifecycleListener init
INFO: Loaded APR based Apache Tomcat Native library 1.1.33 using APR version 1.5.1.
Oct 13, 2015 7:52:02 AM org.apache.catalina.core.AprLifecycleListener init
INFO: APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
Oct 13, 2015 7:52:04 AM org.apache.catalina.core.AprLifecycleListener initializeSSL
INFO: OpenSSL successfully initialized (OpenSSL 1.0.1m 19 Mar 2015)
Oct 13, 2015 7:52:04 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-apr-8605"]
Oct 13, 2015 7:52:04 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["ajp-apr-8005"]
Oct 13, 2015 7:52:04 AM org.apache.catalina.core.StandardService startInternal
INFO: Starting service Catalina
Oct 13, 2015 7:52:04 AM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.54
Oct 13, 2015 7:52:14 AM org.apache.catalina.core.ApplicationContext log
INFO: ColdFusionStartUpServlet: ColdFusion: Starting application services
Oct 13, 2015 7:52:14 AM org.apache.catalina.core.ApplicationContext log
INFO: ColdFusionStartUpServlet: ColdFusion: VM version = 25.60-b23
Oct 13, 2015 7:52:25 AM org.eclipse.jetty.util.log.JavaUtilLog info
INFO: jetty-9.0.7.v20131107
Oct 13, 2015 7:52:25 AM org.eclipse.jetty.util.log.JavaUtilLog info
INFO: Started o.e.j.s.ServletContextHandler@3c75e648{/,null,AVAILABLE}
Oct 13, 2015 7:52:25 AM org.eclipse.jetty.util.log.JavaUtilLog warn
WARNING: FAILED ServerConnector@69f41e78{HTTP/1.1}{0.0.0.0:5500}: java.net.BindException: Address already in use: bind
java.net.BindException: Address already in use: bind
at sun.nio.ch.Net.bind0(Native Method)
at sun.nio.ch.Net.bind(Net.java:433)
at sun.nio.ch.Net.bind(Net.java:425)
at sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:223)
at sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:74)
at org.eclipse.jetty.server.ServerConnector.open(ServerConnector.java:264)
at org.eclipse.jetty.server.AbstractNetworkConnector.doStart(AbstractNetworkConnector.java:80)
at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:69)
at org.eclipse.jetty.server.Server.doStart(Server.java:303)
at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:69)
at coldfusion.monitor.jetty.server.MonitoringServer.startServer(MonitoringServer.java:109)
at coldfusion.monitor.MonitoringServiceImpl.startJettyServer(MonitoringServiceImpl.java:196)
at coldfusion.monitor.MonitoringServiceImpl.start(MonitoringServiceImpl.java:149)
at coldfusion.server.CFService.setupMonitoringService(CFService.java:486)
at coldfusion.server.CFService.start(CFService.java:699)
at coldfusion.server.j2ee.CFStartUpServlet.startCFService(CFStartUpServlet.java:553)
at coldfusion.server.j2ee.CFStartUpServlet.init(CFStartUpServlet.java:505)
at javax.servlet.GenericServlet.init(GenericServlet.java:158)
at coldfusion.bootstrap.ClassloaderHelper.initServletClass(ClassloaderHelper.java:121)
at coldfusion.bootstrap.BootstrapServlet.init(BootstrapServlet.java:59)
at org.apache.catalina.core.StandardWrapper.initServlet(StandardWrapper.java:1284)
at org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1197)
at org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:1087)
at org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:5210)
at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5493)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1559)
at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1549)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)

Oct 13, 2015 7:52:25 AM org.eclipse.jetty.util.log.JavaUtilLog warn
WARNING: FAILED org.eclipse.jetty.server.Server@340cadfc: java.net.BindException: Address already in use: bind
java.net.BindException: Address already in use: bind
at sun.nio.ch.Net.bind0(Native Method)
at sun.nio.ch.Net.bind(Net.java:433)
at sun.nio.ch.Net.bind(Net.java:425)
at sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:223)
at sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:74)
at org.eclipse.jetty.server.ServerConnector.open(ServerConnector.java:264)
at org.eclipse.jetty.server.AbstractNetworkConnector.doStart(AbstractNetworkConnector.java:80)
at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:69)
at org.eclipse.jetty.server.Server.doStart(Server.java:303)
at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:69)
at coldfusion.monitor.jetty.server.MonitoringServer.startServer(MonitoringServer.java:109)
at coldfusion.monitor.MonitoringServiceImpl.startJettyServer(MonitoringServiceImpl.java:196)
at coldfusion.monitor.MonitoringServiceImpl.start(MonitoringServiceImpl.java:149)
at coldfusion.server.CFService.setupMonitoringService(CFService.java:486)
at coldfusion.server.CFService.start(CFService.java:699)
at coldfusion.server.j2ee.CFStartUpServlet.startCFService(CFStartUpServlet.java:553)
at coldfusion.server.j2ee.CFStartUpServlet.init(CFStartUpServlet.java:505)
at javax.servlet.GenericServlet.init(GenericServlet.java:158)
at coldfusion.bootstrap.ClassloaderHelper.initServletClass(ClassloaderHelper.java:121)
at coldfusion.bootstrap.BootstrapServlet.init(BootstrapServlet.java:59)
at org.apache.catalina.core.StandardWrapper.initServlet(StandardWrapper.java:1284)
at org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1197)
at org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:1087)
at org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:5210)
at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5493)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1559)
at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1549)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)

Oct 13, 2015 7:52:27 AM org.apache.catalina.core.ApplicationContext log
INFO: CFMxmlServlet: Macromedia Flex Build: 87315.134646
Oct 13, 2015 7:52:40 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-apr-8605"]
Oct 13, 2015 7:52:40 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["ajp-apr-8005"]
Oct 13, 2015 7:52:40 AM com.adobe.coldfusion.launcher.Launcher run
INFO: Server startup in 40448 ms

This log file is from second of the instances having issue during last server restart:

Oct 13, 2015 7:52:02 AM org.apache.catalina.core.AprLifecycleListener init
INFO: Loaded APR based Apache Tomcat Native library 1.1.33 using APR version 1.5.1.
Oct 13, 2015 7:52:02 AM org.apache.catalina.core.AprLifecycleListener init
INFO: APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
Oct 13, 2015 7:52:03 AM org.apache.catalina.core.AprLifecycleListener initializeSSL
INFO: OpenSSL successfully initialized (OpenSSL 1.0.1m 19 Mar 2015)
Oct 13, 2015 7:52:04 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-apr-8607"]
Oct 13, 2015 7:52:04 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["ajp-apr-8007"]
Oct 13, 2015 7:52:04 AM org.apache.catalina.core.StandardService startInternal
INFO: Starting service Catalina
Oct 13, 2015 7:52:04 AM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.54
Oct 13, 2015 7:52:09 AM org.apache.catalina.util.SessionIdGenerator createSecureRandom
INFO: Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [141] milliseconds.
Oct 13, 2015 7:52:14 AM org.apache.catalina.core.ApplicationContext log
INFO: ColdFusionStartUpServlet: ColdFusion: Starting application services
Oct 13, 2015 7:52:14 AM org.apache.catalina.core.ApplicationContext log
INFO: ColdFusionStartUpServlet: ColdFusion: VM version = 25.60-b23
Oct 13, 2015 7:52:25 AM org.eclipse.jetty.util.log.JavaUtilLog info
INFO: jetty-9.0.7.v20131107
Oct 13, 2015 7:52:25 AM org.eclipse.jetty.util.log.JavaUtilLog info
INFO: Started o.e.j.s.ServletContextHandler@37fad941{/,null,AVAILABLE}
Oct 13, 2015 7:52:25 AM org.eclipse.jetty.util.log.JavaUtilLog warn
WARNING: FAILED ServerConnector@5c29fc94{HTTP/1.1}{0.0.0.0:5500}: java.net.BindException: Address already in use: bind
java.net.BindException: Address already in use: bind
at sun.nio.ch.Net.bind0(Native Method)
at sun.nio.ch.Net.bind(Net.java:433)
at sun.nio.ch.Net.bind(Net.java:425)
at sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:223)
at sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:74)
at org.eclipse.jetty.server.ServerConnector.open(ServerConnector.java:264)
at org.eclipse.jetty.server.AbstractNetworkConnector.doStart(AbstractNetworkConnector.java:80)
at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:69)
at org.eclipse.jetty.server.Server.doStart(Server.java:303)
at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:69)
at coldfusion.monitor.jetty.server.MonitoringServer.startServer(MonitoringServer.java:109)
at coldfusion.monitor.MonitoringServiceImpl.startJettyServer(MonitoringServiceImpl.java:196)
at coldfusion.monitor.MonitoringServiceImpl.start(MonitoringServiceImpl.java:149)
at coldfusion.server.CFService.setupMonitoringService(CFService.java:486)
at coldfusion.server.CFService.start(CFService.java:699)
at coldfusion.server.j2ee.CFStartUpServlet.startCFService(CFStartUpServlet.java:553)
at coldfusion.server.j2ee.CFStartUpServlet.init(CFStartUpServlet.java:505)
at javax.servlet.GenericServlet.init(GenericServlet.java:158)
at coldfusion.bootstrap.ClassloaderHelper.initServletClass(ClassloaderHelper.java:121)
at coldfusion.bootstrap.BootstrapServlet.init(BootstrapServlet.java:59)
at org.apache.catalina.core.StandardWrapper.initServlet(StandardWrapper.java:1284)
at org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1197)
at org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:1087)
at org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:5210)
at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5493)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1559)
at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1549)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)

Oct 13, 2015 7:52:25 AM org.eclipse.jetty.util.log.JavaUtilLog warn
WARNING: FAILED org.eclipse.jetty.server.Server@5d5db612: java.net.BindException: Address already in use: bind
java.net.BindException: Address already in use: bind
at sun.nio.ch.Net.bind0(Native Method)
at sun.nio.ch.Net.bind(Net.java:433)
at sun.nio.ch.Net.bind(Net.java:425)
at sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:223)
at sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:74)
at org.eclipse.jetty.server.ServerConnector.open(ServerConnector.java:264)
at org.eclipse.jetty.server.AbstractNetworkConnector.doStart(AbstractNetworkConnector.java:80)
at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:69)
at org.eclipse.jetty.server.Server.doStart(Server.java:303)
at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:69)
at coldfusion.monitor.jetty.server.MonitoringServer.startServer(MonitoringServer.java:109)
at coldfusion.monitor.MonitoringServiceImpl.startJettyServer(MonitoringServiceImpl.java:196)
at coldfusion.monitor.MonitoringServiceImpl.start(MonitoringServiceImpl.java:149)
at coldfusion.server.CFService.setupMonitoringService(CFService.java:486)
at coldfusion.server.CFService.start(CFService.java:699)
at coldfusion.server.j2ee.CFStartUpServlet.startCFService(CFStartUpServlet.java:553)
at coldfusion.server.j2ee.CFStartUpServlet.init(CFStartUpServlet.java:505)
at javax.servlet.GenericServlet.init(GenericServlet.java:158)
at coldfusion.bootstrap.ClassloaderHelper.initServletClass(ClassloaderHelper.java:121)
at coldfusion.bootstrap.BootstrapServlet.init(BootstrapServlet.java:59)
at org.apache.catalina.core.StandardWrapper.initServlet(StandardWrapper.java:1284)
at org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1197)
at org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:1087)
at org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:5210)
at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5493)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1559)
at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1549)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)

Oct 13, 2015 7:52:27 AM org.apache.catalina.core.ApplicationContext log
INFO: CFMxmlServlet: Macromedia Flex Build: 87315.134646
Oct 13, 2015 7:52:38 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-apr-8607"]
Oct 13, 2015 7:52:39 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["ajp-apr-8007"]
Oct 13, 2015 7:52:39 AM com.adobe.coldfusion.launcher.Launcher run
INFO: Server startup in 39425 ms

This is a log file from 3rd instance having issue during last server restart:

Oct 13, 2015 7:52:02 AM org.apache.catalina.core.AprLifecycleListener init
INFO: Loaded APR based Apache Tomcat Native library 1.1.33 using APR version 1.5.1.
Oct 13, 2015 7:52:02 AM org.apache.catalina.core.AprLifecycleListener init
INFO: APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
Oct 13, 2015 7:52:03 AM org.apache.catalina.core.AprLifecycleListener initializeSSL
INFO: OpenSSL successfully initialized (OpenSSL 1.0.1m 19 Mar 2015)
Oct 13, 2015 7:52:04 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-apr-8603"]
Oct 13, 2015 7:52:04 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["ajp-apr-8003"]
Oct 13, 2015 7:52:04 AM org.apache.catalina.core.StandardService startInternal
INFO: Starting service Catalina
Oct 13, 2015 7:52:04 AM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.54
Oct 13, 2015 7:52:14 AM org.apache.catalina.core.ApplicationContext log
INFO: ColdFusionStartUpServlet: ColdFusion: Starting application services
Oct 13, 2015 7:52:14 AM org.apache.catalina.core.ApplicationContext log
INFO: ColdFusionStartUpServlet: ColdFusion: VM version = 25.60-b23
Oct 13, 2015 7:52:25 AM org.eclipse.jetty.util.log.JavaUtilLog info
INFO: jetty-9.0.7.v20131107
Oct 13, 2015 7:52:25 AM org.eclipse.jetty.util.log.JavaUtilLog info
INFO: Started o.e.j.s.ServletContextHandler@3c75e648{/,null,AVAILABLE}
Oct 13, 2015 7:52:25 AM org.eclipse.jetty.util.log.JavaUtilLog warn
WARNING: FAILED ServerConnector@69f41e78{HTTP/1.1}{0.0.0.0:5500}: java.net.BindException: Address already in use: bind
java.net.BindException: Address already in use: bind
at sun.nio.ch.Net.bind0(Native Method)
at sun.nio.ch.Net.bind(Net.java:433)
at sun.nio.ch.Net.bind(Net.java:425)
at sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:223)
at sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:74)
at org.eclipse.jetty.server.ServerConnector.open(ServerConnector.java:264)
at org.eclipse.jetty.server.AbstractNetworkConnector.doStart(AbstractNetworkConnector.java:80)
at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:69)
at org.eclipse.jetty.server.Server.doStart(Server.java:303)
at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:69)
at coldfusion.monitor.jetty.server.MonitoringServer.startServer(MonitoringServer.java:109)
at coldfusion.monitor.MonitoringServiceImpl.startJettyServer(MonitoringServiceImpl.java:196)
at coldfusion.monitor.MonitoringServiceImpl.start(MonitoringServiceImpl.java:149)
at coldfusion.server.CFService.setupMonitoringService(CFService.java:486)
at coldfusion.server.CFService.start(CFService.java:699)
at coldfusion.server.j2ee.CFStartUpServlet.startCFService(CFStartUpServlet.java:553)
at coldfusion.server.j2ee.CFStartUpServlet.init(CFStartUpServlet.java:505)
at javax.servlet.GenericServlet.init(GenericServlet.java:158)
at coldfusion.bootstrap.ClassloaderHelper.initServletClass(ClassloaderHelper.java:121)
at coldfusion.bootstrap.BootstrapServlet.init(BootstrapServlet.java:59)
at org.apache.catalina.core.StandardWrapper.initServlet(StandardWrapper.java:1284)
at org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1197)
at org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:1087)
at org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:5210)
at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5493)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1559)
at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1549)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)

Oct 13, 2015 7:52:25 AM org.eclipse.jetty.util.log.JavaUtilLog warn
WARNING: FAILED org.eclipse.jetty.server.Server@340cadfc: java.net.BindException: Address already in use: bind
java.net.BindException: Address already in use: bind
at sun.nio.ch.Net.bind0(Native Method)
at sun.nio.ch.Net.bind(Net.java:433)
at sun.nio.ch.Net.bind(Net.java:425)
at sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:223)
at sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:74)
at org.eclipse.jetty.server.ServerConnector.open(ServerConnector.java:264)
at org.eclipse.jetty.server.AbstractNetworkConnector.doStart(AbstractNetworkConnector.java:80)
at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:69)
at org.eclipse.jetty.server.Server.doStart(Server.java:303)
at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:69)
at coldfusion.monitor.jetty.server.MonitoringServer.startServer(MonitoringServer.java:109)
at coldfusion.monitor.MonitoringServiceImpl.startJettyServer(MonitoringServiceImpl.java:196)
at coldfusion.monitor.MonitoringServiceImpl.start(MonitoringServiceImpl.java:149)
at coldfusion.server.CFService.setupMonitoringService(CFService.java:486)
at coldfusion.server.CFService.start(CFService.java:699)
at coldfusion.server.j2ee.CFStartUpServlet.startCFService(CFStartUpServlet.java:553)
at coldfusion.server.j2ee.CFStartUpServlet.init(CFStartUpServlet.java:505)
at javax.servlet.GenericServlet.init(GenericServlet.java:158)
at coldfusion.bootstrap.ClassloaderHelper.initServletClass(ClassloaderHelper.java:121)
at coldfusion.bootstrap.BootstrapServlet.init(BootstrapServlet.java:59)
at org.apache.catalina.core.StandardWrapper.initServlet(StandardWrapper.java:1284)
at org.apache.catalina.core.StandardWrapper.loadServlet(StandardWrapper.java:1197)
at org.apache.catalina.core.StandardWrapper.load(StandardWrapper.java:1087)
at org.apache.catalina.core.StandardContext.loadOnStartup(StandardContext.java:5210)
at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5493)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1559)
at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1549)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)

Oct 13, 2015 7:52:27 AM org.apache.catalina.core.ApplicationContext log
INFO: CFMxmlServlet: Macromedia Flex Build: 87315.134646
Oct 13, 2015 7:52:40 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-apr-8603"]
Oct 13, 2015 7:52:40 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["ajp-apr-8003"]
Oct 13, 2015 7:52:40 AM com.adobe.coldfusion.launcher.Launcher run
INFO: Server startup in 40095 ms

Here is log file on an instance that actually started properly (one of those fully working instances is using port 5500, the other ones use random ports):

Oct 13, 2015 7:52:02 AM org.apache.catalina.core.AprLifecycleListener init

INFO: Loaded APR based Apache Tomcat Native library 1.1.33 using APR version 1.5.1.

Oct 13, 2015 7:52:02 AM org.apache.catalina.core.AprLifecycleListener init

INFO: APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].

Oct 13, 2015 7:52:03 AM org.apache.catalina.core.AprLifecycleListener initializeSSL

INFO: OpenSSL successfully initialized (OpenSSL 1.0.1m 19 Mar 2015)

Oct 13, 2015 7:52:04 AM org.apache.coyote.AbstractProtocol init

INFO: Initializing ProtocolHandler ["http-apr-8608"]

Oct 13, 2015 7:52:04 AM org.apache.coyote.AbstractProtocol init

INFO: Initializing ProtocolHandler ["ajp-apr-8008"]

Oct 13, 2015 7:52:04 AM org.apache.catalina.core.StandardService startInternal

INFO: Starting service Catalina

Oct 13, 2015 7:52:04 AM org.apache.catalina.core.StandardEngine startInternal

INFO: Starting Servlet Engine: Apache Tomcat/7.0.54

Oct 13, 2015 7:52:15 AM org.apache.catalina.core.ApplicationContext log

INFO: ColdFusionStartUpServlet: ColdFusion: Starting application services

Oct 13, 2015 7:52:15 AM org.apache.catalina.core.ApplicationContext log

INFO: ColdFusionStartUpServlet: ColdFusion: VM version = 25.60-b23

Oct 13, 2015 7:52:26 AM org.eclipse.jetty.util.log.JavaUtilLog info

INFO: jetty-9.0.7.v20131107

Oct 13, 2015 7:52:27 AM org.eclipse.jetty.util.log.JavaUtilLog info

INFO: Started o.e.j.s.ServletContextHandler@718d048a{/,null,AVAILABLE}

Oct 13, 2015 7:52:27 AM org.eclipse.jetty.util.log.JavaUtilLog info

INFO: Started ServerConnector@51efa93e{HTTP/1.1}{0.0.0.0:55598}

Oct 13, 2015 7:52:30 AM org.apache.catalina.core.ApplicationContext log

INFO: CFMxmlServlet: Macromedia Flex Build: 87315.134646

Oct 13, 2015 7:52:42 AM org.apache.coyote.AbstractProtocol start

INFO: Starting ProtocolHandler ["http-apr-8608"]

Oct 13, 2015 7:52:42 AM org.apache.coyote.AbstractProtocol start

INFO: Starting ProtocolHandler ["ajp-apr-8008"]

Oct 13, 2015 7:52:42 AM com.adobe.coldfusion.launcher.Launcher run

INFO: Server startup in 42366 ms

Here is our current jvm.config file that's used on all instances (the difference for each is the instance path and for some different Xms and Xmx arguments, other settings are the same):

#
# VM configuration
#
# Where to find JVM, if {java.home}/jre exists then that JVM is used
# if not then it must be the path to the JRE itself

java.home=D:/Java/jdk1.8.0_60/jre

#
# If no java.home is specified a VM is located by looking in these places in this
# order:
#
# 1) ../runtime/jre
# 2) registry (windows only)
# 3) JAVA_HOME env var plus jre (ie $JAVA_HOME/jre)
# 4) java.exe in path
#

application.home=D:/CF11/INSTANCEPATH

# Arguments to VM
java.args=-server -Xms768m -Xmx1024m -XX:MaxMetaspaceSize=256m -XX:+UseG1GC -Xbatch -Dcoldfusion.home={application.home} -Duser.language=en -Dcoldfusion.rootDir={application.home} -Dcoldfusion.libPath={application.home}/lib -Dorg.apache.coyote.USE_CUSTOM_STATUS_MSG_IN_HEADER=true -Dcoldfusion.jsafe.defaultalgo=FIPS186Random -Dorg.eclipse.jetty.util.log.class=org.eclipse.jetty.util.log.JavaUtilLog -Djsse.enableSNIExtension=false -Dcoldfusion.disablejsafe=true -Dcoldfusion.classPath={application.home}/lib/updates,{application.home}/lib,{application.home}/lib/axis2,{application.home}/gateway/lib/,{application.home}/wwwroot/WEB-INF/flex/jars,{application.home}/wwwroot/WEB-INF/cfform/jars,D:\\CF11\\Jars\\EAIMessaging,D:\\CF11\\Jars\\ALLINSTANCES

java.class.path={application.home}/lib/oosdk/lib,{application.home}/lib/oosdk/classes

# Comma separated list of shared library path
java.library.path={application.home}/lib,{application.home}/jintegra/bin,{application.home}/jintegra/bin/international,{application.home}/lib/oosdk/classes/win

Report · Oct 13, 2015

Hi Pawel,

I note on a CF11 system running multiple instances I looked at has ColdFusion11\INSTANCE\lib\jetty.xml.

Part of jetty.xml says:

When I edit jetty "port" section of jetty.xml on my localhost CF11 to 5501 and start CF11 coldfusion-error.log part says:

Oct 14, 2015 8:27:18 AM org.eclipse.jetty.util.log.JavaUtilLog info

INFO: jetty-9.0.7.v20131107

Oct 14, 2015 8:27:18 AM org.eclipse.jetty.util.log.JavaUtilLog info

INFO: Started o.e.j.s.ServletContextHandler@15a081f{/,null,AVAILABLE}

Oct 14, 2015 8:27:19 AM org.eclipse.jetty.util.log.JavaUtilLog info

INFO: Started ServerConnector@d02caa{HTTP/1.1}{0.0.0.0:5501}

After 5501 port change I note CFadmin > Server Settings > Settings Summary > Save as PDF button works ok.

HTH, Carl.

Report · Oct 13, 2015

Off topic - I see G1 collector in use. I tend to find G1 works well on bigger heap values.

Even tho your heap is small perhaps you would like to try these JVM adjustments to see if you get some more performance:

-XX:MetaspaceSize=212m -XX:MaxMetaspaceSize=256m -XX:ReservedCodeCacheSize=124m -XX:CompressedClassSpaceSize=96m -XX:+UseG1GC -XX:ParallelGCThreads=24 -XX:ConcGCThreads=24 -XX:InitiatingHeapOccupancyPercent=60 -XX:+ParallelRefProcEnabled

Report · Oct 14, 2015

Carl, thank you very much. This is exactly the setting we were looking for. Also, thank you for your suggestions on G1 collector, we'll try them in our setup. Do you have suggestions on settings for G1 for the following memory sizes?

-Xms1024m -Xmx4800m
-Xms768m -Xmx1280m
-Xms768m -Xmx2048m

Report · Oct 14, 2015

Hi Pawel,

Glad that jetty.xml <Set name="port">550n helped.

I tend to find via tradition java logging or JMX enabled with JDK tools like JMC that G1 works better with at least 4096Mb heap. Less than that I tend to deploy ParallelGC (default CF setting).

EG for G1

-Xms4096 -Xmx4096 -XX:MetaspaceSize=312m -XX:MaxMetaspaceSize=512m -XX:ReservedCodeCacheSize=324m -XX:CompressedClassSpaceSize=96m -XX:+UseG1GC -XX:ParallelGCThreads=24 -XX:ConcGCThreads=24 -XX:InitiatingHeapOccupancyPercent=60 -XX:+ParallelRefProcEnabled

Eg for ParallelGC

-Xms768m -Xmx2048m -XX:NewSize=312m -XX:MaxNewSize=312m -XX:SurvivorRatio=4 -XX:TargetSurvivorRatio=100 -XX:MetaspaceSize=212m -XX:MaxMetaspaceSize=412m -XX:ReservedCodeCacheSize=224m -XX:CompressedClassSpaceSize=64m -XX:+UseParallelGC -XX:ParallelGCThreads=24 -XX:MinHeapFreeRatio=40 -XX:MaxHeapFreeRatio=70

From your coldfusion-error.log I see you are using AJP-APR so likely you have tomcat tuning present already otherwise that is another important aspect to consider for performance.

Regards, Carl.

Report · Oct 15, 2015

Carl, do you not hesitate at all in proposing all those various jvm args, as if they will always work for everyone in any situation (based solely on your distinction of heap size and GC algorithm choice)?

I just lament when such args are proposed without clarification of “why” (other than a general assertion that things may run “better”). You’re changing so many “knobs” that way. How do you know that each knob change is right for everyone in every situation? I’m asking sincerely.

Of course, I do appreciate all your hard work here and elsewhere, so this is not an attack or complaint, but a plea for the sake of others who may read this and be tempted to pass along the suggested “tweaks”.

/charlie

PS I know this is getting off-topic of the OP, but since you took it this direction with the earlier message of observing his use of G1, it seems fair to raise this point here.

/Charlie (troubleshooter, carehart.org)

Report · Oct 15, 2015

Hi Charlie,

No offence taken.

I hear you - indeed I do hover over the add reply button when suggesting JVM arguments.

For interested readers I always maintain you should do your own monitoring or logging before and after changes to know you get a benefit. It could be an adequate situation gets worse. Naturally everyone's payload is different and JVM arguments or tomcat parameters are only part of the overall picture.

Cheers, Carl.

Report · Oct 15, 2015

PS

Further...

Agree an explanation is good to have as to why this or that setting. Fair to say I am not good at putting words and sentences together, Often I am actually busy doing my real work diagnosing CF, Windows or SQL related issues so time is a problem as well when it comes to participating on a user forum.

I did a post here with some explanation on some of the JVM arguments offered in this thread.

https://forums.adobe.com/message/7826203#7826203

Regards again, Carl.

Report · Oct 16, 2015

Fair enough, Carl, and thanks for taking my comments in the spirit intended.

All I would caution, then, is that when folks are tempted to share some JVM args as a potential solution, they should indicate that those worked for a situation but may not work for all. Sadly, the note I was replying to (and the earlier one before it) did propose them as a set that might “get some more performance”.

(And I do totally appreciate your other point about being busy and not often feeling you have much time to write more, needing to get on to other problem solving. We’re in the same boat.)

And I’m pointing all this out as much for the benefit of other folks to beware that not all proposed jvm arg tweaks should be accepted as something that will (or even could) work for them. I’m hoping that they, too, may carry this concern forward if/when they see such suggestions. Just trying to help the community, as I know you always are and most here are.

I’ll just say that as for myself, if I ever was tempted to propose such tweaks, I’d feel compelled to add at least some disclaimer to beware that they may not work well for all. That’s what I fail often to see (all over the web, from many, in such discussions), which prompted my reply. If you may agree, then if nothing else, perhaps you could point to that URL whenever you may find yourself in a similar situation. (I’m not telling you what to do, it’s just a suggestion.)

Indeed, if I ever came up with a blog post on the topic, I’d link to that when offering such suggestions, as I do often with other suggestions that may have more than can be covered in a sentence or two.

Keep up the good work!

/charlie

/Charlie (troubleshooter, carehart.org)

Report · Oct 20, 2015

Thank you Carl, these settings (with explanations) are very helpful. I haven't had a chance to do anything with them, but once I find some time, I'll see if they will help us with performance tuning of our servers.

Adobe Community

ColdFusion 11 Instances not starting properly after server restart

1 Correct answer