ORA-7445(kcrfw_update_blk_list)错误

Posted on 2011/12/25 by yangtingkun

客户的11.2数据库测试环境中碰到了ORA-7445(kcrfw_update_blk_list)错误。
详细的错误信息如下：

Tue DEC 20 22:00:02 2011
BEGIN automatic SQL Tuning Advisor run FOR special tuning task "SYS_AUTO_SQL_TUNING_TASK"
Tue DEC 20 22:00:46 2011
Exception [TYPE: SIGBUS, Non-existent physical address] [ADDR:0x62652000] [PC:0x216E0C4, kcrfw_update_blk_list()+196] [flags: 0x0, COUNT: 1]
Errors IN file /u01/app/oracle/diag/rdbms/fhacdb/fhacdb/trace/fhacdb_lgwr_24506.trc (incident=140173):
ORA-07445: exception encountered: core dump [kcrfw_update_blk_list()+196] [SIGBUS] [ADDR:0x62652000] [PC:0x216E0C4] [Non-existent physical address] []
Incident details IN: /u01/app/oracle/diag/rdbms/fhacdb/fhacdb/incident/incdir_140173/fhacdb_lgwr_24506_i140173.trc
USE ADRCI OR Support Workbench TO package the incident.
See Note 411.1 at My Oracle Support FOR error AND packaging details.
Tue DEC 20 22:00:48 2011
Dumping diagnostic DATA IN directory=[cdmp_20111220220048], requested BY (instance=1, osid=24506 (LGWR)), summary=[incident=140173].
Tue DEC 20 22:00:49 2011
PMON (ospid: 24482): terminating the instance due TO error 470
System state dump requested BY (instance=1, osid=24482 (PMON)), summary=[abnormal instance termination].
System State dumped TO trace file /u01/app/oracle/diag/rdbms/fhacdb/fhacdb/trace/fhacdb_diag_24492.trc
Tue DEC 20 22:00:50 2011
ORA-1092 : opitsk aborting process
Tue DEC 20 22:00:50 2011
License high water mark = 45
Dumping diagnostic DATA IN directory=[cdmp_20111220220049], requested BY (instance=1, osid=24482 (PMON)), summary=[abnormal instance termination].
Instance TERMINATED BY PMON, pid = 24482
USER (ospid: 17228): terminating the instance
Instance TERMINATED BY USER, pid = 17228
Tue DEC 20 22:01:03 2011
Adjusting the DEFAULT VALUE OF parameter parallel_max_servers
FROM 960 TO 685 due TO the VALUE OF parameter processes (700)
Starting ORACLE instance (normal)
WARNING: You are trying TO USE the MEMORY_TARGET feature. This feature requires the /dev/shm file system TO be mounted FOR at least 7868514304 bytes. /dev/shm IS either NOT mounted OR IS mounted WITH available SPACE less than this SIZE. Please fix this so that MEMORY_TARGET can WORK AS expected. CURRENT available IS 7857356800 AND used IS 562315264 bytes. Ensure that the mount point IS /dev/shm FOR this directory.
memory_target needs larger /dev/shm
Wed DEC 21 09:34:59 2011
Adjusting the DEFAULT VALUE OF parameter parallel_max_servers
FROM 960 TO 685 due TO the VALUE OF parameter processes (700)
Starting ORACLE instance (normal)
WARNING: You are trying TO USE the MEMORY_TARGET feature. This feature requires the /dev/shm file system TO be mounted FOR at least 7784628224 bytes. /dev/shm IS either NOT mounted OR IS mounted WITH available SPACE less than this SIZE. Please fix this so that MEMORY_TARGET can WORK AS expected. CURRENT available IS 7742439424 AND used IS 677232640 bytes. Ensure that the mount point IS /dev/shm FOR this directory.
memory_target needs larger /dev/shm

对应的详细信息为：

*** 2011-12-20 22:00:46.889
*** SESSION ID:(586.1) 2011-12-20 22:00:46.889
*** CLIENT ID:() 2011-12-20 22:00:46.889
*** SERVICE NAME:(SYS$BACKGROUND) 2011-12-20 22:00:46.889
*** MODULE NAME:() 2011-12-20 22:00:46.889
*** ACTION NAME:() 2011-12-20 22:00:46.889
Dump continued FROM file: /u01/app/oracle/diag/rdbms/fhacdb/fhacdb/trace/fhacdb_lgwr_24506.trc
ORA-07445: exception encountered: core dump [kcrfw_update_blk_list()+196] [SIGBUS] [ADDR:0x62652000] [PC:0x216E0C4] [Non-existent physical address] []
========= Dump FOR incident 140173 (ORA 7445 [kcrfw_update_blk_list()+196]) ========
----- Beginning of Customized Incident Dump(s) -----
Exception [TYPE: SIGBUS, Non-existent physical address] [ADDR:0x62652000] [PC:0x216E0C4, kcrfw_update_blk_list()+196] [flags: 0x0, COUNT: 1]
Registers:
%rax: 0x0000000000015ffc %rbx: 0x0000000000000000 %rcx: 0x0000000000033908
%rdx: 0x000000006263c000 %rdi: 0x0000000000001d55 %rsi: 0x000000000000eaa8
%rsp: 0x00007fff89e18410 %rbp: 0x00007fff89e18440  %r8: 0x0000000000000002
 %r9: 0x0000000000015ffc %r10: 0x000000006263c000 %r11: 0x000000000000eaa8
%r12: 0x0000000000001d55 %r13: 0x00007fc19ece10b8 %r14: 0x0000000000000002
%r15: 0x0000000000000000 %rip: 0x000000000216e0c4 %efl: 0x0000000000010212
  kcrfw_update_blk_list()+170 (0x216e0aa) mov 0x5deb4677(%rip),%r12d
  kcrfw_update_blk_list()+177 (0x216e0b1) mov 0x5deb4660(%rip),%rdx
  kcrfw_update_blk_list()+184 (0x216e0b8) lea 0x0(,%r12,8),%r11
  kcrfw_update_blk_list()+192 (0x216e0c0) lea (%r11,%r12,4),%rax
