Datapump amazing parameters METRIC and LOGTIME

Here is a datapump export from a local test database.

C:\Users\Administrator>expdp demo/demo schemas=HR

 

Export: Release 12.1.0.2.0 - Production on Thu Jan 11 03:44:46 2018

 

Copyright (c) 1982, 2014, Oracle and/or its affiliates.  All rights reserved.

 

Connected to: Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production

With the Partitioning, OLAP, Advanced Analytics and Real Application Testing options

Starting "DEMO"."SYS_EXPORT_SCHEMA_01":  demo/******** schemas=HR

Estimate in progress using BLOCKS method...

Processing object type SCHEMA_EXPORT/TABLE/TABLE_DATA

Total estimation using BLOCKS method: 448 KB

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/SEQUENCE/SEQUENCE

Processing object type SCHEMA_EXPORT/TABLE/TABLE

Processing object type SCHEMA_EXPORT/TABLE/GRANT/OWNER_GRANT/OBJECT_GRANT

Processing object type SCHEMA_EXPORT/TABLE/COMMENT

Processing object type SCHEMA_EXPORT/PROCEDURE/PROCEDURE

Processing object type SCHEMA_EXPORT/PROCEDURE/ALTER_PROCEDURE

Processing object type SCHEMA_EXPORT/VIEW/VIEW

Processing object type SCHEMA_EXPORT/TABLE/INDEX/INDEX

Processing object type SCHEMA_EXPORT/TABLE/CONSTRAINT/CONSTRAINT

Processing object type SCHEMA_EXPORT/TABLE/INDEX/STATISTICS/INDEX_STATISTICS

Processing object type SCHEMA_EXPORT/TABLE/CONSTRAINT/REF_CONSTRAINT

Processing object type SCHEMA_EXPORT/TABLE/TRIGGER

Processing object type SCHEMA_EXPORT/TABLE/STATISTICS/TABLE_STATISTICS

Processing object type SCHEMA_EXPORT/STATISTICS/MARKER

. . exported "HR"."COUNTRIES"                            6.460 KB      25 rows

. . exported "HR"."DEPARTMENTS"                          7.125 KB      27 rows

. . exported "HR"."EMPLOYEES"                            17.09 KB     107 rows

. . exported "HR"."JOBS"                                 7.109 KB      19 rows

. . exported "HR"."JOB_HISTORY"                          7.195 KB      10 rows

. . exported "HR"."LOCATIONS"                            8.437 KB      23 rows

. . exported "HR"."REGIONS"                              5.546 KB       4 rows

Master table "DEMO"."SYS_EXPORT_SCHEMA_01" successfully loaded/unloaded

******************************************************************************

Dump file set for DEMO.SYS_EXPORT_SCHEMA_01 is:

  C:\APP\ADMINISTRATOR\ADMIN\ORA12C\DPDUMP\EXPDAT.DMP

Job "DEMO"."SYS_EXPORT_SCHEMA_01" successfully completed at Thu Jan 11 03:46:00 2018 elapsed 0 00:01:10

 

If I told that this particular export took around a couple of hours to complete, how would you know which parts took a long time and which completed faster?

 

The default log file gives you an accounting of what was done in which order, but very little in the way of performance data.

 

Now let’s say when we specify METRICS=YES – it has the very useful effect of adding information to the logfile – that tell us how long it took to export a particular type of database object.

 

C:\Users\Administrator>expdp demo/demo schemas=HR metrics=YES

 

Export: Release 12.1.0.2.0 - Production on Thu Jan 11 03:49:47 2018

 

Copyright (c) 1982, 2014, Oracle and/or its affiliates.  All rights reserved.

 

Connected to: Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production

With the Partitioning, OLAP, Advanced Analytics and Real Application Testing options

Starting "DEMO"."SYS_EXPORT_SCHEMA_01":  demo/******** schemas=HR metrics=YES

Startup took 1 seconds

Estimate in progress using BLOCKS method...

Processing object type SCHEMA_EXPORT/TABLE/TABLE_DATA

     Estimated 7 TABLE_DATA objects in 2 seconds

Total estimation using BLOCKS method: 448 KB

Processing object type SCHEMA_EXPORT/USER

     Completed 1 USER objects in 0 seconds

Processing object type SCHEMA_EXPORT/SYSTEM_GRANT

     Completed 7 SYSTEM_GRANT objects in 0 seconds

Processing object type SCHEMA_EXPORT/ROLE_GRANT

     Completed 1 ROLE_GRANT objects in 0 seconds

Processing object type SCHEMA_EXPORT/DEFAULT_ROLE

     Completed 1 DEFAULT_ROLE objects in 0 seconds

Processing object type SCHEMA_EXPORT/PRE_SCHEMA/PROCACT_SCHEMA

     Completed 1 PROCACT_SCHEMA objects in 0 seconds

Processing object type SCHEMA_EXPORT/SEQUENCE/SEQUENCE

     Completed 3 SEQUENCE objects in 8 seconds

Processing object type SCHEMA_EXPORT/TABLE/TABLE

     Completed 7 TABLE objects in 21 seconds

Processing object type SCHEMA_EXPORT/TABLE/GRANT/OWNER_GRANT/OBJECT_GRANT

     Completed 9 OBJECT_GRANT objects in 1 seconds

Processing object type SCHEMA_EXPORT/TABLE/COMMENT

     Completed 39 COMMENT objects in 0 seconds

Processing object type SCHEMA_EXPORT/PROCEDURE/PROCEDURE

     Completed 2 PROCEDURE objects in 0 seconds

Processing object type SCHEMA_EXPORT/PROCEDURE/ALTER_PROCEDURE

     Completed 2 ALTER_PROCEDURE objects in 0 seconds

Processing object type SCHEMA_EXPORT/VIEW/VIEW

     Completed 1 VIEW objects in 1 seconds

Processing object type SCHEMA_EXPORT/TABLE/INDEX/INDEX

     Completed 18 INDEX objects in 2 seconds

Processing object type SCHEMA_EXPORT/TABLE/CONSTRAINT/CONSTRAINT

     Completed 9 CONSTRAINT objects in 1 seconds

Processing object type SCHEMA_EXPORT/TABLE/INDEX/STATISTICS/INDEX_STATISTICS

     Completed 19 INDEX_STATISTICS objects in 0 seconds

Processing object type SCHEMA_EXPORT/TABLE/CONSTRAINT/REF_CONSTRAINT

     Completed 10 REF_CONSTRAINT objects in 0 seconds

Processing object type SCHEMA_EXPORT/TABLE/TRIGGER

     Completed 2 TRIGGER objects in 1 seconds

Processing object type SCHEMA_EXPORT/TABLE/STATISTICS/TABLE_STATISTICS

     Completed 7 TABLE_STATISTICS objects in 1 seconds

Processing object type SCHEMA_EXPORT/STATISTICS/MARKER

     Completed 1 MARKER objects in 0 seconds

. . exported "HR"."COUNTRIES"              6.460 KB      25 rows in 0 seconds

. . exported "HR"."DEPARTMENTS"            7.125 KB      27 rows in 0 seconds

. . exported "HR"."EMPLOYEES"              17.09 KB     107 rows in 0 seconds

. . exported "HR"."JOBS"                   7.109 KB      19 rows in 0 seconds

. . exported "HR"."JOB_HISTORY"            7.195 KB      10 rows in 0 seconds

. . exported "HR"."LOCATIONS"              8.437 KB      23 rows in 0 seconds

. . exported "HR"."REGIONS"                5.546 KB       4 rows in 1 seconds

     Completed 7 SCHEMA_EXPORT/TABLE/TABLE_DATA objects in 1 seconds

Master table "DEMO"."SYS_EXPORT_SCHEMA_01" successfully loaded/unloaded

******************************************************************************

Dump file set for DEMO.SYS_EXPORT_SCHEMA_01 is:

  C:\APP\ADMINISTRATOR\ADMIN\ORA12C\DPDUMP\EXPDAT.DMP

Job "DEMO"."SYS_EXPORT_SCHEMA_01" successfully completed at Thu Jan 11 03:50:28 2018 elapsed 0 00:00:41

 

 

Here we get a good sense of what took time or not in processing, starting with 12c we could get even more granular measurement by specifying the LOGTIME parameter, this parameter add a timestamp down to the millisecond for every line in the logfile.

 

 

C:\Users\Administrator>expdp demo/demo schemas=HR metrics=YES LOGTIME=ALL

 

Export: Release 12.1.0.2.0 - Production on Thu Jan 11 03:51:12 2018

 

Copyright (c) 1982, 2014, Oracle and/or its affiliates.  All rights reserved.

 

Connected to: Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production

With the Partitioning, OLAP, Advanced Analytics and Real Application Testing options

11-JAN-18 03:51:14.185: Starting "DEMO"."SYS_EXPORT_SCHEMA_01":  demo/******** schemas=HR metrics=YES LOGTIME=ALL

11-JAN-18 03:51:14.342: Startup took 1 seconds

11-JAN-18 03:51:14.420: Estimate in progress using BLOCKS method...

11-JAN-18 03:51:14.935: Processing object type SCHEMA_EXPORT/TABLE/TABLE_DATA

11-JAN-18 03:51:14.951:      Estimated 7 TABLE_DATA objects in 0 seconds

11-JAN-18 03:51:14.982: Total estimation using BLOCKS method: 448 KB

11-JAN-18 03:51:15.310: Processing object type SCHEMA_EXPORT/USER

11-JAN-18 03:51:15.357:      Completed 1 USER objects in 0 seconds

11-JAN-18 03:51:15.357: Processing object type SCHEMA_EXPORT/SYSTEM_GRANT

11-JAN-18 03:51:15.388:      Completed 7 SYSTEM_GRANT objects in 0 seconds

11-JAN-18 03:51:15.388: Processing object type SCHEMA_EXPORT/ROLE_GRANT

11-JAN-18 03:51:15.592:      Completed 1 ROLE_GRANT objects in 0 seconds

11-JAN-18 03:51:15.592: Processing object type SCHEMA_EXPORT/DEFAULT_ROLE

11-JAN-18 03:51:15.654:      Completed 1 DEFAULT_ROLE objects in 0 seconds

11-JAN-18 03:51:15.670: Processing object type SCHEMA_EXPORT/PRE_SCHEMA/PROCACT_SCHEMA

11-JAN-18 03:51:23.357:      Completed 1 PROCACT_SCHEMA objects in 0 seconds

11-JAN-18 03:51:23.373: Processing object type SCHEMA_EXPORT/SEQUENCE/SEQUENCE

11-JAN-18 03:51:23.810:      Completed 3 SEQUENCE objects in 8 seconds

11-JAN-18 03:51:23.826: Processing object type SCHEMA_EXPORT/TABLE/TABLE

11-JAN-18 03:51:28.373:      Completed 7 TABLE objects in 4 seconds

11-JAN-18 03:51:28.451: Processing object type SCHEMA_EXPORT/TABLE/GRANT/OWNER_GRANT/OBJECT_GRANT

11-JAN-18 03:51:28.482:      Completed 9 OBJECT_GRANT objects in 1 seconds

11-JAN-18 03:51:28.482: Processing object type SCHEMA_EXPORT/TABLE/COMMENT

11-JAN-18 03:51:28.810:      Completed 39 COMMENT objects in 0 seconds

11-JAN-18 03:51:28.826: Processing object type SCHEMA_EXPORT/PROCEDURE/PROCEDURE

11-JAN-18 03:51:28.904:      Completed 2 PROCEDURE objects in 0 seconds

11-JAN-18 03:51:28.920: Processing object type SCHEMA_EXPORT/PROCEDURE/ALTER_PROCEDURE

11-JAN-18 03:51:29.013:      Completed 2 ALTER_PROCEDURE objects in 0 seconds

11-JAN-18 03:51:29.013: Processing object type SCHEMA_EXPORT/VIEW/VIEW

11-JAN-18 03:51:30.326:      Completed 1 VIEW objects in 1 seconds

11-JAN-18 03:51:30.326: Processing object type SCHEMA_EXPORT/TABLE/INDEX/INDEX

11-JAN-18 03:51:31.388:      Completed 18 INDEX objects in 1 seconds

11-JAN-18 03:51:31.388: Processing object type SCHEMA_EXPORT/TABLE/CONSTRAINT/CONSTRAINT

11-JAN-18 03:51:31.467:      Completed 9 CONSTRAINT objects in 1 seconds

11-JAN-18 03:51:31.482: Processing object type SCHEMA_EXPORT/TABLE/INDEX/STATISTICS/INDEX_STATISTICS

11-JAN-18 03:51:31.685:      Completed 19 INDEX_STATISTICS objects in 0 seconds

11-JAN-18 03:51:31.701: Processing object type SCHEMA_EXPORT/TABLE/CONSTRAINT/REF_CONSTRAINT

11-JAN-18 03:51:31.748:      Completed 10 REF_CONSTRAINT objects in 0 seconds

11-JAN-18 03:51:31.763: Processing object type SCHEMA_EXPORT/TABLE/TRIGGER

11-JAN-18 03:51:31.920:      Completed 2 TRIGGER objects in 0 seconds

11-JAN-18 03:51:31.935: Processing object type SCHEMA_EXPORT/TABLE/STATISTICS/TABLE_STATISTICS

11-JAN-18 03:51:31.951:      Completed 7 TABLE_STATISTICS objects in 0 seconds

11-JAN-18 03:51:31.951: Processing object type SCHEMA_EXPORT/STATISTICS/MARKER

11-JAN-18 03:51:32.826:      Completed 1 MARKER objects in 1 seconds

11-JAN-18 03:51:32.935: . . exported "HR"."COUNTRIES"     6.460 KB      25 rows in 0 seconds

11-JAN-18 03:51:32.982: . . exported "HR"."DEPARTMENTS"   7.125 KB      27 rows in 0 seconds

11-JAN-18 03:51:33.013: . . exported "HR"."EMPLOYEES"     17.09 KB     107 rows in 1 seconds

11-JAN-18 03:51:33.076: . . exported "HR"."JOBS"          7.109 KB      19 rows in 0 seconds

11-JAN-18 03:51:33.123: . . exported "HR"."JOB_HISTORY"   7.195 KB      10 rows in 0 seconds

11-JAN-18 03:51:33.154: . . exported "HR"."LOCATIONS"     8.437 KB      23 rows in 0 seconds

11-JAN-18 03:51:33.185: . . exported "HR"."REGIONS"       5.546 KB       4 rows in 0 seconds

11-JAN-18 03:51:33.638:      Completed 7 SCHEMA_EXPORT/TABLE/TABLE_DATA objects in 1 seconds

11-JAN-18 03:51:33.732: Master table "DEMO"."SYS_EXPORT_SCHEMA_01" successfully loaded/unloaded

11-JAN-18 03:51:33.748: ******************************************************************************

11-JAN-18 03:51:33.748: Dump file set for DEMO.SYS_EXPORT_SCHEMA_01 is:

11-JAN-18 03:51:33.748:   C:\APP\ADMINISTRATOR\ADMIN\ORA12C\DPDUMP\EXPDAT.DMP

11-JAN-18 03:51:33.779: Job "DEMO"."SYS_EXPORT_SCHEMA_01" successfully completed at Thu Jan 11 03:51:33 2018 elapsed 0 00:00:20

 

 

C:\Users\Administrator>