SQL Server Performance Forum – Threads Archive

poor query performance [update: MS says bug]

I recently restored a SQL 2000 database to my brand new, souped-up SQL
2005 server. Some queries that used to run in under a second in 2000
now take anywhere from 30 to 50 seconds in 2005! I don’t understand why this is happening. I can see the execution plans
are different (although I’m not quite sure how to read or make sense of
the plan). I tried updating all statistics first. When that didn’t
work I tried rebuilding the indexes. Again, no luck. Any ideas?

what is the difference in HW between the two?
processors, memory and disks use SET STATISTICS TIME & SET STATISTICS IO to determine whether the difference is in CPU and or disks. best yet, provide the sql so we can see if there is anything unusual. provide the execution plan from SET SHOWPLAN ALL or SET STATISTICS PROFILE for 2000 & 2005

OLD Machine:
Windows 2000 Ent. SP4
SQL 2000 Std.
Dual 1.8GHz Xeon Procs
4GB RAM
Smart Array with single mirrored pair for db & log files NEW Machine:
Windows 2003 Ent. SP1
SQL 2005 Std.
Dual 3.6GHz Xeon Procs
4GB RAM
Fiber SAN with 1 mirrored pair for db files & 1 pair for log files
You asked for it so here’s the query:
SELECT d.detail_id, a.activity_id, a.type, vh.type as holdType, vh.matching, hc.description as holdDesc, d.vin, a.activity_date, t.description, c.name as custname, c1.name as alt1_custname, m.makedesc, v.model, v.vinstat,
c2.name as alt2_custname, c3.name as alt3_custname, c4.name as alt4_custname, (select count(*) from activity_exc e where e.detail_id = d.detail_id) as exc_count,
ca.carriername, a.carrier_num, d.load_num, u.ln, u.fn, a.status, f.description as facilityname, l.description as lotname, a.sublot, d.military_time, d.park_space, d.space_num, d.row_num, d.vls_num, w.weathdesc, d.warning, d.odometer, d.comment, d.transmitted, d.last_trans_date,
v.onhold, v.sold, v.priority, v.dest_code
FROM activity_det d
LEFT OUTER JOIN activity_hdr a on (a.activity_id = d.activity_id)
LEFT OUTER JOIN vinHold vh on (vh.detail_id = d.detail_id)
LEFT OUTER JOIN holdCodes hc on (hc.code = vh.type)
LEFT OUTER JOIN activity t on (t.type = a.type)
LEFT OUTER JOIN facility f on (f.facility_id = a.facility)
LEFT OUTER JOIN lot l on (l.facility_id = a.facility and l.lot = a.lot)
LEFT OUTER JOIN weather w on (w.weather = a.weather)
LEFT OUTER JOIN cust c on (c.custid = a.custid)
LEFT OUTER JOIN cust c1 on (c1.custid = a.alt_custid1)
LEFT OUTER JOIN cust c2 on (c2.custid = a.alt_custid2)
LEFT OUTER JOIN cust c3 on (c3.custid = a.alt_custid3)
LEFT OUTER JOIN cust c4 on (c4.custid = a.alt_custid4)
LEFT OUTER JOIN carrier ca on (ca.carrier = a.carrier)
LEFT OUTER JOIN userlogin u on (u.user_initials = a.avi_user),
vin v, make m
WHERE d.vin = v.vin and v.make = m.make and d.vin = ‘1BLNOTAREALVIN470’ and a.badscan = 0 and d.badscan = 0 and exists (select useractivity.uid from useractivity where useractivity.type = t.type and useractivity.uid = ‘username’)
and (a.facility = ” or exists (select userfacility.uid from userfacility where userfacility.facility = a.facility and userfacility.uid = ‘username’))
and (a.custid = ” or exists (select usercust.uid from usercust where (usercust.custid = a.custid or usercust.custid = a.alt_custid1 or usercust.custid = a.alt_custid2 or usercust.custid = a.alt_custid3 or usercust.custid = a.alt_custid4) and usercust.uid = ‘username’))
and (a.carrier = ” or exists (select usercarrier.uid from usercarrier where usercarrier.carrier = a.carrier and usercarrier.uid = ‘username’))
and exists (select userplant.uid from userplant where userplant.plantid = v.plantid and userplant.uid = ‘username’)
and exists (select usermake.uid from usermake where usermake.make = v.make and usermake.uid = ‘username’)
and exists (select userclass.uid from userclass where userclass.class = v.class and userclass.uid = ‘username’)
and exists (select usercommodity.uid from usercommodity where usercommodity.commodity = v.commodity and usercommodity.uid = ‘username’) order by a.activity_date desc, d.military_time desc
As you can imagine, the execution plans are fairly large. I’ll put them in different posts
if needed but from SET STATISTICS IO it looks like 2005 is creating a 1000000 row worktable
for [activity_hdr]. This seems to only happen if I have more than 3 references to
[activity_hdr] (aliased as "a") in the where clause. Query returns in 37 seconds. With the same query, SQL 2000 never creates a worktable and
the query returns in .057 seconds. Also, as a side note, when I use DBCC SHOW_STATISTICS( table, target ) the
results look different between the two databases. Again, not sure what I’m
looking for with this command but the 2000 database displays values in many
places where 2005 displays zeros. I thought that 2005 might not be using the
correct sample size. I ran update statistics with sample size at 25% (same I
use for 2000). No change. edit: spelling

I don’t know mssql server 2005 query optimizer behaviour yet, but I have a few ideas about how you could possible improve the query. 1. Outer join with activity_hdr doesn’t make sense since you have conditions on that table in where clause (a.badscan = 0). Use inner join instead.
2. Instead of one big query I would use if and for each condition a.something = ” I would build separate query.
3. Make sure you have appropriate indexes.
4. Why does the query returns d.vin when it is already known? Condition d.vin = ‘1BLNOTAREALVIN470’ is part of where clause.
5. See if some exists can be replaced by inner joins. I don’t like the approach used for this query for the same reason that makes it hard to swallow for query optimizer (see point 2 and 5). 2005 and 2000 query optimizer are obviously different and it happened that 2000 handles that type of mess better.
Also, it is obvious that data model is not quite normalized, but I guess you can’t do anything about it.

If I were you, I’ll run Database Tuning Advisor to find out new indexes and compare with all execution plan.
Luis Martin
Moderator
SQL-Server-Performance.com Although nature commences with reason and ends in experience it is necessary for us to do the opposite, that is to commence with experience and from this to proceed to investigate the reason.
Leonardo Da Vinci Nunca esperes el reconocimiento de tus hijos, eso ocurrirÃ¡ luego de tu muerte
All postings are provided â€œAS ISâ€ with no warranties for accuracy.

mmarovic – thanks for the tips. I had hoped to avoid it but am beginning to think that a LOT of the queries will need to be rewritten. This is just one example of many. I understand the query I posted isn’t the prettiest thing and I never said it was written "correctly". I didn’t even say whether or not I wrote it <img src=’/community/emoticons/emotion-1.gif’ alt=’

if you are seeing a difference in the plan (costs) depending on the number columns referencing : activity_hdr a and the execution plan shows a hash to that table, it is because the optimizer is deciding that result set is sufficiently large to spool into a temp table. where is your temp db for the new system i do recall that the startup cost of a hash being much higher in 2005 than in 2000, but not enough for this now we need to know the difference in plans, the estimated and true row count for each op

Joe, does your tool work with sql server 2005? I haven’t installed 2005 yet, so I haven’t tried it. This is exact situation where this tool would be a great help.

<blockquote id="quote">quote:<hr height="1" noshade id="quote">Originally posted by fwa mmarovic – thanks for the tips. I had hoped to avoid it but am beginning to think that a LOT of the queries will need to be rewritten. This is just one example of many. I understand the query I posted isn’t the prettiest thing and I never said it was written "correctly". I didn’t even say whether or not I wrote it <img src=’/community/emoticons/emotion-1.gif’ alt=’

‘ /> ! My dilema is that I’ve got a piece of code that runs about 650 times slower on a server that’s twice as powerful. That’s hard to explain to the client. I was really hoping I’d see a big improvement just by moving to a faster server and newer database without having to change a thing. The fact that I’m not even getting the same performance is really disappointing.<hr height="1" noshade id="quote"></blockquote id="quote">I feel your pain and I understand it is not your fault but I am afraid the only help I can offer for the issue are query tunning tips and maybe index design tips. <blockquote id="quote">quote:<hr height="1" noshade id="quote">There’s not enough activity on the 2005 database to generate a "good" trace file. If I run the Database Engine Tuning Advisor, is there a way to feed it a sql 2000 trace file?<hr height="1" noshade id="quote"></blockquote id="quote">I don’t know about that, but I am pretty sure the indexes usefull on 2000 are equally useful on 2005, so you can run index tunning wizard on 2000 and apply recommendations on 2005. On top of that you can try to use hints to force execution plan on 2005 that would be equal to one on 2000. However that is not allways possible and even if it is, that is the query optimization you try to avoid for now.

