联机日志文件过小引发的log file 相关等待

本文涉及的产品
日志服务 SLS,月写入数据量 50GB 1个月
传统型负载均衡 CLB,每月750个小时 15LCU
网络型负载均衡 NLB,每月750个小时 15LCU
简介:       Oracle 联机重做日志文件记录了数据库的所有变化(DML,DDL或管理员对数据所作的结构性更改等),用于对于意外删除或宕机利用日志文件实现数据恢复来确保数据的完整性。

      Oracle 联机重做日志文件记录了数据库的所有变化(DML,DDL或管理员对数据所作的结构性更改等),用于对于意外删除或宕机利用日志文件实现数据恢复来确保数据的完整性。但不合理的联机日志文件规划将引发日志相关的等待事件。下面是这样一个来自生产环境中的例子。

 

1、故障描述

--客户描述该数据库晚上用于实现数据同步以及汇总,以前一直工作的比较良好,随着需要同步的数量量的增大,最近变得越来越慢。
--下面我们首先取了客户晚8点至第二天7点的awr report。

WORKLOAD REPOSITORY report for

DB Name         DB Id    Instance     Inst Num Release     RAC Host
------------ ----------- ------------ -------- ----------- --- ------------
ST990         2152526631 ST990               1 10.2.0.3.0  NO  v2011db02p

              Snap Id      Snap Time      Sessions Curs/Sess
            --------- ------------------- -------- ---------
Begin Snap:     21787 21-Feb-13 20:00:22        50      19.5
  End Snap:     21798 22-Feb-13 07:00:47        44      20.0
   Elapsed:              660.42 (mins)
   DB Time:              928.06 (mins)

--从上面的awr report 可知,单实例,10.2.0.3版本,期间的会话数也不多
--Elapsed < DB Time
--Elapsed Time=(20130222 07:00:00 - 20130221 20:00:00)≈ 660
--DB Time=928.06 ,运行环境为16核CPU, 660*16=10560, cpu花费了928.06分钟在处理Oralce非空闲等待和运算上
--从上可知,整个系统还是比较空闲

--下面来看看top event
Top 5 Timed Events                                         Avg %Total
~~~~~~~~~~~~~~~~~~                                        wait   Call
Event                                 Waits    Time (s)   (ms)   Time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
CPU time                                         20,673          37.1
log file parallel write              27,399       4,797    175    8.6 System I/O
control file parallel write          13,428       4,688    349    8.4 System I/O
log file sync                        19,564       3,795    194    6.8     Commit
db file scattered read           26,651,537       3,439      0    6.2   User I/O

--从上面的top event事件上来看,log file相关等待事件表现明显
--log file parallel write等待事件总等待次数27,399 总等待时间4,797/60=79.95(min),超出一个小时,相当可观
--其次是control file parallel write与log file sync事件的相关等待

--下面是等待事件的detail信息
Wait Events                          DB/Inst: ST1200/ST1200  Snaps: 21787-21798
-> s  - second
-> cs - centisecond -     100th of a second
-> ms - millisecond -    1000th of a second
-> us - microsecond - 1000000th of a second
-> ordered by wait time desc, waits desc (idle events last)

                                             %Time  Total Wait    wait     Waits
