ARCn: Media recovery disabled原因分析

1.数据库版本

SQL> select * from v$version;

BANNER
-------------------------------------------------------------
Oracle9i Enterprise Edition Release 9.2.0.8.0 - Production
PL/SQL Release 9.2.0.8.0 - Production
CORE    9.2.0.8.0       Production
TNS for Linux: Version 9.2.0.8.0 - Production
NLSRTL Version 9.2.0.8.0 - Production

2.alert日志出现类此记录

Fri Feb 10 05:16:55 2012
ARC1: Media recovery disabled
Fri Feb 10 05:17:23 2012
ARC0: Media recovery disabled
Fri Feb 10 05:17:23 2012
ARC1: Media recovery disabled
Fri Feb 10 05:18:23 2012
ARC1: Media recovery disabled
Fri Feb 10 05:19:12 2012
Thread 1 advanced to log sequence 24
  Current log# 1 seq# 24 mem# 0: /tmp/recover/redo01.log
Fri Feb 10 05:19:12 2012
ARC0: Media recovery disabled
Fri Feb 10 05:19:23 2012
ARC1: Media recovery disabled
Fri Feb 10 05:20:23 2012
ARC1: Media recovery disabled
Fri Feb 10 05:21:23 2012
ARC1: Media recovery disabled

3.数据库归档信息

SQL> archive log list;
Database log mode              No Archive Mode
Automatic archival             Enabled
Archive destination            /tmp/recover
Oldest online log sequence     25
Current log sequence           27

SQL> show parameter log_archive_start

NAME                                 TYPE        VALUE
------------------------------------ ----------- ---------------
log_archive_start                    boolean     TRUE

从这里可以看出,数据库处于非归档模式,但是log_archive_start=true,这样会导致归档进程自动启动(ARCn),因为数据库设置为非归档模式,从而导致该进程启动后,又自己关闭

4.解决方法

SQL> alter system set log_archive_start=false scope=spfile;

System altered.

SQL> startup force      
ORACLE instance started.

Total System Global Area  202445176 bytes
Fixed Size                   450936 bytes
Variable Size             167772160 bytes
Database Buffers           33554432 bytes
Redo Buffers                 667648 bytes
Database mounted.
Database opened.
SQL> show parameter log_archive_start

NAME                                 TYPE        VALUE
------------------------------------ ----------- --------------
log_archive_start                    boolean     FALSE
SQL> ARCHIVE LOG LIST;
Database log mode              No Archive Mode
Automatic archival             Disabled
Archive destination            /tmp/recover
Oldest online log sequence     26
Current log sequence           28

ALERT中无类此记录出现

手动提交分布式事务一例

一.alert文件中出现了很多类此记录

Fri Feb 10 05:25:01 2012
Errors in file /tmp/recover/ahcx216_reco_7956.trc:
ORA-12154: TNS:could not resolve service name
Fri Feb 10 05:25:01 2012
Errors in file /tmp/recover/ahcx216_reco_7956.trc:
ORA-12154: TNS:could not resolve service name

这里可以看出来两个信息:
1.出错的进程是rec0进程,而该进程的作用是解决分布式事务失败后遗留问题(事务提交或者回滚)
2.错误信息是tns不能被解析

二.查看trace文件

/tmp/recover/ahcx216_reco_7956.trc
Oracle9i Enterprise Edition Release 9.2.0.8.0 - Production
With the Partitioning, OLAP and Oracle Data Mining options
JServer Release 9.2.0.8.0 - Production
ORACLE_HOME = /opt/oracle/product/9.2.0/db_1
System name:    Linux
Node name:      localhost.localdomain
Release:        2.6.9-89.0.0.0.1.ELhugemem
Version:        #1 SMP Tue May 19 04:38:38 EDT 2009
Machine:        i686
Instance name: ahcx216
Redo thread mounted by this instance: 1
Oracle process number: 7
Unix process pid: 7956, image: oracle@localhost.localdomain (RECO)


*** SESSION ID:(6.1) 2012-02-10 04:58:24.886
*** 2012-02-10 04:58:24.886
ERROR, tran=6.1.712757, session#=1, ose=0:
ORA-12154: TNS:could not resolve service name
………………
*** 2012-02-10 05:25:01.580
ERROR, tran=6.1.712757, session#=1, ose=0:
ORA-12154: TNS:could not resolve service name
*** 2012-02-10 05:25:01.627
ERROR, tran=12.19.99059, session#=1, ose=0:
ORA-12154: TNS:could not resolve service name

通过这里我们可以看出事务id分别为12.19.99059和6.1.712757有问题

三.查看dba_2pc_pending视图

SQL> select local_tran_id,state,fail_time,retry_time from dba_2pc_pending;

LOCAL_TRAN_ID     STATE            FAIL_TIME           RETRY_TIME
-------------- ---------------- --------------       --------------
6.1.712757	collecting	2010/12/1 13:39:03   2012/2/10 5:38:52
12.19.99059	collecting	2010/12/1 15:56:26   2012/2/10 5:38:52

可以看出,果然有两个分布式事务在2010年12月1日出了问题(本库是一个问题库,在把库拉起来后发现该问题)
因为是异机恢复,而且间隔时间较长,很多tns的信息都已经不存在,所以需要手工提交分布式事务

四.手动提交事务

SQL> BEGIN
  2  DBMS_TRANSACTION.PURGE_LOST_DB_ENTRY('6.1.712757');
  3  DBMS_TRANSACTION.PURGE_LOST_DB_ENTRY('12.19.99059');
  4  END;
  5  /
BEGIN
*
第 1 行出现错误:
ORA-30019: Illegal rollback Segment operation in Automatic Undo mode
ORA-06512: at "SYS.DBMS_TRANSACTION", line 65
ORA-06512: at "SYS.DBMS_TRANSACTION", line 85
ORA-06512: at line 2

SQL> alter session set "_smu_debug_mode"=4;

Session altered.

-------------------------------------------------------------
--设置UNDO_SUPPRESS_ERRORS=true也可以解决此问题
alter system set UNDO_SUPPRESS_ERRORS = TRUE;
EXECUTE DBMS_TRANSACTION.PURGE_LOST_DB_ENTRY('<事务ID>');
commit;
alter system set UNDO_SUPPRESS_ERRORS = false;
--------------------------------------------------------------

SQL> commit;

SQL> exec DBMS_TRANSACTION.PURGE_LOST_DB_ENTRY('6.1.712757');

PL/SQL procedure successfully completed.


SQL> exec DBMS_TRANSACTION.PURGE_LOST_DB_ENTRY('12.19.99059');
BEGIN DBMS_TRANSACTION.PURGE_LOST_DB_ENTRY('12.19.99059'); END;

*
ERROR at line 1:
ORA-01453: SET TRANSACTION must be first statement of transaction
ORA-06512: at "SYS.DBMS_TRANSACTION", line 65
ORA-06512: at "SYS.DBMS_TRANSACTION", line 85
ORA-06512: at line 1
--第一个分布式事务处理后,未提交导致

SQL> commit;

Commit complete.

SQL> exec DBMS_TRANSACTION.PURGE_LOST_DB_ENTRY('12.19.99059');

PL/SQL procedure successfully completed.

SQL> commit;

Commit complete.

五.补充说明
开始在另一个会话中,执行失败原因

SQL> alter session set "_smu_debug_mode"=4;

会话已更改。

SQL> commit;

提交完成。

SQL> BEGIN
  2  DBMS_TRANSACTION.PURGE_LOST_DB_ENTRY('6.1.712757');
  3  DBMS_TRANSACTION.PURGE_LOST_DB_ENTRY('12.19.99059');
  4  END;
  5  /
BEGIN
*
第 1 行出现错误:
ORA-01453: SET TRANSACTION must be first statement of transaction
ORA-06512: at "SYS.DBMS_TRANSACTION", line 65
ORA-06512: at "SYS.DBMS_TRANSACTION", line 85
ORA-06512: at line 3

因为这里的begin end中包含了两个事务的清理,在清理完第一个事务之后,需要提交才能够清理第二个,这里因为没有提交,导致ORA-01453错误。

通过sql语句获取awr/statspack逻辑读/物理读

在日常的性能监控中,我们经常需要需要通过一段时间内数据库的逻辑读/物理读来大致反映数据库的性能情况,这里列出通过awr和statspack来获取相关数据(查询最近30天数据,除掉第一条和最后一条数据)

awr逻辑读

WITH A AS
 (SELECT B.SNAP_ID, SUM(VALUE)/1024/1024/1024*8192 VALUE
    FROM DBA_HIST_SYSSTAT B
   WHERE B.DBID = (SELECT DBID FROM V$DATABASE)
          AND b.INSTANCE_NUMBER = &INST_NUM
     AND B.STAT_NAME IN ('session logical reads')
   GROUP BY B.SNAP_ID
   ORDER BY SNAP_ID)
