事情的经过是这样:
某日某菜鸟dba在巡检生产数据库时发现alert log出现如下错误:
ORA-00600: internal error code, arguments: [qkabix], [0], [], [], [], [], [], []
经过检查相应的trace file和在metalink上搜索和比对相应的执行计划,发现和某一未经过确认的bug相类似
参见 Doc ID:743212.1
Cause
The problem could be related to a CBO ( Cost Based Optimizer ) issue when a query uses a bitmap access paths for b-tree indexes.
It is reported in Bug 5945798 but not confirmed.
Solution
One possible workaround to avoid the error is to disable the optimizer to produce bitmap plans for B-Tree indexes even if
there is no bitmap index anywhere in sight:
- at session level
sql> alter session set "_b_tree_bitmap_plans"=false;
- or at system level
sql> alter system set "_b_tree_bitmap_plans"=false;
- or in the init.ora
_b_tree_bitmap_plans = false
菜鸟惊呼:哇塞,我的系统也能出现如此高档,如此牛逼闪闪,如此(此处为响应祖国六十华诞,自行省略若千字)。。。的bug?这不是我梦寐已久,连做春梦都会在头脑中闪现的场景么?难道上天终于开了眼,要眷顾一下我这个小菜鸟?
于是乎,他大胆的做出一个决定,修改此隐藏参数:
alter system set "_b_tree_bitmap_plans"=false scope=both sid='racn1';
故事到这里就结束了吗? 不,这显然不合乎常理,冥冥之中,菜鸟总感觉会发生点什么,但是他又说不清楚,就想看王家卫的电影一样,总感觉电影想要放个屁出来,但往往等了90分钟后,却连个屁也没等到,甚至连口臭味都没有闻到,于是觉得导演的这个屁肯定是在不经意间就放出来了,但是无奈吾等众生天资愚钝,未能领会到大师的屁意,让这人间美屁就这样流逝掉,实在是暴殄天物。但是转念一想,我们花了90分钟的生命,不管花没花银子,我们至少该得到些什么啊?浑身上下一摸,连根毛都没多,最后终于恍然大悟:原来我们是被这种欲屁还休的手段足足忽悠了足足90分钟,到头来还被电影屁服的屁滚尿流。
扯远了。。。
就在修改完参数的第二天,菜鸟像往常一样打开灰常牛逼闪闪的工具secureCRT,曾经有菜菜鸟问过菜鸟,secureCRT和CRT有什么分别?菜鸟虽菜,但是英文不烂,再加上入行也有些日子了,自然是对菜菜鸟这样的鸟问题十分不屑:“secureCRT都不知道?你英文也太烂了,CRT+secure 就是加长加宽加安全版的CRT,知道了不?”。菜菜鸟还是一头雾水:“secure是安全我知道了,但加长和加宽是如何理解呢?”,菜鸟一脸的牛逼样,手指在菜菜鸟的鼻子上点啊点的:“你个菜鸟,secure+CRT自然是比CRT要宽了吧,你再换个角度,不就比CRT要长了嘛”。
又扯远了。。。
菜鸟的手指熟练在键盘上击打着,随着手臂的移动,上上下下左左右右bbaa,仿佛是在钢琴边弹奏着一首美妙的曲子,无数个日日夜夜,当别人花天酒地灯红酒绿,当别人酣酣入睡沉入梦乡,菜鸟都依然坚守在他的键盘前,一刻也不停息的敲着打着,仿佛键盘就是菜鸟的恋人,他熟悉恋人身上的任何一个部位,任何一个细节,这些部位和细节,他都触摸过无数遍,菜鸟不用去看键盘,他甚至不用去考虑自己的手指的位置,但此刻,菜鸟的手却停住了,他的左手食指和无名指与右手的中指和食指分别停在了CaiB这四个键上。
就在secureCRT上,随着vmstat -wt 1的敲下,菜鸟看到了一个令他震惊的现象,id列居然降到了30,在早上这个时间段,id列应该是在80以上才正常啊,莫非,系统也有晨勃的习惯?ps auxw|sort -rn +2|head -30显示有一个LOCAL=NO的oracle进程一直占据着第一位,通过pid去数据库查找,发现此sql:
SQL> SELECT sms_id, cha_content, MESSAGE
2 FROM callcenter.t_sms_sndqueue
3 WHERE ( sms_sta_id = 5
4 AND on_dat > TO_CHAR (SYSDATE - 1, 'YYYY-MM-DD HH24:MI:SS')
5 )
6 OR (sms_sta_id = 2 OR sms_sta_id = 6)
7 AND on_dat BETWEEN TO_CHAR (SYSDATE - 4 * 3600 / 86400,
8 'YYYY-MM-DD HH24:MI:SS'
9 )
10 AND TO_CHAR (SYSDATE - 900 / 86400,
11 'YYYY-MM-DD HH24:MI:SS'
12 )
13 AND ROWNUM < 30;
12 rows selected.
Execution Plan
----------------------------------------------------------
Plan hash value: 338642532
--------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 3228K| 443M| 21616 (1)| 00:04:20 |
| 1 | COUNT | | | | | |
|* 2 | FILTER | | | | | |
| 3 | TABLE ACCESS FULL| T_SMS_SNDQUEUE | 3228K| 443M| 21616 (1)| 00:04:20 |
--------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - filter("SMS_STA_ID"=5 AND "ON_DAT">TO_CHAR(SYSDATE@!-1,'YYYY-MM-DD
HH24:MI:SS') OR ("SMS_STA_ID"=2 OR "SMS_STA_ID"=6) AND
"ON_DAT">=TO_CHAR(SYSDATE@!-.1666666666666666666666666666666666666667,'YYYY-MM
-DD HH24:MI:SS') AND "ON_DAT"<=TO_CHAR(SYSDATE@!-.0104166666666666666666666666
666666666667,'YYYY-MM-DD HH24:MI:SS') AND ROWNUM<30)
Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
97846 consistent gets
0 physical reads
180 redo size
2069 bytes sent via SQL*Net to client
492 bytes received via SQL*Net from client
2 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
11 rows processed
这个sql显然不是最近新上的玩意,如果这种用字符存储日期的表设计被菜鸟发现,菜鸟肯定会将其否决掉,这个sql显而易见是有问题的,但是问题是,既然不是新上的玩意,那为何这个sql之前没有问题呢?菜鸟想到了那个该死的隐藏参数,难道加了参数以后导致了执行计划的改变?
将参数改回原来的值后:
Execution Plan
----------------------------------------------------------
Plan hash value: 3230192025
-------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
-------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 3228K| 443M| 7 (29)| 00:00:01 |
| 1 | COUNT | | | | | |
|* 2 | FILTER | | | | | |
| 3 | TABLE ACCESS BY INDEX ROWID | T_SMS_SNDQUEUE | 3228K| 443M| 7 (29)| 00:00:01 |
| 4 | BITMAP CONVERSION TO ROWIDS | | | | | |
| 5 | BITMAP OR | | | | | |
| 6 | BITMAP CONVERSION FROM ROWIDS | | | | | |
|* 7 | INDEX RANGE SCAN | SMS_CHA_INS_STAID_IDX | | | 1 (0)| 00:00:01 |
| 8 | BITMAP OR | | | | | |
| 9 | BITMAP CONVERSION FROM ROWIDS| | | | | |
|* 10 | INDEX RANGE SCAN | SMS_CHA_INS_STAID_IDX | | | 1 (0)| 00:00:01 |
| 11 | BITMAP CONVERSION FROM ROWIDS| | | | | |
|* 12 | INDEX RANGE SCAN | SMS_CHA_INS_STAID_IDX | | | 1 (0)| 00:00:01 |
-------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - filter("SMS_STA_ID"=5 AND "ON_DAT">TO_CHAR(SYSDATE@!-1,'YYYY-MM-DD HH24:MI:SS') OR
("SMS_STA_ID"=2 OR "SMS_STA_ID"=6) AND "ON_DAT">=TO_CHAR(SYSDATE@!-.166666666666666666666666666666666
6666667,'YYYY-MM-DD HH24:MI:SS') AND "ON_DAT"<=TO_CHAR(SYSDATE@!-.01041666666666666666666666666666666
66667,'YYYY-MM-DD HH24:MI:SS') AND ROWNUM<30)
7 - access("SMS_STA_ID"=5)
10 - access("SMS_STA_ID"=2)
12 - access("SMS_STA_ID"=6)
Statistics
----------------------------------------------------------
1 recursive calls
0 db block gets
10 consistent gets
0 physical reads
0 redo size
457 bytes sent via SQL*Net to client
481 bytes received via SQL*Net from client
1 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
0 rows processed
果不其然,就是这个该死的参数导致此sql执行计划改变,当然,那个sql本身是有问题的,但如果不是参数的修改,它或许根本不会浮出水面。
菜鸟终于送了一口气,虽然早点到公司小息一会并顺便做个春梦的计划泡汤,但毕竟,问题总算解决了,虽然这个倒霉的问题,完全出自自己之手。