log writer异常引起的数据库宕机分析

潇湘秦

已于 2024-04-10 14:17:29 修改

阅读量880

点赞数 16

文章标签：数据库

于 2024-03-01 17:07:55 首次发布

本文链接：https://blog.csdn.net/xiaofan23z/article/details/136401535

版权

-------------------------------------------------------------------
欢迎关注作者
CSDN：潇湘秦-CSDN博客

公众号：潇湘秦

-------------------------------------------------------------------

前两天一个朋友微信上联系我说，他们那有个库卡死，应用无法连接，OS命令也无法执行，

后面等他们主机重启后，要来了alert log和systemstate dump文件来追踪一下看看是什么原因。

1.alertlog信息分析

先看看alert log，最先看到的是2/28上午开始有tablespace statspack 空间不足的报警

因为这是一套标准版的oracle 12c，之前遇到过性能问题，需要调优所以安装了statspack；

这个问题处理比较简单直接添加数据文件即可，理论上只是一个表空间满应该不会导致系统hang死。

ps：科普一下oracle数据库的license 分为标准版和企业版，价格差别是很大的，有些企业为了节省license会使用标准版本（日、台企，欧美企业为主）

标准版的数据库是没有Tuning Pack和Diagnostics Pack，企业版自带了Tuning Pack和Diagnostics Pack，但是这两个包其实需要额外的license的；

也就是说标准版里大家熟悉的调优工具AWR,ADDM,ASH等都是没有的，只能使用免费的工具statspack ；

而且免费版的statspack需要DBA 自己创建和配置。

后面看alertlog 发现 13:17-15:46没有任何信息，估计这段时间系统是完全卡死了，直到15:46主机重启后的数据库启动信息

在启动日志中看到部分recovery 信息，可以知道当时数据库是直接宕掉了，被异常关闭的。

数据库recovery 之后正常open，随后alertlog 出现如下报错，看样子是redolog 有问题无法写入

在MOS上查到类似的报错信息，MOS上给出的原因是redo log的读写权限问题

朋友给的反馈是最近的变动有两点：1.最近磁盘空间做了扩容；2.增加了网络的IP管控设备

因为无法登陆到oracle 主机，所以无法确定是不是权限问题引起的IO error(但是我估计不是，以为扩容后已经正常运行了很久)

Instance is down ORA-00345 ORA-00312 ORA-27072 Linux-x86_64 Error: 30: Read-only file system (Doc ID 1985774.1)

随后在alertlog中再次报出ORA-00345 ORA-00312 ORA-27072 后实例直接宕机，报错如下

好在异常宕机时系统自动收集了systemstate dump，可供后续分析宕机原因

systemstate dump介绍可参考我如下博文

Oracle systemstate、gdb、dbx介绍 - 墨天轮

检索MOS 可以找到大量相似的案例不过后台进程不同，本案例是LG00(log writer)，如下案例是OFSD （Oracle Flashback Storage Deamon）

案例多数以BUG为主，但是如果要确认是不是BUG 估计要开SR 给oracle support来确认。

2.分析systemstate dump文件

一般以下几种情况会收集systemstate dump

当数据库实例遇到内部错误时：当Oracle数据库实例遇到严重错误时，它通常会自动收集系统状态转储。这些错误可能包括内存损坏、死锁等，系统状态转储有助于分析和诊断问题。如本案例。
当发生故障时：在Oracle数据库中，故障恢复机制会自动收集系统状态转储以帮助诊断故障并尝试恢复数据一致性。
监控进程启动时：在数据库监控进程（MMON、MMNL等）启动时，它们有时会收集系统状态转储以支持数据库性能分析和诊断。
由DBA手动触发：DBA可以手动触发系统状态转储以收集数据库当前的系统状态信息，以便分析数据库性能问题或诊断其他问题。

下面来分析一下 systemstate dump 信息

开头可以看出这是一个level 10的dump 算是一个标准的dump级别

Systemstate levels:

1. level2:dump(不包括lock element)

2. level10:dump

3. level11:dump+global cache of rac --会产生大量的trc，并耗时较久，不建议使用

4. level256:short stack（函数堆栈）

5. _level258:level256+_level2 --可以快速dump 但是会丢失部分锁信息

6. level266:level256+_level10 --较为常用速度较快根据系统负载一般20-60s，收集的信息也足够分析用

7. level267:level256+_level11 --和level11类似耗时久 trc大

因为实例宕机是因为LG00引起的所以先查找LG00进程的信息（trc文件15M 不可能全部看完，只能找关键信息）

