Consistent Gets may not tell the truth
[中文]
Author:
fuyuncat
Source:
www.HelloDBA.com
Date:
2015-10-23 22:48:14
Share to
Consistent gets is important statistics data indicating the performance of a SQL. It's a metric data for us to tune SQL. Normally, we may compare the performance of two SQL or same SQL with different execution plan. However, sometimes, CG may not tell us the release performance of SQL.
Let's review below 2 statistics data output first.
SQL代码
- SQL 1:
- Statistics
- ----------------------------------------------------------
- 0 recursive calls
- 0 db block gets
- 460 consistent gets
- 0 physical reads
- 0 redo size
- 1203583 bytes sent via SQL*Net to client
- 3868 bytes received via SQL*Net from client
- 306 SQL*Net roundtrips to/from client
- 0 sorts (memory)
- 0 sorts (disk)
- 4563 rows processed
- SQL 2:
- Statistics
- ----------------------------------------------------------
- 0 recursive calls
- 0 db block gets
- 167 consistent gets
- 0 physical reads
- 0 redo size
- 267325 bytes sent via SQL*Net to client
- 3868 bytes received via SQL*Net from client
- 306 SQL*Net roundtrips to/from client
- 1 sorts (memory)
- 0 sorts (disk)
- 4563 rows processed
The consistent gets of the 1st SQL is almost 3 times of the 2nd one. Seems the 2nd must have better performance. Isn't it?
Ok, let's go back to see how did these data got.
SQL代码
- HelloDBA.COM> create table t1 as select * from dba_tables;
- Table created.
- HelloDBA.COM> create table t2 as select * from dba_users;
- Table created.
- HelloDBA.COM> exec dbms_stats.gather_table_stats('DEMO', 'T1');
- PL/SQL procedure successfully completed.
- HelloDBA.COM> exec dbms_stats.gather_table_stats('DEMO', 'T2');
- PL/SQL procedure successfully completed.
- HelloDBA.COM> set timing on
- HelloDBA.COM> set autot trace
- HelloDBA.COM> select * from t1;
- 4563 rows selected.
- Elapsed: 00:00:00.10
- Execution Plan
- ----------------------------------------------------------
- Plan hash value: 3617692013
- --------------------------------------------------------------------------
- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
- --------------------------------------------------------------------------
- | 0 | SELECT STATEMENT | | 4563 | 1078K| 49 (0)| 00:00:01 |
- | 1 | TABLE ACCESS FULL| T1 | 4563 | 1078K| 49 (0)| 00:00:01 |
- --------------------------------------------------------------------------
- Statistics
- ----------------------------------------------------------
- 0 recursive calls
- 0 db block gets
- 460 consistent gets
- 0 physical reads
- 0 redo size
- 1203583 bytes sent via SQL*Net to client
- 3868 bytes received via SQL*Net from client
- 306 SQL*Net roundtrips to/from client
- 0 sorts (memory)
- 0 sorts (disk)
- 4563 rows processed
- HelloDBA.COM> select * from t1, t2 where t2.username='SYS';
- 4563 rows selected.
- Elapsed: 00:00:00.23
- Execution Plan
- ----------------------------------------------------------
- Plan hash value: 1323614827
- -----------------------------------------------------------------------------
- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
- -----------------------------------------------------------------------------
- | 0 | SELECT STATEMENT | | 4563 | 1581K| 52 (0)| 00:00:01 |
- | 1 | MERGE JOIN CARTESIAN| | 4563 | 1581K| 52 (0)| 00:00:01 |
- |* 2 | TABLE ACCESS FULL | T2 | 1 | 113 | 3 (0)| 00:00:01 |
- | 3 | BUFFER SORT | | 4563 | 1078K| 49 (0)| 00:00:01 |
- | 4 | TABLE ACCESS FULL | T1 | 4563 | 1078K| 49 (0)| 00:00:01 |
- -----------------------------------------------------------------------------
- Predicate Information (identified by operation id):
- ---------------------------------------------------
- 2 - filter("T2"."USERNAME"='SYS')
- Statistics
- ----------------------------------------------------------
- 0 recursive calls
- 0 db block gets
- 167 consistent gets
- 0 physical reads
- 0 redo size
- 267325 bytes sent via SQL*Net to client
- 3868 bytes received via SQL*Net from client
- 306 SQL*Net roundtrips to/from client
- 1 sorts (memory)
- 0 sorts (disk)
- 4563 rows processed
These 2 SQLs are simple. If we ignore the performance statistics data, we can easily determine their performance from their logical structure or from their execution plan --- The performance of the 1st one must be better than the 2nd one, because there is one more full table scan in the execution plan.
Then why the 2nd one has less consistent gets?
Set SQL Trace for them, and then look into the formatted trace file.
SQL代码
- Rows (1st) Rows (avg) Rows (max) Row Source Operation
- ---------- ---------- ---------- ---------------------------------------------------
- 4563 4563 4563 MERGE JOIN CARTESIAN (cr=167 pr=0 pw=0 time=38433 us cost=52 size=1619865 card=4563)
- 1 1 1 TABLE ACCESS FULL T2 (cr=3 pr=0 pw=0 time=78 us cost=3 size=113 card=1)
- 4563 4563 4563 BUFFER SORT (cr=164 pr=0 pw=0 time=22958 us cost=49 size=1104246 card=4563)
- 4563 4563 4563 TABLE ACCESS FULL T1 (cr=164 pr=0 pw=0 time=11815 us cost=49 size=1104246 card=4563)
This is the plan statistics data of the 2nd SQL. Obviously, there are 2 parts of consistent gets, FTS on t1 and FTS on t2.
In this plan, FTS on t1 is 164. But why the 1st SQL got 466? That is because of fetch array size. Default array size of SQL*Plus is 15. If we set it large enough, it will be,
SQL代码
- HelloDBA.COM> set arraysize 5000
- HelloDBA.COM> set autot trace stat
- HelloDBA.COM> select * from t1;
- Statistics
- ----------------------------------------------------------
- 0 recursive calls
- 0 db block gets
- 165 consistent gets
- 0 physical reads
- 0 redo size
- 1147039 bytes sent via SQL*Net to client
- 524 bytes received via SQL*Net from client
- 2 SQL*Net roundtrips to/from client
- 0 sorts (memory)
- 0 sorts (disk)
- 4563 rows processed
165. Yes, becasue no matter how large of the array size, oracle will always retrieve the 1st row in the 1st fetch. More details refer to this article.
http://www.hellodba.com/reader.php?ID=39&lang=EN
F2 is a fairly small, consistent gets is just 3, it makes sense.
Is this the end of the story? No, let remove the filter from the 2nd SQL,
SQL代码
- HelloDBA.COM> select * from t1, t2;
- 246402 rows selected.
- Statistics
- ----------------------------------------------------------
- 1 recursive calls
- 0 db block gets
- 219 consistent gets
- 0 physical reads
- 0 redo size
- 14113903 bytes sent via SQL*Net to client
- 181209 bytes received via SQL*Net from client
- 16428 SQL*Net roundtrips to/from client
- 1 sorts (memory)
- 0 sorts (disk)
- 246402 rows processed
Only 219 consistent gets? It's a Cartesian Join, how come the small consistent gets is it?
Generate the SQL trace file again,
SQL代码
- Rows (1st) Rows (avg) Rows (max) Row Source Operation
- ---------- ---------- ---------- ---------------------------------------------------
- 246402 246402 246402 MERGE JOIN CARTESIAN (cr=219 pr=0 pw=0 time=957833 us cost=2553 size=87472710 card=246402)
- 54 54 54 TABLE ACCESS FULL T2 (cr=55 pr=0 pw=0 time=728 us cost=3 size=6102 card=54)
- 246402 246402 246402 BUFFER SORT (cr=164 pr=0 pw=0 time=433549 us cost=2550 size=1104246 card=4563)
- 4563 4563 4563 TABLE ACCESS FULL T1 (cr=164 pr=0 pw=0 time=10674 us cost=47 size=1104246 card=4563)
CR of FTS on t1 is unchanged, while CR of FTS on t2 is increased to 55.
What is this number? It's row number of T2 plus 1.
SQL代码
- HelloDBA.COM> select count(*) from t2;
- COUNT(*)
- ----------
- 54
But wait, logically, Cartesian Join means n*m, right? How come a result of n+m?
Actually, Oracle do read the data of t1 for multiple times (54). However, after first scan on t1, data has been cached into private work area, the following reads are from the private buffer instead of shared buffer. Therefore, they are not counted into consistent gets.
To get its real "gets", we may use nested loop join hint to force it read data from shared buffer instead of private buffer.
SQL代码
- HelloDBA.COM> select /*+use_nl(t1) leading(t1)*/* from t1, t2;
- 246402 rows selected.
- Elapsed: 00:00:07.43
- Execution Plan
- ----------------------------------------------------------
- Plan hash value: 787647388
- -----------------------------------------------------------------------------
- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
- -----------------------------------------------------------------------------
- | 0 | SELECT STATEMENT | | 246K| 83M| 5006 (1)| 00:01:01 |
- | 1 | MERGE JOIN CARTESIAN| | 246K| 83M| 5006 (1)| 00:01:01 |
- | 2 | TABLE ACCESS FULL | T1 | 4563 | 1078K| 49 (0)| 00:00:01 |
- | 3 | BUFFER SORT | | 54 | 6102 | 4956 (1)| 00:01:00 |
- | 4 | TABLE ACCESS FULL | T2 | 54 | 6102 | 1 (0)| 00:00:01 |
- -----------------------------------------------------------------------------
- Statistics
- ----------------------------------------------------------
- 0 recursive calls
- 0 db block gets
- 4568 consistent gets
- 0 physical reads
- 0 redo size
- 16632868 bytes sent via SQL*Net to client
- 181209 bytes received via SQL*Net from client
- 16428 SQL*Net roundtrips to/from client
- 1 sorts (memory)
- 0 sorts (disk)
- 246402 rows processed
Although the execution plan is not changed, the consistents gets is increased significantly.
What we should note from this case is,
Fetch array size affects the consistent gets.
Consistent gets statistics data will only include the gets from shared buffer;
Test environment: Oracle 11.2.0.3 on Oracle Linux 5 64bit
--- Fuyuncat ---