一、 环境信息：
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有一个好处，就是可以对比相同版本的其它库的历史执行计划。
 666.png

造成相同执行计划在不同库性能差异的这种情况的原因有很多，比如优化器的相关参数设置不同、机器配置不同，库本身的性能较好或库本身很空闲等。这里不对这些原因进行分析，先分析一下该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));


111.png 

然后与该trace追踪到的执行计划进行对比：

 

 222.png

发现该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直接绑定较优的执行计划。

 

绑定后的执行计划效果如下：
333.png

绑定之后的提升效果还是很明显的，单次平均执行时间已经下降到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)