Re: Why such high buffer gets for a simple insert and inconsistent in every run

  • From: Hemant K Chitale <hemantkchitale@xxxxxxxxx>
  • To: krishsingh.111@xxxxxxxxx
  • Date: Wed, 8 Aug 2018 08:16:44 +0800

A SQL Trace (dbms_session.enable_trace) will tell you the buffer gets from
recursive SQLs.

You could selectively trace specific executions in the session with
disable/enable.

On Mon, 6 Aug 2018, 00:09 kunwar singh, <krishsingh.111@xxxxxxxxx> wrote:

Hello Performance Experts,

I always thought simple insert ( table doesnt have a LOB)  would always
return very few buffer gets ( if only 1 index on the table) . But below
testcase shows 9 or 11 buffer gets everytime i insert these records . If i
keep on repeating the same inserts it drops to ~6 gets/exec.
Can anyone tell why this is the case? I always thought it would be 3
gets/exec for every execution in such a simple insert into and single index
table.

Version:12.1.0.1.0

TESTCASE:
++++++ ++++++ ++++++

13:48:51 SQL> alter system flush shared_pool;
System altered.
Elapsed: 00:00:00.04
13:48:55 SQL> alter system flush buffer_cache;
System altered.
Elapsed: 00:00:00.17
13:49:03 SQL> create index emp_ix on emp(empno);
Index created.
Elapsed: 00:00:00.16
13:49:08 SQL> exec dbms_stats.gather_table_stats(user, upper('EMP'),
null, method_opt=>'FOR TABLE FOR ALL COLUMNS SIZE REPEAT', cascade=>true);
PL/SQL procedure successfully completed.
Elapsed: 00:00:00.92
select *from user_tables where table_name='EMP'

================================================================================
TABLE_NAME                     --> EMP
TABLESPACE_NAME                --> USERS
CLUSTER_NAME                   -->
IOT_NAME                       -->
STATUS                         --> VALID
PCT_FREE                       --> 10
PCT_USED                       -->
INI_TRANS                      --> 1
MAX_TRANS                      --> 255
INITIAL_EXTENT                 --> 65536
NEXT_EXTENT                    --> 1048576
MIN_EXTENTS                    --> 1
MAX_EXTENTS                    --> 2147483645
PCT_INCREASE                   -->
FREELISTS                      -->
FREELIST_GROUPS                -->
LOGGING                        --> YES
BACKED_UP                      --> N
NUM_ROWS                       --> 14
BLOCKS                         --> 5
EMPTY_BLOCKS                   --> 0
AVG_SPACE                      --> 0
CHAIN_CNT                      --> 0
AVG_ROW_LEN                    --> 38
AVG_SPACE_FREELIST_BLOCKS      --> 0
NUM_FREELIST_BLOCKS            --> 0
DEGREE                         -->          1
INSTANCES                      -->          1
CACHE                          -->     N
TABLE_LOCK                     --> ENABLED
SAMPLE_SIZE                    --> 14
LAST_ANALYZED                  --> 05-AUG-18
PARTITIONED                    --> NO
IOT_TYPE                       -->
TEMPORARY                      --> N
SECONDARY                      --> N
NESTED                         --> NO
BUFFER_POOL                    --> DEFAULT
FLASH_CACHE                    --> DEFAULT
CELL_FLASH_CACHE               --> DEFAULT
ROW_MOVEMENT                   --> DISABLED
GLOBAL_STATS                   --> YES
USER_STATS                     --> NO
DURATION                       -->
SKIP_CORRUPT                   --> DISABLED
MONITORING                     --> YES
CLUSTER_OWNER                  -->
DEPENDENCIES                   --> DISABLED
COMPRESSION                    --> DISABLED
COMPRESS_FOR                   -->
DROPPED                        --> NO
READ_ONLY                      --> NO
SEGMENT_CREATED                --> YES
RESULT_CACHE                   --> DEFAULT
CLUSTERING                     --> NO
ACTIVITY_TRACKING              -->
DML_TIMESTAMP                  -->
HAS_IDENTITY                   --> NO
CONTAINER_DATA                 --> NO
select *from user_indexes where index_name='EMP_IX'

