Poor Data Export Performance(revised)

这是一个十分简单的单表导出作业，表上大约有200万条数据；但实际exp导出时dump文件每秒增长不足1MB，速度十分缓慢。

SQL> show user;
USER is "SH"

SQL> select count(*) from orders;

  COUNT(*)
----------
   2319232

SQL> select bytes/1024/1024 from dba_segments where owner='SH' and segment_name='ORDERS';

BYTES/1024/1024
---------------
            261

/*该表大小为261MB*/

/*这里我们使用直接路径导出*/
[maclean@rh2 ~]$ exp sh/sh file=/s01/orders.dmp direct=y tables=orders
Export: Release 11.2.0.1.0 - Production on Wed Aug 18 21:52:56 2010
Copyright (c) 1982, 2009, Oracle and/or its affiliates.  All rights reserved.
Connected to: Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
Export done in US7ASCII character set and AL16UTF16 NCHAR character set
server uses WE8MSWIN1252 character set (possible charset conversion)
About to export specified tables via Direct Path ...
. . exporting table                         ORDERS

/* 我们通过脚本观察导出文件大小增长速度，每秒大约0.4MB */

[maclean@rh2 s01]$ while (1>0) do ls -lh orders.dmp ; sleep 1; done
-rw-r--r-- 1 maclean oinstall 912K Aug 18 21:54 orders.dmp
-rw-r--r-- 1 maclean oinstall 1.4M Aug 18 21:54 orders.dmp
-rw-r--r-- 1 maclean oinstall 1.8M Aug 18 21:54 orders.dmp
-rw-r--r-- 1 maclean oinstall 2.2M Aug 18 21:54 orders.dmp
-rw-r--r-- 1 maclean oinstall 2.6M Aug 18 21:54 orders.dmp
-rw-r--r-- 1 maclean oinstall 3.0M Aug 18 21:54 orders.dmp
-rw-r--r-- 1 maclean oinstall 3.5M Aug 18 21:54 orders.dmp
-rw-r--r-- 1 maclean oinstall 3.9M Aug 18 21:54 orders.dmp
-rw-r--r-- 1 maclean oinstall 4.3M Aug 18 21:54 orders.dmp
-rw-r--r-- 1 maclean oinstall 4.7M Aug 18 21:54 orders.dmp
-rw-r--r-- 1 maclean oinstall 5.1M Aug 18 21:54 orders.dmp

/*是什么导致了exp如此缓慢呢，有必看一下该导出服务进程的trace文件*/

SQL> select spid from v$process where addr=(select paddr from v$session where module like 'exp@%');
SPID
------------------------
22624

SQL> oradebug setospid 22624;
Oracle pid: 37, Unix process pid: 22624, image: oracle@rh2 (TNS V1-V3)
SQL> oradebug tracefile_name;
/rdbms/sprod/SPROD/trace/SPROD_ora_22624.trc
SQL> host
[maclean@rh2 trace]$ ls -lh SPROD_ora_22624.trc
-rw-r----- 1 maclean oinstall 1.2G Aug 18 21:58 SPROD_ora_22624.trc

/* 这个trace文件居然有1.2G之巨，会存放了些什么呢？*/

[maclean@rh2 trace]$ tail -100 SPROD_ora_22624.trc
2010-08-18 21:59:14.748194 : nsbasic_bsd:41 20 43 4C 41 53 53 07  |A.CLASS.|
2010-08-18 21:59:14.748201 : nsbasic_bsd:00 78 6D 08 0F 01 1A 2E  |.xm.....|
2010-08-18 21:59:14.748212 : nsbasic_bsd:07 00 78 6D 08 0F 01 1A  |..xm....|
2010-08-18 21:59:14.748219 : nsbasic_bsd:2E 13 00 32 30 30 39 2D  |...2009-|
2010-08-18 21:59:14.748225 : nsbasic_bsd:30 38 2D 31 35 3A 30 30  |08-15:00|
2010-08-18 21:59:14.748232 : nsbasic_bsd:3A 32 35 3A 34 35 05 00  |:25:45..|
2010-08-18 21:59:14.748239 : nsbasic_bsd:43 48 45 43 4B 01 00 4E  |CHECK..N|
2010-08-18 21:59:14.748246 : nsbasic_bsd:01 00 4E 01 00 4E 02 00  |..N..N..|
2010-08-18 21:59:14.748253 : nsbasic_bsd:C1 02 FE FF 06 00 50 55  |......PU|
2010-08-18 21:59:14.748260 : nsbasic_bsd:42 4C 49 43 15 00 2F 39  |BLIC../9|

/*绝大多数是Oracle sqlnet trace的内容，是不是因为设置了Oracle SqlNet端的trace选项，从而导致了导出服务进程写出大量sqlnet trace，最终引发exp的缓慢?*/

[maclean@rh2 trace]$ cat $ORACLE_HOME/network/admin/sqlnet.ora
TRACE_LEVEL_SERVER = 16
TRACE_FILE_SERVER = SERVER
TRACE_TIMESTAMP_ SERVER = ON
TRACE_UNIQUE_SERVER = ON

/*的确启用了server端sqlnet trace*/

[maclean@rh2 trace]$ echo "" >  /s01/11gdb/network/admin/sqlnet.ora

