• Global community
    • Language:
      • Deutsch
      • English
      • Español
      • Français
      • Português
  • 日本語コミュニティ
    Dedicated community for Japanese speakers
  • 한국 커뮤니티
    Dedicated community for Korean speakers
Exit
0

Coldfusion 10 Update 13 IIS7 503 Service Unavailable

New Here ,
Sep 10, 2014 Sep 10, 2014

Copy link to clipboard

Copied

Coldfusion 10 Update 13

Windows Server Datacenter 2008 SP2

IIS7

We're having periodic issues where our Coldfusion service seems to recycle or restart, and the user will receive a 503 Error Code back from IIS.

At the time of the error, our coldfusion-out.log shows the service starting:

Sep 9, 2014 12:46:55 PM Information [pool-2-thread-1] - Starting logging...

Sep 9, 2014 12:46:55 PM Information [pool-2-thread-1] - Starting license...

Sep 9, 2014 12:46:57 PM Information [pool-2-thread-1] - Standard Edition enabled

Sep 9, 2014 12:46:57 PM Information [pool-2-thread-1] - Starting crypto...

Sep 9, 2014 12:46:57 PM Information [pool-2-thread-1] - Starting security...

Sep 9, 2014 12:46:59 PM Information [pool-2-thread-1] - Starting scheduler...

Sep 9, 2014 12:46:59 PM Information [pool-2-thread-1] - Starting WatchService...

Sep 9, 2014 12:46:59 PM Information [pool-2-thread-1] - Starting debugging...

Sep 9, 2014 12:46:59 PM Information [pool-2-thread-1] - Starting sql...

Sep 9, 2014 12:47:00 PM Information [pool-2-thread-1] - Pool Manager Started

Sep 9, 2014 12:47:00 PM Information [pool-2-thread-1] - Starting mail...

Sep 9, 2014 12:47:00 PM Information [pool-2-thread-1] - Starting runtime...

Sep 9, 2014 12:47:01 PM Information [pool-2-thread-1] - CORBA Configuration not enabled

Sep 9, 2014 12:47:01 PM Information [pool-2-thread-1] - Starting cron...

Sep 9, 2014 12:47:02 PM Information [pool-2-thread-1] - Starting registry...

Sep 9, 2014 12:47:02 PM Information [pool-2-thread-1] - Starting client...

Sep 9, 2014 12:47:02 PM Information [pool-2-thread-1] - Starting xmlrpc...

Sep 9, 2014 12:47:02 PM Information [pool-2-thread-1] - Starting jaxrs...

Sep 9, 2014 12:47:02 PM Information [pool-2-thread-1] - Starting graphing...

Sep 9, 2014 12:47:02 PM Information [pool-2-thread-1] - Starting solr...

Sep 9, 2014 12:47:02 PM Information [pool-2-thread-1] - Starting archive...

Sep 9, 2014 12:47:02 PM Information [pool-2-thread-1] - Starting document...

Sep 9, 2014 12:47:02 PM Information [pool-2-thread-1] - Starting eventgateway...

Sep 9, 2014 12:47:03 PM Information [pool-2-thread-1] - Event Gateway Disabled.

Sep 9, 2014 12:47:03 PM Information [pool-2-thread-1] - Starting FlexAssembler...

Sep 9, 2014 12:47:03 PM Information [pool-2-thread-1] - Starting .NET...

Sep 9, 2014 12:47:04 PM Information [pool-2-thread-1] - Starting Monitoring...

Sep 9, 2014 12:47:04 PM Information [pool-2-thread-1] - Starting WebSocket...

Sep 9, 2014 12:47:04 PM Information [pool-2-thread-1] - WebSocket server listens on port: 8575

Sep 9, 2014 12:47:04 PM Information [pool-2-thread-1] - ColdFusion started

Sep 9, 2014 12:47:04 PM Information [pool-2-thread-1] - ColdFusion: application services are now available

The IIS access log shows the page request followed by the 503 status code.

2014-09-09 16:46:48 10.185.130.118 POST /cart 8086 - 10.238.196.27 Mozilla/5.0+(Windows+NT+6.1;+WOW64;+Trident/7.0;+rv

:11.0)+like+Gecko 503 0 0 2199

In the Windows Event Logs, we see the following

12:46:44PM The WinHTTP Web Proxy Auto-Discovery Service service entered the running state.

12:47:16PM The ColdFusion 10 Application Server service entered the running state.

This issue is occuring multiple times per day

Views

3.0K

Translate

Translate

Report

Report
Community guidelines
Be kind and respectful, give credit to the original source of content, and search for duplicates before posting. Learn more
community guidelines