*** 2024-02-28 16:21:54.180
PROCESS 16: LG00
  ----------------------------------------
  SO: 0x2b258ace0, type: 2, owner: (nil), flag: INIT/-/-/0x00 if: 0x3 c: 0x3
   proc=0x2b258ace0, name=process, file=ksu.h LINE:13949, pg=0 conuid=0
  (process) Oracle pid:16, ser:1, calls cur/top: 0x2b4671b78/0x2b4671b78
            flags : (0x7) DEAD  icon_uid:0
            flags2: (0x0),  flags3: (0x10) 
            intr error: 0, call error: 0, sess error: 0, txn error 0
            intr queue: empty
    ksudlp FALSE at location: 0
    Cleanup details:
      Found dead = 1 sec ago
      Total Cleanup attempts = 0, Total time = 0 sec,
        Cleanup timer = 0.000000 sec
    (post info) last post received: 0 0 200
                last post received-location: kcrfh.h LINE:5328 ID:kcrfw_slave_queue_insert
                last process to post me: 0x2b65e0cc0 1 6
                last post sent: 0 0 26
                last post sent-location: ksa2.h LINE:290 ID:ksasnd
                last process posted by me: 0x2b65e2310 1 2
                waiter on post event: 0
    (latch info) hold_bits=0x0
    Process Group: DEFAULT, pseudo proc: 0x2b6635df8
    O/S info: user: oracle, term: UNKNOWN, ospid: 3490 (DEAD)   ###可以看到实例宕机时候,ospid的状态已经为dead
    OSD pid info: 
    ----------------------------------------
    SO: 0x2aa1a25e0, type: 13, owner: 0x2b258ace0, flag: INIT/-/-/0x00 if: 0x1 c: 0x1   ###出问题时LG00 操作的文件为两个控制文件一个redo文件 都是对数据库至关重要的文件
     proc=0x2b258ace0, name=FileOpenBlock, file=ksfd.h LINE:7394, pg=0 conuid=0
    (FOB) flags=2050 fib=0x2af4de9b8 incno=0 pending i/o cnt=0
     fname=/appl/oracle/oradata/ORCL/datafile01/ORCL/control02.ctl
     fno=1 lblksz=16384 fsiz=656
    ----------------------------------------
    SO: 0x2aa1a24a0, type: 13, owner: 0x2b258ace0, flag: INIT/-/-/0x00 if: 0x1 c: 0x1
     proc=0x2b258ace0, name=FileOpenBlock, file=ksfd.h LINE:7394, pg=0 conuid=0
    (FOB) flags=2050 fib=0x2af4de500 incno=0 pending i/o cnt=0
     fname=/appl/oracle/oradata/ORCL/datafile01/ORCL/control01.ctl
     fno=0 lblksz=16384 fsiz=656
    ----------------------------------------
    SO: 0x2aa1a0f30, type: 13, owner: 0x2b258ace0, flag: INIT/-/-/0x00 if: 0x1 c: 0x1
     proc=0x2b258ace0, name=FileOpenBlock, file=ksfd.h LINE:7394, pg=0 conuid=0
    (FOB) flags=2050 fib=0x2af4e4270 incno=0 pending i/o cnt=0
     fname=/appl/oracle/oradata/ORCL/onlinelogB/redo04b.log
     fno=0 lblksz=512 fsiz=2097152
    ----------------------------------------
    SO: 0x2b44f5778, type: 4, owner: 0x2b258ace0, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
     proc=0x2b258ace0, name=session, file=ksu.h LINE:13957, pg=0 conuid=0
    (session) sid: 1 ser: 26305 trans: (nil), creator: 0x2b258ace0
              flags: (0x51) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
              flags2: (0x80409) -/-/INC
              DID: 0001-0010-00000002, short-term DID: 0000-0000-00000000
              txn branch: (nil)
              edition#: 0              user#/name: 0/SYS
              oct: 0, prv: 0, sql: (nil), psql: (nil)
              stats: 0x2a5fa68d8, PX stats: 0xc72a8d0
    ksuxds FALSE at location: 0
    service name: SYS$BACKGROUND
    Current Wait Stack:
      Not in wait; last wait ended 14.813654 sec ago 
    There are 42 sessions blocked by this session.    ##这里可以看到关键信息 系统卡死时 该进程blocked 42个session
    Dumping one waiter:
      inst: 1, sid: 687, ser: 14954
      wait event: 'LGWR any worker group'
        p1: ''=0x0
        p2: ''=0x0
        p3: ''=0x0
      row_wait_obj#: 4294967295, block#: 0, row#: 0, file# 0
      min_blocked_time: 222 secs, waiter_cache_ver: 675
    Wait State:
      fixed_waits=0 flags=0x21 boundary=(nil)/-1
    Session Wait History:
        elapsed time of 14.813748 sec since last wait

另外检索系统宕机是的wait event ，统计有library cache lock 83个，而且还block了其他的session

log buffer space 等待5个其中一个 block 27个session

一般来说如果系统长时间hold log buffer space 等待可能是如下两种情况引起

The log buffer in the SGA is too small.
The LGWR process is too slow.

当前的案例应该是因为LG00和LGWR进程异常引起，但是主机内存40GB, SGA 9GB PGA 3GB 也是偏低的可以适当扩大

后记：因为朋友只提供了alert和systemstatedump ，无法登陆到主机和数据库查询主机和数据库的状态，没有OS和数据库相关监控

再加上标准版数据库，很多信息在OS和数据库重启后无法查询，导致系统的根因无法完全确定,只能通过已有的log推测大概是因为log write

进程异常导致的数据库宕机，而且数据库的参数设置也不太合理

-------------------------------------------------------------------------------------

墨天伦，CSDN：潇湘秦转载请注明出处

墨天伦：潇湘秦的个人主页 - 墨天轮
CSDN：潇湘秦-CSDN博客

公众号：潇湘秦的DBA之路

-------------------------------------------------------------------------------------

潇湘秦

关注

16
点赞
踩
25

收藏

觉得还不错? 一键收藏
打赏
0
评论
log writer异常引起的数据库宕机分析

标准版的数据库是没有Tuning Pack和Diagnostics Pack，企业版自带了Tuning Pack和Diagnostics Pack，但是这两个包其实需要额外的license的；ps：科普一下oracle数据库的license 分为标准版和企业版，价格差别是很大的，有些企业为了节省license会使用标准版本（日、台企，欧美企业为主）后记：因为朋友只提供了alert和systemstatedump ，无法登陆到主机和数据库查询主机和数据库的状态，没有OS和数据库相关监控。
复制链接

扫一扫