Oracle内部错误:ORA-00600[17175]一例

一套HP-UX上的10.2.0.4系统出现ORA-00600[17175] Oracle600内部错误,相关的日志信息如下:

Wed Dec 1 01:57:55 2010
Errors in file /u01/app/oracle/admin/xgp2/bdump/xgp21_pmon_3250.trc:
ORA-00600: internal error code, arguments: [17175], [255], [], [], [], [], [], []
ORA-00601: cleanup lock conflict
Wed Dec 1 01:57:57 2010
Trace dumping is performing id=[cdmp_20101201015757]
Wed Dec 1 01:58:05 2010
LGWR: terminating instance due to error 472
Wed Dec 1 01:58:05 2010
Errors in file /u01/app/oracle/admin/xgp2/bdump/xgp21_lms1_3291.trc:
ORA-00472: PMON process terminated with error
Wed Dec 1 01:58:05 2010
Errors in file /u01/app/oracle/admin/xgp2/bdump/xgp21_lms2_3293.trc:
ORA-00472: PMON process terminated with error
Wed Dec 1 01:58:05 2010
Errors in file /u01/app/oracle/admin/xgp2/bdump/xgp21_lms3_3295.trc:
ORA-00472: PMON process terminated with error
Wed Dec 1 01:58:05 2010
Errors in file /u01/app/oracle/admin/xgp2/bdump/xgp21_lms0_3289.trc:
ORA-00472: PMON process terminated with error
Wed Dec 1 01:58:05 2010
Errors in file /u01/app/oracle/admin/xgp2/bdump/xgp21_lmon_3283.trc:
ORA-00472: PMON process terminated with error
Wed Dec 1 01:58:05 2010
Errors in file /u01/app/oracle/admin/xgp2/bdump/xgp21_lmd0_3287.trc:
ORA-00472: PMON process terminated with error
Wed Dec 1 01:58:05 2010
Shutting down instance (abort)
License high water mark = 421

/u01/app/oracle/admin/xgp2/bdump/xgp21_pmon_3250.trc
Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - 64bit Production
With the Partitioning, Real Application Clusters, OLAP, Data Mining
and Real Application Testing options
ORACLE_HOME = /u01/app/oracle/product/10.2.0/db_1
System name: HP-UX
Node name: XGP2_db1
Release: B.11.31
Version: U
Machine: ia64
Instance name: xgp21
Redo thread mounted by this instance: 1
Oracle process number: 2
Unix process pid: 3250, image: oracle@XGP2_db1 (PMON)

*** SERVICE NAME:(SYS$BACKGROUND) 2010-12-01 01:57:55.933
*** SESSION ID:(333.1) 2010-12-01 01:57:55.933
*** 2010-12-01 01:57:55.933
ksedmp: internal or fatal error
ORA-00600: internal error code, arguments: [17175], [255], [], [], [], [], [], []
ORA-00601: cleanup lock conflict


ksedst <- ksedmp <- ksfdmp <- kgeriv <- kgesiv
<- kgesic1 <- kghcln <- kslilcr <- $cold_ksl_cleanup <- ksepop
<- kgepop <- kgesev <- ksesec0 <- $cold_kslges <- ksl_get_child_latch
<- kslgpl <- es <- ksfglt <- kghext_numa <- ksmasgn
<- kghnospc <- $cold_kghalo <- ksmdacnk <- ksmdget <- ksosp_alloc
<- ksoreq_submit <- ksbsrv <- kmmssv <- kmmlsa <- kmmlod
<- ksucln <- ksbrdp <- opirip <- $cold_opidrv <- sou2o
<- $cold_opimai_real <- main <- main_opd_entry

PROCESS STATE
-------------
Process global information:
process: c00000018d000078, call: c00000018d252238, xact: 0000000000000000, curses: c00000018d2508a8, usrses: c00000018d2508a8
----------------------------------------
SO: c00000018d000078, type: 2, owner: 0000000000000000, flag: INIT/-/-/0x00
(process) Oracle pid=2, calls cur/top: c00000018d252238/c00000018d252238, flag: (e) SYSTEM
int error: 0, call error: 0, sess error: 0, txn error 0
(post info) last post received: 0 0 48
last post received-location: ksoreq_reply
last process to post me: c00000018d037978 1 64
last post sent: 0 0 24
last post sent-location: ksasnd
last process posted by me: c00000018d001058 1 6
(latch info) wait_event=0 bits=90
holding (efd=5) c00000020001d500 Parent+children shared pool level=7
Location from where latch is held: kghfrunp: alloc: clatch nowait:
Context saved from call: 0
state=busy, wlstate=free
holding (efd=5) c00000020000b5f8 OS process allocation level=4
Location from where latch is held: ksoreq_submit:
Context saved from call: 13835058076152957304
state=busy, wlstate=free
Process Group: DEFAULT, pseudo proc: c0000004dd263230
O/S info: user: oracle, term: UNKNOWN, ospid: 3250
OSD pid info: Unix process pid: 3250, image: oracle@XGP2_db1 (PMON)


SO: c0000004df4d5f28, type: 19, owner: c00000018d000078, flag: INIT/-/-/0x00
GES MSG BUFFERS: st=emp chunk=0x0000000000000000 hdr=0x0000000000000000 lnk=0x0000000000000000 flags=0x0 inc=4
outq=0 sndq=0 opid=2 prmb=0x0
mbg[i]=(2 19) mbg[b]=(0 0) mbg[r]=(0 0)
fmq[i]=(4 1) fmq[b]=(0 0) fmq[r]=(0 0)
mop[s]=20 mop[q]=1 pendq=0 zmbq=0
nonksxp_recvs=0
------------process 0xc0000004df4d5f28--------------------
proc version : 0
Local node : 0
pid : 3250
lkp_node : 0
svr_mode : 0
proc state : KJP_NORMAL
Last drm hb acked : 0
Total accesses : 181
Imm. accesses : 180
Locks on ASTQ : 0
Locks Pending AST : 0
Granted locks : 0
AST_Q:
PENDING_Q:
GRANTED_Q:
----------------------------------------
SO: c00000018d2f3610, type: 11, owner: c00000018d000078, flag: INIT/-/-/0x00
(broadcast handle) flag: (2) ACTIVE SUBSCRIBER, owner: c00000018d000078,
event: 1, last message event: 1,
last message waited event: 1, messages read: 0
channel: (c0000004dd29fdb0) scumnt mount lock
scope: 1, event: 19, last mesage event: 0,
publishers/subscribers: 0/19,
messages published: 0
SO: c00000018d2508a8, type: 4, owner: c00000018d000078, flag: INIT/-/-/0x00
(session) sid: 333 trans: 0000000000000000, creator: c00000018d000078, flag: (51) USR/- BSY/-/-/-/-/-
DID: 0001-0002-00000003, short-term DID: 0000-0000-00000000
txn branch: 0000000000000000
oct: 0, prv: 0, sql: 0000000000000000, psql: 0000000000000000, user: 0/SYS
service name: SYS$BACKGROUND
last wait for 'latch: shared pool' blocking sess=0x0000000000000000 seq=342 wait_time=175677 seconds since wait started=0
address=c0000002000fff60, number=d6, tries=7
Dumping Session Wait History
for 'latch: shared pool' count=1 wait_time=175677
address=c0000002000fff60, number=d6, tries=7
for 'latch: shared pool' count=1 wait_time=97554
address=c0000002000fff60, number=d6, tries=6
for 'latch: shared pool' count=1 wait_time=78023
address=c0000002000fff60, number=d6, tries=5
for 'latch: shared pool' count=1 wait_time=38978
address=c0000002000fff60, number=d6, tries=4
for 'latch: shared pool' count=1 wait_time=38942
address=c0000002000fff60, number=d6, tries=3
for 'latch: shared pool' count=1 wait_time=19435
address=c0000002000fff60, number=d6, tries=2
for 'latch: shared pool' count=1 wait_time=12655
address=c0000002000fff60, number=d6, tries=1
for 'latch: shared pool' count=1 wait_time=8
address=c0000002000fff60, number=d6, tries=0
for 'os thread startup' count=1 wait_time=144253
=0, =0, =0
for 'os thread startup' count=1 wait_time=141360
=0, =0, =0


SO: c00000018d2f3500, type: 11, owner: c00000018d000078, flag: INIT/-/-/0x00
(broadcast handle) flag: (2) ACTIVE SUBSCRIBER, owner: c00000018d000078,
event: 2, last message event: 40,
last message waited event: 40, messages read: 1
channel: (c0000004dd29bbd8) system events broadcast channel
scope: 2, event: 224634, last mesage event: 40,
publishers/subscribers: 0/161,
messages published: 1


SO: c00000018d252238, type: 3, owner: c00000018d000078, flag: INIT/-/-/0x00
(call) sess: cur c00000018d2508a8, rec 0, usr c00000018d2508a8; depth: 0
----------------------------------------
SO: c00000018d2594b0, type: 5, owner: c00000018d252238, flag: INIT/-/-/0x00
(enqueue) PR-00000000-00000000 DID: 0001-0002-00000003
lv: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 res_flag: 0x2
res: 0xc0000004df401718, mode: X, lock_flag: 0x0
own: 0xc00000018d2508a8, sess: 0xc00000018d2508a8, proc: 0xc00000018d000078, prv: 0xc0000004df401728
----------------------------------------
SO: c00000018d30b710, type: 16, owner: c00000018d000078, flag: INIT/-/-/0x00
(osp req holder)
CHILD REQUESTS:
(osp req) type=2(BACKGROUND) flags=0x20001(STATIC/-) state=1(INITED) err=0
pg=0 arg1=0 arg2=(null) reply=(null) pname=S018
pid=0 parent=c00000018d30b710 fulfill=0000000000000000
----------------------------------------
SO: c0000004dbff09c0, type: 192, owner: c0000004dbff09c0, flag: -/-/-/0x00

在metalink上搜索600[17175]内部错误相关的文档,可以找到该错误的大量信息:

Keywords: ora-00600 [17175]

1. Bug 6250251: ORA-00600 17175 DURING KGI CLEANUP - DUMP - ORADEBUG
--ora-600 followed by ora-601 and instance crash with ORA-17175.
--Also, setting of heap check event triggers this problem. In this case
--it is event="10235 trace name context forever, level 27"

2. Bug 4216668 - Dump from INSERT / MERGE on internal columns (Doc ID 4216668.8)
--INSERT or MERGE commands might core dump if operating on object types and internal columns are involved.

3. Bug 7590297: ORA-600 [17175] [255] ORA-601: CLEANUP LOCK CONFLICT CRASHED THE DATABASE

4. SR 3-2296150050
--The error has occurred when Oracle was cleaning shared pool latch/heap information about the process 
which died in middle.
--There is no data corruption associated with this error.
--This is evident from the function kghcln in the trace stack at which it failed.
--This problem is usually the symptom of some earlier problem with the latch.
--Either after a process has died, or a process has signaled an error while holding a shared pool latch, 
and the index to the shared pool latch is invalid.

--There was a Bug 7590297 raised for this issue which could not be progressed due to unavailability of information.
--From few earlier known issues - This can be due to PMON may sometimes signal ORA-601 
while trying to start up additional shared servers or dispatchers.
--There the workaround suggested was to Start the instance with max # of shared servers.

--Can you reproduce the problem?If the instance has been restated the issue may not persist as it is related to memory.
--If the issue persists then we have to perform the following to monitoring the instance to investigate further:

--1. Set the following event in parameter file:
--event="10257 trace name context forever, level 10"
--event="601 trace name SYSTEMSTATE level 10"

--The first event will cause PMON to dump info about shared server startup.
--The second event will cause PMON to do a system state dump when the 601 occurs.

--2. You should also have the track of this in intervals and save the historical results from:

--SQL> select e.total_waits, e.total_timeouts, e.time_waited from v$session_event e, v$session s
, v$bgprocess b where b.name='PMON' and s.paddr=b.paddr and e.sid=s.sid and e.event='process startup';


5. SR 3-2123025401
--=== ODM Solution / Action Plan ===
--Disabled NUMA for resolution

6. SR 7314313.994

Analysis:

Bug 6250251 and bug 4216668 are not applicable to this case.
Bug 7590297 is applicable to this case, as the call stack, error message are the same with this case. 
But this patch is suspended as requested info is not available.

SR 3-2296150050: same error message, same DB version, similar call stack; closed without solution.
SR 3-2123025401: same error message, same DB version, similar call stack. 
The issue happened twice in that SR and solved by disabling NUMA
SR 7314313.994: same error message, same DB version, similar call stack; closed without solution.

ERROR:
ORA-600 [17175] [a]


VERSIONS:
versions 9.2 to 10.1


DESCRIPTION:


This error occurs when we are cleaning up a shared pool latch (either after a process has died, 
or a process has signaled an error while holding a shared pool latch), 
and the index to the shared pool latch is invalid.


ARGUMENTS:
Arg [a] index of the latch recovery structure - usually 255

FUNCTIONALITY:
Generic Heap Manager


IMPACT:
INSTANCE HANG
PROCESS FAILURE
INSTANCE FAILURE

以下为Oracle GCS给出的行动计划,GCS认为绝大多数ORA-00600 [17xxx]是由memory相关的问题引起的,这些问题往往在重启实例后就可以得到解决。并建议可以设置shared_servers=max_shared_servers后进一步观察:

From the uploaded files it looks like you were reported with ORA-00600 [17175] errors 
and crashed the instance.What is the current status after the restart of the database. 
Are you still reported with the same errors and crashing the instance ?
Mostly the ORA-00600 [17xxx] errors are memory releated and might have got resolved after the database restart.


Further looking at the uploaded trace file the failing functions and the error closely 
matches Bug 6958493and is closed as duplicate of BaseBug 6962340which is closed 
as could not able to reproduce the error.


Also a smillar issue is reported inBug 3104250which is fixed in 10g, but that doesn't mean 
you cannot get this error for a new reason and that the same workaround would fix it.
We need to implement the workaround and set: shared_servers=max_shared_servers 
if the error reproduces again. If this is still repeated issue then we can file a new bug with development for the same.


ACTION PLAN
===========
1. Monitor the alertlog for the ORA-00600 [17175] errors for the next few days and if the database still crashes then please
set shared_servers=max_shared_servers and see if the problem resolves or not.

