CF9 & SQL Server on Amazon Web Servers

59 views
Skip to first unread message

Stephen M

unread,
Jan 27, 2012, 6:21:44 AM1/27/12
to cfaussie
We recently moved one of our CF projects to Amazon Web Servers and
have started to get the "500 internal server error". This happens
regularly when we run a stored proc with does a lot of DB processing.
It often takes more than 300 seconds. I've set all the CF timeouts to
300 secs so why don't I at least get a CF exception that I can
handle?

This app previously ran on CF7 and it never produced the 500 error.
If it timed out then we got a CF timeout that I could handle with
code. But that was a local pair of VM servers. We also get this
problem on our UAT environment which is local (a pair of VM servers in
our building), so I shouldn't be blaming Amazon.

This is a fairly new CF install. I had originally left the JVM heap
and Garbage collection settings at default. Do they typically require
modifications when installing on 64 bit systems? I've just changed
the UAT server to JVM heap min & max of 1024MB but it hasn't helped.
I have set production at 512 and 768.

There's not a lot of CF processing going on. It just displays the
query result in a table. And we rarely have more than 3 or 4 users at
a time. But these errors are occuring when I know that I am the only
user. So there's one stored proc being called and CF is just sitting
there waiting. Often the error will occur, then I hit refresh and
bang, the query result displays perfectly. Hmmm, that final cfloop to
display the table is pretty big but it hasn't been a problem in the
past.

I have looked at all those JVM heap and GC settings in the past for an
app that does have lots of users and does a lot of CF processing and
it certainly helped but I really don't think that CF is the problem
here. There just aren't that many users and not a lot of
processing.

Anyway, we're running out of ideas, I'll listen to anything to do with
"500 internal server error"

regards,
Stephen

Paul Kukiel

unread,
Jan 27, 2012, 6:25:40 AM1/27/12
to cfau...@googlegroups.com
In CFADMIN did you enable "

Kym Kovan

unread,
Jan 27, 2012, 6:38:44 AM1/27/12
to cfau...@googlegroups.com
Hi Steven,

you don't mention what OS you are running but in general with 64bit
machines it is good to double the old 32 bit recommendations as a first
pass in server tuning.

For 2008 R2 the OS takes a gig or more with its trick memory free space
caching and its a good starting point with CF to set Max Perm at 512MB
and Max Heap at 2048MB so you need at least 3GB allocated to your VM.

As soon as the sites get busy you will have to up those numbers. If you
have CF Enterprise then turn _off_ the server memory monitoring as it
won't let you go above 2GB Heap and you will want to. It will force a GC
when you don't want one.

Our busy "ordinary" servers run with 5GB RAM, 3GB Max Heap and with the
OS free space caching they run with about 100MB of real free memory
space, and run fast...

With a stored proc running for 300 seconds I would also be looking at
how the DB server is configured, that is a lonnng proc.

HTH

Kym K

On 27/01/2012 10:21 PM, Stephen M wrote:

> We recently moved one of our CF projects to Amazon Web Servers and
> have started to get the "500 internal server error". This happens
> regularly when we run a stored proc with does a lot of DB processing.
> It often takes more than 300 seconds. I've set all the CF timeouts to
> 300 secs so why don't I at least get a CF exception that I can
> handle?
>
> This app previously ran on CF7 and it never produced the 500 error.
> If it timed out then we got a CF timeout that I could handle with
> code. But that was a local pair of VM servers. We also get this
> problem on our UAT environment which is local (a pair of VM servers in
> our building), so I shouldn't be blaming Amazon.
>
> This is a fairly new CF install. I had originally left the JVM heap
> and Garbage collection settings at default. Do they typically require
> modifications when installing on 64 bit systems? I've just changed

> the UAT server to JVM heap min& max of 1024MB but it hasn't helped.


