ACTION PLAN (What, Why)

Hi 您好！

非常感谢您的耐心等待！

如果v$sysmetric_history的时间间隔不能满足您的需求的话，您可以考虑以更短的时间间隔从v$sesstat等动态视图里抽取redo size等信息：

--当前各个会话的redo size情况
select
ss.sid,
'redo size:'||ss.value,
s.program,
s.module
from
v$statname
sn,v$sesstat
ss,v$session s
where
ss.statistic#=sn.statistic#
and
sn.name='redo size'
and
s.sid=ss.sid
and
ss.value>0
order by
ss.value;

set lines 120
col osuser format a10
col username format 10
--当前各个会话的块变更数量
select
osuser,
username,
process pid,
ses.sid sid,
serial#,
physical_reads,
block_changes
from
v$session ses,
v$sess_io sio
where
ses.sid = sio.sid
order
by physical_reads desc;

非常感谢您的理解和配合！

Best Regards,
Bracelf Tang
Oracle Customer Services
Working hours: 9:00 - 18:00 GMT+8

Oracle Support	- Tuesday		[Call - Outbound]

Call - Outbound

Hi

非常感谢您在百忙之中抽空接听我的电话！

现将通话记录总结如下，如果记录上有出入或者遗漏，欢迎您在SR上更新订正：

1. log file parallel write 等待事件的数据的由来，是LGWR等写出redo日志的会话中记录的当前的等待事件的时长，然后内存中的ASH buffer会在1秒的时间间隔里从V$SESSION取到这个等待事件及其等待时长，记录到V$ACTIVE_SESSION_HISTORY这个动态性能视图里，最后在AWR snapshot采集时，从V$ACTIVE_SESSION_HISTORY抽取10秒一个间隔的采样数据，写到磁盘上的ASH数据中，磁盘上这份采样数据可以通过视图DBA_HIST_ACTIVE_SESS_HISTORY来查询；由于您使用的第三方监控脚本zabix的数据间隔是10秒，有可能是从DBA_HIST_ACTIVE_SESS_HISTORY里抽取的数据，至于其具体详细抽取逻辑请咨询这个工具的供应商；关于采样间隔更短的 redo size, 我将进一步调查看看，一有进展就给您更新。

2.关于 log file parallel write 等待事件的时长，很大程度上取决于 I/O 设备的速度，请同时考虑收集类似于 iostat 这样的I/O设备性能统计数据，一起进行比较，看看是否redo等I/O请求量并没有明显的波动，而I/O速度却出现了较大波动，如果是这样的话，很可能是I/O设备性能不稳定造成的；

3.目前来看，应用的响应速度与 log file parallel write 等待事件的时长看起来有很强的关联性；如果今后发现应用的响应速度与 log file parallel write 等待事件的时长并没有太强的关联性，请考虑对应用的响应时间进行细化，看看主要的时间开销是在CPU, 网络，I/O等待, 还是 log file sync等其它等待上。 log file parallel write 等待事件是后台LGWR等进程执行的操作，通常只会导致前端进程在 log file sync 等待上花时间，如果不是 log file sync 等待上花时间，很可能和LGWR等后台进程的操作无关，只是同时受到影响而已。谢谢您的理解！

很高兴与您一起讨论问题，如果还有什么尚未解释清楚的地方，请您更新SR，我将竭诚为您服务。

祝您虎年吉祥，工作顺利，万事如意!

Best regards,
Bracelf Tang
Oracle Customer Service
Working hours: 9:00 - 12:30, 13:30 - 18:00 GMT+8

Oracle Support	- Tuesday		[Notes]

尊敬的客户 您好！

非常感谢您的耐心等待！

我还在分析调查，一有进展就更新SR。

非常感谢您的理解！

Best Regards,
Bracelf Tang
Oracle Customer Services
Working hours: 9:00 - 18:00 GMT+8

Tuesday [Update from Customer]

就是想有数据支撑来评估 dblogfileparallelwrite 响应时间波动或升高的合理性。

谢谢！

Oracle Support	- Tuesday		[Notes]

尊敬的客户，您好！

谢谢您的快速回复！

关于您的问题，我会尽快进行调查处理.
一旦调查有进展，我再联系您！

祝好！

Best Regards,
Bracelf Tang
Global Software Services
Working hours: 9:00 - 12:30, 13:30 - 8:00 GMT+8

Tuesday [Update from Customer]

您好，

如果还有什么尚未解释清楚的地方，或者，您还有什么需要，请分享一下您问题的背景，以便更好地为您服务。
<<<<<<<<<
因在一套对IO读写非常敏感的业务DB中，观察到 db-log file parallel write 这个指标的延时有波动，而且有时波动会超过0.1ms持续1分钟，这个在趋势图上会看到比较明显的峰值（平时在0.3ms，波动范围0.03ms左右；而一旦这个延时达3ms，业务就会有卡顿感，Active session就会有冲高增多的情况发生），因此想弄清楚， db-log file parallel write 这个指标的偶尔延时波动升高（如升高0.2ms）的原因和及其升高和什么有关系，同时根据一些指标(比如 redo写量增加或其他的指标) 来评估这个波动是不是正常的？还是因为其他可能的因素引起的（比如存储IO不稳定等）。

谢谢！

Oracle Support	- Tuesday		[ODM Action Plan]

Follow-up (When)

ACTION PLAN (What, Why)

尊敬的客户 您好！

非常感谢您的耐心等待！

请允许我回答您的问题如下:

根据上面每条记录，是不是可以计算出DB 每分钟的 Redo Generated量 (bytes)，
如：2022/1/31 13:01:17 ~ 2022/1/31 13:02:17，此1分钟，Redo Generated量= 10353.884545000860 ？
那从2022/1/31 12:56:18开始，到2022/1/31 13:01:17，连续5分钟的 Redo Generated量 是不是此每条记录 value60 再相加？

----> 这样没有问题的。

以此，我们想得到DB 每分钟的 Redo Generated量 ，然后将其做成按时间的Redo Generated量趋势图；以此来衡量系统redo的繁忙度，同时以此来近似解释db log file parallel write响应时间波动的原因。这是否可行？

----> 可行的。

这每条记录中， 'Redo Writes Per Sec' 对应的VALUE 的单位是什么，是次数吗,还是其他？

----> 是写redo操作的次数。
如果您还想看每次写的redo块数，您需要参考v$sysstat或者dba_hist_sysstat的"redo blocks written"的值除以"redo writes"的值。

[参考资料]
Statistics Descriptions
https://docs.oracle.com/cd/E11882_01/server.112/e40402/stats002.htm#i375475

Redo Generated Per Sec 和 db log file parallel write 的度量在DB中哪个视图中有详细的记录？

Redo Generated Per Sec 这样的度量值，您可以从v$metricname视图和上述Statistics Descriptions的文档上可以查到其单位；
log file parallel write 这样的等待事件，您可以从v$event_name视图查到。

如果还有什么尚未解释清楚的地方，或者，您还有什么需要，请分享一下您问题的背景，以便更好地为您服务。

非常感谢您的理解和配合！

Best Regards,
Bracelf Tang
Oracle Customer Services
Working hours: 9:00 - 18:00 GMT+8

Oracle Support	- Tuesday		[ODM Research]

-- Analysis --

Note: This is INTERNAL ONLY research. No action should be taken by the customer on this information. This is research only, and may NOT be applicable to your specific situation.

Statistics Descriptions
https://docs.oracle.com/cd/E11882_01/server.112/e40402/stats002.htm#i375475

redo writes
Total number of writes by LGWR to the redo log files. "redo blocks written" divided by this statistic equals the number of blocks per write

redo blocks written
Total number of redo blocks written. This statistic divided by "redo writes" equals number of blocks per write.

Oracle Support	- Tuesday		[Notes]

尊敬的客户，您好！

谢谢您的快速回复！

关于您的问题，我会尽快进行调查处理.
一旦调查有进展，我再联系您！

祝好！