ORA-00600: internal error code, arguments: [15160]

一套windows上的11.1.0.7系统,用户在查询时出现ORA-00600: internal error code, arguments: [15160], [], [], [], [], [], [], [], [], [], [], []错误如下:

Dump continued from file: c:\app\administrator\diag\rdbms\dbuat\dbuat\trace\dbuat_ora_544.trc
ORA-00600: internal error code, arguments: [15160], [], [], [], [], [], [], [], [], [], [], []

========= Dump for incident 16131 (ORA 600 [15160]) ========

*** 2010-07-20 15:49:20.015
----- Current SQL Statement for this session (sql_id=3vx5wh2859qy4) -----
SELECT * FROM ACVW_ACDCBIRD
WHERE CUST_AC_NO = NVL(:B5 , CUST_AC_NO)
AND BRANCH_CODE = :B4
AND ACCOUNT_CLASS = NVL(:B3 , ACCOUNT_CLASS)
AND CUST_NO = NVL(:B2 , CUST_NO)
AND CCY = NVL(:B1 , CCY)

----- PL/SQL Call Stack -----
object line object
handle number name
4648BA6C 811 package body FCUAT.ACPKS_FCJ_ACDCBIRD
4648BA6C 895 package body FCUAT.ACPKS_FCJ_ACDCBIRD
4648BA6C 199 package body FCUAT.ACPKS_FCJ_ACDCBIRD
4648BA6C 122 package body FCUAT.ACPKS_FCJ_ACDCBIRD
4648E458 13 anonymous block
4648F520 161 package body FCUAT.STPKS_FIDPKG_WRAPPER
464953BC 1940 package body FCUAT.STPKS_FCMAINT_SERVICE
464B8DE0 164 package body FCUAT.GWPKS_SERVICE_ROUTER
464B8DE0 1549 package body FCUAT.GWPKS_SERVICE_ROUTER
464B8DE0 1718 package body FCUAT.GWPKS_SERVICE_ROUTER
464B96E0 1 anonymous block

----- Call Stack Trace -----

PGOSF60__ksfdmp dbgexPhaseII dbgexProcessError dbgeExecuteForError

该ORA-600[15160]内部错误已知可能由以下Bug引起:

1)
Bug:8295719 - ORA-600 [15160] running query with FULL OUTER join Fixed-Releases: B201 Tags: ANSI CBO OERI REDISCOVERY INFORMATION:
If a query with nested views and Full Outer Join fails during parsing in Oracle11g with ORA-600 [15160] and Join Predicate Push Down (JPPD) is taking place and one of the nested view query blocks in the 10053 trace has a very high value for cost in the chosen plan (in section CBQT Join Predicate Push Down Additional Phase) then you may have encountered this bug.
WORKAROUND:
_optimizer_push_pred_cost_based = false

2)
Bug 7370515 - ORA-600[15160]: INTERNAL ERROR CODE
REDISCOVERY INFORMATION:
If you encountered ORA-600[15160] error when UNION/UNION ALL view is on the right side of null aware anti join, it could be this bug.
WORKAROUND:
Set "_optimizer_null_aware_antijoin"=false

3)
Bug 9826143 - UNION QUERY WITH OUTER JOIN AND GROUP BY CLAUSE FAILS WITH ORA-600 [15160] (36)
>>>>>>>>>>
Bug 9213751 - SQL GETS ORA-600 [15160] WITH _OPTIMIZER_PUSH_PRED_COST_BASED=TRUE (11)
From trace: [_optimizer_push_pred_cost_based = true]

4)
Bug 8947490 - ORA-600[15160] OCCURS WHEN USING SQL TUNING ADVISOR
REDISCOVERY INFORMATION:
a query with full outer joined union view produced ora-[15160] most likely during sqltune /index advisor.

可以从bug描述中了解到这是一个优化器相关的bug,一般与优化器相关的bug都可以通过关闭优化器的部分特性来workaround。针对ORA-600[15160]内部错误,我们可以尝试设置以下2个隐藏参数以绕过问题:

1) SQl>
Alter session set "_optimizer_null_aware_antijoin"=false;

/* to disable null aware anti join */

2) SQl>
Alter session set "_OPTIMIZER_PUSH_PRED_COST_BASED" =false ;

/*WORKAROUND: disable cost based push predicate */

以上多个bug据Oracle官方说法均已在11.2.0.1版本中修复了。

ORA-00600: [7005], [192]内部错误一例

一套AIX上的9.2.0.6系统,应用的某条查询语句执行时频繁报ORA-00600:[7005]错误,alert告警日志内容如下:

Errors in file /oracle/admin/BIDW/udump/bidw2_ora_3252288.trc:
ORA-00600: internal error code, arguments: [7005], [192], [], [], [], [], [], []
Mon Dec  7 15:20:27 2009
Errors in file /oracle/admin/BIDW/udump/bidw2_ora_3252288.trc:
ORA-00600: internal error code, arguments: [7005], [192], [], [], [], [], [], []
Mon Dec  7 15:20:27 2009
Trace dumping is performing id=[cdmp_20091207152027]
Mon Dec  7 15:20:28 2009
Thread 2 advanced to log sequence 909143
 Current log# 7 seq# 909143 mem# 0: /oradata2/bidw/BIDW/redo2_3
...............
Mon Dec  7 15:21:10 2009
Errors in file /oracle/admin/BIDW/udump/bidw2_ora_3600486.trc:
ORA-00600: internal error code, arguments: [7005], [192], [], [], [], [], [], []
Mon Dec  7 15:21:11 2009
Errors in file /oracle/admin/BIDW/udump/bidw2_ora_3600486.trc:
ORA-00600: internal error code, arguments: [7005], [192], [], [], [], [], [], []

[Read more…]

ORA-00600:[15570]内部错误一例

一套Linux上的10.2.0.1系统出现ORA-00600:[15570]内部错误,日志如下:

Sat Jun 5 11:33:17 2010
Memory Notification: Library Cache Object loaded into SGA
Heap size 2190K exceeds notification threshold (2048K)
KGL object name :XDB.XDbD/PLZ01TcHgNAgAIIegtw==
Sat Jun 5 14:57:25 2010
Thread 1 advanced to log sequence 16540
Current log# 3 seq# 16540 mem# 0: /ora_data/mantas/redo03.log
Sat Jun 5 14:58:37 2010
Errors in file /opt/oracle/admin/mantas/udump/mantas_ora_10803.trc:
ORA-00600: internal error code, arguments: [15570], [], [], [], [], [], [], []
Sat Jun 5 14:58:37 2010
Errors in file /opt/oracle/admin/mantas/udump/mantas_ora_10903.trc:
ORA-00600: internal error code, arguments: [15570], [], [], [], [], [], [], []
Sat Jun 5 14:58:39 2010
Errors in file /opt/oracle/admin/mantas/udump/mantas_ora_10801.trc:
ORA-00600: internal error code, arguments: [15570], [], [], [], [], [], [], []

[Read more…]

