Slow DMLs and ROLLBACK
I was confronted with an application team recently for creating their 19th index on a large table with close to 100 columns! The developer community was entirely unhappy as their idea was shot down by me. Added to above, recently more requests started coming on our way to faster the ROLLBACKS. So, thought to write a test case, what will happen if we create too many indexes on a table, too many indexes on a same column.
Here is my test table with just 0.25 million records and I am just UPDATing and ROLLBACKing the operations. Just observer the time, gets, redo etc
SQL> create table mytab as SELECT LEVEL v1,'Testinggggggggggggggggggg' v2, level+level v3,level*2 v4 FROM dual CONNECT BY LEVEL <= 250000; Table created. SQL> update mytab set v1=v1+1 ; 250000 rows updated. Elapsed: 00:00:51.19 Execution Plan ---------------------------------------------------------- Plan hash value: 636898616 ---------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | ---------------------------------------------------------------------------- | 0 | UPDATE STATEMENT | | 214K| 13M| 256 (5)| 00:00:02 | | 1 | UPDATE | MYTAB | | | | | | 2 | TABLE ACCESS FULL| MYTAB | 214K| 13M| 256 (5)| 00:00:02 | ---------------------------------------------------------------------------- Note ----- - dynamic sampling used for this statement Statistics ---------------------------------------------------------- 422 recursive calls 267053 db block gets 1796 consistent gets 8239 physical reads 85348908 redo size 833 bytes sent via SQL*Net to client 781 bytes received via SQL*Net from client 3 SQL*Net roundtrips to/from client 2 sorts (memory) 0 sorts (disk) 250000 rows processed SQL> rollback; Rollback complete. Elapsed: 00:01:06.51
Then I create a series of indexes and repeated the tests.
SQL> create index iv11 on mytab(v1); Index created. Elapsed: 00:00:06.70 SQL> update mytab set v1=v1+1 ; 250000 rows updated. Elapsed: 00:01:58.98 Execution Plan ---------------------------------------------------------- Plan hash value: 636898616 ---------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | ---------------------------------------------------------------------------- | 0 | UPDATE STATEMENT | | 214K| 13M| 256 (5)| 00:00:02 | | 1 | UPDATE | MYTAB | | | | | | 2 | TABLE ACCESS FULL| MYTAB | 214K| 13M| 256 (5)| 00:00:02 | ---------------------------------------------------------------------------- Note ----- - dynamic sampling used for this statement Statistics ---------------------------------------------------------- 225 recursive calls 1689696 db block gets 3453 consistent gets 16429 physical reads 203059024 redo size 839 bytes sent via SQL*Net to client 781 bytes received via SQL*Net from client 3 SQL*Net roundtrips to/from client 1 sorts (memory) 0 sorts (disk) 250000 rows processed SQL> rollback; Rollback complete. Elapsed: 00:02:14.98 SQL> create index iv12 on mytab(v1,v2); Index created. Elapsed: 00:00:16.18 SQL> update mytab set v1=v1+1 ; 250000 rows updated. Elapsed: 00:03:26.32 Execution Plan ---------------------------------------------------------- Plan hash value: 636898616 ---------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | ---------------------------------------------------------------------------- | 0 | UPDATE STATEMENT | | 214K| 13M| 256 (5)| 00:00:02 | | 1 | UPDATE | MYTAB | | | | | | 2 | TABLE ACCESS FULL| MYTAB | 214K| 13M| 256 (5)| 00:00:02 | ---------------------------------------------------------------------------- Note ----- - dynamic sampling used for this statement Statistics ---------------------------------------------------------- 1205 recursive calls 3332753 db block gets 6663 consistent gets 28757 physical reads 348501124 redo size 841 bytes sent via SQL*Net to client 781 bytes received via SQL*Net from client 3 SQL*Net roundtrips to/from client 1 sorts (memory) 0 sorts (disk) 250000 rows processed SQL> rollback; Rollback complete. Elapsed: 00:03:33.93 SQL> create index iv13 on mytab(v1,v3); Index created. Elapsed: 00:00:08.96 SQL> update mytab set v1=v1+1 ; 250000 rows updated. Elapsed: 00:04:13.84 Execution Plan ---------------------------------------------------------- Plan hash value: 636898616 ---------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | ---------------------------------------------------------------------------- | 0 | UPDATE STATEMENT | | 214K| 13M| 256 (5)| 00:00:02 | | 1 | UPDATE | MYTAB | | | | | | 2 | TABLE ACCESS FULL| MYTAB | 214K| 13M| 256 (5)| 00:00:02 | ---------------------------------------------------------------------------- Note ----- - dynamic sampling used for this statement Statistics ---------------------------------------------------------- 1084 recursive calls 4836321 db block gets 4395 consistent gets 34481 physical reads 448165184 redo size 841 bytes sent via SQL*Net to client 781 bytes received via SQL*Net from client 3 SQL*Net roundtrips to/from client 5 sorts (memory) 0 sorts (disk) 250000 rows processed SQL> rollback; Rollback complete. Elapsed: 00:04:29.11 SQL> create index iv14 on mytab(v1,v4); Index created. Elapsed: 00:00:08.75 SQL> update mytab set v1=v1+1 ; 250000 rows updated. Elapsed: 00:05:46.25 Execution Plan ---------------------------------------------------------- Plan hash value: 636898616 ---------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | ---------------------------------------------------------------------------- | 0 | UPDATE STATEMENT | | 214K| 13M| 256 (5)| 00:00:02 | | 1 | UPDATE | MYTAB | | | | | | 2 | TABLE ACCESS FULL| MYTAB | 214K| 13M| 256 (5)| 00:00:02 | ---------------------------------------------------------------------------- Note ----- - dynamic sampling used for this statement Statistics ---------------------------------------------------------- 2179 recursive calls 6356272 db block gets 4905 consistent gets 42900 physical reads 561477020 redo size 842 bytes sent via SQL*Net to client 781 bytes received via SQL*Net from client 3 SQL*Net roundtrips to/from client 1 sorts (memory) 0 sorts (disk) 250000 rows processed SQL> rollback; Rollback complete. Elapsed: 00:06:19.96 SQL> create index iv15 on mytab(v2,v1); Index created. Elapsed: 00:00:31.00 SQL> update mytab set v1=v1+1 ; 250000 rows updated. Elapsed: 00:07:04.75 Execution Plan ---------------------------------------------------------- Plan hash value: 636898616 ---------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | ---------------------------------------------------------------------------- | 0 | UPDATE STATEMENT | | 214K| 13M| 256 (5)| 00:00:02 | | 1 | UPDATE | MYTAB | | | | | | 2 | TABLE ACCESS FULL| MYTAB | 214K| 13M| 256 (5)| 00:00:02 | ---------------------------------------------------------------------------- Note ----- - dynamic sampling used for this statement Statistics ---------------------------------------------------------- 3905 recursive calls 7894909 db block gets 7949 consistent gets 54586 physical reads 703850100 redo size 843 bytes sent via SQL*Net to client 781 bytes received via SQL*Net from client 3 SQL*Net roundtrips to/from client 1 sorts (memory) 0 sorts (disk) 250000 rows processed SQL> rollback; Rollback complete. Elapsed: 00:07:50.15 SQL> create index iv16 on mytab(v3,v1); Index created. Elapsed: 00:00:13.25 SQL> update mytab set v1=v1+1 ; 250000 rows updated. Elapsed: 00:07:57.92 Execution Plan ---------------------------------------------------------- Plan hash value: 636898616 ---------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | ---------------------------------------------------------------------------- | 0 | UPDATE STATEMENT | | 214K| 13M| 256 (5)| 00:00:02 | | 1 | UPDATE | MYTAB | | | | | | 2 | TABLE ACCESS FULL| MYTAB | 214K| 13M| 256 (5)| 00:00:02 | ---------------------------------------------------------------------------- Note ----- - dynamic sampling used for this statement Statistics ---------------------------------------------------------- 2076 recursive calls 9394625 db block gets 4905 consistent gets 60221 physical reads 803628840 redo size 843 bytes sent via SQL*Net to client 781 bytes received via SQL*Net from client 3 SQL*Net roundtrips to/from client 1 sorts (memory) 0 sorts (disk) 250000 rows processed SQL> rollback; Rollback complete. Elapsed: 00:09:49.83 SQL> create index iv17 on mytab(v4,v1); Index created. Elapsed: 00:00:13.77 SQL> update mytab set v1=v1+1 ; 250000 rows updated. Elapsed: 00:09:34.02 Execution Plan ---------------------------------------------------------- Plan hash value: 636898616 ---------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | ---------------------------------------------------------------------------- | 0 | UPDATE STATEMENT | | 214K| 13M| 256 (5)| 00:00:02 | | 1 | UPDATE | MYTAB | | | | | | 2 | TABLE ACCESS FULL| MYTAB | 214K| 13M| 256 (5)| 00:00:02 | ---------------------------------------------------------------------------- Note ----- - dynamic sampling used for this statement Statistics ---------------------------------------------------------- 1045 recursive calls 10910432 db block gets 4424 consistent gets 67748 physical reads 916654628 redo size 843 bytes sent via SQL*Net to client 781 bytes received via SQL*Net from client 3 SQL*Net roundtrips to/from client 1 sorts (memory) 0 sorts (disk) 250000 rows processed SQL> rollback; Rollback complete. Elapsed: 00:10:35.62
Both UPDATE and ROLLBACK takes more than 8 to 10 times to complete the operation with 7 indexes. Other statistics are following.
| Update Time (Sec) | % Increase | Rollback Time (Sec) | % Increase | |
| No index |
51 |
67 |
||
| 1 Index |
119 |
133% |
135 |
101% |
| 2 Indexes |
207 |
306% |
214 |
219% |
| 3 Indexes |
254 |
398% |
269 |
301% |
| 4 Indexes |
346 |
578% |
377 |
463% |
| 5 Indexes |
425 |
733% |
470 |
601% |
| 6 Indexes |
478 |
837% |
590 |
781% |
| 7 Indexes |
574 |
1025% |
636 |
849% |
Database I/O Stats
| DBBLKGETS | % Increase | Con. Gets | % Increase | Phy. Reads | % Increase | |
| No index |
267053 |
1796 |
8239 |
|||
| 1 Index |
1689696 |
533% |
3453 |
92% |
16429 |
99% |
| 2 Indexes |
3332753 |
1148% |
6663 |
271% |
28757 |
249% |
| 3 Indexes |
4836321 |
1711% |
4395 |
145% |
34481 |
319% |
| 4 Indexes |
6356272 |
2280% |
4905 |
173% |
42900 |
421% |
| 5 Indexes |
7894909 |
2856% |
7949 |
343% |
54586 |
563% |
| 6 Indexes |
9394625 |
3418% |
4905 |
173% |
60221 |
631% |
| 7 Indexes |
10910432 |
3985% |
4424 |
146% |
67748 |
722% |
REDO generation statistics
| Redo | % Increase | |
| No index |
85348908 |
|
| 1 Index |
203059024 |
138% |
| 2 Indexes |
348501124 |
308% |
| 3 Indexes |
448165184 |
425% |
| 4 Indexes |
561477020 |
558% |
| 5 Indexes |
703850100 |
725% |
| 6 Indexes |
803628840 |
842% |
| 7 Indexes |
916654628 |
974% |
In nutshell, whenever the number of indexes are increased, it will take more time and resource to complete each DML activity. So, your SELECT will be faster on the cost of other DMLs. Next time if your rollback or update is slow, before rushing to the DBA’s check the design.
Note: I have included the V1 column purposefully in all indexes.
Categories: Oracle, Performance
slow delete, slow insert, slow rollback, slow update
Comments (0)
Trackbacks (0)
Leave a comment
Trackback
Thomas Saviour's Blog 