HelloDBA [中文]
Search Internet Search HelloDBA
  Oracle Technology Site. email: fuyuncat@gmail.com  MSN: fuyuncat@hotmail.com Add to circle  acoug  acoug 

Consistent Gets may not tell the truth

[中文]

Author:  fuyuncat

Source:  www.HelloDBA.com

Date:  2015-10-23 22:48:14

Share to  Twitter Facebook GMail Blogger Orkut Google Bookmarks Sina Weibo QQ Renren Tieba Kaixin Douban Taobao

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代码
  1. SQL 1:  
  2. Statistics  
  3. ----------------------------------------------------------  
  4.           0  recursive calls  
  5.           0  db block gets  
  6.         460  consistent gets  
  7.           0  physical reads  
  8.           0  redo size  
  9.     1203583  bytes sent via SQL*Net to client  
  10.        3868  bytes received via SQL*Net from client  
  11.         306  SQL*Net roundtrips to/from client  
  12.           0  sorts (memory)  
  13.           0  sorts (disk)  
  14.        4563  rows processed  
  15.   
  16. SQL 2:  
  17. Statistics  
  18. ----------------------------------------------------------  
  19.           0  recursive calls  
  20.           0  db block gets  
  21.         167  consistent gets  
  22.           0  physical reads  
  23.           0  redo size  
  24.      267325  bytes sent via SQL*Net to client  
  25.        3868  bytes received via SQL*Net from client  
  26.         306  SQL*Net roundtrips to/from client  
  27.           1  sorts (memory)  
  28.           0  sorts (disk)  
  29.        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代码
  1. HelloDBA.COM> create table t1 as select * from dba_tables;  
  2.   
  3. Table created.  
  4.   
  5. HelloDBA.COM> create table t2 as select * from dba_users;  
  6.   
  7. Table created.  
  8.   
  9. HelloDBA.COM> exec dbms_stats.gather_table_stats('DEMO''T1');  
  10.   
  11. PL/SQL procedure successfully completed.  
  12.   
  13. HelloDBA.COM> exec dbms_stats.gather_table_stats('DEMO''T2');  
  14.   
  15. PL/SQL procedure successfully completed.  
  16.   
  17. HelloDBA.COM> set timing on  
  18. HelloDBA.COM> set autot trace  
  19. HelloDBA.COM> select * from t1;  
  20.   
  21. 4563 rows selected.  
  22.   
  23. Elapsed: 00:00:00.10  
  24.   
  25. Execution Plan  
  26. ----------------------------------------------------------  
  27. Plan hash value: 3617692013  
  28.   
  29. --------------------------------------------------------------------------  
  30. | Id  | Operation         | Name | Rows  | Bytes | Cost (%CPU)| Time     |  
  31. --------------------------------------------------------------------------  
  32. |   0 | SELECT STATEMENT  |      |  4563 |  1078K|    49   (0)| 00:00:01 |  
  33. |   1 |  TABLE ACCESS FULL| T1   |  4563 |  1078K|    49   (0)| 00:00:01 |  
  34. --------------------------------------------------------------------------  
  35.   
  36.   
  37. Statistics  
  38. ----------------------------------------------------------  
  39.           0  recursive calls  
  40.           0  db block gets  
  41.         460  consistent gets  
  42.           0  physical reads  
  43.           0  redo size  
  44.     1203583  bytes sent via SQL*Net to client  
  45.        3868  bytes received via SQL*Net from client  
  46.         306  SQL*Net roundtrips to/from client  
  47.           0  sorts (memory)  
  48.           0  sorts (disk)  
  49.        4563  rows processed  
  50.   
  51. HelloDBA.COM> select * from t1, t2 where t2.username='SYS';  
  52.   
  53. 4563 rows selected.  
  54.   
  55. Elapsed: 00:00:00.23  
  56.   
  57. Execution Plan  
  58. ----------------------------------------------------------  
  59. Plan hash value: 1323614827  
  60.   
  61. -----------------------------------------------------------------------------  
  62. | Id  | Operation            | Name | Rows  | Bytes | Cost (%CPU)| Time     |  
  63. -----------------------------------------------------------------------------  
  64. |   0 | SELECT STATEMENT     |      |  4563 |  1581K|    52   (0)| 00:00:01 |  
  65. |   1 |  MERGE JOIN CARTESIAN|      |  4563 |  1581K|    52   (0)| 00:00:01 |  
  66. |*  2 |   TABLE ACCESS FULL  | T2   |     1 |   113 |     3   (0)| 00:00:01 |  
  67. |   3 |   BUFFER SORT        |      |  4563 |  1078K|    49   (0)| 00:00:01 |  
  68. |   4 |    TABLE ACCESS FULL | T1   |  4563 |  1078K|    49   (0)| 00:00:01 |  
  69. -----------------------------------------------------------------------------  
  70.   
  71. Predicate Information (identified by operation id):  
  72. ---------------------------------------------------  
  73.   
  74.    2 - filter("T2"."USERNAME"='SYS')  
  75.   
  76.   
  77. Statistics  
  78. ----------------------------------------------------------  
  79.           0  recursive calls  
  80.           0  db block gets  
  81.         167  consistent gets  
  82.           0  physical reads  
  83.           0  redo size  
  84.      267325  bytes sent via SQL*Net to client  
  85.        3868  bytes received via SQL*Net from client  
  86.         306  SQL*Net roundtrips to/from client  
  87.           1  sorts (memory)  
  88.           0  sorts (disk)  
  89.        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代码
  1. Rows (1st) Rows (avgRows (max)  Row Source Operation  
  2. ---------- ---------- ----------  ---------------------------------------------------  
  3.       4563       4563       4563  MERGE JOIN CARTESIAN (cr=167 pr=0 pw=0 time=38433 us cost=52 size=1619865 card=4563)  
  4.          1          1          1   TABLE ACCESS FULL T2 (cr=3 pr=0 pw=0 time=78 us cost=3 size=113 card=1)  
  5.       4563       4563       4563   BUFFER SORT (cr=164 pr=0 pw=0 time=22958 us cost=49 size=1104246 card=4563)  
  6.       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代码
  1. HelloDBA.COM> set arraysize 5000  
  2. HelloDBA.COM> set autot trace stat  
  3. HelloDBA.COM> select * from t1;  
  4.   
  5. Statistics  
  6. ----------------------------------------------------------  
  7.           0  recursive calls  
  8.           0  db block gets  
  9.         165  consistent gets  
  10.           0  physical reads  
  11.           0  redo size  
  12.     1147039  bytes sent via SQL*Net to client  
  13.         524  bytes received via SQL*Net from client  
  14.           2  SQL*Net roundtrips to/from client  
  15.           0  sorts (memory)  
  16.           0  sorts (disk)  
  17.        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代码
  1. HelloDBA.COM> select * from t1, t2;  
  2.   
  3. 246402 rows selected.  
  4.   
  5.   
  6. Statistics  
  7. ----------------------------------------------------------  
  8.           1  recursive calls  
  9.           0  db block gets  
  10.         219  consistent gets  
  11.           0  physical reads  
  12.           0  redo size  
  13.    14113903  bytes sent via SQL*Net to client  
  14.      181209  bytes received via SQL*Net from client  
  15.       16428  SQL*Net roundtrips to/from client  
  16.           1  sorts (memory)  
  17.           0  sorts (disk)  
  18.      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代码
  1. Rows (1st) Rows (avgRows (max)  Row Source Operation  
  2. ---------- ---------- ----------  ---------------------------------------------------  
  3.     246402     246402     246402  MERGE JOIN CARTESIAN (cr=219 pr=0 pw=0 time=957833 us cost=2553 size=87472710 card=246402)  
  4.         54         54         54   TABLE ACCESS FULL T2 (cr=55 pr=0 pw=0 time=728 us cost=3 size=6102 card=54)  
  5.     246402     246402     246402   BUFFER SORT (cr=164 pr=0 pw=0 time=433549 us cost=2550 size=1104246 card=4563)  
  6.       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代码
  1. HelloDBA.COM> select count(*) from t2;  
  2.   
  3.   COUNT(*)  
  4. ----------  
  5.         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代码
  1. HelloDBA.COM> select /*+use_nl(t1) leading(t1)*/* from t1, t2;  
  2.   
  3. 246402 rows selected.  
  4.   
  5. Elapsed: 00:00:07.43  
  6.   
  7. Execution Plan  
  8. ----------------------------------------------------------  
  9. Plan hash value: 787647388  
  10.   
  11. -----------------------------------------------------------------------------  
  12. | Id  | Operation            | Name | Rows  | Bytes | Cost (%CPU)| Time     |  
  13. -----------------------------------------------------------------------------  
  14. |   0 | SELECT STATEMENT     |      |   246K|    83M|  5006   (1)| 00:01:01 |  
  15. |   1 |  MERGE JOIN CARTESIAN|      |   246K|    83M|  5006   (1)| 00:01:01 |  
  16. |   2 |   TABLE ACCESS FULL  | T1   |  4563 |  1078K|    49   (0)| 00:00:01 |  
  17. |   3 |   BUFFER SORT        |      |    54 |  6102 |  4956   (1)| 00:01:00 |  
  18. |   4 |    TABLE ACCESS FULL | T2   |    54 |  6102 |     1   (0)| 00:00:01 |  
  19. -----------------------------------------------------------------------------  
  20.   
  21.   
  22. Statistics  
  23. ----------------------------------------------------------  
  24.           0  recursive calls  
  25.           0  db block gets  
  26.        4568  consistent gets  
  27.           0  physical reads  
  28.           0  redo size  
  29.    16632868  bytes sent via SQL*Net to client  
  30.      181209  bytes received via SQL*Net from client  
  31.       16428  SQL*Net roundtrips to/from client  
  32.           1  sorts (memory)  
  33.           0  sorts (disk)  
  34.      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 ---

Top

Copyright ©2005, HelloDBA.Com All reseverd.

Declaration
by fuyuncat