随着Oracle技术本身的不断发展,“自动化”和“智能化”的数据库时代已经来临。无论是运维管理、开发调试,传统DBA们的工作内容都已经发生了很大变化。一些诸如内存池划分调整、归档日志管理等功能,都已经被Oracle自动或者半自动的特性所解决。对新一代DBA而言,保持不断学习的精神,接受新问题,发现属于自己的一片新天地,才是当务之急。
今天,和一个朋友解决了一个运维环境问题。笔者感觉很有意思,记录下来,供需要的朋友不时之需。
1、问题说明
今天,一个朋友从QQ上提出问题,说在测试环境的一台10gR2库,近期突然生成很多Trace Dump文件。每个文件大小在4-5M,频率每分钟若干次。几天之内占用了上百G的空间,删除无用文件之后依然产生。
Oracle Trace文件从本质上是Oracle前后台进程在特殊的情景下,例如开启跟踪模式、运行异常,自动向文件系统中输出的诊断文件。Trace文件通常以trc结尾,包含进程环境信息、运行过程和故障点输出。对Oracle官方和管理人员而言,Trace文件是诊断的重要依据。
正常运行情况下,每台数据库都会生成一些trc文件,每个文件大小在几k左右,是不会产生朋友遇到的问题的。
之后,朋友将数据库alert log和一个trace文件样本发给笔者。Trace文件大小在4M左右,明显超过正常大小。之所以还要alert log,是因为Oracle在生成trace文件时候,通常对应alert log中有相应记录。
2、问题分析
朋友的数据库环境是Oracle 10gR2,具体版本是10.2.0.3.0.。从alert log中,可以发现是一个标准的Windows数据库环境。
System parameters with non-default values:
processes = 150
sga_target = 612368384
control_files = D:\ORADATA\ORACLE10\CONTROL01.CTL, D:\ORADATA\ORACLE10\CONTROL02.CTL, D:\ORADATA\ORACLE10\CONTROL03.CTL
db_block_size = 8192
compatible = 10.2.0.3.0
db_file_multiblock_read_count= 16
db_recovery_file_dest = D:\oracle\product\10.2.0\flash_recovery_area
db_recovery_file_dest_size= 2147483648
undo_management = AUTO
undo_tablespace = UNDOTBS1
remote_login_passwordfile= EXCLUSIVE
在alert log中,我们果然发现了很多异常点。从若干天之前,就不断报错异常。
Wed Jan 21 12:49:10 2015
db_recovery_file_dest_size of 2048 MB is 0.00% used. This is a
user-specified limit on the amount of space that will be used by this
database for recovery-related files, and does not reflect the amount of
space available in the underlying filesystem or ASM diskgroup.
Wed Jan 21 12:49:11 2015
Completed: alter database open
Wed Jan 21 12:49:22 2015
Errors in file d:\oracle\product\10.2.0\admin\oracle10\bdump\oracle10_j002_2524.trc:
Wed Jan 21 12:49:28 2015
Errors in file d:\oracle\product\10.2.0\admin\oracle10\bdump\oracle10_j000_2516.trc:
Wed Jan 21 12:49:34 2015
Errors in file d:\oracle\product\10.2.0\admin\oracle10\bdump\oracle10_j003_3752.trc:
Wed Jan 21 12:49:35 2015
Errors in file d:\oracle\product\10.2.0\admin\oracle10\bdump\oracle10_j002_2524.trc:
ORA-12012: 自动执行作业 26 出错
ORA-08102: 未找到索引关键字, 对象号 239, 文件 1, 块 1674 (2)
之后,每隔约5秒钟,就生成一个trace文件,对应内容相同。
Mon Mar 23 09:30:52 2015
Errors in file d:\oracle\product\10.2.0\admin\oracle10\bdump\oracle10_j002_4348.trc:
ORA-12012: 自动执行作业 26 出错
ORA-08102: 未找到索引关键字, 对象号 239, 文件 1, 块 1674 (2)
Mon Mar 23 09:30:55 2015
Errors in file d:\oracle\product\10.2.0\admin\oracle10\bdump\oracle10_j001_1376.trc:
ORA-12012: 自动执行作业 4 出错
ORA-08102: 未找到索引关键字, 对象号 239, 文件 1, 块 1674 (2)
Mon Mar 23 09:30:56 2015
Errors in file d:\oracle\product\10.2.0\admin\oracle10\bdump\oracle10_j001_1376.trc:
ORA-12012: 自动执行作业 4 出错
ORA-08102: 未找到索引关键字, 对象号 239, 文件 1, 块 1674 (2)
再打开trace文件,文件名称为:oracle10_j000_5820。Jxxx通常为Oracle的自动作业Job后台进程,自动按照执行的规则后台执行。其中,包括了报错功能点:
*** 2015-03-23 09:30:38.468
ksedmp: internal or fatal error
Current SQL statement for this session:
update sys.job$ set failures=0, this_date=null, flag=:1, last_date=:2, next_date = greatest(:3, sysdate), total=total+(sysdate-nvl(this_date,sysdate)) where job=:4
执行job$修改操作时候,发出的错误信息。
诊断的依据中,“对象239,文件1,块1674(2)”是很好的入手点。从提示信息看,似乎这个对象遇到了坏块情况。文件1是system表空间,应该是Oracle内部对象。
由于笔者不能实际操作问题库,所以找到了类似的环境进行简单检查。
SQL> select * from v$version;
BANNER
----------------------------------------------------------------
Oracle Database 10g Enterprise Edition Release 10.2.0.3.0 - Prod
PL/SQL Release 10.2.0.3.0 - Production
CORE 10.2.0.3.0 Production
TNS for 32-bit Windows: Version 10.2.0.3.0 - Production
NLSRTL Version 10.2.0.3.0 – Production
找到object_id=239对象。
SQL> select object_name, object_type, status from dba_objects where object_id=239;
OBJECT_NAME OBJECT_TYPE STATUS
-------------------- ------------------- -------
I_JOB_NEXT INDEX VALID
报错对象是一个索引对象,对应的段结构。
SQL> select SEGMENT_TYPE, TABLESPACE_NAME, HEADER_FILE, HEADER_BLOCK, BLOCKS, EXTENTS from dba_segments where segment_name='I_JOB_NEXT';
SEGMENT_TYPE TABLESPACE_NAME HEADER_FILE HEADER_BLOCK BLOCKS EXTENTS
------------------ -------------------- ----------- ------------ ---------- ----------
INDEX SYSTEM 1 1673 8 1
对应的索引段结构很小,只有一个extents,合计八个数据块。注意:头块编号为1673。报错块号为1674,是段头块后面第一个数据块。
熟悉Oracle段结构的朋友一定知道,索引段后第一个数据块就是索引树的根节点块。报错信息很可能是出现了索引段损坏的情况。
3、问题修复
在Oracle中,坏块是很难处理的一种故障。从官方角度,坏块的来源有两个:一个是软硬件存储之间的不兼容,另一个是Oracle内部Bug。处理坏块的手段有很多,落实到这个案例中,索引段坏块是比较好处理的一种。
最简单的处理策略是尝试rebuild索引,让数据库重新整理结构。模拟操作:
SQL> alter index I_JOB_NEXT rebuild;
Index altered
让朋友在环境上进行测试,发现执行成功,索引状态也是valid。但是问题依然存在,trace文件还会生成。
索要最新的alert log之后,发现报错信息变化。
Mon Mar 23 10:15:35 2015
Errors in file d:\oracle\product\10.2.0\admin\oracle10\bdump\oracle10_j002_6932.trc:
ORA-00604: 递归 SQL 级别 1 出现错误
ORA-08102: 未找到索引关键字, 对象号 239, 文件 1, 块 65946 (2)
ORA-12012: 自动执行作业 26 出错
ORA-08102: 未找到索引关键字, 对象号 239, 文件 1, 块 65946 (2)
Mon Mar 23 10:15:37 2015
Errors in file d:\oracle\product\10.2.0\admin\oracle10\bdump\oracle10_j001_7056.trc:
ORA-00604: 递归 SQL 级别 1 出现错误
ORA-08102: 未找到索引关键字, 对象号 239, 文件 1, 块 65946 (2)
ORA-12012: 自动执行作业 4 出错
ORA-08102: 未找到索引关键字, 对象号 239, 文件 1, 块 65946 (2)
注意,报错内容发生了变化。块号变化到了system表空间另一个位置。说明:rebuild操作生效,修改了index的结构,但是错误依然存在。
笔者的一种猜想是:也许rebuild操作并不能直观反映数据表的数据情况,而报错问题是在索引数据和表段数据的不一致。尝试解决方法:drop后重新create索引对象。
SQL> drop index i_job_next;
Index dropped
SQL> create index i_job_next on job$ (next_date);
Index created
之后,问题解决。
4、结论
相对于各种复杂问题,今天这个问题相对比较单纯简单。但是这个问题告诉我们教训。首先,问题处理要从核心线索入手,层层深入,最后定位问题。其次,对于一些想当然的概念,如rebuild,要更加深层次理解含义,更详细的分析。