Oracle impdp running way too long

I’m trying to import a schema into an oracle instance, that’s running in a docker container (hopefully this is not relevant).

I would like to apologize in advance for the long post, but I wanted to include all I have already checked.

  • How to run docker image , take ssh of container and bind port to “49” in single cmd?
  • Dockerized database passwords management
  • Not able to run Meteor application in Docker container because of couldn't run ps ax error
  • Docker - secure mysql configuration
  • Issue with telefonica/orchestrator
  • webpack and react jsx - hot loading not working with docker container
  • The import quickly loads the tables, builds the indexes, but when it gets to the packages progress just stops.

    The log output stops with these lines

    Processing object type SCHEMA_EXPORT/VIEW/COMMENT
    Processing object type SCHEMA_EXPORT/PACKAGE/PACKAGE_BODY
    

    It appears to be stuck in process 273, “ALTER PACKAGE …”

    set linesize 200
    select s.username, s.sid, s.process, s.status, t.command_type, t.sql_text
      from v$session s
         , v$sqltext t
     where t.sql_id = s.sql_id
     order by t.sql_id, t.piece
    
    USERNAME                              SID PROCESS                  STATUS   COMMAND_TYPE SQL_TEXT
    ------------------------------ ---------- ------------------------ -------- ------------ ----------------------------------------------------------------
    SYS                                   192 266                      ACTIVE             47 BEGIN :1 := sys.kupc$que_int.get_status(:2, :3); END;
    SYS                                   195 699                      ACTIVE              3 select s.username, s.sid, s.process, s.status, t.command_type, t
    SYS                                   195 699                      ACTIVE              3 .sql_text   from v$session s      , v$sqltext t  where t.sql_id
    SYS                                   195 699                      ACTIVE              3 = s.sql_id  order by t.sql_id, t.piece
    SYS                                     7 273                      ACTIVE             98  ALTER PACKAGE "XXX"."XXX_AQ_PUT"   COMPILE BODY     PLSQL_OPTIM
    SYS                                     7 273                      ACTIVE             98 IZE_LEVEL=  2    PLSQL_CODE_TYPE=  INTERPRETED    PLSQL_DEBUG=
    SYS                                     7 273                      ACTIVE             98 FALSE    PLSCOPE_SETTINGS=  'IDENTIFIERS:NONE' REUSE SETTINGS TI
    SYS                                     7 273                      ACTIVE             98 MESTAMP '2015-06-02 13:31:03'
    SYS                                   196 271                      ACTIVE             47 BEGIN :1 := sys.kupc$que_int.receive(:2); END;
    

    but “ps agxu” reveals that process 273 uses a lot of CPU

    oracle     119  0.0  0.0 1782464 14724 ?       Ss   10:56   0:01 ora_pmon_xxxdb
    oracle     121  0.0  0.0 1780172 11276 ?       Ss   10:56   0:02 ora_vktm_xxxdb
    oracle     125  0.0  0.0 1780172 11216 ?       Ss   10:56   0:00 ora_gen0_xxxdb
    oracle     127  0.0  0.0 1780172 11228 ?       Ss   10:56   0:00 ora_diag_xxxdb
    oracle     129  0.0  0.0 1780172 19120 ?       Ss   10:56   0:00 ora_dbrm_xxxdb
    oracle     131  0.0  0.0 1780172 11504 ?       Ss   10:56   0:00 ora_psp0_xxxdb
    oracle     133  0.0  0.0 1780684 14884 ?       Ss   10:56   0:04 ora_dia0_xxxdb
    oracle     135  0.0  0.3 1780172 109800 ?      Ss   10:56   0:00 ora_mman_xxxdb
    oracle     137  0.0  1.3 1817344 439448 ?      Ss   10:56   0:02 ora_dbw0_xxxdb
    oracle     139  0.0  0.0 1796924 20736 ?       Ss   10:56   0:01 ora_lgwr_xxxdb
    oracle     141  0.0  0.0 1780684 29472 ?       Ss   10:56   0:02 ora_ckpt_xxxdb
    oracle     143  0.0  0.3 1786832 108004 ?      Ss   10:56   0:01 ora_smon_xxxdb
    oracle     145  0.0  0.0 1781708 20928 ?       Ss   10:56   0:00 ora_reco_xxxdb
    oracle     147  0.0  0.1 1786180 62136 ?       Ss   10:56   0:01 ora_mmon_xxxdb
    oracle     149  0.0  0.0 1780172 19240 ?       Ss   10:56   0:00 ora_mmnl_xxxdb
    oracle     151  0.0  0.0 1803680 11540 ?       Ss   10:56   0:00 ora_d000_xxxdb
    oracle     153  0.0  0.0 1781368 10352 ?       Ss   10:56   0:00 ora_s000_xxxdb
    oracle     163  0.0  0.0 1780172 13140 ?       Ss   10:56   0:00 ora_qmnc_xxxdb
    oracle     228  0.0  0.0   9508  1288 ?        S    10:56   0:00 /bin/bash /home/oracle/bin/import-dump
    oracle     243  0.0  0.1 1784780 56672 ?       Ss   10:56   0:01 ora_cjq0_xxxdb
    oracle     263  0.0  0.0 1783616 25872 ?       Ss   10:56   0:00 ora_q001_xxxdb
    oracle     266  0.0  0.0  64128 12920 ?        S    10:57   0:00 impdp    as sysdba' directory=data dumpfile=xxx_exp.dmp schemas=xxx version=11.1
    oracle     267  0.0  0.3 1796312 115144 ?      Ss   10:57   0:04 oraclexxxdb (DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq)))
    oracle     269  0.0  0.0 1780916 15944 ?       Ss   10:57   0:00 ora_q002_xxxdb
    oracle     271  0.0  0.3 1828020 117032 ?      Ss   10:57   0:04 ora_dm00_xxxdb
    oracle     273 98.1  3.9 1981864 1293136 ?     Rs   10:57 216:44 ora_dw00_xxxdb
    oracle     275  0.0  0.0 1790988 20540 ?       Ss   10:57   0:01 ora_smco_xxxdb
    oracle     277  0.0  0.0 1790920 28676 ?       Ss   10:57   0:01 ora_w000_xxxdb
    

    There is plenty of free diskspace, and the tablespaces can expand as seen from this report

    set linesize 150
    set pagesize 50
    col "Tablespace" for a25
    col "Used MB" for 99,999
    col "Free MB" for 99,999
    col "Total MB" for 99,999
    col "Max MB" for 99,999
    
    select df.tablespace_name "Tablespace"
         , totalusedspace "Used MB"
         , (df.totalspace - tu.totalusedspace) "Free MB"
         , df.totalspace "Total MB"
         , round(100 * ( (df.totalspace - tu.totalusedspace)/ df.totalspace)) "Pct. Free"
         , MaxSpace "Max MB"
      from (
            select tablespace_name
                 , round(sum(bytes) / 1048576) TotalSpace
                 , round(sum(
                      case
                          when maxbytes = 0 then bytes
                          else maxbytes
                      end
                      ) / 1024 / 1024) MaxSpace
              from dba_data_files
             group by tablespace_name
           ) df,
           (
            select round(sum(bytes)/(1024*1024)) totalusedspace
                 , tablespace_name
              from dba_segments
              group by tablespace_name
           ) tu
     where df.tablespace_name = tu.tablespace_nam
    
    Tablespace                Used MB Free MB Total MB  Pct. Free  Max MB
    ------------------------- ------- ------- -------- ---------- -------
    SYSAUX                        455      25      480          5  32,768
    UNDOTBS1                      127       3      130          2  32,768
    XXX_T_256K                     50       2       52          4  32,768
    XXX_T_8M                      858      43      901          5  32,768
    XXX_T_256M                 11,664     642   12,306          5  65,536
    USERS                           0       5        5        100  32,768
    SYSTEM                        684       6      690          1  32,768
    XXX_I_8M                      584      29      613          5  32,768
    XXX_I_256K                      5       1        6         17  32,768
    XXX_I_256M                 34,496   1,772   36,268          5  65,536
    

    There are no blocking locks

    set lines 200
    set pages 50
    col object1 for a30
    col object2 for a30
    select l.*, o1.owner || '.' || o1.object_name object1, o2.owner || '.' || o2.object_name object2
      from v$lock l
         , dba_objects o1
         , dba_objects o2
     where o1.object_id = l.id1
       and o2.object_id(+) = l.id2
    
    ADDR             KADDR                   SID TY        ID1        ID2      LMODE    REQUEST      CTIME      BLOCK OBJECT1                        OBJECT2
    ---------------- ---------------- ---------- -- ---------- ---------- ---------- ---------- ---------- ---------- ------------------------------ ------------------------------
    00000000BFC51AC8 00000000BFC51B20          7 TO      12697          1          3          0      11738          0 SYS.IMPDP_STATS                .
    00000000BFC50F50 00000000BFC50FA8          3 RS         25          1          2          0      12155          0 SYS.PROXY_ROLE_DATA$           .
    00000000BFC519E0 00000000BFC51A38         66 TS          3          1          3          0      12155          0 SYS.I_OBJ#                     .
    00000000BFC51910 00000000BFC51968        127 MR        201          0          4          0      12155          0 SYS.I_SQL$TEXT_HANDLE          .
    00000000BFC510F0 00000000BFC51148          7 AE        100          0          4          0      12087          0 SYS.ORA$BASE                   .
    00000000BFC51360 00000000BFC513B8        192 AE        100          0          4          0      12092          0 SYS.ORA$BASE                   .
    00000000BFC51430 00000000BFC51488        190 AE        100          0          4          0      12154          0 SYS.ORA$BASE                   .
    00000000BFC51B98 00000000BFC51BF0        196 AE        100          0          4          0      12090          0 SYS.ORA$BASE                   .
    00000000BFC51C68 00000000BFC51CC0        195 AE        100          0          4          0        180          0 SYS.ORA$BASE                   .
    00000000BFC527E0 00000000BFC52838        127 MR         11          0          4          0      12093          0 SYS.I_USER#                    .
    00000000BFC50DB0 00000000BFC50E08          3 XR          4          0          1          0      12159          0 SYS.TAB$                       .
    00000000BFC51840 00000000BFC51898        127 MR          4          0          4          0      12155          0 SYS.TAB$                       .
    00000000BFC516A0 00000000BFC516F8        127 MR          2          0          4          0      12155          0 SYS.C_OBJ#                     .
    00000000BFC528B0 00000000BFC52908        127 MR         12          0          4          0      12093          0 SYS.FET$                       .
    00000000BFC52628 00000000BFC52680        127 MR         10          0          4          0      12093          0 SYS.C_USER#                    .
    00000000BFC52558 00000000BFC525B0        127 MR          8          0          4          0      12093          0 SYS.C_FILE#_BLOCK#             .
    00000000BFC52218 00000000BFC52270        127 MR          5          0          4          0      12093          0 SYS.CLU$                       .
    00000000BFC522E8 00000000BFC52340        127 MR          6          0          4          0      12093          0 SYS.C_TS#                      .
    00000000BFC52488 00000000BFC524E0        127 MR          7          0          4          0      12093          0 SYS.I_TS#                      .
    00000000BFC523B8 00000000BFC52410        127 MR          9          0          4          0      12093          0 SYS.I_FILE#_BLOCK#             .
    00000000BFC51770 00000000BFC517C8        127 MR          3          0          4          0      12155          0 SYS.I_OBJ#                     .
    

    Update:

    Unfortunately I still can’t see what’s wrong.

    The select from gv$session gave no rows.

    Here is an excerpt of the output from gv$sql. It’s sorted on last_load_time, so it should show a timeline of what has been going on. The ALTER PACKAGE is still marked active, but has only used 182 microseconds in three days, and as far as I can see there are no recursive SQL statements, the ALTER could be waiting on.

    SQL> select elapsed_time/1000000 seconds, s.inst_id, s.sql_text, s.users_executing, s.cpu_time,
           s.first_load_time, s.last_load_time
      2    3  from gv$sql s
      4  where users_executing > 0
      5  union
     select elapsed_time/1000000 seconds, s.inst_id, s.sql_text, s.users_executing, s.cpu_time,
           s.first_load_time, s.last_load_time
      6    7    8  from gv$sql s
      9   where rownum < 50
     10  order by last_load_time
     11  /
    
       SECONDS    INST_ID SQL_TEXT                                           USERS_EXECUTING   CPU_TIME FIRST_LOAD_TIME     LAST_LOAD_TIME
    ---------- ---------- -------------------------------------------------- --------------- ---------- ------------------- -------------------
       .000293          1 LOCK TABLE  FOR INDEX "XXX"."PK_YYYYYYYYYYYYYYYYYY               0        572 2016-04-08/11:02:09 2016-04-08/11:02:09
                          " IN EXCLUSIVE MODE  NOWAIT
    
       .000358          1 LOCK TABLE  FOR INDEX "XXX"."IX_XXX_YYYYYYYYYYYYYY               0       2132 2016-04-08/11:02:38 2016-04-08/11:02:38
                          YYYYY" IN EXCLUSIVE MODE  NOWAIT
    
       .000349          1 LOCK TABLE  FOR INDEX "XXX"."IX_XXX_DATA_02" IN EX               0        574 2016-04-08/11:03:06 2016-04-08/11:03:06
                          CLUSIVE MODE  NOWAIT
    
       .000402          1 INSERT INTO "SYS". "IMPDP_STATS" (TYPE,VERSION,FLA               0        289 2016-04-08/11:03:17 2016-04-08/11:03:17
                          GS,C1,C2,C3,C5,N1,N2,N3,N4,N5,N6,N7,N8,N9,N10,N11,
                          N12,D1,CL1) VALUES ('I',5,2,:B3 ,NULL,NULL,:B2 ,15
                          219,31,15219,1,1,2108,1,15219,NULL,NULL,NULL,NULL,
                          TO_DATE('2014-11-15 19:10:36',:B1 ),NULL)
    
       .000405          1 INSERT INTO "SYS". "IMPDP_STATS" (TYPE,VERSION,FLA               0          0 2016-04-08/11:03:17 2016-04-08/11:03:17
                          GS,C1,C2,C3,C5,N1,N2,N3,N4,N5,N6,N7,N8,N9,N10,N11,
                          N12,D1,CL1) VALUES ('I',5,2,:B3 ,NULL,NULL,:B2 ,10
                          6867,670,713,1,6,4759,2,106867,NULL,NULL,NULL,NULL
                          ,TO_DATE('2016-03-19 19:19:38',:B1 ),NULL)
    
       .000419          1 INSERT INTO "SYS". "IMPDP_STATS" (TYPE,VERSION,FLA               0        743 2016-04-08/11:03:17 2016-04-08/11:03:17
                          GS,C1,C2,C3,C5,N1,N2,N3,N4,N5,N6,N7,N8,N9,N10,N11,
                          N12,D1,CL1) VALUES ('I',5,2,:B3 ,NULL,NULL,:B2 ,13
                          7849,1763,11,160,686,7556,2,137849,NULL,NULL,NULL,
                          NULL,TO_DATE('2016-02-20 19:20:18',:B1 ),NULL)
    
       .000425          1 INSERT INTO "SYS". "IMPDP_STATS" (TYPE,VERSION,FLA               0          0 2016-04-08/11:03:17 2016-04-08/11:03:17
                          GS,C1,C2,C3,C5,N1,N2,N3,N4,N5,N6,N7,N8,N9,N10,N11,
                          N12,D1,CL1) VALUES ('I',5,2,:B3 ,NULL,NULL,:B2 ,70
                          9979,2005,3,668,18908,56726,2,709979,NULL,NULL,NUL
                          L,NULL,TO_DATE('2016-03-26 19:19:30',:B1 ),NULL)
    
       .000451          1 INSERT INTO "SYS". "IMPDP_STATS" (TYPE,VERSION,FLA               0        280 2016-04-08/11:03:17 2016-04-08/11:03:17
                          GS,C1,C2,C3,C5,N1,N2,N3,N4,N5,N6,N7,N8,N9,N10,N11,
                          N12,D1,CL1) VALUES ('I',5,2,:B3 ,NULL,NULL,:B2 ,0,
                          0,0,0,0,0,0,0,NULL,NULL,NULL,NULL,TO_DATE('2016-02
                          -20 19:20:18',:B1 ),NULL)
    
       .001567          1 delete from  viewtrcol$ where obj#=:1                            0       1405 2016-04-08/10:57:24 2016-04-08/11:03:18
       .000182          1  ALTER PACKAGE "XXX"."XXX_AQ_PUT"   COMPILE BODY                 1        372 2016-04-08/11:03:25 2016-04-08/11:03:25
                             PLSQL_OPTIMIZE_LEVEL=  2    PLSQL_CODE_TYPE=  I
                          NTERPRETED    PLSQL_DEBUG=  FALSE    PLSCOPE_SETTI
                          NGS=  'IDENTIFIERS:NONE' REUSE SETTINGS TIMESTAMP
                          '2015-06-02 13:31:03'
    
       .003691          1 insert into wrh$_filemetric_history     (snap_id,                0       2914 2016-04-08/11:06:36 2016-04-08/11:06:36
                          dbid, instance_number,      fileid, creationtime,
                               begin_time, end_time, intsize, group_id,
                           avgreadtime, avgwritetime, physicalread,      phy
                          sicalwrite, phyblkread, phyblkwrite)  select
                          :snap_id, :dbid, :instance_number,      fileid, cr
                          eationtime,      begtime, endtime, intsize_csec, g
                          roupid,      avrdtime, avwrtime, phyread,      phy
                          write, phybkrd, phybkwr  from x$kewmflmv
    
       .004734          1 INSERT INTO WRH$_METRIC_NAME(dbid, GROUP_ID, METRI               0       2384 2016-04-08/11:06:36 2016-04-08/11:06:36
                          C_ID, GROUP_NAME, METRIC_NAME, METRIC_UNIT) SELECT
                           DISTINCT :dbid, GROUP_ID, METRIC_ID, GROUP_NAME,
                          METRIC_NAME, METRIC_UNIT FROM V$METRICNAME
    
       .009059          1 SELECT COUNT(*) FROM (SELECT TOP_LEVEL_CALL#, TOP_               0       4325 2016-04-08/11:06:36 2016-04-08/11:06:36
                          LEVEL_CALL_NAME FROM V$TOPLEVELCALL MINUS SELECT T
                          OP_LEVEL_CALL#, TOP_LEVEL_CALL_NAME FROM WRH$_TOPL
                          EVELCALL_NAME WHERE dbid = :dbid)
    
       .003014          1 delete from WRH$_ENQUEUE_STAT tab where (:beg_snap               0       2124 2016-04-08/11:26:19 2016-04-08/11:26:19
                           <= tab.snap_id and         tab.snap_id <= :end_sn
                          ap and         dbid = :dbid)    and not exists (se
                          lect 1 from WRM$_BASELINE b                    whe
                          re (tab.dbid = b.dbid) and
                            (tab.snap_id >= b.start_snap_id) and
                                        (tab.snap_id <= b.end_snap_id))
    

    Not much to see en dba_resumables too

      1* select * from dba_resumable
    
       USER_ID SESSION_ID INSTANCE_ID COORD_INSTANCE_ID COORD_SESSION_ID STATUS       TIMEOUT START_TIME           SUSPEND_TIME         RESUME_TIME          NAME                           SQL_TEXT                                           ERROR_NUMBER ERROR_PARAMETER1     ERROR_PARAMETER2     ERROR_PARAMETER3     ERROR_PARAMETER4     ERROR_PARAMETER5     ERROR_MSG
    ---------- ---------- ----------- ----------------- ---------------- --------- ---------- -------------------- -------------------- -------------------- ------------------------------ -------------------------------------------------- ------------ -------------------- -------------------- -------------------- -------------------- -------------------- --------------------------------------------------
             0        196           1                                    NORMAL          7200                                                                SYS.SYS_IMPORT_SCHEMA_01       BEGIN :1 := sys.kupc$que_int.receive(:2); END;                0
             0          7           1                                    NORMAL          7200                                                                SYS.SYS_IMPORT_SCHEMA_01.1      ALTER PACKAGE "XXX"."XXX_AQ_PUT"   COMPILE BODY              0
                                                                                                                                                                                               PLSQL_OPTIMIZE_LEVEL=  2    PLSQL_CODE_TYPE=  I
                                                                                                                                                                                            NTERPRETED    PLSQL_DEBUG=  FALSE    PLSCOPE_SETTI
                                                                                                                                                                                            NGS=  'IDENTIFIERS:NONE' REUSE SETTINGS TIMESTAMP
                                                                                                                                                                                            '2015-06-02 13:31:03'
    

    I feel stuck 🙁

  • Launch a Docker container with a Windows Scheduled Task
  • Dockerfile vs Dockerrun.aws.json on AWS Elastic Beanstalk
  • Docker volume access from host
  • Dockerfile - Defining an ENV variable with a dynamic value
  • Docker container delete from Jenkins hangs
  • Moving from Vagrant to Vagrant with Docker
  • One Solution collect form web for “Oracle impdp running way too long”

    The simplest way to find blocking locks is to look at the sessions. It’s usually best to look for who is blocking, not what is blocking.

    select *
    from gv$session
    where blocking_session is not null
    

    The ALTER may be waiting on a recursive SQL statement. Those statement do not always count as “blocking”. Run this statement to see what other SQL is running. If you’re lucky there will be a statement that has been running almost as long as the ALTER; that will be the next query to investigate:

    select elapsed_time/1000000 seconds, gv$sql.*
    from gv$sql
    where users_executing > 0
    order by users_executing desc;
    

    For investigating space issues it is usually better to look at DBA_RESUMABLE instead of specific space sizes. There are a lot of ways for Oracle to run out of space. The tablespace may look fine, but ASM or the OS may be out of space.

    select * from dba_resumable;
    

    Based on the updates it looks like the imported data contains Advanced Queues objects. Advanced Queue’s have additional import and export restrictions. Everything is “special” with AQ’s. Hopefully your organization has someone who specializes in AQs. It wouldn’t surprise me if you’ll need a create a Support Request for this issue.

    Docker will be the best open platform for developers and sysadmins to build, ship, and run distributed applications.