SQL Server Performance

poor query performance [update: MS says bug]

Discussion in 'SQL Server 2005 General DBA Questions' started by fwa, Mar 14, 2006.

  1. fwa New Member

    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?
  2. joechang New Member

    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
  3. fwa New Member

    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
  4. mmarovic Active Member

    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.
  5. Luis Martin Moderator

    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.



  6. fwa New Member

    mmarovic - thanks for the tips. I had hoped to avoid it but <br />am beginning to think that a LOT of the queries will need to <br />be rewritten. This is just one example of many.<br /><br />I understand the query I posted isn't the prettiest thing and <br />I never said it was written "correctly". I didn't even say <br />whether or not I wrote it <img src='/community/emoticons/emotion-1.gif' alt=':)' /> ! My dilema is that I've got <br />a piece of code that runs about 650 times slower on a server <br />that's twice as powerful. That's hard to explain to the client.<br />I was really hoping I'd see a big improvement just by moving to <br />a faster server and newer database without having to change a <br />thing. The fact that I'm not even getting the same performance <br />is really disappointing.<br /><br />I'm reaching but, is there a chance that the statistics are <br />screwed up some how?<br /><br />There's not enough activity on the 2005 database to generate a <br />"good" trace file. If I run the Database Engine Tuning Advisor, <br />is there a way to feed it a sql 2000 trace file?<br /><br />Thanks for the input. <br /><br />
  7. joechang New Member

    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
  8. mmarovic Active Member

    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.
  9. mmarovic Active Member

    <blockquote id="quote"><font size="1" face="Verdana, Arial, Helvetica" id="quote">quote:<hr height="1" noshade id="quote"><i>Originally posted by fwa</i><br /><br />mmarovic - thanks for the tips. I had hoped to avoid it but <br />am beginning to think that a LOT of the queries will need to <br />be rewritten. This is just one example of many.<br /><br />I understand the query I posted isn't the prettiest thing and <br />I never said it was written "correctly". I didn't even say <br />whether or not I wrote it <img src='/community/emoticons/emotion-1.gif' alt=':)' /> ! My dilema is that I've got <br />a piece of code that runs about 650 times slower on a server <br />that's twice as powerful. That's hard to explain to the client.<br />I was really hoping I'd see a big improvement just by moving to <br />a faster server and newer database without having to change a <br />thing. The fact that I'm not even getting the same performance <br />is really disappointing.<hr height="1" noshade id="quote"></font 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.<br /><br /><blockquote id="quote"><font size="1" face="Verdana, Arial, Helvetica" id="quote">quote:<hr height="1" noshade id="quote">There's not enough activity on the 2005 database to generate a <br />"good" trace file. If I run the Database Engine Tuning Advisor, <br />is there a way to feed it a sql 2000 trace file?<hr height="1" noshade id="quote"></font 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.<br /><br />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.<br />
  10. fwa New Member

    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
  11. joechang New Member

    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
  12. fwa New Member

    Here are the execution plans...<br /><br /><br /><br /><b>SQL 2000 (SET SHOWPLAN_ALL ON)</b><br /><pre id="code"><font face="courier" size="2" id="code"><br />Rows Executes StmtText StmtId NodeId Parent PhysicalOp LogicalOp Argument DefinedValues EstimateRows EstimateIO EstimateCPU AvgRowSize TotalSubtreeCost OutputList Warnings Type Parallel EstimateExecutions<br />----------- ----------- ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ----------- ----------- ----------- ------------------------------ ------------------------------ ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------ -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ------------- ------------- ------------- ----------- ---------------- ------------------------------------------------------------------------------------------------------------------------------------------- -------- ------------------------------ -------- ------------------<br />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<br />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<br />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<br />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<br />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<br />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<br />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<br />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<br />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<br />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<br />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<br />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<br />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<br />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<br />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<br />1 1 | | |--Constant Scan 24 23 22 Constant Scan Constant Scan NULL NULL 1 0 0 0 0 NULL NULL PLAN_ROW 0 1<br />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<br />1 1 | | |--Constant Scan 24 40 39 Constant Scan Constant Scan NULL NULL 1 0 0 0 0 NULL NULL PLAN_ROW 0 1<br />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<br />1 1 | | |--Constant Scan 24 57 56 Constant Scan Constant Scan NULL NULL 1 0 0 0 0 NULL NULL PLAN_ROW 0 1<br />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<br />1 1 | | |--Constant Scan 24 74 73 Constant Scan Constant Scan NULL NULL 1 0 0 0 0 NULL NULL PLAN_ROW 0 1<br />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<br />1 1 | |--Constant Scan 24 91 90 Constant Scan Constant Scan NULL NULL 1 0 0 0 0 NULL NULL PLAN_ROW 0 1<br />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] &gt; [Expr1020] AND [usercust].[custid] &lt; [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] &gt; [Expr1020] AND [usercust].[custid] &lt; [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<br /></font id="code"></pre id="code"><br /><br /><br /><br /><br /><br /><br /><b>SQL 2005 (SET STATISTICS PROFILE ON)</b><br /><pre id="code"><font face="courier" size="2" id="code"><br />Rows Executes StmtText StmtId NodeId Parent PhysicalOp LogicalOp Argument DefinedValues EstimateRows EstimateIO EstimateCPU AvgRowSize TotalSubtreeCost OutputList Warnings Type Parallel EstimateExecutions<br />-------------------- -------------------- ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ----------- ----------- ----------- ------------------------------ ------------------------------ ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- --------------------------------------------------------------------------------------------------------------------------------------- ------------- ------------- ------------- ----------- ---------------- --------------------------------------------------------------------------------------------------------------------------------------- -------- ---------------------------------------------------------------- -------- ------------------<br />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<br />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<br />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<br />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<br />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<br />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<br />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<br />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<br />1069710 1069710 | |--Concatenation 1 9 7 Concatenation Concatenation NULL NULL 1 0 2E-07 9 1.583181 NULL NULL PLAN_ROW 1 1069717<br />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<br />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<br />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<br />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<br />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<br />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<br />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<br />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<br />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<br /></font id="code"></pre id="code">
  13. fwa New Member

    Ran the query with OPTION (FORCE ORDER) in 2005. Didn't seem to do anything.
  14. fwa New Member

    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

Share This Page