Home > Oracle, Performance > Slow DMLs and ROLLBACK

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.

About these ads
  1. Anita Gupta
    June 11, 2012 at 1:13 pm | #1

    good one Sir….

  1. No trackbacks yet.

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

Follow

Get every new post delivered to your Inbox.

%d bloggers like this: