Recompile problem - SQL Server Forums

Please start any new threads on our new site at https://forums.sqlteam.com. We've got lots of great SQL Server experts to answer whatever question you can come up with.

All Forums

SQL Server 2000 Forums

SQL Server Development (2000)

Recompile problem

Author

Topic

Nedra
Starting Member

21 Posts

Posted - 2005-03-11 : 11:25:14

I have a procedure that takes 50+ seconds to run and does 50000 reads. When I copy and paste that same code into a query analyzer window, it runs in 3 seconds and does 1200 reads. I'm using the same parameters for both tests, and I am running dbcc dropcleanbuffers and dbcc freeproccache before each test. Incidentally, both tests produce the same exact query plan.

The table has over 1 million rows, and the query plan shown as doing index seeks as expected.

Does anyone know what might be causing this? More importantly, does anyone know how to fix this? :)

TG
Master Smack Fu Yak Hacker

6065 Posts

Posted - 2005-03-11 : 12:36:35

Great problem! When you execute the procedure, are you executing it from a QA window or accross some Sql Provider?

edit:
Although, I can't see why that would make a diff since its a proc.

Be One with the Optimizer
TG

Nedra
Starting Member

21 Posts

Posted - 2005-03-11 : 12:38:05

In both cases its from query analyzer. I had captured the call in profiler, and the copied and pasted the call text to run the proc. Likewise, just copy and pasted the proc text (minus the create part of course), and ran that via query analyzer.

TG
Master Smack Fu Yak Hacker

6065 Posts

Posted - 2005-03-11 : 12:40:16

when you script out the procedure does it include any unusual SET options?

Be One with the Optimizer
TG

Nedra
Starting Member

21 Posts

Posted - 2005-03-11 : 14:00:02

It sets ansi nulls and quoted identifiers

SET QUOTED_IDENTIFIER ON
GO
SET ANSI_NULLS ON
GO

TG
Master Smack Fu Yak Hacker

6065 Posts

Posted - 2005-03-11 : 15:23:03

Sorry, I'm at a loss. If the Proc and the Statement are using the exact same execution plan with the same parameters, I don't understand how your reads and execution time can be so different.

Be One with the Optimizer
TG

TG
Master Smack Fu Yak Hacker

6065 Posts

Posted - 2005-03-11 : 15:30:23

One more question: When you execute the statement (not the sp) you are still using parameters right? You aren't replacing the parameter values with constants are you?

ie:
--where myColumn = @myColumn
where myColumn = 'Nedra'

edit: then again with the same execution plan that wouldn't matter. Uhh! I have no idea...sorry

Be One with the Optimizer
TG

TG
Master Smack Fu Yak Hacker

6065 Posts

Posted - 2005-03-11 : 16:04:34

Ok, I don't think its possible for Sql Server to run the same query with the same parameters with the same execution plan on the same tables with the same data and have 1 instance make 50000 reads and another instance make 1200 reads. How did you confirm what the plans were and that they were identical? Is the data in the tables changing dramatically either by this SP or by other processes? And you're certain both instances used the same parameters? Can you post the SP?

I notice no one else is chiming in here...come on guys, help me out.

Be One with the Optimizer
TG

Nedra
Starting Member

21 Posts

Posted - 2005-03-11 : 16:51:14

Here's the proc call I'm running via QA:

dbcc freeproccache
dbcc dropcleanbuffers
go
declare @AcctBal money
, @FullAcctBal money

exec sps_GLTCustBal
@CustId = 'EC75C6E0-D6F7-4AD3-883F-69E675F8BAFE'
, @LoggedInUser = '!!3'
, @AsOfDate = null
, @AcctBal = @AcctBal output
, @FullAcctBal = @FullAcctBal output

select @AcctBal, @FullAcctBal

It calls this procedure:

create proc sps_GLTCustBal
@CustId uniqueidentifier
, @LoggedInUser char(3)
, @AsOfDate datetime = null
, @AcctBal money = $0.00 output
, @FullAcctBal money = $0.00 output
, @RowCount int = 0 output
--with encryption--
as
set nocount on
declare
@ErrorNo int
, @Const_ACCT_ARC smallint
, @Const_ACCT_ARB smallint
, @Const_ACCT_GLTTYPE_DETAIL smallint
, @Const_ACCT_GEN_YES char(1)
, @Const_ACCT_PURGE_JE smallint
, @Const_ACCT_CLOSEDSTATUS_OUTOFDATE char(1)