/*清空sqlnet.ora配置文件，禁用server端sqlnet trace*/

/*再次尝试exp导出*/

[maclean@rh2 ~]$ exp sh/sh file=/s01/orders.dmp direct=y tables=orders
Export: Release 11.2.0.1.0 - Production on Wed Aug 18 22:00:35 2010
Copyright (c) 1982, 2009, Oracle and/or its affiliates.  All rights reserved.
Connected to: Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
Export done in US7ASCII character set and AL16UTF16 NCHAR character set
server uses WE8MSWIN1252 character set (possible charset conversion)

About to export specified tables via Direct Path ...
. . exporting table                         ORDERS

[maclean@rh2 s01]$ while (1>0) do ls -lh orders.dmp ; sleep 1; done
-rw-r--r-- 1 maclean oinstall 61M Aug 18 22:00 orders.dmp
-rw-r--r-- 1 maclean oinstall 94M Aug 18 22:00 orders.dmp
-rw-r--r-- 1 maclean oinstall 108M Aug 18 22:00 orders.dmp
-rw-r--r-- 1 maclean oinstall 140M Aug 18 22:00 orders.dmp
-rw-r--r-- 1 maclean oinstall 162M Aug 18 22:00 orders.dmp
-rw-r--r-- 1 maclean oinstall 181M Aug 18 22:00 orders.dmp

/*dump文件每秒增长20MB左右，exp导出速度恢复正常*/

/*验证了之前设置server端16级的sqlnet trace会引起exp性能下降的猜测*/

/*如果是expdp数据泵导出工具是否会受到该sqlnet trace的影响呢*/

[maclean@rh2 s01]$ echo "TRACE_LEVEL_SERVER = 16
> TRACE_FILE_SERVER = SERVER
> TRACE_TIMESTAMP_ SERVER = ON
> TRACE_UNIQUE_SERVER = ON" > $ORACLE_HOME/network/admin/sqlnet.ora

[maclean@rh2 dump]$ expdp sh/sh directory=ordump dumpfile=orders.dmp tables=orders
Export: Release 11.2.0.1.0 - Production on Wed Aug 18 22:05:17 2010
Copyright (c) 1982, 2009, Oracle and/or its affiliates.  All rights reserved.
Connected to: Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
Starting "SH"."SYS_EXPORT_TABLE_01":  sh/******** directory=ordump dumpfile=orders.dmp tables=orders
Estimate in progress using BLOCKS method...
Processing object type TABLE_EXPORT/TABLE/TABLE_DATA
Total estimation using BLOCKS method: 261 MB
Processing object type TABLE_EXPORT/TABLE/TABLE
Processing object type TABLE_EXPORT/TABLE/STATISTICS/TABLE_STATISTICS
. . exported "SH"."ORDERS"                               223.8 MB 2319232 rows
Master table "SH"."SYS_EXPORT_TABLE_01" successfully loaded/unloaded
******************************************************************************
Dump file set for SH.SYS_EXPORT_TABLE_01 is:
  /s01/dump/orders.dmp
Job "SH"."SYS_EXPORT_TABLE_01" successfully completed at 22:05:29

/* expdp数据泵在12s内完成了导出工作，可见其并不受到sqlnet trace的不良影响*/

/* 如果我们降低Sqlnet trace的级别，是否可以降低其对exp导出性能的影响呢？*/

/*尝试将trace level改成1*/

[maclean@rh2 s01]$ echo "TRACE_LEVEL_SERVER = 1
> TRACE_FILE_SERVER = SERVER
> TRACE_TIMESTAMP_ SERVER = ON
> TRACE_UNIQUE_SERVER = ON"   >  $ORACLE_HOME/network/admin/sqlnet.ora

maclean@rh2 ~]$ exp sh/sh file=/s01/orders.dmp direct=y tables=orders
Export: Release 11.2.0.1.0 - Production on Wed Aug 18 22:11:57 2010
Copyright (c) 1982, 2009, Oracle and/or its affiliates.  All rights reserved.
Connected to: Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
Export done in US7ASCII character set and AL16UTF16 NCHAR character set
server uses WE8MSWIN1252 character set (possible charset conversion)

About to export specified tables via Direct Path ...
. . exporting table                         ORDERS    2319232 rows exported
EXP-00091: Exporting questionable statistics.
Export terminated successfully with warnings.

[maclean@rh2 s01]$ while (1>0) do ls -lh orders.dmp ; sleep 1; done
-rw-r--r-- 1 maclean oinstall 0 Aug 18 22:11 orders.dmp
-rw-r--r-- 1 maclean oinstall 33M Aug 18 22:11 orders.dmp
-rw-r--r-- 1 maclean oinstall 74M Aug 18 22:11 orders.dmp
-rw-r--r-- 1 maclean oinstall 108M Aug 18 22:12 orders.dmp
-rw-r--r-- 1 maclean oinstall 146M Aug 18 22:12 orders.dmp
-rw-r--r-- 1 maclean oinstall 183M Aug 18 22:12 orders.dmp

/* 导出速度没有明显下降，较低级别的server端sqlnet trace不会对exp导出性能造成影响*/

这个例子告诉我们在使用高级别的sqlnet trace诊断Oracle网络问题后，一定要记得要还原现场的配置，否则可能造成"莫名的性能问题"。