================================================================================
INDEX_NAME                     --> EMP_IX
INDEX_TYPE                     --> NORMAL
TABLE_OWNER                    --> TEST
TABLE_NAME                     --> EMP
TABLE_TYPE                     --> TABLE
UNIQUENESS                     --> NONUNIQUE
COMPRESSION                    --> DISABLED
PREFIX_LENGTH                  -->
TABLESPACE_NAME                --> USERS
INI_TRANS                      --> 2
MAX_TRANS                      --> 255
INITIAL_EXTENT                 --> 65536
NEXT_EXTENT                    --> 1048576
MIN_EXTENTS                    --> 1
MAX_EXTENTS                    --> 2147483645
PCT_INCREASE                   -->
PCT_THRESHOLD                  -->
INCLUDE_COLUMN                 -->
FREELISTS                      -->
FREELIST_GROUPS                -->
PCT_FREE                       --> 10
LOGGING                        --> YES
BLEVEL                         --> 0
LEAF_BLOCKS                    --> 1
DISTINCT_KEYS                  --> 14
AVG_LEAF_BLOCKS_PER_KEY        --> 1
AVG_DATA_BLOCKS_PER_KEY        --> 1
CLUSTERING_FACTOR              --> 1
STATUS                         --> VALID
NUM_ROWS                       --> 14
SAMPLE_SIZE                    --> 14
LAST_ANALYZED                  --> 05-AUG-18
DEGREE                         --> 1
INSTANCES                      --> 1
PARTITIONED                    --> NO
TEMPORARY                      --> N
GENERATED                      --> N
SECONDARY                      --> N
BUFFER_POOL                    --> DEFAULT
FLASH_CACHE                    --> DEFAULT
CELL_FLASH_CACHE               --> DEFAULT
USER_STATS                     --> NO
DURATION                       -->
PCT_DIRECT_ACCESS              -->
ITYP_OWNER                     -->
ITYP_NAME                      -->
PARAMETERS                     -->
GLOBAL_STATS                   --> YES
DOMIDX_STATUS                  -->
DOMIDX_OPSTATUS                -->
FUNCIDX_STATUS                 -->
JOIN_INDEX                     --> NO
IOT_REDUNDANT_PKEY_ELIM        --> NO
DROPPED                        --> NO
VISIBILITY                     --> VISIBLE
DOMIDX_MANAGEMENT              -->
SEGMENT_CREATED                --> YES
ORPHANED_ENTRIES               --> NO
INDEXING                       --> FULL
14:27:49 SQL> insert into emp
values(1111,'TESTEMP2','MANAGER',7839,sysdate,100,100,20);
1 row created.

14:30:45 SQL> select
executions,buffer_gets,last_load_time,last_active_time ,sql_text from v$sql
where sql_id='77byu2419ywqu';

      Exec|         Gets|LAST_LOAD_TIME                |LAST_ACTIVE_TIME
|SQL Text

----------|-------------|------------------------------|------------------|--------------------------------------------------------------------------------
         1|           70|2018-08-05/14:28:13           |05-AUG-18
14:28:13|insert into emp
values(1111,'TESTEMP2','MANAGER',7839,sysdate,100,100,20)

14:31:26 SQL> insert into emp
values(1112,'TESTEMP3','MANAGER',7839,sysdate,100,100,20);
1 row created.
14:31:52 SQL> select
executions,buffer_gets,last_load_time,last_active_time ,sql_text from v$sql
where sql_id='btq8j18jtvk1f';
      Exec|         Gets|LAST_LOAD_TIME                |LAST_ACTIVE_TIME
|SQL Text

----------|-------------|------------------------------|------------------|--------------------------------------------------------------------------------
         1|           11|2018-08-05/14:31:40           |05-AUG-18