> I have set production at 512 and 768.
>
> There's not a lot of CF processing going on. It just displays the
> query result in a table. And we rarely have more than 3 or 4 users at
> a time. But these errors are occuring when I know that I am the only
> user. So there's one stored proc being called and CF is just sitting
> there waiting. Often the error will occur, then I hit refresh and
> bang, the query result displays perfectly. Hmmm, that final cfloop to
> display the table is pretty big but it hasn't been a problem in the
> past.
>
> I have looked at all those JVM heap and GC settings in the past for an
> app that does have lots of users and does a lot of CF processing and
> it certainly helped but I really don't think that CF is the problem
> here. There just aren't that many users and not a lot of
> processing.
>
> Anyway, we're running out of ideas, I'll listen to anything to do with
> "500 internal server error"
>
> regards,
> Stephen
>


--

Yours,

Kym Kovan
mbcomms.net.au


Stephen M

unread,
Jan 29, 2012, 10:14:15 PM1/29/12
to cfaussie


On Jan 27, 10:38 pm, Kym Kovan <dev-li...@mbcomms.net.au> wrote:
> Hi Steven,
>
> you don't mention what OS you are running but in general with 64bit
> machines it is good to double the old 32 bit recommendations as a first
> pass in server tuning.
>
> For 2008 R2 the OS takes a gig or more with its trick memory free space
> caching and its a good starting point with CF to set Max Perm at 512MB
> and Max Heap at 2048MB so you need at least 3GB allocated to your VM.

It is 2008R2 with 4 GB

Andrew Scott

unread,
Jan 29, 2012, 10:25:06 PM1/29/12
to cfau...@googlegroups.com
I agree with Paul, the first thing you need to do is switch this on so that you can see the actual ColdFusion error.

Other than this, you can always look into the logs and see what is in the Application and Exception logs.

It maybe a simple case of a misconfiguration, but you won't know till you follow these first few basic steps.

-- 
Regards,
Andrew Scott
WebSite: http://www.andyscott.id.au/



--
You received this message because you are subscribed to the Google Groups "cfaussie" group.
To post to this group, send email to cfau...@googlegroups.com.
To unsubscribe from this group, send email to cfaussie+u...@googlegroups.com.
For more options, visit this group at http://groups.google.com/group/cfaussie?hl=en.



Stephen M

unread,
Mar 29, 2012, 12:56:03 AM3/29/12
to cfau...@googlegroups.com


On Friday, January 27, 2012 10:21:44 PM UTC+11, Stephen M wrote:

I've replicated this problem on my local workstation using a network db server, so its no longer about Amazon.

I can get the timeout error  on the stored proc as below.  But the problem is I am getting this timeout at the 120 sec mark when the CF Request timeout, the datasource query tiomeout and the IIS connection timeouts are all set to 300 secs  or more. 

A stupid question - does the query timeout in the datascource setting apply to stored procs as well?  I assume that it would.

I also notice that on my dev server I have some extra settings under Request Tuning that I don't have on the win 2008 servers which are only CF9 standard.  The extra settings are for Request Queue Timeout settings.  I have increased that to the same as the regular request timeout because it says
"If a request has waited in the queue for this long, timeout the request. This value should be at least as long as the Request Timeout setting (currently 300 seconds)." 

The next setting is for a Request Queue Timeout page
"Specify a relative path from the web root to an HTML page to send to clients when a template request times out before running, for example /CFIDE/timeout.html. The page you specify cannot contain CFML. If you do not specify a page, clients receive a 500 Request Timeout error when their request does not run. "

This immediately attracts my attention because it is the first time I have seen the mention of the 500 Request Timeout error which is what I get if I do not set Enable HTTP status codes.

Changing the Request Queue Timeout hasn't made any difference and I don't have that setting on the server anyway but I'm curious as to what effect it actually has.  The real timeout (as timed by me with my watch) is 120 secs, so I was wondering if the request waiting after the stored proc in the queue is the one triggering the timeout error.  As in, the stored proc finally comes back after 2 minutes, then CF looks at the next request in the queue and says that CFLOOP has been there too long so its timed out.  But in that case the Request Queue timeout setting should fix it but it hasn't.  I'll try a reboot and run it again.