> kcrfw_update_blk_list()+196 (0x216e0c4) mov %ebx,0x4(%rax,%rdx)
  kcrfw_update_blk_list()+200 (0x216e0c8) mov 0x5deb465a(%rip),%edx
  kcrfw_update_blk_list()+206 (0x216e0ce) mov 0x78(%r13),%rcx
  kcrfw_update_blk_list()+210 (0x216e0d2) mov 0x34(%rcx,%r15),%r15d
  kcrfw_update_blk_list()+215 (0x216e0d7) lea 0x0(,%rdx,8),%rax
*** 2011-12-20 22:00:46.901
dbkedDefDump(): Starting a non-incident diagnostic dump (flags=0x3, level=3, mask=0x0)
----- SQL Statement (None) -----
CURRENT SQL information unavailable - no cursor.
----- Call Stack Trace -----
calling              CALL     entry                argument VALUES IN hex      
location             TYPE     point                (? means dubious VALUE)     
-------------------- -------- -------------------- ----------------------------
skdstdst()+36        CALL     kgdsdst()            000000000 ? 000000000 ?
                                                   7FC19EEA4098 ? 000000001 ?
                                                   000000001 ? 000000003 ?
ksedst1()+98         CALL     skdstdst()           000000000 ? 000000000 ?
                                                   7FC19EEA4098 ? 000000001 ?
                                                   000000000 ? 000000003 ?
ksedst()+34          CALL     ksedst1()            000000001 ? 000000001 ?
                                                   7FC19EEA4098 ? 000000001 ?
                                                   000000000 ? 000000003 ?
dbkedDefDump()+2741  CALL     ksedst()             000000001 ? 000000001 ?
                                                   7FC19EEA4098 ? 000000001 ?
                                                   000000000 ? 000000003 ?
ksedmp()+36          CALL     dbkedDefDump()       000000003 ? 000000003 ?
                                                   7FC19EEA4098 ? 000000001 ?
                                                   000000000 ? 000000003 ?
ssexhd()+2366        CALL     ksedmp()             000000003 ? 000000003 ?
                                                   7FC19EEA4098 ? 000000001 ?
                                                   000000000 ? 000000003 ?
__sighandler()       CALL     ssexhd()             000000007 ? 7FC19EEACD70 ?
                                                   7FC19EEACC68 ? 000000001 ?
                                                   000000000 ? 000000003 ?
kcrfw_update_blk_li  signal   __sighandler()       000001D55 ? 00000EAA8 ?
st()+196                                           06263C000 ? 000033908 ?
                                                   000000002 ? 000015FFC ?
kcrfw_post()+284     CALL     kcrfw_update_blk_li  7FC19ECE10B8 ? 00000EAA8 ?
                              st()                 06263C000 ? 000033908 ?
                                                   000000002 ? 000015FFC ?
kcrfw_redo_write()+  CALL     kcrfw_post()         7FFF89E18FB8 ? 00000EAA8 ?
2528                                               06263C000 ? 000033908 ?
                                                   000000002 ? 000015FFC ?
ksbabs()+771         CALL     kcrfw_redo_write()   7FFF89E18FB8 ? 000000018 ?
                                                   06263C000 ? 000033908 ?
                                                   000000002 ? 000015FFC ?
ksbrdp()+971         CALL     ksbabs()             7FFF89E18FB8 ? 000000018 ?
                                                   06263C000 ? 000033908 ?
                                                   000000002 ? 000015FFC ?
opirip()+618         CALL     ksbrdp()             7FFF89E18FB8 ? 000000018 ?
                                                   06263C000 ? 000033908 ?
                                                   000000002 ? 000015FFC ?
opidrv()+598         CALL     opirip()             000000032 ? 000000004 ?
                                                   7FFF89E1A178 ? 000033908 ?
                                                   000000002 ? 000015FFC ?
sou2o()+98           CALL     opidrv()             000000032 ? 000000004 ?
                                                   7FFF89E1A178 ? 000033908 ?
                                                   000000002 ? 000015FFC ?
opimai_real()+261    CALL     sou2o()              7FFF89E1A150 ? 000000032 ?
                                                   000000004 ? 7FFF89E1A178 ?
                                                   000000002 ? 000015FFC ?
ssthrdmain()+252     CALL     opimai_real()        000000000 ? 7FFF89E1A340 ?
                                                   000000004 ? 7FFF89E1A178 ?
                                                   000000002 ? 000015FFC ?
main()+196           CALL     ssthrdmain()         000000003 ? 7FFF89E1A340 ?
                                                   000000001 ? 000000000 ?
                                                   000000002 ? 000015FFC ?
__libc_start_main()  CALL     main()               000000003 ? 7FFF89E1A4E0 ?
+253                                               000000001 ? 000000000 ?
                                                   000000002 ? 000015FFC ?
_start()+36          CALL     __libc_start_main()  000A07804 ? 000000001 ?
                                                   7FFF89E1A4D8 ? 000000000 ?
                                                   000000002 ? 000015FFC ?
--------------------- Binary Stack Dump ---------------------

虽然这个错误信息在MOS上没有任何记录，根据错误信息和TRACE信息不难判断，导致问题的原因是由于内存空间不足所致。
由于配置的MEMORY_TARGET的值大于/dev/shm的值，导致Oracle在处理内存地址时出现了异常，从而导致数据库的崩溃。
那么解决问题的方法很简单，缩小MEMORY_TARGET的值，或增大/dev/shm的设置，确保MEMORY_TARGET小于/dev/shm，数据库即可正常启动。

