如何对 Oracle 数据泵（expdp/impdp） 进行 debug

一．概述 我在之前写过2篇有关Oracle 数据泵的文章，如下： Oracle 10gData Pump Expdp/Impdp 详解 http://www.linuxidc.com/Li

一．概述

我在之前写过2篇有关Oracle 数据泵的文章，如下：

Oracle 10gData Pump Expdp/Impdp 详解 

Oracleexpdp/impdp 使用示例 

这两篇都是介绍数据泵的使用。

那么在实际的使用中，我们也会遇到一个问题，发生一些ORA-xx的错误，有具体的错误，我们都可以去google去分析，但是还有情况，就是也不错误，而是在某一步停住了，而且很长时间不动。 

这是时候，我们是不好判断数据泵的操作是否正常。

在数据泵卡住的时候，有一个很好的方法来判断：

1． 在expdp的时候，我们要观察dump 文件的变化，只要dump 文件大小在变化，那就说明expdp是正常的。

2． 在impdp的时候，我们可以及时查看表空间的变化，只要我们的表空间在变化，说明我们的impdp是正常的。

如果在数据泵操作的时候，表空间和dump都没有变化，数据泵操作也停止在某一步不动。那么我们就只能对数据泵进行debug操作。 

二．如何对数据泵进行debug？ 

trace 生成的文件可能很大，所以在进行trace之前，必须先检查dump文件的大小：max_dump_file_size。 

[oracle@asm trace]$ orz param max_dump 

Session altered. 

NAME ISDEFAULT SESMO SYSMOD VALUE

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

max_dump_file_size TRUE TRUE IMMEDIATE unlimited

 

如果不是unlimited，就进行修改：

ALTER SYSTEM SETmax_dump_file_size = unlimited SCOPE = both;

 

2.1 使用Data Pump的TRACE 参数

 

2.1.1 TRACE 说明

 

启动trace 功能只需要在expdp/impdp 命令后加上一个trace 参数，该参数由一个7位的16进制数据组成。

 

前三位指定Data Pump组件的代码，后四位一般是:0300。

 

任何已0开头的trace的值都会被忽略，trace值不区分大小写。

 

如：

TRACE = 04A0300 或者 TRACE=4a0300

 

 

trace值的一些注意事项：

（1） trace 值不要超过7位十六进制数字。

（2） 不要添加十六进制的0x符号。

（3） 不要将16进制转换成10进制。

（4） 会忽略最前面的0，即使长度不满足7位。

（5） 参数不区分大小写。

 

 

在使用trace 参数时，执行数据泵操作的用户需要具有DBA 角色或者EXP_FULL_DATABASE /IMP_FULL_DATABASE的角色，如果权限不足，就会报ORA-31631的错误。

ORA-31631: privileges are required

 

解决方法：给用户赋权。 如：

GRANT exp_full_database TO tianlesoftware;

 

操作完成之后，在收回权限即可：

revoke exp_full_database from tianlesoftware;

 

使用TRACE的示例：

expdp scott/tiger DIRECTORY=my_dir DUMPFILE=expdp_s.dmp LOGFILE=expdp_s.log TABLES=empTRACE=480300

2.1.2 TRACE值的具体计算规则

在前面我们讲了TRACE 值的前3位表示的是数据泵的组件代码，具体如下： 

-- Summary of Data Pump trace levels:

-- ==================================

 

Trace DM DW ORA Lines

level trc trc trc in

(hex) file file file trace Purpose

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

10300 x x x SHDW: To trace the Shadowprocess (API) (expdp/impdp)

20300 x x x KUPV: To trace Fixed table

40300 x x x 'div' To trace Process services

80300 x KUPM: To trace Master ControlProcess (MCP) (DM)

100300 x x KUPF: To trace File Manager

200300 x x x KUPC: To trace Queue services

400300 x KUPW: To trace Workerprocess(es) (DW)

800300 x KUPD: To trace DataPackage

1000300 x META: To trace Metadata Package

--- +

1FF0300 x x x 'all' To trace all components (full tracing)

 

如果想trace 所有的数据泵组件，只需要指定trace的值为1ff0300即可。

 

如果我们想通知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 MasterControl and Worker processes

 

叠加的时候，最后4位不变，把前面3位的值相加。

 

注意：

Oracle 建议使用480300的trace值，设置该值将会trace Master Control process (MCP) 和 theWorker process(es)。

 

2.1.3 TRACE 文件的log 位置

 

2个trace 文件在BACKGROUND_DUMP_DEST目录下：

