Coldfusion 2016 Not Starting Up after Windows Updates

[Pokermon]

Hello, I just installed the January Microsoft updates for Windows Server 2012R2 and now ColdFusion 2016 ( with level 16 patch ) will not start. Please help, this is a production system for state Government! Here is the info from the logs. I have tried restarting the server 4 times. Funny thing is that the server log says ColdFusion application server was started. Thanks for any help you can give!

When I try to start the Application Server from Windows Services it times out and gives the following response. "Windows could not start the ColdFusion 2016 Application Server services on Local Computer. Error 1053: The service did not respond to the start or control request in a timely fashion.

Here is the coldfusion-error log:

Jan 24, 2021 7:22:07 AM org.apache.catalina.core.AprLifecycleListener lifecycleEvent
INFO: The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: [D:\ColdFusion2016\cfusion\lib;D:\ColdFusion2016\cfusion\jintegra\bin;D:\ColdFusion2016\cfusion\jintegra\bin\international;D:\ColdFusion2016\cfusion\lib\oosdk\classes\win;D:\\ColdFusion2016\\jre\bin]
Jan 24, 2021 7:22:08 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-nio-8500"]
Jan 24, 2021 7:22:08 AM org.apache.tomcat.util.net.NioSelectorPool getSharedSelector
INFO: Using a shared selector for servlet write/read
Jan 24, 2021 7:22:08 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["ajp-nio-127.0.0.1-8016"]
Jan 24, 2021 7:22:08 AM org.apache.tomcat.util.net.NioSelectorPool getSharedSelector
INFO: Using a shared selector for servlet write/read
Jan 24, 2021 7:22:08 AM org.apache.catalina.core.StandardService startInternal
INFO: Starting service [Catalina]
Jan 24, 2021 7:22:08 AM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/8.5.42
Jan 24, 2021 7:22:21 AM org.apache.jasper.servlet.TldScanner scanJars
INFO: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
Jan 24, 2021 7:22:45 AM org.apache.catalina.util.SessionIdGeneratorBase createSecureRandom
WARNING: Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [22,775] milliseconds.
Jan 24, 2021 7:25:17 AM org.apache.catalina.core.ApplicationContext log
INFO: ColdFusionStartUpServlet: ColdFusion: Starting application services
Jan 24, 2021 7:25:17 AM org.apache.catalina.core.ApplicationContext log
INFO: ColdFusionStartUpServlet: ColdFusion: VM version = 25.72-b15

Here is the coldfusion-out log.

01/24 07:31:58 INFO License Service: Flex 1.5 CF Edition enabled
01/24 07:31:58 INFO Starting Flex 1.5 CF Edition
Jan 24, 2021 07:32:04 AM Information [localhost-startStop-1] - Starting logging...
Jan 24, 2021 07:32:05 AM Information [localhost-startStop-1] - Starting license...
Jan 24, 2021 07:32:06 AM Information [localhost-startStop-1] - Standard Edition enabled
Jan 24, 2021 07:32:07 AM Information [localhost-startStop-1] - Starting crypto...
Jan 24, 2021 07:32:07 AM Information [localhost-startStop-1] - Starting security...
Jan 24, 2021 07:32:24 AM Information [localhost-startStop-1] - Starting scheduler...
Jan 24, 2021 07:32:24 AM Information [localhost-startStop-1] - Starting WatchService...
Jan 24, 2021 07:32:24 AM Information [localhost-startStop-1] - Starting debugging...
Jan 24, 2021 07:32:26 AM Information [localhost-startStop-1] - Starting sql...
Jan 24, 2021 07:32:28 AM Information [localhost-startStop-1] - Pool Manager Started
Jan 24, 2021 07:32:29 AM Information [localhost-startStop-1] - Starting runtime...
Jan 24, 2021 07:32:59 AM Information [localhost-startStop-1] - CORBA Configuration not enabled
Jan 24, 2021 07:32:59 AM Information [localhost-startStop-1] - Starting mail...
Jan 24, 2021 07:32:59 AM Information [localhost-startStop-1] - Starting cron...
Jan 24, 2021 07:33:08 AM Information [localhost-startStop-1] - Created scheduler DefaultQuartzScheduler with thread pool size as 10
Jan 24, 2021 07:33:09 AM Information [DefaultQuartzScheduler_QuartzSchedulerThread] - Task DEFAULT.CHECK FOR COLDFUSION UPDATES misfired.
Jan 24, 2021 07:33:09 AM Information [localhost-startStop-1] - Starting registry...
Jan 24, 2021 07:33:10 AM Information [localhost-startStop-1] - Starting client...
Jan 24, 2021 07:33:11 AM Information [localhost-startStop-1] - Starting xmlrpc...
Jan 24, 2021 07:33:20 AM Information [localhost-startStop-1] - Starting jaxrs...
Jan 24, 2021 07:33:20 AM Information [localhost-startStop-1] - Starting graphing...
Jan 24, 2021 07:33:21 AM Information [localhost-startStop-1] - Starting solr...
Jan 24, 2021 07:33:23 AM Information [localhost-startStop-1] - Starting archive...
Jan 24, 2021 07:33:23 AM Information [localhost-startStop-1] - Starting document...
Jan 24, 2021 07:33:24 AM Information [localhost-startStop-1] - Starting eventgateway...
Jan 24, 2021 07:33:25 AM Information [localhost-startStop-1] - Event Gateway Disabled.
Jan 24, 2021 07:33:25 AM Information [localhost-startStop-1] - Starting FlexAssembler...
Jan 24, 2021 07:33:26 AM Information [localhost-startStop-1] - Starting .NET...
Jan 24, 2021 07:33:26 AM Information [localhost-startStop-1] - Starting Monitoring...
Jan 24, 2021 07:33:46 AM Information [localhost-startStop-1] - Starting Jetty Server on port 5500.
Jan 24, 2021 07:33:48 AM Information [localhost-startStop-1] - Starting WebSocket...
Jan 24, 2021 07:34:05 AM Information [localhost-startStop-1] - ColdFusion started
Jan 24, 2021 07:34:05 AM Information [localhost-startStop-1] - ColdFusion: application services are now available
01/24 07:34:06 INFO Macromedia Flex Build: 87315.134646

