Home » RDBMS Server » Server Utilities » Slow exports using exp command due to open sessions (Oracle 11.1.0.7, SUSE 11 SP1 Linux x86 64bit)
| Slow exports using exp command due to open sessions [message #530857] |
Fri, 11 November 2011 02:51  |
 |
francl
Messages: 8
Registered: November 2011
Location: Slovenia
|
Junior Member |
|
|
I have had the following problem open with Oracle support since March 2011 (8 months), and still no resolution. So I thought I would post here if anyone has any ideas.
When I export all our schema's on Sunday night it takes about 1 hour 50 minutes. When I export the same schema's on any other night it takes 7 hours. The only difference is that on Sunday at 4:00am we drop all connections in the connection pools and reestablish new connections. Then 19hours later on Sunday at 23:00 we perform the exports which only take 2 hours to complete.
I have also tried recreating the connections in the connection pools during the week, and the exports have then only taken 2 hours to complete. But the following night after the connections have been used during the day, the exports again take 7 hours. So it appears the export speed gets significantly slower when there are many open connections that have been used and not closed.
From the stats pack report I found 2 SQL statements internal to the export command, that had an order of magnitude in difference when looking at the elapsed execution time between the fast export, and the slow export (see below).
If anyone has similar problems or has any ideas on how to speed up the exports without having to drop and recreate the database connections in the connection pools each night please let me know.
FAST:
elapsed_time: 430.90
executions: 161,388
Module: exp@Oracle1 (TNS V1-V3)
SELECT COLNAME, COLNO, PROPERTY, NOLOG FROM SYS.EXU10CCL
WHERE CNO = :1 ORDER BY COLNO
elapsed_time: 264.29
executions: 50,349
Module: exp@Oracle1 (TNS V1-V3)
SELECT TOWNER, TNAME, NAME, LENGTH, PRECISION, SCALE, TYPE, ISNULL, CONNAME, COLID, INTCOLID, SEGCOLID, COMMENT$, DEFAULT$, DFLTLEN, ENABLED, DEFER, FLAGS, COLPROP, ADTNAME, ADTOWNER, CHARSETID, CHARSETFORM, FSPRECISION, LFPRECISION, CHARLEN, TFLAGS, 100 FROM SYS.EXU8COL
WHERE TOBJID = :1 ORDER BY INTCOLID
SLOW:
elapse_time: 8264.16
executions: 124,662
Module: exp@Oracle1 (TNS V1-V3)
SELECT COLNAME, COLNO, PROPERTY, NOLOG FROM SYS.EXU10CCL
WHERE CNO = :1 ORDER BY COLNO
elapsed_time: 3877.78
executions: 38,813
Module: exp@Oracle1 (TNS V1-V3)
SELECT TOWNER, TNAME, NAME, LENGTH, PRECISION, SCALE, TYPE, ISNULL, CONNAME, COLID, INTCOLID, SEGCOLID, COMMENT$, DEFAULT$, DFLTLEN, ENABLED, DEFER, FLAGS, COLPROP, ADTNAME, ADTOWNER, CHARSETID, CHARSETFORM, FSPRECISION, LFPRECISION, CHARLEN, TFLAGS, 100 FROM SYS.EXU8COL
WHERE TOBJID = :1 ORDER BY INTCOLID
I use the following export command for each schema:
$ORACLE_HOME/bin/exp user/pass file=somefile.dmp owner=$SCHEMA log=somelog.log buffer=9000000
I have an Oracle Standard edition 11.1.0.7 database on 64bit Linux with a 7GB SGA. I currently export (I use exp not datapump because datapump is a lot slower and we can't use parallel processing features of datapump on a standard edition database) approx 200 schema's each night. The export normally takes 1 hour 50 minutes which is approximately 2 schema's exported every minute. When the exports run slowly each export takes almost 2 minutes to complete.
The database has about 20 GB data and 50 GB indexes. The database has also approx 500 connections via toplink connection pools from 8 application servers.
|
|
|
|
|
|
| Re: Slow exports using exp command due to open sessions [message #531167 is a reply to message #530953] |
Mon, 14 November 2011 04:20  |
|
francl
Messages: 8
Registered: November 2011
Location: Slovenia
|
Junior Member |
|
|
Here is I believe the important section of my SQL TRACE output for the slow and fast export scenarios. The biggest differences can be seen at lines 2 and 3 in my summary and 3 and 4. Also the timestamp on the FETCH output for the fast case appears strange. It appears that SQL TRACE did not update the time stamp even though it did for the WAIT statements.
I can see that there is a discrepancy in the times but I still don't know how to find out what is causing the discrepancy? Can anyone suggest where to go from here ?
Can anyone explain the SQL TRACE output and what it means, I am not sure I have interpreted it correctly.
SUMMARY: See below for SQL TRACE output
TIME STAMP SLOW CASE diff TIME STAMP FAST CASE diff
1 PARSE tim=1321259092073989 tim=1321258936566653
2 EXEC tim=1321259092073989 0 tim=1321258936566653 0
3 WAIT tim=1321259092082601 8612 tim=1321258936571117 4464
4 FETCH tim=1321259092134018 51417 tim=1321258936566653 -4464 ????
5 WAIT tim=1321259092139384 5366 tim=1321258936575019 3902
...
6 WAIT tim=1321259092140374 990 tim=1321258936576304 1285
7 WAIT tim=1321259092140766 392 tim=1321258936576720 416
SLOW CASE:
PARSING IN CURSOR #2 len=87 dep=0 uid=0 oct=3 lid=0 tim=1321259092073989 hv=2746115949 ad='1ec921d30' sqlid='5t956r6juwtvd'
SELECT COLNAME, COLNO, PROPERTY, NOLOG FROM SYS.EXU10CCL WHERE CNO = 302 ORDER BY COLNO
END OF STMT
PARSE #2:c=48003,e=60037,p=2,cr=64,cu=0,mis=1,r=0,dep=0,og=1,plh=2201906051,tim=1321259092073989
EXEC #2:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=2201906051,tim=1321259092073989
WAIT #2: nam='SQL*Net message to client' ela= 4 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1321259092082601
FETCH #2:c=8000,e=60029,p=0,cr=41,cu=0,mis=0,r=1,dep=0,og=1,plh=2201906051,tim=1321259092134018
WAIT #2: nam='SQL*Net message from client' ela= 467 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1321259092139384
FETCH #2:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=2201906051,tim=1321259092134018
STAT #2 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT ORDER BY (cr=41 pr=0 pw=0 time=0 us cost=43 size=6093 card=3)'
...
WAIT #2: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1321259092140374
WAIT #2: nam='SQL*Net message from client' ela= 375 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1321259092140766
FAST CASE:
PARSING IN CURSOR #2 len=87 dep=0 uid=0 oct=3 lid=0 tim=1321258936566653 hv=2746115949 ad='8abcdb80' sqlid='5t956r6juwtvd'
SELECT COLNAME, COLNO, PROPERTY, NOLOG FROM SYS.EXU10CCL WHERE CNO = 302 ORDER BY COLNO
END OF STMT
PARSE #2:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=2201906051,tim=1321258936566653
EXEC #2:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=2201906051,tim=1321258936566653
WAIT #2: nam='SQL*Net message to client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1321258936571117
FETCH #2:c=0,e=0,p=0,cr=41,cu=0,mis=0,r=1,dep=0,og=1,plh=2201906051,tim=1321258936566653
WAIT #2: nam='SQL*Net message from client' ela= 668 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1321258936575019
FETCH #2:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=2201906051,tim=1321258936566653
STAT #2 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT ORDER BY (cr=41 pr=0 pw=0 time=0 us cost=43
...
WAIT #2: nam='SQL*Net message to client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1321258936576304
WAIT #2: nam='SQL*Net message from client' ela= 397 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1321258936576720
[Updated on: Mon, 14 November 2011 04:24] Report message to a moderator |
|
|
|
Goto Forum:
Current Time: Thu Apr 18 00:24:24 CDT 2024
|
] 
Blog
Search
Help
Members
Register
Login
Home