Master Process trace file: _dm_.trc
Worker Process trace file: _dw_.trc

 

还有一个在USER_DUMP_DEST目录：

Shadow Processtrace file: _ora_.trc

 

 

[oracle@asm u01]$ orzparam background

 

Session altered.

 

NAME ISDEFAULT SESMO SYSMOD VALUE

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

background_core_dump TRUE FALSE FALSE partial

background_dump_dest TRUE FALSE IMMEDIATE /u01/app/oracle/diag/rdbms/dave/dave/trace

 

 

[oracle@asm u01]$ orzparam user_dump

 

Session altered.

 

NAME ISDEFAULT SESMO SYSMOD VALUE

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

user_dump_dest TRUE FALSE IMMEDIATE/u01/app/oracle/diag/rdbms/dave/dave/trace

 

 

 

 

2.1.4 TRACE 使用示例

 

SQL> set lin 160 pages 200

SQL> col owner for a10

SQL> col DIRECTORY_PATH for a50

SQL> select * from dba_directories;

 

OWNER DIRECTORY_NAME DIRECTORY_PATH

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

SYS ORACLE_OCM_CONFIG_DIR /u01/app/oracle/11.2.0/db_1/ccr/state

SYS DATA_PUMP_DIR /u01/app/oracle/admin/dave/dpdump/

SYS XMLDIR /u01/app/oracle/11.2.0/db_1/rdbms/xml

 

 

 

SQL>

 

SQL> create directory backup as'/u01/backup';

Directory created.

 

SQL> select * from dba_directories;

 

OWNER DIRECTORY_NAME DIRECTORY_PATH

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

SYS ORACLE_OCM_CONFIG_DIR /u01/app/oracle/11.2.0/db_1/ccr/state

SYS DATA_PUMP_DIR /u01/app/oracle/admin/dave/dpdump/

SYS XMLDIR /u01/app/oracle/11.2.0/db_1/rdbms/xml

SYS BACKUP /u01/backup

 

 

--创建测试表：tianlesoftware：

SQL> conn system/oracle;

Connected.

SQL> create table tianlesoftware asselect * from dba_objects;

Table created.

 

--使用trace：480300进行导出：

[oracle@asm u01]$ expdp system/oracleDIRECTORY=backup DUMPFILE=dave.dmp LOGFILE=dave.log TABLES=tianlesoftwareTRACE=480300

 

Export: Release 11.2.0.3.0 - Production onMon May 27 19:50:49 2013

 

Copyright (c) 1982, 2011, Oracle and/or itsaffiliates. All rights reserved.

 

Connected to: Oracle Database 11gEnterprise Edition Release 11.2.0.3.0 - 64bit Production

With the Partitioning, Automatic StorageManagement, OLAP, Data Mining

and Real Application Testing options