Posted in BUG | Tagged , , , | Leave a comment

JDBC使用INSERT RETURN语句报错ORA-439

Posted on 2011/12/24 by yangtingkun

在给客户开发人员讲解LOB列的访问方式后，开发人员尝试在JDBC中使用包含RETURN的INSERT语句，但是出现了ORA-439错误。
检查后发现客户的程序使用的还是PreparedStatement语句，而RETURNING语句，则是Oracle扩展的SQL语法，因此在声明语句的时候必须使用OraclePreparedStatement方式进行声明。
除了修改SQL语句外，使用OraclePreparedStatement声明语句变量外，还需要注册输出参数，类似的代码如下：

OraclePreparedStatement sqlstmt = 
(OraclePreparedStatement)conn.prepareStatement
("insert into t_lob values (?, ?, empty_clob()) returning contents into ?");
sqlstmt.setInt(1, 1);
sqlstmt.setString(2, "a");
sqlstmt.registerReturnParameter(3, OracleTypes.CLOB);
sqlstat.executeUpdate();
ResultSet resset = sqlstmt.getReturnResultSet();
IF (resset.next())
{
CLOB contents = (CLOB)resset.getClob(2);
...
}

不过即使开发人员声明了OraclePreparedStatement语句，仍然找不到registerReturnParameter过程。
当前的数据库的版本是11.2.0.2，没有道理不支持RETURN语句，何况JDBC的RETURNING语句是从10.2的JDBC就引入新特性。
查询了一下当前客户端JDBC的驱动版本，发现居然还是9.2的版本，这就难怪使用RETURN语句的时候，会出现ORA-439的错误了。
很多时候数据库的版本已经升级到很高的版本，但是应用程序使用的版本或驱动没有进行升级，同样很多新特性无法使用。而且一般而言，推荐客户端驱动版本和所连接数据库的版本保持一致，这样出现BUG的可能性最小。

Posted in ORACLE | Tagged , , , , , , | Leave a comment

插入LOB对象的方法

Posted on 2011/12/23 by yangtingkun

其实以前写过类似的文章，但是都是在其他例子中，没有专门针对这个问题进行过描述，最近发现，还有很多人不清楚，插入一个包含LOB对象的记录需要几个步骤。
在客户的环境中，发现插入一条包含LOB的记录，居然用了四个步骤：

SQL> CREATE TABLE T_LOB (ID NUMBER, NAME VARCHAR2(30), CONTENTS CLOB);
表已创建。
SQL> DECLARE
2 V_CLOB CLOB;
3 V_STR VARCHAR2(32767) := LPAD('A', 4000, 'A');
4 BEGIN
5 INSERT INTO T_LOB 
6 VALUES (1, 'A', EMPTY_CLOB());
7 SELECT CONTENTS 
8 INTO V_CLOB
9 FROM T_LOB
10 WHERE ID = 1
11 FOR UPDATE;
12 DBMS_LOB.WRITE(V_CLOB, 4000, 1, V_STR);
13 UPDATE T_LOB 
14 SET CONTENTS = V_CLOB
15 WHERE ID = 1;
16 COMMIT;
17 END;
18 /
PL/SQL 过程已成功完成。

可以看到，为了插入一条包含LOB的记录，客户首先插入EMPTY_CLOB，然后通过SELECT预计获取LOB的定位符，通过DBMS_LOB包写入数据，最后通过UPDATE语句，对LOB列进行更新。
在上面的步骤中，UPDATE不是必须的，即使不对LOB列执行UPDATE操作，也会导致记录的插入：

SQL> DECLARE
2 V_CLOB CLOB;
3 V_STR VARCHAR2(32767) := LPAD('B', 4000, 'B');
4 BEGIN
5 INSERT INTO T_LOB 
6 VALUES (2, 'B', EMPTY_CLOB());
7 SELECT CONTENTS 
8 INTO V_CLOB
9 FROM T_LOB
10 WHERE ID = 2
11 FOR UPDATE;
12 DBMS_LOB.WRITE(V_CLOB, 4000, 1, V_STR);
13 COMMIT;
14 END;
15 /
PL/SQL 过程已成功完成。

而事实上，这里的SELECT FOR UPDATE语句同样是不必要的，这个语句可以由INSERT的RETURN语句来代替：

SQL> DECLARE
  2  V_CLOB CLOB;
  3  V_STR VARCHAR2(32767) := LPAD('C', 4000, 'C');
  4  BEGIN
  5  INSERT INTO T_LOB 
  6  VALUES (3, 'C', EMPTY_CLOB())
  7  RETURN CONTENTS INTO V_CLOB;
  8  DBMS_LOB.WRITE(V_CLOB, 4000, 1, V_STR);
  9  COMMIT;
 10  END;
 11  /
PL/SQL 过程已成功完成。
SQL> SET LONG 40
SQL> SELECT * FROM T_LOB;
        ID NAME                           CONTENTS
---------- ------------------------------ ----------------------------------------
         3 C                              CCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCCC
         1 A                              AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
         2 B                              BBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBBB

插入包含LOB的记录，除了DBMS_LOB部分一般是必不可少的，此外只需要INSERT语句本身，其他的SELECT和UPDATE语句都不是必须的。去掉这些不必要的步骤，可以有效的降低程序和数据库交互次数，减少单个操作调用的语句数量，从而提高操作的性能。

Posted in ORACLE | Tagged , , , , | Leave a comment

批量加载性能案例

Posted on 2011/12/22 by yangtingkun

客户在大量加载数据是遇到性能问题，检查后发现客户采用的是单条插入单条提交这种最缓慢的方式，为了给客户说明优化效果，现场做了几个代码。
最简单的优化方式莫过于减少COMMIT频度，而最优化的方式是采用批量插入的方式，简单的测试代码如下：

SQL> CREATE TABLE T_INSERT (ID NUMBER, NAME VARCHAR2(30));
TABLE created.
SQL> SET TIMING ON 
SQL> BEGIN
2 FOR I IN 1..100000 LOOP
3 INSERT INTO T_INSERT VALUES (I, 'A' || I);
4 COMMIT;
5 END LOOP;
6 END;
7 /
PL/SQL PROCEDURE successfully completed.
Elapsed: 00:00:05.22
SQL> BEGIN
2 FOR I IN 1..100000 LOOP
3 INSERT INTO T_INSERT VALUES (I, 'A' || I);
4 COMMIT;
5 END LOOP;
6 END;
7 /
PL/SQL PROCEDURE successfully completed.
Elapsed: 00:00:05.51
SQL> BEGIN
2 FOR I IN 1..100000 LOOP
3 INSERT INTO T_INSERT VALUES (I, 'A' || I);
4 IF MOD(I, 1000) = 0 THEN
5 COMMIT;
6 END IF;
7 END LOOP;
8 COMMIT;
9 END;
10 /
PL/SQL PROCEDURE successfully completed.
Elapsed: 00:00:04.01
SQL> BEGIN
2 FOR I IN 1..100000 LOOP
3 INSERT INTO T_INSERT VALUES (I, 'A' || I);
4 IF MOD(I, 1000) = 0 THEN
5 COMMIT;
6 END IF;
7 END LOOP;
8 COMMIT;
9 END;
10 /
PL/SQL PROCEDURE successfully completed.
Elapsed: 00:00:02.64
SQL> DECLARE
2 TYPE T_NUM IS TABLE OF NUMBER INDEX BY BINARY_INTEGER;
3 TYPE T_VAR IS TABLE OF VARCHAR2(30) INDEX BY BINARY_INTEGER;
4 V_NUM T_NUM;
5 V_VAR T_VAR;
6 BEGIN
7 FOR I IN 1..100000 LOOP
8 V_NUM(I) := I;
9 V_VAR(I) := 'A' || I;
10 END LOOP;
11 FORALL I IN 1..100000 
12 INSERT INTO T_INSERT VALUES (V_NUM(I), V_VAR(I));
13 COMMIT;
14 END;
15 /
PL/SQL PROCEDURE successfully completed.
Elapsed: 00:00:00.37
SQL> DECLARE
2 TYPE T_NUM IS TABLE OF NUMBER INDEX BY BINARY_INTEGER;
3 TYPE T_VAR IS TABLE OF VARCHAR2(30) INDEX BY BINARY_INTEGER;
4 V_NUM T_NUM;
5 V_VAR T_VAR;
6 BEGIN
7 FOR I IN 1..100000 LOOP
8 V_NUM(I) := I;
9 V_VAR(I) := 'A' || I;
10 END LOOP;
11 FORALL I IN 1..100000 
12 INSERT INTO T_INSERT VALUES (V_NUM(I), V_VAR(I));
13 COMMIT;
14 END;
15 /
PL/SQL PROCEDURE successfully completed.
Elapsed: 00:00:00.50

这个例子明确说明了单条提交、批量提交以及数值插入的性能差异，很多时候只是口头上的描述，客户不会有太深的印象，而如果通过这种例子来展示性能的差别，结果一目了然，比再多的描述都管用得多。

Posted in ORACLE | Tagged , | Leave a comment

创建ASM启动SPFILE报错ORA-17502

Posted on 2011/12/21 by yangtingkun

客户的数据库的ASM启动存在问题，通过手工创建PFILE，解决了ASM启动的问题，但是尝试利用PFILE生成SPFILE时报错。
详细错误信息为：

[grid@rptdb ~]$ sqlplus / AS sysasm
SQL*Plus: Release 11.2.0.2.0 Production ON Tue DEC 20 19:05:33 2011
Copyright (c) 1982, 2010, Oracle. ALL rights reserved.
Connected.
SQL> shutdown abort
ASM instance shutdown
SQL> startup pfile=/home/grid/init+ASM.ora
ASM instance started
Total System Global Area 283930624 bytes
Fixed SIZE 2225792 bytes
Variable SIZE 256539008 bytes
ASM Cache 25165824 bytes
ASM diskgroups mounted
SQL> CREATE spfile FROM pfile='/home/grid/init+ASM.ora';
CREATE spfile FROM pfile='/home/grid/init+ASM.ora'
*
ERROR at line 1:
ORA-17502: ksfdcre:4 Failed TO CREATE file +DATA/asm/asmparameterfile/registry.253.770384221
ORA-15177: cannot operate ON system aliases

查询ASM状态，并无异常存在：

SQL> SELECT name, group_number, alias_directory, system_created FROM v$asm_alias;
NAME                             GROUP_NUMBER A S
-------------------------------- ------------ - -
RPTALL                                      1 Y Y
DATAFILE                                    1 Y Y
SYSTEM.256.770384991                        1 N Y
SYSAUX.257.770384991                        1 N Y
UNDOTBS1.258.770384991                      1 N Y
USERS.259.770384991                         1 N Y
CONTROLFILE                                 1 Y Y
CURRENT.261.770385125                       1 N Y
CURRENT.260.770385125                       1 N Y
ONLINELOG                                   1 Y Y
group_1.262.770385127                       1 N Y
group_1.263.770385129                       1 N Y
group_2.264.770385129                       1 N Y
group_2.265.770385129                       1 N Y
group_3.266.770385129                       1 N Y
group_3.267.770385129                       1 N Y
TEMPFILE                                    1 Y Y
TEMP.268.770385133                          1 N Y
PARAMETERFILE                               1 Y Y
spfile.269.770385249                        1 N Y
spfilerptall.ora                            1 N N
21 ROWS selected.

可以看到，ASM磁盘组中并不存在asm/asmparameterfile目录，那么导致问题的原因多半是由于这个目录属于Oracle自动创建的目录，而一旦原始的spfile被删除，则目录自动删除，从而导致新创建的操作出现异常。

SQL> CREATE spfile='+DATA' FROM pfile='/home/grid/init+ASM.ora';
File created.
SQL> SELECT name, group_number, alias_directory, system_created FROM v$asm_alias;
NAME                          GROUP_NUMBER A S
----------------------------- ------------ - -
ASM                                      1 Y Y
ASMPARAMETERFILE                         1 Y Y
REGISTRY.253.770411755                   1 N Y
RPTALL                                   1 Y Y
DATAFILE                                 1 Y Y
SYSTEM.256.770384991                     1 N Y
SYSAUX.257.770384991                     1 N Y
UNDOTBS1.258.770384991                   1 N Y
USERS.259.770384991                      1 N Y
CONTROLFILE                              1 Y Y
CURRENT.261.770385125                    1 N Y
CURRENT.260.770385125                    1 N Y
ONLINELOG                                1 Y Y
group_1.262.770385127                    1 N Y
group_1.263.770385129                    1 N Y
group_2.264.770385129                    1 N Y
group_2.265.770385129                    1 N Y
group_3.266.770385129                    1 N Y
group_3.267.770385129                    1 N Y
TEMPFILE                                 1 Y Y
TEMP.268.770385133                       1 N Y
PARAMETERFILE                            1 Y Y
spfile.269.770385249                     1 N Y
spfilerptall.ora                         1 N N
24 ROWS selected.

果然再次尝试同样的命令，参数文件顺利创建成功，且对应的ASM目录也自动生成。因此，导致问题的原因应该是第一次创建ASM的参数文件时，导致最早创建的ASM参数文件被删除，引发了ASM目录被删除，而使得创建操作失败。
第二次创建ASM参数文件，则不存在这个问题，因此Oracle会自动创建ASM目录和SPFILE文件。

Posted in ORACLE | Tagged , , , | Leave a comment

ACTIVE DATAGUARD上的ORA-1555错误

Posted on 2011/12/20 by yangtingkun

11g的ACTIVE DATAGUARD极大的增强了物理STANDBY的功能，可惜任何新特性都很难避免bug的产生，ACTIVE DATAGUARD同样也不例外。
已经有多个客户反应ACTIVE DATAGUARD上执行报表查询出现ORA-1555错误，错误和初始化参数UNDO_RETENTION的设置没有直接关系。而且如果打开了USING CURRENT LOG选项，不但可能导致SNAPSHOT TOO OLD错误，还可能导致整个STANDBY数据库性能越来越慢，以至于完全不可用，最终不得不重启。
查询了一下MOS，发现Oracle确认了这个bug：ORA-01555 on Active Data Guard Standby Database [ID 1273808.1]。
解决这个问题，出了应用对应的补丁10018789之外，也可以考虑将数据库升级到11.2.0.2.2以上。如果是Windows环境，那么比较升级到11.2.0.2.3以上。

Posted in BUG | Tagged , , | Leave a comment

RAC环境关闭CLUSTER后导致连接缓慢

Posted on 2011/12/19 by yangtingkun

客户的四节点RAC在停掉三个后，发现连接RAC明显变慢。

数据库环境是4节点的10.2 RAC for Linux X86-64。由于心跳存在问题，目前将三个节点上的CLUSTER关闭，但是随后不久，客户反应数据库访问变慢。
虽然本来4个节点繁忙程度都不高，但是将4个实例上的压力集中到1个实例上，那么性能有所下降也是正常的。不过检查数据库的工作状态，并未发现异常，无论是从后台cpu忙闲程度，还是从awr报告中查看，似乎并没有太大的压力。
询问客户是查询变慢还是登录变慢，客户也搞不清其中的差别，于是在尝试连接数据库，结果发现，无论是tnsping还是sqlplus登录，有时登录很快，有时要经历3秒到6秒的等待，这应该就是客户反应慢的原因。
检查登录数据库的TNSNAMES.ORA中的配置，客户默认4个节点作为LOAD BALANCE和静态FAILOVER，这种配置方式在节点关闭后并不会导致错误，但是有可能由于需要等待超时而经受性能问题。
检查服务器上CLUSTER的状态，发现4个节点上，有两个VIP的服务都停掉了，应该是用户关闭整个CLUSTER服务是导致的。在此情况下，静态FAILOVER发挥作用，但是会引入超时的问题。而由于配置了LOAD_BALANCE，Oracle会轮训4个VIP地址，这就导致了有时候连接很快完成，而有时连接需要等待3秒以上。
由于存在众多的客户端，无法一一修改客户端使用的TNS配置，那么最简单的解决办法就是将CLUSTER启动，只是关闭其他三个节点的数据库，这样所有的VIP都处于启动状态，即使连接到没有提供的服务的节点，也可以快速的重新启动到启动节点上。
将其他两个VIP关闭的CLUSTER启动，保持DB关闭状态，数据库连接缓慢的问题就此解决。

Posted in ORACLE | Tagged , , , | 2 Comments

ORA-600(kcbshlc_1)和ORA-7445(kggchk)错误

Posted on 2011/12/18 by yangtingkun

以前同时记录两个ORA-600错误，多半是由于这个两个错误在同时，是同一次故障的不同表现，而这次两个错误则是分别出现。
客户的10.2.0.4的逻辑STANDBY备库上前后几次出现了这两个错误：

