今天给一个客户看awr，除了每秒114次硬解析和每秒3000多次解析外，整体 负载运行还是可以的，sql ordered by Parse Calls却很高，执行一次Parse Calls一次，那么什么是parse call呢？
下面是awr的部分内容：
Time Model Statistics
- Total time in database user-calls (DB Time): 49911.6s
- Statistics including the word "background" measure background process time, and so do not contribute to the DB time statistic
- Ordered by % or DB time desc, Statistic name
| Statistic Name | Time (s) | % of DB Time |
|---|---|---|
| sql execute elapsed time | 47,428.54 | 95.03 |
| DB CPU | 45,898.78 | 91.96 |
| parse time elapsed | 1,348.22 | 2.70 |
| hard parse elapsed time | 859.74 | 1.72 |
| PL/SQL execution elapsed time | 653.22 | 1.31 |
| connection management call elapsed time | 396.64 | 0.79 |
| PL/SQL compilation elapsed time | 182.33 | 0.37 |
| failed parse elapsed time | 13.45 | 0.03 |
| hard parse (sharing criteria) elapsed time | 10.70 | 0.02 |
| sequence load elapsed time | 3.81 | 0.01 |
| repeated bind elapsed time | 2.07 | 0.00 |
| hard parse (bind mismatch) elapsed time | 1.20 | 0.00 |
| inbound PL/SQL rpc elapsed time | 0.07 | 0.00 |
| DB time | 49,911.59 |
|
| background elapsed time | 6,717.58 |
|
| background cpu time | 4,862.80 |
|
WORKLOAD REPOSITORY report for
| DB Name | DB Id | Instance | Inst num | Startup Time | Release | RAC |
|---|---|---|---|---|---|---|
| SYORCL | 2951093808 | syorcl1 | 1 | 04-Jun-21 00:06 | 11.2.0.4.0 | YES |
| Host Name | Platform | CPUs | Cores | Sockets | Memory (GB) |
|---|---|---|---|---|---|
| hisrac01 | Linux x86 64-bit | 80 | 40 | 2 | 503.58 |
| Snap Id | Snap Time | Sessions | Cursors/Session | Instances | |
|---|---|---|---|---|---|
| Begin Snap: | 90467 | 04-Jun-21 09:44:53 | 3037 | 2.0 | 2 |
| End Snap: | 90468 | 04-Jun-21 10:53:10 | 3273 | 2.0 | 2 |
| Elapsed: |
|
68.27 (mins) |
|
|
|
| DB Time: |
|
831.86 (mins) |
|
|
|
Report Summary
Load Profile
| Per Second | Per Transaction | Per Exec | Per Call | |
|---|---|---|---|---|
| DB Time(s): | 12.2 | 0.2 | 0.00 | 0.00 |
| DB CPU(s): | 11.2 | 0.2 | 0.00 | 0.00 |
| Redo size (bytes): | 377,980.0 | 6,043.0 |
|
|
| Logical read (blocks): | 4,827,253.5 | 77,176.5 |
|
|
| Block changes: | 2,075.2 | 33.2 |
|
|
| Physical read (blocks): | 1,836.0 | 29.4 |
|
|
| Physical write (blocks): | 187.5 | 3.0 |
|
|
| Read IO requests: | 1,544.7 | 24.7 |
|
|
| Write IO requests: | 131.7 | 2.1 |
|
|
| Read IO (MB): | 14.3 | 0.2 |
|
|
| Write IO (MB): | 1.5 | 0.0 |
|
|
| Global Cache blocks received: | 1,528.4 | 24.4 |
|
|
| Global Cache blocks served: | 517.3 | 8.3 |
|
|
| User calls: | 11,025.4 | 176.3 |
|
|
| Parses (SQL): | 3,824.8 | 61.2 |
|
|
| Hard parses (SQL): | 114.9 | 1.8 |
|
|
| SQL Work Area (MB): | 91.0 | 1.5 |
|
|
| Logons: | 7.0 | 0.1 |
|
|
| Executes (SQL): | 25,177.7 | 402.5 |
|
|
| Rollbacks: | 11.6 | 0.2 |
|
|
| Transactions: | 62.6 |
|
|
|
Instance Efficiency Percentages (Target 100%)
| Buffer Nowait %: | 100.00 | Redo NoWait %: | 100.00 |
| Buffer Hit %: | 99.98 | In-memory Sort %: | 100.00 |
| Library Hit %: | 98.95 | Soft Parse %: | 97.00 |
| Execute to Parse %: | 84.81 | Latch Hit %: | 99.97 |
| Parse CPU to Parse Elapsd %: | 60.54 | % Non-Parse CPU: | 98.22 |
Top 10 Foreground Events by Total Wait Time
| Event | Waits | Total Wait Time (sec) | Wait Avg(ms) | % DB time | Wait Class |
|---|---|---|---|---|---|
| DB CPU |
|
45.9K |
|
92.0 |
|
| SQL*Net message from dblink | 1,123,853 | 2454.6 | 2 | 4.9 | Network |
| gc current block 2-way | 3,250,394 | 480.7 | 0 | 1.0 | Cluster |
| enq: TX - row lock contention | 75 | 363.4 | 4846 | .7 | Application |
| db file sequential read | 1,068,280 | 201.6 | 0 | .4 | User I/O |
| direct path read | 1,917,645 | 161.7 | 0 | .3 | User I/O |
| gc cr block 2-way | 499,041 | 90.8 | 0 | .2 | Cluster |
| log file sync | 206,713 | 73.5 | 0 | .1 | Commit |
| gc cr multi block request | 144,749 | 60.3 | 0 | .1 | Cluster |
| gc cr block busy | 89,287 | 57.9 | 1 | .1 | Cluster |
Wait Classes by Total Wait Time
| Wait Class | Waits | Total Wait Time (sec) | Avg Wait (ms) | % DB time | Avg Active Sessions |
|---|---|---|---|---|---|
| DB CPU |
|
45,899 |
|
92.0 | 11.2 |
| Other | 37,031,102 | 3,550 | 0 | 7.1 | 0.9 |
| Network | 48,060,573 | 2,588 | 0 | 5.2 | 0.6 |
| Cluster | 5,112,446 | 842 | 0 | 1.7 | 0.2 |
| User I/O | 3,355,257 | 429 | 0 | .9 | 0.1 |
| Application | 231,829 | 406 | 2 | .8 | 0.1 |
| System I/O | 1,979,941 | 212 | 0 | .4 | 0.1 |
| Commit | 206,725 | 74 | 0 | .1 | 0.0 |
| Concurrency | 133,834 | 18 | 0 | .0 | 0.0 |
| Configuration | 931 | 0 | 0 | .0 | 0.0 |
Host CPU
| CPUs | Cores | Sockets | Load Average Begin | Load Average End | %User | %System | %WIO | %Idle |
|---|---|---|---|---|---|---|---|---|
| 80 | 40 | 2 | 11.53 | 9.59 | 14.3 | 1.8 | 0.1 | 83.8 |
Instance CPU
SQL ordered by Parse Calls
- Total Parse Calls: 15,667,155
- Captured SQL account for 32.2% of Total
| Parse Calls | Executions | % Total Parses | SQL Id | SQL Module | SQL Text |
|---|---|---|---|---|---|
| 795,112 | 795,112 | 5.08 | yzxt.exe | SELECT Decode ( :1 , 1 , csz1 ... | |
| 692,418 | 692,417 | 4.42 | emrproject.exe | Select nvl ( canshuzhi , quesh... | |
| 418,197 | 418,200 | 2.67 | JDBC Thin Client | begin :con := "TASSETACL"."QUE... | |
| 391,663 | 391,663 | 2.50 | bc6s6tucuw3fa | RecordConversion.exe | select * from BL_DCBINGLITJXM ... |
| 390,203 | 390,203 | 2.49 | RecordConversion.exe | select * from BL_DCBINGLITJXM ... | |
| 303,795 | 303,794 | 1.94 | emr_yzbjq.exe | SELECT "BL_YISHENGCYY"."YISHE... | |
| 281,892 | 281,892 | 1.80 | RecordConversion.exe | select * from BL_DCBINGLITJXM ... | |
| 281,462 | 281,462 | 1.80 | RecordConversion.exe | select * from BL_DCBINGLITJXM ... | |
| 225,455 | 225,464 | 1.44 |
|
begin if SYS_CONTEXT('IDCTX', ... | |
| 161,648 | 193,519 | 1.03 |
|
begin if 1=1 then tlogon.evalr... | |
| 150,856 | 150,856 | 0.96 | CAPAA-PIPE | BEGIN :1 := TAUDIT.recievealla... | |
| 134,182 | 134,181 | 0.86 | yzxt.exe | Select instrb ( :1 , :2 ) From... | |
| 125,795 | 125,795 | 0.80 | yzxt.exe | select xm from gy_zgxx where z... | |
| 121,138 | 121,136 | 0.77 |
|
select text from view$ where r... | |
| 118,774 | 118,774 | 0.76 | RecordConversion.exe | select * from BL_DCBINGLITJXM ... | |
| 116,182 | 116,182 | 0.74 | yzxt.exe | Select sysdate From dual | |
| 115,396 | 115,396 | 0.74 | RecordConversion.exe | select * from BL_DCBINGLITJXM ... | |
| 112,731 | 112,727 | 0.72 |
|
begin if (SYS_CONTEXT('IDCTX',... | |
| 112,726 | 112,730 | 0.72 |
|
begin if ((SYS_CONTEXT('IDCTX'... | |
| 112,701 | 112,700 | 0.72 | mzzj.exe | select nvl ( gwyppb , 0 ) from... | |
| 99,845 | 99,845 | 0.64 |
|
select condition from cdef$ wh... | |
| 98,551 | 98,551 | 0.63 | RecordConversion.exe | select * from BL_DCBINGLITJXM ... | |
| 74,010 | 74,014 | 0.47 |
|
select /*+ connect_by_filterin... | |
| 73,829 | 73,829 | 0.47 | cu8pchvmarrxr | emrproject.exe | SELECT "BL_JIANBIEZDK"."SHUNX... |
| 72,328 | 72,328 | 0.46 | yzxt.exe | Select nvl ( gwyppb , 0 ) From... | |
| 68,433 | 68,433 | 0.44 | emrproject.exe | SELECT getclob ( 'bl_bingcheng... | |
| 65,216 | 65,215 | 0.42 | emrproject.exe | Select to_char ( max ( to_numb... | |
| 65,216 | 65,216 | 0.42 | emrproject.exe | Select nvl ( bingrencpmc , '' ... | |
| 61,712 | 61,712 | 0.39 | emr_yzbjq.exe | Select nvl ( ywbz , 0 ) From Y... | |
| 58,974 | 58,974 | 0.38 | emr_yzbjq.exe | Select fzfl , ypbzl From gy_yp... | |
| 35,830 | 35,829 | 0.23 | yzxt.exe | SELECT "GY_CHARGE_INTERFACE".... | |
| 28,184 | 28,182 | 0.18 |
|
SELECT OPTION_NAME, ENABLED FR... | |
| 28,183 | 28,175 | 0.18 |
|
SELECT COUNT(*) FROM MC$RULE_I... | |
| 28,183 | 28,182 | 0.18 | oraagent.bin@hisrac01 (TNS V1-V3) | begin tlogon.logon; end; | |
| 28,182 | 28,176 | 0.18 |
|
SELECT ASSET_ID, CMDTYPE, RULE... | |
| 28,180 | 28,171 | 0.18 |
|
SELECT 1 FROM MC$RULE_SCHEMA W... | |
| 28,180 | 28,183 | 0.18 |
|
SELECT 1 FROM SYS.DBA_ROLE_PRI... | |
| 28,180 | 28,179 | 0.18 | oraagent.bin@hisrac01 (TNS V1-V3) | declare PRIVS_ERROR exception;... | |
| 28,176 | 28,173 | 0.18 |
|
SELECT RULE_NAME, RULE_CLASS, ... | |
| 16,304 | 16,304 | 0.10 | emrproject.exe | Select count ( *) From EMR_HUI... | |
| 14,920 | 14,920 | 0.10 | emrproject.exe | select count ( *) from jy_weij... | |
| 14,920 | 14,920 | 0.10 | emrproject.exe | Select count ( *) From yz_inpa... | |
| 8,950 | 8,950 | 0.06 | yzxt.exe | SELECT SXXY , brxm, JCDXH FRO... | |
| 7,392 | 7,392 | 0.05 | yzxt.exe | Select Zlbzdm From Ybv_Zldmzd ... | |
| 6,518 | 6,518 | 0.04 | mzzj.exe | Select Trim ( Substr ( :1 , 1 ... | |
| 4,974 | 4,974 | 0.03 | yzxt.exe | Select Ybzfbl , Decode ( :1 , ... | |
| 4,522 | 4,522 | 0.03 | yzxt.exe | SELECT dqz FROM GY_xhb WHERE b... | |
| 3,506 | 3,506 | 0.02 | zyxt.exe | update Yb_JiaoYiXx Set ChuCanX... | |
| 3,502 | 3,502 | 0.02 | zyxt.exe | update Yb_JiaoYiXx Set RuCanXx... | |
| 2,977 | 2,977 | 0.02 | emrproject.exe | Select '#' || fun_get_bltqnr_d... | |
| 2,548 | 0 | 0.02 | oracle@SyData01 (TNS V1-V3) | SELECT /*+ FULL(P) +*/ * FROM ... | |
| 2,259 | 309,619 | 0.01 | RecordConversion.exe | SELECT TO_NUMBER(TO_CHAR(:B2 ,... | |
| 2,209 | 2,209 | 0.01 | yzxt.exe | select order_code , start_time... | |
| 1,591 | 1,591 | 0.01 | mzzj.exe | update Gy_Brjbxxk Set Xm =:1 ,... | |
| 1,490 |
|
0.01 |
|
SELECT DECODE(:B3 , 1, CSZ1, T... | |
| 1,449 | 1,449 | 0.01 | C:\Documents and Settings\charge\??\????.l | Select Ybzfbl , Decode ( :1 , ... | |
| 1,327 | 6,107 | 0.01 |
|
SELECT NVL(BINGRENCPZT, 0) FRO... | |
| 1,135 | 18,021 | 0.01 | yzxt.exe | SELECT SHOUFEILB, XIANZHIFW, T... | |
| 1,059 | 1,059 | 0.01 | mzzj.exe | Select Count ( *) From Zj_Jzxx... | |
| 1,045 | 1,045 | 0.01 | C:\Documents and Settings\charge\??\????.l | INSERT INTO MZ_YBJSXX ( SFSB ,... |
下面我通过模拟程序访问方式复现这个问题
1、第一种，创建连接，open cursor，循环执行绑定变量的sql，不会有问题
import cx_Oracle
def get_oracle_result():
try:
connection = cx_Oracle.connect('scott', 'tiger', '127.0.0.1:1521/prod')
cursor = connection.cursor()
for i in range(1, 10000000):
sql_text = 'delete from emp where deptno = :dno'
cursor.execute(sql_text, {'dno': i})
connection.commit()
print(f"current execution....")
except Exception as re:
print(re)
finally:
print("end")
cursor.close()
connection.close()
get_oracle_result()
SQL ordered by Parse Calls
- Total Parse Calls: 387
- Captured SQL account for 64.9% of Total
| Parse Calls | Executions | % Total Parses | SQL Id | SQL Module | SQL Text |
|---|---|---|---|---|---|
| 71 | 71 | 18.35 |
|
insert into wrm$_snapshot_deta... | |
| 9 | 9 | 2.33 |
|
select /*+ index(idl_ub2$ i_id... | |
| 9 | 9 | 2.33 |
|
select /*+ index(idl_char$ i_i... | |
| 9 | 9 | 2.33 |
|
select /*+ index(idl_ub1$ i_id... | |
| 9 | 9 | 2.33 |
|
select /*+ index(idl_sb4$ i_id... | |
| 8 | 8 | 2.07 |
|
select owner#, name, namespace... | |
| 8 | 8 | 2.07 |
|
select order#, columns, types ... | |
| 6 | 6 | 1.55 |
|
select max(procedure#) from pr... |
2、创建连接、然后open cursor，执行绑定变量sql，循环此操作，会有问题
import cx_Oracle
def get_oracle_result():
try:
for i in range(1, 10000000):
connection = cx_Oracle.connect('scott', 'tiger', '127.0.0.1:1521/prod')
cursor = connection.cursor()
sql_text = 'delete from emp where deptno = :dno'
cursor.execute(sql_text, {'dno': i})
connection.commit()
print(f"current execution....")
cursor.close()
connection.close()
except Exception as re:
print(re)
finally:
print("end")
get_oracle_result()
SQL ordered by Parse Calls
- Total Parse Calls: 42,949
- Captured SQL account for 89.6% of Total
| Parse Calls | Executions | % Total Parses | SQL Id | SQL Module | SQL Text |
|---|---|---|---|---|---|
| 11,481 | 11,481 | 26.73 |
|
select /*+ connect_by_filterin... | |
| 3,830 | 3,830 | 8.92 |
|
select SYS_CONTEXT('USERENV', ... | |
| 3,830 | 3,830 | 8.92 |
|
select value$ from props$ wher... | |
| 3,827 | 3,827 | 8.91 |
|
select privilege# from sysauth... | |
| 3,827 | 3,827 | 8.91 | python@centos7 (TNS V1-V3) | delete from emp where deptno =... | |
| 3,827 | 3,827 | 8.91 | python@centos7 (TNS V1-V3) | insert into sys.aud$( sessioni... | |
| 3,827 | 3,827 | 8.91 |
|
select decode(failover_method,... | |
| 3,827 | 3,827 | 8.91 | python@centos7 (TNS V1-V3) | insert into sys.aud$( sessioni... | |
| 71 | 71 | 0.17 |
|
insert into wrm$_snapshot_deta... |
3、创建连接，使用prepare statement方式执行sql，执行绑定变量， 循环此操作
import cx_Oracle
def get_oracle_result():
try:
for i in range(1, 10000000):
connection = cx_Oracle.connect('scott', 'tiger', '127.0.0.1:1521/prod')
cursor = connection.cursor()
cursor.prepare('delete from emp where DEPTNO=:dno')
cursor.execute(None, {'dno': i})
connection.commit()
print(f"current execution....")
cursor.close()
connection.close()
except Exception as re:
print(re)
finally:
print("end")
get_oracle_result()
SQL ordered by Parse Calls
- Total Parse Calls: 35,201
- Captured SQL account for 90.4% of Total
| Parse Calls | Executions | % Total Parses | SQL Id | SQL Module | SQL Text |
|---|---|---|---|---|---|
| 9,501 | 9,501 | 26.99 |
|
select /*+ connect_by_filterin... | |
| 3,170 | 3,170 | 9.01 |
|
select SYS_CONTEXT('USERENV', ... | |
| 3,170 | 3,170 | 9.01 |
|
select value$ from props$ wher... | |
| 3,167 | 3,167 | 9.00 |
|
select privilege# from sysauth... | |
| 3,167 | 3,167 | 9.00 | python@centos7 (TNS V1-V3) | insert into sys.aud$( sessioni... | |
| 3,167 | 3,167 | 9.00 |
|
select decode(failover_method,... | |
| 3,167 | 3,167 | 9.00 | python@centos7 (TNS V1-V3) | delete from emp where DEPTNO=:... | |
| 3,167 | 3,167 | 9.00 | python@centos7 (TNS V1-V3) | insert into sys.aud$( sessioni... | |
| 71 | 71 | 0.20 |
|
insert into wrm$_snapshot_deta... |
此AWR客户的应用是cs架构，没有使用中间件，比如JBOSS的如果prepared-statement-cache-size > 30，就可以减少软解析的次数。
结论：多个会话下游标不能共享的情况下，就会出现一次执行一次解析，或者有2次执行1次解析的情况。跟是不是软解析并没有直接关系