select
@Const_ACCT_ARC = convert(smallint, dbo.fnc_GetConstant('ACCT_ARC'))
, @Const_ACCT_ARB = convert(smallint, dbo.fnc_GetConstant('ACCT_ARB'))
, @Const_ACCT_GLTTYPE_DETAIL = convert(smallint, dbo.fnc_GetConstant('ACCT_GLTTYPE_DETAIL'))
, @Const_ACCT_GEN_YES = dbo.fnc_GetConstant('ACCT_GEN_YES')
, @Const_ACCT_PURGE_JE = convert(smallint, dbo.fnc_GetConstant('ACCT_PURGE_JE'))
, @Const_ACCT_CLOSEDSTATUS_OUTOFDATE = dbo.fnc_GetConstant('ACCT_CLOSEDSTATUS_OUTOFDATE')

if @AsOfDate is null
begin
select
@AsOfDate = dbo.fnc_StripTime(getdate())
end

create table dbo.#EmpD
(
GLDivCode char(3)
, GLBrnchCode char(3)
, GLDeptCode char(3)
, GLGrpCode char(3)
)

insert into dbo.#EmpD
select
GLDivCode
, GLBrnchCode
, GLDeptCode
, GLGrpCode
from
dbo.fnc_CreateDivBrnchDeptGrpByUser(@LoggedInUser
,null
,null
,null
,null)

select
@FullAcctBal = @FullAcctBal + isnull((glt.DebitAmt - glt.CreditAmt), $0.00)
, @AcctBal = @AcctBal + case
when (inv.GLDivCode is not null
and empd.GLDivCode is not null)
or
inv.GLDivCode is null
then isnull((glt.DebitAmt - glt.CreditAmt), $0.00)
else $0.00
end
from
AFW_GeneralLedgerTransaction as glt
inner join AFW_Invoice as inv
on glt.InvId = inv.InvId
left join #EmpD as empd
on empd.GLDivCode = inv.GLDivCode
and empd.GLBrnchCode = inv.GLBrnchCode
and empd.GLDeptCode = inv.GLDeptCode
and empd.GLGrpCode = inv.GLGrpCode
where
glt.TranDate <= @AsOfDate
and glt.GLSADefine in (@Const_ACCT_ARC, @Const_ACCT_ARB)
and glt.GLTType = @Const_ACCT_GLTTYPE_DETAIL
and glt.IsPosted = @Const_ACCT_GEN_YES
and glt.SourceTran <> @Const_ACCT_PURGE_JE
and (inv.ARClosedStatus = @Const_ACCT_CLOSEDSTATUS_OUTOFDATE
or inv.ARClosedDate > @ASOfDate)
and glt.CustId = @CustId

drop table #EmpD

select @ErrorNo = @@error

return @ErrorNo

Then I run this code from a different QA window:

dbcc freeproccache
dbcc dropcleanbuffers
go

declare
@ErrorNo int
, @Const_ACCT_ARC smallint
, @Const_ACCT_ARB smallint
, @Const_ACCT_GLTTYPE_DETAIL smallint
, @Const_ACCT_GEN_YES char(1)
, @Const_ACCT_PURGE_JE smallint
, @Const_ACCT_CLOSEDSTATUS_OUTOFDATE char(1)
, @ASOfDate datetime
, @CustId uniqueidentifier
, @AcctBal money
, @FullAcctBal money
, @LoggedInUser varchar(3)

select
@Const_ACCT_ARC = convert(smallint, dbo.fnc_GetConstant('ACCT_ARC'))
, @Const_ACCT_ARB = convert(smallint, dbo.fnc_GetConstant('ACCT_ARB'))
, @Const_ACCT_GLTTYPE_DETAIL = convert(smallint, dbo.fnc_GetConstant('ACCT_GLTTYPE_DETAIL'))
, @Const_ACCT_GEN_YES = dbo.fnc_GetConstant('ACCT_GEN_YES')
, @Const_ACCT_PURGE_JE = convert(smallint, dbo.fnc_GetConstant('ACCT_PURGE_JE'))
, @Const_ACCT_CLOSEDSTATUS_OUTOFDATE = dbo.fnc_GetConstant('ACCT_CLOSEDSTATUS_OUTOFDATE')