Thu Jun 16 13:45:05 2011
Errors IN file /u01/app/oracle/admin/db/bdump/db_pmon_27660.trc:
ORA-07445: exception encountered: core dump [kggchk()+77] [SIGSEGV] [Address NOT mapped TO object] [0x000000000] [] []
Thu Jun 16 13:45:13 2011
CKPT: terminating instance due TO error 472
Instance TERMINATED BY CKPT, pid = 27670
.
.
.
Sat Jun 25 01:44:02 2011
Errors IN file /u01/app/oracle/admin/db/bdump/db_pmon_18907.trc:
ORA-00600: internal error code, arguments: [kcbshlc_1], [5], [], [], [], [], [], []
Sat Jun 25 01:44:04 2011
Errors IN file /u01/app/oracle/admin/db/bdump/db_pmon_18907.trc:
ORA-00600: internal error code, arguments: [kcbshlc_1], [5], [], [], [], [], [], []
Sat Jun 25 01:44:04 2011
PMON: terminating instance due TO error 472
Sat Jun 25 01:44:04 2011
krvxerpt: Errors detected IN process 20, ROLE reader.
Sat Jun 25 01:44:04 2011
krvxmrs: Leaving BY exception: 472
Sat Jun 25 01:44:04 2011
Errors IN file /u01/app/oracle/admin/db/bdump/db_p000_19090.trc:
ORA-00472: PMON process TERMINATED WITH error
LOGSTDBY STATUS: ORA-00472: PMON process TERMINATED WITH error
.
.
.
Mon Oct 31 23:23:03 2011
Errors IN file /u01/app/oracle/admin/db/bdump/db_pmon_20147.trc:
ORA-07445: exception encountered: core dump [kggchk()+77] [SIGSEGV] [Address NOT mapped TO object] [0x000000000] [] []
Mon Oct 31 23:23:07 2011
CJQ0: terminating instance due TO error 472
Mon Oct 31 23:23:07 2011
krvxerpt: Errors detected IN process 20, ROLE reader.
Mon Oct 31 23:23:07 2011
krvxmrs: Leaving BY exception: 472
Mon Oct 31 23:23:07 2011
Errors IN file /u01/app/oracle/admin/db/bdump/db_p000_20224.trc:
ORA-00472: PMON process TERMINATED WITH error
LOGSTDBY STATUS: ORA-00472: PMON process TERMINATED WITH error
Mon Oct 31 23:23:07 2011
Errors IN file /u01/app/oracle/admin/db/bdump/db_psp0_20149.trc:
ORA-00472: PMON process TERMINATED WITH error

之所以将两个错误合在一起是有原因的，一方面无论是ORA-600(kcbshlc_1)错误，还是ORA-7445(kggchk)错误，错误都出现在PMON进程上，而且都直接导致了数据库的崩溃；其二，逻辑STANDBY的应用一般都是只读应用，一般来说出错概率最大的都是应用进程，而这两个错误在这方面的表相是一样的，虽然都导致了数据库崩溃，但是数据库重启之后，错误并不会马上重现，日志的应用可以顺利的执行，这说明错误和日志应用没有必然的因果关系；其三，也是最重要的一点，在ORA-7445的详细trace中，在kggchk函数之前出现的就是kcbshlc函数：

*** 2011-10-31 23:23:03.108
ksedmp: internal OR fatal error
ORA-07445: exception encountered: core dump [kggchk()+77] [SIGSEGV] [Address NOT mapped TO object] [0x000000000] [] []
----- Call Stack Trace -----
calling              CALL     entry                argument VALUES IN hex      
location             TYPE     point                (? means dubious VALUE)     
-------------------- -------- -------------------- ----------------------------
ksedst()+31          CALL     ksedst1()            000000000 ? 000000001 ?
                                                   2A97172D50 ? 2A97172DB0 ?
                                                   2A97172CF0 ? 000000000 ?
ksedmp()+610         CALL     ksedst()             000000000 ? 000000001 ?
                                                   2A97172D50 ? 2A97172DB0 ?
                                                   2A97172CF0 ? 000000000 ?
ssexhd()+629         CALL     ksedmp()             000000003 ? 000000001 ?
                                                   2A97172D50 ? 2A97172DB0 ?
                                                   2A97172CF0 ? 000000000 ?
__funlockfile()+64   CALL     ssexhd()             00000000B ? 2A97173D70 ?
                                                   2A97173C40 ? 2A97172DB0 ?
                                                   2A97172CF0 ? 000000000 ?
kggchk()+77          signal   __funlockfile()      0066876E0 ? 000000000 ?
                                                   000000018 ? 0010F4468 ?
                                                   000000000 ? 0052EBEA0 ?
kcbshlc()+105        CALL     kggchk()             0066876E0 ? 000000000 ?
                                                   000000018 ? 0010F4468 ?
                                                   000000000 ? 0052EBEA0 ?
kslilcr()+770        CALL     kcbshlc()            0066876E0 ? 84EC40698 ?
                                                   000000018 ? 0010F4468 ?
                                                   000000000 ? 0052EBEA0 ?
ksl_cleanup()+1567   CALL     kslilcr()            0010F4468 ? 000000000 ?
                                                   000000000 ? 84EC40698 ?
                                                   0066876E0 ? 0052EBEA0 ?
ksuxfl()+492         CALL     ksl_cleanup()        000000000 ? 000000000 ?
                                                   000000000 ? 84EC40698 ?
                                                   0066876E0 ? 0052EBEA0 ?
ksuxda()+55          CALL     ksuxfl()             85F3A6168 ? 000000000 ?
                                                   000000000 ? 84EC40698 ?
                                                   0066876E0 ? 0052EBEA0 ?
ksucln()+1390        CALL     ksuxda()             85F3A6168 ? 000000000 ?
                                                   000000000 ? 84EC40698 ?
                                                   0066876E0 ? 0052EBEA0 ?
