May 30, 2008 at 8:50 am
All,
Here are the details of a view and an associated query, it also shows the widely varying times taken by the query when run several times each run following on from the last.
Any advice on why the times vary so much will be helpful.
This is the view:
CREATE VIEW LGNCC_COMMONEVENTVIEW AS SELECT
-- [ID]
EVENT.EVENTID AS REFERENCE,
5 AS TYPE,
-- [DESCRIPTION]
EVENT.TITLE AS LINE1,
EVENT.OTHERACTION AS LINE2,
-- [CASE]
ENQUIRY.CASEID AS CASEID,
ENQUIRY.CASEREF AS RELATEDCASE,
ENQUIRY.ENQUIRYTYPE AS ENQUIRYTYPE,
ENQUIRY.OBJECTTYPE AS OBJECTTYPE,
ENQUIRY.XREF1 AS XREF1,
ENQUIRY.XREF2 AS XREF2,
ENQUIRY.XREF3 AS XREF3,
ENQUIRY.OBJECTDESC AS OBJECTDESC,
-- [INTERACTION]
-1 AS CLIENTTYPE,
CAST(null as varchar(20)) AS CLIENTID,
CAST(null as varchar(255))AS CLIENTNAME,
-1 AS INTERACTIONID,
CAST(null as varchar(50)) AS INTERACTIONREF,
CAST(null as char(1)) AS INTERACTIONVERIFIED,
-1 AS INTERACTIONCHANNEL,
CAST(null as varchar(50)) AS INTERACTIONREFERENCE,
GETDATE() AS INTERACTIONDATE,
-- [STATUS]
CAST(null as datetime) AS TARGETDATE,
1 AS STATUS,
-- [AUDIT]
EVENT.EVENTDATETIME AS CREATIONDATE,
EVENT.SOURCEUSERID AS CREATEDBY,
EVENT.EVENTDATETIME AS MODIFIEDDATE,
CAST(null as varchar(100)) AS MODIFIEDBY
FROM
LGNCC_CASEEVENTS EVENT
INNER JOIN LGNCC_ENQUIRY ENQUIRY ON ENQUIRY.CASEID = EVENT.CASEID
UNION
SELECT
-- [ID]
EVENT.EVENTID AS REFERENCE,
5 AS TYPE,
-- [DESCRIPTION]
EVENT.TITLE AS LINE1,
EVENT.OTHERACTION AS LINE2,
-- [CASE]
ENQUIRY.CASEID AS CASEID,
ENQUIRY.CASEREF AS RELATEDCASE,
ENQUIRY.ENQUIRYTYPE AS ENQUIRYTYPE,
ENQUIRY.OBJECTTYPE AS OBJECTTYPE,
ENQUIRY.XREF1 AS XREF1,
ENQUIRY.XREF2 AS XREF2,
ENQUIRY.XREF3 AS XREF3,
ENQUIRY.OBJECTDESC AS OBJECTDESC,
-- [INTERACTION]
-1 AS CLIENTTYPE,
CAST(null as varchar(20)) AS CLIENTID,
CAST(null as varchar(255))AS CLIENTNAME,
-1 AS INTERACTIONID,
CAST(null as varchar(50)) AS INTERACTIONREF,
CAST(null as char(1)) AS INTERACTIONVERIFIED,
-1 AS INTERACTIONCHANNEL,
CAST(null as varchar(50)) AS INTERACTIONREFERENCE,
GETDATE() AS INTERACTIONDATE,
-- [STATUS]
CAST(null as datetime) AS TARGETDATE,
0 AS STATUS,
-- [AUDIT]
EVENT.EVENTDATETIME AS CREATIONDATE,
EVENT.SOURCEUSERID AS CREATEDBY,
EVENT.EVENTDATETIME AS MODIFIEDDATE,
CAST(null as varchar(100)) AS MODIFIEDBY
FROM
LGNCC_CLOSEDCASEEVENTS EVENT
INNER JOIN LGNCC_ENQUIRY ENQUIRY ON ENQUIRY.CASEID = EVENT.CASEID
This is the query being run:
SELECT *
FROM LGNCC_COMMONEVENTVIEW
WHERE xref1 = '1001185190' AND objecttype = 'D4' AND ( 1 = 1 )
These are the timing each one run just after the previous query returned:
SQL Server parse and compile time:
CPU time = 125 ms, elapsed time = 637 ms.
(3313 row(s) affected)
Table 'LGNCC_CLOSEDCASEEVENTS'. Scan count 1, logical reads 19439, physical reads 7, read-ahead reads 8137.
Table 'LGNCC_ENQUIRY'. Scan count 2, logical reads 9362, physical reads 1240, read-ahead reads 7.
Table 'LGNCC_CASEEVENTS'. Scan count 1, logical reads 5079, physical reads 5, read-ahead reads 5104.
SQL Server Execution Times:
CPU time = 1266 ms, elapsed time = 82255 ms.
(3313 row(s) affected)
Table 'LGNCC_CLOSEDCASEEVENTS'. Scan count 1, logical reads 19439, physical reads 0, read-ahead reads 0.
Table 'LGNCC_ENQUIRY'. Scan count 2, logical reads 12688, physical reads 3, read-ahead reads 1105.
Table 'LGNCC_CASEEVENTS'. Scan count 1, logical reads 5082, physical reads 0, read-ahead reads 0.
SQL Server Execution Times:
CPU time = 1344 ms, elapsed time = 62420 ms.
(3313 row(s) affected)
Table 'LGNCC_CLOSEDCASEEVENTS'. Scan count 1, logical reads 19439, physical reads 396, read-ahead reads 429.
Table 'LGNCC_ENQUIRY'. Scan count 2, logical reads 9786, physical reads 3, read-ahead reads 0.
Table 'LGNCC_CASEEVENTS'. Scan count 1, logical reads 5082, physical reads 0, read-ahead reads 2813.
SQL Server Execution Times:
CPU time = 1953 ms, elapsed time = 317477 ms.
(3313 row(s) affected)
Table 'LGNCC_CLOSEDCASEEVENTS'. Scan count 1, logical reads 19439, physical reads 14, read-ahead reads 18652.
Table 'LGNCC_ENQUIRY'. Scan count 2, logical reads 9574, physical reads 1097, read-ahead reads 6.
Table 'LGNCC_CASEEVENTS'. Scan count 1, logical reads 5082, physical reads 7, read-ahead reads 5091.
SQL Server Execution Times:
CPU time = 1485 ms, elapsed time = 180487 ms.
(3313 row(s) affected)
Table 'LGNCC_CLOSEDCASEEVENTS'. Scan count 1, logical reads 19439, physical reads 2, read-ahead reads 188.
Table 'LGNCC_ENQUIRY'. Scan count 2, logical reads 9574, physical reads 38, read-ahead reads 0.
Table 'LGNCC_CASEEVENTS'. Scan count 1, logical reads 5082, physical reads 1, read-ahead reads 216.
SQL Server Execution Times:
CPU time = 1187 ms, elapsed time = 52104 ms.
(3313 row(s) affected)
Table 'LGNCC_CLOSEDCASEEVENTS'. Scan count 1, logical reads 19439, physical reads 13, read-ahead reads 17816.
Table 'LGNCC_ENQUIRY'. Scan count 2, logical reads 9576, physical reads 986, read-ahead reads 7.
Table 'LGNCC_CASEEVENTS'. Scan count 1, logical reads 5082, physical reads 0, read-ahead reads 2824.
SQL Server Execution Times:
CPU time = 1953 ms, elapsed time = 251025 ms.
This is the query plan produced:
|--Merge Join(Union)
|--Sort(DISTINCT ORDER BY:([LGNCC_CASEEVENTS].[EventID] ASC, [LGNCC_CASEEVENTS].[Title] ASC, [LGNCC_CASEEVENTS].[OtherAction] ASC, [LGNCC_ENQUIRY].[CaseID] ASC, [LGNCC_ENQUIRY].[CaseRef] ASC, [LGNCC_ENQUIRY].[EnquiryType] ASC, [LGNCC_ENQUIRY].[xref2
| |--Compute Scalar(DEFINE:([LGNCC_CASEEVENTS].[EventDateTime]=[LGNCC_CASEEVENTS].[EventDateTime]))
| |--Compute Scalar(DEFINE:([Expr1063]=getdate()))
| |--Hash Match(Inner Join, HASH:([LGNCC_ENQUIRY].[CaseID])=([LGNCC_CASEEVENTS].[CaseID]), RESIDUAL:([LGNCC_CASEEVENTS].[CaseID]=[LGNCC_ENQUIRY].[CaseID]))
| |--Filter(WHERE:([LGNCC_ENQUIRY].[ObjectType]='D4'))
| | |--Bookmark Lookup(BOOKMARK:([Bmk1002]), OBJECT:([FrontlineLive].[FrontlineLive].[LGNCC_ENQUIRY]))
| | |--Index Seek(OBJECT:([FrontlineLive].[FrontlineLive].[LGNCC_ENQUIRY].[LGNCC_ENQUIRY_XREF1]), SEEK:([LGNCC_ENQUIRY].[xref1]='1001185190') ORDERED FORWARD)
| |--Clustered Index Scan(OBJECT:([FrontlineLive].[FrontlineLive].[LGNCC_CASEEVENTS].[PK__LGNCC_CASEEVENTS__40F9A68C]))
|--Sort(DISTINCT ORDER BY:([LGNCC_CLOSEDCASEEVENTS].[EventID] ASC, [LGNCC_CLOSEDCASEEVENTS].[Title] ASC, [LGNCC_CLOSEDCASEEVENTS].[OtherAction] ASC, [LGNCC_ENQUIRY].[CaseID] ASC, [LGNCC_ENQUIRY].[CaseRef] ASC, [LGNCC_ENQUIRY].[EnquiryType] ASC, [LGN
|--Compute Scalar(DEFINE:([LGNCC_CLOSEDCASEEVENTS].[EventDateTime]=[LGNCC_CLOSEDCASEEVENTS].[EventDateTime]))
|--Compute Scalar(DEFINE:([Expr1065]=getdate()))
|--Hash Match(Inner Join, HASH:([LGNCC_ENQUIRY].[CaseID])=([LGNCC_CLOSEDCASEEVENTS].[CaseID]), RESIDUAL:([LGNCC_CLOSEDCASEEVENTS].[CaseID]=[LGNCC_ENQUIRY].[CaseID]))
|--Filter(WHERE:([LGNCC_ENQUIRY].[ObjectType]='D4'))
| |--Bookmark Lookup(BOOKMARK:([Bmk1019]), OBJECT:([FrontlineLive].[FrontlineLive].[LGNCC_ENQUIRY]))
| |--Index Seek(OBJECT:([FrontlineLive].[FrontlineLive].[LGNCC_ENQUIRY].[LGNCC_ENQUIRY_XREF1]), SEEK:([LGNCC_ENQUIRY].[xref1]='1001185190') ORDERED FORWARD)
|--Clustered Index Scan(OBJECT:([FrontlineLive].[FrontlineLive].[LGNCC_CLOSEDCASEEVENTS].[PK__LGNCC_CLOSEDCASE__42E1EEFE]))
These are the row counts from the tables:
lgncc_closedcaseevents = 720722 rows
lgncc_caseevents = 16382 rows
lgncc_enquiry = 478130 rows
xref1 in lgncc_enquiry = 1557 rows
Any advice welcome.
Ronnie
May 30, 2008 at 9:02 am
You are getting Clustered Index Scans (basically table scans) on your CaseEvents tables which will cause the query to be slower. Depending on the use of the tables and you may want and index on xref1 and objecttype. The next question is why do you have "AND 1=1" since it is always true?
As faras differenct execution times, well as you run it more data is cached so you should hit the cache more as you run it more, and depending on server activity the times will not always be the same.
Jack Corbett
Consultant - Straight Path Solutions
Check out these links on how to get faster and more accurate answers:
Forum Etiquette: How to post data/code on a forum to get the best help
Need an Answer? Actually, No ... You Need a Question
May 30, 2008 at 12:09 pm
The clustered index scan on lgncc_caseevents and lgncc_closedcaseevents are on an index that is on caseid, which is the join column to the table in the view.
Also the first run was faster than the second so caching is not neccesarily an issue. In fact one of the middle runs was the slowest.
Ronnie
May 30, 2008 at 12:58 pm
You can see that in the slower queries you had more physical reads on the ENQUIRY table which means something else happened that caused it to be flushed from the cache. The execution time can vary based on other factors while physical disk access is really a key area to try to limit. It appears that for some reason the ENQUIRY table is being flushed from cache more often so as your IO Stats show (physical reads and read-ahead reads) it being read from disk and/or reloaded into cache in executions 1,2,4,6.
You are also hitting the ENQUIRY table twice in the view and you can limit that to once by UNION'ing the 2 EVENTS tables first and then joining on the ENQUIRY table something like this:
[font="Courier New"]SELECT
-- [ID]
EVENT.REFERENCE,
EVENT.TYPE,
-- [DESCRIPTION]
EVENT.LINE1,
EVENT.LINE2,
-- [CASE]
ENQUIRY.CASEID,
ENQUIRY.CASEREF AS RELATEDCASE,
ENQUIRY.ENQUIRYTYPE AS ENQUIRYTYPE,
ENQUIRY.OBJECTTYPE AS OBJECTTYPE,
ENQUIRY.XREF1 AS XREF1,
ENQUIRY.XREF2 AS XREF2,
ENQUIRY.XREF3 AS XREF3,
ENQUIRY.OBJECTDESC AS OBJECTDESC,
-- [INTERACTION]
-1 AS CLIENTTYPE,
CAST(NULL AS VARCHAR(20)) AS CLIENTID,
CAST(NULL AS VARCHAR(255))AS CLIENTNAME,
-1 AS INTERACTIONID,
CAST(NULL AS VARCHAR(50)) AS INTERACTIONREF,
CAST(NULL AS CHAR(1)) AS INTERACTIONVERIFIED,
-1 AS INTERACTIONCHANNEL,
CAST(NULL AS VARCHAR(50)) AS INTERACTIONREFERENCE,
GETDATE() AS INTERACTIONDATE,
-- [STATUS]
CAST(NULL AS DATETIME) AS TARGETDATE,
0 AS STATUS,
-- [AUDIT]
EVENT.CREATIONDATE,
EVENT.CREATEDBY,
EVENT.MODIFIEDDATE,
EVENT.MODIFIEDBY
FROM
(
SELECT
E.CASEID,
E.EVENTID AS REFERENCE,
5 AS TYPE,
-- [DESCRIPTION]
E.TITLE AS LINE1,
E.OTHERACTION AS LINE2,
E.EVENTDATETIME AS CREATIONDATE,
E.SOURCEUSERID AS CREATEDBY,
E.EVENTDATETIME AS MODIFIEDDATE,
CAST(NULL AS VARCHAR(100)) AS MODIFIEDBY
FROM
LGNCC_CASEEVENTS E
UNION
SELECT
E.CASEID,
E.EVENTID AS REFERENCE,
5 AS TYPE,
-- [DESCRIPTION]
E.TITLE AS LINE1,
E.OTHERACTION AS LINE2,
E.EVENTDATETIME AS CREATIONDATE,
E.SOURCEUSERID AS CREATEDBY,
E.EVENTDATETIME AS MODIFIEDDATE,
CAST(NULL AS VARCHAR(100)) AS MODIFIEDBY
FROM
LGNCC_CASEEVENTS E
) AS EVENT INNER JOIN
LGNCC_ENQUIRY ENQUIRY ON
ENQUIRY.CASEID = EVENT.CASEID
[/font]
Jack Corbett
Consultant - Straight Path Solutions
Check out these links on how to get faster and more accurate answers:
Forum Etiquette: How to post data/code on a forum to get the best help
Need an Answer? Actually, No ... You Need a Question
May 30, 2008 at 2:28 pm
Why would SQL Server be flushing the cache so quickly ?
Ronnie
May 30, 2008 at 2:54 pm
I don't know why the cache would clear other than either a small cache size or activity. You could check the buffer cache hit ratio counter.
Did you try the modified view statement?
Jack Corbett
Consultant - Straight Path Solutions
Check out these links on how to get faster and more accurate answers:
Forum Etiquette: How to post data/code on a forum to get the best help
Need an Answer? Actually, No ... You Need a Question
May 30, 2008 at 6:29 pm
First, I think I'd use UNION ALL... considering the source tables, there's probably not much chance of duplication, anyway.
The other thing is that the CPU time is not varying all that much and one place took more time with 13 physical reads than it did with 14... I don't believe that this is either a real query problem nor a cache problem. I believe that it's a "pipe" problem... as in I/O problem especially on the output side. Could be wrong but it just looks that way to me...
--Jeff Moden
Change is inevitable... Change for the better is not.
June 1, 2008 at 2:11 am
Hi
When you say I/O output problem do you mean network bandwidth ?
Ronnie
June 1, 2008 at 4:02 am
Despite what already has been mentioned, do you have some more information regarding your indexes and PKs?
Best Regards,
Chris Büttner
June 1, 2008 at 4:38 am
The lgncc_enquiry table is indexed on xref1 and has another index on xref1 and objecttype. The lgncc_caseevents table and lgncc_closedcaseevents are both indexed on caseid.
Ronnie
June 1, 2008 at 5:06 am
Hi Ronnie,
Could you pls post the DDL for those?
If I am not completely wrong, the second index (xref1, objecttype) is not being used at all, only the first one. (The seek only involves the XREF1, the filter for ObjectType is after the complete row has been retrieved via bookmark lookup).
Thanks!
Best Regards,
Chris Büttner
June 1, 2008 at 9:21 am
Chris,
You are correct in assuming that it is not using the index that contains the objecttype even though it is specified in the query, there are only four unique objecttypes in the lgncc_enquiry tble.
I do not understand why it is using the xref1 only index then doing a bookmark lookup to filter on the objecttype when there is an index already there with the information.
create index lgncc_enquiry_xref1 on lgncc_enquiry (xref1)
create index lgncc_enquriy_t1 on lgncc_enquiry (xref1,objecttype)
Ronnie
June 1, 2008 at 10:26 am
Ronnie.Doggart (6/1/2008)
HiWhen you say I/O output problem do you mean network bandwidth ?
Ronnie
Yep... that and recompiles... because of the 1=1 trick to make it easier to form a WHERE clause, I'm assuming that you're building dynamic SQL in some GUI code and executing it instead of passing parameters to a well formed stored procedure.
--Jeff Moden
Change is inevitable... Change for the better is not.
June 1, 2008 at 10:57 am
Hi ronnie,
the additional column probably doesnt provide much value (e.g 99 percent of the rows contain this specific value that is filtered for). But make sure the statistics on this col are up to date.
Don't you have PK's on your tables?
Can you post the XML QUery Plan?
Best Regards,
Chris Büttner
June 2, 2008 at 12:34 am
Yes the tables do have Primary Keys:
ALTER TABLE [dbo].[LGNCC_ENQUIRY] ADD PRIMARY KEY CLUSTERED
(
[ID] ASC
)WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, SORT_IN_TEMPDB = OFF, IGNORE_DUP_KEY = OFF, ONLINE = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON) ON [PRIMARY]
ALTER TABLE [dbo].[LGNCC_CASEEVENTS] ADD PRIMARY KEY CLUSTERED
(
[EventID] ASC
)WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, SORT_IN_TEMPDB = OFF, IGNORE_DUP_KEY = OFF, ONLINE = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON) ON [PRIMARY]
ALTER TABLE [dbo].[LGNCC_CLOSEDCASEEVENTS] ADD PRIMARY KEY CLUSTERED
(
[EventID] ASC
)WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, SORT_IN_TEMPDB = OFF, IGNORE_DUP_KEY = OFF, ONLINE = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON) ON [PRIMARY]
Ronnie
Viewing 15 posts - 1 through 15 (of 32 total)
You must be logged in to reply to this topic. Login to reply