Difference parse call between 11203 and 11204 issue

anbob

有个库版本11204，发现很严重的parse问题

1. Load Profile
   
2. 
   
3. Per Second        Per Transaction        Per Exec        Per Call
   
4. DB Time(s):         0.7         0.0         0.00         0.00
   
5. DB CPU(s):         0.4         0.0         0.00         0.00
   
6. Redo size (bytes):         469,220.8         1,272.4                  
   
7. Logical read (blocks):         5,820.7         15.8                  
   
8. Block changes:         3,166.9         8.6                  
   
9. Physical read (blocks):         0.0         0.0                  
   
10. Physical write (blocks):         27.1         0.1                  
    
11. Read IO requests:         0.0         0.0                  
    
12. Write IO requests:         5.3         0.0                  
    
13. Read IO (MB):         0.0         0.0                  
    
14. Write IO (MB):         0.2         0.0                  
    
15. User calls:         2,131.7         5.8                  
    
16. Parses (SQL):         841.7         2.3                  
    
17. Hard parses (SQL):         0.0         0.0                  
    
18. SQL Work Area (MB):         0.2         0.0                  
    
19. Logons:         0.6         0.0                  
    
20. Executes (SQL):         1,207.4         3.3                  
    
21. Rollbacks:         0.0         0.0                  
    
22. Transactions:         368.8                           
    
23. Instance Efficiency Percentages (Target 100%)
    
24. 
    
25. Buffer Nowait %:         100.00        Redo NoWait %:         100.00
    
26. Buffer Hit %:         100.00        In-memory Sort %:         100.00
    
27. Library Hit %:         100.25        Soft Parse %:         99.99
    
28. Execute to Parse %:         30.28        Latch Hit %:         99.85
    
29. Parse CPU to Parse Elapsd %:         14.60        % Non-Parse CPU:         98.95
    
30. Top 10 Foreground Events by Total Wait Time
    
31. 
    
32. Event        Waits        Total Wait Time (sec)        Wait Avg(ms)        % DB time        Wait Class
    
33. log file sync        1,180,970        1630.1        1        67.8        Commit
    
34. DB CPU                 1239.6                 51.5         
    
35. library cache: mutex X        8,437        125.1        15        5.2        Concurrency
    
36. latch: shared pool        713        45.9        64        1.9        Concurrency
    
37. SQL*Net message to client        4,597,267        13.9        0        .6        Network
    
38. latch: enqueue hash chains        188        3.1        17        .1        Other
    
39. cursor: pin S        693        2.9        4        .1        Concurrency
    
40. latch free        144        1.6        11        .1        Other
    
41. cursor: pin S wait on X        20        .2        12        .0        Concurrency
    
42. cursor: mutex S        2        .2        114        .0        Concurrency
    

复制代码

后来做了个测试，怀疑11204 没用 softer soft parse ，session_cached_cursor不为0

1. --####################### 11203
   
2. 
   
3. sys@ANBOB>alter system flush shared_pool;
   
4. System altered.
   
5. 
   
6. sys@ANBOB>select LOADED_VERSIONS ,OPEN_VERSIONS ,EXECUTIONS,LOADS,PARSE_CALLS from v$sql where sql_text like 'select /*weejar11203*/%';
   
7. no rows selected
   
8. 
   
9. sys@ANBOB>conn weejar/weejar
   
10. Connected.
    
11. 
    
12. weejar@ANBOB>select /*anbob11203*/ count(*) from test;
    
13.             COUNT(*)
    
14. --------------------
    
15.                    1
    
16. -- 执行同样sql 5次
    
17. 
    
18. weejar@ANBOB>select LOADED_VERSIONS ,OPEN_VERSIONS ,EXECUTIONS,LOADS,PARSE_CALLS from v$sql where sql_text like 'select /*anbob11203*/%';
    
19. 
    
20.      LOADED_VERSIONS        OPEN_VERSIONS           EXECUTIONS                LOADS          PARSE_CALLS
    
21. -------------------- -------------------- -------------------- -------------------- --------------------
    
22.                    1                    1                    5                    1                    3
    
23. 
    
24. weejar@ANBOB>show parameter session_cached
    
25. 
    
26. NAME                                 TYPE        VALUE
    
27. ------------------------------------ ----------- ------------------------------
    
28. session_cached_cursors               integer     50
    
29. weejar@ANBOB>select * from v$version;
    