SELECT A.SNAP_ID,
       LAG(VALUE, 1, '0') OVER(ORDER BY A.SNAP_ID) "START_VALUE(G)",
       VALUE "END_VALUE(G)",
       TO_CHAR(END_INTERVAL_TIME,'YYYY-MM-DD HH24:MI:SS')"END_TIME",
       VALUE - LAG(VALUE, 1, '0') OVER(ORDER BY A.SNAP_ID) "D-VALUE(G)"
  FROM A,(SELECT END_INTERVAL_TIME,SNAP_ID
    FROM DBA_HIST_SNAPSHOT B
   WHERE  B.DBID = (SELECT dbid FROM v$database)
     AND B.INSTANCE_NUMBER = &INST_NUM) B
     WHERE A.SNAP_ID=B.snap_id
     AND END_INTERVAL_TIME>=SYSDATE-30;

awr物理读

WITH A AS
 (SELECT B.SNAP_ID, SUM(VALUE)/1024/1024/1024*8192 VALUE
    FROM DBA_HIST_SYSSTAT B
   WHERE B.DBID = (SELECT DBID FROM V$DATABASE)
          AND b.INSTANCE_NUMBER = &INST_NUM
     AND B.STAT_NAME IN ('physical reads')
   GROUP BY B.SNAP_ID
   ORDER BY SNAP_ID)
SELECT A.SNAP_ID,
       LAG(VALUE, 1, '0') OVER(ORDER BY A.SNAP_ID) "START_VALUE(G)",
       VALUE "END_VALUE(G)",
       TO_CHAR(END_INTERVAL_TIME,'YYYY-MM-DD HH24:MI:SS')"END_TIME",
       VALUE - LAG(VALUE, 1, '0') OVER(ORDER BY A.SNAP_ID) "D-VALUE(G)"
  FROM A,(SELECT END_INTERVAL_TIME,SNAP_ID
    FROM DBA_HIST_SNAPSHOT B
   WHERE  B.DBID = (SELECT dbid FROM v$database)
     AND B.INSTANCE_NUMBER = &INST_NUM) B
     WHERE A.SNAP_ID=B.snap_id
     AND END_INTERVAL_TIME>=SYSDATE-30;

statspack逻辑读

WITH A AS
 (SELECT B.SNAP_ID, SUM(VALUE)/1024/1024/1024*8192 VALUE
    FROM STATS$SYSSTAT B
   WHERE B.DBID = (SELECT DBID FROM V$DATABASE)
     AND B.INSTANCE_NUMBER = &INST_NUM
     AND B.NAME IN ('session logical reads')
   GROUP BY B.SNAP_ID
   ORDER BY SNAP_ID)
SELECT A.SNAP_ID,
       LAG(VALUE, 1, '0') OVER(ORDER BY A.SNAP_ID) "START_VALUE(G)",
       VALUE "END_VALUE(G)",
       TO_CHAR(SNAP_TIME, 'YYYY-MM-DD HH24:MI:SS') "END_TIME",
       VALUE - LAG(VALUE, 1, '0') OVER(ORDER BY A.SNAP_ID) "D-VALUE(G)"
  FROM A,
       (SELECT SNAP_TIME, SNAP_ID
          FROM STATS$SNAPSHOT B
         WHERE B.DBID = (SELECT DBID FROM V$DATABASE)
           AND B.INSTANCE_NUMBER = &INST_NUM) B
 WHERE A.SNAP_ID = B.SNAP_ID
  AND snap_time>=SYSDATE-30;

statspack物理读

WITH A AS
 (SELECT B.SNAP_ID, SUM(VALUE)/1024/1024/1024*8192 VALUE
    FROM STATS$SYSSTAT B
   WHERE B.DBID = (SELECT DBID FROM V$DATABASE)
     AND B.INSTANCE_NUMBER = &INST_NUM
     AND B.NAME IN ('physical reads')
   GROUP BY B.SNAP_ID
   ORDER BY SNAP_ID)
SELECT A.SNAP_ID,
       LAG(VALUE, 1, '0') OVER(ORDER BY A.SNAP_ID) "START_VALUE(G)",
       VALUE "END_VALUE(G)",
       TO_CHAR(SNAP_TIME, 'YYYY-MM-DD HH24:MI:SS') "END_TIME",
       VALUE - LAG(VALUE, 1, '0') OVER(ORDER BY A.SNAP_ID) "D-VALUE(G)"
  FROM A,
       (SELECT SNAP_TIME, SNAP_ID
          FROM STATS$SNAPSHOT B
         WHERE B.DBID = (SELECT DBID FROM V$DATABASE)
           AND B.INSTANCE_NUMBER = &INST_NUM) B
 WHERE A.SNAP_ID = B.SNAP_ID
 AND snap_time>=SYSDATE-30;