匪夷所思:罕见的 Oracle 全局事务锁等待事件分析

杨廷琨,云和恩墨CTO,Oracle ACED,ITPUB Oracle 数据库管理版版主 ,人称"杨长老”,十数年如一日坚持进行Oracle技术研究与写作,号称"Oracle的百科全书”,迄今已经在自己的博客上发表了超过3000篇技术文章。与 Eygle 共同主编出版了多本《Oracle DBA手记》系列图书。

此次大会杨长老分享的主题是“深入内核-Oracle双活架构和踩坑案例实战”,来听杨老师分享架构,看他如何巧妙地处理雷区。

这是在某客户现场的一次即时分析,这个问题困扰了用户一段时间,数据库体现为严重的性能问题,导致应用出现大范围超时以及会话激增等问题,多次尝试 kill session 都无法彻底解决问题,重启后系统恢复正常。

拿到故障时刻的 AWR 报告,可以发现问题时刻,数据库的主要等待为:

Global transaction acquire instance locks enq: TX - row lock contention。

Event

Waits

Time(s)

Avg wait (ms)

% DB time

Wait Class

Global transaction acquire instance locks

5,342

5,343

1000

74.09

Configuration

enq: TX - row lock contention

5

1,437

287308

19.92

Application

DB CPU

331

4.59

direct path read

37,708

72

2

0.99

User I/O

log file sync

7,817

12

2

0.16

Commit

其中 TX – row lock contention 等待十分常见,这个等待事件造成应用的阻塞也很容易理解,但是Global transaction acquire instance locks并不是常见等待,从字面上理解,是全局事务在尝试获取实例锁。这个等待在等待时间占比上,消耗了将近75%的DB TIME。

当然数据库中TOP 5中最严重的等待不一定是问题的根源,分析问题时刻的 ASH 信息,在问题时刻,最先出现的是全局事务获取锁的等待,随后开始出现行锁等待:

SQL> select to_char(sample_time, 'hh24miss'), session_id, event, blocking_session 2 from dba_hist_active_sess_history 3 where sample_time >= to_date('201810180652', 'yyyymmddhh24mi') 4 and sample_time <= to_date('201810180700', 'yyyymmddhh24mi') 5 and instance_number = 1 6 order by 1, 2;

首先出现问题的是会话 763,其处于Global transaction acquire instance locks等待中,该会话并未显示被其他会话阻塞。之后开始出现了行锁等待,这些等待enq: TX - row lock contention的会话,其阻塞对象都是会话763。

显然在本次故障中,虽然最终导致大范围业务挂起的是enq: TX - row lock contention等待,但是最终问题的根源是Global transaction acquire instance locks等待。

几乎与此同时,后台告警日志出现大量的报错:

Thu Oct 18 06:53:33 2018 opiodr aborting process unknown ospid (26428) as a result of ORA-24756 Thu Oct 18 06:53:36 2018 Errors in file /trace/orcl1_pmon_30688.trc: ORA-24756: transaction does not exist Errors in file /trace/orcl1_pmon_30688.trc: ORA-24756: transaction does not exist Errors in file /trace/orcl1_pmon_30688.trc: ORA-24756: transaction does not exist Errors in file /trace/orcl1_pmon_30688.trc: ORA-24756: transaction does not exist

数据库中出现该等待的时间点 06:52,再考虑到等待在报错前会经历一个超时,因此数据库中的等待与告警日志中的 ORA-24756 错误有密切的关系。

以 ORA-24756 作为关键字查询 MOS,可以找到与当前现象非常接近的文章:

PMON cleanup fails with ORA-24756: transaction does not exist (文档 ID 2299927.1)。

文档中描述的报错现象与当前问题一致,且数据库版本也很接近。Oracle认为这个错误是由于PMON进程在清理不存在的事务时出现了卡住的现象

Oracle给出了几个比较类似的bug,但是这些bug的状态不是不可重现就是已中止,因此类似的问题并没有明确的结论:

Bug 20676168 - PMON GOT CONTINUOUS ORA-24756 DURING SHUTDOWN <<<<<<<<<< Closed, Could Not Reproduce Bug 16317766 - EXADATA : ORA-24756: TRANSACTION DOES NOT EXIST <<<<<<<<<<<< Suspended, Req'd Info not Avail Bug 9757979 - PMON CLEANUP FAILS WITH ORA-24756: TRANSACTION DOES NOT EXIST <<<<<<<<<<< Closed, Could Not Reproduce