14:31:40|insert into emp
values(1112,'TESTEMP3','MANAGER',7839,sysdate,100,100,20)
14:32:05 SQL> insert into emp
values(1113,'TESTEMP3','MANAGER',7839,sysdate,100,100,20);
1 row created.


14:33:42 SQL> select
executions,buffer_gets,last_load_time,last_active_time ,sql_text from v$sql
where sql_id='1pa70cs8zdx24';
      Exec|         Gets|LAST_LOAD_TIME                |LAST_ACTIVE_TIME
|SQL Text

----------|-------------|------------------------------|------------------|--------------------------------------------------------------------------------
         1|            9|2018-08-05/14:32:35           |05-AUG-18
14:32:35|insert into emp
values(1113,'TESTEMP3','MANAGER',7839,sysdate,100,100,20)
1 row selected.
14:32:57 SQL> insert into emp
values(1114,'TESTEMP3','MANAGER',7839,sysdate,100,100,20);
1 row created.
14:34:04 SQL>  select
executions,buffer_gets,last_load_time,last_active_time ,sql_text from v$sql
where sql_id='g59gcpjybxc7b';
      Exec|         Gets|LAST_LOAD_TIME                |LAST_ACTIVE_TIME
|SQL Text

----------|-------------|------------------------------|------------------|--------------------------------------------------------------------------------
         1|           11|2018-08-05/14:33:32           |05-AUG-18
14:33:32|insert into emp
values(1114,'TESTEMP3','MANAGER',7839,sysdate,100,100,20)

14:34:13 SQL> select *from v$version;
BANNER
      |    CON_ID

--------------------------------------------------------------------------------|----------
Oracle Database 12c Enterprise Edition Release 12.1.0.1.0 - 64bit
Production    |         0
PL/SQL Release 12.1.0.1.0 - Production
      |         0
CORE    12.1.0.1.0      Production
              |         0
TNS for Linux: Version 12.1.0.1.0 - Production
      |         0
NLSRTL Version 12.1.0.1.0 - Production
      |         0


----after thousands of inserts for empno =1114, gets/exec approx 6.
      Exec|         Gets|LAST_LOAD_TIME                |LAST_ACTIVE_TIME
            |SQL_TEXT

----------|-------------|------------------------------|------------------------------|----------------------------------------------------------------------------------------------------
      2029|        12711|2018-08-05/14:56:22           |05-AUG-18
14:59:24            | insert into emp
values(1114,'TESTEMP3','MANAGER',7839,sysdate,100,100,20)
--- here are the fresh stats after gathering them again:
select *from user_indexes where index_name='EMP_IX'

================================================================================
INDEX_NAME                     --> EMP_IX
INDEX_TYPE                     --> NORMAL
TABLE_OWNER                    --> TEST
TABLE_NAME                     --> EMP
TABLE_TYPE                     --> TABLE
UNIQUENESS                     --> NONUNIQUE
COMPRESSION                    --> DISABLED
PREFIX_LENGTH                  -->
TABLESPACE_NAME                --> USERS
INI_TRANS                      --> 2
MAX_TRANS                      --> 255
INITIAL_EXTENT                 --> 65536
NEXT_EXTENT                    --> 1048576
MIN_EXTENTS                    --> 1
MAX_EXTENTS                    --> 2147483645
PCT_INCREASE                   -->
PCT_THRESHOLD                  -->
INCLUDE_COLUMN                 -->
FREELISTS                      -->
FREELIST_GROUPS                -->
PCT_FREE                       --> 10
LOGGING                        --> YES
BLEVEL                         --> 1
LEAF_BLOCKS                    --> 6
DISTINCT_KEYS                  --> 18
AVG_LEAF_BLOCKS_PER_KEY        --> 1
AVG_DATA_BLOCKS_PER_KEY        --> 1
CLUSTERING_FACTOR              --> 15
STATUS                         --> VALID
NUM_ROWS                       --> 2058
SAMPLE_SIZE                    --> 2058
LAST_ANALYZED                  --> 05-AUG-18 15:01:47
DEGREE                         --> 1
INSTANCES                      --> 1
PARTITIONED                    --> NO
TEMPORARY                      --> N
GENERATED                      --> N
SECONDARY                      --> N
BUFFER_POOL                    --> DEFAULT
FLASH_CACHE                    --> DEFAULT
CELL_FLASH_CACHE               --> DEFAULT
USER_STATS                     --> NO
DURATION                       -->
PCT_DIRECT_ACCESS              -->
ITYP_OWNER                     -->
ITYP_NAME                      -->
PARAMETERS                     -->
GLOBAL_STATS                   --> YES
DOMIDX_STATUS                  -->
DOMIDX_OPSTATUS                -->
FUNCIDX_STATUS                 -->
JOIN_INDEX                     --> NO
IOT_REDUNDANT_PKEY_ELIM        --> NO
DROPPED                        --> NO
VISIBILITY                     --> VISIBLE
DOMIDX_MANAGEMENT              -->
SEGMENT_CREATED                --> YES
ORPHANED_ENTRIES               --> NO
INDEXING                       --> FULL
PL/SQL procedure successfully completed.
Elapsed: 00:00:00.06
select *from user_tables where table_name='EMP'