=================
15:33:20.020 - Application Exception - in C:\WorkingDirectory\RTE\wwwroot\trunk\RTEreports\com\roymorgan\RTEreports\services\ReportDAO.cfc : line 83
	    The request has exceeded the allowable time limit Tag: CFSTOREDPROC

charlie arehart

unread,
Mar 29, 2012, 7:12:29 PM3/29/12
to cfau...@googlegroups.com

Stephen, I’ll share some thoughts. This is hard to explain in email because things are often not at all what they may seem on the surface. I help people solve these kind of problems all the time (via my consulting, over the web, and I’d be happy to offer that to you, satisfaction guaranteed or you don’t pay for the time, which may take less than an hour). But in case you are averse to that, or want to try what you can for free, and in that I may help you (or others reading this), here you go.

First, yes, the DSN timeout could affect the CFSTOREDPROC, but which timeout do you mean? There are ones that apply to the connection pool, not to any CF processing itself.

Second, are you saying there is no TIMEOUT on the CFSTOREDPROC in question?

Third, and perhaps most significant, I would argue that the timeout may be due NOT to that tag, but to processing that preceded it.

Before I elaborate on that, let me clarify that whatever the timeout time is, it’s definitely being set in CF (not in IIS or the database or anything else), since the error is definitely CF’s error saying that the request has exceeded the timeout.

But as for where it may be, it’s reasonable for you to assume that the timeout is happening on the CFSTOREDPROC that the error points to. But it may not be. I’ve spoken and written about this before. I’ll summarize here but if you want more details, see:

CF911: Lies, Damned Lies, and CF Request Timeouts...What You May Not Realize
http://www.carehart.org/blog/client/index.cfm/2010/10/15/Lies_damned_lies_and_CF_timeouts

In brief, it could be that something prior to that CFSTOREDPROC is what really held up the request. CF will often let some long-running tag go well beyond any timeout (set on the tag, or in the CF Admin, or in CFSETTING, etc.) because CF can’t interrupt the tag while it’s running. This is most often with tags that talk to something outside of CF, like CFQUERY, CFSTOREDPROC, CFHTTO, etc. See the blog entry for more.

The thing is, CF will indeed check the time for the request, but on a subsequent tag after that one that held things up (and it’s not all tags where it checks the time. It does on ones like CFQUERY, CFSTOREDPROC, CFOUTPUT, CFLOOP, and so on, but not on CFSET, CFIF, and so on.)  So you would want to look at what precedes that CFSTOREDPROC in the flow of control. It could be another CFQUERY or CFSTOREDPROC, but it could also be a CFHTTP, or a CFINVOKE, or perhaps even a CFLOCK, which got held up.

And note that the timeout (whatever it is, which is causing this check on this CFSTOREDPROC to say “we’ve taken to long”) could really be any value at all, less than the 120 seconds you are clocking. For instance, it may be that there’s a CFSETTING REQUESTTIMEOUT somewhere in the request (in that file, in an included file, or in the application.cfc/cfm) which sets the timeout to say, 60 seconds. Again, some tags simply will not stop when that time is hit, but they will finish (in your case, in less than 120 seconds), and then processing would fall through and hit this tag that DOES check the time (your CFSTOREDPROC), where it errors and says the request has taken too long.

I realize that this can be mind-numbing to consider—and even frustrating when we are all led to believe that the error is what it says. That’s why I blogged what I did (and have presented on it, too, including in the cfobjective lightning round of talks last year). It’s really an important problem that many don’t understand and are misled by.

Finally, note that you don’t even need to guess at why the request is taking long. If you have CF Enterprise (and its Server Monitor) or CF Std or Enterprise and FusionReactor or SeeFusion, you can use those tools to get a “stack trace” while the request is running (or even by email if you setup an alert), which will tell you exactly what line of code is running in a long-running request at a point in time. For more on that, see my blog entry and talks at:

CF911: Easier thread dumps and stack traces in CF: how and why
http://www.carehart.org/blog/client/index.cfm/2009/6/24/easier_thread_dumps

If any of that has helped, great. If you may think it’s on the right track but would you be interested some help, it shouldn’t take more than 15 minutes for us to find and solve this, over the web. If you may be interested, check out www.carehart.org/consulting/. I am in the US, at GMT-4 but I’m always happy to work later or early to help folks in timezones that are far from me.

 

/charlie

 

--

You received this message because you are subscribed to the Google Groups "cfaussie" group.

To view this discussion on the web visit https://groups.google.com/d/msg/cfaussie/-/cJmIKCjsQcsJ.

Stephen M

unread,
Apr 1, 2012, 8:50:19 AM4/1/12
to cfau...@googlegroups.com


On Friday, March 30, 2012 10:12:29 AM UTC+11, charlie arehart wrote:

Stephen, I’ll share some thoughts. This is hard to explain in email because things are often not at all what they may seem on the surface. I help people solve these kind of problems all the time (via my consulting, over the web, and I’d be happy to offer that to you, satisfaction guaranteed or you don’t pay for the time, which may take less than an hour). But in case you are averse to that, or want to try what you can for free, and in that I may help you (or others reading this), here you go.

First, yes, the DSN timeout could affect the CFSTOREDPROC, but which timeout do you mean? There are ones that apply to the connection pool, not to any CF processing itself.

Second, are you saying there is no TIMEOUT on the CFSTOREDPROC in question?

Charlie,  First I am sure it is the stored proc because it is a report that takes dates to and from and parameters.  If I asked for March to December, it takes about 115 seconds and works, if I ask for Feb to Dec it takes 120 seconds and fails.  No, I do not have a timeout on the stored proc itself. Should I?  I assume its using the query timeout set in the datasource in the Admin.

The pre-processing before the stored proc call for both those cases would be identical.  Its just getting all the params together, formatting them and passing them to the CFC that handles database calls.


Third, and perhaps most significant, I would argue that the timeout may be due NOT to that tag, but to processing that preceded it.

Before I elaborate on that, let me clarify that whatever the timeout time is, it’s definitely being set in CF (not in IIS or the database or anything else), since the error is definitely CF’s error saying that the request has exceeded the timeout.

But as for where it may be, it’s reasonable for you to assume that the timeout is happening on the CFSTOREDPROC that the error points to. But it may not be. I’ve spoken and written about this before. I’ll summarize here but if you want more details, see:

CF911: Lies, Damned Lies, and CF Request Timeouts...What You May Not Realize
http://www.carehart.org/blog/client/index.cfm/2010/10/15/Lies_damned_lies_and_CF_timeouts

I have read that blog entry and found it very informative thank-you.
 

In brief, it could be that something prior to that CFSTOREDPROC is what really held up the request. CF will often let some long-running tag go well beyond any timeout (set on the tag, or in the CF Admin, or in CFSETTING, etc.) because CF can’t interrupt the tag while it’s running. This is most often with tags that talk to something outside of CF, like CFQUERY, CFSTOREDPROC, CFHTTO, etc. See the blog entry for more.

The thing is, CF will indeed check the time for the request, but on a subsequent tag after that one that held things up (and it’s not all tags where it checks the time. It does on ones like CFQUERY, CFSTOREDPROC, CFOUTPUT, CFLOOP, and so on, but not on CFSET, CFIF, and so on.)  So you would want to look at what precedes that CFSTOREDPROC in the flow of control. It could be another CFQUERY or CFSTOREDPROC, but it could also be a CFHTTP, or a CFINVOKE, or perhaps even a CFLOCK, which got held up.

And note that the timeout (whatever it is, which is causing this check on this CFSTOREDPROC to say “we’ve taken to long”) could really be any value at all, less than the 120 seconds you are clocking. For instance, it may be that there’s a CFSETTING REQUESTTIMEOUT somewhere in the request (in that file, in an included file, or in the application.cfc/cfm) which sets the timeout to say, 60 seconds. Again, some tags simply will not stop when that time is hit, but they will finish (in your case, in less than 120 seconds), and then processing would fall through and hit this tag that DOES check the time (your CFSTOREDPROC), where it errors and says the request has taken too long.

I realize that this can be mind-numbing to consider—and even frustrating when we are all led to believe that the error is what it says. That’s why I blogged what I did (and have presented on it, too, including in the cfobjective lightning round of talks last year). It’s really an important problem that many don’t understand and are misled by.

Finally, note that you don’t even need to guess at why the request is taking long. If you have CF Enterprise (and its Server Monitor) or CF Std or Enterprise and FusionReactor or SeeFusion, you can use those tools to get a “stack trace” while the request is running (or even by email if you setup an alert), which will tell you exactly what line of code is running in a long-running request at a point in time. For more on that, see my blog entry and talks at:

CF911: Easier thread dumps and stack traces in CF: how and why
http://www.carehart.org/blog/client/index.cfm/2009/6/24/easier_thread_dumps

If any of that has helped, great. If you may think it’s on the right track but would you be interested some help, it shouldn’t take more than 15 minutes for us to find and solve this, over the web. If you may be interested, check out www.carehart.org/consulting/. I am in the US, at GMT-4 but I’m always happy to work later or early to help folks in timezones that are far from me.

 /charlie

Thanks for your response, I have actually successfully run the report by bypassing CF and using SSMS and then just exported the data to XL, so the customer has their report and the pressure is off for a bit.  But I still need to sort this out.  I'll try some more of your suggestions.

 

From: cfau...@googlegroups.com [mailto:cfaussie@googlegroups.com] On Behalf Of Stephen M
Sent: Thursday, March 29, 2012 12:56 AM
To: cfau...@googlegroups.com
Subject: [cfaussie] Re: CF9 & SQL Server on Amazon Web Servers

 



On Friday, January 27, 2012 10:21:44 PM UTC+11, Stephen M wrote:


I've replicated this problem on my local workstation using a network db server, so its no longer about Amazon.

I can get the timeout error  on the stored proc as below.  But the problem is I am getting this timeout at the 120 sec mark when the CF Request timeout, the datasource query tiomeout and the IIS connection timeouts are all set to 300 secs  or more. 

A stupid question - does the query timeout in the datascource setting apply to stored procs as well?  I assume that it would.

I also notice that on my dev server I have some extra settings under Request Tuning that I don't have on the win 2008 servers which are only CF9 standard.  The extra settings are for Request Queue Timeout settings.  I have increased that to the same as the regular request timeout because it says
"If a request has waited in the queue for this long, timeout the request. This value should be at least as long as the Request Timeout setting (currently 300 seconds)." 

The next setting is for a Request Queue Timeout page
"Specify a relative path from the web root to an HTML page to send to clients when a template request times out before running, for example /CFIDE/timeout.html. The page you specify cannot contain CFML. If you do not specify a page, clients receive a 500 Request Timeout error when their request does not run. "

This immediately attracts my attention because it is the first time I have seen the mention of the 500 Request Timeout error which is what I get if I do not set Enable HTTP status codes.

Changing the Request Queue Timeout hasn't made any difference and I don't have that setting on the server anyway but I'm curious as to what effect it actually has.  The real timeout (as timed by me with my watch) is 120 secs, so I was wondering if the request waiting after the stored proc in the queue is the one triggering the timeout error.  As in, the stored proc finally comes back after 2 minutes, then CF looks at the next request in the queue and says that CFLOOP has been there too long so its timed out.  But in that case the Request Queue timeout setting should fix it but it hasn't.  I'll try a reboot and run it again.


=================

15:33:20.020 - Application Exception - in C:\WorkingDirectory\RTE\wwwroot\trunk\RTEreports\com\roymorgan\RTEreports\services\ReportDAO.cfc : line 83

           The request has exceeded the allowable time limit Tag: CFSTOREDPROC

 

