Re: Why such high buffer gets for a simple insert and inconsistent in every run
Date: Wed, 8 Aug 2018 06:30:21 +0000
Message-ID: <VI1P190MB0221674E9F4A630FE3CA5598A1260_at_VI1P190MB0221.EURP190.PROD.OUTLOOK.COM>
Also just i. general sql trace tells you what you’re doing, session stats tell you why you’re doing something - see https://github.com/tanelpoder/tpt-oracle/blob/master/snapper.sql
https://jonathanlewis.wordpress.com/2016/10/06/my-session-workload/
Sent from my iPhone
On 8 Aug 2018, at 02:15, Hemant K Chitale <hemantkchitale_at_gmail.com<mailto:hemantkchitale_at_gmail.com>> wrote:
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_at_gmail.com<mailto:krishsingh.111_at_gmail.com>> 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 --> FULL14: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 --> FULLPL/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
-- http://www.freelists.org/webpage/oracle-lReceived on Wed Aug 08 2018 - 08:30:21 CEST