select @CustId = 'EC75C6E0-D6F7-4AD3-883F-69E675F8BAFE'
, @LoggedInUser = '!!3'
, @AsOfDate = null
, @AcctBal = 0.00
, @FullAcctBal = 0.00

if @AsOfDate is null
begin
select
@AsOfDate = dbo.fnc_StripTime(getdate())
end

create table #EmpD
(
GLDivCode char(3)
, GLBrnchCode char(3)
, GLDeptCode char(3)
, GLGrpCode char(3)
)

insert into #EmpD
select
GLDivCode
, GLBrnchCode
, GLDeptCode
, GLGrpCode
from
dbo.fnc_CreateDivBrnchDeptGrpByUser('!!3'
,null
,null
,null
,null)

select
@FullAcctBal = @FullAcctBal + isnull((glt.DebitAmt - glt.CreditAmt), $0.00)
, @AcctBal = @AcctBal + case
when (inv.GLDivCode is not null
and empd.GLDivCode is not null)
or
inv.GLDivCode is null
then isnull((glt.DebitAmt - glt.CreditAmt), $0.00)
else $0.00
end
from
AFW_GeneralLedgerTransaction as glt
inner join AFW_Invoice as inv
on glt.InvId = inv.InvId
left join #EmpD as empd
on empd.GLDivCode = inv.GLDivCode
and empd.GLBrnchCode = inv.GLBrnchCode
and empd.GLDeptCode = inv.GLDeptCode
and empd.GLGrpCode = inv.GLGrpCode
where
glt.TranDate <= @AsOfDate
and glt.GLSADefine in (@Const_ACCT_ARC, @Const_ACCT_ARB)
and glt.GLTType = @Const_ACCT_GLTTYPE_DETAIL
and glt.IsPosted = @Const_ACCT_GEN_YES
and glt.SourceTran <> @Const_ACCT_PURGE_JE
and (inv.ARClosedStatus = @Const_ACCT_CLOSEDSTATUS_OUTOFDATE
or inv.ARClosedDate > @ASOfDate)
and glt.CustId = @CustId

drop table #EmpD

select @FullAcctBal, @AcctBal

I use profiler to capture the duration and the reads. The database I'm running this against is a copy of the live version, but on an isolated system that only I am running against. I'm using running show execution plan when I run each example above to see the query plan. I'm sure both everything is the same. I've verified the totals come out the same.

TG
Master Smack Fu Yak Hacker

6065 Posts

Posted - 2005-03-11 : 17:37:06

Here is one thing I'd suggest just to start narrowing down possibilities. Create either a Permanent table or global temp table for #EmpD outside these processes with the same data as this call would generate. And then remove this:
create table dbo.#EmpD
(
GLDivCode char(3)
, GLBrnchCode char(3)
, GLDeptCode char(3)
, GLGrpCode char(3)
)

insert into dbo.#EmpD
select
GLDivCode
, GLBrnchCode
, GLDeptCode
, GLGrpCode
from
dbo.fnc_CreateDivBrnchDeptGrpByUser(@LoggedInUser
,null
,null
,null
,null)

I noticed that in the non-sp portion you hardcoded '!!3' rather than @LoggedInUser. (Probably doesn't matter)

Lets just make sure that the problem doesn't have anything to do with using a function to populate a temp table. After these changes to both the proc and the direct call, lets see if the problem is still there.

The next thing I'd do, if that doesn't change the proc performance, is to remove all the const functions and replace the variables in the where clause with quoted strings. Basically, just keep stripping stuff out until the problem goes away and then one by one adding them back until we figure out the culprit.

Be One with the Optimizer
TG

spirit1
Cybernetic Yak Master

11752 Posts

Posted - 2005-03-11 : 17:48:28

use
set statistics io on
and
set statistics time on

and see what that gives you.

that is weird.

Go with the flow & have fun! Else fight the flow

Subscribe to SQLTeam.com

SQLTeam.com Articles via RSS

SQLTeam.com Weblog via RSS

- Advertisement -

Resources