Steven Erat's Blog Steven Erat Photography
 
 
Viewing By Entry
 
 

TalkingTree  Help! My ColdFusion MX Server is Slow!!!!

 

Determining Root Cause for Slow Application

I've often seen ColdFusion users complain that their server/application is running very slowly, not handling requests as fast as normal, or just plain "hung". Many would suggest examining log files to determine the status and recent history of the ColdFusion server in order to find clues that might reveal what the server was actually doing. While this troubleshooting step can be useful, it can only get you so far.
What's often overlooked is the ability to generate a "Full Thread Dump" from ColdFusion MX as a means to precisely determine exactly what the server was doing at exactly that moment, something that you wouldn't be able to otherwise garner from the logs alone.

Macromedia has a ColdFusionMX TechNote describing how to produce a Full Thread Dump, but there has been very little written so far describing what to do with it then. To that end, here is a reply I recently sent to the CFTalk mailing list:


You should take several full thread dumps in succession with a small interval in between them. Then to examine the thread dump, look for JRun Proxy Service threads beginning with jrpp-xxx where xxx is a number and jrpp-xxx is the thread id. Specifically, to find the running threads that are handling .cfm requests, search for the string (excluding the quotes) ".cfm:". This will lead you to a template and its path with a line number at the end after the colon. You'll also see other mentions of .cfm: further down in the stack of a particular thread, but it the top most one that was executing at that instant. Truncated example:

"jrpp-96" prio=5 tid=0x477e5008 nid=0xc50 runnable [698f000..698fdbc]
at coldfusion.tagext.NativeCfx.processRequest(Native Method)
at coldfusion.tagext.lang.CFSearchTag.doStartTag(CFSearchTag.java:207)
at coldfusion.runtime.CfJspPage._emptyTag(CfJspPage.java:1871)
at cf_cachelists2ecfm612782408.runPage(/opt/apache/htdocs/_cachelists.cfm:30)
at coldfusion.runtime.CfJspPage.invoke(CfJspPage.java:147)
at coldfusion.tagext.lang.IncludeTag.doStartTag(IncludeTag.java:357)
{snip}



Here, jrpp-96 is the JRun thread which is handling the template /opt/apache/htdocs/_cachelists.cfm. That template is currently executing a tag that is either on line 30 or ends on line 30. In this case the tag is CFSEARCH. If you find that this thread stack exists in subsequent full thread dumps that were taken at short intervals, where the same thread id, same template, and same operation is occurring for both thread stacks, then that should be sufficient proof that the cfm request has been executing for the duration of the interval between the two thread dump instances.

Typically the number of jrpp thread stacks having cfm templates in the stack in a single full thread dump will not exceed the number of Simultaneous Requests set in the CFAdmin, also known as the activeHandler limit for JRun people. The full thread dump is precise enough to do full accounting of all running threads, showing exactly what they are doing at that instant. <br/>

Its important to emphasize that observing the actions of threads in one thread dump loses the context of time. That's what ColdFusion was doing at that instant, but one thread dump by itself says nothing about how long a thread runs. Rather, its best to look for the same template running with the same thread id across two or more thread dumps taken in rapid succession. It requires some effort to extract and analyze the threads in various thread dumps, but looking at one thread dump alone is not useful for determining what's slowing down the application response times.

Once that is done and you have a list of templates involved and operations that were being executed, then you can focus your effort to debug just that area.

Additional thread stack examples:

1) Reading data back from an ODBC Socket connection

"jrpp-45" prio=5 tid=0x47373e78 nid=0x2f4 runnable [2bae000..2bafdbc]
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at java.io.DataInputStream.readFully(DataInputStream.java:266)
at macromedia.sequelink.net.TrEndPoint.recv(Unknown Source)
at macromedia.sequelink.net.Session.channelRecv(Unknown Source)
at macromedia.sequelink.net.Session.recv(Unknown Source)
at macromedia.sequelink.net.Session.recvIIOPHeader(Unknown Source)
at macromedia.sequelink.net.Session.recv(Unknown Source)
at macromedia.sequelink.net.Session.recv(Unknown Source)
at macromedia.sequelink.net.Session.reply(Unknown Source)
at macromedia.sequelink.ssp.Chain.send(Unknown Source)
at macromedia.sequelink.ctxt.stmt.StatementContext.execDirect(Unknown Source)
at macromedia.jdbc.sequelink.SequeLinkImplStatement.execute(Unknown Source)
at macromedia.jdbc.slbase.BaseStatement.commonExecute(Unknown Source)
at macromedia.jdbc.slbase.BaseStatement.executeInternal(Unknown Source)
at macromedia.jdbc.slbase.BaseStatement.execute(Unknown Source)

- locked {0x158ce0c0}(a macromedia.jdbc.sequelink.SequeLinkConnection)
at coldfusion.server.j2ee.sql.JRunStatement.execute(JRunStatement.java:212)
at coldfusion.sql.Executive.executeQuery(Executive.java:974)
at coldfusion.sql.Executive.executeQuery(Executive.java:886)
at coldfusion.sql.SqlImpl.execute(SqlImpl.java:229)
at coldfusion.tagext.sql.QueryTag.doEndTag(QueryTag.java:447)
at cf_additionalresources2ecfm1082472973.runPage(/opt/apache/htdocs/additionalresources.cfm:41)