30. 
    
31. BANNER
    
32. --------------------------------------------------------------------------------
    
33. Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
    
34. PL/SQL Release 11.2.0.3.0 - Production
    
35. CORE    11.2.0.3.0      Production
    
36. TNS for Linux: Version 11.2.0.3.0 - Production
    
37. NLSRTL Version 11.2.0.3.0 - Production
    
38. 
    
39. ############  11204
    
40. sys@ORA11204>conn weejar;
    
41. Enter password:
    
42. Connected.
    
43. weejar@ORA11204>select LOADED_VERSIONS ,OPEN_VERSIONS ,EXECUTIONS,LOADS,PARSE_CALLS from v$sql where sql_text like 'select /*anbob11204*/%';
    
44. no rows selected
    
45. 
    
46. weejar@ORA11204>select /*anbob11204*/ count(*) from test1;
    
47.             COUNT(*)
    
48. --------------------
    
49.                    0
    
50. -- 同样执行5次
    
51. 
    
52. 
    
53. weejar@ORA11204>select LOADED_VERSIONS ,OPEN_VERSIONS ,EXECUTIONS,LOADS,PARSE_CALLS from v$sql where sql_text like 'select /*anbob11204*/%';
    
54. 
    
55.      LOADED_VERSIONS        OPEN_VERSIONS           EXECUTIONS                LOADS          PARSE_CALLS
    
56. -------------------- -------------------- -------------------- -------------------- --------------------
    
57.                    1                    1                    5                    1                    5
    
58. 
    
59. sys@ORA11204>show parameter session_cache
    
60. 
    
61. NAME                                 TYPE        VALUE
    
62. ------------------------------------ ----------- ------------------------------
    
63. session_cached_cursors               integer     50
    
64. sys@ORA11204>select * from v$version;
    
65. 
    
66. BANNER
    
67. --------------------------------------------------------------------------------
    
68. Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production
    
69. PL/SQL Release 11.2.0.4.0 - Production
    
70. CORE    11.2.0.4.0      Production
    
71. TNS for Linux: Version 11.2.0.4.0 - Production
    
72. NLSRTL Version 11.2.0.4.0 - Production
    

复制代码

问题：
11204 解析有问题还是v$sql.parse_calls显示有问题，有人知道么？

thanks.