correct answers 1 Correct answer

Guide , Sep 10, 2014 Sep 10, 2014

From isapi_redirect.log appears tomcat at the CF10 end is failing.

Perhaps applying some of the CF tomcat tuning mentioned in this blog will help. The blog is titled CF11 however details are pertinent to CF10:

http://blogs.coldfusion.com/post.cfm/coldfusion-11-iis-connector-tuning

I discuss and demonstrate some of the CF tomcat settings here:

http://vimeo.com/67571552

The connector date stamp seems correct.


HTH again, Carl.

Votes

Translate

Translate
Guide ,
Sep 10, 2014 Sep 10, 2014

Copy link to clipboard

Copied

Prior to CF starting any errors in coldfusion-out.log?

Any errors warnings in coldfusion-error.log at that time?

Any errors warnings in ColdFusion10\config\wsconfig\N\isapi_redirect.log ?

Where N = some number probably 1.

CF10 update 13. So likely manual step to update isapi_redirect.dll has been done however to check what is the date stamp of isapi_redirect.dll ?


HTH, Carl.

Votes

Translate

Translate

Report

Report
Community guidelines
Be kind and respectful, give credit to the original source of content, and search for duplicates before posting. Learn more
community guidelines
New Here ,
Sep 10, 2014 Sep 10, 2014

Copy link to clipboard

Copied

There are no errors in the coldfusion-out.log prior to the startup:

Sep 9, 2014 12:38:28 PM Information [scheduler-0] - Run Client Storage Purge

09/09 12:46:55 INFO License Service: Flex 1.5 CF Edition enabled

09/09 12:46:55 INFO Starting Flex 1.5 CF Edition

Sep 9, 2014 12:46:55 PM Information [pool-2-thread-1] - Starting logging...

...

These messages from coldfusion-error.log may be related, but there is no timestamp available in the log:

Sep 08, 2014 9:39:56 AM org.apache.catalina.core.ApplicationContext log

INFO: CFMxmlServlet: Macromedia Flex Build: 87315.134646

Sep 08, 2014 9:40:04 AM org.apache.coyote.AbstractProtocol start

INFO: Starting ProtocolHandler ["ajp-bio-8012"]

Sep 08, 2014 9:40:04 AM com.adobe.coldfusion.launcher.Launcher run

INFO: Server startup in 30945 ms

java.lang.NullPointerException

  at coldfusion.server.jrun4.metrics.SimpleLoadMetric.run(SimpleLoadMetric.java:157)

  at coldfusion.scheduling.ThreadPool.run(ThreadPool.java:211)

  at coldfusion.scheduling.WorkerThread.run(WorkerThread.java:71)

...ABOVE LINE REPEATED...

Sep 09, 2014 1:32:57 PM org.apache.catalina.core.AprLifecycleListener init

isapi_redirect.log:

[Tue Sep 09 11:35:39.400 2014] [3968:2000] [info] ajp_send_request::jk_ajp_common.c (1658): (cfusion) all endpoints are disconnected, detected by connect check (3), cping (0), send (0)

[Tue Sep 09 12:46:46.059 2014] [3968:2832] [info] ajp_send_request::jk_ajp_common.c (1658): (cfusion) all endpoints are disconnected, detected by connect check (3), cping (0), send (0)

[Tue Sep 09 12:46:47.057 2014] [3968:2832] [info] jk_open_socket::jk_connect.c (626): connect to 127.0.0.1:8012 failed (errno=61)

[Tue Sep 09 12:46:47.057 2014] [3968:2832] [info] ajp_connect_to_endpoint::jk_ajp_common.c (1047): Failed opening socket to (127.0.0.1:8012) (errno=61)

[Tue Sep 09 12:46:47.057 2014] [3968:2832] [error] ajp_send_request::jk_ajp_common.c (1669): (cfusion) connecting to backend failed. Tomcat is probably not started or is listening on the wrong port (errno=61)

[Tue Sep 09 12:46:47.057 2014] [3968:2832] [info] ajp_service::jk_ajp_common.c (2692): (cfusion) sending request to tomcat failed (recoverable), because of error during request sending (attempt=1)

[Tue Sep 09 12:46:48.181 2014] [3968:2832] [info] jk_open_socket::jk_connect.c (626): connect to 127.0.0.1:8012 failed (errno=61)

[Tue Sep 09 12:46:48.212 2014] [3968:2832] [info] ajp_connect_to_endpoint::jk_ajp_common.c (1047): Failed opening socket to (127.0.0.1:8012) (errno=61)

