注册 登录
qy88千亿国际专家网 返回首页

文仲彦的个人空间 http://zjw.zlsoft.com/?648 [收藏] [复制] [RSS]

日志

某三甲医院数据泵导出卡死问题处理

已有 1893 次阅读2014-12-19 16:41 |个人分类:评审文章|系统分类:典型案例
    随着我们用户10g11g数据库的普遍运用,越来越多的技术人员开始使用数据泵(expdp/impdp)替代传统的逻辑备份方式(exp/imp,数据泵相比传统的逻辑备份无论是在效率、功能上都是大大的提高,对我们在进行大数据备份迁移时提供了很好的便利。但是11g的数据泵根据平台和版本的不同还是有存在很多BUG,经常遇到莫名的卡死、报错现象,让人不知所措,下面介绍下我最近遇到的一个案例。

数据泵导出卡死

最近一用户准备搭建测试环境,由于该用户正式库是AIX小机,测试环境是X86平台,因此只能通过expdp进行数据导出,但是在导出的时候,发现EXPDP一直卡在如下位置,几个小时都不动弹: Export: Release 11.2.0.3.0 - Production on Fri Dec 5 13:06:21 2014
Copyright (c) 1982, 2011, Oracle and/or its affiliates.  All rights reserved.
Connected to: Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP,
Data Mining and Real Application Testing options
Starting "SYSTEM"."SYS_EXPORT_FULL_01":  system/******** dumpfile=dump:full20141204b_%U_db.dmp logfile=dump:full_expdp1204b_db.log full=y exclude= TABLE:"IN (select table_name from  dba_tables where table_name in ('
电子病历图形','检验图像结果','检验报告图像') and owner='ZLHIS')" cluster=n
Estimate in progress using BLOCKS method...
Processing object type DATABASE_EXPORT/SCHEMA/TABLE/TABLE_DATA
Total estimation using BLOCKS method: 125.3 GB
Processing object type DATABASE_EXPORT/TABLESPACE
Processing object type DATABASE_EXPORT/PROFILE
Processing object type DATABASE_EXPORT/SYS_USER/USER
Processing object type DATABASE_EXPORT/SCHEMA/USER
Processing object type DATABASE_EXPORT/ROLE
…………………………….(省略)
Processing object type DATABASE_EXPORT/SCHEMA/TABLE/PRE_TABLE_ACTION
Processing object type DATABASE_EXPORT/SCHEMA/TABLE/GRANT/OWNER_GRANT/OBJECT_GRANT
Processing object type DATABASE_EXPORT/SCHEMA/TABLE/GRANT/CROSS_SCHEMA/OBJECT_GRANT
Processing object type DATABASE_EXPORT/SCHEMA/TABLE/COMMENT
Processing object type DATABASE_EXPORT/SCHEMA/VIEW/VIEW
Processing object type DATABASE_EXPORT/SCHEMA/VIEW/GRANT/OWNER_GRANT/OBJECT_GRANT
Processing object type DATABASE_EXPORT/SCHEMA/VIEW/GRANT/CROSS_SCHEMA/OBJECT_GRANT
Processing object type DATABASE_EXPORT/SCHEMA/VIEW/COMMENT
Processing object type DATABASE_EXPORT/SCHEMA/TYPE/TYPE_BODY
看起导出卡死在TYPE_BODY对象的导出,但是其实不然,即使排除该对象,导出又会卡在其他地方,所以从日志中看带有一定的欺骗性,这也是我们之前的同事一直无法处理的原因,其实我们应该从后台去看引起导出的原因是什么,我们还是先看下为什么会卡死,遇到这种情况,我们一般都是通过hang分析来解决,怎么hang分析可以参考我们部门发布的技术论文《数据库hang诊断与分析技术介绍》,这里我们就不再介绍改方法,直接看结果通过分析,我们发现了是由于数据泵导出过程中要执行的一段SQL语句引起的,SQL语句如下;          可以看到是一个查询内部字典信息的SQL,我们把改SQL语句直接拿到PLSQL中去执行,同样的卡死,出现等待事件如下:          这个等待事件我们以前没有见过,但是这里我们可以看到一个关键词TABLE_STATISTICS,这个不是表的统计信息吗?原来因为我们要排除一些表,所以数据泵需要通过查询排除这些表的统计信息,而就是这个排除查询,导致整个导出卡死,那处理办法也就有了,我们不导出统计信息,不久可以不执行这个查询了吗?于是修改导出语句为如下,排除统计信息的导出 expdp system/******** dumpfile=dump:full20141204b_%U_db.dmp logfile=dump:full_expdp1204b_db.log full=y exclude=STATISTICS,TABLE:"IN (select table_name from dba_tables where table_name in ('电子病历图形','检验图像结果','检验报告图像') and owner='ZLHIS')" cluster=n          果然数据导出不再卡死,因此找到了根本的原因就是统计信息的导出排除语句在数据库中执行卡死,那为什么会卡死呢?我在官方网站上继续查找原因,终于还是被我发现了,原来是AIX下的一个BUG引起,文档名称EXPDP HANGS ON AIX WHEN EXCLUDE IS USED WITH QUERY CLAUSE (文档 ID 1513238.1) 其实在进行数据泵导出导入的时候,除了原有的日志记录,还可以进行更详细的日志跟踪,获取更多的信息方便我们进行问题解决和分析。

对数据泵启用跟踪功能

启用跟踪功能,只需要在DataPump(expdp)DataPump(impdp)的时候添加一个trace参数,对其指定一个7位数的十六进制。前三个数字启用跟踪特定的数据泵组件,而通常最后四位数字为:0300。任何前导零的可以省略,跟踪参数指定的值是不区分大小写的。 TRACE = 04A0300
 or:
TRACE=4a0300
注意该参数的使用必须要有特定的权限,否则会报ORA-31631错误 expdp scott/tiger DIRECTORY=my_dir DUMPFILE=expdp_s.dmp LOGFILE=expdp_s.log TABLES=emp TRACE=480300    Export: Release 10.2.0.3.0 - Production on Friday, 19 October, 2007 13:46:33    Copyright (c) 2003, 2005, Oracle. All rights reserved.    Connected to: Oracle Database 10g Enterprise Edition Release 10.2.0.3.0 - Production    With the Partitioning, Oracle Label Security, OLAP and Data Mining Scoring Engine options    ORA-31631: privileges are required   这种情况,我们只需要授予 EXP_FULL_DATABASE 或者IMP_FULL_DATABASE角色 CONNECT / AS SYSDBA   GRANT exp_full_database TO scott;    expdp scott/tiger DIRECTORY=my_dir DUMPFILE=expdp_s.dmp LOGFILE=expdp_s.log TABLES=emp TRACE=480300 这里的参数为480300,其他Trace的参数及跟踪的数据泵组件对应的例子有: -- Example of combination (last 4 digits are usually 0300):    40300 to trace Process services   80300 to trace Master Control Process (MCP)   400300 to trace Worker process(es)    -- +    4C0300 to trace Process services and Master Control and Worker processes  生成的跟踪日志的格式一般如下 -- Run a Data Pump job with full tracing: -- This results in two trace files in BACKGROUND_DUMP_DEST:    --    Master Process trace file: <SID>_dm<number>_<process_id>.trc     --    Worker Process trace file: <SID>_dw<number>_<process_id>.trc     -- And one trace file in USER_DUMP_DEST:    --    Shadow Process trace file: <SID>_ora_<process_id>.trc  如何找到参数文件的位置? Data Pump trace files 一般写在BACKGROUND_DUMP_DEST USER_DUMP_DEST目录下,文件的格式如下: <strong>Data Pump Master Control Process (MCP).</strong> Format : <SID>_dm<number>_<process_id>.trc Example: ORCL_dm00_2896.trc   or:   ORCL_dm01_3422.trc (for second active Master Control Process) Location: BACKGROUND_DUMP_DEST   or   <ADR_HOME>/trace <strong>Data Pump Worker Process trace file.</strong> Format : <SID>_dw<number>_<process_id>.trc Example: ORCL_dw01_2936.trc   or:   ORCL_dw01_2844.trc  and  ORCL_dw02_2986.trc (if PARALLEL=2) Location: BACKGROUND_DUMP_DEST   or   <ADR_HOME>/trace <strong>Data Pump Shadow Process trace file.</strong> Format : <SID>_ora_<process_id>.trc Example: ORCL_ora_3020.trc Location: USER_DUMP_DEST   or   <ADR_HOME>/trace

跟踪日志生成格式

         我们在执行数据泵导出时,就生成了/u01/app/product/oracle/diag/rdbms/hnyy/hnyy1/trace/hnyy1_dm00_28574120.trc文件,打开该文件的内容如下,就是我们跟踪本次数据泵导出的一些关键信息: Trace file /u01/app/product/oracle/diag/rdbms/hnyy/hnyy1/trace/hnyy1_dm00_28574120.trc Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP, Data Mining and Real Application Testing options ORACLE_HOME = /u01/app/product/oracle/db_1 System name:          AIX Node name:              orcl1 Release:          1 Version:          6 Machine:       00F6C6C64C00 Instance name: hnyy1 Redo thread mounted by this instance: 1 Oracle process number: 559 Unix process pid: 28574120, image: oracle@orcl1 (DM00) *** 2014-12-05 13:06:38.154 *** SESSION ID:(8851.28833) 2014-12-05 13:06:38.154 *** CLIENT ID:() 2014-12-05 13:06:38.154 *** SERVICE NAME:(SYS$USERS) 2014-12-05 13:06:38.154 *** MODULE NAME:() 2014-12-05 13:06:38.154 *** ACTION NAME:() 2014-12-05 13:06:38.154   KUPP:13:06:38.142: Current trace/debug flags: 00480300 = 4719360 *** MODULE NAME:(Data Pump Master) 2014-12-05 13:06:38.195 *** ACTION NAME:(SYS_EXPORT_FULL_01) 2014-12-05 13:06:38.195   KUPC:13:06:38.194: Setting remote flag for this process to FALSE prvtaqis - Enter prvtaqis subtab_name upd prvtaqis sys table upd KUPM:13:06:38.336: Attached to control queue as MCP KUPM:13:06:38.345: While starting, control queue subscriber count is: 2 KUPP:13:06:38.346: Initialization complete for master process DM00 KUPM:13:06:38.405: Entered main loop KUPM:13:06:38.640: ****IN DISPATCH at 47198, request type=1001 KUPM:13:06:38.640: Current user is: SYSTEM KUPM:13:06:38.640: hand := DBMS_DATAPUMP.OPEN ('EXPORT', 'FULL', '', 'SYS_EXPORT_FULL_01', '', '2'); *** 2014-12-05 13:06:40.338 KUPM:13:06:40.337: Resumable enabled KUPM:13:06:40.346: Entered state: DEFINING KUPM:13:06:40.346: initing file system kwqberlst !retval block kwqberlst rqan->lagno_kwqiia  7 kwqberlst rqan->lascn_kwqiia > 0 block kwqberlst rqan->lascn_kwqiia  7 kwqberlst ascn -1500723611 lascn 22 KUPM:13:06:42.700: ****IN DISPATCH at 47202, request type=1035 KUPM:13:06:42.700: Current user is: SYSTEM KUPM:13:06:42.700: DBMS_DATAPUMP.SET_PARAMETER (hand, 'CLIENT_COMMAND', 'system/******** dumpfile=dump:full20141204b_%U_db.dmp logfile=dump:full_expdp1204b_db.log full=y exclude=STATISTICS,PACKAGE,FUNCTION,PROCEDURE,INDEX,TABLE:"IN (select table_name from dba_tab KUPM:13:06:42.700: les where table_name in ('电子病历图形','检验图像结果','检验报告图像') and owner='ZLHIS')" cluster=n TRACE=480300 '); KUPM:13:06:42.700: In Check_param_dependency with name: CLIENT_COMMAND KUPM:13:06:42.703: ****OUT DISPATCH, request type=1035, response type =2041 kwqberlst !retval block kwqberlst rqan->lagno_kwqiia  7 kwqberlst rqan->lascn_kwqiia > 0 block kwqberlst rqan->lascn_kwqiia  7 kwqberlst ascn -1500723611 lascn 22 KUPM:13:06:42.750: ****IN DISPATCH at 47202, request type=1022 KUPM:13:06:42.750: Current user is: SYSTEM KUPM:13:06:42.750: DBMS_DATAPUMP.ADD_FILE (hand, 'full20141204b_%U_db.dmp', 'DUMP', 0, , 1); KUPM:13:06:42.750: Current user is: SYSTEM KUPM:13:06:42.750: DBMS_DATAPUMP.ADD_FILE (hand, 'full20141204b_%U_db.dmp', 'DUMP', 0, , 1); 这个日志中记录了非常详细的数据泵的过程记录,以及出现的各种问题,其中也包含了如本案例中的一些内部SQL语句,根据这个详细的日志记录,更有利于我们分析数据泵导出导入过程中出现的错误,有机会大家尝试下这种方法,能够更加便捷的发现数据泵导出过程中遇到的问题。

路过

鸡蛋

鲜花

握手

雷人

评论 (0 个评论)

facelist
您需要登录后才可以评论 登录 | 注册
手机版|小黑屋|ZLSOFT Inc. ( 渝ICP备12005023号 GMT+8, 2019-3-21 03:13 , Processed in 0.159495 second(s), 23 queries .
Powered by Discuz! X3.2 © 2001-2013 Comsenz Inc.
返回顶部