山上有风

1 问题描述

客户数据库服务器在06年11月8日归档日志快速增长，认为有异常情况，请求协助分析。

2 问题分析
启用logmnr分析
检查归档日志，发现大概每分钟产生1个到2个归档，每个200M.
为分析具体的内容，使用logmnr分析日志。

execute dbms_logmnr.add_logfile(logfilename=>'/oradata10/oracle/arch/arch_1_56478.arc',
options=>dbms_logmnr.addfile);

exec dbms_logmnr.start_logmnr();

分析插入操作的情况

spool inssql.txt
select session_info ,sql_redo from v$logmnr_contents where upper(operation) = 'INSERT';
spool off

因为归档日志太大，没有分析完就停止。 绝大部分内容是

insert into "UNKNOWN"."OBJ# 31552"() values ();

查看对象情况：

SQL> select object_name, owner from dba_objects where object_id = 31552;

OBJECT_NAME
--------------------------------------------------------------------------------
OWNER
------------------------------
GLTMP_ASSORA
NC31

查看表结构：

--------------------------------------------------------------------------------

CREATE GLOBAL TEMPORARY TABLE "NC31"."GLTMP_ASSORA"
( "ASSID" CHAR(20)
) ON COMMIT DELETE ROWS

分析是NC软件在这个时间端有大量的临时表数据插入.

分析DELETE:

spool delsql.txt
select session_info ,sql_redo from v$logmnr_contents where upper(operation) = 'DELETE';
spool off

查看delsql.txt,大部分是如下内容：
delete from "UNKNOWN"."OBJ# 34216" where "COL 1" = HEXTORAW('3131313756323130303
030303030303053454b57') and ROWID = 'AARpmJAABAABpt/AAw';

查具体的segment:

SQL> select owner, object_name, object_type, temporary as TEMP from dba_objects where object_id = 34216;

OWNER
------------------------------
OBJECT_NAME
--------------------------------------------------------------------------------
OBJECT_TYPE T
------------------ -
NC31
ASSTEMPORA
TABLE Y

查看其创建SQL

SQL>set long 9000
SQL> select dbms_metadata.get_ddl('TABLE','ASSTEMPORA','NC31') from dual;

DBMS_METADATA.GET_DDL('TABLE','ASSTEMPORA','NC31')
--------------------------------------------------------------------------------

CREATE GLOBAL TEMPORARY TABLE "NC31"."ASSTEMPORA"
( "ASSID" CHAR(20)
) ON COMMIT DELETE ROWS

分析，归档日志内容大部分是global temporary表的操作引起的。应该属于正常的业务。

查是否存在bug:
查到是9204的bug：
2874489: Excessive REDO generated for INSERT as SELECT into GLOBAL TEMPORARY TABLES.
Fixed: 9205
确实命中了bug. 这个bug导致临时表的insert as select 操作产生大量的redo 日志。

向客户了解这几天的业务情况：

原dba介绍
以前开archivelog 时也差不多每分钟产生一个归档。

比较同期归档日志：

发现2006－10－7号下午13:40到15:00直接归档日志产生的频率也达到每分钟1－2个。

dba发现归档产生非常多后，停止了归档模式， 后来因为shareplex的需要，重新启动了归档模式。
Mon Sep 18 23:55:58 2006
alter database archivelog
Mon Sep 18 23:55:58 2006
Completed: alter database archivelog

财务部 ：
发生问题的几天大量查报表，业务量比上个月增加。

3 总结和建议

因为应用使用了较多的global temporary 进行数据处理， 而9204版本存在的bug使得这些操作产生更多的arch log。针对业务的需要，在业务繁忙的时候，提高清理归档日志频率； 如果归档太多影响到业务，可以考虑升级到9206。

4.附测试9204bug

测试9204的这个bug：

D:MyDocument>sqlplus lyf/lyf

在oracle 10g 上测试：

[oracle@iassrv oracle]$ sqlplus lyf/lyf

SQL*Plus: Release 10.1.0.4.2 - Production on Fri Nov 10 12:31:11 2006

Copyright (c) 1982, 2005, Oracle. All rights reserved.

Connected to:
Oracle Database 10g Enterprise Edition Release 10.1.0.4.2 - Production
With the Partitioning, OLAP and Data Mining options

SQL> create table cc1 (c1 number);

Table created.

SQL> set autotrace trace stat
1* insert into cc1 select rownum from dba_objects
SQL> /

60303 rows created.

Statistics
----------------------------------------------------------
1732 recursive calls
1536 db block gets
12848 consistent gets
752 physical reads
973516 redo size
632 bytes sent via SQL*Net to client
556 bytes received via SQL*Net from client
3 SQL*Net roundtrips to/from client
27 sorts (memory)
0 sorts (disk)
60303 rows processed

SQL> create global temporary table cc2 (c1 number);

Table created.

SQL> insert into cc2 select rownum from dba_objects;

60304 rows created.

Statistics
----------------------------------------------------------
33 recursive calls
708 db block gets
12275 consistent gets
455 physical reads
167188 redo size
636 bytes sent via SQL*Net to client
555 bytes received via SQL*Net from client
3 SQL*Net roundtrips to/from client
2 sorts (memory)
0 sorts (disk)
60304 rows processed

SQL>

Global temporary 的 redo log 比一般的表少很多。

在oracle 9206上测试

D:oracleora92sqlplusadmin>sqlplus lyf/lyf

SQL>

分析： 9206已经没有这个问题。Global temporary表比一般表生成的redo少。

--------