================================================================================
TABLE_NAME                     --> EMP
TABLESPACE_NAME                --> USERS
CLUSTER_NAME                   -->
IOT_NAME                       -->
STATUS                         --> VALID
PCT_FREE                       --> 10
PCT_USED                       -->
INI_TRANS                      --> 1
MAX_TRANS                      --> 255
INITIAL_EXTENT                 --> 65536
NEXT_EXTENT                    --> 1048576
MIN_EXTENTS                    --> 1
MAX_EXTENTS                    --> 2147483645
PCT_INCREASE                   -->
FREELISTS                      -->
FREELIST_GROUPS                -->
LOGGING                        --> YES
BACKED_UP                      --> N
NUM_ROWS                       --> 2058
BLOCKS                         --> 20
EMPTY_BLOCKS                   --> 0
AVG_SPACE                      --> 0
CHAIN_CNT                      --> 0
AVG_ROW_LEN                    --> 42
AVG_SPACE_FREELIST_BLOCKS      --> 0
NUM_FREELIST_BLOCKS            --> 0
DEGREE                         -->          1
INSTANCES                      -->          1
CACHE                          -->     N
TABLE_LOCK                     --> ENABLED
SAMPLE_SIZE                    --> 2058
LAST_ANALYZED                  --> 05-AUG-18 15:01:47
PARTITIONED                    --> NO
IOT_TYPE                       -->
TEMPORARY                      --> N
SECONDARY                      --> N
NESTED                         --> NO
BUFFER_POOL                    --> DEFAULT
FLASH_CACHE                    --> DEFAULT
CELL_FLASH_CACHE               --> DEFAULT
ROW_MOVEMENT                   --> DISABLED
GLOBAL_STATS                   --> YES
USER_STATS                     --> NO
DURATION                       -->
SKIP_CORRUPT                   --> DISABLED
MONITORING                     --> YES
CLUSTER_OWNER                  -->
DEPENDENCIES                   --> DISABLED
COMPRESSION                    --> DISABLED
COMPRESS_FOR                   -->
DROPPED                        --> NO
READ_ONLY                      --> NO
SEGMENT_CREATED                --> YES
RESULT_CACHE                   --> DEFAULT
CLUSTERING                     --> NO
ACTIVITY_TRACKING              -->
DML_TIMESTAMP                  -->
HAS_IDENTITY                   --> NO
CONTAINER_DATA                 --> NO



++++++ ++++++ ++++++
Please let me know if you need any more information in order to understand
this behaviour.

p.s. Pardon my ignorance if i have sent the email in wrong format etc. Any
guidance is appreciated :)


Cheers,
Kunwar

Other related posts: