欢迎您访问程序员文章站本站旨在为大家提供分享程序员计算机编程知识!
您现在的位置是: 首页  >  数据库

大量redo生成的问题原因及改进

程序员文章站 2022-05-23 19:00:54
...

其实最终还是因为在短期内生成了大量的redo,造成了频繁的日志切换,导致归档占用了大量的空间,最后无法登录,从这个层面来说,我

接着上次分享的关于数据库无法登录的原因
其实最终还是因为在短期内生成了大量的redo,造成了频繁的日志切换,导致归档占用了大量的空间,最后无法登录,从这个层面来说,我们可以做一些工作来尽可能长时间的保留近期的归档,但是我们还可以换一个思路,那就是看看到底是什么操作生成了大量的redo,能不能试着减少redo的生成量。
一般来说,这个问题有点傻,日志肯定是记录尽可能完整的信息,这是做数据恢复的基础,我们还是不要过早下结论,先来分析一下再来做决定。
查看数据库的redo切换频率,在近几天内的redo切换频率极高,对于一个OLTP的系统来说是很非常高的负载,这种频繁的日志切换我也只在数据迁移的一些场景中碰到过。

大量redo生成的问题原因及改进

但是奇怪的是查看数据库的DB time,却发现这个值其实并不高,看起来似乎有些矛盾,从这一点来看数据库内的数据变化频率其实并不是很高。
BEGIN_SNAP END_SNAP SNAPDATE DURATION_MINS DBTIME
---------- ---------- ----------------------- ----------
82560 82561 05 Sep 2015 00:00 30 26
82561 82562 05 Sep 2015 00:30 30 26
82562 82563 05 Sep 2015 01:00 29 29
82563 82564 05 Sep 2015 01:30 30 27
82564 82565 05 Sep 2015 02:00 30 23
82565 82566 05 Sep 2015 02:30 30 23
82566 82567 05 Sep 2015 03:00 30 20
82567 82568 05 Sep 2015 03:30 30 22
82568 82569 05 Sep 2015 04:00 30 20
82569 82570 05 Sep 2015 04:30 30 25
82570 82571 05 Sep 2015 05:00 30 23
82571 82572 05 Sep 2015 05:30 30 27
82572 82573 05 Sep 2015 06:00 30 40
82573 82574 05 Sep 2015 06:30 30 26
82574 82575 05 Sep 2015 07:00 30 28
82575 82576 05 Sep 2015 07:30 30 34
82576 82577 05 Sep 2015 08:00 29 40
82577 82578 05 Sep 2015 08:30 30 37
82578 82579 05 Sep 2015 09:00 30 40
82579 82580 05 Sep 2015 09:30 30 38
82580 82581 05 Sep 2015 10:00 30 41
82581 82582 05 Sep 2015 10:30 30 40
82582 82583 05 Sep 2015 11:00 30 37
82583 82584 05 Sep 2015 11:30 30 39
82584 82585 05 Sep 2015 12:00 30 41
82585 82586 05 Sep 2015 12:30 30 34
82586 82587 05 Sep 2015 13:00 30 53
82587 82588 05 Sep 2015 13:30 30 82
82588 82589 05 Sep 2015 14:00 30 74
82589 82590 05 Sep 2015 14:30 30 45

对于这种情况,我们还是抓取一个awr报告来看看。
在awr报告中,可以看到瓶颈还是主要在DB CPU和IOsh

Top 5 Timed Foreground Events

EventWaitsTime(s)Avg wait (ms)% DB timeWait Class

DB CPU 2,184 68.89

db file parallel read 6,096 413 68 13.02 User I/O

log file sync 65,199 363 6 11.47 Commit

db file sequential read 46,038 172 4 5.43 User I/O

direct path read 415,685 46 0 1.47 User I/O

查看时间模型,可以看到DB CPU和sql相关的影响各占了主要的比例。
看到这,自己还是有些犯嘀咕,柑橘这个问题还是有些奇怪,能够关注的一个重点就是sql语句了,但是top 1的sql语句还是有些奇怪。

Elapsed Time (s)ExecutionsElapsed Time per Exec (s)%Total%CPU%IOSQL IdSQL ModuleSQL Text

931.73 14,409 0.06 29.39 99.77 0.00 JDBC Thin Client update sync_id set ma...

这条语句执行频率极高,语句也很简单,但是CPU消耗却很高,初步怀疑是走了全表扫描。
语句如下:
update sync_id set max_id = :1 where sync_id_type = :2
简单查看执行计划,发现确实是走了全表扫描,如果碰到这个问题,第一感觉是需要走索引,没有索引可以建个索引,但是当我看到sql by Executions这个部分时,自己感觉到问题其实不是那么简单。
可以看到第2个语句其实就是刚刚提到的top 1的sql,对应的指标还是很不寻常的,一次执行处理的行数近5000度行,执行了1万多次,处理的数据行数近8千万。

ExecutionsRows ProcessedRows per ExecElapsed Time (s)%CPU%IOSQL IdSQL ModuleSQL Text

14,684 14,684 1.00 3.39 94.7 .7 JDBC Thin Client update sus_log set failed_c...

14,409 78,329,332 5,436.14 931.73 99.8 0 JDBC Thin Client update sync_id set ma...