Event                                 Waits  -outs    Time (s)    (ms)      /txn
---------------------------- -------------- ------ ----------- ------- ---------
log file parallel write              27,399     .0       4,797     175       1.1
control file parallel write          13,428     .0       4,688     349       0.5
log file sync                        19,564   10.6       3,795     194       0.8
db file scattered read           26,651,537     .0       3,439       0   1,049.4
db file sequential read           6,682,373     .0       1,567       0     263.1
log file switch (checkpoint           1,091   92.9       1,019     934       0.0
Datapump dump file I/O              633,458     .0         286       0      24.9
log file switch completion              332   31.6         183     552       0.0
log buffer space                        255   47.8         155     608       0.0
free buffer waits                     2,409   99.5         120      50       0.1
buffer busy waits                       145   62.8          96     664       0.0

2、分析故障

--客户描述该数据库晚上用于实现数据同步以及汇总,以前一直工作的比较良好,随着需要同步的数量量的增大,最近变得越来越慢。
--下面我们首先取了客户晚8点至第二天7点的awr report。

WORKLOAD REPOSITORY report for

DB Name         DB Id    Instance     Inst Num Release     RAC Host
------------ ----------- ------------ -------- ----------- --- ------------
ST990         2152526631 ST990               1 10.2.0.3.0  NO  v2011db02p

              Snap Id      Snap Time      Sessions Curs/Sess
            --------- ------------------- -------- ---------
Begin Snap:     21787 21-Feb-13 20:00:22        50      19.5
  End Snap:     21798 22-Feb-13 07:00:47        44      20.0
   Elapsed:              660.42 (mins)
   DB Time:              928.06 (mins)

--从上面的awr report 可知,单实例,10.2.0.3版本,期间的会话数也不多
--Elapsed < DB Time
--Elapsed Time=(20130222 07:00:00 - 20130221 20:00:00)≈ 660
--DB Time=928.06 ,运行环境为16核CPU, 660*16=10560, cpu花费了928.06分钟在处理Oralce非空闲等待和运算上
--从上可知,整个系统还是比较空闲

--下面来看看top event
Top 5 Timed Events                                         Avg %Total
~~~~~~~~~~~~~~~~~~                                        wait   Call
Event                                 Waits    Time (s)   (ms)   Time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
CPU time                                         20,673          37.1
log file parallel write              27,399       4,797    175    8.6 System I/O
control file parallel write          13,428       4,688    349    8.4 System I/O
log file sync                        19,564       3,795    194    6.8     Commit
db file scattered read           26,651,537       3,439      0    6.2   User I/O

--从上面的top event事件上来看,log file相关等待事件表现明显
--log file parallel write等待事件总等待次数27,399 总等待时间4,797/60=79.95(min),超出一个小时,相当可观
--其次是control file parallel write与log file sync事件的相关等待

--下面是等待事件的detail信息
Wait Events                          DB/Inst: ST1200/ST1200  Snaps: 21787-21798
-> s  - second
-> cs - centisecond -     100th of a second
-> ms - millisecond -    1000th of a second
-> us - microsecond - 1000000th of a second
-> ordered by wait time desc, waits desc (idle events last)

                                             %Time  Total Wait    wait     Waits
Event                                 Waits  -outs    Time (s)    (ms)      /txn
---------------------------- -------------- ------ ----------- ------- ---------
log file parallel write              27,399     .0       4,797     175       1.1
control file parallel write          13,428     .0       4,688     349       0.5
log file sync                        19,564   10.6       3,795     194       0.8
db file scattered read           26,651,537     .0       3,439       0   1,049.4
db file sequential read           6,682,373     .0       1,567       0     263.1
log file switch (checkpoint           1,091   92.9       1,019     934       0.0
Datapump dump file I/O              633,458     .0         286       0      24.9
log file switch completion              332   31.6         183     552       0.0
log buffer space                        255   47.8         155     608       0.0
free buffer waits                     2,409   99.5         120      50       0.1
buffer busy waits                       145   62.8          96     664       0.0


3、几个log file 事件
log file parallel write

The log file parallel write wait event has three parameters: files, blocks, and requests. In Oracle Database 10g, this wait event falls under the System I/O wait class. Keep the following key thoughts in mind when dealing with the log file parallel write wait event.

    The log file parallel write event belongs only to the LGWR process.
    A slow LGWR can impact foreground processes commit time.
    Significant log file parallel write wait time is most likely an I/O issue

 

log file sync

The log file sync wait event has one parameter: buffer#. In Oracle Database 10g, this wait event falls under the Commit wait class. Keep the following key thoughts in mind when dealing with the log file sync wait event.

    The log file sync wait event is related to transaction terminations (commits or rollbacks).

    When a process spends a lot of time on the log file sync event, it is usually indicative of too many commits or short transactions.

 

The log file switch (checkpoint incomplete) wait event has no wait parameters.

In Oracle Database 10g, this wait event falls under the Configuration wait class. Keep the following key thought in mind when dealing with the log file switch (checkpoint incomplete) wait event.

    Excessive log switches caused by small log files and a high transaction rate

更多的知识点可以参考 Oracle Wait Interface: A Practical Guide to Performance Diagnostics & Tuning

 

4、建议与解决方案
 a、从上面的分析以及日志相关等待事件的解释来看,首要的是增加日志文件的大小(200-250MB)。可参考:调整联机重做日志大小(change redo log size)
 b、日志文件组太多,建议减少到4-5组
 c、可能的情形下,将日志存放到高速磁盘(目前是raid 5上),如存放到raid 0之上
 d、采用批量提交的方式来提交事务
 e、建议增加DBWn的数目

 

更多参考:

有关Oracle RAC请参考
     使用crs_setperm修改RAC资源的所有者及权限
     使用crs_profile管理RAC资源配置文件
     RAC 数据库的启动与关闭
     再说 Oracle RAC services
     Services in Oracle Database 10g
     Migrate datbase from single instance to Oracle RAC
     Oracle RAC 连接到指定实例
     Oracle RAC 负载均衡测试(结合服务器端与客户端)
     Oracle RAC 服务器端连接负载均衡(Load Balance)
     Oracle RAC 客户端连接负载均衡(Load Balance)
     ORACLE RAC 下非缺省端口监听配置(listener.ora tnsnames.ora)
     ORACLE RAC 监听配置 (listener.ora tnsnames.ora)
     配置 RAC 负载均衡与故障转移
     CRS-1006 , CRS-0215 故障一例 
     基于Linux (RHEL 5.5) 安装Oracle 10g RAC
     使用 runcluvfy 校验Oracle RAC安装环境

有关Oracle 网络配置相关基础以及概念性的问题请参考:
     配置非默认端口的动态服务注册
     配置sqlnet.ora限制IP访问Oracle
     Oracle 监听器日志配置与管理
     设置 Oracle 监听器密码(LISTENER)
     配置ORACLE 客户端连接到数据库

有关基于用户管理的备份和备份恢复的概念请参考
     Oracle 冷备份
     Oracle 热备份
     Oracle 备份恢复概念
     Oracle 实例恢复
     Oracle 基于用户管理恢复的处理
     SYSTEM 表空间管理及备份恢复
     SYSAUX表空间管理及恢复
     Oracle 基于备份控制文件的恢复(unsing backup controlfile)

有关RMAN的备份恢复与管理请参考
     RMAN 概述及其体系结构
     RMAN 配置、监控与管理
     RMAN 备份详解
     RMAN 还原与恢复
     RMAN catalog 的创建和使用
     基于catalog 创建RMAN存储脚本
     基于catalog 的RMAN 备份与恢复
     RMAN 备份路径困惑
     使用RMAN实现异机备份恢复(WIN平台)
     使用RMAN迁移文件系统数据库到ASM
     linux 下RMAN备份shell脚本
     使用RMAN迁移数据库到异机

有关ORACLE体系结构请参考
     Oracle 表空间与数据文件
     Oracle 密码文件
     Oracle 参数文件
     Oracle 联机重做日志文件(ONLINE LOG FILE)
     Oracle 控制文件(CONTROLFILE)
     Oracle 归档日志
     Oracle 回滚(ROLLBACK)和撤销(UNDO)
     Oracle 数据库实例启动关闭过程
     Oracle 10g SGA 的自动化管理
     Oracle 实例和Oracle数据库(Oracle体系结构)

相关实践学习
日志服务之使用Nginx模式采集日志
本文介绍如何通过日志服务控制台创建Nginx模式的Logtail配置快速采集Nginx日志并进行多维度分析。
目录
打赏
0
0
0
0
42
分享
相关文章
图解MySQL【日志】——Redo Log
Redo Log(重做日志)是数据库中用于记录数据页修改的物理日志,确保事务的持久性和一致性。其主要作用包括崩溃恢复、提高性能和保证事务一致性。Redo Log 通过先写日志的方式,在内存中缓存修改操作,并在适当时候刷入磁盘,减少随机写入带来的性能损耗。WAL(Write-Ahead Logging)技术的核心思想是先将修改操作记录到日志文件中,再择机写入磁盘,从而实现高效且安全的数据持久化。Redo Log 的持久化过程涉及 Redo Log Buffer 和不同刷盘时机的控制参数(如 `innodb_flush_log_at_trx_commit`),以平衡性能与数据安全性。
29 5
图解MySQL【日志】——Redo Log
什么是Apache日志?为什么Apache日志分析很重要?
Apache是全球广泛使用的Web服务器软件,支持超过30%的活跃网站。它通过接收和处理HTTP请求,与后端服务器通信,返回响应并记录日志,确保网页请求的快速准确处理。Apache日志分为访问日志和错误日志,对提升用户体验、保障安全及优化性能至关重要。EventLog Analyzer等工具可有效管理和分析这些日志,增强Web服务的安全性和可靠性。
MySQL日志详解——日志分类、二进制日志bin log、回滚日志undo log、重做日志redo log
MySQL日志详解——日志分类、二进制日志bin log、回滚日志undo log、重做日志redo log、原理、写入过程;binlog与redolog区别、update语句的执行流程、两阶段提交、主从复制、三种日志的使用场景;查询日志、慢查询日志、错误日志等其他几类日志
117 35
MySQL日志详解——日志分类、二进制日志bin log、回滚日志undo log、重做日志redo log
简单聊聊MySQL的三大日志(Redo Log、Binlog和Undo Log)各有什么区别
在MySQL数据库管理中,理解Redo Log(重做日志)、Binlog(二进制日志)和Undo Log(回滚日志)至关重要。Redo Log确保数据持久性和崩溃恢复;Binlog用于主从复制和数据恢复,记录逻辑操作;Undo Log支持事务的原子性和隔离性,实现回滚与MVCC。三者协同工作,保障事务ACID特性。文章还详细解析了日志写入流程及可能的异常情况,帮助深入理解数据库日志机制。
MySQL事务日志-Undo Log工作原理分析
事务的持久性是交由Redo Log来保证,原子性则是交由Undo Log来保证。如果事务中的SQL执行到一半出现错误,需要把前面已经执行过的SQL撤销以达到原子性的目的,这个过程也叫做"回滚",所以Undo Log也叫回滚日志。
123 7
MySQL事务日志-Undo Log工作原理分析
图解MySQL【日志】——Undo Log
Undo Log(回滚日志)是 MySQL 中用于实现事务原子性和一致性的关键机制。在默认的自动提交模式下,MySQL 隐式开启事务,每条增删改语句都会记录到 Undo Log 中。其主要作用包括:
35 0
什么是事件日志管理系统?事件日志管理系统有哪些用处?
事件日志管理系统是IT安全的重要工具,用于集中收集、分析和解释来自组织IT基础设施各组件的事件日志,如防火墙、路由器、交换机等,帮助提升网络安全、实现主动威胁检测和促进合规性。系统支持多种日志类型,包括Windows事件日志、Syslog日志和应用程序日志,通过实时监测、告警及可视化分析,为企业提供强大的安全保障。然而,实施过程中也面临数据量大、日志管理和分析复杂等挑战。EventLog Analyzer作为一款高效工具,不仅提供实时监测与告警、可视化分析和报告功能,还支持多种合规性报告,帮助企业克服挑战,提升网络安全水平。
133 2
什么是日志管理,如何进行日志管理?
日志管理是对IT系统生成的日志数据进行收集、存储、分析和处理的实践,对维护系统健康、确保安全及获取运营智能至关重要。本文介绍了日志管理的基本概念、常见挑战、工具的主要功能及选择解决方案的方法,强调了定义管理目标、日志收集与分析、警报和报告、持续改进等关键步骤,以及如何应对数据量大、安全问题、警报疲劳等挑战,最终实现日志数据的有效管理和利用。
480 0
【日志框架整合】Slf4j、Log4j、Log4j2、Logback配置模板
本文介绍了Java日志框架的基本概念和使用方法,重点讨论了SLF4J、Log4j、Logback和Log4j2之间的关系及其性能对比。SLF4J作为一个日志抽象层,允许开发者使用统一的日志接口,而Log4j、Logback和Log4j2则是具体的日志实现框架。Log4j2在性能上优于Logback,推荐在新项目中使用。文章还详细说明了如何在Spring Boot项目中配置Log4j2和Logback,以及如何使用Lombok简化日志记录。最后,提供了一些日志配置的最佳实践,包括滚动日志、统一日志格式和提高日志性能的方法。
1196 31
【日志框架整合】Slf4j、Log4j、Log4j2、Logback配置模板
AI助理

你好,我是AI助理

可以解答问题、推荐解决方案等