3 Replies Latest reply: Apr 17, 2012 2:08 PM by Krandolph RSS

    Daily Crash/AutoRestart: Troubleshooting (CF9 on Ubuntu 11 on EC2 M1.Small)

    azimuthinternet

      Hello,

       

      I have CF9 running on an Amazon M1.Small EC2 instance. The OS is Ubuntu 11. The instance has 1.7 GB memory and a single Xeon CPU.

       

      Here is a tail of my /opt/coldfusion9/logs/cfserver.log (I've included the first 11 lines just to show that it appears nothing unusual was going on):

       

      04/12 01:12:39 Information [jrpp-1079] - Starting HTTP request {URL='http://blog.[domain].com:80/mostrecent.php', method='post'}

      04/12 01:12:39 Information [jrpp-1111] - HTTP request completed  {Status Code=200 ,Time taken=11894 ms}

      04/12 01:12:39 Information [jrpp-1187] - HTTP request completed  {Status Code=200 ,Time taken=17524 ms}

      04/12 01:12:39 Information [jrpp-1134] - HTTP request completed  {Status Code=200 ,Time taken=11768 ms}

      04/12 01:12:39 Information [jrpp-1134] - Starting HTTP request {URL='http://blog.[domain].com:80/mostrecent.php', method='post'}

      04/12 01:12:39 Information [jrpp-1155] - HTTP request completed  {Status Code=200 ,Time taken=12109 ms}

      04/12 01:12:39 Information [jrpp-1155] - Starting HTTP request {URL='http://blog.[domain].com:80/mostrecent.php', method='post'}

      04/12 01:12:39 Information [jrpp-1154] - HTTP request completed  {Status Code=200 ,Time taken=12181 ms}

      04/12 01:12:41 Information [jrpp-1199] - HTTP request completed  {Status Code=200 ,Time taken=13582 ms}

      04/12 01:12:42 Information [jrpp-1206] - HTTP request completed  {Status Code=200 ,Time taken=14211 ms}

      04/12 01:12:42 Information [jrpp-1122] - HTTP request completed  {Status Code=200 ,Time taken=14669 ms}

       

      And then, out of the blue I get a WebSitePulse alert and tail my log and it says it's restarting. Well, that's nice...hmmm.


      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.getRemoteServerName(Unknown Source)

          at jrun.servlet.session.SessionReplicationService.start(SessionReplicationService.java:53)

          at jrun.servlet.ServletEngineService.createSessionReplicationService(ServletEngineService.ja va: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.java:312)

          at jrunx.kernel.JRunServiceDeployer.startLifecycle(JRunServiceDeployer.java:260)

          at jrunx.kernel.JRunServiceDeployer.deployServices(JRunServiceDeployer.java: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.getRemoteServerName(Unknown Source)

          at jrun.servlet.session.SessionReplicationService.start(SessionReplicationService.java:53)

          at jrun.servlet.ServletEngineService.createSessionReplicationService(ServletEngineService.ja va: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.java:312)

          at jrunx.kernel.JRunServiceDeployer.startLifecycle(JRunServiceDeployer.java:260)

          at jrunx.kernel.JRunServiceDeployer.deployServices(JRunServiceDeployer.java: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)

       

      602 Seconds? That's um... 10 minutes to startup, and since I'm monitoring the server at 15 minute intervals, it logs 15 minutes of estimated downtime for my client's displeasure.

       

      In the meantime (prior to the restart having completed), the server's handing out Error 500's like this:

       

      Server Error

      The server encountered an internal error and was unable to complete your request.

      Could not connect to JRun Server.

       

      So, I check /opt/coldfusion9/bin/coldfusion status and it tells me:

       

      Could not contact the ColdFusion Application Server running on this machine:

           Perhaps ColdFusion is not running on this machine?

           Perhaps cfstat is not enabled from the ColdFusion administrator?

           Perhaps ColdFusion was not restarted after enabling cfstat?

           Perhaps cfstat service is not listening on default port?

             Use option -port with port number as per the cfstatport

             defined in the neo-metrics xml file.

       

      Erm. Funny that that status script could contact the CAS because when I ran `top`, I could see it using up CPU and RAM, and a `ps aux` revealed it was, in fact, running...maybe it was just still starting up and wasn't ready to "talk". I'm not sure.

       

      Obviously, I'm curious as to what the cause was in the first place...cfserver.log just before the `autorestart` isn't telling me much, so I tail the application.log and the exception log but there's nothing in there with a timestamp right before this mysterious autorestart.

      This is weird too: I can't actually seem to stop the CF server from running:

       

      root@coffeereview:~# /opt/coldfusion9/bin/coldfusion status

       

      Pg/Sec  DB/Sec  CP/Sec  Reqs  Reqs  Reqs  AvgQ   AvgReq AvgDB  Bytes  Bytes

      Now Hi  Now Hi  Now Hi  Q'ed  Run'g TO'ed Time   Time   Time   In/Sec Out/Sec

      0   0   0   0   -1  -1  0     0     0     0      -46102960      0      0    

      root@coffeereview:~# /opt/coldfusion9/bin/coldfusion stop

      Stopping ColdFusion 9, please wait

      Stopping coldfusion server................................................................................... ............^C

       

      Here, I get tired of waiting and hit Ctrl-C, but sometimes I'll wait and wait and it never does anything other than draw dots.

       

      root@coffeereview:~# /opt/coldfusion9/bin/coldfusion status

       

      Pg/Sec  DB/Sec  CP/Sec  Reqs  Reqs  Reqs  AvgQ   AvgReq AvgDB  Bytes  Bytes

      Now Hi  Now Hi  Now Hi  Q'ed  Run'g TO'ed Time   Time   Time   In/Sec Out/Sec

      0   0   0   0   -1  -1  0     0     0     0      -11525740      0      0

       

      Still running. Obviously, I could hit the PID with a kill -9, but that seems a lottle rough, and not the ideal way to go about it. Last time I force quit it that way, I think it took even longer than 10 minutes to start back up when I ran `service coldfusion9 start`.

       

      So, my goal here is to figure out these 3 things:

       

      1. Why is my CF server is crashing and restarting?

      2. Why does it take so long to restart? and

      3. Why can I not stop the CF server by normal means?

       

      Any help with answering these questions would be much appreciated.

        • 1. Re: Daily Crash/AutoRestart: Troubleshooting (CF9 on Ubuntu 11 on EC2 M1.Small)
          azimuthinternet Community Member

          166 Views and 0 replies after 3 days. No one wants to give this one a go, eh? ;-)  Why not?

           

          Anyway, I've had a brief respite in the WebSitePulse alerts. Upgrading to an M1.Medium EC2 instance may or may not have been what stopped the daily crashes (double the RAM and CPU of the M1.Small). Are there official system requirements for CF that I should have been aware of before attempting to run it on an M1.Small?

           

          In any case, I'm apprehensive about trying a restart because of the other issues I reported (which I've now posted in other threads:

           

          1. CF9: Normal Startup Time?

          2. CF9: Cannot Stop Server

          • 2. Re: Daily Crash/AutoRestart: Troubleshooting (CF9 on Ubuntu 11 on EC2 M1.Small)
            azimuthinternet Community Member

            These last two sub-issues have been resolved. Apparently, both my inability to stop the server and the extremely long startup time were caused by not having my internal IP in my /etc/hosts file. Adding a listing like so fixed the problem:

             

            10.176.195.20 servername.com servername

             

            From my ifconfig:

             

            inet addr:10.176.195.20  Bcast:10.176.195.255  Mask:255.255.254.0

             

            Previously, there had been no entry in /etc/hosts for 10.176.195.20.

             

            The other issue, that of frequent mysterious restarts, seems (perhaps) to have been resolved by upgrading the resources on the EC2 instance. However, the  M1.Small met the system requirements for CF9, so that shouldn't have been necessary and it might have been code changes I made which require many fewer calls to MySQL. I'm actually planning to downgrade the server (back to what it was before) and see if the problem comes back. I'll try to remember to post the results of that experiment.

            • 3. Re: Daily Crash/AutoRestart: Troubleshooting (CF9 on Ubuntu 11 on EC2 M1.Small)
              Krandolph

              Hello,

               

              Have you changed your database drivers?   I noticed that there doesn't seem to be a very thorough testing of the database drivers in use by the non-windows ColdFusion installs.

               

              It seems that almost every contract job I go to where they are using ColdFusion on something other than Windows, we have had to play 'musical chairs' with the drivers in a attempt to find one that works well with a particular configuration of the operating system, Java, ColdFusion and the database connection.

               

              At one of my more recent jobs, Adobe has been working with the client for months in an attempt to find a driver that will work well for that flavor of Solaris and Oracle.

               

              We used FusionReactor to help us narrow down that the data connection was dieing between ColdFusion and the Oracle database and that the 'death' of the connection would end up casuing ColdFusion to lock up.

               

              I hope you have better luck than I did at that client.  It's been four months now and quite the number of different Oracle drivers.  I just heard this morning that they are going to give the Oracle thin client driver another go.

               

              Best regards,
              KR