ksbrdp()+794         CALL     ksucln()             060008100 ? 000000000 ?
                                                   043FC1A0B ? 84EC40698 ?
                                                   0066876E0 ? 0052EBEA0 ?
opirip()+616         CALL     ksbrdp()             060008100 ? 000000000 ?
                                                   000000001 ? 060008100 ?
                                                   0066876E0 ? 0052EBEA0 ?
opidrv()+582         CALL     opirip()             000000032 ? 000000004 ?
                                                   7FBFFFF738 ? 060008100 ?
                                                   0066876E0 ? 0052EBEA0 ?
sou2o()+114          CALL     opidrv()             000000032 ? 000000004 ?
                                                   7FBFFFF738 ? 060008100 ?
                                                   0066876E0 ? 0052EBEA0 ?
opimai_real()+317    CALL     sou2o()              7FBFFFF710 ? 000000032 ?
                                                   000000004 ? 7FBFFFF738 ?
                                                   0066876E0 ? 0052EBEA0 ?
main()+116           CALL     opimai_real()        000000003 ? 7FBFFFF7A0 ?
                                                   000000004 ? 7FBFFFF738 ?
                                                   0066876E0 ? 0052EBEA0 ?
__libc_start_main()  CALL     main()               000000003 ? 7FBFFFF7A0 ?
+219                                               000000004 ? 7FBFFFF738 ?
                                                   0066876E0 ? 0052EBEA0 ?
_start()+42          CALL     __libc_start_main()  000713988 ? 000000001 ?
                                                   7FBFFFF8E8 ? 005288D00 ?
                                                   000000000 ? 000000003 ?
--------------------- Binary Stack Dump ---------------------

根据上面三点进行判断，这两个错误应该是同一个BUG引发的，根据MOS查询ORA-600 [kcbshlc_1] [ID 1274837.1]文档记录的信息最为接近，要解决这个问题可以通过将数据库版本升级到10.2.0.4.3或10.2.0.5。

Posted in BUG | Tagged , , , , | Leave a comment

ORA-7445(_ssbev_env)错误

Posted on 2011/12/17 by yangtingkun

客户的Oracle 10201 for Windows环境频繁出现这个错误。
详细的错误信息为：

Fri DEC 16 16:27:02 2011
Errors IN file d:\oracle\product\10.2.0\db_1\rdbms\trace\px_ora_5360.trc:
ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [unable_to_trans_pc] [PC:0x7D611D87] [ADDR:0x55909090] [UNABLE_TO_READ] []
Fri DEC 16 16:27:03 2011
Errors IN file d:\oracle\product\10.2.0\db_1\rdbms\trace\px_ora_5360.trc:
ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [unable_to_trans_pc] [PC:0x7D611D87] [ADDR:0x55909090] [UNABLE_TO_READ] []
ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [unable_to_trans_pc] [PC:0x7D611D87] [ADDR:0x55909090] [UNABLE_TO_READ] []
Fri DEC 16 16:27:03 2011
Errors IN file d:\oracle\product\10.2.0\db_1\rdbms\trace\px_ora_5360.trc:
ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [unable_to_trans_pc] [PC:0x7D611D87] [ADDR:0x55909090] [UNABLE_TO_READ] []
ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [unable_to_trans_pc] [PC:0x7D611D87] [ADDR:0x55909090] [UNABLE_TO_READ] []
ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [unable_to_trans_pc] [PC:0x7D611D87] [ADDR:0x55909090] [UNABLE_TO_READ] []
Fri DEC 16 16:27:03 2011
Errors IN file d:\oracle\product\10.2.0\db_1\rdbms\trace\px_ora_5360.trc:
ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [unable_to_trans_pc] [PC:0x7D611D87] [ADDR:0x55909090] [UNABLE_TO_READ] []
ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [unable_to_trans_pc] [PC:0x7D611D87] [ADDR:0x55909090] [UNABLE_TO_READ] []
ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [unable_to_trans_pc] [PC:0x7D611D87] [ADDR:0x55909090] [UNABLE_TO_READ] []
ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [unable_to_trans_pc] [PC:0x7D611D87] [ADDR:0x55909090] [UNABLE_TO_READ] []
Fri DEC 16 16:27:03 2011
Errors IN file d:\oracle\product\10.2.0\db_1\rdbms\trace\px_ora_5360.trc:
ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [unable_to_trans_pc] [PC:0x7D611D87] [ADDR:0x55909090] [UNABLE_TO_READ] []
ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [unable_to_trans_pc] [PC:0x7D611D87] [ADDR:0x55909090] [UNABLE_TO_READ] []
ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [unable_to_trans_pc] [PC:0x7D611D87] [ADDR:0x55909090] [UNABLE_TO_READ] []
ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [unable_to_trans_pc] [PC:0x7D611D87] [ADDR:0x55909090] [UNABLE_TO_READ] []
ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [unable_to_trans_pc] [PC:0x7D611D87] [ADDR:0x55909090] [UNABLE_TO_READ] []
.
.
.
Fri DEC 16 16:27:08 2011
Errors IN file d:\oracle\product\10.2.0\db_1\rdbms\trace\px_ora_5360.trc:
ORA-07445: exception encountered: core dump [] [] [] [] [] []
ORA-07445: exception encountered: core dump [] [] [] [] [] []
ORA-07445: exception encountered: core dump [] [] [] [] [] []
ORA-07445: exception encountered: core dump [] [] [] [] [] []
ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [unable_to_trans_pc] [PC:0x7D611D87] [ADDR:0x55909090] [UNABLE_TO_READ] []
ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [unable_to_trans_pc] [PC:0x7D611D87] [ADDR:0x55909090] [UNABLE_TO_READ] []
ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [unable_to_trans_pc] [PC:0x7D611D87] [ADDR:0x55909090] [UNABLE_TO_READ] []
ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [unable_to_trans_pc] [PC:0x7D611D87] [ADDR:0x55909090] [UNABLE_TO_READ] []
ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [unable_to_trans_pc] [PC:0x7D611D87] [ADDR:0x55909090] [UNABLE_TO_READ] []
ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [unable_to_trans_pc] 
.
.
.