无论是Global transaction acquire instance locks等待还是后台alert日志中不断出现的ORA-24756错误,问题都指向Oracle的锁和全局事务处理。

而从11g以后,RAC的全局事务的处理由后台进程GTXn来自动维护。该进程是否启动受初始化参数 global_txn_processes 的控制,该参数默认值为1,也就是在数据库启动的时候会默认启动GTXn进程。

询问客户近期是否进行过应用和数据库的调整,可以确认的是客户的应用程序并未发生任何变化,在之前也未出现过类似的问题,不过在出现问题之前,数据库做过主库和Data Guard备库之间的切换演练,而切换演练完成后,恢复正常业务时,就出现了这次故障。显然这次切换演练的操作是被怀疑的重点

在详细检查了alert告警日志后发现,在DATA GUARD演练后切换回主库时,GTXn进程未启动:

Thu Oct 18 02:36:18 2018 alter database commit to switchover to physical standby with session shutdown ALTER DATABASE COMMIT TO SWITCHOVER TO PHYSICAL STANDBY [Process Id: 4366] (orcl1) . Switchover: Primary controlfile converted to standby controlfile succesfully. Switchover: Complete - Database shutdown required Completed: alter database commit to switchover to physical standby with session shutdown Thu Oct 18 02:45:27 2018 . RFS[8]: Assigned to RFS process 3216 RFS[8]: Identified database type as 'physical standby': Client is ARCH pid 11990 Thu Oct 18 03:11:13 2018 alter database open AUDIT_TRAIL initialization parameter is changed to OS, as DB is NOT compatible for database opened with read-only access This instance was first to open Beginning standby crash recovery. Serial Media Recovery started . Thu Oct 18 03:11:13 2018 SMON: enabling cache recovery Dictionary check beginning Dictionary check complete Database Characterset is ZHS16GBK No Resource Manager plan active Starting background process GTX0 Thu Oct 18 03:11:14 2018 GTX0 started with pid=51, OS id=5041 replication_dependency_tracking turned off (no async multimaster replication found) Physical standby database opened for read only access. Completed: alter database open . Thu Oct 18 04:57:19 2018 alter database commit to switchover to primary with session shutdown ALTER DATABASE SWITCHOVER TO PRIMARY (orcl1) Maximum wait for role transition is 15 minutes. Switchover: Media recovery is still active Role Change: Canceling MRP - no more redo to apply . Switchover: Complete - Database mounted as primary Completed: alter database commit to switchover to primary with session shutdown Thu Oct 18 04:57:39 2018 alter database open This instance was first to open Picked broadcast on commit scheme to generate SCNs . Thu Oct 18 04:57:44 2018 QMNC started with pid=41, OS id=22585 LOGSTDBY: Validating controlfile with logical metadata LOGSTDBY: Validation complete Completed: alter database open . Thu Oct 18 06:53:33 2018 opiodr aborting process unknown ospid (26428) as a result of ORA-24756 Thu Oct 18 06:53:36 2018 Errors in file /trace/orcl1_pmon_30688.trc: ORA-24756: transaction does not exist Errors in file /trace/orcl1_pmon_30688.trc: . Starting background process GTX0 Thu Oct 18 09:51:20 2018 GTX0 started with pid=36, OS id=32470 Starting background process RCBG Thu Oct 18 09:51:20 2018

从上面节选的部分alert日志可以看到,在2点36分,主库执行了SWITCHOVER操作,开始切换演练。

  • 3点11分,数据库打开,alert中提示,当前数据库为物理备库,为只读打开模式,在随后的日志中标红的部分,显示此时后台进程GTX0进程启动。
  • 4点57分,数据库再次执行SWITCHOVER切换,此时数据库并未完全SHUTDOWN,而是直接转换为MOUNT模式,并于4点57分44秒完成了数据库的OPEN过程。但是这个时间段的alert中并未发现GXTn进程的启动。
  • 而在alert中发现GTX0进程再次出现,是故障之后实例1重启时刻的9点51分