Best Regards,
Bracelf Tang
Global Software Services
Working hours: 9:00 - 12:30, 13:30 - 8:00 GMT+8

Monday [Update from Customer]

按时间序，
Redo Generated Per Sec 和 db log file parallel write 的度量在DB中哪个视图中有详细的记录？

谢谢！

Monday [Update from Customer]

另，

select * from gv$sysmetric_history where metric_name ='Redo Writes Per Sec'

INST_ID BEGIN_TIME END_TIME INTSIZE_CSEC GROUP_ID METRIC_ID METRIC_NAME VALUE METRIC_UNIT
1 1 2022/1/31 20:06:17 2022/1/31 20:07:18 6013 2 2034 Redo Writes Per Sec 0.947946116747048 Writes Per Second
2 1 2022/1/31 20:05:17 2022/1/31 20:06:17 6014 2 2034 Redo Writes Per Sec 0.764881942135018 Writes Per Second
3 1 2022/1/31 20:04:17 2022/1/31 20:05:17 6013 2 2034 Redo Writes Per Sec 0.964576750374189 Writes Per Second
4 1 2022/1/31 20:03:17 2022/1/31 20:04:17 6014 2 2034 Redo Writes Per Sec 0.814765547056867 Writes Per Second
5 1 2022/1/31 20:02:17 2022/1/31 20:03:17 6013 2 2034 Redo Writes Per Sec 1.6963246299684 Writes Per Second
6 1 2022/1/31 20:01:17 2022/1/31 20:02:17 6013 2 2034 Redo Writes Per Sec 0.665225345085648 Writes Per Second
7 1 2022/1/31 20:00:18 2022/1/31 20:01:17 5914 2 2034 Redo Writes Per Sec 1.30199526547176 Writes Per Second
8 1 2022/1/31 19:59:17 2022/1/31 20:00:18 6014 2 2034 Redo Writes Per Sec 3.40871300299302 Writes Per Second

这每条记录中， 'Redo Writes Per Sec' 对应的VALUE 的单位是什么，是次数吗,还是其他？

谢谢！

Monday [Update from Customer]

您好，

如下面：
select * from v$sysmetric_history where metric_name='Redo Generated Per Sec'；

BEGIN_TIME END_TIME INTSIZE_CSEC GROUP_ID METRIC_ID METRIC_NAME VALUE METRIC_UNIT
1 2022/1/31 13:01:17 2022/1/31 13:02:17 6011 2 2016 Redo Generated Per Sec 10353.8845450008 Bytes Per Second
2 2022/1/31 13:00:17 2022/1/31 13:01:17 6012 2 2016 Redo Generated Per Sec 113855.821689953 Bytes Per Second
3 2022/1/31 12:59:17 2022/1/31 13:00:17 6013 2 2016 Redo Generated Per Sec 302268.751039415 Bytes Per Second
4 2022/1/31 12:58:17 2022/1/31 12:59:17 6011 2 2016 Redo Generated Per Sec 8957.91049742139 Bytes Per Second
5 2022/1/31 12:57:17 2022/1/31 12:58:17 6011 2 2016 Redo Generated Per Sec 8426.28514390285 Bytes Per Second
6 2022/1/31 12:56:18 2022/1/31 12:57:17 5912 2 2016 Redo Generated Per Sec 11091.6102841678 Bytes Per Second

根据上面每条记录，是不是可以计算出DB 每分钟的 Redo Generated量 (bytes)，
如：2022/1/31 13:01:17 ~ 2022/1/31 13:02:17，此1分钟，Redo Generated量= 10353.884545000860 ？
那从2022/1/31 12:56:18开始，到2022/1/31 13:01:17，连续5分钟的 Redo Generated量 是不是此每条记录 value60 再相加？

以此，我们想得到DB 每分钟的 Redo Generated量 ，然后将其做成按时间的Redo Generated量趋势图；以此来衡量系统redo的繁忙度，同时以此来近似解释db log file parallel write响应时间波动的原因。这是否可行？

谢谢！

