Copy link to clipboard
Copied
Hello All,
When I start ColdFusion, I'm getting a startup time of 602 seconds (or thereabouts). This can't be normal...can it? What on earth could be taking so long?
Thanks.
In a previous, similar thread, the issues were IPv6 and wrong IPs in /etc/hosts.
Copy link to clipboard
Copied
I would expect 10 to 20 seconds pending platform.
For CF8 on an old Win03 32 bit server with a 1.8GHz XEON the CF runtime logs say:
Server coldfusion ready (startup time: 20 seconds)
HTH, Carl.
Copy link to clipboard
Copied
Thanks Carl. So, I reckon you'd expect less than 10 minutes for CF9 on the following setup:
* Amazon EC2 M1.Small Instance (http://aws.amazon.com/ec2/instance-types/)
* 2007 Xeon @ ~1.1 GHz Single Core Equivalent (1 EC2 Compute Unit)
* 1.7 GB RAM
* Ubuntu 11.10 (GNU/Linux 3.0.0-16-virtual x86_64)
* ColdFusion 9.0.1.274733
Not sure what else to do, I upgraded to an M1.Medium Instance:
* 2007 Xeon @ ~1.1 GHz Dual Core Equivalent (2 EC2 Compute Unit)
* 3.75 GB RAM
* Ubuntu 11.10 (GNU/Linux 3.0.0-16-virtual x86_64)
* ColdFusion 9.0.1.274733
The improvement, if there really was any, was not significant. Startup time was still 586 seconds.
Copy link to clipboard
Copied
When I start ColdFusion, I'm getting a startup time of 602 seconds (or thereabouts). This can't be normal...can it? What on earth could be taking so long?
Dunno. What do the logs say? They might give you an idea if something is going wrong, or some part of it is taking an inordinate amount of time.
You're not giving us much to go on here.
--
Adam
Copy link to clipboard
Copied
Thanks for your reply Adam. I separated out this long-startup-time issue from another thread that no one has replied to yet in which I listed three major issues:
1. Frequent (approximately daily) crash-and-autorestarts.
2. Unable to stop CF server
3. Abnormally long startup time for CF server
I posted quite a bit of log output there: http://forums.adobe.com/message/4339091#433909
Here's a bit of that:
04/12 01:12:42 Information [jrpp-1122] - HTTP request completed {Status Code=200 ,Time taken=14669 ms}
autorestart: Restarting process
Starting Macromedia JRun 4.0 (Build 108858), coldfusion server
04/12 01:16:13 warning Unable to open /opt/coldfusion9/runtime/lib/license.properties
04/12 01:19:24 info JRun Naming Service listening on *:2932
04/12 01:22:35 error Connection refused to host: [external_ip]; nested exception is:
java.net.ConnectException: Connection timed out
[1]java.net.ConnectException: Connection timed out
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(Unknown Source)
at java.net.PlainSocketImpl.connectToAddress(Unknown Source)
at java.net.PlainSocketImpl.connect(Unknown Source)
at java.net.SocksSocketImpl.connect(Unknown Source)
at java.net.Socket.connect(Unknown Source)
at java.net.Socket.connect(Unknown Source)
at java.net.Socket.<init>(Unknown Source)
at java.net.Socket.<init>(Unknown Source)
at sun.rmi.transport.proxy.RMIDirectSocketFactory.createSocket(Unknown Source)
at sun.rmi.transport.proxy.RMIMasterSocketFactory.createSocket(Unknown Source)
at sun.rmi.transport.tcp.TCPEndpoint.newSocket(Unknown Source)
at sun.rmi.transport.tcp.TCPChannel.createConnection(Unknown Source)
at sun.rmi.transport.tcp.TCPChannel.newConnection(Unknown Source)
at sun.rmi.server.UnicastRef.invoke(Unknown Source)
at jrun.servlet.session.SessionReplicationService_Stub.getRemoteServerNa me(Unknown Source)
at jrun.servlet.session.SessionReplicationService.start(SessionReplicati onService.java:53)
at jrun.servlet.ServletEngineService.createSessionReplicationService(Ser vletEngineService.java:130)
at jrun.servlet.ServletEngineService.start(ServletEngineService.java:112 )
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(Unknown Source)
at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(Unknown Source)
at com.sun.jmx.mbeanserver.MBeanIntrospector.invokeM(Unknown Source)
at com.sun.jmx.mbeanserver.PerInterface.invoke(Unknown Source)
at com.sun.jmx.mbeanserver.MBeanSupport.invoke(Unknown Source)
at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(Unknown Source)
at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(Unknown Source)
at jrunx.kernel.ServiceAdapter.invokeMethod(ServiceAdapter.java:705)
at jrunx.kernel.JRunServiceDeployer.invokeOnServices(JRunServiceDeployer .java:460)
at jrunx.kernel.JRunServiceDeployer.startServices(JRunServiceDeployer.ja va:312)
at jrunx.kernel.JRunServiceDeployer.startLifecycle(JRunServiceDeployer.j ava:260)
at jrunx.kernel.JRunServiceDeployer.deployServices(JRunServiceDeployer.j ava:87)
at jrunx.kernel.DeploymentService.loadServices(DeploymentService.java:46 )
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(Unknown Source)
at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(Unknown Source)
at com.sun.jmx.mbeanserver.MBeanIntrospector.invokeM(Unknown Source)
at com.sun.jmx.mbeanserver.PerInterface.invoke(Unknown Source)
at com.sun.jmx.mbeanserver.MBeanSupport.invoke(Unknown Source)
at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(Unknown Source)
at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(Unknown Source)
at jrunx.kernel.JRun.startServer(JRun.java:575)
at jrunx.kernel.JRun.<init>(JRun.java:493)
at jrunx.kernel.JRun$1.run(JRun.java:346)
at java.security.AccessController.doPrivileged(Native Method)
at jrunx.kernel.JRun.start(JRun.java:343)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at jrunx.kernel.JRun.invoke(JRun.java:180)
at jrunx.kernel.JRun.main(JRun.java:168)
[0]java.rmi.ConnectException: Connection refused to host: [external_ip]; nested exception is:
java.net.ConnectException: Connection timed out
at sun.rmi.transport.tcp.TCPEndpoint.newSocket(Unknown Source)
at sun.rmi.transport.tcp.TCPChannel.createConnection(Unknown Source)
at sun.rmi.transport.tcp.TCPChannel.newConnection(Unknown Source)
at sun.rmi.server.UnicastRef.invoke(Unknown Source)
at jrun.servlet.session.SessionReplicationService_Stub.getRemoteServerNa me(Unknown Source)
at jrun.servlet.session.SessionReplicationService.start(SessionReplicati onService.java:53)
at jrun.servlet.ServletEngineService.createSessionReplicationService(Ser vletEngineService.java:130)
at jrun.servlet.ServletEngineService.start(ServletEngineService.java:112 )
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(Unknown Source)
at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(Unknown Source)
at com.sun.jmx.mbeanserver.MBeanIntrospector.invokeM(Unknown Source)
at com.sun.jmx.mbeanserver.PerInterface.invoke(Unknown Source)
at com.sun.jmx.mbeanserver.MBeanSupport.invoke(Unknown Source)
at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(Unknown Source)
at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(Unknown Source)
at jrunx.kernel.ServiceAdapter.invokeMethod(ServiceAdapter.java:705)
at jrunx.kernel.JRunServiceDeployer.invokeOnServices(JRunServiceDeployer .java:460)
at jrunx.kernel.JRunServiceDeployer.startServices(JRunServiceDeployer.ja va:312)
at jrunx.kernel.JRunServiceDeployer.startLifecycle(JRunServiceDeployer.j ava:260)
at jrunx.kernel.JRunServiceDeployer.deployServices(JRunServiceDeployer.j ava:87)
at jrunx.kernel.DeploymentService.loadServices(DeploymentService.java:46 )
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(Unknown Source)
at com.sun.jmx.mbeanserver.StandardMBeanIntrospector.invokeM2(Unknown Source)
at com.sun.jmx.mbeanserver.MBeanIntrospector.invokeM(Unknown Source)
at com.sun.jmx.mbeanserver.PerInterface.invoke(Unknown Source)
at com.sun.jmx.mbeanserver.MBeanSupport.invoke(Unknown Source)
at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(Unknown Source)
at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(Unknown Source)
at jrunx.kernel.JRun.startServer(JRun.java:575)
at jrunx.kernel.JRun.<init>(JRun.java:493)
at jrunx.kernel.JRun$1.run(JRun.java:346)
at java.security.AccessController.doPrivileged(Native Method)
at jrunx.kernel.JRun.start(JRun.java:343)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at jrunx.kernel.JRun.invoke(JRun.java:180)
at jrunx.kernel.JRun.main(JRun.java:168)
Caused by: java.net.ConnectException: Connection timed out
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.PlainSocketImpl.doConnect(Unknown Source)
at java.net.PlainSocketImpl.connectToAddress(Unknown Source)
at java.net.PlainSocketImpl.connect(Unknown Source)
at java.net.SocksSocketImpl.connect(Unknown Source)
at java.net.Socket.connect(Unknown Source)
at java.net.Socket.connect(Unknown Source)
at java.net.Socket.<init>(Unknown Source)
at java.net.Socket.<init>(Unknown Source)
at sun.rmi.transport.proxy.RMIDirectSocketFactory.createSocket(Unknown Source)
at sun.rmi.transport.proxy.RMIMasterSocketFactory.createSocket(Unknown Source)
... 47 more
04/12 01:22:36 info No JDBC data sources have been configured for this server (see jrun-resources.xml)
04/12 01:22:36 info JRun Proxy Server listening on *:51800
04/12 01:22:36 info Deploying enterprise application "Adobe_ColdFusion_9" from: file:/opt/coldfusion9/
04/12 01:22:37 info Deploying web application "Adobe ColdFusion 9" from: file:/opt/coldfusion9/
04/12 01:22:41 INFO License Service: Flex 1.5 CF Edition enabled
04/12 01:22:41 INFO Starting Flex 1.5 CF Edition
04/12 01:22:42 user JSPServlet: init
04/12 01:22:43 user ColdFusionStartUpServlet: init
04/12 01:22:43 user ColdFusionStartUpServlet: ColdFusion: Starting application services
04/12 01:22:43 user ColdFusionStartUpServlet: ColdFusion: VM version = 14.3-b01
04/12 01:22:44 Information [main] - Starting logging...
04/12 01:22:44 Information [main] - Starting license...
04/12 01:22:47 Information [main] - Standard Edition enabled
04/12 01:22:47 Information [main] - Starting crypto...
04/12 01:22:47 Information [main] - Starting security...
04/12 01:22:47 Information [main] - Starting scheduler...
04/12 01:22:48 Information [main] - Starting WatchService...
04/12 01:22:48 Information [main] - Starting debugging...
04/12 01:22:48 Information [main] - Starting sql...
04/12 01:22:48 Information [main] - Pool Manager Started
04/12 01:22:48 Information [main] - Starting mail...
04/12 01:22:48 Information [main] - Starting runtime...
04/12 01:22:48 Information [main] - CORBA Configuration not enabled
04/12 01:22:48 Information [main] - Starting cron...
04/12 01:22:49 Information [main] - Starting registry...
04/12 01:22:49 Information [main] - Starting client...
04/12 01:22:49 Information [main] - Starting xmlrpc...
04/12 01:22:49 Information [main] - Starting graphing...
04/12 01:22:49 Information [main] - Starting verity...
04/12 01:22:49 Information [main] - Starting solr...
04/12 01:22:49 Information [main] - Starting archive...
04/12 01:22:49 Information [main] - Starting document...
04/12 01:22:49 Information [main] - Starting eventgateway...
04/12 01:22:50 Information [main] - Starting Event Backend Handlers.
04/12 01:22:50 Information [main] - Initialized EventRequestDispatcher with a Thread Pool size of 1.
04/12 01:22:50 Information [main] - Initializing EventRequestHandler
04/12 01:22:50 Information [main] - Starting Event Gateways.
04/12 01:22:50 Information [main] - Starting FlexAssembler...
04/12 01:22:50 Information [main] - Starting .NET...
04/12 01:22:50 Information [main] - Starting Monitoring...
04/12 01:22:51 Information [main] - ColdFusion started
04/12 01:22:51 user ColdFusionStartUpServlet: ColdFusion: application services are now available
04/12 01:22:51 user CFMxmlServlet: init
04/12 01:22:51 user CFMxmlServlet: Macromedia Flex Build: 87315.134646
04/12 01:22:51 INFO Macromedia Flex Build: 87315.134646
04/12 01:22:56 user CFSwfServlet: init
04/12 01:22:56 user CFCServlet: init
04/12 01:22:56 error There is no web application configured to service your request
04/12 01:22:56 user NoWebappServlet: init
04/12 01:22:59 user FlashGateway: init
04/12 01:23:00 user MessageBrokerServlet: init
04/12 01:23:00 user CFFormGateway: init
04/12 01:23:01 user CFInternalServlet: init
04/12 01:23:01 user WSRPProducer: init
04/12 01:23:02 user ServerCFCServlet: init
Server coldfusion ready (startup time: 602 seconds)
As you can see, it's up at 01:12:42. It then says it's restarting (but doesn't provide a timestamp). At 01:16:13 it complains about not being able to read the license; so perhaps it was trying to do that for three and a half minutes. At 01:19:24 it reports that the JRun Naming Service is listening, so it took it three minutes to do that after it gave up on the license? I must have tried to hit a page before it was done starting up because the next part of the log is an connection timeout error. At 01:22:36 the startup log continues and wraps up its work by 01:23:02 claiming a total startup time of 602 seconds. So it must have started (re)starting at 01:13 exactly, only 18 seconds after it was (so far as I can tell) humming along happily.
The issue of the license is interesting, because it doesn't happen every time, and it doesn't seem to have much affect on the startup time when it does work. During a different startup run where the license.properties problem didn't come up, the startup time was still 586 seconds.
Copy link to clipboard
Copied
azimuthinternet wrote:
Hello All,
When I start ColdFusion, I'm getting a startup time of 602 seconds (or thereabouts). This can't be normal...can it? What on earth could be taking so long?
Your Operating System, ColdFusion build, web server? What does the log file coldfusion-out.log say?
Copy link to clipboard
Copied
Thanks for your reply BKBK. I don't have a coldfusion-out.log. A listing of /opt/coldfusion9/logs/ reads:
* application.log
* cfserver.log
* derby.log
* eventgateway.log
* exception.log
* ftp.log
* http.log
* mail.log
* mailsent.log
* server.log
I ran a `locate` for coldfusion-out.log and it returned nothing. Any other suggestions?
Copy link to clipboard
Copied
In a previous, similar thread, the issues were IPv6 and wrong IPs in /etc/hosts.
Copy link to clipboard
Copied
Thanks a lot BKBK. It was the /etc/hosts file. There was no entry for my internal IP, so it must have been using the hostname and a DNS lookup (maybe?), because it was eventually attempting to connect on my external IP. After adding my internal IP to the /etc/hosts file, 'stop', 'start', and 'restart' all behave nicely and the startup time is just 34 seconds.
04/17 18:55:48 user CFInternalServlet: destroy
04/17 18:55:48 Information [Thread-1] - Stopping Event Gateways.
04/17 18:55:53 Information [Thread-1] - ColdFusion stopped
04/17 18:55:53 user FlashGateway: destroy
04/17 18:55:53 user WSRPProducer: destroy
04/17 18:55:53 user CFCServlet: destroy
04/17 18:55:53 user CFMxmlServlet: destroy
04/17 18:55:53 user CFFormGateway: destroy
04/17 18:55:53 user CFSwfServlet: destroy
Starting Macromedia JRun 4.0 (Build 108858), coldfusion server
04/17 18:56:21 warning Unable to open /opt/coldfusion9/runtime/lib/license.properties
04/17 18:56:22 info JRun Naming Service listening on *:2932
04/17 18:56:23 info No JDBC data sources have been configured for this server (see jrun-resources.xml)
04/17 18:56:23 info JRun Proxy Server listening on *:51800
04/17 18:56:23 info Deploying enterprise application "Adobe_ColdFusion_9" from: file:/opt/coldfusion9/
04/17 18:56:23 info Deploying web application "Adobe ColdFusion 9" from: file:/opt/coldfusion9/
04/17 18:56:24 INFO License Service: Flex 1.5 CF Edition enabled
04/17 18:56:24 INFO Starting Flex 1.5 CF Edition
04/17 18:56:24 user JSPServlet: init
04/17 18:56:25 user ColdFusionStartUpServlet: init
04/17 18:56:25 user ColdFusionStartUpServlet: ColdFusion: Starting application services
04/17 18:56:25 user ColdFusionStartUpServlet: ColdFusion: VM version = 14.3-b01
04/17 18:56:25 Information [main] - Starting logging...
04/17 18:56:25 Information [main] - Starting license...
04/17 18:56:27 Information [main] - Standard Edition enabled
04/17 18:56:27 Information [main] - Starting crypto...
04/17 18:56:27 Information [main] - Starting security...
04/17 18:56:27 Information [main] - Starting scheduler...
04/17 18:56:27 Information [main] - Starting WatchService...
04/17 18:56:27 Information [main] - Starting debugging...
04/17 18:56:27 Information [main] - Starting sql...
04/17 18:56:27 Information [main] - Pool Manager Started
04/17 18:56:27 Information [main] - Starting mail...
04/17 18:56:27 Information [main] - Starting runtime...
04/17 18:56:27 Information [main] - CORBA Configuration not enabled
04/17 18:56:27 Information [main] - Starting cron...
04/17 18:56:27 Information [main] - Starting registry...
04/17 18:56:27 Information [main] - Starting client...
04/17 18:56:28 Information [main] - Starting xmlrpc...
04/17 18:56:28 Information [main] - Starting graphing...
04/17 18:56:28 Information [main] - Starting verity...
04/17 18:56:28 Information [main] - Starting solr...
04/17 18:56:28 Information [main] - Starting archive...
04/17 18:56:28 Information [main] - Starting document...
04/17 18:56:28 Information [main] - Starting eventgateway...
04/17 18:56:28 Information [main] - Starting Event Backend Handlers.
04/17 18:56:28 Information [main] - Initialized EventRequestDispatcher with a Thread Pool size of 1.
04/17 18:56:28 Information [main] - Initializing EventRequestHandler
04/17 18:56:28 Information [main] - Starting Event Gateways.
04/17 18:56:28 Information [main] - Starting FlexAssembler...
04/17 18:56:28 Information [main] - Starting .NET...
04/17 18:56:28 Information [main] - Starting Monitoring...
04/17 18:56:29 Information [main] - ColdFusion started
04/17 18:56:29 user ColdFusionStartUpServlet: ColdFusion: application services are now available
04/17 18:56:29 user CFMxmlServlet: init
04/17 18:56:29 user CFMxmlServlet: Macromedia Flex Build: 87315.134646
04/17 18:56:29 INFO Macromedia Flex Build: 87315.134646
04/17 18:56:31 user CFSwfServlet: init
04/17 18:56:31 user CFCServlet: init
04/17 18:56:32 user FlashGateway: init
04/17 18:56:32 user MessageBrokerServlet: init
04/17 18:56:33 user CFFormGateway: init
04/17 18:56:33 user CFInternalServlet: init
04/17 18:56:33 user WSRPProducer: init
04/17 18:56:33 user ServerCFCServlet: init
Server coldfusion ready (startup time: 34 seconds)
Notably, it's still unhappy with the license.properties for some reason, but it's not consuming a lot of time or (apparently) causing any other problem than the complaint in the log.
In my case, there was no issue with IPv6. The issue was resolved simply by adding my internal IP to /etc/hosts.
Thanks again.
~Day