8 Replies Latest reply: Apr 17, 2012 12:09 PM by azimuthinternet RSS

    CF9: Normal Startup Time

    azimuthinternet

      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.

        • 1. Re: CF9: Normal Startup Time
          carl type3 Community Member

          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.

          • 2. Re: CF9: Normal Startup Time
            Adam Cameron. Community Member

            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

            • 3. Re: CF9: Normal Startup Time
              BKBK MVP

              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?

              • 4. Re: CF9: Normal Startup Time
                azimuthinternet Community Member

                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.

                • 5. Re: CF9: Normal Startup Time
                  azimuthinternet Community Member

                  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?

                  • 6. Re: CF9: Normal Startup Time
                    azimuthinternet Community Member

                    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.

                    • 7. Re: CF9: Normal Startup Time
                      BKBK MVP

                      In a previous, similar thread, the issues were IPv6 and wrong IPs in /etc/hosts.

                      • 8. Re: CF9: Normal Startup Time
                        azimuthinternet Community Member

                        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