Maclean Liu(刘相兵

这个问题延迟到明天白天回答

anbob

同样的方法 在12C 一样

1. sys@ORA12C>select LOADED_VERSIONS ,OPEN_VERSIONS ,EXECUTIONS,LOADS,PARSE_CALLS from v$sql where sql_text like 'select /*weejar12101*/%';
   
2. 
   
3.      LOADED_VERSIONS        OPEN_VERSIONS           EXECUTIONS                LOADS          PARSE_CALLS
   
4. -------------------- -------------------- -------------------- -------------------- --------------------
   
5.                    1                    1                    5                    1                    5
   
6. 
   
7. sys@ORA12C>select * from v$version;
   
8. 
   
9. BANNER                                                                                         CON_ID
   
10. -------------------------------------------------------------------------------- --------------------
    
11. Oracle Database 12c Enterprise Edition Release 12.1.0.1.0 - 64bit Production                        0
    
12. PL/SQL Release 12.1.0.1.0 - Production                                                              0
    
13. CORE    12.1.0.1.0      Production                                                                          0
    
14. TNS for Linux: Version 12.1.0.1.0 - Production                                                      0
    
15. NLSRTL Version 12.1.0.1.0 - Production                                                              0

复制代码

10204，10205 也是5:5

Maclean Liu(刘相兵

11.2.0.4 确实有该问题

1. Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production
   
2. With the Partitioning, OLAP, Data Mining and Real Application Testing options
   
3. 
   
4. SQL> conn maclean/oracle
   
5. Connected.
   
6. SQL>
   
7. SQL>
   
8. SQL>
   
9. SQL> create table testparse(t1 int);
   
10. 
    
11. Table created.
    
12. 
    
13. SQL>
    
14. SQL> select /* macleanparse */ 1 from testeparse;
    
15. select /* macleanparse */ 1 from testeparse
    
16.                                  *
    
17. ERROR at line 1:
    
18. ORA-00942: table or view does not exist
    
19. 
    
20. 
    
21. SQL> select /* macleanparse */ 1 from testparse;
    
22. 
    
23. no rows selected
    
24. 
    
25. SQL>
    
26. SQL>    select LOADED_VERSIONS ,OPEN_VERSIONS ,EXECUTIONS,LOADS,PARSE_CALLS from v$sql where sql_text like 'select /*macleanparse*/%';
    
27. 
    
28. no rows selected
    
29. 
    
30. SQL> select LOADED_VERSIONS ,OPEN_VERSIONS ,EXECUTIONS,LOADS,PARSE_CALLS from v$sql where sql_text like 'select /* macleanparse */%';
    
31. 
    
32. LOADED_VERSIONS OPEN_VERSIONS EXECUTIONS      LOADS PARSE_CALLS
    
33. --------------- ------------- ---------- ---------- -----------
    
34.               1             0          1          1           1
    
35. 
    
36. SQL> select /* macleanparse */ 1 from testparse;
    
37. 
    
38. no rows selected
    
39. 
    
40. SQL> /
    
41. 
    
42. no rows selected
    
43. 
    
44. SQL> /
    
45. 
    
46. no rows selected
    
47. 
    
48. SQL> /
    
49. 
    
50. no rows selected
    
51. 
    
52. SQL> /
    
53. 
    
54. no rows selected
    
55. 
    
56. SQL> select LOADED_VERSIONS ,OPEN_VERSIONS ,EXECUTIONS,LOADS,PARSE_CALLS from v$sql where sql_text like 'select /* macleanparse */%';
    
57. 
    
58. LOADED_VERSIONS OPEN_VERSIONS EXECUTIONS      LOADS PARSE_CALLS
    
59. --------------- ------------- ---------- ---------- -----------
    
60.               1             1          6          1           6
    
61. 
    
62. SQL> select /* macleanparse */ 1 from testparse;
    
63. 
    
64. no rows selected
    
65. 
    
66. SQL> /
    
67. 
    
68. no rows selected
    
69. 
    
70. SQL> /
    
71. 
    
72. no rows selected
    
73. 
    
74. SQL> /
    
75. 
    
76. no rows selected
    
77. 
    
78. SQL> /
    
79. 
    
80. no rows selected
    
81. 
    
82. SQL> /
    
83. 
    
84. no rows selected
    
85. 
    
86. SQL> select LOADED_VERSIONS ,OPEN_VERSIONS ,EXECUTIONS,LOADS,PARSE_CALLS from v$sql where sql_text like 'select /* macleanparse */%';
    
87. 
    
88. LOADED_VERSIONS OPEN_VERSIONS EXECUTIONS      LOADS PARSE_CALLS
    
89. --------------- ------------- ---------- ---------- -----------
    
90.               1             1         12          1          12
    
91. 
    
92. SQL> select vs.name,vm.value from v$mystat vm,v$statname vs where  vm.statistic#=vs.statistic# and name like '%parse count%';
    
93. 
    
94. NAME                                                                  VALUE
    
95. ---------------------------------------------------------------- ----------
    
96. parse count (total)                                                     167
    
97. parse count (hard)                                                       34
    
98. parse count (failures)                                                    1
    
99. parse count (describe)                                                    0
    
100. 
     
101. SQL> select /* macleanparse */ 1 from testparse;
     
102. 
     
103. no rows selected
     
104. 
     
105. SQL> /
     
106. 
     
107. no rows selected
     
108. 
     
109. SQL> /
     
110. 
     
111. no rows selected
     
112. 
     
113. SQL> /
     
114. 
     
115. no rows selected
     
116. 
     
117. SQL> /
     
118. 
     
119. no rows selected
     
120. 
     
121. SQL> select vs.name,vm.value from v$mystat vm,v$statname vs where  vm.statistic#=vs.statistic# and name like '%parse count%';
     
122. 
     
123. NAME                                                                  VALUE
     
124. ---------------------------------------------------------------- ----------
     
125. parse count (total)                                                     173
     
126. parse count (hard)                                                       34
     
127. parse count (failures)                                                    1
     
128. parse count (describe)                                                    0
     
129. 
     
130. 
     
131. SQL> alter session set events 'immediate trace name errorstack level 3';
     
132. 
     
133. Session altered.
     

复制代码

Maclean Liu(刘相兵

怀疑与SQLPLUS这个客户端有关， 需要尝试jdbc是否会导致该问题

anbob

Maclean Liu(刘相兵 发表于 2013-11-19 15:09
怀疑与SQLPLUS这个客户端有关， 需要尝试jdbc是否会导致该问题

ML, thanks for your reply. take a sample

JAVA CODE

1. import java.sql.*;
   
2. public class parsetest{
   
3. 
   
4. public static Connection getConnection() throws Exception {
   
5.     String driver = "oracle.jdbc.driver.OracleDriver";
   
6.     String url = "jdbc:oracle:thin:@192.168.168.231:1521:ora11204";
   
7.     String username = "weejar";
   
8.     String password = "weejar";
   
9. 
   
10.     Class.forName(driver);
    
11.     Connection conn = DriverManager.getConnection(url, username, password);
    
12.     return conn;
    
13.   }
    
14. 
    
15.   public static int countRows(Connection conn, String tableName) throws SQLException {
    
16.     // select the number of rows in the table
    
17.     Statement stmt = null;
    
18.     ResultSet rs = null;
    
19.     int rowCount = -1;
    
20.     try {
    
21.       stmt = conn.createStatement();
    
22.           for (int i =0; i<10; i++){
    
23.             rs = stmt.executeQuery("SELECT /*ojdbc_parse*/ COUNT(*) FROM " + tableName);
    
24.           }
    
25.       
    
26.       // get the number of rows from the result set
    
27.       rs.next();
    
28.       rowCount = rs.getInt(1);
    
29.     } finally {
    
30.       rs.close();
    
31.       stmt.close();
    
32.     }
    
33. 
    
34.     return rowCount;
    
35.   }
    
36. 
    
37. 
    
38. public static void main(String[] args) {
    
39.     Connection conn = null;
    
40.     try {
    
41.       conn = getConnection();
    
42.       String tableName = "test1";
    
43.       System.out.println("tableName=" + tableName);
    
44.       System.out.println("conn=" + conn);
    
45.           
    
46.           System.out.println("rowCount=" + countRows(conn, tableName));
    
47.     } catch (Exception e) {
    
48.       e.printStackTrace();
    
49.       System.exit(1);
    
50.     } finally {
    
51.       // release database resources
    
52.       try {
    
53.         conn.close();
    
54.       } catch (SQLException e) {
    
55.         e.printStackTrace();
    
56.       }
    
57.     }
    
58.   }
    
59. }

复制代码

D:\>set CLASSPATH=E:\oracle\product\11.2.0\client_1\jdbc\lib\ojdbc6.jar;%CLASSPATH%

D:\>set CLASSPATH
CLASSPATH=E:\oracle\product\11.2.0\client_1\jdbc\lib\ojdbc6.jar;.;D:\jdk1_7\jre\lib\rt.jar;D:\jdk1_7\lib;D:\jdk1_7\lib\tools.jar

D:\>javac parsetest.java

D:\>java parsetest
tableName=test1
conn=oracle.jdbc.driver.T4CConnection@2f0e07
rowCount=0

1. 
   
2. weejar@ORA11204>select LOADED_VERSIONS ,OPEN_VERSIONS ,EXECUTIONS,LOADS,PARSE_CALLS from v$sql where sql_text like 'SELECT /*ojdbc_parse*/%';
   
3. 
   
4.      LOADED_VERSIONS        OPEN_VERSIONS           EXECUTIONS                LOADS          PARSE_CALLS
   
5. -------------------- -------------------- -------------------- -------------------- --------------------
   
6.                    1                    0                   10                    1                   10

复制代码

修改JAVA CODE 在11203 上执行

1. sys@ANBOB>select LOADED_VERSIONS ,OPEN_VERSIONS ,EXECUTIONS,LOADS,PARSE_CALLS from v$sql where sql_text like 'SELECT /*ojdbc_parse*/%';
   
2. 
   
3.      LOADED_VERSIONS        OPEN_VERSIONS           EXECUTIONS                LOADS          PARSE_CALLS
   
4. -------------------- -------------------- -------------------- -------------------- --------------------
   
5.                    1                    0                   10                    1                    3

复制代码

这算bug? ML 可有参数可以降11204 的parse方法为11203么？

anbob

Steve Adams said

If an SQL statement is parsed in a cursor and then executed repeatedly without closing the cursor or parsing another statement in it, then the V$SQLAREA statistics will show many more EXECUTIONS than PARSE_CALLS for that statement. If statements are never reused, then EXECUTIONS and PARSE_CALLS are normally identical. Note that the count of parse calls includes hits in the session cursor cache, which don't even touch the shared cursor. This is done by updating the statistics when the shared cursor is unpinned after execution.

Maclean Liu(刘相兵

11.2.0.4 +session_cached_cursors               integer     50

SQL> select * from v$version;

BANNER
--------------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production
PL/SQL Release 11.2.0.4.0 - Production
CORE    11.2.0.4.0      Production
TNS for Linux: Version 11.2.0.4.0 - Production
NLSRTL Version 11.2.0.4.0 - Production

SQL> conn maclean/oracle
Connected.
SQL> select /* macleanparse */ 1 from testparse;

no rows selected

SQL> select distinct sid from v$mystat;

       SID
----------
       145

SQL> SELECT cach.value cache_hits, prs.value all_parses,round((cach.value/prs.value)*100,2) as "%found in cache"
  2  FROM v$sesstat cach, v$sesstat prs, v$statname nm1, v$statname nm2
  3  WHERE cach.statistic# = nm1.statistic#
  4  AND nm1.name = 'session cursor cache hits'
  5  AND prs.statistic#=nm2.statistic#
  6  AND nm2.name= 'parse count (total)'
  7  AND cach.sid= 145 and prs.sid= cach.sid;

CACHE_HITS ALL_PARSES %found in cache
---------- ---------- ---------------
        20         45           44.44

SQL>
SQL> select /* macleanparse */ 1 from testparse;

no rows selected

SQL>
SQL> /

no rows selected

SQL> /

no rows selected

SQL> /

no rows selected


在session B 中对应每一步 做查询

SQL> SELECT cach.value cache_hits, prs.value all_parses,round((cach.value/prs.value)*100,2) as "%found in cache"
  2  FROM v$sesstat cach, v$sesstat prs, v$statname nm1, v$statname nm2
  3  WHERE cach.statistic# = nm1.statistic#
  4  AND nm1.name = 'session cursor cache hits'
  5  AND prs.statistic#=nm2.statistic#
  6  AND nm2.name= 'parse count (total)'
  7  AND cach.sid= 145 and prs.sid= cach.sid;

CACHE_HITS ALL_PARSES %found in cache
---------- ---------- ---------------
        21         46           45.65

SQL> /

CACHE_HITS ALL_PARSES %found in cache
---------- ---------- ---------------
        22         47           46.81

SQL> /

CACHE_HITS ALL_PARSES %found in cache
---------- ---------- ---------------
        23         48           47.92

SQL> /

CACHE_HITS ALL_PARSES %found in cache
---------- ---------- ---------------
        24         49           48.98

对应可以看到session cursor cache hits的增长

Maclean Liu(刘相兵

11.2.0.4 + session_cached_cursors=0
Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options

session A sid 143

SQL> conn maclean/oracle
Connected.
SQL>
SQL> select /* macleanparse */ 1 from testparse;

no rows selected

SQL> select distinct sid from v$mystat;

       SID
----------
       143

SQL> select /* macleanparse */ 1 from testparse;

no rows selected

SQL> /

no rows selected

SQL> /

no rows selected

SQL> /

no rows selected

SQL> /

no rows selected

SQL> /

no rows selected

SQL> /

no rows selected


session B 对应session A每一个步骤查询

SQL> SELECT cach.value cache_hits, prs.value all_parses,round((cach.value/prs.value)*100,2) as "%found in cache"
  2  FROM v$sesstat cach, v$sesstat prs, v$statname nm1, v$statname nm2
  3  WHERE cach.statistic# = nm1.statistic#
  4  AND nm1.name = 'session cursor cache hits'
  5  AND prs.statistic#=nm2.statistic#
  6  AND nm2.name= 'parse count (total)'
  7  AND cach.sid= 143 and prs.sid= cach.sid;

CACHE_HITS ALL_PARSES %found in cache
---------- ---------- ---------------
         0        261               0

SQL> /

CACHE_HITS ALL_PARSES %found in cache
---------- ---------- ---------------
         0        262               0

SQL> /

CACHE_HITS ALL_PARSES %found in cache
---------- ---------- ---------------
         0        268               0

SQL> /

CACHE_HITS ALL_PARSES %found in cache
---------- ---------- ---------------
         0        268               0

SQL> /

CACHE_HITS ALL_PARSES %found in cache
---------- ---------- ---------------
         0        268               0


看来仅仅是 PARSE_CALLS这个指标发生了变化