Reputation: 1456
Oracle 11gR2: slow insert performance, then fast insert performance
Trying to figure out root cause of slow Oracle insert performance. I am running the exact same SQL twice - both times selecting 1000 rows from an Oracle table and inserting back into same table. First INSERT runs in 76 seconds. Second INSERT (same command) runs in < 1 second. Would love to hear any ideas of what may be going on with the former.
INSERT INTO MY_TABLE SELECT * FROM MY_TABLE WHERE ROWNUM <= 1000;
This is not a parse issue, INSERT of 1 row (ROWNUM <=1) was run immediately before first-1000-row-insert and it ran very fast.
Let me know if there's any trace data that would help.
(EDIT: Gah! - explored meta.stackoverflow, found advice for formatting this data from Excel into ASCII-Art, put results in between code tags as recommended... and still got this mangled mess with all newlines removed.... META-HELP please someone let me know how to format this into a readable table that does not remove newlines!)
╔════════════════════════════════════════════════╦══════════════╦═══════════════╗
║ StatName ║ First Insert ║ Second Insert ║
╠════════════════════════════════════════════════╬══════════════╬═══════════════╣
║ active txn count during cleanout ║ 17 ║ 18 ║
║ buffer is not pinned count ║ 8 ║ 0 ║
║ buffer is pinned count ║ 0 ║ 0 ║
║ bytes received via SQL*Net from client ║ 145 ║ 145 ║
║ bytes sent via SQL*Net to client ║ 79 ║ 79 ║
║ calls to get snapshot scn: kcmgss ║ 4 ║ 1 ║
║ calls to kcmgas ║ 4 ║ 16 ║
║ calls to kcmgcs ║ 49 ║ 50 ║
║ cell physical IO interconnect bytes ║ 16080896 ║ 147456 ║
║ change write time ║ 0 ║ 1 ║
║ cleanout - number of ktugct calls ║ 17 ║ 18 ║
║ consistent gets ║ 71 ║ 68 ║
║ consistent gets - examination ║ 17 ║ 18 ║
║ consistent gets from cache ║ 71 ║ 68 ║
║ consistent gets from cache (fastpath) ║ 50 ║ 50 ║
║ CPU used by this session ║ 17 ║ 3 ║
║ CPU used when call started ║ 0 ║ 0 ║
║ cursor authentications ║ 0 ║ 1 ║
║ db block changes ║ 2131 ║ 2124 ║
║ db block gets ║ 5166 ║ 5160 ║
║ db block gets from cache ║ 5166 ║ 5160 ║
║ db block gets from cache (fastpath) ║ 1035 ║ 1037 ║
║ DB time ║ 7787 ║ 104 ║
║ deferred (CURRENT) block cleanout applications ║ 2 ║ 0 ║
║ enqueue releases ║ 22 ║ 0 ║
║ enqueue requests ║ 25 ║ 0 ║
║ execute count ║ 3 ║ 1 ║
║ file io wait time ║ 76571222 ║ 1010237 ║
║ free buffer inspected ║ 3026 ║ 64 ║
║ free buffer requested ║ 1979 ║ 34 ║
║ Heap Segment Array Inserts ║ 35 ║ 35 ║
║ hot buffers moved to head of LRU ║ 631 ║ 2 ║
║ HSC Heap Segment Block Changes ║ 35 ║ 35 ║
║ IMU Flushes ║ 1 ║ 0 ║
║ index scans kdiixs1 ║ 0 ║ 0 ║
║ logical read bytes from cache ║ 42901504 ║ 42827776 ║
║ logons cumulative ║ 0 ║ 0 ║
║ logons current ║ 0 ║ 0 ║
║ no work - consistent read gets ║ 22 ║ 18 ║
║ non-idle wait count ║ 1732 ║ 19 ║
║ non-idle wait time ║ 7776 ║ 101 ║
║ opened cursors cumulative ║ 3 ║ 1 ║
║ opened cursors current ║ 0 ║ 0 ║
║ parse count (hard) ║ 1 ║ 0 ║
║ parse count (total) ║ 2 ║ 1 ║
║ physical read bytes ║ 16080896 ║ 147456 ║
║ physical read IO requests ║ 1836 ║ 18 ║
║ physical read total bytes ║ 16080896 ║ 147456 ║
║ physical read total IO requests ║ 1836 ║ 18 ║
║ physical read total multi block requests ║ 1 ║ 0 ║
║ physical reads ║ 1963 ║ 18 ║
║ physical reads cache ║ 1963 ║ 18 ║
║ physical reads cache prefetch ║ 253 ║ 0 ║
║ prefetch clients - default ║ 1 ║ 1 ║
║ process last non-idle time ║ 0 ║ 0 ║
║ recursive calls ║ 15 ║ 0 ║
║ recursive cpu usage ║ 0 ║ 0 ║
║ redo entries ║ 1079 ║ 1073 ║
║ redo ordering marks ║ 4 ║ 16 ║
║ redo size ║ 463216 ║ 453624 ║
║ redo subscn max counts ║ 18 ║ 16 ║
║ Requests to/from client ║ 1 ║ 1 ║
║ session connect time ║ 0 ║ 0 ║
║ session cursor cache count ║ 2 ║ 0 ║
║ session cursor cache hits ║ 1 ║ 0 ║
║ session logical reads ║ 5237 ║ 5228 ║
║ session pga memory ║ 393216 ║ 0 ║
║ session pga memory max ║ 393216 ║ 0 ║
║ session uga memory ║ 0 ║ 0 ║
║ session uga memory max ║ 0 ║ 0 ║
║ shared hash latch upgrades - no wait ║ 0 ║ 0 ║
║ sorts (memory) ║ 0 ║ 0 ║
║ sorts (rows) ║ 0 ║ 0 ║
║ SQL*Net roundtrips to/from client ║ 1 ║ 1 ║
║ table fetch by rowid ║ 4 ║ 0 ║
║ table scan blocks gotten ║ 18 ║ 18 ║
║ table scan rows gotten ║ 1017 ║ 1017 ║
║ table scans (long tables) ║ 1 ║ 1 ║
║ table scans (short tables) ║ 0 ║ 0 ║
║ undo change vector size ║ 127384 ║ 126740 ║
║ user calls ║ 2 ║ 2 ║
║ user I/O wait time ║ 7776 ║ 101 ║
║ workarea executions - optimal ║ 0 ║ 0 ║
╚════════════════════════════════════════════════╩══════════════╩═══════════════╝`
Upvotes: 1
Views: 9229
Answers (1)
Reputation: 231671
The difference between the two appears to be primarily due to a difference in physical reads. That implies that when you ran the first INSERT statement, the blocks you needed to SELECT were not in cache and had to be read from disk. When you ran the statement again, the blocks you needed were still in cache so you only had to read them from RAM. Reading from RAM is, obviously, much faster than reading from disk.
That being said, it's hard to imagine that it should really take 76 seconds to read 1000 rows of data (a total of ~16 MB) from disk (file io wait time went from just north of 76 seconds to just north of 1 second and physical read bytes goes from 16 MB to 150 kb). That's a rather insanely slow I/O speed that implies that there is some sort of issue in the underlying disk subsystem.
Upvotes: 4
Related Questions
- How to improve the Oracle insert performance
- oracle insert into very slow
- performance issue when inserting large records
- Oracle Insert All vs Insert
- INSERT-SELECT (Oracle PL/SQL) - Performance Issue
- Insert sequence taking long time
- (oracle) insert in stored procedure very slow compared to insert run manually
- Oracle 11G - Performance effect of indexing at insert
- INSERT into temporary table GTT very slow from PL/SQL
- Inserts are 4x slower if table has lots of record (400K) vs. if it's empty