Here is the server log:

"Information","localhost-startStop-1","01/24/21","07:33:09","","Starting registry..."
"Information","localhost-startStop-1","01/24/21","07:33:10","","Starting client..."
"Information","localhost-startStop-1","01/24/21","07:33:11","","Starting xmlrpc..."
"Information","localhost-startStop-1","01/24/21","07:33:20","","Starting jaxrs..."
"Information","localhost-startStop-1","01/24/21","07:33:20","","Starting graphing..."
"Information","localhost-startStop-1","01/24/21","07:33:21","","Starting solr..."
"Information","localhost-startStop-1","01/24/21","07:33:23","","Starting archive..."
"Information","localhost-startStop-1","01/24/21","07:33:23","","Starting document..."
"Information","localhost-startStop-1","01/24/21","07:33:24","","Starting eventgateway..."
"Information","localhost-startStop-1","01/24/21","07:33:25","","Starting FlexAssembler..."
"Information","localhost-startStop-1","01/24/21","07:33:26","","Starting .NET..."
"Information","localhost-startStop-1","01/24/21","07:33:26","","Starting Monitoring..."
"Information","localhost-startStop-1","01/24/21","07:33:48","","Starting WebSocket..."
"Information","localhost-startStop-1","01/24/21","07:34:05","","ColdFusion started"
"Information","localhost-startStop-1","01/24/21","07:34:05","","ColdFusion: application services are now available"

[Charlie Arehart · Accepted solution]

Can you confirm if this is still a problem, as I'm replying 2 hours after you wrote? I ask because by now perhaps it's starting OK.

As for what you experienced, note that often after a windows update, there's simply a lot of work that goes on (from the update, even after the restart), that uses excessive cpu and disk, making anything else slow, including cf and its startup. This is suggested in your logs, which show long times between most lines, which is vey unusual. And were you saying that despite the log indicating cf was running, cf page requests would not respond? 

If you're still down (cf still won't start, pages won't run) even now a couple hours later, then clearly it would seem something else causing that. (Are there still seconds between most lines in the cf logs during the startup?)

If CF still won't start, then instead what happened was not likely caused BY the os  update but instead is due to some change done to cf or its config that simply didn't take effect until cf restarted, which happened on the os restart. And that could be a number of things. 

Starting cf from the command line, with cfstart in the cfusion/bin folder may work or give more details.

In the interest of time, if you want more direct and immediate help to get things back up, contact me at carehart.org/consulting. It would not take long to resolve things (via a screenshare, while I watch you remote in to the server), whatever the cause may be, including finding and explaining "what really happened".

Otherwise, hope what I shared here so far may help. 

[Pokermon]

Charlie, thanks, as always for your expert reply. It started up when I tried it from the command line.

[Charlie Arehart]

Glad you solved things, and thanks for marking my reply as the answer. But can you clarify: do you mean you could ONLY start it from the command line? Or were you also able to start it as a service (after the dust had settled)?