13 Replies Latest reply: Dec 17, 2012 9:59 AM by Dean Gagne-Oracle RSS

    Question on impdp is slow

    user9944600
      i am running impdp on Solaris 10, Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - 64bit Production.

      the export is faster, but import using impdp is slow. though i started the process with parallel option 8, it does not seem to utilize parallel option as most of the worker processes seems to be waiting. is there a parameter to speed up the index creation parallely.

      please let me know, if i need to provide more information.

      Thanks in advance.
        • 1. Re: Question on impdp is slow
          Srini Chavali-Oracle
          Pl post complete expdp and impdp commands used, along with the first 20 lines of the expdp and impdp logs

          Checklist For Slow Performance Of DataPump Export (expdp) And Import (impdp) [ID 453895.1]
          Oracle Server - Export Data Pump and Import DataPump FAQ [ID 556636.1]
          Parallel Capabilities of Oracle Data Pump [ID 365459.1]

          HTH
          Srini
          • 2. Re: Question on impdp is slow
            sb92075
            user9944600 wrote:
            i am running impdp on Solaris 10, Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - 64bit Production.

            the export is faster, but import using impdp is slow. though i started the process with parallel option 8, it does not seem to utilize parallel option as most of the worker processes seems to be waiting. is there a parameter to speed up the index creation parallely.

            please let me know, if i need to provide more information.

            Thanks in advance.
            in most cases import will be measurably slower than export;
            since export only includes metadata for the indexes while import must spend time actual time building indexes.
            • 3. Re: Question on impdp is slow
              user9944600
              Import: Release 10.2.0.4.0 - 64bit Production on Sunday, 16 December, 2012 7:46:16
              
              Copyright (c) 2003, 2007, Oracle.  All rights reserved.
              ;;; 
              Connected to: Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - 64bit Production
              With the Partitioning, OLAP, Data Mining and Real Application Testing options
              Master table "TLSDBA"."SYS_IMPORT_SCHEMA_25" successfully loaded/unloaded
              Starting "TLSDBA"."SYS_IMPORT_SCHEMA_25":  userid=testsch/******** schemas=TESTSCH2 REMAP_SCHEMA=TESTSCH1:TESTSCH2 PARALLEL=8 DIRECTORY=TEST_DIR DUMPFILE=TESTDMP.dmp LOGFILE=TESTDMP.log STATUS=300 
              Processing object type SCHEMA_EXPORT/USER
              Processing object type SCHEMA_EXPORT/SYSTEM_GRANT
              Processing object type SCHEMA_EXPORT/ROLE_GRANT
              Processing object type SCHEMA_EXPORT/DEFAULT_ROLE
              Processing object type SCHEMA_EXPORT/PRE_SCHEMA/PROCACT_SCHEMA
              Processing object type SCHEMA_EXPORT/TABLE/TABLE
              Processing object type SCHEMA_EXPORT/TABLE/TABLE_DATA
              
              /
              the status output is pasted below. this table hold_offers is having CLOB (probably small clob columns).
              Job: SYS_IMPORT_SCHEMA_25
                Operation: IMPORT
                Mode: SCHEMA
                State: EXECUTING
                Bytes Processed: 418,444,592
                Percent Done: 51
                Current Parallelism: 8
                Job Error Count: 0
                Dump File: /testdir/testdmp.dmp
              
              Worker 1 Status:
                State: WORK WAITING
              
              Worker 2 Status:
                State: EXECUTING
                Object Schema: testsch
                Object Name: HOLD_OFFER
                Object Type: SCHEMA_EXPORT/TABLE/TABLE_DATA
                Completed Objects: 1
                Completed Rows: 43,628
                Completed Bytes: 389,758,608
                Percent Done: 100
                Worker Parallelism: 1
              
              Worker 3 Status:
                State: WORK WAITING
              
              Worker 4 Status:
                State: WORK WAITING
              
              Worker 5 Status:
                State: WORK WAITING
              
              Worker 6 Status:
                State: WORK WAITING
              
              Worker 7 Status:
                State: WORK WAITING
              
              Worker 8 Status:
                State: WORK WAITING
              
              
              /
              • 4. Re: Question on impdp is slow
                user9944600
                Yes, measurably import is slower compared to export. in this case export finishes in 15 minutes and import is taking more than 15 hours. i am using parallel while both export and import. thanks for your attention.
                • 5. Re: Question on impdp is slow
                  Srini Chavali-Oracle
                  How many tables/indexes are in this schema ? How many rows in all of the tables combined ? Have you tried to export and import without the parallel clause ? Have you tried original exp and imp ?

                  HTH
                  Srini
                  • 6. Re: Question on impdp is slow
                    user9944600
                    How many tables/indexes are in this schema ?
                    200 tables in the schema

                    How many rows in all of the tables combined ?
                    i think it will be close to 10 mil rows

                    Have you tried to export and import without the parallel clause ?
                    Yes i have tried without parallel, it is giving the same performance.

                    Have you tried original exp and imp ?
                    it is cumbersome using exp/imp, as i have to do a complete refresh of the schema. i will export schema from another database and import it into another schema.
                    • 7. Re: Question on impdp is slow
                      Srini Chavali-Oracle
                      Pl enable trace in impdp to determine why it is taking so long.

                      Export/Import DataPump Parameter TRACE - How to Diagnose Oracle Data Pump [ID 286496.1]

                      I do not understand why you think exp/imp is more cumbersome than using expdp/impdp

                      HTH
                      Srini
                      • 8. Re: Question on impdp is slow
                        user9944600
                        This is what i see in the trace, when i ran this morning. sorry about the long message... Mostly waiting on " DIRECT WRITE PATH"
                        *** 2012-12-16 09:27:48.212
                        *** ACTION NAME:(SYS_IMPORT_SCHEMA_25) 2012-12-16 09:27:48.212
                        *** MODULE NAME:(Data Pump Worker) 2012-12-16 09:27:48.212
                        *** SERVICE NAME:(SYS$USERS) 2012-12-16 09:27:48.212
                        *** SESSION ID:(468.6611) 2012-12-16 09:27:48.212
                        WAIT #56: nam='direct path write' ela= 147 file number=5 first dba=3347340 block cnt=1 obj#=495 tim=2605943717496
                        WAIT #56: nam='direct path write' ela= 175 file number=5 first dba=3347344 block cnt=1 obj#=495 tim=2605946324370
                        WAIT #56: nam='direct path write' ela= 171 file number=5 first dba=3347281 block cnt=1 obj#=495 tim=2605949132858
                        WAIT #56: nam='direct path write' ela= 201 file number=5 first dba=3347285 block cnt=1 obj#=495 tim=2605951812262
                        *** 2012-12-16 09:27:59.286
                        WAIT #56: nam='direct path write' ela= 178 file number=5 first dba=3347289 block cnt=1 obj#=495 tim=2605954532618
                        WAIT #56: nam='direct path write' ela= 201 file number=5 first dba=3347293 block cnt=1 obj#=495 tim=2605960051126
                        WAIT #56: nam='direct path write' ela= 209 file number=5 first dba=3347297 block cnt=1 obj#=495 tim=2605962631305
                        *** 2012-12-16 09:28:10.599
                        WAIT #56: nam='direct path write' ela= 172 file number=5 first dba=3347301 block cnt=1 obj#=495 tim=2605965580471
                        WAIT #56: nam='direct path write' ela= 211 file number=5 first dba=3347305 block cnt=1 obj#=495 tim=2605968538388
                        WAIT #56: nam='direct path write' ela= 223 file number=5 first dba=3347309 block cnt=1 obj#=495 tim=2605971316263
                        WAIT #56: nam='direct path write' ela= 175 file number=5 first dba=3347313 block cnt=1 obj#=495 tim=2605974139207
                        *** 2012-12-16 09:28:22.050
                        WAIT #56: nam='direct path write' ela= 194 file number=5 first dba=3347317 block cnt=1 obj#=495 tim=2605976762615
                        WAIT #56: nam='direct path write' ela= 198 file number=5 first dba=3347321 block cnt=1 obj#=495 tim=2605979677117
                        WAIT #56: nam='direct path write' ela= 187 file number=5 first dba=3347325 block cnt=1 obj#=495 tim=2605982320740
                        WAIT #56: nam='direct path write' ela= 196 file number=5 first dba=3347329 block cnt=1 obj#=495 tim=2605985124808
                        *** 2012-12-16 09:28:33.471
                        WAIT #56: nam='direct path write' ela= 151 file number=5 first dba=3347333 block cnt=1 obj#=495 tim=2605987916815
                        WAIT #56: nam='direct path write' ela= 169 file number=5 first dba=3347337 block cnt=1 obj#=495 tim=2605990574044
                        WAIT #56: nam='direct path write' ela= 319 file number=5 first dba=3347341 block cnt=1 obj#=495 tim=2605993257180
                        WAIT #56: nam='direct path write' ela= 770 file number=5 first dba=3347282 block cnt=1 obj#=495 tim=2605995949204
                        *** 2012-12-16 09:28:44.459
                        WAIT #56: nam='direct path write' ela= 224 file number=5 first dba=3347286 block cnt=1 obj#=495 tim=2605998646540
                        WAIT #56: nam='direct path write' ela= 188 file number=5 first dba=3347290 block cnt=1 obj#=495 tim=2606001384337
                        WAIT #56: nam='direct path write' ela= 179 file number=5 first dba=3347294 block cnt=1 obj#=495 tim=2606004188492
                        *** 2012-12-16 09:28:55.600
                        WAIT #56: nam='direct path write' ela= 205 file number=5 first dba=3347298 block cnt=1 obj#=495 tim=2606009526583
                        WAIT #56: nam='direct path write' ela= 147 file number=5 first dba=3347302 block cnt=1 obj#=495 tim=2606012258049
                        WAIT #56: nam='direct path write' ela= 191 file number=5 first dba=3347306 block cnt=1 obj#=495 tim=2606015129625
                        WAIT #56: nam='direct path write' ela= 158 file number=5 first dba=3347310 block cnt=1 obj#=495 tim=2606017678682
                        *** 2012-12-16 09:29:06.722
                        WAIT #56: nam='direct path write' ela= 142 file number=5 first dba=3347314 block cnt=1 obj#=495 tim=2606020387997
                        WAIT #56: nam='direct path write' ela= 194 file number=5 first dba=3347318 block cnt=1 obj#=495 tim=2606023149774
                        WAIT #56: nam='direct path write' ela= 162 file number=5 first dba=3347322 block cnt=1 obj#=495 tim=2606026037845
                        WAIT #56: nam='direct path write' ela= 170 file number=5 first dba=3347326 block cnt=1 obj#=495 tim=2606028591900
                        *** 2012-12-16 09:29:17.742
                        WAIT #56: nam='direct path write' ela= 159 file number=5 first dba=3347330 block cnt=1 obj#=495 tim=2606031150311
                        WAIT #56: nam='direct path write' ela= 187 file number=5 first dba=3347334 block cnt=1 obj#=495 tim=2606033872864
                        WAIT #56: nam='direct path write' ela= 181 file number=5 first dba=3347338 block cnt=1 obj#=495 tim=2606036628795
                        WAIT #56: nam='direct path write' ela= 199 file number=5 first dba=3347342 block cnt=1 obj#=495 tim=2606039765779
                        *** 2012-12-16 09:29:29.658
                        WAIT #56: nam='direct path write' ela= 252 file number=5 first dba=3347283 block cnt=1 obj#=495 tim=2606042787092
                        WAIT #56: nam='direct path write' ela= 172 file number=5 first dba=3347287 block cnt=1 obj#=495 tim=2606045731067
                        WAIT #56: nam='Datapump dump file I/O' ela= 963 count=1 intr=32 timeout=2147483647 obj#=495 tim=2606048521230
                        =====================
                        PARSING IN CURSOR #30 len=129 dep=3 uid=0 oct=6 lid=0 tim=2606048522475 hv=2635489469 ad='b880f838'
                        update seq$ set increment$=:2,minvalue=:3,maxvalue=:4,cycle#=:5,order$=:6,cache=:7,highwater=:8,audit$=:9,flags=:10 where obj#=:1
                        END OF STMT
                        PARSE #30:c=0,e=950,p=0,cr=0,cu=0,mis=1,r=0,dep=3,og=4,tim=2606048522471
                        BINDS #30:
                        kkscoacd
                         Bind#0
                          oacdty=02 mxl=22(02) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=18 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=41ebfce68  bln=24  avl=02  flg=09
                          value=50
                         Bind#1
                          oacdty=02 mxl=22(02) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=18 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=41ebfce7a  bln=24  avl=02  flg=09
                          value=1
                         Bind#2
                          oacdty=02 mxl=22(15) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=18 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=41ebfce8c  bln=24  avl=15  flg=09
                          value=999999999999999999999999999
                         Bind#3
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff79d43fe0  bln=24  avl=01  flg=05
                          value=0
                         Bind#4
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff79d43fb0  bln=24  avl=01  flg=05
                          value=0
                         Bind#5
                          oacdty=02 mxl=22(02) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=18 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=41ebfce9e  bln=24  avl=02  flg=09
                          value=20
                         Bind#6
                          oacdty=02 mxl=22(05) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=18 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=41ebfceb0  bln=24  avl=05  flg=09
                          value=59988901
                         Bind#7
                          oacdty=01 mxl=32(32) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=18 fl2=0001 frm=01 csi=873 siz=32 off=0
                          kxsbbbfp=41ebfcec2  bln=32  avl=32  flg=09
                          value="--------------------------------"
                         Bind#8
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff79d43f80  bln=24  avl=01  flg=05
                          value=0
                         Bind#9
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff79d44010  bln=22  avl=03  flg=05
                          value=825
                        EXEC #30:c=0,e=1688,p=0,cr=1,cu=2,mis=1,r=1,dep=3,og=4,tim=2606048524284
                        STAT #30 id=1 cnt=1 pid=0 pos=1 obj=0 op='UPDATE  SEQ$ (cr=1 pr=0 pw=0 time=210 us)'
                        STAT #30 id=2 cnt=1 pid=1 pos=1 obj=102 op='INDEX UNIQUE SCAN I_SEQ1 (cr=1 pr=0 pw=0 time=20 us)'
                        WAIT #56: nam='log file switch completion' ela= 4 p1=0 p2=0 p3=0 obj#=495 tim=2606048527848
                        WAIT #56: nam='log file switch completion' ela= 12173 p1=0 p2=0 p3=0 obj#=495 tim=2606048540040
                        WAIT #56: nam='log file switch completion' ela= 57718 p1=0 p2=0 p3=0 obj#=495 tim=2606048597807
                        WAIT #56: nam='direct path write' ela= 211 file number=5 first dba=3347291 block cnt=1 obj#=495 tim=2606051305881
                        *** 2012-12-16 09:29:41.193
                        WAIT #56: nam='direct path write' ela= 213 file number=5 first dba=3347295 block cnt=1 obj#=495 tim=2606054052120
                        WAIT #56: nam='direct path write' ela= 167 file number=5 first dba=3347299 block cnt=1 obj#=495 tim=2606056734613
                        WAIT #56: nam='direct path write' ela= 155 file number=5 first dba=3347303 block cnt=1 obj#=495 tim=2606059461987
                        =====================
                        PARSING IN CURSOR #36 len=36 dep=3 uid=0 oct=3 lid=0 tim=2606062245981 hv=1570213724 ad='b897dc60'
                        select file# from file$ where ts#=:1
                        END OF STMT
                        PARSE #36:c=0,e=735,p=0,cr=0,cu=0,mis=1,r=0,dep=3,og=4,tim=2606062245976
                        BINDS #36:
                        kkscoacd
                         Bind#0
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff79bc2718  bln=22  avl=02  flg=05
                          value=5
                        EXEC #36:c=0,e=882,p=0,cr=0,cu=0,mis=1,r=0,dep=3,og=4,tim=2606062247037
                        FETCH #36:c=0,e=73,p=0,cr=3,cu=0,mis=0,r=1,dep=3,og=4,tim=2606062247145
                        FETCH #36:c=0,e=4,p=0,cr=0,cu=0,mis=0,r=0,dep=3,og=4,tim=2606062247178
                        STAT #36 id=1 cnt=1 pid=0 pos=1 obj=17 op='TABLE ACCESS FULL FILE$ (cr=3 pr=0 pw=0 time=58 us)'
                        =====================
                        PARSING IN CURSOR #30 len=103 dep=3 uid=0 oct=6 lid=0 tim=2606062247927 hv=3840466760 ad='dbf8a9f0'
                        update tsq$ set blocks=:3,maxblocks=:4,grantor#=:5,priv1=:6,priv2=:7,priv3=:8 where ts#=:1 and user#=:2
                        END OF STMT
                        PARSE #30:c=0,e=411,p=0,cr=0,cu=0,mis=1,r=0,dep=3,og=4,tim=2606062247925
                        BINDS #30:
                        kkscoacd
                         Bind#0
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff79d43fb0  bln=24  avl=04  flg=05
                          value=107864
                         Bind#1
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff79d43f80  bln=24  avl=01  flg=05
                          value=0
                         Bind#2
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff79d43f50  bln=24  avl=01  flg=05
                          value=0
                         Bind#3
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff79d43f00  bln=24  avl=01  flg=05
                          value=0
                         Bind#4
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff79d43ed0  bln=24  avl=01  flg=05
                          value=0
                         Bind#5
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff79d43ea0  bln=24  avl=01  flg=05
                          value=0
                         Bind#6
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff79d44010  bln=22  avl=02  flg=05
                          value=5
                         Bind#7
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff79d43fe0  bln=24  avl=03  flg=05
                          value=298
                        EXEC #30:c=0,e=1253,p=0,cr=4,cu=1,mis=1,r=1,dep=3,og=4,tim=2606062249264
                        STAT #30 id=1 cnt=0 pid=0 pos=1 obj=0 op='UPDATE  TSQ$ (cr=4 pr=0 pw=0 time=200 us)'
                        STAT #30 id=2 cnt=1 pid=1 pos=1 obj=61 op='TABLE ACCESS CLUSTER TSQ$ (cr=4 pr=0 pw=0 time=100 us)'
                        STAT #30 id=3 cnt=1 pid=2 pos=1 obj=11 op='INDEX UNIQUE SCAN I_USER# (cr=1 pr=0 pw=0 time=26 us)'
                        =====================
                        PARSING IN CURSOR #36 len=296 dep=3 uid=0 oct=6 lid=0 tim=2606062249797 hv=2379717279 ad='ae781860'
                        update seg$ set type#=:4,blocks=:5,extents=:6,minexts=:7,maxexts=:8,extsize=:9,extpct=:10,user#=:11,iniexts=:12,lists=decode(:13, 65535, NULL, :13),groups=decode(:14, 65535, NULL, :14), cachehint=:15, hwmincr=:16, spare1=DECODE(:17,0,NULL,:17),scanhint=:18 where ts#=:1 and file#=:2 and block#=:3
                        END OF STMT
                        PARSE #36:c=0,e=441,p=0,cr=0,cu=0,mis=1,r=0,dep=3,og=4,tim=2606062249794
                        BINDS #36:
                        kkscoacd
                         Bind#0
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff79d7e8e8  bln=24  avl=02  flg=05
                          value=8
                         Bind#1
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff777239a8  bln=24  avl=03  flg=05
                          value=1280
                         Bind#2
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff77723978  bln=24  avl=02  flg=05
                          value=25
                         Bind#3
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff77723948  bln=24  avl=02  flg=05
                          value=1
                         Bind#4
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff77723918  bln=24  avl=06  flg=05
                          value=2147483645
                         Bind#5
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff777238e8  bln=24  avl=03  flg=05
                          value=128
                         Bind#6
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff777238b8  bln=24  avl=01  flg=05
                          value=0
                         Bind#7
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff77723888  bln=24  avl=03  flg=05
                          value=298
                         Bind#8
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff77723858  bln=24  avl=02  flg=05
                          value=8
                         Bind#9
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff77723828  bln=24  avl=01  flg=05
                          value=0
                         Bind#10
                          No oacdef for this bind.
                         Bind#11
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff777237f8  bln=24  avl=01  flg=05
                          value=0
                         Bind#12
                          No oacdef for this bind.
                         Bind#13
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff777237c8  bln=24  avl=01  flg=05
                          value=0
                         Bind#14
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff77723798  bln=24  avl=04  flg=05
                          value=268663
                         Bind#15
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff77723768  bln=24  avl=04  flg=05
                          value=131329
                         Bind#16
                          No oacdef for this bind.
                         Bind#17
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff77723738  bln=24  avl=01  flg=05
                          value=0
                         Bind#18
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff79d7e998  bln=22  avl=02  flg=05
                          value=5
                         Bind#19
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff79d7e968  bln=24  avl=03  flg=05
                          value=1024
                         Bind#20
                          oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
                          oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
                          kxsbbbfp=ffffffff79d7e938  bln=24  avl=05  flg=05
                          value=3089939
                        EXEC #36:c=0,e=1944,p=0,cr=5,cu=1,mis=1,r=1,dep=3,og=4,tim=2606062251863
                        STAT #36 id=1 cnt=0 pid=0 pos=1 obj=0 op='UPDATE  SEG$ (cr=5 pr=0 pw=0 time=175 us)'
                        STAT #36 id=2 cnt=1 pid=1 pos=1 obj=14 op='TABLE ACCESS CLUSTER SEG$ (cr=5 pr=0 pw=0 time=95 us)'
                        STAT #36 id=3 cnt=1 pid=2 pos=1 obj=9 op='INDEX UNIQUE SCAN I_FILE#_BLOCK# (cr=2 pr=0 pw=0 time=20 us)'
                        WAIT #56: nam='direct path write' ela= 187 file number=5 first dba=3347435 block cnt=1 obj#=495 tim=2606062252386
                        *** 2012-12-16 09:29:52.404
                        WAIT #56: nam='direct path write' ela= 207 file number=5 first dba=3347373 block cnt=1 obj#=495 tim=2606064999999
                        WAIT #56: nam='direct path write' ela= 196 file number=5 first dba=3347377 block cnt=1 obj#=495 tim=2606067831026
                        WAIT #56: nam='direct path write' ela= 201 file number=5 first dba=3347381 block cnt=1 obj#=495 tim=2606073598446
                        *** 2012-12-16 09:30:04.265
                        WAIT #56: nam='direct path write' ela= 194 file number=5 first dba=3347385 block cnt=1 obj#=495 tim=2606076582964
                        WAIT #56: nam='direct path write' ela= 160 file number=5 first dba=3347389 block cnt=1 obj#=495 tim=2606079463821
                        WAIT #56: nam='direct path write' ela= 162 file number=5 first dba=3347393 block cnt=1 obj#=495 tim=2606082341832
                        WAIT #56: nam='direct path write' ela= 141 file number=5 first dba=3347397 block cnt=1 obj#=495 tim=2606085308680
                        *** 2012-12-16 09:30:16.264
                        WAIT #56: nam='Datapump dump file I/O' ela= 762 count=1 intr=32 timeout=2147483647 obj#=495 tim=2606088301034
                        :
                        :
                        :
                        :
                        <<<< TRIMMED FOR  BREVITY >>>>
                        EXEC #30:c=0,e=687,p=0,cr=1,cu=2,mis=0,r=1,dep=3,og=4,tim=2606171456459
                        STAT #30 id=1 cnt=1 pid=0 pos=1 obj=0 op='UPDATE  SEQ$ (cr=1 pr=0 pw=0 time=225 us)'
                        STAT #30 id=2 cnt=1 pid=1 pos=1 obj=102 op='INDEX UNIQUE SCAN I_SEQ1 (cr=1 pr=0 pw=0 time=29 us)'
                        WAIT #56: nam='direct path write' ela= 213 file number=5 first dba=3347383 block cnt=1 obj#=495 tim=2606174205674
                        *** 2012-12-16 09:31:47.264
                        WAIT #56: nam='direct path write' ela= 173 file number=5 first dba=3347387 block cnt=1 obj#=495 tim=2606177168189
                        WAIT #56: nam='direct path write' ela= 170 file number=5 first dba=3347391 block cnt=1 obj#=495 tim=2606180061880
                        WAIT #56: nam='Datapump dump file I/O' ela= 10 count=1 intr=32 timeout=2147483647 obj#=495 tim=2606182966681
                        WAIT #56: nam='direct path write' ela= 215 file number=5 first dba=3347395 block cnt=1 obj#=495 tim=2606185745141
                        *** 2012-12-16 09:31:58.934
                        WAIT #56: nam='direct path write' ela= 144 file number=5 first dba=3347399 block cnt=1 obj#=495 tim=2606188565060
                        /
                        Edited by: user9944600 on Dec 16, 2012 5:07 PM
                        • 9. Re: Question on impdp is slow
                          Srini Chavali-Oracle
                          This could possibly be a storage or IO issue. If you have an AWR license, pl also review the AWR report during the time impdp was executing to look at the Top 5 timed events.

                          WAITEVENT: "direct path write" Reference Note [ID 50416.1]
                          Resolving Issues Where 'direct path write' Waits When I/O is Slow [ID 1477235.1]
                          Resolving Issues Where 'direct path write' Waits When I/O is NOT Slow and Cause is Unknown [ID 1475655.1]
                          Resolving Issues Where Session Level Problems are Caused by Contention on 'direct path write' Waits [ID 1476094.1]

                          What is datafile 5 ? Pl query DBA_DATA_FILES.

                          http://docs.oracle.com/cd/B19306_01/server.102/b14237/statviews_3083.htm#REFRN23049

                          HTH
                          Srini
                          • 10. Re: Question on impdp is slow
                            user9944600
                            this is a development database and this tablespace is the only tablespace where we are storing both tables and indexes.

                            Thank you very much.
                            • 11. Re: Question on impdp is slow
                              Richard Harrison .
                              Hi,
                              I've been doing a lot of playing around with this specifc problem recently and I'm not sure if what I've found is specific to BLOBs on SLES or whether its the same for other platforms too. I've found that if you set:

                              filesystemio_options=NONE (and then restart db)

                              BLOB imports go about 10x faster.

                              Can you try that on your server and see what happens? It seems directio is painfully slow on sles with blob imports but I've not got to the bottom of why yet.

                              Cheers,
                              Rich
                              • 12. Re: Question on impdp is slow
                                dba7188@
                                Thanks Rich, i will be creating a SR with oracle support.
                                • 13. Re: Question on impdp is slow
                                  Dean Gagne-Oracle
                                  Hi,

                                  Just an f.y.i.... Indexes are created serially, but built in parallel. What does that mean:

                                  There is on create index statement at a time, but your create index statement is modified to look like:

                                  create index foo ... parallel 8;

                                  followed by:

                                  alter index foo parallel <original parallel value>;

                                  This way, the index will use pq slaves to build the index faster and then restore the original value used.

                                  Hope this helps.

                                  Dean

                                  p.s. I also meant to say that there was a bug where parallel pq slaves were not being used (the parallel value was always set to 1 and then altered to the original value) so you could check to see if that bug is in your version and if there is a fix for it.

                                  Edited by: Dean Gagne on Dec 17, 2012 10:58 AM