显然,问题已经非常明确,在数据库由物理备库切换为主库的过程中,GTXn进程没有启动,这导致了Oracle无法处理分布式事务的锁问题,因此前台会话出现Global transaction acquire instance locks等待,而后台PMON也无法正常的清理会话和事务。

由于实例2在SWITCHOVER切换过程中是被SHUTDOWN后重新启动的,因此实例2上的GTXn进程是正常启动的,这也是应用切换到实例2上不在出现故障的原因。

如果要避免类似的问题产生,一方面在进行DATA GUARD的切换演练后,在主库切换到PRIMARY模式后,再执行一次数据库重启的操作,确保所有必要的进程都会启动。另一方面,对于应用程序,如果确实需要修改其他数据库中的表,应该通过建立其他数据库连接的方式来实现,避免在数据库中通过数据库链的方式直接更新远端表。

这个案例给我们的警示是:

数据库的工作非常紧密,不同版本的变化也不断向前,了解数据库不同版本的新特性,在进行变更时进行详细的检查确认,才能确保数据库安全稳定运行,少出问题。

原文发布于微信公众号 - 数据和云(OraNews)

原文发表时间:2018-11-11

本文参与腾讯云自媒体分享计划,欢迎正在阅读的你也加入,一起分享。

发表于

我来说两句

0 条评论
登录 后参与评论

相关文章

来自专栏张戈的专栏

HTTP加速器varnish安装小记(1)

上午共享的那个varnish 安装手册,个人看了下,有点不知所云,好吧~看来还是先安装玩玩! 苦逼公司服务器没法连外网,不能用什么 wget 或 yum 命令直...

41480
来自专栏FreeBuf

XSS的原理分析与解剖:第三章(技巧篇)

作者 Black-Hole 0×01 前言: 关于前两节url: 第一章:http://www.freebuf.com/articles/web/40520....

21070
来自专栏杨建荣的学习笔记

运维平台的建设思考-元数据管理(四)(r8笔记第16天)

对于服务器的一些信息,如果数据量大了之后总是感觉力不从心,需要了解,但是感觉得到的这些信息不够清晰明了。 比如我们得到一台服务器,需要知道最基本的硬件配置,内存...

405150
来自专栏流媒体

Linux下ndk编译移植FFmpeg到Android平台(二)——集成x264和libfdk-aac

在前面的Linux下ndk编译移植FFmpeg到Android平台文章中介绍了如何将最基本的FFmpeg到Android平台。但只是简单的移植了FFmpeg,没...

36280
来自专栏知识分享

八,ESP8266 文件保存数据(基于Lua脚本语言)

应该是LUA介绍8266的最后一篇,,,,,,下回是直接用SDK,,然后再列个12345.......不过要等一两个星期,先忙完朋友的事情 前面几篇 用AT指令...

41470
来自专栏Golang语言社区

社区leaf学习笔记|07. 游戏玩家注册、登陆(下)

Leaf服务器返回给H5的JSON消息结构 文件位置:server\login\internal\handler.go

10810
来自专栏杨建荣的学习笔记

恢复控制文件避免使用resetlogs选项 (r10笔记第12天)

在搭建Data Guard的时候,我们可以直接从主库生成一个备库控制文件,或者拷贝一个备库的控制文件即可,后续的工作就交给Data Guard来自动恢复...

32740
来自专栏.NET技术

.net core实践系列之短信服务-Sikiro.SMS.Job服务的实现

本篇会继续讲解Sikiro.SMS.Job服务的实现,在我写第一篇的时候,我就发现我当时设计的架构里Sikiro.SMS.Job这个可以选择不需要,而使用MQ代...

10720
来自专栏杨建荣的学习笔记

曲折的10g,11g中EM的安装配置过程(r4笔记第98天)

今天在本地搭了一套oracle环境,首先安装数据库的时候顺带了EM,结果安装好之后想修改监听器的端口,把原本15521的端口换成别的,结果在目录中修改了几个参数...

28930
来自专栏kl的专栏

Activiti工作流杂谈-工作机制详解

以下内容为博主在公司内部分享的一个小文档,谈到了activiti的各方面内容,有需要的可留言要word原文件 

90990

扫码关注云+社区

领取腾讯云代金券