Odd Timeout Behavior

Question

Odd Timeout Behavior

Chris Becker

SSCrazy

Points: 2645
More actions
September 29, 2011 at 11:21 am

#245618

SQL Server 2008R2 Standard 64-bit, Service Pack 1. On Win2008 Std Server 64bit Service Pack 1
Stored procedure call from .Net client is timing out. A bit of a complex procedure with derived tables, summations, case statements etc.
Run from SSMS it takes < 3 seconds. Even after a dbcc freeproccache and dropcleanbuffers. Run from client with timeout set to 0, will run for 22 minutes!!
I cleared the procedure cache thinking client may be stuck w/ bad plan. Did not resolve.
When client calls proc the physicalio and memusage columns of master..sysprocesses = 0 for this spid. Only cpu number is changing and server cpu goes to 50% for duration of execution.
Any ideas? This is very odd behavior.
TIA,
Chris
Chris Becker bcsdata.net

Viewing 5 posts - 1 through 4 (of 4 total)

You must be logged in to reply to this topic. Login to reply

bkubicek SSChampion Points: 10948 More actions · Answer 1

Chris Becker (9/29/2011)
SQL Server 2008R2 Standard 64-bit, Service Pack 1. On Win2008 Std Server 64bit Service Pack 1
Stored procedure call from .Net client is timing out. A bit of a complex procedure with derived tables, summations, case statements etc.
Run from SSMS it takes < 3 seconds. Even after a dbcc freeproccache and dropcleanbuffers. Run from client with timeout set to 0, will run for 22 minutes!!
I cleared the procedure cache thinking client may be stuck w/ bad plan. Did not resolve.
When client calls proc the physicalio and memusage columns of master..sysprocesses = 0 for this spid. Only cpu number is changing and server cpu goes to 50% for duration of execution.
Any ideas? This is very odd behavior.
TIA,
Chris

In general when I have had trouble with performance with stored procs or functions often the issue is in-memory or table variables. I have found that once table variables get records counts > 1000 records there are often major performance issues. So if you are using table variables it might be worth a try to remove them and use a different structure to see if the performance improves. If you aren't using any table variables then I would suspect indexes.

Evil Kraig F SSC Guru Points: 100851 More actions · Answer 2

What's the rowcount and rowsize of the returned data? Have you tested the network throttles?

This may be a data return issue more then it's a coding issue. You should also have a dev review the code and perhaps build off a test that does nothing more then take data from the proc and dump to screen.

There's a lot of 'what if' factors that can come into play after you're out of the engine. These things can help you determine where to start the troubleshooting.

The other thing to test is to do the process from the front end while running a profiler against the database, and make sure you're testing with the same parameters. Preferably you'll be working on a QA system that you can isolate the calls. From there, determine that this proc is the *only* thing this does in the front end. You might be tripping up on an interative re-call to the database on a per row from the starting proc, etc etc...

When there's a lot of moving parts, try to nail some of them down. 🙂

- Craig Farrell

Never stop learning, even if it hurts. Ego bruises are practically mandatory as you learn unless you've never risked enough to make a mistake.

For better assistance in answering your questions[/url] | Forum Netiquette
For index/tuning help, follow these directions.[/url] |Tally Tables[/url]
Twitter: @AnyWayDBA

Chris Becker SSCrazy Points: 2645 More actions · Answer 3

Thanks for your time

@SSChasing Mays: no table vars (I agree and hate those things; ). Indexes? Hmmm, I could start dropping them one by one, would sure like to see query plan client is using. SSMS query plan cost is low and executes in < 3 secs. But really, no disk or mem usage? This is just churning cpu?? If a bad index I would expect to see spid hitting disk or hogging memory cache.

@Evil:

Return rowcount is < 200 rows - this does not RPC:Complete then take 22 minutes to return to client, the time between rpc starting and completed event is 22 minutes. All db side.

I am seeing this in profiler.

I am seeing this in sysprocesses where status like '%run%'

Exact same call compared from client vs ssms, call picked up from trace.

Chris Becker bcsdata.net

Evil Kraig F SSC Guru Points: 100851 More actions · Answer 4

Chris Becker (9/29/2011)
@Evil:
Return rowcount is < 200 rows - this does not RPC:Complete then take 22 minutes to return to client, the time between rpc starting and completed event is 22 minutes. All db side.
I am seeing this in profiler.

:crazy:

Alright, next trick. Pull the Showplan XML during the trace when you run this proc, and then we'll compare it to the Actual Execution plan you get when it runs in 3 seconds. If we can see the proc code that will help as well, as well as the underlying DDL. My guess is some kind of parameter sniffing is altering the plan, but we'll see. In the meanwhile, also, what's your maintenance schedule for statistics?

For more instructions on pulling the Showplan XML:

1) Activate this:

2) In the profiler, you should see an entry that looks like an execution plan in the 'text' window. Rt-click that line, and Extract Event Data... to a .sqlplan file.

3) Attach the profiler version and the actual from SSMS here, and we'll take a look at 'em.

- Craig Farrell

Never stop learning, even if it hurts. Ego bruises are practically mandatory as you learn unless you've never risked enough to make a mistake.

For better assistance in answering your questions[/url] | Forum Netiquette
For index/tuning help, follow these directions.[/url] |Tally Tables[/url]
Twitter: @AnyWayDBA