Okay, I’ve identified another poor performer. I stripped out all of
the extraneous code. To start fresh I dropped the databases and restored the same database
backup to SQL2000 and SQL2005 so the databases are identical and ran
the query against both. detail_id is the primary key and clustered
index on activity_det. So I’m asking for 1 record here. SELECT d.vin, a.lot
FROM activity_det d
INNER JOIN activity_hdr a on (a.activity_id = d.activity_id)
WHERE d.detail_id = ‘3093458’
and (a.facility = ” or exists (select userfacility.uid from userfacility where userfacility.facility = a.facility and userfacility.uid = ‘username’))
and (a.custid = ” or exists (select usercust.uid from usercust where (usercust.custid = a.custid or usercust.custid = a.alt_custid1 or usercust.custid = a.alt_custid2 or usercust.custid = a.alt_custid3 or usercust.custid = a.alt_custid4) and usercust.uid = ‘username’))
Here are the results… SQL 2000
Table ‘usercust’. Scan count 2, logical reads 5, physical reads 0, read-ahead reads 0.
Table ‘userfacility’. Scan count 1, logical reads 2, physical reads 0, read-ahead reads 0.
Table ‘activity_hdr’. Scan count 1, logical reads 3, physical reads 0, read-ahead reads 0.
Table ‘activity_det’. Scan count 1, logical reads 3, physical reads 0, read-ahead reads 0. SQL Server Execution Times:
CPU time = 0 ms, elapsed time = 1 ms.
SQL 2005
Table ‘activity_det’. Scan count 0, logical reads 3, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘Worktable’. Scan count 1069710, logical reads 3211421, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘Worktable’. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘userfacility’. Scan count 0, logical reads 2100386, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘activity_hdr’. Scan count 5, logical reads 31311, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table ‘usercust’. Scan count 1, logical reads 39, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0. SQL Server Execution Times:
CPU time = 65219 ms, elapsed time = 114962 ms
I just can’t believe it. edit: readability

mmarovic
my tool does not work with 2005, i would have to break into the true 2005 system tables, and MS has put in things to prevent my tampering, ie, checksums etc, will look into it though. fwa
i don’t understand why sql 2000 uses a good plan,
the way the query is written, i would expect problems for both 2000 & 2005 i really think i need to see the actual execution plan details, ie, estimated and true row counts, otherwise, the 2000 numbers don’t make sense try OPTION (FORCE ORDER) in 2005 for the above query

