一、 环境信息：
Oracle 11.1.0.7.0 - 64bit，单机，AIX 6.1
二、 EXPDP性能诊断
1、 expdp脚本如下：
cat exp_SCOTT_20180511.par
userid="/ as sysdba" directory=temp_dump dumpfile=exp_SCOTT_20180511_%u.dmp logfile=exp_SCOTT_20180511.log cluster=n parallel=8 compression=all schemas=SCOTT exclude=statistics
2、导出整个schema的时间大约为13个小时，数据量133GB：
sed -n -e '2p' -e '/method:/p' -e '$p' exp_SCOTT_2018051.log Export: Release 11.1.0.7.0 - 64bit Production on Friday, 11 May, 2018 15:16:44 Total estimation using BLOCKS method: 133.3 GB Job "SYS"."SYS_EXPORT_SCHEMA_01" successfully completed at 04:13:05
3、 expdp 导出过程10046 Trace追踪诊断：
因该库需要使用expdp按schema导出导入方式进行整库迁移，按照一个schema导出需要13个小时的速度是接受不了的，虽然该机器配置不是非常的好。接下来导出另外一个schema，并启用10046 trace追踪：
--查询正在执行的expdp相关会话信息： set lines 150 pages 100 numwidth 7 col program for a38 col username for a10 col spid for a7 select to_char(sysdate,'YYYY-MM-DD HH24:MI:SS') "DATE", s.program, s.sid, s.status, s.username, d.job_name, p.spid, s.serial#, p.pid from v$session s, v$process p, dba_datapump_sessions d where p.addr=s.paddr and s.saddr=d.saddr; DATE PROGRAM SID STATUS USERNAME JOB_NAME SPID SERIAL# PID ------------------- -------------------------- ------- -------- ---------- --------------------- ------- ------- ------- 2018-05-14 14:46:10 ) 2814 ACTIVE SYS SYS_EXPORT_SCHEMA_01 488648 6557 467 2018-05-14 14:46:10 ) 3243 ACTIVE SYS SYS_EXPORT_SCHEMA_01 124224 19566 466 2018-05-14 14:46:10 V1-V3) 2801 ACTIVE SYS SYS_EXPORT_SCHEMA_01 340810 61833 464
--查询对应会话是否有其它会话阻塞: select sid,serial#,event,blocking_session,seconds_in_wait,state,last_call_et from v$session where serial# in (6557,19566,61833); SID SERIAL# EVENT BLOCKING_SESSION SECONDS_IN_WAIT STATE LAST_CALL_ET ------- ------- -------------------------------------- ---------------- --------------- ------------------- ------------ 2801 61833 wait for unread message on broadcast channel 1 WAITING 46636 2814 6557 db file sequential read 0 WAITED SHORT TIME 46636 3243 19566 wait for unread message on broadcast channel 0 WAITING 46638
--对相关进程进行10046 trace追踪： oradebug setospid 124224 oradebug unlimit oradebug event 10046 trace name context forever, level 12; oradebug tracefile_name --oradebug event 10046 trace name context off; oradebug setospid 488648 oradebug unlimit oradebug event 10046 trace name context forever, level 12; oradebug tracefile_name --oradebug event 10046 trace name context off; --已上trace时间长一点，会抓取较大的信息
同时查看相关trace文件的的信息：
grep "nam=' WAIT #13: nam='db file sequential read'" TEST_dw01_488648.trc|awk '{print $12}'|sort -u
obj#=-1
obj#=0
obj#=14
...
obj#=579
obj#=596
obj#=9发现这些在等待的这些对象基本都是SYS用户下：
select obj#,owner#,name,namespace from obj$ where obj# in (-1,0,14,3,36,559,563,566,567,575,578,579,596,9); OBJ# OWNER# NAME NAMESPACE ---------- ---------- ------------------------------ ---------- 3 0 I_OBJ# 4 9 0 I_FILE#_BLOCK# 4 14 0 SEG$ 1 36 0 I_OBJ1 4 559 0 PARTOBJ$ 1 563 0 TABPART$ 1 566 0 I_TABPART_BOPART$ 4 567 0 I_TABPART_OBJ$ 4 575 0 TABSUBPART$ 1 578 0 I_TABSUBPART_POBJSUBPART$ 4 579 0 I_TABSUBPART$_OBJ$ 4 596 0 LOBFRAG$ 1
同时查看expdp导出日志，是在估算大小：
Total estimation using BLOCKS method:xxx.xx GB
初步诊断为，expdp在导出时，要估算导出大小，需要查询sys用户下的基表，很有可能是这些查询的SQL出现了性能问题。
--抽查SEG$表的统计信息： OWNER PARTNAME NROWS BLOCKS AVGSPC CCNT ROWLEN SSIZE ANADATE ---------- ---------- -------- ---------- ------ ---- ------ -------- ------------------- SYS 4531 132 0 0 66 4531 2013-07-19 01:10:49
发现该表统计信息很久没有更新，接连查询其它表的统计信息，发现都是很久没有更新统计信息。于是做了如下操作，先将相关表的统计信息更新到最新：
--收集整个sys用户的统计信息： exec dbms_stats.gather_schema_stats(ownname => 'SYS',degree=>8); --收集数据字典的统计信息： exec dbms_stats.gather_dictionary_stats(options =>'gather auto',degree=>16); --收集fixed表统计信息： exec dbms_stats.gather_fixed_objects_stats;
然后中断已经在导出的进程，等统计信息收集完成后，再执行导出，测试导出速度是否有提升。发现导出速度并没有明显提升，看来真正的问题并没有找到，再次进行trace追踪。
tkprof TEST_dm00_124224.trc tkprof_TEST_dm00_124224.out waits=y sort=exeela tkprof TEST_dw01_488648.trc tkprof_TEST_dw01_488648.out waits=y sort=exeela
然后发现如下SQL异常：
SQL ID: aujcr6t1u8u62 Plan Hash: 3731411368 SELECT LVL FROM SYS.KU$_REF_PAR_LEVEL_VIEW WHERE OBJ# = :B1 call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 0 0.00 0.00 0 0 0 0 Execute 160363 1.87 32.76 0 0 0 0 Fetch 160362 13047.39 13496.19 0 1008676980 0 0 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 320725 13049.26 13528.96 0 1008676980 0 0 Misses in library cache during parse: 0 Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ db file sequential read 169141 0.60 453.81 db file scattered read 3 0.01 0.02 OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 167759 4.95 5.86 0 0 0 0 Execute 648851 123.59 151.44 0 0 0 0 Fetch 648850 13057.99 13507.29 0 1010718198 0 488487 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 1465460 13186.53 13664.61 0 1010718198 0 488487
查询该SQL历史执行的情况：
set lines 180 pages 9999
col execs for 999,999,999
col avg_etime for 999,999.999
col avg_lio for 999,999,999.9
col begin_interval_time for a30
col node for 99999
break on plan_hash_value on startup_time skip 1
select ss.snap_id,
ss.instance_number node,
begin_interval_time,
sql_id,
plan_hash_value,
nvl(executions_delta, 0) execs,
(elapsed_time_delta /
decode(nvl(executions_delta, 0), 0, 1, executions_delta)) / 1000000 avg_etime,
(buffer_gets_delta /
decode(nvl(buffer_gets_delta, 0), 0, 1, executions_delta)) avg_lio,
(disk_reads_delta /
decode(nvl(buffer_gets_delta, 0), 0, 1, executions_delta)) avg_pio
from DBA_HIST_SQLSTAT S, DBA_HIST_SNAPSHOT SS
where sql_id = to_char('aujcr6t1u8u62')
and ss.snap_id = S.snap_id
and ss.instance_number = S.instance_number
and executions_delta > 0
order by 1, 2, 3;
--可以看到，该SQL单次执行时间为0.081秒，30分钟内只能执行20万次左右
SNAP_ID NODE BEGIN_INTERVAL_TIME SQL_ID PLAN_HASH_VALUE EXECS AVG_ETIME AVG_LIO AVG_PIO
-------- ----- --------------------- ------------- --------------- ------------ ------------ -------------- ----------
54453 1 11-MAY-18 03.00.27.869 PM aujcr6t1u8u62 3731411368 7,607 .081 6,289.2 .816221901
54454 1 11-MAY-18 03.30.30.087 PM aujcr6t1u8u62 20,606 .081 6,290.0 0
54455 1 11-MAY-18 04.00.32.259 PM aujcr6t1u8u62 20,736 .081 6,290.0 0因为是expdp导出执行的sql，对于这样的sql有一个好处，就是可以对比相同版本的其它库的历史执行计划。
造成相同执行计划在不同库性能差异的这种情况的原因有很多，比如优化器的相关参数设置不同、机器配置不同，库本身的性能较好或库本身很空闲等。这里不对这些原因进行分析，先分析一下该SQL，看看该SQL的执行计划是否合理：
--获取该sql的绑定变量： SQL> set linesize 200 pagesize 200 SQL> col name for a30 SQL> col datatype_string for a20 SQL> col value_string for a20 SQL> select sql_id, name, datatype_string, last_captured, value_string from v$sql_bind_capture2 where sql_id = 'aujcr6t1u8u62' order by last_captured, position; SQL_ID NAME DATATYPE_STRING LAST_CAPTURED VALUE_STRING ------------- ------------------------------ -------------------- ------------------- -------------------- aujcr6t1u8u62 :B1 NUMBER 2018-05-15 16:49:30 801250 aujcr6t1u8u62 :B1 NUMBER 2018-05-16 10:39:08 885287 --获取真实的执行计划： set pages 9999 line 333 var B1 number; exec :B1 := 885287; SELECT LVL FROM SYS.KU$_REF_PAR_LEVEL_VIEW WHERE OBJ# = :B1; select * from table(dbms_xplan.display_cursor(null,0));
然后与该trace追踪到的执行计划进行对比：
发现该SQL使用的优化器模式是Rule Based Optimizer(简称RBO)，是基于数据字典的优化，它根据数据字典查询有无可用的索引，如果有则使用，否则不使用，不同的访问方法有预定好的优先级，选择优先级高的执行方法。但在这里不知道它为什么没有选择走CDEF$的I_CDEF3索引，而是走了全表扫描。这也可以解释为什么收集完sys用户统计信息之后，执行计划不变的原因了。那问题来了，是使用CBO做索引扫描的执行效率高，还是现在RBO模式的效率高呢？经测试，使用Cost Based Optimizer(简称CBO)的效率高，也就是通过变量信息产生的真正执行计划。
SQL> SELECT /*+ rule */ LVL FROM SYS.KU$_REF_PAR_LEVEL_VIEW WHERE OBJ# = :B1; no rows selected Elapsed: 00:00:00.10 SQL> SELECT LVL FROM SYS.KU$_REF_PAR_LEVEL_VIEW WHERE OBJ# = :B1; no rows selected Elapsed: 00:00:00.00
既然问题已经找到，接下来就好办了，使用coe_xfr_sql_profile.sql直接绑定较优的执行计划。
绑定后的执行计划效果如下：
绑定之后的提升效果还是很明显的，单次平均执行时间已经下降到0.002秒，平均逻辑读也成倍的下降。这里为什么说很明显呢？可能看起来0.081秒的执行效率已经很高了，但是这个sql的是需要很次执行的，在expdp导出schema的过程中，需要查询整个schema的所有对象。
优化后的导出效果，1个多小时就完成了导出：
sed -n -e '2p' -e '$p' exp_SCOTT_20180515.log Export: Release 11.1.0.7.0 - 64bit Production on Tuesday, 15 May, 2018 16:51:22 Job "SYS"."SYS_EXPORT_SCHEMA_01" successfully completed at 18:16:51
三、 总结
1、 对于expdp/impdp的性能影响因素很多，比如库整体性能，机器配置情况，存储I/O资源等。
2、 有关expdp/impdp性能诊断请参考：
SRDC - 数据泵导入（IMPDP）性能问题的诊断收集 (Document 2365615.1)
SRDC - 数据泵导出性能问题的诊断收集 (Document 2365568.1)
针对数据泵导出 (expdp) 和导入 (impdp)工具性能降低问题的检查表 (Document 1549185.1)
