【发布时间】:2017-12-12 20:18:17
【问题描述】:
Oracle 数据库 11g 版本 11.2.0.4.0 - 64 位生产
已解决:是由基数反馈引起的。我以为我之前已经测试过并消除了它,但显然弄错了。
将此添加到查询中:
select --+ opt_param('_optimizer_use_feedback' 'false')
现在一直很快。
我有一个奇怪的情况,查询似乎在前 2 次执行中运行得相当快,然后在后续执行中慢得多。我正在使用带有“设置自动跟踪”的 sqlplus 来获取查询计划,并且对于每次运行,计划都是相同的(相同的行估计等)。最后的自动跟踪统计显示在后续执行中读取了更多数据。
如果我在语法上更改查询(只需添加或删除 cmets 即可),以便它可能是 SQL 缓存中的新查询,那么它会快速运行两次,然后再缓慢运行。如果我将它改回我之前使用过的查询版本(因此在缓存中),那么它总是很慢。
我认为它与cardinality feedback 无关,因为:
- 我已尝试禁用此功能,但没有任何效果
- 所有执行的计划都是相同的
那么接下来我该往哪里看呢?我可以使用哪些工具来缩小发生这种情况的范围?
这是我正在测试的查询:
set timing on
set autotrace on
select distinct
cc2.circuit_id as circuit_id
, cc2.circuit_component_id as component_circuit_id
from bsdb.bs_instance si
join bsdb.bs_location_schedule ls
on ls.bs_instance_id = si.id
and coalesce(ls.terminated_date, sysdate) >= sysdate
join npc.npc_customer_service cs
on cs.bs_location_schedule_id = ls.id
and cs.circuit_status_id in (1, 2, 6)
join tdb.loc_site_code lsc
on lsc.id = ls.site_code_id
left outer join scdb.brand br
on br.id = si.brand_id
join tdb.organisation o
on o.org_code = coalesce(br.brand_org_code, si.client_org_code)
and o.org_code = 2421
join npc.npc_customer_service_circuit csc
on csc.customer_service_id = cs.customer_service_id
and coalesce(csc.end_date, sysdate) >= sysdate
join npc.npc_circuit_component cc
on cc.circuit_id = csc.circuit_id
and coalesce(cc.end_date, sysdate) >= sysdate
join npc.npc_circuit_hierarchy ch
on ch.sub_circuit_id = cc.circuit_component_id
join npc.npc_circuit_component cc2
on cc2.circuit_id = ch.master_circuit_id
and coalesce(cc2.end_date, sysdate) >= sysdate
;
如果我删除 scdb.brand 的外连接(在此特定情况下不需要,但通常用于此查询),则性能在多次运行中是快速且一致的。
自动跟踪输出,包括计划,快速运行:
109 rows selected.
Elapsed: 00:00:00.51
Execution Plan
Plan hash value: 2956052167
--------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 173 | 18857 | 2069 (6)| 00:00:07 |
| 1 | HASH UNIQUE | | 173 | 18857 | 2069 (6)| 00:00:07 |
|* 2 | FILTER | | | | | |
|* 3 | HASH JOIN OUTER | | 173 | 18857 | 2068 (6)| 00:00:07 |
|* 4 | HASH JOIN | | 173 | 17473 | 2063 (6)| 00:00:07 |
|* 5 | HASH JOIN | | 173 | 15397 | 2000 (6)| 00:00:07 |
| 6 | NESTED LOOPS | | 244 | 18056 | 1297 (2)| 00:00:05 |
| 7 | NESTED LOOPS | | 249 | 18056 | 1297 (2)| 00:00:05 |
| 8 | NESTED LOOPS | | 249 | 15438 | 799 (3)| 00:00:03 |
|* 9 | HASH JOIN | | 205 | 9635 | 183 (9)| 00:00:01 |
|* 10 | HASH JOIN | | 280 | 8960 | 110 (5)| 00:00:01 |
|* 11 | TABLE ACCESS FULL | BS_LOCATION_SCHEDULE | 695 | 12510 | 44 (7)| 00:00:01 |
| 12 | NESTED LOOPS | | 3452 | 48328 | 66 (4)| 00:00:01 |
|* 13 | INDEX UNIQUE SCAN | ORGANISATION__PK | 1 | 4 | 1 (0)| 00:00:01 |
|* 14 | TABLE ACCESS FULL | NPC_CUSTOMER_SERVICE | 3452 | 34520 | 65 (4)| 00:00:01 |
|* 15 | TABLE ACCESS FULL | NPC_CUSTOMER_SERVICE_CIRCUIT | 2531 | 37965 | 72 (13)| 00:00:01 |
|* 16 | TABLE ACCESS BY INDEX ROWID| NPC_CIRCUIT_COMPONENT | 1 | 15 | 3 (0)| 00:00:01 |
|* 17 | INDEX RANGE SCAN | NPC_CIRCUIT_COMPONENT_I01 | 9 | | 2 (0)| 00:00:01 |
|* 18 | INDEX UNIQUE SCAN | NPC_CIRCUIT_HIERARCHY_I02 | 1 | | 1 (0)| 00:00:01 |
| 19 | TABLE ACCESS BY INDEX ROWID | NPC_CIRCUIT_HIERARCHY | 1 | 12 | 2 (0)| 00:00:01 |
|* 20 | TABLE ACCESS FULL | NPC_CIRCUIT_COMPONENT | 23529 | 344K| 702 (13)| 00:00:03 |
| 21 | TABLE ACCESS FULL | BS_INSTANCE | 13483 | 158K| 63 (2)| 00:00:01 |
| 22 | TABLE ACCESS FULL | BRAND | 1246 | 9968 | 5 (0)| 00:00:01 |
--------------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - filter(COALESCE("BR"."BRAND_ORG_CODE","SI"."CLIENT_ORG_CODE")=2421)
3 - access("BR"."ID"(+)="SI"."BRAND_ID")
4 - access("LS"."BS_INSTANCE_ID"="SI"."ID")
5 - access("CC2"."CIRCUIT_ID"="CH"."MASTER_CIRCUIT_ID")
9 - access("CSC"."CUSTOMER_SERVICE_ID"="CS"."CUSTOMER_SERVICE_ID")
10 - access("CS"."BS_LOCATION_SCHEDULE_ID"="LS"."ID")
11 - filter(COALESCE("LS"."TERMINATED_DATE",SYSDATE@!)>=SYSDATE@! AND "LS"."SITE_CODE_ID" IS NOT NULL)
13 - access("O"."ORG_CODE"=2421)
14 - filter("CS"."BS_LOCATION_SCHEDULE_ID" IS NOT NULL AND ("CS"."CIRCUIT_STATUS_ID"=1 OR
"CS"."CIRCUIT_STATUS_ID"=2 OR "CS"."CIRCUIT_STATUS_ID"=6))
15 - filter(COALESCE("CSC"."END_DATE",SYSDATE@!)>=SYSDATE@!)
16 - filter(COALESCE("CC"."END_DATE",SYSDATE@!)>=SYSDATE@!)
17 - access("CC"."CIRCUIT_ID"="CSC"."CIRCUIT_ID")
18 - access("CH"."SUB_CIRCUIT_ID"="CC"."CIRCUIT_COMPONENT_ID")
20 - filter(COALESCE("CC2"."END_DATE",SYSDATE@!)>=SYSDATE@!)
Statistics
29 recursive calls
0 db block gets
45368 consistent gets
0 physical reads
0 redo size
3423 bytes sent via SQL*Net to client
576 bytes received via SQL*Net from client
9 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
109 rows processed
自动跟踪输出,包括计划,慢速运行:
109 rows selected.
Elapsed: 00:00:02.67
Execution Plan
Plan hash value: 2956052167
--------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 173 | 18857 | 2069 (6)| 00:00:07 |
| 1 | HASH UNIQUE | | 173 | 18857 | 2069 (6)| 00:00:07 |
|* 2 | FILTER | | | | | |
|* 3 | HASH JOIN OUTER | | 173 | 18857 | 2068 (6)| 00:00:07 |
|* 4 | HASH JOIN | | 173 | 17473 | 2063 (6)| 00:00:07 |
|* 5 | HASH JOIN | | 173 | 15397 | 2000 (6)| 00:00:07 |
| 6 | NESTED LOOPS | | 244 | 18056 | 1297 (2)| 00:00:05 |
| 7 | NESTED LOOPS | | 249 | 18056 | 1297 (2)| 00:00:05 |
| 8 | NESTED LOOPS | | 249 | 15438 | 799 (3)| 00:00:03 |
|* 9 | HASH JOIN | | 205 | 9635 | 183 (9)| 00:00:01 |
|* 10 | HASH JOIN | | 280 | 8960 | 110 (5)| 00:00:01 |
|* 11 | TABLE ACCESS FULL | BS_LOCATION_SCHEDULE | 695 | 12510 | 44 (7)| 00:00:01 |
| 12 | NESTED LOOPS | | 3452 | 48328 | 66 (4)| 00:00:01 |
|* 13 | INDEX UNIQUE SCAN | ORGANISATION__PK | 1 | 4 | 1 (0)| 00:00:01 |
|* 14 | TABLE ACCESS FULL | NPC_CUSTOMER_SERVICE | 3452 | 34520 | 65 (4)| 00:00:01 |
|* 15 | TABLE ACCESS FULL | NPC_CUSTOMER_SERVICE_CIRCUIT | 2531 | 37965 | 72 (13)| 00:00:01 |
|* 16 | TABLE ACCESS BY INDEX ROWID| NPC_CIRCUIT_COMPONENT | 1 | 15 | 3 (0)| 00:00:01 |
|* 17 | INDEX RANGE SCAN | NPC_CIRCUIT_COMPONENT_I01 | 9 | | 2 (0)| 00:00:01 |
|* 18 | INDEX UNIQUE SCAN | NPC_CIRCUIT_HIERARCHY_I02 | 1 | | 1 (0)| 00:00:01 |
| 19 | TABLE ACCESS BY INDEX ROWID | NPC_CIRCUIT_HIERARCHY | 1 | 12 | 2 (0)| 00:00:01 |
|* 20 | TABLE ACCESS FULL | NPC_CIRCUIT_COMPONENT | 23529 | 344K| 702 (13)| 00:00:03 |
| 21 | TABLE ACCESS FULL | BS_INSTANCE | 13483 | 158K| 63 (2)| 00:00:01 |
| 22 | TABLE ACCESS FULL | BRAND | 1246 | 9968 | 5 (0)| 00:00:01 |
--------------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - filter(COALESCE("BR"."BRAND_ORG_CODE","SI"."CLIENT_ORG_CODE")=2421)
3 - access("BR"."ID"(+)="SI"."BRAND_ID")
4 - access("LS"."BS_INSTANCE_ID"="SI"."ID")
5 - access("CC2"."CIRCUIT_ID"="CH"."MASTER_CIRCUIT_ID")
9 - access("CSC"."CUSTOMER_SERVICE_ID"="CS"."CUSTOMER_SERVICE_ID")
10 - access("CS"."BS_LOCATION_SCHEDULE_ID"="LS"."ID")
11 - filter(COALESCE("LS"."TERMINATED_DATE",SYSDATE@!)>=SYSDATE@! AND "LS"."SITE_CODE_ID" IS NOT NULL)
13 - access("O"."ORG_CODE"=2421)
14 - filter("CS"."BS_LOCATION_SCHEDULE_ID" IS NOT NULL AND ("CS"."CIRCUIT_STATUS_ID"=1 OR
"CS"."CIRCUIT_STATUS_ID"=2 OR "CS"."CIRCUIT_STATUS_ID"=6))
15 - filter(COALESCE("CSC"."END_DATE",SYSDATE@!)>=SYSDATE@!)
16 - filter(COALESCE("CC"."END_DATE",SYSDATE@!)>=SYSDATE@!)
17 - access("CC"."CIRCUIT_ID"="CSC"."CIRCUIT_ID")
18 - access("CH"."SUB_CIRCUIT_ID"="CC"."CIRCUIT_COMPONENT_ID")
20 - filter(COALESCE("CC2"."END_DATE",SYSDATE@!)>=SYSDATE@!)
Statistics
0 recursive calls
0 db block gets
82317 consistent gets
0 physical reads
0 redo size
3423 bytes sent via SQL*Net to client
577 bytes received via SQL*Net from client
9 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
109 rows processed
tkprof 输出,快速运行:
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.05 0.05 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 9 0.59 0.59 0 65896 0 109
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 11 0.64 0.64 0 65896 0 109
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 631
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
109 109 109 HASH UNIQUE (cr=65896 pr=0 pw=0 time=596536 us cost=2069 size=18857 card=173)
192 192 192 FILTER (cr=65896 pr=0 pw=0 time=629952 us)
25244 25244 25244 HASH JOIN OUTER (cr=65896 pr=0 pw=0 time=595042 us cost=2068 size=18857 card=173)
25244 25244 25244 HASH JOIN (cr=65874 pr=0 pw=0 time=579863 us cost=2063 size=17473 card=173)
25244 25244 25244 HASH JOIN (cr=65501 pr=0 pw=0 time=408409 us cost=2000 size=15397 card=173)
12247 12247 12247 NESTED LOOPS (cr=61723 pr=0 pw=0 time=338753 us cost=1297 size=18056 card=244)
12247 12247 12247 NESTED LOOPS (cr=49476 pr=0 pw=0 time=276466 us cost=1297 size=18056 card=249)
16700 16700 16700 NESTED LOOPS (cr=24758 pr=0 pw=0 time=232395 us cost=799 size=15438 card=249)
12630 12630 12630 HASH JOIN (cr=995 pr=0 pw=0 time=59090 us cost=183 size=9635 card=205)
5558 5558 5558 HASH JOIN (cr=622 pr=0 pw=0 time=36847 us cost=110 size=8960 card=280)
8984 8984 8984 TABLE ACCESS FULL BS_LOCATION_SCHEDULE (cr=247 pr=0 pw=0 time=6835 us cost=44 size=12510 card=695)
5653 5653 5653 NESTED LOOPS (cr=375 pr=0 pw=0 time=7076 us cost=66 size=48328 card=3452)
1 1 1 INDEX UNIQUE SCAN ORGANISATION__PK (cr=2 pr=0 pw=0 time=38 us cost=1 size=4 card=1)(object id 98786)
5653 5653 5653 TABLE ACCESS FULL NPC_CUSTOMER_SERVICE (cr=373 pr=0 pw=0 time=5278 us cost=65 size=34520 card=3452)
32022 32022 32022 TABLE ACCESS FULL NPC_CUSTOMER_SERVICE_CIRCUIT (cr=373 pr=0 pw=0 time=25562 us cost=72 size=37965 card=2531)
16700 16700 16700 TABLE ACCESS BY INDEX ROWID NPC_CIRCUIT_COMPONENT (cr=23763 pr=0 pw=0 time=131644 us cost=3 size=15 card=1)
17448 17448 17448 INDEX RANGE SCAN NPC_CIRCUIT_COMPONENT_I01 (cr=17401 pr=0 pw=0 time=61607 us cost=2 size=0 card=9)(object id 4306712)
12247 12247 12247 INDEX UNIQUE SCAN NPC_CIRCUIT_HIERARCHY_I02 (cr=24718 pr=0 pw=0 time=78582 us cost=1 size=0 card=1)(object id 4306727)
12247 12247 12247 TABLE ACCESS BY INDEX ROWID NPC_CIRCUIT_HIERARCHY (cr=12247 pr=0 pw=0 time=51413 us cost=2 size=12 card=1)
324238 324238 324238 TABLE ACCESS FULL NPC_CIRCUIT_COMPONENT (cr=3778 pr=0 pw=0 time=161012 us cost=702 size=352935 card=23529)
13529 13529 13529 TABLE ACCESS FULL BS_INSTANCE (cr=373 pr=0 pw=0 time=5917 us cost=63 size=161796 card=13483)
1271 1271 1271 TABLE ACCESS FULL BRAND (cr=22 pr=0 pw=0 time=542 us cost=5 size=9968 card=1246)
********************************************************************************
tkprof 输出,运行缓慢:
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 9 5.66 5.66 0 82317 0 109
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 11 5.66 5.66 0 82317 0 109
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 631
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
109 109 109 HASH UNIQUE (cr=82317 pr=0 pw=0 time=5667122 us cost=16766 size=16723107 card=153423)
192 192 192 FILTER (cr=82317 pr=0 pw=0 time=5865780 us)
25244 25244 25244 HASH JOIN RIGHT OUTER (cr=82317 pr=0 pw=0 time=5595368 us cost=13509 size=16723107 card=153423)
1271 1271 1271 TABLE ACCESS FULL BRAND (cr=22 pr=0 pw=0 time=315 us cost=5 size=9968 card=1246)
25244 25244 25244 HASH JOIN (cr=82295 pr=0 pw=0 time=5582567 us cost=13501 size=15495723 card=153423)
13529 13529 13529 TABLE ACCESS FULL BS_INSTANCE (cr=373 pr=0 pw=0 time=6801 us cost=63 size=161796 card=13483)
25244 25244 25244 HASH JOIN (cr=81922 pr=0 pw=0 time=5561289 us cost=13435 size=13654647 card=153423)
8984 8984 8984 TABLE ACCESS FULL BS_LOCATION_SCHEDULE (cr=247 pr=0 pw=0 time=5118 us cost=44 size=161712 card=8984)
25388 25388 25388 HASH JOIN (cr=81675 pr=0 pw=0 time=5568466 us cost=13388 size=10893033 card=153423)
12343 12343 12343 HASH JOIN (cr=77897 pr=0 pw=0 time=7626696 us cost=12679 size=1423744 card=25424)
16798 16798 16798 HASH JOIN (cr=4526 pr=0 pw=0 time=217551 us cost=848 size=1139336 card=25894)
12751 12751 12751 HASH JOIN (cr=748 pr=0 pw=0 time=21460 us cost=139 size=124439 card=4291)
5653 5653 5653 NESTED LOOPS (cr=375 pr=0 pw=0 time=4514 us cost=66 size=48328 card=3452)
1 1 1 INDEX UNIQUE SCAN ORGANISATION__PK (cr=2 pr=0 pw=0 time=22 us cost=1 size=4 card=1)(object id 98786)
5653 5653 5653 TABLE ACCESS FULL NPC_CUSTOMER_SERVICE (cr=373 pr=0 pw=0 time=3612 us cost=65 size=34520 card=3452)
32022 32022 32022 TABLE ACCESS FULL NPC_CUSTOMER_SERVICE_CIRCUIT (cr=373 pr=0 pw=0 time=13825 us cost=72 size=480330 card=32022)
324238 324238 324238 TABLE ACCESS FULL NPC_CIRCUIT_COMPONENT (cr=3778 pr=0 pw=0 time=112639 us cost=703 size=4863570 card=324238)
24918733 24918733 24918733 INDEX FAST FULL SCAN NPC_CIRCUIT_HIERARCHY_U01 (cr=73371 pr=0 pw=0 time=3349816 us cost=11418 size=292240992 card=24353416)(object id 4306730)
324238 324238 324238 TABLE ACCESS FULL NPC_CIRCUIT_COMPONENT (cr=3778 pr=0 pw=0 time=95358 us cost=703 size=4863570 card=324238)
********************************************************************************
所以慢查询其实是在使用不同的plan,但是这个plan和autotrace显示的不一样。仍然很想知道为什么它在两次运行后会发生变化。
我想我会尝试重写查询以消除外部连接,方法是将其拆分为两个由联合连接的单独查询。
编辑 1:添加查询
编辑 2:添加自动跟踪输出
编辑 3:从测试查询中删除 with()、对偶、1=1
编辑 4:添加 tkprof 输出
编辑 5:原来是基数反馈
【问题讨论】:
-
你能显示查询(或示例)吗?
-
尝试跟踪查询并特别注意递归查询。例如,您提到了基数反馈。如果查询计划的注释部分没有提到基数反馈,那么它就没有使用它来更改计划。 但是,在 Oracle 做出决定之前,它可能需要生成一个递归 SQL 语句来检查是否需要基数反馈。该递归 SQL 语句可能需要调整;也许有错误的字典或固定的对象统计信息。
-
揭示一个隐藏假设的一个问题 - 每个查询运行是否使用相同的绑定参数?或者也许不同?如果参数不同,则相同的递归查询可以在结果中给出完全不同的记录数量,具体取决于隐藏在给定参数下的树的大小,因此尽管计划相同,但执行时间也会有很大差异。
-
测试查询未使用绑定参数(prod 使用)。我已经替换了这个测试的实际值,因此不应该有任何计划/性能变化。
-
“一致获取”在第二次运行中高出一个数量级。出于某种原因,它正在读取更多数据。 (从记忆中,但仍然阅读。)我还注意到你有内连接在左连接之后。我通常建议避免这种情况,因为它会使连接的推理变得更加困难。 (我什至不确定数据库是如何处理它的。)
标签: oracle oracle11g recursive-query