扫二维码与项目经理沟通
我们在微信上24小时期待你的声音
解答本文疑问/技术咨询/运营咨询/技术建议/互联网交流
Chains most likely to have caused the hang: 《《《最 终 阻塞源都是由于 resmgr:cpu quantum 引起。 [a] Chain 1 Signature: ' resmgr:cpu quantum '<='buffer busy waits'<='buffer busy waits'<='enq: TX - index contention' Chain 1 Signature Hash: 0xe7466825 [b] Chain 2 Signature: ' resmgr:cpu quantum '<='buffer busy waits' Chain 2 Signature Hash: 0x23972dee [c] Chain 3 Signature: ' resmgr:cpu quantum '<='buffer busy waits' Chain 3 Signature Hash: 0x23972dee ==================================================================== Chain 1: ------------------------------------------------------------------------------- Oracle session identified by: { instance: 1 (jfdb.jfdb1) os id: 78941 process id: 1240, oracle@XXX-JF-DB03 session id: 22 <<<< session 22 session serial #: 32445 } is waiting for 'enq: TX - index contention' with wait info: { p1: 'name|mode'=0x54580004 p2: 'usn<<16 | slot'=0x1cb0015 p3: 'sequence'=0xf3fa7 time in wait: 0.122389 sec timeout after: never wait id: 199367 blocking: 0 sessions wait history: * time between current wait and wait #1: 0.000318 sec ……… } and is blocked by <<<< 被阻塞 => Oracle session identified by: { instance: 1 (jfdb.jfdb1) os id: 1349 process id: 2756, oracle@XXX-JF-DB03 session id: 3320 <<< session serial #: 3849 } which is waiting for ‘buffer busy waits’ with wait info: { p1: ‘file#’=0x8c p2: ‘block#’=0x286540 p3: ‘class#’=0x1 time in wait: 0.218850 sec timeout after: never wait id: 51286
blocking: 58 sessions wait history: ………. }
and is blocked by <<<<
被阻塞 => Oracle session identified by: { instance: 1 (jfdb.jfdb1) os id: 3182 process id: 2975, oracle@XXX-JF-DB03
session id: 5658 << session serial #: 181 } which is waiting for 'buffer busy waits' with wait info: { p1: 'file#'=0x8c p2: 'block#'=0x285b1f p3: 'class#'=0x1 time in wait: 0.219271 sec timeout after: never wait id: 38737
blocking: 63 sessions wait history:
。。。。。。 }
and is blocked by<<<<
被阻塞 => Oracle session identified by: { instance: 1 (jfdb.jfdb1) os id: 27602 process id: 2384, oracle@XXX-JF-DB03
session id: 334
《《《session 334 session serial #: 757 } which is waiting for 'resmgr:cpu quantum' with wait info: { p1: 'location'=0x2 p2: 'consumer group id'=0x3259 p3: ' '=0x0 time in wait: 0.040860 sec timeout after: never wait id: 95941
blocking: 114 sessions wait history:
。。。。。。。 } Chain 1 Signature: 'resmgr:cpu quantum'<='buffer busy waits'<='buffer busy waits'<='enq: TX - index contention' Chain 1 Signature Hash: 0xe7466825 |
对 以上 hanganalyze 会 话进 行整理：
session : 334 同 时 阻塞114个会 话 | 阻塞了》 | session : 5658 同 时 阻塞63个会 话 | 阻塞了》 | session : 3320 同 时 阻塞 58 个会 话 | 阻塞了》 | session id: 22 |
resmgr:cpu quantum | buffer busy waits | buffer busy waits | enq: TX - index contention |
从以上 hanganalyze 日志可以看出， enq: TX - index contention 和 buffer busy waits 的等待堆积最终的源头是由于 resmgr:cpu quantum 等待引起，并且这些等待同时又阻塞了多个其他会话。
以下从文档 ID 2097889.1 可以获得该等待事件的说明：
《 WAITEVENT: "resmgr:cpu quantum" Reference Note ( 文档 ID 2097889.1) 》 · Event 'resmgr: cpu quantum' is a standard event used by resource manager to control the allocation of CPU to processes . When a session waits for 'resmgr: cpu quantum' that session is waiting to be allocated a quantum of CPU time. 等待事件 'resmgr ： cpu quantum' 是 资源管理器用来控制 CPU 分配给进程 的标准事件。 当会话等待 'resmgr ： cpu quantum' 时， 会话正在等待分配一个 CPU 时间额度 。 This wait occurs when the resource manager is enabled and is throttling CPU consumption. To reduce the occurrence of this wait event, increase the CPU allocation for the session's current consumer group . 当启用资源管理器并限制 CPU 消耗时会发生此等待。 为了减少此等待事件的发生，请增加会话当前消费组的 CPU 分配 。 |
该等待事件存在的意义是当resource manager控制CPU调度时，需要控制对应进程暂时不使用CPU而进程到内部运行队列中，以保证该进程对应的consumer group(消费组)没有消耗比指定resource manager指令更多的CPU。此时session就会以” resmgr:cpu quantum ”的名义等待在内部运行队列中，wait一段时间以减少对CPU的争用，直到再次获得CPU时该等待事件结束。
《 11g: Scheduler Maintenance Tasks or Autotasks ( 文档 ID 756734.1) 》
|
根据以上说明，可以发现在 Oracle 11g 中，在默认情况下会启用自动化维护任务，数据库会在工作日的每晚 22:00 到第二天的凌晨 2:00 ，周末的凌晨 6:00 到第二天的凌晨 2:00, 自动开启自动化维护窗口对数据库进行诸如优化器的统计信息收集、自动 SQL 的优化。在此期间数据库中便由 resource manager 来控制 CPU 的调度，启用资源管理计划主要是为了保障维护窗口内的任务有充分的资源进行使用。
从告警日志中可以看出， 4 月 1 日 6:00 启动自动化维护窗口的信息：
Current log# 6 seq# 23750 mem# 0: +DG_DATA/jfdb/onlinelog/group_6.279.909112437 Sun Apr 01 05:51:29 2018 Archived Log entry 46019 added for thread 1 sequence 23749 ID 0x4d5ab97e dest 1: Sun Apr 01 06:00:00 2018 《《《《 6 点整开启自动化维护窗口 Setting Resource Manager plan SCHEDULER[0x32DF]:DEFAULT_MAINTENANCE_PLAN via scheduler window Setting Resource Manager plan DEFAULT_MAINTENANCE_PLAN via parameter Sun Apr 01 06:00:00 2018 Starting background process VKRM 《《《启动相应的进程 Sun Apr 01 06:00:00 2018 VKRM started with pid=361, OS id=48797 |
那么资源管理计划是如何限制资源的呢？ 需要了解 RESOURCE MANAGER 的机制。
以下当前资源管理计划所使用 MGMT_P* 的 情况：
在 这 个 资 源管理 计 划DEFAULT_MAINTENANCE_PLAN中，主要存在四个CPU使用 组 ： 1. ORA$AUTOTASK_SUB_PLAN 和 ORA$DIAGNOSTICS 实际 是用于自 动维护 任 务的。
2. SYS_GROUP 是 SYS 和 SYSTEM 用 户 的初始使用者 组，组中的会话都是 sys 或 system 账号创建的会话。
3. OTHER_GROUPS 用于在活 动资 源 计 划之外的所有使用者 组拥 有的会 话，即使其他业务用户及个人用户的会话。
资 源管理 计 划中MGMT_P* 设 置的百分比 值 并不是一个固定限制的 值 是一个在 资 源 紧张时 的限制 值 ，但在 资 源空 闲时 有可能超出 这 个 值 。
例如，在DEFAULT_MAINTENANCE_PLAN中ORA$AUTOTASK_SUB_PLAN分配了25%，但此 时 如果数据 库 比 较 空 闲 ，SYS_GROUP和OTHER_GROUPS等其他 组 没有什么 资 源占用，ORA$AUTOTASK_SUB_PLAN 则 可能增 长 到50%，但如果此 时资 源比 较紧张 OTHER_GROUPS 且已 经 占用50%以上，ORA$AUTOTASK_SUB_PLAN 则 需下降到25%。
因此，在 这 个 资 源管理 计 划中，ORA$AUTOTASK_SUB_PLAN和ORA$DIAGNOSTICS 设 了MAX_UTILIZATION_LIMIT大使用限制 为 90 。 这样 即使cpu是空 闲 的， 该组 或 计 划也不能分配90%以上的cpu 资 源。
对 于 资 源 计 划而言， 为 某个消耗 组 或者子 计 划分配的份 额 若没有使用，就可以被其他的消耗 组 或子 计 划使用。
再次分析 这 个 资 源管理 计 划DEFAULT_MAINTENANCE_PLAN，SYS_GROUP 优 先 级 最高在 级别 1 ，分配75%，在当 时 的情况，sys或system 账 号 创 建的会 话 占用的CPU 资 源并不一定达到了75%，其剩余的 资 源 则 分配 给级别 2 。在 级别 2 中ORA$AUTOTASK_SUB_PLAN和ORA$DIAGNOSTICS的自 动维护 任 务 在 资 源 紧张 的情况下用了30%，而其余70% 则 分配 给 了OTHER_GROUPS的 业务 会 话 。
资 源管理 计 划中MGMT_P* 设 置的百分比 值 可以理解 为 依据CPU个数的百分比来 计 算， 这 CPU 个数 则 来自CPU_COUNT参数 设 置的 值 。
在排查的过程中，发现当前数据库的CPU_COUNT仅设置为8，而实际上这台主机有32个CPU 核数，64个逻辑CPU。
CPU_COUNT:
实际CPU Cores及逻辑cpu个数：
在oracle 官方文档中已说明CPU_COUNT是依据CPU cores 的数量来指定的，并且也说明很多组件包括Resource Manager都是依靠这个cpu个数的。
这说明了，在资源管理计划开启时，受CPU_COUNT 为8的限制，数据库只能使用到了主机 32个CPU 核数中的8个，即为1/4。
分析故障期间主机的CPU 使用情况，发现在资源管理计划开启后，CPU使用率逐渐升高，但始终不超过25%，直到9:30后手工禁用了资源管理计划，CPU资源被放开，CPU使用率则立即上升到45%左右。
因此，可以看出，资
源管理
计
划
打开期间，由于CPU_COUNT的设置过小，导致了数据库只能最多使用到了主机25%的CPU资源，并且受以上资源管理计划控制CPU机制的影响，业务会话可能只能用到这25% CPU资源中的70%，这就是导致数据库在4月1日高峰期时数据库达到了CPU了资源瓶颈的原因。
我们在微信上24小时期待你的声音
解答本文疑问/技术咨询/运营咨询/技术建议/互联网交流
微信二维码
移动版官网