{snip}

2) CFHTTP trying to connect to the remote resource

"jrpp-12" prio=5 tid=0x3c342580 nid=0x72c in Object.wait() [3e7ee000..3e7efdbc]
at java.lang.Object.wait(Native Method)
- waiting on {0x10933140} (a HTTPClient.HTTPConnection$EstablishConnection)
at java.lang.Thread.join(Thread.java:1009)
- locked {0x10933140} (a HTTPClient.HTTPConnection$EstablishConnection)
at HTTPClient.HTTPConnection.getSocket(HTTPConnection.java:3184)
at HTTPClient.HTTPConnection.sendRequest(HTTPConnection.java:2931)
- locked {0x109312b8}(a HTTPClient.HTTPConnection)
at HTTPClient.HTTPConnection.handleRequest(HTTPConnection.java:2767)
at HTTPClient.HTTPConnection.setupRequest(HTTPConnection.java:2559)
at HTTPClient.HTTPConnection.Get(HTTPConnection.java:916)
at coldfusion.tagext.net.HttpTag.createConnection(HttpTag.java:1526)
at coldfusion.tagext.net.HttpTag.connHelper(HttpTag.java:703)
at coldfusion.tagext.net.HttpTag.doEndTag(HttpTag.java:990)
at cfdsp_htm2ecfm1703620815.runPage(/opt/apache/htdocs/dsp_htm.cfm:45)

{snip}

Reference
Debugging stack traces in ColdFusion MX

 


Comments

A caveat on taking Thread Dumps... About 3 thread dumps taken in succession from the time of hanging should be sufficient to determine what the server was doing and what threads were running. Wait about 15 seconds between each, and this way they can be compared to see which threads are completed across the dumps and which threads are stuck or hanging.

Do not generate 20 or 30 thread dumps each time. And worse yet, I recommend not sending Macromedia Support a huge log having tons of thread dumps in it. An over abundance of thread dumps can slow down the troubleshooting process. :)




 

 

Calendar

 
Sun Mon Tue Wed Thu Fri Sat
      1 2 3 4
5 6 7 8 9 10 11
12 13 14 15 16 17 18
19 20 21 22 23 24 25
26 27 28 29 30    

Search This Site

 
This is an exact search only

About This Site

 
Adobe Alumni & Community Professional. Expert in ColdFusion, Flex, LCDS, Photoshop, Lightroom. Linux RHCE. Follow Me!. For my photography check out Boston Portrait Photographer.
More about me

Recent Entries

 
ColdFusion 9.01 Server Monito..

Recent Comments

 
Posted By Swagat:
Ben Forta, best-selling ColdFusion author is coming to India this August at India's largest Adobe Flash Platform Conference. Ben Forta will conduct a ...

Posted By Steve:
The updated presentation I gave at CF.Objective() 2010 is available here: [link] At the end of the preso I gave a brief, pre-recorded demo of wri ...

Posted By Brad Munz:
I've come across a OOM problem in HotSpot which looks alot like this: java.lang.OutOfMemoryError: requested 4096000 bytes for GrET in /BUILD_AREA/jdk6 ...

recently played

 

no song is playing

now playing, a plug-in for itunes

Categories

 
RSS Adobe (34)
RSS Bicycling (9)
RSS Blogging (39)
RSS Books (13)
RSS Breeze (13)
RSS CFMX Podcasts (10)
RSS ColdFusion (429)
RSS Computer Technology (51)
RSS Events (26)
RSS Flex (20)
RSS Gadgets (10)
RSS HiTech Industry (16)
RSS Java (25)
RSS Learning (57)
RSS Linux (70)
RSS Mac OS X (22)
RSS Macromedia (27)
RSS Meetup (35)
RSS New England (62)
RSS Odds & Ends (25)
RSS Outdoors (32)
RSS Personal (29)
RSS Photos (111)
RSS Photoshop (29)
RSS Podcasts (18)
RSS Rants (19)
RSS Restaurants (8)
RSS Science (34)
RSS Spain (16)
RSS Travel (42)
RSS Twitter (10)
RSS Video (20)
RSS Webcam (3)
RSS Writing (10)

Blogs I Read

 
Terrence Ryan
Ben Forta
Ray Camden
Kinky Solutions
Dan Vega
Gary Gilbert
Simeon Bateman
Red Hat Blogs
O'Reilly Digital Media
O'Reilly Radar
John Nack
The Strobist
Scott Kelby
Matt Kloskowski
Joe McNally
Digital Photography School
Engadget
Science Blog

RSS

 


Add to Google
Add to My Yahoo!

Aggregated By

 


Aggregated by ColdFusionBlogger.org

Credits and Stuff

 
BlogCFC - Free ColdFusion Powered Blog Software
CJM Group - ColdFusion Website Hosting


 
 
blog | photos | flickr | referers | webcam | stats | about | contact
 
Copyright © 2010 Steven Erat. All rights reserved.
This is a personal weblog. The opinions expressed here represent my own and not those of my employer