问题:
今天在开发的新上线一个功能后,下面SQL消耗了大量的CPU,数据库处一度处于满负荷进行,使用率达到100%.赶紧kill掉了正进行的SQL,以免对其它业务产生影响。
通过测试,发现一个很奇怪的问题,SQL在第一次执行时会很快,在连续执行几次后,一次比一次的慢。
甚至到最后一直挂起在那,产生等待。当停掉后,过会(10分钟左右)再执行,第一次又会变快,如果再连接执行几次,又会出现同样的慢直至挂起问题。
下面是测试结果:
--第一次执行会很快,逻辑读是8000多
--第二次执行会变慢,逻辑读是44513,如下:
SQL> Select *
2 From (Select Task.Order_Id As Od,
3 Task.Task_Type As Tp,
4 Task.Task_Status As Ts,
5 To_Char(Task.Create_Time, 'yyyy-mm-dd hh24:mi:ss') As Ct,
6 Task.Create_User As Cu,
7 To_Char(Task.Handle_Time, 'yyyy-mm-dd hh24:mi:ss') As Ht,
8 Task.Task_User As Sku,
9 Task.Id As Ind,
10 o.Channel_Id
11 From Tk_Taskinfo_Dt Task, Tk_Orders_Dt o
12 Where 1 = 1
13 And Task.Order_Id = o.Odrid
14 And Task_Status <> '0002900001'
15 And Task.Task_User = 'tianyh'
16 And Task.Accept_Time >=
17 To_Date('2012-12-01 00:00:00', 'yyyy-mm-dd hh24:mi:ss')
18 And ((o.Channel_Id = 'QD00002' And
19 Task.Task_Type In
20 ('0002000013', '0002000017', '0002000038', '0002000008',
21 '0002000031', '0002000004', '0002000012', '0002000016',
22 '0002000032', '0002000035', '0002000024', '0002000010',
23 '0002000014', '0002000019', '0002000006', '0002000034',
24 '0002000041')) Or
25 (o.Channel_Id = 'QD00003' And
26 Task.Task_Type In
27 ('0002000041', '0002000004', '0002000010', '0002000012',
28 '0002000034', '0002000006', '0002000019', '0002000008',
29 '0002000031', '0002000014', '0002000017', '0002000016',
30 '0002000024', '0002000013', '0002000035', '0002000038',
31 '0002000032')) Or
32 (o.Channel_Id = 'QD00001' And
33 Task.Task_Type In
34 ('0002000041', '0002000016', '0002000019', '0002000017',
35 '0002000035', '0002000008', '0002000004', '0002000034',
36 '0002000031', '0002000006', '0002000013', '0002000024',
37 '0002000032', '0002000014', '0002000038', '0002000010',
38 '0002000012')))
39 Union All
40 Select Task.Order_Id As Od,
41 Task.Task_Type As Tp,
42 Task.Task_Status As Ts,
43 To_Char(Task.Create_Time, 'yyyy-mm-dd hh24:mi:ss') As Ct,
44 Task.Create_User As Cu,
45 To_Char(Task.Handle_Time, 'yyyy-mm-dd hh24:mi:ss') As Ht,
46 Task.Task_User As Sku,
47 Task.Id As Ind,
48 o.Channel_Id
49 From Tk_Taskinfo_Finish_Dt Task, Tk_Orders_Dt o
50 Where 1 = 1
51 And Task.Order_Id = o.Odrid
52 And Task.Task_User = 'tianyh'
53 And Task.Accept_Time >=
54 To_Date('2012-12-01 00:00:00', 'yyyy-mm-dd hh24:mi:ss')
55 And ((o.Channel_Id = 'QD00002' And
56 Task.Task_Type In
57 ('0002000013', '0002000017', '0002000038', '0002000008',
58 '0002000031', '0002000004', '0002000012', '0002000016',
59 '0002000032', '0002000035', '0002000024', '0002000010',
60 '0002000014', '0002000019', '0002000006', '0002000034',
61 '0002000041')) Or
62 (o.Channel_Id = 'QD00003' And
63 Task.Task_Type In
64 ('0002000041', '0002000004', '0002000010', '0002000012',
65 '0002000034', '0002000006', '0002000019', '0002000008',
66 '0002000031', '0002000014', '0002000017', '0002000016',
67 '0002000024', '0002000013', '0002000035', '0002000038',
68 '0002000032')) Or
69 (o.Channel_Id = 'QD00001' And
70 Task.Task_Type In
71 ('0002000041', '0002000016', '0002000019', '0002000017',
72 '0002000035', '0002000008', '0002000004', '0002000034',
73 '0002000031', '0002000006', '0002000013', '0002000024',
74 '0002000032', '0002000014', '0002000038', '0002000010',
75 '0002000012')))
76 Order By Ct Desc)
77 Where Rownum <= 25;
已选择25行。
执行计划
----------------------
Plan hash value: 523130039
-----------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | Pstart| Pstop |
-----------------------------------------------------------
| 0 | SELECT STATEMENT | | 25 | 2650 | 110 (1)| 00:00:02 | | |
|* 1 | COUNT STOPKEY | | | | | | | |
| 2 | VIEW | | 26 | 2756 | 110 (1)| 00:00:02 | | |
|* 3 | SORT ORDER BY STOPKEY | | 26 | 3496 | 109 (97)| 00:00:02 | | |
| 4 | UNION-ALL | | | | | | | |
| 5 | NESTED LOOPS | | | | | | | |
| 6 | NESTED LOOPS | | 1 | 121 | 4 (0)| 00:00:01 | | |
|* 7 | TABLE ACCESS BY INDEX ROWID | TK_TASKINFO_DT | 1 | 96 | 2 (0)| 00:00:01 | | |
|* 8 | INDEX RANGE SCAN | IDX_TK_TASKINFO3 | 1 | | 1 (0)| 00:00:01 | | |
|* 9 | INDEX UNIQUE SCAN | PK_TK_ORDERS_ODRID | 1 | | 1 (0)| 00:00:01 | | |
|* 10 | TABLE ACCESS BY INDEX ROWID | TK_ORDERS_DT | 1 | 25 | 2 (0)| 00:00:01 | | |
| 11 | NESTED LOOPS | | | | | | | |
| 12 | NESTED LOOPS | | 25 | 3375 | 105 (0)| 00:00:02 | | |
| 13 | INLIST ITERATOR | | | | | | | |
| 14 | TABLE ACCESS BY GLOBAL INDEX ROWID| TK_TASKINFO_FINISH_DT | 84 | 9240 | 47 (0)| 00:00:01 | ROWID | ROWID |
|* 15 | INDEX RANGE SCAN | IDX$$_08700001 | 84 | | 20 (0)| 00:00:01 | | |
|* 16 | INDEX UNIQUE SCAN | PK_TK_ORDERS_ODRID | 1 | | 1 (0)| 00:00:01 | | |
|* 17 | TABLE ACCESS BY INDEX ROWID | TK_ORDERS_DT | 1 | 25 | 2 (0)| 00:00:01 | | |
-----------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
统计信息
----------------------
1 recursive calls
0 db block gets
44513 consistent gets
0 physical reads
116 redo size
4125 bytes sent via SQL*Net to client
531 bytes received via SQL*Net from client
3 SQL*Net roundtrips to/from client
1 sorts (memory)
0 sorts (disk)
25 rows processed
--第三次的执行计划,逻辑读是257654
执行计划
----------------------
Plan hash value: 523130039
-----------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | Pstart| Pstop |
-----------------------------------------------------------
| 0 | SELECT STATEMENT | | 25 | 2650 | 110 (1)| 00:00:02 | | |
|* 1 | COUNT STOPKEY | | | | | | | |
| 2 | VIEW | | 26 | 2756 | 110 (1)| 00:00:02 | | |
|* 3 | SORT ORDER BY STOPKEY | | 26 | 3496 | 109 (97)| 00:00:02 | | |
| 4 | UNION-ALL | | | | | | | |
| 5 | NESTED LOOPS | | | | | | | |
| 6 | NESTED LOOPS | | 1 | 121 | 4 (0)| 00:00:01 | | |
|* 7 | TABLE ACCESS BY INDEX ROWID | TK_TASKINFO_DT | 1 | 96 | 2 (0)| 00:00:01 | | |
|* 8 | INDEX RANGE SCAN | IDX_TK_TASKINFO3 | 1 | | 1 (0)| 00:00:01 | | |
|* 9 | INDEX UNIQUE SCAN | PK_TK_ORDERS_ODRID | 1 | | 1 (0)| 00:00:01 | | |
|* 10 | TABLE ACCESS BY INDEX ROWID | TK_ORDERS_DT | 1 | 25 | 2 (0)| 00:00:01 | | |
| 11 | NESTED LOOPS | | | | | | | |
| 12 | NESTED LOOPS | | 25 | 3375 | 105 (0)| 00:00:02 | | |
| 13 | INLIST ITERATOR | | | | | | | |
| 14 | TABLE ACCESS BY GLOBAL INDEX ROWID| TK_TASKINFO_FINISH_DT | 84 | 9240 | 47 (0)| 00:00:01 | ROWID | ROWID |
|* 15 | INDEX RANGE SCAN | IDX$$_08700001 | 84 | | 20 (0)| 00:00:01 | | |
|* 16 | INDEX UNIQUE SCAN | PK_TK_ORDERS_ODRID | 1 | | 1 (0)| 00:00:01 | | |
|* 17 | TABLE ACCESS BY INDEX ROWID | TK_ORDERS_DT | 1 | 25 | 2 (0)| 00:00:01 | | |
-----------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
统计信息
----------------------
1 recursive calls
0 db block gets
257654 consistent gets
0 physical reads
64 redo size
4125 bytes sent via SQL*Net to client
531 bytes received via SQL*Net from client
3 SQL*Net roundtrips to/from client
1 sorts (memory)
0 sorts (disk)
25 rows processed
--第三次的执行计划,逻辑读是538909
执行计划
----------------------
Plan hash value: 523130039
-----------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | Pstart| Pstop |
-----------------------------------------------------------
| 0 | SELECT STATEMENT | | 25 | 2650 | 110 (1)| 00:00:02 | | |
|* 1 | COUNT STOPKEY | | | | | | | |
| 2 | VIEW | | 26 | 2756 | 110 (1)| 00:00:02 | | |
|* 3 | SORT ORDER BY STOPKEY | | 26 | 3496 | 109 (97)| 00:00:02 | | |
| 4 | UNION-ALL | | | | | | | |
| 5 | NESTED LOOPS | | | | | | | |
| 6 | NESTED LOOPS | | 1 | 121 | 4 (0)| 00:00:01 | | |
|* 7 | TABLE ACCESS BY INDEX ROWID | TK_TASKINFO_DT | 1 | 96 | 2 (0)| 00:00:01 | | |
|* 8 | INDEX RANGE SCAN | IDX_TK_TASKINFO3 | 1 | | 1 (0)| 00:00:01 | | |
|* 9 | INDEX UNIQUE SCAN | PK_TK_ORDERS_ODRID | 1 | | 1 (0)| 00:00:01 | | |
|* 10 | TABLE ACCESS BY INDEX ROWID | TK_ORDERS_DT | 1 | 25 | 2 (0)| 00:00:01 | | |
| 11 | NESTED LOOPS | | | | | | | |
| 12 | NESTED LOOPS | | 25 | 3375 | 105 (0)| 00:00:02 | | |
| 13 | INLIST ITERATOR | | | | | | | |
| 14 | TABLE ACCESS BY GLOBAL INDEX ROWID| TK_TASKINFO_FINISH_DT | 84 | 9240 | 47 (0)| 00:00:01 | ROWID | ROWID |
|* 15 | INDEX RANGE SCAN | IDX$$_08700001 | 84 | | 20 (0)| 00:00:01 | | |
|* 16 | INDEX UNIQUE SCAN | PK_TK_ORDERS_ODRID | 1 | | 1 (0)| 00:00:01 | | |
|* 17 | TABLE ACCESS BY INDEX ROWID | TK_ORDERS_DT | 1 | 25 | 2 (0)| 00:00:01 | | |
-----------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
统计信息
----------------------
1 recursive calls
0 db block gets
538909 consistent gets
0 physical reads
0 redo size
4125 bytes sent via SQL*Net to client
531 bytes received via SQL*Net from client
3 SQL*Net roundtrips to/from client
1 sorts (memory)
0 sorts (disk)
25 rows processed
SQL>
--如果再次一直快速连续读,SQL就会挂起,产生长时间的等待。
--但每次的执行计划都是一样的。
解决:
1.尝试对所涉及的表的索引进行rebuild,重新分析表,收缩表,但是效果不大。
2.最终在SQL上加上/*+ rule*/提示,执行计划虽然还是一样,但是不会出现上面多次连续执行SQL产生等待的问题。
如下:
SQL> Select /*+ rule*/ *
2 From (Select Task.Order_Id As Od,
3 Task.Task_Type As Tp,
4 Task.Task_Status As Ts,
5 To_Char(Task.Create_Time, 'yyyy-mm-dd hh24:mi:ss') As Ct,
6 Task.Create_User As Cu,
7 To_Char(Task.Handle_Time, 'yyyy-mm-dd hh24:mi:ss') As Ht,
8 Task.Task_User As Sku,
9 Task.Id As Ind,
10 o.Channel_Id
11 From Tk_Taskinfo_Dt Task, Tk_Orders_Dt o
......
......
结论:
通过oracle CBO查询SQL会产生等待
通过oracle RBO查询SQL会得到很好效果。
不过具体原因还有待研究,而且通过使用RBO后,随着数据量的变量,不知会不会效率变得低下,还有待观察。
通过查找参考,发现有位网友也出现过同样的问题,只不过他第二次查询的执行计划是变了,我这里还是同样的执行计划。
http://blog.sina.com.cn/s/blog_62e039f00100yvs1.html