Here are the execution plans… SQL 2000 (SET SHOWPLAN_ALL ON) <pre id="code"> Rows Executes StmtText StmtId NodeId Parent PhysicalOp LogicalOp Argument DefinedValues EstimateRows EstimateIO EstimateCPU AvgRowSize TotalSubtreeCost OutputList Warnings Type Parallel EstimateExecutions ———– ———– —————————————————————————————————————————————————————————————————————————————————————- ———– ———– ———– —————————— —————————— —————————————————————————————————————————————————————————— ——————————————————————————————————————————————————————————————————————————– ————- ————- ————- ———– —————- ——————————————————————————————————————————————- ——– —————————— ——– —————— 1 1 SELECT d.vin, a.lot FROM activity_det d INNER JOIN activity_hdr a on (a.activity_id = d.activity_id) WHERE d.detail_id = ‘3093458’ and (a.facility = ” or exists (select userfacility.uid from userfacility where userfacility.facility = a.facility and u 24 1 0 NULL NULL NULL NULL 1 NULL NULL NULL 0.01431925 NULL NULL SELECT 0 NULL 1 1 |–Filter(WHERE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[custid]=” OR [Expr1007])) 24 3 1 Filter Filter WHERE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[custid]=” OR [Expr1007]) NULL 1 0 6.8E-07 587 0.01431915 [d].[vin], [a].[lot] NULL PLAN_ROW 0 1 1 1 |–Nested Loops(Left Semi Join, WHERE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[custid]=”)OUTER REFERENCES<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[alt_custid4], [a].[alt_custid3], [a].[alt_custid2], [a].[alt_custid1], [a].[custid]), DEFINE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[Expr1007] = [PROBE VALUE])) 24 4 3 Nested Loops Left Semi Join WHERE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[custid]=”)OUTER REFERENCES<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[alt_custid4], [a].[alt_custid3], [a].[alt_custid2], [a].[alt_custid1], [a].[custid]), DEFINE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[Expr1007] = [PROBE VALUE]) [Expr1007] = [PROBE VALUE] 1 0 4.18E-06 587 0.01431847 [d].[vin], [a].[custid], [a].[lot], [Expr1007] NULL PLAN_ROW 0 1 1 1 |–Filter(WHERE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[facility]=” OR [Expr1006])) 24 5 4 Filter Filter WHERE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[facility]=” OR [Expr1006]) NULL 1 0 6.8E-07 586 0.009858578 [d].[vin], [a].[alt_custid4], [a].[alt_custid3], [a].[alt_custid2], [a].[alt_custid1], [a].[custid], [a].[lot] NULL PLAN_ROW 0 1 1 1 | |–Nested Loops(Left Semi Join, WHERE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[facility]=”)OUTER REFERENCES<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[facility]), DEFINE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[Expr1006] = [PROBE VALUE])) 24 6 5 Nested Loops Left Semi Join WHERE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[facility]=”)OUTER REFERENCES<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[facility]), DEFINE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[Expr1006] = [PROBE VALUE]) [Expr1006] = [PROBE VALUE] 1 0 4.18E-06 586 0.009857898 [d].[vin], [a].[alt_custid4], [a].[alt_custid3], [a].[alt_custid2], [a].[alt_custid1], [a].[custid], [a].[facility], [a].[lot], [Expr1006] NULL PLAN_ROW 0 1 1 1 | |–Nested Loops(Inner Join, OUTER REFERENCES<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[d].[activity_id])) 24 7 6 Nested Loops Inner Join OUTER REFERENCES<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[d].[activity_id]) NULL 1 0 4.18E-06 586 0.006570336 [d].[vin], [a].[alt_custid4], [a].[alt_custid3], [a].[alt_custid2], [a].[alt_custid1], [a].[custid], [a].[facility], [a].[lot] NULL PLAN_ROW 0 1 1 1 | | |–Clustered Index Seek(OBJECT<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[xxx].[dbo].[activity_det].[PK_activity_det] AS [d]), SEEK<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[d].[detail_id]=309345<img src=’/community/emoticons/emotion-11.gif’ alt=’8)’ /> ORDERED FORWARD) 24 8 7 Clustered Index Seek Clustered Index Seek OBJECT<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[xxx].[dbo].[activity_det].[PK_activity_det] AS [d]), SEEK<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[d].[detail_id]=309345<img src=’/community/emoticons/emotion-11.gif’ alt=’8)’ /> ORDERED FORWARD [d].[activity_id], [d].[vin] 1 0.003203475 7.9603E-05 254 0.003283078 [d].[activity_id], [d].[vin] NULL PLAN_ROW 0 1 1 1 | | |–Clustered Index Seek(OBJECT<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[xxx].[dbo].[activity_hdr].[PK_veh_activity] AS [a]), SEEK<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[activity_id]=[d].[activity_id]) ORDERED FORWARD) 24 9 7 Clustered Index Seek Clustered Index Seek OBJECT<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[xxx].[dbo].[activity_hdr].[PK_veh_activity] AS [a]), SEEK<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[activity_id]=[d].[activity_id]) ORDERED FORWARD [a].[alt_custid4], [a].[alt_custid3], [a].[alt_custid2], [a].[alt_custid1], [a].[custid], [a].[facility], [a].[lot] 1 0.003203475 7.9603E-05 342 0.003283078 [a].[alt_custid4], [a].[alt_custid3], [a].[alt_custid2], [a].[alt_custid1], [a].[custid], [a].[facility], [a].[lot] NULL PLAN_ROW 0 1 1 1 | |–Clustered Index Seek(OBJECT<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[xxx].[dbo].[userfacility].[PK_userfacility]), SEEK<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[userfacility].[uid]=’username’ AND [userfacility].[facility]=[a].[facility]) ORDERED FORWARD) 24 10 6 Clustered Index Seek Clustered Index Seek OBJECT<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[xxx].[dbo].[userfacility].[PK_userfacility]), SEEK<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[userfacility].[uid]=’username’ AND [userfacility].[facility]=[a].[facility]) ORDERED FORWARD NULL 1 0.003203475 7.9607E-05 43 0.003283082 NULL NULL PLAN_ROW 0 1 1 1 |–Nested Loops(Inner Join, OUTER REFERENCES<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[Expr1020], [Expr1021], [Expr1022])) 24 16 4 Nested Loops Inner Join OUTER REFERENCES<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[Expr1020], [Expr1021], [Expr1022]) NULL 1 0.002214241 0.0001238731 42 0.004428481 [usercust].[uid] NULL PLAN_ROW 0 1 2 1 |–Merge Interval 24 17 16 Merge Interval Merge Interval NULL NULL 5 0 0 0 0 [Expr1020], [Expr1021], [Expr1022] NULL PLAN_ROW 0 1 5 1 | |–Sort(TOP 5, ORDER BY<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[Expr1023] DESC, [Expr1024] ASC, [Expr1020] ASC, [Expr1025] DESC)) 24 18 17 Sort TopN Sort TOP 5, ORDER BY<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[Expr1023] DESC, [Expr1024] ASC, [Expr1020] ASC, [Expr1025] DESC) NULL 5 0 0 0 0 [Expr1020], [Expr1021], [Expr1022], [Expr1023], [Expr1024], [Expr1025] NULL PLAN_ROW 0 1 5 1 | |–Compute Scalar(DEFINE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[Expr1023]=(4&[Expr1022])=4 AND NULL=[Expr1020], [Expr1024]=4&[Expr1022], [Expr1025]=16&[Expr1022])) 24 19 18 Compute Scalar Compute Scalar DEFINE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[Expr1023]=(4&[Expr1022])=4 AND NULL=[Expr1020], [Expr1024]=4&[Expr1022], [Expr1025]=16&[Expr1022]) [Expr1023]=(4&[Expr1022])=4 AND NULL=[Expr1020], [Expr1024]=4&[Expr1022], [Expr1025]=16&[Expr1022] 5 0 0 0 0 [Expr1020], [Expr1021], [Expr1022], [Expr1023], [Expr1024], [Expr1025] NULL PLAN_ROW 0 1 5 1 | |–Concatenation 24 20 19 Concatenation Concatenation NULL [Expr1020] = ([Expr1008], [Expr1011], [Expr1014], [Expr1017], [Expr1020]), [Expr1021] = ([Expr1009], [Expr1012], [Expr1015], [Expr1018], [Expr1021]), [Expr1022] = ([Expr1010], [Expr1013], [Expr1016], [Expr1019], [Expr1022]) 5 0 0 0 0 [Expr1020], [Expr1021], [Expr1022] NULL PLAN_ROW 0 1 1 1 | |–Compute Scalar(DEFINE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[custid]=[a].[custid], [a].[custid]=[a].[custid], [Expr1010]=62)) 24 22 20 Compute Scalar Compute Scalar DEFINE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[custid]=[a].[custid], [a].[custid]=[a].[custid], [Expr1010]=62) [a].[custid]=[a].[custid], [a].[custid]=[a].[custid], [Expr1010]=62 1 0 0 0 0 [a].[custid], [a].[custid], [Expr1010] NULL PLAN_ROW 0 1 1 1 | | |–Constant Scan 24 23 22 Constant Scan Constant Scan NULL NULL 1 0 0 0 0 NULL NULL PLAN_ROW 0 1 1 1 | |–Compute Scalar(DEFINE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[alt_custid1]=[a].[alt_custid1], [a].[alt_custid1]=[a].[alt_custid1], [Expr1013]=62)) 24 39 20 Compute Scalar Compute Scalar DEFINE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[alt_custid1]=[a].[alt_custid1], [a].[alt_custid1]=[a].[alt_custid1], [Expr1013]=62) [a].[alt_custid1]=[a].[alt_custid1], [a].[alt_custid1]=[a].[alt_custid1], [Expr1013]=62 1 0 0 0 0 [a].[alt_custid1], [a].[alt_custid1], [Expr1013] NULL PLAN_ROW 0 1 1 1 | | |–Constant Scan 24 40 39 Constant Scan Constant Scan NULL NULL 1 0 0 0 0 NULL NULL PLAN_ROW 0 1 1 1 | |–Compute Scalar(DEFINE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[alt_custid2]=[a].[alt_custid2], [a].[alt_custid2]=[a].[alt_custid2], [Expr1016]=62)) 24 56 20 Compute Scalar Compute Scalar DEFINE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[alt_custid2]=[a].[alt_custid2], [a].[alt_custid2]=[a].[alt_custid2], [Expr1016]=62) [a].[alt_custid2]=[a].[alt_custid2], [a].[alt_custid2]=[a].[alt_custid2], [Expr1016]=62 1 0 0 0 0 [a].[alt_custid2], [a].[alt_custid2], [Expr1016] NULL PLAN_ROW 0 1 1 1 | | |–Constant Scan 24 57 56 Constant Scan Constant Scan NULL NULL 1 0 0 0 0 NULL NULL PLAN_ROW 0 1 1 1 | |–Compute Scalar(DEFINE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[alt_custid3]=[a].[alt_custid3], [a].[alt_custid3]=[a].[alt_custid3], [Expr1019]=62)) 24 73 20 Compute Scalar Compute Scalar DEFINE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[alt_custid3]=[a].[alt_custid3], [a].[alt_custid3]=[a].[alt_custid3], [Expr1019]=62) [a].[alt_custid3]=[a].[alt_custid3], [a].[alt_custid3]=[a].[alt_custid3], [Expr1019]=62 1 0 0 0 0 [a].[alt_custid3], [a].[alt_custid3], [Expr1019] NULL PLAN_ROW 0 1 1 1 | | |–Constant Scan 24 74 73 Constant Scan Constant Scan NULL NULL 1 0 0 0 0 NULL NULL PLAN_ROW 0 1 1 1 | |–Compute Scalar(DEFINE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[alt_custid4]=[a].[alt_custid4], [a].[alt_custid4]=[a].[alt_custid4], [Expr1022]=62)) 24 90 20 Compute Scalar Compute Scalar DEFINE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[alt_custid4]=[a].[alt_custid4], [a].[alt_custid4]=[a].[alt_custid4], [Expr1022]=62) [a].[alt_custid4]=[a].[alt_custid4], [a].[alt_custid4]=[a].[alt_custid4], [Expr1022]=62 1 0 0 0 0 [a].[alt_custid4], [a].[alt_custid4], [Expr1022] NULL PLAN_ROW 0 1 1 1 | |–Constant Scan 24 91 90 Constant Scan Constant Scan NULL NULL 1 0 0 0 0 NULL NULL PLAN_ROW 0 1 1 2 |–Clustered Index Seek(OBJECT<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[xxx].[dbo].[usercust].[PK_usercust]), SEEK<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[usercust].[custid] > [Expr1020] AND [usercust].[custid] < [Expr1021]), WHERE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[usercust].[uid]=’username’) ORDERED FORWARD) 24 125 16 Clustered Index Seek Clustered Index Seek OBJECT<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[xxx].[dbo].[usercust].[PK_usercust]), SEEK<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[usercust].[custid] > [Expr1020] AND [usercust].[custid] < [Expr1021]), WHERE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[usercust].[uid]=’username’) ORDERED FORW [usercust].[uid] 1 0.002214241 0.0001238731 42 0.004428481 [usercust].[uid] NULL PLAN_ROW 0 1 </pre id="code"> SQL 2005 (SET STATISTICS PROFILE ON) <pre id="code"> Rows Executes StmtText StmtId NodeId Parent PhysicalOp LogicalOp Argument DefinedValues EstimateRows EstimateIO EstimateCPU AvgRowSize TotalSubtreeCost OutputList Warnings Type Parallel EstimateExecutions ——————– ——————– —————————————————————————————————————————————————————————————————————————————————————- ———– ———– ———– —————————— —————————— —————————————————————————————————————————————————————————————————————————————————————- ————————————————————————————————————————————— ————- ————- ————- ———– —————- ————————————————————————————————————————————— ——– —————————————————————- ——– —————— 1 1 SELECT d.vin, a.lot FROM activity_det d INNER JOIN activity_hdr a on (a.activity_id = d.activity_id) WHERE d.detail_id = ‘3093458’ and (a.facility = ” or exists (select userfacility.uid from userfacility where userfacility.facility = a.facility and u 1 1 0 NULL NULL NULL NULL 1 NULL NULL NULL 32.92748 NULL NULL SELECT 0 NULL 1 1 |–Parallelism(Gather Streams) 1 2 1 Parallelism Gather Streams NULL NULL 1 0 0.02850325 24 32.92748 [d].[vin], [a].[lot] NULL PLAN_ROW 1 1 1 4 |–Nested Loops(Inner Join, WHERE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[xxx].[dbo].[activity_det].[activity_id] as [d].[activity_id]=[xxx].[dbo].[activity_hdr].[activity_id] as [a].[activity_id])) 1 3 2 Nested Loops Inner Join WHERE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[xxx].[dbo].[activity_det].[activity_id] as [d].[activity_id]=[xxx].[dbo].[activity_hdr].[activity_id] as [a].[activity_id]) NULL 1 0 1.810924 24 32.89898 [d].[vin], [a].[lot] NULL PLAN_ROW 1 1 4 4 |–Parallelism(Distribute Streams, Broadcast Partitioning) 1 4 3 Parallelism Distribute Streams NULL NULL 1 0 0.02850346 27 0.03178656 [d].[activity_id], [d].[vin] NULL PLAN_ROW 1 1 1 1 | |–Clustered Index Seek(OBJECT<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[xxx].[dbo].[activity_det].[PK_activity_det] AS [d]), SEEK<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[d].[detail_id]=(309345<img src=’/community/emoticons/emotion-11.gif’ alt=’8)’ />) ORDERED FORWARD) 1 5 4 Clustered Index Seek Clustered Index Seek OBJECT<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[xxx].[dbo].[activity_det].[PK_activity_det] AS [d]), SEEK<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[d].[detail_id]=(309345<img src=’/community/emoticons/emotion-11.gif’ alt=’8)’ />) ORDERED FORWARD [d].[activity_id], [d].[vin] 1 0.003125 0.0001581 27 0.0032831 [d].[activity_id], [d].[vin] NULL PLAN_ROW 0 1 1069710 4 |–Nested Loops(Left Semi Join, OUTER REFERENCES<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[custid], [a].[alt_custid1], [a].[alt_custid2], [a].[alt_custid3], [a].[alt_custid4])) 1 6 3 Nested Loops Left Semi Join OUTER REFERENCES<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[custid], [a].[alt_custid1], [a].[alt_custid2], [a].[alt_custid3], [a].[alt_custid4]) NULL 866470.8 0 2.012138 22 30.79633 [a].[activity_id], [a].[lot] NULL PLAN_ROW 1 1 1069710 4 |–Nested Loops(Left Semi Join, OUTER REFERENCES<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[facility])) 1 7 6 Nested Loops Left Semi Join OUTER REFERENCES<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[a].[facility]) NULL 962745.3 0 2.235708 37 27.35933 [a].[activity_id], [a].[lot], [a].[custid], [a].[alt_custid1], [a].[alt_custid2], [a].[alt_custid3], [a].[alt_custid4] NULL PLAN_ROW 1 1 1069710 4 | |–Clustered Index Scan(OBJECT<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[xxx].[dbo].[activity_hdr].[PK_veh_activity] AS [a])) 1 8 7 Clustered Index Scan Clustered Index Scan OBJECT<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[xxx].[dbo].[activity_hdr].[PK_veh_activity] AS [a]) [a].[activity_id], [a].[facility], [a].[lot], [a].[custid], [a].[alt_custid1], [a].[alt_custid2], [a].[alt_custid3], [a].[alt_custid4] 1069717 22.95201 0.5884228 41 23.54044 [a].[activity_id], [a].[facility], [a].[lot], [a].[custid], [a].[alt_custid1], [a].[alt_custid2], [a].[alt_custid3], [a].[alt_custid4] NULL PLAN_ROW 1 1 1069710 1069710 | |–Concatenation 1 9 7 Concatenation Concatenation NULL NULL 1 0 2E-07 9 1.583181 NULL NULL PLAN_ROW 1 1069717 19517 1069710 | |–Filter(WHERE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />STARTUP EXPR([xxx].[dbo].[activity_hdr].[facility] as [a].[facility]=”))) 1 10 9 Filter Filter WHERE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />STARTUP EXPR([xxx].[dbo].[activity_hdr].[facility] as [a].[facility]=”)) NULL 1 0 4.8E-07 9 1.583181 NULL NULL PLAN_ROW 1 1069717 19517 1069710 | | |–Constant Scan 1 11 10 Constant Scan Constant Scan NULL NULL 1 0 1.157E-06 9 1.069717 NULL NULL PLAN_ROW 1 1069717 1050193 1050193 | |–Clustered Index Seek(OBJECT<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[xxx].[dbo].[userfacility].[PK_userfacility]), SEEK<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[xxx].[dbo].[userfacility].[uid]=’username’ AND [xxx].[dbo].[userfacility].[facility]=[xxx].[dbo].[activity_hdr].[facility] as [a].[facility]) O 1 13 9 Clustered Index Seek Clustered Index Seek OBJECT<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[xxx].[dbo].[userfacility].[PK_userfacility]), SEEK<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[xxx].[dbo].[userfacility].[uid]=’username’ AND [xxx].[dbo].[userfacility].[facility]=[xxx].[dbo].[activity_hdr].[facility] as [a].[facility]) ORDERED FORWARD NULL 1 0.003125 0.0001581 9 32.89898 NULL NULL PLAN_ROW 1 1069717 1069710 1069710 |–Concatenation 1 14 6 Concatenation Concatenation NULL NULL 1 0 6.024692E-07 9 1.424863 NULL NULL PLAN_ROW 1 962745.3 0 1069710 |–Filter(WHERE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />STARTUP EXPR([xxx].[dbo].[activity_hdr].[custid] as [a].[custid]=”))) 1 15 14 Filter Filter WHERE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />STARTUP EXPR([xxx].[dbo].[activity_hdr].[custid] as [a].[custid]=”)) NULL 1 0 4.8E-07 9 1.424863 NULL NULL PLAN_ROW 1 962745.3 0 1069710 | |–Constant Scan 1 16 15 Constant Scan Constant Scan NULL NULL 1 0 1.157E-06 9 1.069717 NULL NULL PLAN_ROW 1 1069717 1069710 1069710 |–Filter(WHERE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[xxx].[dbo].[usercust].[custid]=[xxx].[dbo].[activity_hdr].[custid] as [a].[custid] OR [xxx].[dbo].[usercust].[custid]=[xxx].[dbo].[activity_hdr].[alt_custid1] as [a].[alt_custid1] OR [xxx].[dbo].[usercust].[custid]=[ 1 18 14 Filter Filter WHERE<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[xxx].[dbo].[usercust].[custid]=[xxx].[dbo].[activity_hdr].[custid] as [a].[custid] OR [xxx].[dbo].[usercust].[custid]=[xxx].[dbo].[activity_hdr].[alt_custid1] as [a].[alt_custid1] OR [xxx].[dbo].[usercust].[custid]=[xxx].[dbo].[activity_hdr].[alt_c NULL 5.024693 0 6.628891E-05 9 32.89898 NULL NULL PLAN_ROW 1 962745.3 12836600 1069710 |–Index Spool(SEEK<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[xxx].[dbo].[usercust].[uid]=’username’)) 1 19 18 Index Spool Eager Spool SEEK<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[xxx].[dbo].[usercust].[uid]=’username’) NULL 37.24096 0.03339527 0.001421965 10 32.89898 [xxx].[dbo].[usercust].[custid] NULL PLAN_ROW 1 962745.3 1124 1 |–Clustered Index Scan(OBJECT<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[xxx].[dbo].[usercust].[PK_usercust])) 1 20 19 Clustered Index Scan Clustered Index Scan OBJECT<img src=’/community/emoticons/emotion-6.gif’ alt=’