[Tue Sep 09 12:46:48.227 2014] [3968:2832] [error] ajp_send_request::jk_ajp_common.c (1669): (cfusion) connecting to backend failed. Tomcat is probably not started or is listening on the wrong port (errno=61)

[Tue Sep 09 12:46:48.227 2014] [3968:2832] [info] ajp_service::jk_ajp_common.c (2692): (cfusion) sending request to tomcat failed (recoverable), because of error during request sending (attempt=2)

[Tue Sep 09 12:46:48.227 2014] [3968:2832] [error] ajp_service::jk_ajp_common.c (2711): (cfusion) connecting to tomcat failed.

[Tue Sep 09 12:46:48.227 2014] [3968:2832] [error] HttpExtensionProc::jk_isapi_plugin.c (2309): service() failed with http error 503

We ran the wsconfig.exe and reconfigured the connectors after the latest update was applied. 

Timestamp of isapi_redirect.dll is 11/2/2013 2:12 PM

Thank you very much!

Votes

Translate

Translate

Report

Report
Community guidelines
Be kind and respectful, give credit to the original source of content, and search for duplicates before posting. Learn more
community guidelines
Guide ,
Sep 10, 2014 Sep 10, 2014

Copy link to clipboard

Copied

From isapi_redirect.log appears tomcat at the CF10 end is failing.

Perhaps applying some of the CF tomcat tuning mentioned in this blog will help. The blog is titled CF11 however details are pertinent to CF10:

http://blogs.coldfusion.com/post.cfm/coldfusion-11-iis-connector-tuning

I discuss and demonstrate some of the CF tomcat settings here:

http://vimeo.com/67571552

The connector date stamp seems correct.


HTH again, Carl.

Votes

Translate

Translate

Report

Report
Community guidelines
Be kind and respectful, give credit to the original source of content, and search for duplicates before posting. Learn more
community guidelines
New Here ,
Sep 12, 2014 Sep 12, 2014

Copy link to clipboard

Copied

Hi Carl,

I've applied the settings in that article recommended for my server configuration.  According to the isapi_redirect.log, everything is much more stable, however we are still seeing a few of these 503 errors.

I've also gone through your video, and have a better understanding of what is happening.

I'll continue monitoring for a few days and report back.

Regards,

Tom

Votes

Translate

Translate

Report

Report
Community guidelines
Be kind and respectful, give credit to the original source of content, and search for duplicates before posting. Learn more
community guidelines
New Here ,
Sep 15, 2014 Sep 15, 2014

Copy link to clipboard

Copied

Hi Carl,

Do the thread count settings have any bearing on Coldfusion standard edition?  I notice that even under load, the server only seems to spawn 10 ajp-bio-8012-exec threads.  Does the 10 CFThread limit on coldfusion standard edition also affect this thread count?

Thanks in advance,

Tom

threads.png

Votes

Translate

Translate

Report

Report
Community guidelines
Be kind and respectful, give credit to the original source of content, and search for duplicates before posting. Learn more
community guidelines
Guide ,
Sep 15, 2014 Sep 15, 2014

Copy link to clipboard

Copied

Capture.JPG

Hi Tom,

Tomcat by default configures to run with 10 threads available. In server.xml that is defined as minSpareThreads, in workers.properties as connection_pool_minsize. While Official CF blog post does not give it a mention I do in my talk and I think the default setting of 10 is not adequate for production systems.

To configure a value greater than 10 then server.xml needs in connector AJP section:


minSpareThreads="N" where N=<10 EG 100

works.properties needs:


worker.cfusion.connection_pool_minsize=N where N=<10 EG 100

Above is Jvisualvm thread monitoring diagram, I can’t picture them all but 100 spare threads. You will notice AJP is using APR rather than BIO. I ran a "bad app" so I could get some more activity.

I  note the slide deck mentioned in video is still present to download.

HTH again, Carl.

Votes

Translate

Translate

Report

Report
Community guidelines
Be kind and respectful, give credit to the original source of content, and search for duplicates before posting. Learn more
community guidelines
Guide ,
Sep 16, 2014 Sep 16, 2014

Copy link to clipboard

Copied

LATEST

Capture.JPG

PS

showing 100 threads using JMC - Java Mission Control.

CF system has 100 tomcat threads allocated. If it didn't every time the load would go beyond 10 threads it would bottleneck, slow down or worse still crash.

Votes

Translate

Translate

Report

Report
Community guidelines
Be kind and respectful, give credit to the original source of content, and search for duplicates before posting. Learn more
community guidelines
Resources
Documentation