Starting"SYSTEM"."SYS_EXPORT_TABLE_01": system/******** DIRECTORY=backupDUMPFILE=dave.dmp LOGFILE=dave.log TABLES=tianlesoftware TRACE=480300

Estimate in progress using BLOCKS method...

Processing object typeTABLE_EXPORT/TABLE/TABLE_DATA

Total estimation using BLOCKS method: 9 MB

Processing object typeTABLE_EXPORT/TABLE/TABLE

Processing object typeTABLE_EXPORT/TABLE/PRE_TABLE_ACTION

. . exported"SYSTEM"."TIANLESOFTWARE" 7.215 MB 74608 rows

Master table"SYSTEM"."SYS_EXPORT_TABLE_01" successfully loaded/unloaded

******************************************************************************

Dump file set for SYSTEM.SYS_EXPORT_TABLE_01is:

/u01/backup/dave.dmp

Job"SYSTEM"."SYS_EXPORT_TABLE_01" successfully completed at19:51:22

 

 

--查看trace文件：

 

-rw-r----- 1 oracle asmadmin 1433 May 27 19:51 dave_dw00_7486.trm

-rw-r----- 1 oracle asmadmin 32109 May 27 19:51 dave_dw00_7486.trc

-rw-r----- 1 oracle asmadmin 1417 May 27 19:51 dave_dm00_7484.trm

-rw-r----- 1 oracle asmadmin 25025 May 27 19:51 dave_dm00_7484.trc

 

-rw-r----- 1 oracle asmadmin 2908 May 27 19:50 dave_ora_7480.trc

 

 

[oracle@asm trace]$ head -50 dave_dw00_7486.trc

Trace file/u01/app/oracle/diag/rdbms/dave/dave/trace/dave_dw00_7486.trc

Oracle Database 11g Enterprise EditionRelease 11.2.0.3.0 - 64bit Production

With the Partitioning, Automatic StorageManagement, OLAP, Data Mining

and Real Application Testing options

ORACLE_HOME = /u01/app/oracle/11.2.0/db_1

System name: Linux

Node name: asm

Release: 2.6.32-100.34.1.el6uek.x86_64

Version: #1 SMP Wed May 25 17:46:45 EDT 2011

Machine: x86_64

Instance name: dave

Redo thread mounted by this instance: 1

Oracle process number: 42

Unix process pid: 7486, image: oracle@asm(DW00)

 

 

*** 2013-05-27 19:50:55.052

*** SESSION ID:(24.127) 2013-05-2719:50:55.052

*** CLIENT ID:() 2013-05-27 19:50:55.052

*** SERVICE NAME:(SYS$BACKGROUND) 2013-05-2719:50:55.052

*** MODULE NAME:() 2013-05-27 19:50:55.052

*** ACTION NAME:() 2013-05-27 19:50:55.052

 

KUPP:19:50:55.051: Current trace/debugflags: 00480300 = 4719360

*** MODULE NAME:(Data Pump Worker)2013-05-27 19:50:55.054

*** ACTION NAME:(SYS_EXPORT_TABLE_01)2013-05-27 19:50:55.054

 

KUPW:19:50:55.054: 0: ALTER SESSION ENABLEPARALLEL DML called.

KUPW:19:50:55.054: 0: ALTER SESSION ENABLEPARALLEL DML returned.

KUPC:19:50:55.098: Setting remote flag forthis process to FALSE

prvtaqis - Enter

prvtaqis subtab_name upd

prvtaqis sys table upd

KUPW:19:50:55.665: 0: KUPP$PROC.WHATS_MY_IDcalled.

KUPW:19:50:55.665: 1: KUPP$PROC.WHATS_MY_IDreturned.

KUPW:19:50:55.666: 1: worker max messagenumber: 1000

KUPW:19:50:55.668: 1: Full cluster accessallowed

KUPW:19:50:55.669: 1: Original job starttime: 13-MAY-27 07:50:51 PM

KUPW:19:50:55.671: 1: Seqno 16 isTABLE_EXPORT/TABLE/TABLE_DATA

KUPW:19:50:55.671: 1: Seqno 63 isTABLE_EXPORT/TABLE/INDEX/TABLE_DATA

KUPW:19:50:55.671: 1:KUPP$PROC.WHATS_MY_NAME called.

KUPW:19:50:55.671: 1:KUPP$PROC.WHATS_MY_NAME returned. Process name: DW00

KUPW:19:50:55.671: 1:KUPV$FT_INT.GET_INSTANCE_ID called.

KUPW:19:50:55.674: 1:KUPV$FT_INT.GET_INSTANCE_ID returned. Instance name: dave

KUPW:19:50:55.679: 1: ALTER SESSION ENABLERESUMABLE called.

KUPW:19:50:55.679: 1: ALTER SESSION ENABLERESUMABLE returned.

KUPW:19:50:55.682: 1: KUPF$FILE.INITcalled.

KUPW:19:50:55.883: 1: KUPF$FILE.INITreturned.

KUPW:19:50:55.886: 1:KUPF$FILE.GET_MAX_CSWIDTH called.

KUPW:19:50:55.886: 1:KUPF$FILE.GET_MAX_CSWIDTH returned.

[oracle@asm trace]$

 

 

[oracle@asm trace]$ head -50 dave_dm00_7484.trc

Trace file/u01/app/oracle/diag/rdbms/dave/dave/trace/dave_dm00_7484.trc

Oracle Database 11g Enterprise EditionRelease 11.2.0.3.0 - 64bit Production

With the Partitioning, Automatic StorageManagement, OLAP, Data Mining

and Real Application Testing options

ORACLE_HOME = /u01/app/oracle/11.2.0/db_1

System name: Linux

Node name: asm

Release: 2.6.32-100.34.1.el6uek.x86_64

Version: #1 SMP Wed May 25 17:46:45 EDT 2011

Machine: x86_64

Instance name: dave

Redo thread mounted by this instance: 1

Oracle process number: 35

Unix process pid: 7484, image: oracle@asm(DM00)

 

 

*** 2013-05-27 19:50:50.817

*** SESSION ID:(66.5) 2013-05-2719:50:50.817

*** CLIENT ID:() 2013-05-27 19:50:50.817

*** SERVICE NAME:(SYS$USERS) 2013-05-2719:50:50.817

*** MODULE NAME:() 2013-05-27 19:50:50.817

*** ACTION NAME:() 2013-05-27 19:50:50.817

 

KUPP:19:50:50.816: Current trace/debugflags: 00480300 = 4719360

*** MODULE NAME:(Data Pump Master)2013-05-27 19:50:50.823

*** ACTION NAME:(SYS_EXPORT_TABLE_01)2013-05-27 19:50:50.823

 

KUPC:19:50:50.823: Setting remote flag forthis process to FALSE

prvtaqis - Enter

prvtaqis subtab_name upd

prvtaqis sys table upd

KUPM:19:50:50.884: Attached to controlqueue as MCP

KUPM:19:50:50.884: While starting, controlqueue subscriber count is: 2

KUPP:19:50:50.884: Initialization completefor master process DM00

KUPM:19:50:50.916: Entered main loop

KUPM:19:50:50.922: ****IN DISPATCH at71450, request type=1001

KUPM:19:50:50.922: Current user is: SYSTEM

KUPM:19:50:50.922: hand :=DBMS_DATAPUMP.OPEN ('EXPORT', 'TABLE', '', 'SYS_EXPORT_TABLE_01', '', '2');

 

*** 2013-05-27 19:50:51.719

KUPM:19:50:51.719: Resumable enabled

KUPM:19:50:51.734: Entered state: DEFINING

KUPM:19:50:51.734: initing file system

KUPM:19:50:51.749: ****OUT DISPATCH,request type=1001, response type =2041

kwqberlst !retval block

kwqberlst rqan->lagno_kwqiia 5

kwqberlst rqan->lascn_kwqiia > 0 block

kwqberlst rqan->lascn_kwqiia 5

kwqberlst ascn 1644468 lascn 22

KUPM:19:50:51.764: ****IN DISPATCH at71451, request type=1035

 

 

[oracle@asm trace]$ head -50 dave_ora_7480.trc

Trace file/u01/app/oracle/diag/rdbms/dave/dave/trace/dave_ora_7480.trc

Oracle Database 11g Enterprise EditionRelease 11.2.0.3.0 - 64bit Production

With the Partitioning, Automatic StorageManagement, OLAP, Data Mining

and Real Application Testing options

ORACLE_HOME = /u01/app/oracle/11.2.0/db_1

System name: Linux

Node name: asm

Release: 2.6.32-100.34.1.el6uek.x86_64

Version: #1 SMP Wed May 25 17:46:45 EDT 2011

Machine: x86_64

Instance name: dave

Redo thread mounted by this instance: 1

Oracle process number: 36

Unix process pid: 7480, image: oracle@asm(TNS V1-V3)

 

 

*** 2013-05-27 19:50:49.871

*** SESSION ID:(21.359) 2013-05-2719:50:49.871

*** CLIENT ID:() 2013-05-27 19:50:49.871

*** SERVICE NAME:(SYS$USERS) 2013-05-2719:50:49.871

*** MODULE NAME:(ude@asm (TNS V1-V3))2013-05-27 19:50:49.871

*** ACTION NAME:() 2013-05-27 19:50:49.871

 

KUPP:19:50:49.871: Input trace/debug flags:00480300 = 4719360

KUPP:19:50:49.873: Current trace/debugflags: 00480300 = 4719360

 

*** 2013-05-27 19:50:50.633

KUPC:19:50:50.633: Setting remote flag forthis process to FALSE

prvtaqis - Enter

prvtaqis subtab_name upd

prvtaqis sys table upd

prvtaqis - Enter

prvtaqis subtab_name upd

prvtaqis sys table upd

kwqberlst rqan->lascn_kwqiia > 0block

kwqberlst rqan->lascn_kwqiia 5

kwqberlst ascn 1644478 lascn 22

kwqberlst !retval block

kwqberlst rqan->lagno_kwqiia 5

 

*** 2013-05-27 19:50:51.760

kwqberlst rqan->lascn_kwqiia > 0block

kwqberlst rqan->lascn_kwqiia 5

kwqberlst ascn 1644478 lascn 22

kwqberlst !retval block

kwqberlst rqan->lagno_kwqiia 5

kwqberlst rqan->lascn_kwqiia > 0block

kwqberlst rqan->lascn_kwqiia 5

kwqberlst ascn 1644478 lascn 22

kwqberlst !retval block

[oracle@asm trace]$