‘ />[xxx].[dbo].[usercust].[PK_usercust]) [xxx].[dbo].[usercust].[uid], [xxx].[dbo].[usercust].[custid] 1124 0.02979167 0.0013934 20 0.03118507 [xxx].[dbo].[usercust].[uid], [xxx].[dbo].[usercust].[custid] NULL PLAN_ROW 1 1 </pre id="code">

Ran the query with OPTION (FORCE ORDER) in 2005. Didn’t seem to do anything.

Just wanted to update this thread…. I contacted Microsoft Product Support Services and opened a case on
3/16/2006. This was the first time I’ve ever contacted PSS. For $245
I kind of expected them to just come back and say, "Uh, yeah, you’re
gonna have to go ahead and, uh, rewrite your query, dummy." But this
wasn’t the case. The tech was very knowledgeable and accommodating.
I spent a little over an hour on the phone with him trying a few
things but he was getting unexpected results. One of the things we
tried was running the Database Engine Tuning Advisor using just the
troublesome query and applying the recommendations. After this the
query ran slower! I sent a backup of the database to PSS and they ran the query in SQL
2000 & SQL 2005 environments. Here are a couple of emails from
Microsoft updating the status of the case…
3/23/2006

quote:
Hi Sam, Thanks for sharing all the information so far. Here is what I have to
share with you at this stage: ANALYSIS