这个错误出现后就会在告警日志中频繁的报错，并最终导致数据库崩溃。
检查对应的TRACE文件：

Dump file d:\oracle\product\10.2.0\db_1\rdbms\trace\px_ora_5360.trc
Fri DEC 16 16:27:02 2011
ORACLE V10.2.0.1.0 - Production vsnsta=0
vsnsql=14 vsnxtr=3
Oracle DATABASE 10g Enterprise Edition Release 10.2.0.1.0 - Production
WITH the Partitioning, OLAP AND DATA Mining options
Windows Server 2003 Version V5.2 Service Pack 2
CPU                 : 16 - TYPE 586, 2 Physical Cores
Process Affinity    : 0x00000000
Memory (Avail/Total): Ph:5675M/8181M, Ph+PgF:7432M/9789M, VA:2641M/4095M
Instance name: px
Redo thread mounted BY this instance: 0 <none>
Oracle process NUMBER: 0
Windows thread id: 5360, image: ORACLE.EXE
*** 2011-12-16 16:27:02.539
ksedmp: internal OR fatal error
ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [unable_to_trans_pc] [PC:0x7D611D87] [ADDR:0x55909090] [UNABLE_TO_READ] []
CURRENT SQL information unavailable - no SGA.
----- Call Stack Trace -----
calling              CALL     entry                argument VALUES IN hex      
location             TYPE     point                (? means dubious VALUE)     
-------------------- -------- -------------------- ----------------------------
7D611D87                      00000000             
7D60F983             CALLrel  7D60F666             
7D610C82             CALL???  00000000             
7D5342B0             CALL???  00000000             
_ssbev_env+40        CALL???  00000000             
_slzgetevar+278      CALLrel  _ssbev_env+0         
_kpummpin+686        CALLrel  _slzgetevar+0        C32F3A8 607B5158 19 C32F388
                                                   20 0
_kpupin+81           CALLrel  _kpummpin+0          C32F408 0 0 0 0 61E2E060 0
                                                   836A4C
_kpkipgi+83          CALLrel  _kpupin+0            2 0 0 0 0 0 836A4C
_kpkipgn+14          CALLrel  _kpkipgi+0           0
_kscnfy+1334         CALLreg  00000000             7 0
_opirip+58           CALLrel  _kscnfy+0            7 0
_opidrv+857          CALLrel  _opirip+0            32 4 C32FEC0
_sou2o+45            CALLrel  _opidrv+0            32 4 C32FEC0
_opimai_real+227     CALLrel  _sou2o+0             C32FEB4 32 4 C32FEC0
_opimai+92           CALLrel  _opimai_real+0       3 C32FEEC
_BackgroundThreadSt  CALLrel  _opimai+0            
art@4+422                                          
7D50FE1E             CALLreg  00000000             
--------------------- Binary Stack Dump ---------------------

查询MOS后，确认是Windows平台上的bug，详情参考MS-Windows: ORA-7445 On functions: ssbev_env, slzgetevar + no SGA [ID 1305096.1]。这个bug影响10.2.0.5以前的Windows平台下的10g，导致问题的原因是一个未公布的Bug:8592848，Oracle在10.2.0.5和11.2.0.1中fixed了这个bug。

Posted in BUG | Tagged , , , , , , , | Leave a comment

启动数据库出现ORA-9925错误

Posted on 2011/12/16 by yangtingkun

尝试用非oracle用户启动数据库，碰到这个错误。
错误详细信息为：

enmo@jyoracle:/oracle/admin/enmo>sqlplus / AS sysdba
SQL*Plus: Release 10.2.0.4.0 - Production ON Fri DEC 16 20:28:09 2011
Copyright (c) 1982, 2007, Oracle. ALL Rights Reserved.
ERROR:
ORA-09925: Unable TO CREATE audit trail file
IBM AIX RISC System/6000 Error: 2: No such file OR directory
Additional information: 9925
ORA-09925: Unable TO CREATE audit trail file
IBM AIX RISC System/6000 Error: 2: No such file OR directory
Additional information: 9925
 
Enter user-name: 
ERROR:
ORA-01017: invalid username/password; logon denied
 
Enter user-name: 
ERROR:
ORA-01017: invalid username/password; logon denied
 
SP2-0157: unable TO CONNECT TO ORACLE after 3 attempts, exiting SQL*Plus

其实这个错误很明显，是由于AUDIT TRAIL文件无法创建所致，导致这个问题多半是由于权限造成的，检查后发现果然如此：
enmo@jyoracle:/oracle/admin/enmo>ls
adump bdump cdump udump
enmo@jyoracle:/oracle/admin/enmo>ls -l
total 0
drwxr-xr-x 2 enmo dba 256 Dec 16 20:17 adump
drwxr-xr-x 2 enmo dba 256 Dec 16 20:14 bdump
drwxr-xr-x 2 enmo dba 256 Dec 16 20:14 cdump
drwxr-xr-x 2 enmo dba 256 Dec 16 20:15 udump
enmo@jyoracle:/oracle/admin/enmo>chmod 775 adump
enmo@jyoracle:/oracle/admin/enmo>sqlplus / as sysdba
SQL*Plus: Release 10.2.0.4.0 – Production on Fri Dec 16 20:29:46 2011
Copyright (c) 1982, 2007, Oracle. All Rights Reserved.
Connected to an idle instance.

由于当前的用户属于dba组，并非oracle用户，因此如果要数据库可以访问adump目录，应该设置改目录组选项可写。

Posted in ORACLE | Tagged , , | Leave a comment