Oracle Support	- Monday		[ODM Answer]

尊敬的客户 您好！

非常感谢您的耐心等待！

请允许我回答您的问题如下:

-> BEGIN_TIME 表示本次系统度量的开始时间；
END_TIME 表示本次系统度量的结束时间；
INTSIZE_CSEC 表示系统度量的时长（单位是百分之一秒）；
GROUP_ID 表示系统度量的组号；
METRIC_ID 表示系统度量的ID；
METRIC_NAME 表示系统度量的名称，比如'Redo Generated Per Sec'；
VALUE 表示本次系统度量的数值；
METRIC_UNIT 表示系统度量的计量单位，比如，每秒的字节数；

[参考资料]
https://docs.oracle.com/cd/E18283_01/server.112/e17110/dynviews_3091.htm

如果还有什么尚未解释清楚的地方，或者，您还有什么需要，请分享一下您问题的背景，以便更好地为您服务。

非常感谢您的理解和配合！

Best Regards,
Bracelf Tang
Oracle Customer Services
Working hours: 9:00 - 18:00 GMT+8

Oracle Support	- Monday		[ODM Question]

咨询视图 v$sysmetric_history 在 metric_name='Redo Generated Per Sec' 时，其各列的含义是什么？
如：
select * from v$sysmetric_history where metric_name='Redo Generated Per Sec'；

BEGIN_TIME END_TIME INTSIZE_CSEC GROUP_ID METRIC_ID METRIC_NAME VALUE METRIC_UNIT
1 2022/1/31 13:01:17 2022/1/31 13:02:17 6011 2 2016 Redo Generated Per Sec 10353.8845450008 Bytes Per Second
2 2022/1/31 13:00:17 2022/1/31 13:01:17 6012 2 2016 Redo Generated Per Sec 113855.821689953 Bytes Per Second
3 2022/1/31 12:59:17 2022/1/31 13:00:17 6013 2 2016 Redo Generated Per Sec 302268.751039415 Bytes Per Second
4 2022/1/31 12:58:17 2022/1/31 12:59:17 6011 2 2016 Redo Generated Per Sec 8957.91049742139 Bytes Per Second
5 2022/1/31 12:57:17 2022/1/31 12:58:17 6011 2 2016 Redo Generated Per Sec 8426.28514390285 Bytes Per Second
6 2022/1/31 12:56:18 2022/1/31 12:57:17 5912 2 2016 Redo Generated Per Sec 11091.6102841678 Bytes Per Second
7 2022/1/31 12:55:17 2022/1/31 12:56:18 6011 2 2016 Redo Generated Per Sec 8498.48610880053 Bytes Per Second
8 2022/1/31 12:54:17 2022/1/31 12:55:17 6012 2 2016 Redo Generated Per Sec 11677.4451097804 Bytes Per Second
9 2022/1/31 12:53:17 2022/1/31 12:54:17 6010 2 2016 Redo Generated Per Sec 10543.9600665557 Bytes Per Second
10 2022/1/31 12:52:17 2022/1/31 12:53:17 6013 2 2016 Redo Generated Per Sec 15910.4606685515 Bytes Per Second
11 2022/1/31 12:51:17 2022/1/31 12:52:17 6012 2 2016 Redo Generated Per Sec 9080.90485695276 Bytes Per Second
12 2022/1/31 12:50:17 2022/1/31 12:51:17 6012 2 2016 Redo Generated Per Sec 11937.6580172987 Bytes Per Second
13 2022/1/31 12:49:17 2022/1/31 12:50:17 6010 2 2016 Redo Generated Per Sec 121648.053244592 Bytes Per Second
14 2022/1/31 12:48:17 2022/1/31 12:49:17 6010 2 2016 Redo Generated Per Sec 10151.2811980033 Bytes Per Second
15 2022/1/31 12:47:18 2022/1/31 12:48:17 5910 2 2016 Redo Generated Per Sec 8733.06260575296 Bytes Per Second

需要统计RAC 每秒或每分钟的redo量大小，并按时间监控其大小趋势图。