Hi all,
I'm posting here in the hope that this list can shed some light on an issue I
keep encountering with CF 9.0.1 running on Windows Server 2008 R2.
My CF instance sometimes stops responding to and/or properly process HTTP
requests. When this happens I see the following symptoms:
- my monitoring software reports HTTP failure, 'Unable to contact web server at
website.com/index.cfm'
- Pingdom reports website as down
- the CF service is running seemingly normally
- another non-CF site on the same server works fine (more or less eliminating
IIS as a cause)
- a server restart will fix the issue (temporarily until the next 'event')
- A CF service restart often hangs so I end up rebooting the server
- (potentially unrelated: the CF service does not start up after server reboot
even though it is set to automatic, a manual start of the service works)
Last night at 00:20am UTC another outage occurred. This time I could tie it to
an external event. At precisely that time, Amazon Web Services performed a
planned update to their RDS service (MySQL basically) which CF connects to as a
datasource.
Note that I run RDS in multi-AZ mode which means that when the database shuts
down for any reason it fails over to another instance with identical
credentials. However it appears CF was never able to reconnect, not even when
the original DB came back a few mins later.
Moreover not only did the DB connection fail, but CF also stopped processing
HTTP requests - no pages (even those without cfquery tags) would load (well
they may have done, but see below for how long they suddenly take to process).
I noticed in my CF logs:
server.log (hundreds of these entries right after the DB connection failed):
"Warning","jrpp-25682","11/18/12","00:28:08",,"Thread: jrpp-25682, processing
template: C:\inetpub\wwwroot\scribblar.com\...\index.cfm, completed in 314
seconds, exceeding the 30 second warning limit"
application.log
"Error","jrpp-25680","11/18/12","00:19:54","scribblar","Error Executing
Database Query.Server shutdown in progress The specific sequence of files
included or processed is: C:\inetpub\wwwroot\....page.cfm"
"Error","jrpp-25678","11/18/12","00:20:05","scribblar","Error Executing
Database Query.Communications link failure The last packet successfully
received from the server was 53,418 milliseconds ago. The last packet sent
successfully to the server was 0 milliseconds ago. The specific sequence of
files included or processed is: C:\inetpub\wwwroot\...page.cfm"
"Error","jrpp-25682","11/18/12","00:21:29","scribblar","Error Executing
Database Query.Could not create connection to database server. Attempted
reconnect 3 times. Giving up.
[these logs then repeat a lot of times]
(notice the pages in the server.lo0g take forever to load - to a user they
don't work at all as noone waits 5 mins...)
Every single page requests after the original 'Error Executing Database' takes
several minutes according to the logs.
exception.log:
(loads of these, I picked one as a sample)
"Error","jrpp-25779","11/18/12","07:57:02","scribblar","Error Executing
Database Query.Could not create connection to database server. Attempted
reconnect 3 times. Giving up. The specific sequence of files included or
processed is: C:\inetpub\wwwroot\...\index.cfm, line: 8 "
coldfusion.tagext.sql.QueryTag$DatabaseQueryException: Error Executing Database
Query.
at coldfusion.tagext.sql.QueryTag.doEndTag(QueryTag.java:641)
at cfindex2ecfm507991868.runPage(C:\inetpub\wwwroot\...\index.cfm:8)
at coldfusion.runtime.CfJspPage.invoke(CfJspPage.java:231)
at coldfusion.tagext.lang.IncludeTag.doStartTag(IncludeTag.java:416)
at coldfusion.filter.CfincludeFilter.invoke(CfincludeFilter.java:65)
at
coldfusion.filter.ApplicationFilter.invoke(ApplicationFilter.java:360)
at
coldfusion.filter.RequestMonitorFilter.invoke(RequestMonitorFilter.java:48)
at coldfusion.filter.MonitoringFilter.invoke(MonitoringFilter.java:40)
at coldfusion.filter.PathFilter.invoke(PathFilter.java:94)
at coldfusion.filter.ExceptionFilter.invoke(ExceptionFilter.java:70)
at
coldfusion.filter.ClientScopePersistenceFilter.invoke(ClientScopePersistenceFilter.java:28)
at coldfusion.filter.BrowserFilter.invoke(BrowserFilter.java:38)
at coldfusion.filter.NoCacheFilter.invoke(NoCacheFilter.java:46)
at coldfusion.filter.GlobalsFilter.invoke(GlobalsFilter.java:38)
at coldfusion.filter.DatasourceFilter.invoke(DatasourceFilter.java:22)
at coldfusion.filter.CachingFilter.invoke(CachingFilter.java:62)
at coldfusion.CfmServlet.service(CfmServlet.java:200)
at
coldfusion.bootstrap.BootstrapServlet.service(BootstrapServlet.java:89)
at jrun.servlet.FilterChain.doFilter(FilterChain.java:86)
at
coldfusion.monitor.event.MonitoringServletFilter.doFilter(MonitoringServletFilter.java:42)
at
coldfusion.bootstrap.BootstrapFilter.doFilter(BootstrapFilter.java:46)
at jrun.servlet.FilterChain.doFilter(FilterChain.java:94)
at jrun.servlet.FilterChain.service(FilterChain.java:101)
at jrun.servlet.ServletInvoker.invoke(ServletInvoker.java:106)
at jrun.servlet.JRunInvokerChain.invokeNext(JRunInvokerChain.java:42)
at
jrun.servlet.JRunRequestDispatcher.invoke(JRunRequestDispatcher.java:286)
at
jrun.servlet.ServletEngineService.dispatch(ServletEngineService.java:543)
at
jrun.servlet.jrpp.JRunProxyService.invokeRunnable(JRunProxyService.java:203)
at
jrunx.scheduler.ThreadPool$DownstreamMetrics.invokeRunnable(ThreadPool.java:320)
at
jrunx.scheduler.ThreadPool$ThreadThrottle.invokeRunnable(ThreadPool.java:428)
at
jrunx.scheduler.ThreadPool$UpstreamMetrics.invokeRunnable(ThreadPool.java:266)
at jrunx.scheduler.WorkerThread.run(WorkerThread.java:66)
Caused by:
com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Could not
create connection to database server. Attempted reconnect 3 times. Giving up.
at sun.reflect.GeneratedConstructorAccessor1575.newInstance(Unknown
Source)
at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:406)
at com.mysql.jdbc.Util.getInstance(Util.java:381)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1012)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:986)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:981)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:926)
at com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2409)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2675)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2616)
at com.mysql.jdbc.StatementImpl.execute(StatementImpl.java:782)
at com.mysql.jdbc.StatementImpl.execute(StatementImpl.java:879)
at
coldfusion.server.j2ee.sql.JRunStatement.execute(JRunStatement.java:348)
at coldfusion.sql.Executive.executeQuery(Executive.java:1364)
at coldfusion.sql.Executive.executeQuery(Executive.java:1127)
at coldfusion.sql.Executive.executeQuery(Executive.java:1058)
at coldfusion.sql.SqlImpl.execute(SqlImpl.java:341)
at coldfusion.tagext.sql.QueryTag.executeQuery(QueryTag.java:915)
at coldfusion.tagext.sql.QueryTag.setupCachedQuery(QueryTag.java:854)
at coldfusion.tagext.sql.QueryTag.doEndTag(QueryTag.java:586)
... 31 more
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException:
Communications link failure
I read this blog post by Charlie Arehart and wondered if my issue is related:
http://www.carehart.org/blog/client/index.cfm/2010/10/15/Lies_damned_lies_and_CF_timeouts
But I still do not understand how I could prevent the issues I am seeing.
Also I'm not sure if previous issues with HTTP requests 'hanging' were related
to database connectivity issues - I'll try and establish that. What I do know
is that I've seen these symptoms many times before...
Any tips would be much appreciated. It's crucial that my site is up and running
as it provides an API for customers... :-/
Cheers
Stefan
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~|
Order the Adobe Coldfusion Anthology now!
http://www.amazon.com/Adobe-Coldfusion-Anthology/dp/1430272155/?tag=houseoffusion
Archive:
http://www.houseoffusion.com/groups/cf-talk/message.cfm/messageid:353229
Subscription: http://www.houseoffusion.com/groups/cf-talk/subscribe.cfm
Unsubscribe: http://www.houseoffusion.com/groups/cf-talk/unsubscribe.cfm