In SQL 2000, the same query runs faster (less than a second)
because each step in the query is executed only 1 time and 1 row is
returned.
However, in SQL 2005, each step returns 10000+ rows with 10000+
executes, thereby increasing the total execution time to 40+
seconds.
This is evident from the execution plans for the each query.
At this stage, we expect that SQL 2005#%92s behavior is the right
behavior. The number of rows returned and executes should be high.
However, this increases the processing time as well.
The only way to get the execution time down is by trying to
re-write the query more efficiently.

ACTION ITEMS At this stage, this case is being reviewed by my escalation services
team to possible changes in query design. Once I hear from them, I
will share these suggestions with you to test out in your application.
At this stage, we don#%92t suspect this to be a bug. I will continue to keep you posted on this. Thanks Sanchan Sahai Saxena
MCAD.NET, MCSD.NET Microsoft SQL Server Support Team
Product Support Services (PSS) – Charlotte, NC
Phone: 980-776-8952
Hours: M-F 9:00AM – 6:00PM EST

4/3/2006

quote:
Hi Sam, Thank you for your time today to discuss this issue. Please find below
the summary of the issue, as part of our closing email. ISSUE
Your application queries ran slower against SQL 2005 (45+ seconds)
than they did against SQL 2000 (milliseconds). RESOLUTION
We took one query as a sample query and ran some tests in-house. We
found that the executes for each steps were much more for SQL 2005
than they were in SQL 2000. Also, the number of rows returned per
executes were also high in SQL 2005. There was a clustered index scan
in SQL 2005. On further investigation, we found that you might be hitting a known
bug in SQL 2005, wherein we are not able to push the filter criteria
for an index. This bug has been resolved in SP1. We expect SP1 to be out very soon.
You also mentioned that you are currently focusing on other issues and
are okay with waiting for SP1 to be released. At this stage, I will go ahead and archive this case. Also, since this
is a bug, we will mark it as non-decrement for your company. I see
from the case that this was an individual case. How did you pay for
it? Do you have a receipt for the transaction? Do let me know.
Sanchan Sahai Saxena
MCAD.NET, MCSD.NET Microsoft SQL Server Support Team
Product Support Services (PSS) – Charlotte, NC
Phone: 980-776-8952
Hours: M-F 9:00AM – 6:00PM EST

So there you go… It took a little while but Microsoft confirmed it
as a bug. At least on the phone he said it was a bug. In the email
he hedged his bets a little with "might be hitting a known bug". While the case was in process I came up with a workaround for my
query. By massaging the data a little, I was able to eliminate the
OR’s in the where clause. Not really the greatest solution but it
allowed us to move forward with the migration to 2005. Anyway, my experience with PSS was a good one and I learned a few
things while troubleshooting over the phone. -Sam By the way, just to be clear, here’s the query we used to troubleshoot
the problem…
SELECT d.vin
FROM activity_det d
INNER JOIN activity_hdr a on (a.activity_id = d.activity_id)
WHERE d.detail_id = ‘3093458’
and (a.facility = ” or
exists (select userfacility.uid
from userfacility
where userfacility.facility = a.facility
and userfacility.uid = ‘beth’))
and (a.custid = ” or
exists (select usercust.uid
from usercust
where (usercust.custid = a.custid or
usercust.custid = a.alt_custid1 or
usercust.custid = a.alt_custid2 or
usercust.custid = a.alt_custid3 or
usercust.custid = a.alt_custid4)
and usercust.uid = ‘beth’)) edit: readability
edit: added query used to troubleshoot

]]>