ORA-00600:[32695], [hash aggregation can't be done]错误一例

还是那个hash group by算法的问题,日志文件中出现以下记录:

*** ACTION NAME:(SQL 窗口 - 新建) 2010-09-03 14:27:54.594
*** MODULE NAME:(PL/SQL Developer) 2010-09-03 14:27:54.594
*** SERVICE NAME:(HQYDB1) 2010-09-03 14:27:54.594
*** SESSION ID:(3205.17923) 2010-09-03 14:27:54.594
*** 2010-09-03 14:27:54.594
ksedmp: internal or fatal error
ORA-00600: internal error code, arguments: [32695], [hash aggregation can't be done], [], [], [], [], [], []
Current SQL statement for this session:
create table zou_201008_cell_id as
select /* g_all_cdr02,60 */
calling_num mobile_number,
lac,
lpad(cell_id,5,'0') cell_id,
count(*) c,
sum(call_duration) call_duration,
sum(decode(record_type,'00',1,0)*call_duration) moc_call_duration,
sum(decode(record_type,'01',1,0)*call_duration) mtc_call_duarion
from  g_all_cdr02
where substr(calling_num,1,7) in (select mobile_prefix from zou_mobile_prefix)
group by
calling_num ,
lac,
lpad(cell_id,5,'0')
----- Call Stack Trace -----
calling              call     entry                argument values in hex
location             type     point                (? means dubious value)
-------------------- -------- -------------------- ----------------------------
ksedst+001c          bl       ksedst1              100000000 ? 11055A9A0 ?
ksedmp+0290          bl       ksedst               104A54870 ?
ksfdmp+0018          bl       03F30204
kgeriv+0108          bl       _ptrgl
kgesiv+0080          bl       kgeriv               1050BE654 ? 1050BE604 ?
                                                   0000027E5 ? 080000000 ?
                                                   07FFFFFFF ?
ksesic1+0060         bl       kgesiv               43300000FFFF5310 ?
                                                   4530000000000000 ?
                                                   000000071 ? 000000001 ?
                                                   000000000 ?
qeshPartitionBuildH  bl       01F9CA24
D+04bc
qeshGBYOpenScan2+02  bl       qeshPartitionBuildH  0000027E5 ? 1105C06C0 ?
34                            D
qeshGBYOpenScan+001  bl       qeshGBYOpenScan2     FFFFFFFFFFF5740 ? 11055A938 ?
8                                                  000000000 ? 000000010 ?
qerghFetch+05e8      bl       qeshGBYOpenScan      000001000 ?
rwsfcd+0054          bl       _ptrgl
qerltFetch+036c      bl       03F2EB1C
ctcdrv+4160          bl       01F9C898
opiexe+2884          bl       ctcdrv               100000001 ? 100000001 ?
                                                   110467F30 ?
opiosq0+19f0         bl       opiexe               FFFFFFFFFFF8B50 ?
                                                   2824422142420820 ?
                                                   FFFFFFFFFFF8C10 ?
kpooprx+0168         bl       opiosq0              300000000 ? 000000000 ?
                                                   000000000 ? A4000000000000 ?
kpoal8+0400          bl       kpooprx              FFFFFFFFFFFB464 ?
                                                   FFFFFFFFFFFB068 ?
                                                   1BF000001BF ? 100000001 ?
                                                   000000000 ? A40000000000A4 ?
                                                   000000000 ? 1103878F8 ?
opiodr+0ae0          bl       _ptrgl
ttcpip+1020          bl       _ptrgl
opitsk+1124          bl       01F9F2A0
opiino+0990          bl       opitsk               000000000 ? 000000000 ?
opiodr+0ae0          bl       _ptrgl
opidrv+0484          bl       01F9E0E8
sou2o+0090           bl       opidrv               3C02DC1BBC ? 44065F000 ?
                                                   FFFFFFFFFFFF3A0 ?
opimai_real+01bc     bl       01F9B9F4
main+0098            bl       opimai_real          000000000 ? 000000000 ?
__start+0098         bl       main                 000000000 ? 000000000 ?

--------------------- Binary Stack Dump ---------------------

这次是因为应用人员不了解alter session的作用域,在PL/SQL Developer工具中的不同窗口(也就是不在同一会话中)中执行了”alter session set “_gby_hash_aggregation_enabled” = false;”和涉及group by操作的SQL,并导致了unpublished bug:6471770被触发。
我们比较容易地workaround绕过这个Bug:


/* 在会话级别设置优化参数_gby_hash_aggregation_enabled */

alter session set "_gby_hash_aggregation_enabled" = false;

/* 或者在语句中加入NO_USE_HASH_AGGREGATION的 hint */

select  /*+ NO_USE_HASH_AGGREGATION */ ....

以上提及的unpublished bug:6471770据称在10.2.0.5,11.1.0.7,11.2.0.1版本中被修正了。

Oracle SQL Developer 的一个Bug

Oracle SQL Developer是Oracle近几年来推出的一款免费的图形界面SQL PL/SQL开发工具,在11g中它甚至被集成到了Oracle server软件中;如果你平常有用这款IDE的话,大概会注意到它提供了十分实用的Database copy,diff,export功能。

当在Oracle SQL developer中使用sys用户登录数据库,并尝试导出某些schema的ddl定义时,可能会丢失一些constraint约束的ddl信息,如以下例子:

我们尝试导出scott用户的表,索引以及约束的相关ddl,当使用sys用户登录数据库时,Oracle SQL developer给出的SQL:

--------------------------------------------------------
--  File created - Monday-August-30-2010
--------------------------------------------------------
--------------------------------------------------------
--  DDL for Table BONUS
--------------------------------------------------------

  CREATE TABLE "BONUS"
   (	"ENAME" VARCHAR2(10),
	"JOB" VARCHAR2(9),
	"SAL" NUMBER,
	"COMM" NUMBER
   ) ;
--------------------------------------------------------
--  DDL for Table DEPT
--------------------------------------------------------

  CREATE TABLE "DEPT"
   (	"DEPTNO" NUMBER(2,0),
	"DNAME" VARCHAR2(14),
	"LOC" VARCHAR2(13)
   ) ;
--------------------------------------------------------
--  DDL for Table EMP
--------------------------------------------------------

  CREATE TABLE "EMP"
   (	"EMPNO" NUMBER(4,0),
	"ENAME" VARCHAR2(10),
	"JOB" VARCHAR2(9),
	"MGR" NUMBER(4,0),
	"HIREDATE" DATE,
	"SAL" NUMBER(7,2),
	"COMM" NUMBER(7,2),
	"DEPTNO" NUMBER(2,0)
   ) ;
--------------------------------------------------------
--  DDL for Table SALGRADE
--------------------------------------------------------

  CREATE TABLE "SALGRADE"
   (	"GRADE" NUMBER,
	"LOSAL" NUMBER,
	"HISAL" NUMBER
   ) ;

--------------------------------------------------------
--  DDL for Index PK_DEPT
--------------------------------------------------------

  CREATE UNIQUE INDEX "PK_DEPT" ON "DEPT" ("DEPTNO")   ;
--------------------------------------------------------
--  DDL for Index PK_EMP
--------------------------------------------------------

  CREATE UNIQUE INDEX "PK_EMP" ON "EMP" ("EMPNO")   ;

以上SQL中未给出PK和FK约束的ddl信息。

如果使用scott用户登录数据库,导出自身schema的table,index,constraint定义信息时:

--------------------------------------------------------
--  File created - Monday-August-30-2010
--------------------------------------------------------
--------------------------------------------------------
--  DDL for Table BONUS
--------------------------------------------------------

  CREATE TABLE "BONUS"
   (	"ENAME" VARCHAR2(10),
	"JOB" VARCHAR2(9),
	"SAL" NUMBER,
	"COMM" NUMBER
   ) ;
--------------------------------------------------------
--  DDL for Table DEPT
--------------------------------------------------------

  CREATE TABLE "DEPT"
   (	"DEPTNO" NUMBER(2,0),
	"DNAME" VARCHAR2(14),
	"LOC" VARCHAR2(13)
   ) ;
--------------------------------------------------------
--  DDL for Table EMP
--------------------------------------------------------

  CREATE TABLE "EMP"
   (	"EMPNO" NUMBER(4,0),
	"ENAME" VARCHAR2(10),
	"JOB" VARCHAR2(9),
	"MGR" NUMBER(4,0),
	"HIREDATE" DATE,
	"SAL" NUMBER(7,2),
	"COMM" NUMBER(7,2),
	"DEPTNO" NUMBER(2,0)
   ) ;
--------------------------------------------------------
--  DDL for Table SALGRADE
--------------------------------------------------------

  CREATE TABLE "SALGRADE"
   (	"GRADE" NUMBER,
	"LOSAL" NUMBER,
	"HISAL" NUMBER
   ) ;

--------------------------------------------------------
--  Constraints for Table EMP
--------------------------------------------------------

  ALTER TABLE "EMP" ADD CONSTRAINT "PK_EMP" PRIMARY KEY ("EMPNO") ENABLE;

--------------------------------------------------------
--  Constraints for Table DEPT
--------------------------------------------------------

  ALTER TABLE "DEPT" ADD CONSTRAINT "PK_DEPT" PRIMARY KEY ("DEPTNO") ENABLE;
--------------------------------------------------------
--  DDL for Index PK_EMP
--------------------------------------------------------

  CREATE UNIQUE INDEX "PK_EMP" ON "EMP" ("EMPNO")   ;
--------------------------------------------------------
--  DDL for Index PK_DEPT
--------------------------------------------------------

  CREATE UNIQUE INDEX "PK_DEPT" ON "DEPT" ("DEPTNO")  ;

--------------------------------------------------------
--  Ref Constraints for Table EMP
--------------------------------------------------------

  ALTER TABLE "EMP" ADD CONSTRAINT "FK_DEPTNO" FOREIGN KEY ("DEPTNO")
	  REFERENCES "DEPT" ("DEPTNO") ENABLE;

Oracle SQL developer给出了正确的SQL,包含FK和PK约束。
这个Bug在8月(2010 Aug)被确认将影响此前所有版本的Oracle SQL developer。

undo backup optimization does not work on 11.2.0.1?

Backup Undo Optimization是11g的新特性之一,RMAN将避免备份撤销表空间上那些已提交事务的撤销数据。且该特性无法被禁用(You can enable and disable backup optimization, but backup undo optimization is built-in behavior.)。

我们在11.2.0.1版本上具体测试一下这个新特性:

SQL> select * from v$version;
BANNER
--------------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
PL/SQL Release 11.2.0.1.0 - Production
CORE    11.2.0.1.0      Production
TNS for Linux: Version 11.2.0.1.0 - Production
NLSRTL Version 11.2.0.1.0 - Production

/*  为了避免undo自动调优干扰我们的测试,修改_undo_autotune参数禁用该特性 */

SQL> alter system set "_undo_autotune"=false;
System altered.

/* 创建一个新的undo表空间,清理现场 */
SQL> create undo tablespace UNDOTEST datafile size 500M autoextend on next 50M maxsize unlimited;
Tablespace created.

SQL> alter system set undo_tablespace=UNDOTEST;
System altered.

/* 列出相关的undo参数,可以看到这里undo_retention参数设为极短的10s */

SQL> show parameter undo;
NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
_undo_autotune                       boolean     FALSE
undo_management                      string      AUTO
undo_retention                       integer     10
undo_tablespace                      string      UNDOTEST

RMAN> list backup;

specification does not match any backup in the repository

RMAN> backup tablespace UNDOTEST;

RMAN> list backup of tablespace UNDOTEST;

BS Key  Type LV Size       Device Type Elapsed Time Completion Time
------- ---- -- ---------- ----------- ------------ ---------------
4       Full    1.90M      DISK        00:00:00     25-AUG-10

/* undo表空间初始的备份大小为1.9M  */

SQL> conn maclean/maclean
Connected.

SQL> select count(*) from YOUYUS;
  COUNT(*)
----------
    579808

/* YOUYUS表有大约60万条数据,我们批量删除这些数据,将产生大量的undo*/

SQL> delete YOUYUS;
579808 rows deleted.

/*  此时再次执行备份undo表空间操作 */

RMAN> backup tablespace UNDOTEST;

RMAN>  list backup of tablespace UNDOTEST;

BS Key  Type LV Size       Device Type Elapsed Time Completion Time
------- ---- -- ---------- ----------- ------------ ---------------
5       Full    134.43M    DISK        00:00:03     25-AUG-10

/*  在存在大量active undo数据的情况下,备份文件增大到134M */

SQL> commit;
Commit complete.

SQL> exec dbms_lock.sleep(20);
PL/SQL procedure successfully completed.

SQL> select status,sum(blocks) from dba_undo_extents group by status;
STATUS    SUM(BLOCKS)
--------- -----------
UNEXPIRED        2696
EXPIRED         32936

/* commit后等待20s,确定没有active的撤销段 */

RMAN> backup tablespace UNDOTEST;

RMAN> list backup of tablespace UNDOTEST;
BS Key  Type LV Size       Device Type Elapsed Time Completion Time
------- ---- -- ---------- ----------- ------------ ---------------
6       Full    134.49M    DISK        00:00:02     25-AUG-10

/* 备份文件还要大于commit前,undo backup optimization居然没有起作用? */

/* 这个会是BUG吗? */

根据以上情况我提交了SR,ORACLE GCS给出的回复:

Bug 6399468: UNDO OPTIMIZATION
====> Undo optimization was changed from ‘all undo not needed’ to ‘undo not in use older than 1 hour’
In unpublished bug 6399468 DEV has confirmed the Undo optimization was changed from ‘all undo not needed’ to ‘undo not in use older than 1 hour’. For your last test case please wait for 1 hour and try backup again.

居然又是一个unpublished的BUG,Oracle DEV部门确认了backup undo optimization所避免备份的是1个小时以上未被尝试使用的undo,而非所有不再需要的undo。这是典型的开发部门和文档撰写部门间没有充分交流造成的问题!

/* 尝试等待3600s */

SQL> exec dbms_lock.sleep(3600);
PL/SQL procedure successfully completed.

/* 3600s还真漫长....... */

RMAN> backup tablespace UNDOTEST;

RMAN> list backup of tablespace UNDOTEST;
BS Key  Type LV Size       Device Type Elapsed Time Completion Time
------- ---- -- ---------- ----------- ------------ ---------------
10      Full    15.01M     DISK        00:00:00     25-AUG-10

/* 备份集缩小到15m,undo backup optimization起到了作用!*/

That's great!

关于DataPump的external_table模式

在pre10g的很长时间内,Oracle仅提供exp/imp导入导出工具,虽然这2个实用程序十分有效(现在也是如此),但因为它们受限于client/server模式工具自身的限制,以普通用户程序的身份来运转数以TB计的数据,其才不堪大用!DataPump是10g以后主推的数据抽取/导入工具,不同于exp/imp工具,DataPump是一个服务器端的实用程序,因为运行在服务器上故而DataPump进程可以直接访问数据文件与SGA(无需借shadow进程之手),与exp/imp工具相比使用DataPump可以获得显著的性能改善。DataPump可以通过直接路径或外部表路径这两种方法导出数据;其中直接路径避开了数据库高速缓存。当使用直接路径模式抽取数据时,DataPump从磁盘直接读取数据文件,抽取和格式化文件内容,最后将内容写出到转储文件。该种模式和SGA交互等待少,其导入导出速度直接取决于数据库所在磁盘速度和cpu;因此,直接路径极为快速。

外部表路径模式将使用到数据库的高速缓存buffer cache,通过外部表路径方法导出数据时,DataPump使用普通的SELECT操作将数据块从数据文件中读入buffer cache,为了写出转储文件,数据会在缓存中被格式化。通过外部表路径导入数据时,DataPump根据转储文件的内容构造标准的插入语句,并且通过将数据块从数据文件读至缓存来执行这些语句,插入操作按照标准的样式在缓存中完成;如同任何普通DML操作一样,外部表路径也会同时产生撤销和重做。

DataPump自身会根据对象的复杂性作出使用直接路径还是外部表路径的选择;对于较复杂的对象(后文将列出)而言,为了分解复杂性而必须同SGA进行交互,此情况下Data Pump只能采用外部表模式。我们还可以通过使用access_method参数来控制其行为,当然这仅在我们确认Data Pump作出了错误选择时才有必要。

若满足右列条件EXPDP将采用direct_path即直接路径模式 表结构允许使用直接路径模式,举例而言:

表上没有启用针对SELECT操作的fine-grained access control

非队列表(queue table)

表上没有BFILE和opaque类型的列,或包含有opaque列的对象类型

表上没有加密列

表上没有被废弃的旧类型列

若表上存在LONG或LONG RAW类型列,则此列只能是最后一列
使用Expdp执行导出任务时没有为相关表指定QUERY, SAMPLE, or REMAP_DATA等参数

需要导出的表或分区相对较少(多达250M),亦或者表或分区其实很大,但导出任务无法工作在并行模式(未指定parallel参数,或parallel参数设置为1)

若满足右列条件EXPDP将采用external_table即外部表模式 数据结构不满足在直接路径模式下抽取的条件,举例而言:

表上启用了针对SELECT操作的精细粒度控制

队列表

表上包含了BFILE或opaque类型列,或者包含有opaque列的对象类型

表上存在加密列

表上存在被废弃的旧类型列

表上存在LONG或LONG RAW类型列,且不是最后列

数据结构满足使用直接路径模式的条件,但执行导出任务时相关表上指定了QUERY, SAMPLE, or REMAP_DATA等参数

数据结构满足使用直接路径模式的条件,但相关的表或分区相对较大(大于250M),此时并行SQL可以用来加速数据抽取

若满足右列条件IMPDP将采用direct_path即直接路径模式 数据结构满足使用直接路径模式的条件,举例而言:

当导入某单一表分区时该分区表上没有建立全局索引,这一点也包括分区的对象表

没有基于LOB列建立的域索引(domain index)

非cluster表

表上没有BFILE列或opaque类型列

表上没有嵌入了opaque类型的VARRAY列

表上没有加密列

没有启用补全日志(Supplemental logging)且表上没有LOB类型列

若导入表已预先建立了表建构,则需满足以下条件:

表上没有激活的触发器 并且 若是分区表则应有索引 并且 表上上没有启用针对INSERT操作的精细粒度控制 并且 表上除去check类型约束不存在其他类型约束 并且 表上没有unique的索引

执行导入任务时没有为相关表指定QUERY, REMAP_DATA等参数

需要导入的表或分区相对较小(少于250M),或者表或分区其实很大,但无法以并行模式导入(未指定parallel参数或指定其为1)

若满足右列条件IMPDP将采用external_table即外部表路径 当数据结构不满足在直接路径模式下导入的条件,举例而言:

当导入某单一表分区时该分区表上建有全局索引,这一点也包括分区的对象表

表上有基于LOB列建立的域索引(domain index)

cluster表

表上有BFILE列或opaque类型列

表上有嵌入了opaque类型的VARRAY列

表上有加密列

启用了补全日志且表上有至少一个LOB列

若导入表已预先建立了表建构,且满足以下条件:

表上有激活的触发器 或者

是分区表且没有任何索引 或者

表上启用了针对INSERT操作的精细粒度控制 或者

表上除去check类型约束还还有其他类型约束 或者

表上有unique的索引

执行导入任务时有为相关表指定QUERY, REMAP_DATA等参数

数据结构满足使用直接路径模式的条件,但相关的表或分区相对较大(大于250M),此时并行SQL可以用来加速数据导入

我们有必要深入了解一下外部表路径究竟是如何工作的:

SQL> select * from v$version;
BANNER
----------------------------------------------------------------
Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - 64bi
PL/SQL Release 10.2.0.4.0 - Production
CORE    10.2.0.4.0      Production
TNS for Linux: Version 10.2.0.4.0 - Production
NLSRTL Version 10.2.0.4.0 - Production

SQL> exec dbms_workload_repository.create_snapshot;
PL/SQL procedure successfully completed.

/*  执行expdp导出任务,TCACHE表大小为465M,这里显示指定了外部表路径 */

[maclean@rh2 ~]$ expdp maclean/maclean directory=dumps tables=TCACHE dumpfile=tcache1.dmp access_method=external_table
Export: Release 10.2.0.4.0 - 64bit Production on Tuesday, 24 August, 2010 20:31:48
Copyright (c) 2003, 2007, Oracle.  All rights reserved.
Connected to: Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
Starting "MACLEAN"."SYS_EXPORT_TABLE_07":  maclean/******** directory=dumps tables=TCACHE dumpfile=tcache1.dmp access_method=external_table
Estimate in progress using BLOCKS method...
Processing object type TABLE_EXPORT/TABLE/TABLE_DATA
Total estimation using BLOCKS method: 544 MB
Processing object type TABLE_EXPORT/TABLE/TABLE
Processing object type TABLE_EXPORT/TABLE/STATISTICS/TABLE_STATISTICS
. . exported "MACLEAN"."TCACHE"                          465.6 MB 4999999 rows
Master table "MACLEAN"."SYS_EXPORT_TABLE_07" successfully loaded/unloaded
******************************************************************************
Dump file set for MACLEAN.SYS_EXPORT_TABLE_07 is:
  /s01/dump/tcache1.dmp
Job "MACLEAN"."SYS_EXPORT_TABLE_07" successfully completed at 20:32:18

/*  这次我们指定了并行度为4  */

[maclean@rh2 ~]$ expdp maclean/maclean directory=dumps tables=TCACHE dumpfile=tcache2.dmp,tcache3.dmp,tcache4.dmp,tcache5.dmp access_method=external_table parallel=4
Export: Release 10.2.0.4.0 - 64bit Production on Tuesday, 24 August, 2010 20:32:49
Copyright (c) 2003, 2007, Oracle.  All rights reserved.
Connected to: Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
Starting "MACLEAN"."SYS_EXPORT_TABLE_07":  maclean/******** directory=dumps tables=TCACHE dumpfile=tcache2.dmp,tcache3.dmp,tcache4.dmp,tcache5.dmp access_method=external_table parallel=4
Estimate in progress using BLOCKS method...
Processing object type TABLE_EXPORT/TABLE/TABLE_DATA
Total estimation using BLOCKS method: 544 MB
Processing object type TABLE_EXPORT/TABLE/TABLE
Processing object type TABLE_EXPORT/TABLE/STATISTICS/TABLE_STATISTICS
. . exported "MACLEAN"."TCACHE"                          465.6 MB 4999999 rows
Master table "MACLEAN"."SYS_EXPORT_TABLE_07" successfully loaded/unloaded
******************************************************************************
Dump file set for MACLEAN.SYS_EXPORT_TABLE_07 is:
  /s01/dump/tcache2.dmp
  /s01/dump/tcache3.dmp
  /s01/dump/tcache4.dmp
Job "MACLEAN"."SYS_EXPORT_TABLE_07" successfully completed at 20:33:04

SQL> exec dbms_workload_repository.create_snapshot;
PL/SQL procedure successfully completed.

SQL> @?/rdbms/admin/awrrpt

接着我们分析该时段内的awr报告!

从AWR报告中,我们不难找到以下语句:
SQL ID 3qwsywpvtdyjp:
CREATE TABLE "ET$088200010001" ( "OWNER", "OBJECT_NAME", "SUBOBJECT_NAME", "OBJECT_ID", "DATA_OBJECT_ID", "OBJECT_TYPE", "CREATED", "LAST_DDL_TIME", "TIMESTAMP", "STATUS", "TEMPORARY", "GENERATED", "SECONDARY" ) ORGANIZATION EXTERNAL ( TYPE ORACLE_DATAPUMP DEFAULT DIRECTORY DUMPS ACCESS PARAMETERS (DEBUG =0 DATAPUMP INTERNAL TABLE "MACLEAN"."TCACHE" JOB ( "MACLEAN", "SYS_EXPORT_TABLE_07", 1) WORKERID 1 PARALLEL 1 VERSION COMPATIBLE ENCRYPTPASSWORDISNULL ) LOCATION ('bogus.dat') ) PARALLEL 1 REJECT LIMIT UNLIMITED AS SELECT /*+ PARALLEL(KU$, 1) */ "OWNER", "OBJECT_NAME", "SUBOBJECT_NAME", "OBJECT_ID", "DATA_OBJECT_ID", "OBJECT_TYPE", "CREATED", "LAST_DDL_TIME", "TIMESTAMP", "STATUS", "TEMPORARY", "GENERATED", "SECONDARY" FROM RELATIONAL("MACLEAN"."TCACHE" ) KU$

SQL ID 1rxax27p7anr3:
CREATE TABLE "ET$088000020001" ( "OWNER", "OBJECT_NAME", "SUBOBJECT_NAME", "OBJECT_ID", "DATA_OBJECT_ID", "OBJECT_TYPE", "CREATED", "LAST_DDL_TIME", "TIMESTAMP", "STATUS", "TEMPORARY", "GENERATED", "SECONDARY" ) ORGANIZATION EXTERNAL ( TYPE ORACLE_DATAPUMP DEFAULT DIRECTORY DUMPS ACCESS PARAMETERS (DEBUG =0 DATAPUMP INTERNAL TABLE "MACLEAN"."TCACHE" JOB ( "MACLEAN", "SYS_EXPORT_TABLE_07", 1) WORKERID 2 PARALLEL 2 VERSION COMPATIBLE ENCRYPTPASSWORDISNULL ) LOCATION ('bogus.dat') ) PARALLEL 2 REJECT LIMIT UNLIMITED AS SELECT /*+ PARALLEL(KU$, 2) */ "OWNER", "OBJECT_NAME", "SUBOBJECT_NAME", "OBJECT_ID", "DATA_OBJECT_ID", "OBJECT_TYPE", "CREATED", "LAST_DDL_TIME", "TIMESTAMP", "STATUS", "TEMPORARY", "GENERATED", "SECONDARY" FROM RELATIONAL("MACLEAN"."TCACHE" ) KU$

以上就是Expdp在导出数据时使用的创建组织类型为ORACLE_DATAPUMP的外部表的SQL语句;后者语句中指定的并行度为2,而非我所指定的4,因该是Oracle考虑到所需导出表的具体大小,设置过高的并行度反而会适得其反,所以对设定值做了修正。

启用了并行的SQL 1rxax27p7anr3执行时间为22.63s,反而要比不使用并行慢;可见在TCACHE表这个数量级,完全没有必要使用并行导出。

接着我们来探究一下外部表路径的导入:

SQL> truncate table tcache;
Table truncated.
SQL> set pagesize 1400;
SQL> set linesize 140;

/* 执行外部表路径的数据导入,并行度1  */

[maclean@rh2 admin]$ impdp maclean/maclean directory=dumps tables=TCACHE content=data_only  dumpfile=tcache1.dmp access_method=external_table

/* 在以上SQL执行期间查询V$SQL动态视图的相关语句*/

select sql_text,
       sql_id,
       cpu_time,
       elapsed_time,
       disk_reads,
       buffer_gets,
       rows_processed
  from v$sql
 where sql_text like '%TCACHE%'
   and sql_text not like '%like%';

SQL_TEXT
--------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID          CPU_TIME ELAPSED_TIME DISK_READS BUFFER_GETS ROWS_PROCESSED
------------- ---------- ------------ ---------- ----------- --------------
INSERT /*+ SYS_DL_CURSOR */ INTO RELATIONAL("MACLEAN"."TCACHE") ("OWNER","OBJECT_NAME","SUBOBJECT_NAME","OBJECT_ID","DATA_OBJECT_ID","OBJECT
_TYPE","CREATED","LAST_DDL_TIME","TIMESTAMP","STATUS","TEMPORARY","GENERATED","SECONDARY") VALUES (NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,N
ULL,NULL,NULL,NULL,NULL)
6tn47a220d34q        408          408          0           0              0

INSERT /*+APPEND+*/  /*+PARALLEL("TCACHE",1)+*/ INTO RELATIONAL("MACLEAN"."TCACHE" ) ("OWNER", "OBJECT_NAME", "SUBOBJECT_NAME", "OBJECT_ID",
 "DATA_OBJECT_ID", "OBJECT_TYPE", "CREATED", "LAST_DDL_TIME", "TIMESTAMP", "STATUS", "TEMPORARY", "GENERATED", "SECONDARY")     SELECT "OWNE
R", "OBJECT_NAME", "SUBOBJECT_NAME", "OBJECT_ID", "DATA_OBJECT_ID", "OBJECT_TYPE", "CREATED", "LAST_DDL_TIME", "TIMESTAMP", "STATUS", "TEMPO
RARY", "GENERATED", "SECONDARY"     FROM "ET$087B00060001" KU$
66q4w8c4ak0wf      31576        31576          0         608              0

/* 当导入job完成后再次查询 */
select sql_text,
       sql_id,
       cpu_time,
       elapsed_time,
       disk_reads,
       buffer_gets,
       rows_processed
  from v$sql
 where sql_text like '%TCACHE%'
   and sql_text not like '%like%';

SQL_TEXT
--------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID          CPU_TIME ELAPSED_TIME DISK_READS BUFFER_GETS ROWS_PROCESSED
------------- ---------- ------------ ---------- ----------- --------------
INSERT /*+ SYS_DL_CURSOR */ INTO RELATIONAL("MACLEAN"."TCACHE") ("OWNER","OBJECT_NAME","SUBOBJECT_NAME","OBJECT_ID","DATA_OBJECT_ID","OBJECT
_TYPE","CREATED","LAST_DDL_TIME","TIMESTAMP","STATUS","TEMPORARY","GENERATED","SECONDARY") VALUES (NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,N
ULL,NULL,NULL,NULL,NULL)
6tn47a220d34q        408          408          0           0              0

/* 执行完成后一句SQL立马消失了!? Oracle好像很不情愿我们看到外部表路径使用的INSERT语句 :) */

INSERT /*+APPEND+*/ /*+PARALLEL("TCACHE",1)+*/
INTO RELATIONAL
  ("MACLEAN"."TCACHE")
  ("OWNER",
   "OBJECT_NAME",
   "SUBOBJECT_NAME",
   "OBJECT_ID",
   "DATA_OBJECT_ID",
   "OBJECT_TYPE",
   "CREATED",
   "LAST_DDL_TIME",
   "TIMESTAMP",
   "STATUS",
   "TEMPORARY",
   "GENERATED",
   "SECONDARY")
  SELECT "OWNER",
         "OBJECT_NAME",
         "SUBOBJECT_NAME",
         "OBJECT_ID",
         "DATA_OBJECT_ID",
         "OBJECT_TYPE",
         "CREATED",
         "LAST_DDL_TIME",
         "TIMESTAMP",
         "STATUS",
         "TEMPORARY",
         "GENERATED",
         "SECONDARY"
    FROM "ET$087F00230001" KU$

/* 这里的KU$代表的就是以ORACLE_DATAPUMP转储文件形式存放在数据库外的外部表 */

/* 可以看到这里尝试使用了APPEND插入模式,以减少undo和redo的产生*/

SQL> truncate table tcache;
Table truncated.

/* 若启用并行导入呢? */

[maclean@rh2 admin]$ impdp maclean/maclean directory=dumps tables=TCACHE content=data_only  dumpfile=tcache2.dmp,tcache3.dmp,tcache4.dmp access_method=external_table parallel=3
........

select sql_text,
       sql_id,
       cpu_time,
       elapsed_time,
       disk_reads,
       buffer_gets,
       rows_processed
  from v$sql
 where sql_text like '%TCACHE%'
   and sql_text not like '%like%';
SQL_TEXT
--------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID          CPU_TIME ELAPSED_TIME DISK_READS BUFFER_GETS ROWS_PROCESSED
------------- ---------- ------------ ---------- ----------- --------------
INSERT /*+APPEND+*/  /*+PARALLEL("TCACHE",1)+*/ INTO RELATIONAL("MACLEAN"."TCACHE" ) ("OWNER", "OBJECT_NAME", "SUBOBJECT_NAME", "OBJECT_ID",
 "DATA_OBJECT_ID", "OBJECT_TYPE", "CREATED", "LAST_DDL_TIME", "TIMESTAMP", "STATUS", "TEMPORARY", "GENERATED", "SECONDARY")     SELECT "OWNE
R", "OBJECT_NAME", "SUBOBJECT_NAME", "OBJECT_ID", "DATA_OBJECT_ID", "OBJECT_TYPE", "CREATED", "LAST_DDL_TIME", "TIMESTAMP", "STATUS", "TEMPO
RARY", "GENERATED", "SECONDARY"     FROM "ET$087A00040001" KU$
2mvs15623ssvy    5910289      5910289          0       73578              0

INSERT /*+ SYS_DL_CURSOR */ INTO RELATIONAL("MACLEAN"."TCACHE") ("OWNER","OBJECT_NAME","SUBOBJECT_NAME","OBJECT_ID","DATA_OBJECT_ID","OBJECT
_TYPE","CREATED","LAST_DDL_TIME","TIMESTAMP","STATUS","TEMPORARY","GENERATED","SECONDARY") VALUES (NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,N
ULL,NULL,NULL,NULL,NULL)
6tn47a220d34q       1167         1167          0           0              0

/* 似乎因为沿用了APPEND插入模式,插入语句的并行度并未上升 */

/* 因为Oracle不想同我们分享它的小秘密,所以awr和ash报告中都不记录外部表路径插入SQL的相关信息 */

/* 好吧,它有权保持沉默!  */

That's great!

Pending Problem

这个问题发生在今年的1月,用户以操作系统认证形式登陆RAC中的主用实例时发现登陆挂起,但不出现错误。之后应用人员陆续手动杀死服务进程,杀死进程后发现实例可以登录了,应用人员在没有做任何信息转储的情况下重启了数据库,这就造成了我们后期诊断时缺乏必要的信息,也是这个case变成悬案的主要原因。

在实例hang住的一个半小时中告警日志没有任何信息;仅有的有用信息是该实例中diag,pmon,lmd后台进程的trace文件。以下为trace文件:

lmd0 trace:
*** 2010-01-16 11:02:58.106
DUMP LOCAL BLOCKER/HOLDER: block level 5 res [0x10b0005][0xeb5],[TX]
----------resource 0x70000044a76e1a0----------------------
resname       : [0x10b0005][0xeb5],[TX]
Local node    : 1
dir_node      : 1
master_node   : 1
hv idx        : 25
hv last r.inc : 0
current inc   : 20
hv status     : 0
hv master     : 0
open options  : dd
grant_bits    : KJUSERNL KJUSEREX
grant mode    : KJUSERNL  KJUSERCR  KJUSERCW  KJUSERPR  KJUSERPW  KJUSEREX
count         : 1         0         0         0         0         1
val_state     : KJUSERVS_NOVALUE
valblk        : 0x00000000000000000000000000000000 .
access_node   : 1
vbreq_state   : 0
state         : x0
resp          : 70000044a76e1a0
On Scan_q?    : N
Total accesses: 15061
Imm.  accesses: 12545
Granted_locks : 1
Cvting_locks  : 1
value_block:  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
GRANTED_Q :
lp 700000488546990 gl KJUSEREX rp 70000044a76e1a0 [0x10b0005][0xeb5],[TX]
  master 1 gl owner 70000048dd08220 possible pid 2928930 xid 2033-0333-0026D22C bast 0 rseq 215 mseq 0 history 0x14951495
  open opt KJUSERDEADLOCK
CONVERT_Q:
lp 700000488546ae0 gl KJUSERNL rl KJUSEREX rp 70000044a76e1a0 [0x10b0005][0xeb5],[TX]
  master 1 gl owner 70000048ee0ed48 possible pid 2040272 xid 2006-0066-0006F888 bast 0 rseq 215 mseq 0 history 0x1495149a
  convert opt KJUSERGETVALUE KJUSERTRCCANCEL
----------enqueue 0x700000488546990------------------------
lock version     : 2242641
Owner node       : 1
grant_level      : KJUSEREX
req_level        : KJUSEREX
bast_level       : KJUSERNL
notify_func      : 0
resp             : 70000044a76e1a0
procp            : 70000048928b8f0
pid              : 2040272
proc version     : 40135
oprocp           : 0
opid             : 0
group lock owner : 70000048dd08220
possible pid     : 2928930
xid              : 2033-0333-0026D22C
dd_time          : 0.0 secs
dd_count         : 0
timeout          : 0.0 secs
On_timer_q?      : N
On_dd_q?         : N
lock_state       : GRANTED
Open Options     : KJUSERDEADLOCK
Convert options  : KJUSERNOQUEUE
History          : 0x14951495
Msg_Seq          : 0x0
res_seq          : 215
valblk           : 0x00000000000000000000000000000000 .
DUMP LOCAL BLOCKER: initiate state dump for TIMEOUT
  possible owner[819.2928930] on resource TX-010B0005-00000EB5
Submitting asynchronized dump request [28]

pmon trace:
*** SESSION ID:(3384.1) 2010-01-16 11:00:11.349
[claim lock for dead process][lp 0x7000004870f7078][p 0x7000004891a79e0.2928930][hist x49514951]

[claim lock for dead process][lp 0x700000488546990][p 0x70000048928b8f0.0][hist x49514951]   <<<< note:this message@2010-01-16 12:35

pmon trace:
*** 2010-01-16 11:02:58.244
Dump requested by process [orapid=6]
REQUEST:custom dump [2] with parameters [6][819][2][2]
. process info of pid[819.2928930] requested by pid[6.3621092]
Dumping process 819.2928930 info:
*** 2010-01-16 11:02:58.244
Dumping diagnostic information for ospid 2928930:
OS pid = 2928930
loadavg : 10.83 10.96 10.91
swap info: free_mem = 21646.73M rsv = 128.00M
           alloc = 235.52M avail = 32768.00M swap_free = 32532.48M
       F S      UID     PID    PPID   C PRI NI ADDR    SZ    WCHAN    STIME    TTY  TIME CMD
  240001 A  orauser 2928930       1 120 120 20 6da7bd510 174068          10:35:28      -  1:50 oracleCRMDB22 (LOCAL=NO)
open: The file access permissions do not allow the specified action.
procstack: write(/proc/2928930/ctl): The requested resource is busy.
2928930: oracleCRMDB22 (LOCAL=NO)

lmd0进程的trace文件显示该进程发现了本地存在阻塞超时的问题,[0x10b0005][0xeb5],[TX]资源的拥有者是2928930进程,而pmon进程认为2928930进程可能出于僵死状态,故希望RAC中的diag进程能对该进程做进一步的诊断,diag进程受到pmon的邀请”Dump requested by process [orapid=6]”,尝试”Dumping process 819.2928930 info:”,并利用AIX上的procstack调试工具分析此进程当时的调用栈,但出现了”procstack: write(/proc/2928930/ctl): The requested resource is busy”的错误,在网上搜索该记录的相关信息发现可能是AIX上procstack工具的一个Bug,而跟实例挂起问题关系不大:

Problem summary
****************************************************************
* USERS AFFECTED:
* Users of the procstac command on the 5300-09 Technology Level
* with the bos.perf.proctools fileset at the 5.3.9.0 and 5.3.9.1
* levels.
****************************************************************
* PROBLEM DESCRIPTION:
* The procstac command fails with an error similar to:
*
* open: Permission denied
* procstack: write(/proc/2068724/ctl): Device busy
****************************************************************
* RECOMMENDATION:
* Install APAR IZ47903.
****************************************************************
Problem conclusion
*Modified the code to fix this problelm.

diag进程的跟踪文件还显示2928930进程持有redo copy latch;这个case发生后的一个礼拜恰好有Oracle原厂工程师到该客户单位做巡检,原厂工程师查看了实例挂起期间的ASH报告,发现该时段内实例中redo相关的等待频繁发生,基本可以认定是僵死进程持有”redo copy latch”造成了RAC中单实例hang住。

原厂工程师的结论令客户比较满意,这个case基本可以结束了。但我对这个结论并不完全认同,2928930进程持有的redo copy latch是一个子栓,该类子栓在实例上的总数取决于CPU总数,一般来说等于CPU * 2;该实例所在服务器为IBM的p595配有32个cpu,redo copy latch共有64个,单单一个子栓被hold住会造成整个实例都hang住,且登录挂起吗?

SQL> show parameter cpu_count
NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
cpu_count                            integer     32

SQL> select count(*) from v$latch_children where name='redo copy';
  COUNT(*)
----------
        64

/*我们在非生产环境测试一下*/

select addr "十六进制地址",
       to_number(addr, 'xxxxxxxxxxxx') "十进制地址",
       gets,
       misses,
       immediate_gets,
       immediate_misses
  from v$latch_children
 where name = 'redo copy';

十六进制 十进制地址       GETS     MISSES IMMEDIATE_GETS IMMEDIATE_MISSES
-------- ---------- ---------- ---------- -------------- ----------------
2DAB5898  766204056          7          0              0                0
2DAB5818  766203928          5          0              0                0
2DAB5798  766203800          5          0              0                0
2DAB5718  766203672          5          0              0                0
2DAB5698  766203544          5          0              0                0
2DAB5618  766203416          5          0              0                0
2DAB5598  766203288          5          0            511                0
2DAB5518  766203160          5          0         297024              347
8 rows selected.

/*正式测试前的redo copy child latch统计信息,我们还要用到这里的十进制latch地址*/

/*我们尝试手动hold住一个redo copy child latch,并在其他会话中执行一些产生redo的操作*/

session A:
SQL> oradebug setmypid;
Statement processed.
SQL> oradebug call kslgetl 766203160 1;
Function returned 1

/* kslgetl是Oracle内部用get latch的函数,oradebug 可以调用该函数*/

session B:

SQL> select * From v$latchholder;
       PID        SID LADDR    NAME                                                                   GETS
---------- ---------- -------- ---------------------------------------------------------------- ----------
        22        136 2DAB5518 redo copy                                                            297443

另外开三个session,执行一下批量插入数据的匿名块,测试redo是否能够正常产生:
begin
  for i in 1 .. 90000 loop
    insert into tv values (i, i, i);
    commit;
  end loop;
end;
/
PL/SQL procedure successfully completed.

session A:
SQL> oradebug call kslfre 766203160 1;
Function returned 2FD548E0
/*手动释放766203160对应的redo copy 子闩*/

select addr "十六进制地址",
       to_number(addr, 'xxxxxxxxxxxx') "十进制地址",
       gets,
       misses,
       immediate_gets,
       immediate_misses
  from v$latch_children
 where name = 'redo copy';

十六进制 十进制地址       GETS     MISSES IMMEDIATE_GETS IMMEDIATE_MISSES
-------- ---------- ---------- ---------- -------------- ----------------
2DAB5898  766204056          7          0              0                0
2DAB5818  766203928          5          0              0                0
2DAB5798  766203800          5          0              0                0
2DAB5718  766203672          5          0            745                0
2DAB5698  766203544          5          0         122370                5
2DAB5618  766203416          5          0         176712                5
2DAB5598  766203288          5          0         144441                6
2DAB5518  766203160          6          0         297443              373
/*可以看到虽然8个子闩中一个被手动hold住,但对实例的影响远不足以到达hang所需要的条件*/

虽然能证明单个redo copy latch被僵死进程长期持有和实例hang住没有必然的因果联系,但因为缺少相关的systemstate和hanganalyze转储信息,我们也无法进一步做出推断。
这个case发生后的几个月,我无意中在MOS上发现了以下Bug note:

Diagnostic collection may hang or crash the instance
Description

Sometimes while the DIAG process is collecting diagnostics
the database may hang or crash.
This is more likely to occur in a RAC or ASM environment .

You may be seeing this problem if the database crashes or hangs just
after you see the following text in a trace file:
“Dumping diagnostic information for X”
where X is the process that hung or terminated.

This fix replaces invokations of a port specific OS debugger
(like gdb) with Oracle ORADEBUG calls to gather the required
diagnostics.

Note:
For HP Itanium fixes for this issue in 10.2.0.3/10.2.0.4 use bug 8767023
instead of this bug#.

For AIX fixes for this issue in 10.2.0.3/10.2.0.4 use bug 8929701
instead of this bug#.

Workaround
>=10.2.0.3 only: Set init.ora parameter “_ksb_disable_diagpid” = TRUE
but this will disable automatic diagnostics collection.

当diag诊断进程调用系统debugger工具调试问题进程时可能出现实例hang或crash的,且该问题多发于RAC或ASM环境中,workaroud的方法是动态设置_ksb_disable_diagpid为TRUE,可以避免diag诊断进程对问题进程的调试,但这些调试信息往往对我们又是有用的,这倒有些《种树郭橐驼说》中”既然已,勿动勿虑,去不复顾”的味道。

好了这个问题,仍旧pending着,是个悬案。

ORA-00600: internal error code, arguments: [kdsgrp1] example

一套Linux x86-64上的11.2.0.1系统,alert日志中出现ORA-00600: internal error code, arguments: [kdsgrp1]错误,相关trace的部分内容如下:

Dump file /u01/app/oracle/diag/rdbms/utdw016/utdw016b/incident/incdir_276035/utdw016b_ora_5756_i276035.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP,
Data Mining and Real Application Testing options
ORACLE_HOME = /u01/app/oracle/product/112utdw016
System name:	Linux
Node name:	x42k601
Release:	2.6.18-164.el5
Version:	#1 SMP Tue Aug 18 15:51:48 EDT 2009
Machine:	x86_64
Instance name: utdw016b
Redo thread mounted by this instance: 2
Oracle process number: 52
Unix process pid: 5756, image: oracle@x42k601

*** 2010-07-28 11:08:35.394
*** SESSION ID:(577.11818) 2010-07-28 11:08:35.394
*** CLIENT ID:() 2010-07-28 11:08:35.394
*** SERVICE NAME:(utdw016-edw) 2010-07-28 11:08:35.394
*** MODULE NAME:(pmdtm@x42k604-zone1 (TNS V1-V3)) 2010-07-28 11:08:35.394
*** ACTION NAME:() 2010-07-28 11:08:35.394

Dump continued from file: /u01/app/oracle/diag/rdbms/utdw016/utdw016b/trace/utdw016b_ora_5756.trc
ORA-00600: internal error code, arguments: [kdsgrp1], [], [], [], [], [], [], [], [], [], [], []

========= Dump for incident 276035 (ORA 600 [kdsgrp1]) ========

*** 2010-07-28 11:08:35.395
dbkedDefDump(): Starting incident default dumps (flags=0x2, level=3, mask=0x0)
----- Current SQL Statement for this session (sql_id=9hfdcgzzgmgvp) -----
DELETE FROM EIMABS.FACT_OPEN_SALES_ORDER WHERE DIM_SNAPSHOT_TYPE_ID = (SELECT DIM_SNAPSHOT_TYPE_ID FROM EIMABS.DIM_SNAPSHOT_TYPE WHERE SNAPSHOT_TYPE_CODE='FUTURE')
----- PL/SQL Stack -----
----- PL/SQL Call Stack -----
object line object
handle number name
0x5578e0528 6 anonymous block

----- Call Stack Trace -----
calling call entry argument values in hex
location type point (? means dubious value)
-------------------- -------- -------------------- ----------------------------
skdstdst()+36 call kgdsdst() 000000000 ? 000000000 ?
7FFFA85D7418 ? 000000001 ?
7FFFA85DB918 ? 000000000 ?
ksedst1()+98 call skdstdst() 000000000 ? 000000000 ?
7FFFA85D7418 ? 000000001 ?
000000000 ? 000000000 ?
ksedst()+34 call ksedst1() 000000000 ? 000000001 ?
7FFFA85D7418 ? 000000001 ?
000000000 ? 000000000 ?
dbkedDefDump()+2736 call ksedst() 000000000 ? 000000001 ?
7FFFA85D7418 ? 000000001 ?
000000000 ? 000000000 ?
ksedmp()+36 call dbkedDefDump() 000000003 ? 000000002 ?
7FFFA85D7418 ? 000000001 ?
000000000 ? 000000000 ?
ksfdmp()+64 call ksedmp() 000000003 ? 000000002 ?
7FFFA85D7418 ? 000000001 ?
000000000 ? 000000000 ?
dbgexPhaseII()+1764 call ksfdmp() 000000003 ? 000000002 ?
7FFFA85D7418 ? 000000001 ?
000000000 ? 000000000 ?
dbgexProcessError() call dbgexPhaseII() 2B30E1B74718 ? 2B30E1B795F8 ?
+2279 7FFFA85E3708 ? 000000001 ?
000000000 ? 000000000 ?
dbgeExecuteForError call dbgexProcessError() 2B30E1B74718 ? 2B30E1B795F8 ?
()+83 000000001 ? 000000000 ?
7FFF00000000 ? 000000000 ?
dbgePostErrorKGE()+ call dbgeExecuteForError 2B30E1B74718 ? 2B30E1B795F8 ?
1615 () 000000001 ? 000000001 ?
000000000 ? 000000000 ?
dbkePostKGE_kgsf()+ call dbgePostErrorKGE() 000000000 ? 2B30E1B87F38 ?
63 000000258 ? 2B30E1B795F8 ?
000000000 ? 000000000 ?
kgeadse()+383 call dbkePostKGE_kgsf() 00A9B2EE0 ? 2B30E1B87F38 ?
000000258 ? 2B30E1B795F8 ?
000000000 ? 000000000 ?
kgerinv_internal()+ call kgeadse() 00A9B2EE0 ? 2B30E1B87F38 ?
45 000000258 ? 000000000 ?
000000000 ? 000000000 ?
kgerinv()+33 call kgerinv_internal() 00A9B2EE0 ? 2B30E1B87F38 ?
A85DBCA000000000 ?
000000258 ? 000000000 ?
000000000 ?
kgeasnmierr()+143 call kgerinv() 00A9B2EE0 ? 2B30E1B87F38 ?
A85DBCA000000000 ?
000000000 ? 000000000 ?
000000000 ?
kdsgrp1_dump()+832 call kgeasnmierr() 00A9B2EE0 ? 2B30E1B87F38 ?
A85DBCA000000000 ?
000000000 ? 000000003 ?
000000003 ?
kdsgrp1()+19 call kdsgrp1_dump() 00A9B2EE0 ? 2B30E1B87F38 ?
7FFFA85E4360 ? 000000000 ?
000000003 ? 000000003 ?
kdsgrp()+6346 call kdsgrp1() 00A9B2EE0 ? 2B30E1B87F38 ?
7FFFA85E4360 ? 000000000 ?
000000003 ? 000000003 ?
qetlbr()+211 call kdsgrp() 2B30E2018620 ? 000000000 ?
2B30E2018620 ? 000000000 ?
000000003 ? 000000003 ?
qertbFetchByRowID() call qetlbr() 2B30E2018620 ? 00000001A ?
+850 000000000 ? 0000000C8 ?
00400F521 ? 000000000 ?
qergiFetch()+276 call qertbFetchByRowID() 000000000 ? 2B30E2018518 ?
000000000 ? 000000000 ?
000000001 ? 000000000 ?
qerdlFetch()+678 call qergiFetch() 511B78238 ? 2B30E20187F8 ?
000000000 ? 000000000 ?
000000001 ? 000000000 ?
delexe()+952 call qerdlFetch() 511B78090 ? 2B30E2018900 ?
000000000 ? 000000000 ?
000007FFF ? 000000000 ?
opiexe()+14449 call delexe() 000000000 ? 000000000 ?
000000000 ? 2B30E27E1E08 ?
2B30E1FCA000 ? 000000000 ?
opipls()+3098 call opiexe() 000000004 ? 000000005 ?
7FFFA85E6708 ? 2B30E27E1E08 ?
2B30E1FCA000 ? 000000000 ?
opiodr()+1149 call opipls() 000000066 ? 000000007 ?
7FFFA85E7F90 ? 000000000 ?
2B30E2701C28 ? 300000000 ?
__PGOSF141_rpidrus( call opiodr() 000000066 ? 000000007 ?
)+206 7FFFA85E7F90 ? 000000003 ?
008C71EF0 ? 300000000 ?
skgmstack()+148 call __PGOSF141_rpidrus( 7FFFA85E79A0 ? 000000007 ?
) 7FFFA85E7F90 ? 000000003 ?
008C71EF0 ? 300000000 ?
rpiswu2()+612 call skgmstack() 7FFFA85E7978 ? 00A9B2B20 ?
00000F618 ? 008468D40 ?
7FFFA85E79A0 ? 300000000 ?
rpidrv()+1342 call rpiswu2() 55CE5B2F8 ? 000000078 ?
55CE5B37C ? 000000009 ?
2B30E1FEEF98 ? 000000078 ?
psddr0()+459 call rpidrv() 000000003 ? 000000066 ?
7FFFA85E7F90 ? 000000039 ?
2B30E1FEEF98 ? 000000078 ?
psdnal()+457 call psddr0() 000000003 ? 000000066 ?
7FFFA85E7F90 ? 000000031 ?
2B30E1FEEF98 ? 000000078 ?
pevm_EXECC()+376 call psdnal() 7FFFA85E9370 ? 7FFFA85E9580 ?
7FFFA85E7F90 ? 2B30E2742370 ?
2B30E1FEEF98 ? 000000078 ?
pfrinstr_EXECC()+75 call pevm_EXECC() 2B30E273F0A0 ? 7FFFA85E9580 ?
000000020 ? 2B30E2742370 ?
2B30E1FEEF98 ? 000000078 ?
pfrrun_no_tool()+63 call pfrinstr_EXECC() 2B30E273F0A0 ? 51148B482 ?
2B30E273F110 ? 2B30E2742370 ?
2B30E1FEEF98 ? 2B3000000020 ?
pfrrun()+1025 call pfrrun_no_tool() 2B30E273F0A0 ? 51148B482 ?
2B30E273F110 ? 2B30E2742370 ?
2B30E1FEEF98 ? 2B3000000020 ?
plsql_run()+769 call pfrrun() 2B30E273F0A0 ? 000000000 ?
2B30E273F110 ? 7FFFA85E9370 ?
2B30E1FEEF98 ? 503AC23E2 ?
peicnt()+296 call plsql_run() 2B30E273F0A0 ? 000000001 ?
000000000 ? 7FFFA85E9370 ?
2B30E1FEEF98 ? 000000000 ?
kkxexe()+520 call peicnt() 7FFFA85E9370 ? 2B30E273F0A0 ?
2B30E2418960 ? 7FFFA85E9370 ?
2B30E2486008 ? 000000000 ?
opiexe()+14796 call kkxexe() 2B30E2013538 ? 2B30E273F0A0 ?
000000000 ? 7FFFA85E9370 ?
2B30E2486008 ? 000000000 ?
kpoal8()+2283 call opiexe() 000000049 ? 000000003 ?
7FFFA85EA8F8 ? 7FFFA85E9370 ?
2B30E2486008 ? 000000000 ?
opiodr()+1149 call kpoal8() 00000005E ? 00000001C ?
7FFFA85ED9D0 ? 7FFFA85E9370 ?
2B30E2486008 ? 5E00000001 ?
ttcpip()+1251 call opiodr() 00000005E ? 00000001C ?
7FFFA85ED9D0 ? 000000000 ?
008C71DB0 ? 5E00000001 ?
opitsk()+1628 call ttcpip() 00A9C6450 ? 0086CCB08 ?
7FFFA85ED9D0 ? 000000000 ?
7FFFA85ED430 ? 7FFFA85EDBD4 ?
opiino()+953 call opitsk() 00A9C6450 ? 000000000 ?
7FFFA85ED9D0 ? 000000000 ?
7FFFA85ED430 ? 7FFFA85EDBD4 ?
opiodr()+1149 call opiino() 00000003C ? 000000004 ?
7FFFA85EF0C8 ? 000000000 ?
7FFFA85ED430 ? 7FFFA85EDBD4 ?
opidrv()+565 call opiodr() 00000003C ? 000000004 ?
7FFFA85EF0C8 ? 000000000 ?
008C71860 ? 7FFFA85EDBD4 ?
sou2o()+98 call opidrv() 00000003C ? 000000004 ?
7FFFA85EF0C8 ? 000000000 ?
008C71860 ? 7FFFA85EDBD4 ?
opimai_real()+128 call sou2o() 7FFFA85EF0A0 ? 00000003C ?
000000004 ? 7FFFA85EF0C8 ?
008C71860 ? 7FFFA85EDBD4 ?
ssthrdmain()+209 call opimai_real() 000000002 ? 7FFFA85EF290 ?
000000004 ? 7FFFA85EF0C8 ?
008C71860 ? 7FFFA85EDBD4 ?
main()+196 call ssthrdmain() 000000002 ? 7FFFA85EF290 ?
000000001 ? 000000000 ?
008C71860 ? 7FFFA85EDBD4 ?
__libc_start_main() call main() 000000002 ? 7FFFA85EF438 ?
+244 000000001 ? 000000000 ?
008C71860 ? 7FFFA85EDBD4 ?
_start()+36 call __libc_start_main() 0009D3E88 ? 000000002 ?
7FFFA85EF428 ? 000000000 ?
008C71860 ? 000000002 ?

错误由此删除语句引起:

DELETE FROM EIMABS.FACT_OPEN_SALES_ORDER WHERE 
DIM_SNAPSHOT_TYPE_ID = 
(SELECT DIM_SNAPSHOT_TYPE_ID FROM EIMABS.DIM_SNAPSHOT_TYPE WHERE SNAPSHOT_TYPE_CODE='FUTURE')

其中EIMABS.DIM_SNAPSHOT_TYPE是一个普通堆表,而EIMABS.FACT_OPEN_SALES_ORDER是一个分区表,针对该分区表的各个分区进行了validate structure分析:

SQL> @?/rdbms/admin/utlvalid
Table created.

SQL> set time on;

23:32:51 SQL> analyze table EIMABS.DIM_SNAPSHOT_TYPE validate structure cascade;
Table analyzed.

00:30:46 SQL> analyze table EIMABS.FACT_OPEN_SALES_ORDER partition (P_2455405) validate structure cascade into invalid_rows;
analyze table EIMABS.FACT_OPEN_SALES_ORDER partition (P_2455405) validate structure cascade into invalid_rows
*
ERROR at line 1:
ORA-01499: table/index cross reference failure - see trace file

推测可能是P_2455405分区相关的索引可能出现了讹误,尝试重建该表上的15个索引,再次测试相关应用发现问题仍未解决。此次产生的trace文件:

Dump file /u01/app/oracle/diag/rdbms/utdw016/utdw016a/incident/incdir_310187/utdw016a_ora_26473_i310187.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP,
Data Mining and Real Application Testing options
ORACLE_HOME = /u01/app/oracle/product/112utdw016
System name:	Linux
Node name:	x42k600
Release:	2.6.18-164.el5
Version:	#1 SMP Tue Aug 18 15:51:48 EDT 2009
Machine:	x86_64
Instance name: utdw016a
Redo thread mounted by this instance: 1
Oracle process number: 62
Unix process pid: 26473, image: oracle@x42k600

*** 2010-07-30 04:10:19.931
*** SESSION ID:(1993.31898) 2010-07-30 04:10:19.931
*** CLIENT ID:() 2010-07-30 04:10:19.931
*** SERVICE NAME:(utdw016-edw) 2010-07-30 04:10:19.931
*** MODULE NAME:(pmdtm@x42k604-zone2 (TNS V1-V3)) 2010-07-30 04:10:19.931
*** ACTION NAME:() 2010-07-30 04:10:19.931

Dump continued from file: /u01/app/oracle/diag/rdbms/utdw016/utdw016a/trace/utdw016a_ora_26473.trc
ORA-00600: internal error code, arguments: [kdsgrp1], [], [], [], [], [], [], [], [], [], [], []

========= Dump for incident 310187 (ORA 600 [kdsgrp1]) ========

*** 2010-07-30 04:10:19.932
dbkedDefDump(): Starting incident default dumps (flags=0x2, level=3, mask=0x0)
----- Current SQL Statement for this session (sql_id=9hfdcgzzgmgvp) -----
DELETE FROM EIMABS.FACT_OPEN_SALES_ORDER WHERE DIM_SNAPSHOT_TYPE_ID = (SELECT DIM_SNAPSHOT_TYPE_ID FROM EIMABS.DIM_SNAPSHOT_TYPE WHERE SNAPSHOT_TYPE_CODE='FUTURE')
----- PL/SQL Stack -----
----- PL/SQL Call Stack -----

SO: 0x5334781d0, type: 52, owner: 0x55d2646b8, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
      proc=0x55caf0778, name=transaction, file=ktccts.h LINE:388, pg=0
     (trans) flg = 0x00001e03, flg2 = 0x000c0000, flg3 = 0x00000000, prx = (nil), ros = 2147483647
     flg  = 0x00001e03: ALC TRN VUS VID CHG USN
     flg2 = 0x000c0000: PGA NIP
     flg3 = 0x00000000:
     bsn = 0x8419 bndsn = 0x841b spn = 0x85c7
     efd = 15 DID:
     file:kta.c lineno:1665
     parent xid: 0x0000.000.00000000
     env: (scn: 0x0a19.a0b7c9d4  xid: 0x0021.017.00028415  uba: 0x00e00545.0438.12  statement num=0  parent xid: xid: 0x0000.000.00000000  scn: 0x0a19.a0b7c9d9 0sch: scn: 0x0000.00000000  mascn: (scn: 0x0000.00000000)
     cev: (spc = 11546  arsp = 0x5335450a8  ubkds (ubk:tsn: 2 rdba: 0x00e00545 flag:0x8 hdl:(nil) addr:0x35c50c014)  useg tsn: 2 rdba: 0x00e2c990
           hwm uba: 0x00e00545.0438.12  col uba: 0x00000000.0000.00
           num bl: 3 bk list: 0x53db19518)
           cr opc: 0x0 spc: 11546 uba: 0x00e00545.0438.12
     ccbstg: 0x00000000
     (enqueue) TX-00210017-00028415	DID: 0001-003E-00000C70
     lv: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  res_flag: 0x47
     mode: X, lock_flag: 0x0, lock: 0x533478248, res: 0x5414c2da0
     own: 0x55d2646b8, sess: 0x8b37718, proc: 0x55caf0778, prv: 0x5414c2db0
     slk: (nil)
      xga: (nil), heap: UGA
     Trans IMU st: 0 Pool index 65535, Redo pool 0x533478980, Undo pool 0x533478a68
     Redo pool range [0x2b13aacccb90 0x2b13aacccb90 0x2b13aacd1390]
     Undo pool range [0x2b13aacc8390 0x2b13aacc8390 0x2b13aacccb90]
      chnf control flags 0x0         CHNF hwm uba uba: 0x00000000.0000.00        ----------------------------------------
       SO: 0x53db19518, type: 51, owner: 0x5334781d0, flag: -/-/-/0x00 if: 0x3 c: 0x3

SO: 0x55d2646b8, type: 4, owner: 0x55caf0778, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
    proc=0x55caf0778, name=session, file=ksu.h LINE:11467, pg=0
   (session) sid: 1993 ser: 31898 trans: 0x5334781d0, creator: 0x55caf0778
             flags: (0x45) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
             flags2: (0x40008) -/-
             DID: , short-term DID:
             txn branch: (nil)
             oct: 7, prv: 0, sql: 0x5534eae70, psql: 0x55a4ff230, user: 120/EIMABS
   ksuxds FALSE at location: 0
   service name: utdw016-edw
   client details:
     O/S info: user: infom, term: , ospid: 21955
     machine: x42k604-zone2 program: pmdtm@x42k604-zone2 (TNS V1-V3)
     application name: pmdtm@x42k604-zone2 (TNS V1-V3), hash value=4200765728
   Current Wait Stack:
     Not in wait; last wait ended 1.028093 sec ago
   Wait State:
     fixed_waits=0 flags=0x21 boundary=(nil)/-1
   Session Wait History:
       elapsed time of 1.028173 sec since last wait
    0: waited for 'Disk file operations I/O'
       FileOperation=0x5, fileno=0x1, filetype=0x3
       wait_id=4666 seq_num=4860 snap_id=2
       wait times: snap=0.000039 sec, exc=0.000181 sec, total=0.000687 sec
       wait times: max=infinite
       wait counts: calls=0 os=0
       occurred after 0.000000 sec of elapsed time
    1: waited for 'ASM file metadata operation'
       msgop=0x12, locn=0x0, =0x0
       wait_id=4667 seq_num=4859 snap_id=2
       wait times: snap=0.000002 sec, exc=0.000005 sec, total=0.000506 sec
       wait times: max=infinite
       wait counts: calls=0 os=0
       occurred after 0.000000 sec of elapsed time
    2: waited for 'KSV master wait'
       =0x0, =0x0, =0x0
       wait_id=4668 seq_num=4858 snap_id=1
       wait times: snap=0.000501 sec, exc=0.000501 sec, total=0.000501 sec
       wait times: max=infinite
       wait counts: calls=1 os=1
       occurred after 0.000000 sec of elapsed time
    3: waited for 'ASM file metadata operation'
       msgop=0x12, locn=0x0, =0x0
       wait_id=4667 seq_num=4857 snap_id=1
       wait times: snap=0.000003 sec, exc=0.000003 sec, total=0.000003 sec
       wait times: max=infinite
       wait counts: calls=0 os=0
       occurred after 0.000000 sec of elapsed time
    4: waited for 'Disk file operations I/O'
       FileOperation=0x5, fileno=0x1, filetype=0x3
       wait_id=4666 seq_num=4856 snap_id=1
       wait times: snap=0.000142 sec, exc=0.000142 sec, total=0.000142 sec
       wait times: max=infinite
       wait counts: calls=0 os=0
......

Block header dump:  0x0400f521 Data

Block header dump:  0x2317a579 Index

Block header dump:  0x2317a577 " "

Block header dump:  0x048c8c3c " "

Block header dump:  0x2317a1bb " "

Block header dump:  0x048c78ad " "

Block header dump:  0x0400f51f Data

Block header dump:  0x2317a33b Index

Block header dump:  0x048c78f3 " "

Block header dump:  0x07541a44 " "

Block header dump:  0x07577b92 " "

Block header dump:  0x078a4eb7 " "

Block header dump:  0x2317a4b7 " "

Block header dump:  0x040fe621 " "

Block header dump:  0x2317a47b " "

同时应用人员发现此系统中另一SQL语句也会导致ORA-600[kdsgrp1]错误的出现,如下:

SELECT
F.DIM_BIZ_SECTOR_ID AS DIM_BIZ_SECTOR_ID,
F.DW_REVENUE_ID ,
F.DIM_ENT_ITEM_ID AS DIM_ENT_ITEM_ID,
F.DIM_REV_PCH_KEY_ACCT_ID AS DIM_PCH_KEY_ACCOUNT_ID,
CT.DIM_PGH_COUNTRY_GROUP_ID AS DIM_PGH_COUNTRY_GROUP_ID,
F.DIM_REVENUE_DATE_ID AS DIM_FORECAST_DATE_ID,
NEXT_DAY(SYSDATE-4.000000000000000,'FRI') AS SNAPSHOT_DATE,
F.REVENUE_DT AS FORECAST_DATE,
F.REVENUE_QTY AS REVENUE_QTY
FROM
EIMABS.FACT_REVENUE F,
EIMABS.DIM_BIZ_SECTOR B,
EIMABS.DIM_ENT_ITEM E,
EIMABS.DIM_PCH_KEY_ACCOUNT PCH,
EIMABS.DIM_COUNTRY CT,
EIMABS.DIM_FISCAL_CAL_DATE CAL
WHERE
F.DIM_BIZ_SECTOR_ID = B.DIM_BIZ_SECTOR_ID
AND F.DIM_ENT_ITEM_ID = E.DIM_ENT_ITEM_ID
AND F.DIM_REV_PCH_KEY_ACCT_ID = PCH.DIM_PCH_KEY_ACCOUNT_ID
AND F.DIM_ULT_DEST_COUNTRY_ID = CT.DIM_COUNTRY_ID
AND UPPER(B.BIZ_SECTOR_CODE) = 'MDB'
AND F.DIM_REVENUE_DATE_ID = CAL.DIM_CALENDAR_DATE_ID
AND CAL.FISCAL_MONTH_NUM IN
(SELECT FISCAL_MONTH_NUM FROM EIMABS.DIM_FISCAL_CAL_MONTH
WHERE DIM_CALENDAR_MONTH_ID IN (
(SELECT B.DIM_CALENDAR_MONTH_ID -1 FROM EIMABS.DIM_FISCAL_CAL_DATE A , EIMABS.DIM_FISCAL_CAL_MONTH B
WHERE CALENDAR_DT = TRUNC(SYSDATE) AND A.DIM_CALENDAR_MONTH_ID = B.DIM_CALENDAR_MONTH_ID),
(SELECT B.DIM_CALENDAR_MONTH_ID -2 FROM EIMABS.DIM_FISCAL_CAL_DATE A , EIMABS.DIM_FISCAL_CAL_MONTH B
WHERE CALENDAR_DT = TRUNC(SYSDATE) AND A.DIM_CALENDAR_MONTH_ID = B.DIM_CALENDAR_MONTH_ID)));

ERROR at line 12:
ORA-00600: internal error code, arguments: [kdsgrp1], [], [], [], [], [], [],
[], [], [], [], []

/*相关trace文件如下*/

Trace file /u01/app/oracle/diag/rdbms/utdw016/utdw016a/trace/utdw016a_ora_26473.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP,
Data Mining and Real Application Testing options
ORACLE_HOME = /u01/app/oracle/product/112utdw016
System name:	Linux
Node name:	x42k600
Release:	2.6.18-164.el5
Version:	#1 SMP Tue Aug 18 15:51:48 EDT 2009
Machine:	x86_64
Instance name: utdw016a
Redo thread mounted by this instance: 1
Oracle process number: 62
Unix process pid: 26473, image: oracle@x42k600


*** 2010-07-30 04:10:18.249
*** SESSION ID:(1993.31898) 2010-07-30 04:10:18.249
*** CLIENT ID:() 2010-07-30 04:10:18.249
*** SERVICE NAME:(utdw016-edw) 2010-07-30 04:10:18.249
*** MODULE NAME:(pmdtm@x42k604-zone2 (TNS V1-V3)) 2010-07-30 04:10:18.249
*** ACTION NAME:() 2010-07-30 04:10:18.249

* kdsgrp1-1: *************************************************
           row 0x0400f521.1a continuation at
           0x0400f521.1a file# 16 block# 62753 slot 26 not found
KDSTABN_GET: 0 ..... ntab: 1
curSlot: 26 ..... nrows: 28
kdsgrp - dump CR block dba=0x0400f521
Block header dump:  0x0400f521
Object id on Block? Y
seg/obj: 0x11527d  csc: 0xa19.61e20b3c  itc: 2  flg: E  typ: 1 - DATA
    brn: 0  bdba: 0x400f500 ver: 0x01 opc: 0
    inc: 0  exflg: 0

Itl           Xid                  Uba         Flag  Lck        Scn/Fsc
0x01   0x0040.02f.0001bfcd  0x2822b8ea.0224.34  C-U-    0  scn 0x0a19.61e1aa84
0x02   0x003f.01c.00028920  0x2822f9de.01e0.6b  --U-   26  fsc 0x0000.61e21527
bdba: 0x0400f521
data_block_dump,data header at 0x2d63ec064

这个case同时提交了SR,Oracle GCS支持分析日志后认为告警日志中曾经出现kewastUnPackStats记录,说明可能由11.2.0.1上的Bug 8967729 引起的:

I researched the issue further based upon the error that followed the log switch command,

Tue Aug 03 10:00:04 2010
ALTER SYSTEM ARCHIVE LOG
Tue Aug 03 10:00:05 2010
Thread 1 advanced to log sequence 8652 (LGWR switch)
Current log# 4 seq# 8652 mem# 0: +UAT_DATA/utdw016/redo041a.log
Current log# 4 seq# 8652 mem# 1: +UAT_ARCH/utdw016/redo042a.log
Tue Aug 03 10:00:14 2010
Archived Log entry 16346 added for thread 1 sequence 8651 ID 0x8d616825 dest 1:
Tue Aug 03 10:00:21 2010
ALTER SYSTEM ARCHIVE LOG
Tue Aug 03 10:00:23 2010
Thread 1 advanced to log sequence 8653 (LGWR switch)
Current log# 5 seq# 8653 mem# 0: +UAT_DATA/utdw016/redo051a.log
Current log# 5 seq# 8653 mem# 1: +UAT_ARCH/utdw016/redo052a.log
Tue Aug 03 10:00:23 2010
Archived Log entry 16348 added for thread 1 sequence 8652 ID 0x8d616825 dest 1:
Tue Aug 03 10:00:45 2010
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> kewastUnPackStats(): bad magic 1 (0x2b29e289bf13, 0)

We need to resolve this issue and then determine whether these indexes corrupt again within the database.

I found Bug 8967729 11.2.0.1 Abstract: KEWASTUNPACKSTATS(): BAD MAGIC MESSAGE IN ALERT.LOG.

Basically, there is a archivelog switch issue that is causes string corruption.

This issue was introduced by the fix of bug #8715387 and has been fully fixed as part of Bug 8730312 11.2 Abstract: FWD MERGE FOR BASE Bug 8715387 FOR 12G.

Please download and install patch 8730312 for your Oracle and OS versions.
However, if you have installed patches in this 11.2 database, then upload the results of the Opatch inventory.
We will check the installed database patches against patch 8730312 for any contradictions.

Hdr: 8967729 11.2.0.1 RDBMS 11.2.0.1 SVRMAN AWR PRODID-5 PORTID-226 8730312
Abstract: KEWASTUNPACKSTATS(): BAD MAGIC MESSAGE IN ALERT.LOG
PROBLEM:
--------
In a two-node RAC cluster (+ Data Guard), the rac instances write many
strange messages in alert log, such:
kewastUnPackStats(): bad magic 1 (0x2ac893121390, 0)
The hex address changes.

DIAGNOSTIC ANALYSIS:
--------------------
I don't see any error associated with this message.
It looks like Bug 8730312 description, but the base bug 8715387 should be
already fixed in 11.2.0.1 version.

WORKAROUND:
-----------
n/a

RELATED BUGS:
-------------
8715387, 8730312

REPRODUCIBILITY:
----------------

TEST CASE:
----------

STACK TRACE:
------------
Tue Sep 22 09:15:34 2009
ALTER SYSTEM ARCHIVE LOG
Tue Sep 22 09:15:34 2009
LGWR: Standby redo logfile selected to archive thread 1 sequence 1244
LGWR: Standby redo logfile selected for thread 1 sequence 1244 for
destination LOG_ARCHIVE_DEST_2
Thread 1 advanced to log sequence 1244 (LGWR switch)
  Current log# 2 seq# 1244 mem# 0:
+DGCTRL/saneons/onlinelog/group_2.264.697133919
Archived Log entry 3903 added for thread 1 sequence 1243 ID 0x5186bbfd dest
1:
Tue Sep 22 10:00:02 2009
kewastUnPackStats(): bad magic 1 (0x2b1d760d3038, 0)
kewastUnPackStats(): bad magic 1 (0x2b1d760d3038, 0)

MOS认为应用补丁8730312可以解决我们的问题,但实际apply patch后EIMABS.FACT_OPEN_SALES_ORDER上的DELETE语句可以正常执行了,而之后发现的查询语句仍会报ORA-00600:[kdsgrp1]错误:

We have applied the patch. And we're in process of analyze all the partitions. So far there's no error reported. We analyzed all the partitions in table EIMABS.FACT_REVENUE, there's no error either. However, when we run the query, we still get the same error. Please note the other tables in the query are not partitioned.

SELECT
F.DIM_BIZ_SECTOR_ID AS DIM_BIZ_SECTOR_ID,
F.DW_REVENUE_ID ,
F.DIM_ENT_ITEM_ID AS DIM_ENT_ITEM_ID,
F.DIM_REV_PCH_KEY_ACCT_ID AS DIM_PCH_KEY_ACCOUNT_ID,
CT.DIM_PGH_COUNTRY_GROUP_ID AS DIM_PGH_COUNTRY_GROUP_ID,
F.DIM_REVENUE_DATE_ID AS DIM_FORECAST_DATE_ID,
NEXT_DAY(SYSDATE-4.000000000000000,'FRI') AS SNAPSHOT_DATE,
F.REVENUE_DT AS FORECAST_DATE,
F.REVENUE_QTY AS REVENUE_QTY
FROM
EIMABS.FACT_REVENUE F,
EIMABS.DIM_BIZ_SECTOR B,
EIMABS.DIM_ENT_ITEM E,
EIMABS.DIM_PCH_KEY_ACCOUNT PCH,
EIMABS.DIM_COUNTRY CT,
EIMABS.DIM_FISCAL_CAL_DATE CAL
WHERE
F.DIM_BIZ_SECTOR_ID = B.DIM_BIZ_SECTOR_ID
AND F.DIM_ENT_ITEM_ID = E.DIM_ENT_ITEM_ID
AND F.DIM_REV_PCH_KEY_ACCT_ID = PCH.DIM_PCH_KEY_ACCOUNT_ID
AND F.DIM_ULT_DEST_COUNTRY_ID = CT.DIM_COUNTRY_ID
AND UPPER(B.BIZ_SECTOR_CODE) = 'MDB'
AND F.DIM_REVENUE_DATE_ID = CAL.DIM_CALENDAR_DATE_ID
AND CAL.FISCAL_MONTH_NUM IN
(SELECT FISCAL_MONTH_NUM FROM EIMABS.DIM_FISCAL_CAL_MONTH
WHERE DIM_CALENDAR_MONTH_ID IN (
(SELECT B.DIM_CALENDAR_MONTH_ID -1 FROM EIMABS.DIM_FISCAL_CAL_DATE A , EIMABS.DIM_FISCAL_CAL_MONTH B
WHERE CALENDAR_DT = TRUNC(SYSDATE) AND A.DIM_CALENDAR_MONTH_ID = B.DIM_CALENDAR_MONTH_ID),
(SELECT B.DIM_CALENDAR_MONTH_ID -2 FROM EIMABS.DIM_FISCAL_CAL_DATE A , EIMABS.DIM_FISCAL_CAL_MONTH B
WHERE CALENDAR_DT = TRUNC(SYSDATE) AND A.DIM_CALENDAR_MONTH_ID = B.DIM_CALENDAR_MONTH_ID)));

SELECT
*
ERROR at line 1:
ORA-00600: internal error code, arguments: [kdsgrp1], [], [], [], [], [], [],
[], [], [], [], []

/*以下为trace文件*/
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP,
Data Mining and Real Application Testing options
ORACLE_HOME = /u01/app/oracle/product/112utdw016
System name:	Linux
Node name:	x42k600
Release:	2.6.18-164.el5
Version:	#1 SMP Tue Aug 18 15:51:48 EDT 2009
Machine:	x86_64
Instance name: utdw016a
Redo thread mounted by this instance: 1
Oracle process number: 64
Unix process pid: 7170, image: oracle@x42k600 (TNS V1-V3)


*** 2010-08-05 19:10:19.776
*** SESSION ID:(10.4634) 2010-08-05 19:10:19.776
*** CLIENT ID:() 2010-08-05 19:10:19.776
*** SERVICE NAME:(SYS$USERS) 2010-08-05 19:10:19.776
*** MODULE NAME:(sqlplus@x42k600 (TNS V1-V3)) 2010-08-05 19:10:19.776
*** ACTION NAME:() 2010-08-05 19:10:19.776

* kdsgrp1-1:
*************************************************
           row 0x04608b75.40 continuation at
           0x04608b75.40 file# 17 block# 2132853 slot 64 not found
KDSTABN_GET: 0 ..... ntab: 1
curSlot: 64 ..... nrows: 130
kdsgrp - dump CR block dba=0x04608b75
Block header dump:  0x04608b75
Object id on Block? Y
seg/obj: 0x1c8071  csc: 0xa19.622a6023  itc: 2  flg: E  typ: 1 - DATA
    brn: 0  bdba: 0x4608b40 ver: 0x01 opc: 0
    inc: 0  exflg: 0

Itl           Xid                  Uba         Flag  Lck        Scn/Fsc
0x01   0x000f.040.0001267d  0x01067067.022e.1e  --U-   64  fsc 0x0000.622a621d
0x02   0x0029.026.0001be36  0x282115c8.0223.0a  C---    0  scn 0x0a19.62297970  <---------- this TX shows in the index too
bdba: 0x04608b75
data_block_dump,data header at 0x47c16c064
===============
tsiz: 0x3f98
hsiz: 0x116
pbl: 0x47c16c064
    76543210
flag=--------
ntab=1
nrow=130
frre=64
..
..
tab 0, row 63, @0x3a65
tl: 110 fb: --H-FL-- lb: 0x1  cc: 22
col  0: [ 5]  c4 0e 31 32 04
col  1: [ 2]  c1 02
col  2: [ 5]  c4 02 44 33 44
col  3: [ 5]  c4 03 14 10 23
col  4: [ 5]  c4 09 5f 35 38
col  5: [ 5]  c4 05 32 42 0b
col  6: [ 2]  c2 03
col  7: [ 5]  c4 03 2e 36 49
col  8: [ 1]  80
col  9: [ 1]  80
col 10: [ 7]  32 30 34 31 39 32 35
col 11: [ 1]  4e
col 12: [ 7]  78 6e 06 18 01 01 01
col 13: [ 2]  c1 06
col 14: [ 3]  c2 4d 33
col 15: [ 7]  78 6e 07 1b 0a 0d 04
col 16: [ 4]  c3 05 2f 25
col 17: [ 2]  c1 09
col 18: [ 3]  c2 02 50
col 19: [ 3]  c2 02 50
col 20: [ 2]  c1 0e
col 21: [ 8]  38 30 30 31 31 38 35 38
end_of_block_dump


Block dump from cache:
Dump of buffer cache at level 4 for tsn=13, rdba=73436021
BH (0x47fd84178) file#: 17 rdba: 0x04608b75 (17/2132853) class: 1 ba: 0x47c16c000
 set: 47 pool 3 bsz: 16384 bsi: 0 sflg: 1 pwc: 0,25
 dbwrid: 0 obj: 1867889 objn: 1130693 tsn: 13 afn: 17 hint: f
 hash: [0x54be43860,0x54be43860] lru: [0x49beca1a0,0x3b7e094c0]
 ckptq: [NULL] fileq: [NULL] objq: [0x52a0e8580,0x52a0e8580]
 use: [0x54271be40,0x54271be40] wait: [NULL]
 st: SCURRENT md: SHR tch: 0 le: 0x3effd22c8
 flags:
 LRBA: [0x0.0.0] LSCN: [0x0.0] HSCN: [0xffff.ffffffff] HSUB: [65535]
 cr pin refcnt: 0 sh pin refcnt: 0
Block dump from disk:
buffer tsn: 13 rdba: 0x04608b75 (17/2132853)
scn: 0x0a19.622a621d seq: 0x01 flg: 0x06 tail: 0x621d0601
frmt: 0x02 chkval: 0xdf67 type: 0x06=trans data

Block header dump:  0x04608b75
Object id on Block? Y
seg/obj: 0x1c8071  csc: 0xa19.622a6023  itc: 2  flg: E  typ: 1 - DATA
    brn: 0  bdba: 0x4608b40 ver: 0x01 opc: 0
    inc: 0  exflg: 0

Itl           Xid                  Uba         Flag  Lck        Scn/Fsc
0x01   0x000f.040.0001267d  0x01067067.022e.1e  --U-   64  fsc 0x0000.622a621d
0x02   0x0029.026.0001be36  0x282115c8.0223.0a  C---    0  scn 0x0a19.62297970
bdba: 0x04608b75

Incident 322216 created, dump file: /u01/app/oracle/diag/rdbms/utdw016/utdw016a/incident/incdir_322216/utdw016a_ora_7170_i322216.trc
ORA-00600: internal error code, arguments: [kdsgrp1], [], [], [], [], [], [], [], [], [], [], []

utdw016a_ora_7170_i322218.trc
-------------------------------
----- Current SQL Statement for this session (sql_id=88kca6rwpm9pc) -----
SELECT
F.DIM_BIZ_SECTOR_ID AS DIM_BIZ_SECTOR_ID,
F.DW_REVENUE_ID ,
F.DIM_ENT_ITEM_ID AS DIM_ENT_ITEM_ID,
 F.DIM_REV_PCH_KEY_ACCT_ID AS DIM_PCH_KEY_ACCOUNT_ID,
 CT.DIM_PGH_COUNTRY_GROUP_ID AS DIM_PGH_COUNTRY_GROUP_ID,
  F.DIM_REVENUE_DATE_ID AS DIM_FORECAST_DATE_ID,
 NEXT_DAY(SYSDATE-4.000000000000000,'FRI') AS SNAPSHOT_DATE,
 F.REVENUE_DT AS FORECAST_DATE,
 F.REVENUE_QTY AS REVENUE_QTY
FROM
 EIMABS.FACT_REVENUE F,
 EIMABS.DIM_BIZ_SECTOR B,
 EIMABS.DIM_ENT_ITEM E,
 EIMABS.DIM_PCH_KEY_ACCOUNT PCH,
 EIMABS.DIM_COUNTRY CT,
 EIMABS.DIM_FISCAL_CAL_DATE CAL
WHERE
   F.DIM_BIZ_SECTOR_ID = B.DIM_BIZ_SECTOR_ID
AND F.DIM_ENT_ITEM_ID = E.DIM_ENT_ITEM_ID
AND F.DIM_REV_PCH_KEY_ACCT_ID = PCH.DIM_PCH_KEY_ACCOUNT_ID
AND F.DIM_ULT_DEST_COUNTRY_ID = CT.DIM_COUNTRY_ID
AND UPPER(B.BIZ_SECTOR_CODE) = 'MDB'
AND F.DIM_REVENUE_DATE_ID = CAL.DIM_CALENDAR_DATE_ID
AND CAL.FISCAL_MONTH_NUM IN
(SELECT FISCAL_MONTH_NUM FROM EIMABS.DIM_FISCAL_CAL_MONTH
 WHERE DIM_CALENDAR_MONTH_ID IN (
      (SELECT B.DIM_CALENDAR_MONTH_ID -1 FROM EIMABS.DIM_FISCAL_CAL_DATE A , EIMABS.DIM_FISCAL_CAL_MONTH B
          WHERE CALENDAR_DT = TRUNC(SYSDATE) AND A.DIM_CALENDAR_MONTH_ID = B.DIM_CALENDAR_MONTH_ID),
          (SELECT B.DIM_CALENDAR_MONTH_ID -2 FROM EIMABS.DIM_FISCAL_CAL_DATE A , EIMABS.DIM_FISCAL_CAL_MONTH B
          WHERE CALENDAR_DT = TRUNC(SYSDATE) AND A.DIM_CALENDAR_MONTH_ID = B.DIM_CALENDAR_MONTH_ID)))

----- Call Stack Trace -----
 kdsgrp1  kdsgrp  qetlbr  qertbFetchByRowID  qerjotRowProc  qerbtFetch  wProc  qergiFetch

  BH (0x47fd84178) file#: 17 rdba: 0x04608b75 (17/2132853) class: 1 ba: 0x47c16c000
       set: 47 pool 3 bsz: 16384 bsi: 0 sflg: 1 pwc: 0,25
       dbwrid: 0 obj: 1867889 objn: 1130693 tsn: 13 afn: 17 hint: f

addr: 0x47fd84178 obj: 1867889 cls: DATA bscn: 0xa19.622a621d
       buffer tsn: 13 rdba: 0x04608b75 (17/2132853)
       scn: 0x0a19.622a621d seq: 0x01 flg: 0x06 tail: 0x621d0601
       frmt: 0x02 chkval: 0xdf67 type: 0x06=trans data

Block header dump:  0x04608b75
Object id on Block? Y
seg/obj: 0x1c8071  csc: 0xa19.622a6023  itc: 2  flg: E  typ: 1 - DATA
    brn: 0  bdba: 0x4608b40 ver: 0x01 opc: 0
    inc: 0  exflg: 0

Itl           Xid                  Uba         Flag  Lck        Scn/Fsc
0x01   0x000f.040.0001267d  0x01067067.022e.1e  --U-   64  fsc 0x0000.622a621d
0x02   0x0029.026.0001be36  0x282115c8.0223.0a  C---    0  scn 0x0a19.62297970
bdba: 0x04608b75
data_block_dump,data header at 0x47c16c064
===============
tsiz: 0x3f98
hsiz: 0x116
pbl: 0x47c16c064
    76543210
flag=--------
ntab=1
nrow=130
frre=64


     BH (0x49fe84af8) file#: 29 rdba: 0x076e5058 (29/3035224) class: 1 ba: 0x49ee0c000
       set: 44 pool 3 bsz: 16384 bsi: 0 sflg: 1 pwc: 0,25
       dbwrid: 1 obj: 1893758 objn: 1893758 tsn: 17 afn: 29 hint: f
       addr: 0x49fe84af8 obj: 1893758 cls: DATA bscn: 0xa19.62297970
       buffer tsn: 17 rdba: 0x076e5058 (29/3035224)
       scn: 0x0a19.62297970 seq: 0x01 flg: 0x06 tail: 0x79700601
       frmt: 0x02 chkval: 0xe878 type: 0x06=trans data

Block header dump:  0x076e5058
Object id on Block? Y
seg/obj: 0x1ce57e  csc: 0xa19.6229787e  itc: 2  flg: E  typ: 2 - INDEX
    brn: 0  bdba: 0x76e5054 ver: 0x01 opc: 0
    inc: 0  exflg: 0

Itl           Xid                  Uba         Flag  Lck        Scn/Fsc
0x01   0x0000.000.00000000  0x00000000.0000.00  ----    0  fsc 0x0000.00000000
0x02   0x0029.026.0001be36  0x282115de.0223.2a  --U-   14  fsc 0x0000.62297970  <--------------- same TX as in the table


之后MOS又有回复,认为设置隐式参数_row_cr=FALSE可以解决问题:

There are few bugs that could raise the ora-600[KDSGRP1]  in 11.2

1) based on the stack --> Bug:8771916 ORA-600 [KDSGRP1] WHEN DOING AN UPDATE


Abstract:            OERI [kdsgrp1] during CR read
Fixed-Releases:     C100
Tags:               OERI
Details:
 ORA-600 [kdsgrp1] can occur intermittently when using
 a query access path to a row in a table via an index
 due to a consistent read problem.
 Workaround:
   Disabling rowCR (which is an optimization to reduce consistent-read
   rollbacks during queries) by setting "_row_cr"=FALSE in the
   initialization files in one workaround. However, this could cause
   performance degradation of queries - the statistics "RowCR hits" /
   "RowCR attempts" can help show if this workaround may be detrimental
   to performance.


2) based on the fact it is hit on partitioned tables

Bug 8546356  ORA-8102/ORA-1499/OERI[kdsgrp1] Composite Partitioned Index corruption after rebuild ONLINE
Details:
  When a COMPOSITE PARTITIONED index is rebuild ONLINE and concurrent DML on
  the same table is run on separate RAC instances, index corruption might
  happen where the index is missing some keys. This is only pertaining to
  composite partitioned indexes.
  Wrong results or the next errors can be produced by SQL statements:
  ORA-8102 by a delete/update
  ORA-1499 by "analyze table validate structure cascade"
  ORA-600 [kdsgrp1]
  ORA-600 [qertbFetchByRowID]
  Workaround:
  Do not run concurrent DML from any instance other than the one where index
  online rebuild is happening or rebuild the index without the ONLINE clause.
  To fix it: Rebuild the index.

Please set in init.ora this parameter _row_cr=FALSE and bounce database,
 see after that if OERI[kdsgrp1] still reproduces.

There is one-off patch available for Bug 8771916 for 11.2.0.1 on LInux x86_64
                                              and for Bug 8546356 the one-off patch is done for 11.2.0.1.2

There is also Bug:8951812 hit a lot in 11.2.0.1, one-off patch available
An index can become corrupt during index rebuild online producing
 ORA-600 errors or other external like ORA-8102 by an update/delete,
 ORA-1499 by "analyze table validate structure cascade".

这个case仍在继续,to be continued .....

沪ICP备14014813号-2

沪公网安备 31010802001379号