--
You received this message because you are subscribed to the Google Groups "cfaussie" group.
To view this discussion on the web visit https://groups.google.com/d/msg/cfaussie/-/cJmIKCjsQcsJ.
To post to this group, send email to cfau...@googlegroups.com.

To unsubscribe from this group, send email to cfaussie+unsubscribe@googlegroups.com.

charlie arehart

unread,
Apr 2, 2012, 12:15:09 AM4/2/12
to cfau...@googlegroups.com

OK. Thanks for the update, Stephen, and will look forward to hearing if you find out any more.

As for your first question, it’s not that you “should” have a timeout on the CFSTOREDPROC (or a CFQUERY, in a similar instance). I was just wondering if you did. Since you say that the error only happens when you know that THAT tag is what’s running longer, then it would seem that we need to know what’s making it generate the timeout error if it exceeds that 120 secs.

Now, I would have said you could certainly try adding a TIMEOUT (of longer duration) to the CFSTOREDPROC (or a CFQUERY, if you had one) to see if that helps, but I just realized: the ability to do a TIMEOUT on CFSTOREDPROC is in fact new only in CF10. Doh! :-) I had it in mind because I’d written about it in my blog entry:

Charlie Arehart's Ultimate List of 200+ New #ColdFusion 10 Features
http://www.carehart.org/blog/client/index.cfm/2012/3/7/charlie_areharts_ultimate_cf10_new_features_list

Just pointing that out if any readers here had not seen it.

But before we give up hope to see if a TIMEOUT would help, note that unless your stored proc call has multiple resultsets, you could call it in fact using CFQUERY (the old way we used to call SPs). The syntax may very per DB, but you can often say exec sp, or call sp or {sp}. That’s just if you may want to try it, to see if then adding a TIMEOUT may make a difference.

As for the timeout in the DSN, that depends on some variations, too. Do you mean the new “query timeout” option in the Advanced Settings page for a DSN, which is new in CF 9? I’ve found that it sometimes does and sometimes does not work. For more on the feature, and my observations, see my blog entry:

New for CF9 (and 9.0.1): a query timeout that really works, with a caveat
http://www.carehart.org/blog/client/index.cfm/2010/7/14/hidden_gem_in_cf9_admin_querytimeout


Hope that helps.

/charlie

 

From: cfau...@googlegroups.com [mailto:cfau...@googlegroups.com] On Behalf Of Stephen M
Sent: Sunday, April 01, 2012 8:50 AM
To: cfau...@googlegroups.com
Subject: Re: [cfaussie] Re: CF9 & SQL Server on Amazon Web Servers


On Friday, March 30, 2012 10:12:29 AM UTC+11, charlie arehart wrote:

Stephen, I’ll share some thoughts. This is hard to explain in email because things are often not at all what they may seem on the surface. I help people solve these kind of problems all the time (via my consulting, over the web, and I’d be happy to offer that to you, satisfaction guaranteed or you don’t pay for the time, which may take less than an hour). But in case you are averse to that, or want to try what you can for free, and in that I may help you (or others reading this), here you go.

First, yes, the DSN timeout could affect the CFSTOREDPROC, but which timeout do you mean? There are ones that apply to the connection pool, not to any CF processing itself.

Second, are you saying there is no TIMEOUT on the CFSTOREDPROC in question?

Charlie,  First I am sure it is the stored proc because it is a report that takes dates to and from and parameters.  If I asked for March to December, it takes about 115 seconds and works, if I ask for Feb to Dec it takes 120 seconds and fails.  No, I do not have a timeout on the stored proc itself. Should I?  I assume its using the query timeout set in the datasource in the Admin.

The pre-processing before the stored proc call for both those cases would be identical.  Its just getting all the params together, formatting them and passing them to the CFC that handles database calls.



<snip>

In brief, it could be that something prior to that CFSTOREDPROC is what really held up the request. CF will often let some long-running tag go well beyond any timeout (set on the tag, or in the <snip>
/charlie

Reply all
Reply to author
Forward
0 new messages