如何對 Oracle 資料泵（expdp/impdp） 進行 debug

一．概述

我在之前寫過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: <SID>_dm<number>_<process_id>.trc
Worker Process trace file: <SID>_dw<number>_<process_id>.trc

 

還有一個在USER_DUMP_DEST目錄：

Shadow Processtrace file: <SID>_ora_<process_id>.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]$

1 2 下一頁