log file sync 等待事件的真凶跑哪里去了

lxjweb

1概述：
1个4节点rac,aix,11.2.0.3 ,近期有半小时的性能波动(16号9点--9点半),按照15号同时段（正常时段)通过AWR分析，发现top 5里的log file sync 等待事件的真正原因没了。它去了哪里?

2.下面是AWR里的部分确认结果：
正常时平均等<5ms，异常时300ms左右，正常时段和异常时段各取30分钟，从awr报告里得出如下数据
1.确认了log file parallel write 不大,正常时1ms，异常时2ms
2.确认了user calls/user commits 比值没有大的变化
3.两个top 5事件 里事件不同，db time占比也不同（稍后贴图)
4.有DG 配置(异步），只有dest2:
     SERVICE=salerpt ASYNC VALID_FOR=(ONLINE_LOGFILES, PRIMARY_ROLE) DB_UNIQUE_NAME=sass

Thks!

lxjweb

系统在波动时段，的确出现了网络流量的波动，但是不确定是否和网络有关。

Maclean Liu(刘相兵

就系统看 cpu和内存都未成为瓶颈， 但GCS和GES的延迟明显提高了：

Avg global enqueue get time (ms):        40.6
Avg global cache cr block receive time (ms):        65.0
Avg global cache current block receive time (ms):        11.7
Avg global cache cr block build time (ms):        0.0
Avg global cache cr block send time (ms):        0.0
Global cache log flushes for cr blocks served %:        10.2
Avg global cache cr block flush time (ms):        1,664.2
Avg global cache current block pin time (ms):        0.2
Avg global cache current block send time (ms):        0.0
Global cache log flushes for current blocks served %:        0.5
Avg global cache current block flush time (ms):        1,870.9

Maclean Liu(刘相兵

你可以认为波动期内系统已经hang了 分析log file sync单个等待事件没啥意义





Event        Waits        Time(s)        Avg wait (ms)        % DB time        Wait Class
gc buffer busy acquire        535,403        323,746        605        28.34        Cluster
log file sync        750,532        228,804        305        20.03        Commit
buffer busy waits        242,080        202,202        835        17.70        Concurrency
library cache lock        16,897        149,282        8835        13.07        Concurrency
gc cr block busy        319,236        58,825        184        5.15        Cluster

tatistic Name        Time (s)        % of DB Time
sql execute elapsed time        778,131.14        68.12
connection management call elapsed time        162,396.91        14.22
DB CPU        16,600.36        1.45
parse time elapsed        1,648.53        0.14
sequence load elapsed time        895.77        0.08
hard parse elapsed time        328.93        0.03
PL/SQL execution elapsed time        290.99        0.03
hard parse (sharing criteria) elapsed time        54.51        0.00
hard parse (bind mismatch) elapsed time        28.81        0.00
failed parse elapsed time        5.07        0.00
PL/SQL compilation elapsed time        0.37        0.00
repeated bind elapsed time        0.07        0.00
DB time        1,142,367.48         
background elapsed time        16,449.22         
background cpu time        2,719.93         



Global Cache and Enqueue Services - Workload Characteristics

Avg global enqueue get time (ms):        40.6
Avg global cache cr block receive time (ms):        65.0
Avg global cache current block receive time (ms):        11.7
Avg global cache cr block build time (ms):        0.0
Avg global cache cr block send time (ms):        0.0
Global cache log flushes for cr blocks served %:        10.2
Avg global cache cr block flush time (ms):        1,664.2
Avg global cache current block pin time (ms):        0.2
Avg global cache current block send time (ms):        0.0
Global cache log flushes for current blocks served %:        0.5
Avg global cache current block flush time (ms):        1,870.9

Global Cache and Enqueue Services - Messaging Statistics

Avg message sent queue time (ms):        0.1
Avg message sent queue time on ksxp (ms):        8.7
Avg message received queue time (ms):        0.0
Avg GCS message process time (ms):        0.0
Avg GES message process time (ms):        0.1
% of direct sent messages:        49.50
% of indirect sent messages:        49.49
% of flow controlled messages:        1.01