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 會 話進(jìn) 行整理：
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 分配給進(jìn)程 的標(biāo)準(zhǔn)事件。 當(dāng)會話等待 '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 . 當(dāng)啟用資源管理器并限制 CPU 消耗時會發(fā)生此等待。 為了減少此等待事件的發(fā)生，請?jiān)黾訒挳?dāng)前消費(fèi)組的 CPU 分配 。 |
該等待事件存在的意義是當(dāng)resource manager控制CPU調(diào)度時，需要控制對應(yīng)進(jìn)程暫時不使用CPU而進(jìn)程到內(nèi)部運(yùn)行隊(duì)列中，以保證該進(jìn)程對應(yīng)的consumer group(消費(fèi)組)沒有消耗比指定resource manager指令更多的CPU。此時session就會以” resmgr:cpu quantum ”的名義等待在內(nèi)部運(yùn)行隊(duì)列中，wait一段時間以減少對CPU的爭用，直到再次獲得CPU時該等待事件結(jié)束。
《 11g: Scheduler Maintenance Tasks or Autotasks ( 文檔 ID 756734.1) 》
|
根據(jù)以上說明，可以發(fā)現(xiàn)在 Oracle 11g 中，在默認(rèn)情況下會啟用自動化維護(hù)任務(wù)，數(shù)據(jù)庫會在工作日的每晚 22:00 到第二天的凌晨 2:00 ，周末的凌晨 6:00 到第二天的凌晨 2:00, 自動開啟自動化維護(hù)窗口對數(shù)據(jù)庫進(jìn)行諸如優(yōu)化器的統(tǒng)計(jì)信息收集、自動 SQL 的優(yōu)化。在此期間數(shù)據(jù)庫中便由 resource manager 來控制 CPU 的調(diào)度，啟用資源管理計(jì)劃主要是為了保障維護(hù)窗口內(nèi)的任務(wù)有充分的資源進(jìn)行使用。
從告警日志中可以看出， 4 月 1 日 6:00 啟動自動化維護(hù)窗口的信息：
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 點(diǎn)整開啟自動化維護(hù)窗口 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 《《《啟動相應(yīng)的進(jìn)程 Sun Apr 01 06:00:00 2018 VKRM started with pid=361, OS id=48797 |
那么資源管理計(jì)劃是如何限制資源的呢？ 需要了解 RESOURCE MANAGER 的機(jī)制。
以下當(dāng)前資源管理計(jì)劃所使用 MGMT_P* 的 情況：
在 這 個 資 源管理 計(jì) 劃DEFAULT_MAINTENANCE_PLAN中，主要存在四個CPU使用 組 ： 1. ORA$AUTOTASK_SUB_PLAN 和 ORA$DIAGNOSTICS 實(shí)際 是用于自 動維護(hù) 任 務(wù)的。
2. SYS_GROUP 是 SYS 和 SYSTEM 用 戶 的初始使用者 組，組中的會話都是 sys 或 system 賬號創(chuàng)建的會話。
3. OTHER_GROUPS 用于在活 動資 源 計(jì) 劃之外的所有使用者 組擁 有的會 話，即使其他業(yè)務(wù)用戶及個人用戶的會話。
資 源管理 計(jì) 劃中MGMT_P* 設(shè) 置的百分比 值 并不是一個固定限制的 值 是一個在 資 源 緊張時 的限制 值 ，但在 資 源空 閑時 有可能超出 這 個 值 。
例如，在DEFAULT_MAINTENANCE_PLAN中ORA$AUTOTASK_SUB_PLAN分配了25%，但此 時 如果數(shù)據(jù) 庫 比 較 空 閑 ，SYS_GROUP和OTHER_GROUPS等其他 組 沒有什么 資 源占用，ORA$AUTOTASK_SUB_PLAN 則 可能增 長 到50%，但如果此 時資 源比 較緊張 OTHER_GROUPS 且已 經(jīng) 占用50%以上，ORA$AUTOTASK_SUB_PLAN 則 需下降到25%。
因此，在 這 個 資 源管理 計(jì) 劃中，ORA$AUTOTASK_SUB_PLAN和ORA$DIAGNOSTICS 設(shè) 了MAX_UTILIZATION_LIMIT大使用限制 為 90 。 這樣 即使cpu是空 閑 的， 該組 或 計(jì) 劃也不能分配90%以上的cpu 資 源。
對 于 資 源 計(jì) 劃而言， 為 某個消耗 組 或者子 計(jì) 劃分配的份 額 若沒有使用，就可以被其他的消耗 組 或子 計(jì) 劃使用。
再次分析 這 個 資 源管理 計(jì) 劃DEFAULT_MAINTENANCE_PLAN，SYS_GROUP 優(yōu) 先 級 最高在 級別 1 ，分配75%，在當(dāng) 時 的情況，sys或system 賬 號 創(chuàng) 建的會 話 占用的CPU 資 源并不一定達(dá)到了75%，其剩余的 資 源 則 分配 給級別 2 。在 級別 2 中ORA$AUTOTASK_SUB_PLAN和ORA$DIAGNOSTICS的自 動維護(hù) 任 務(wù) 在 資 源 緊張 的情況下用了30%，而其余70% 則 分配 給 了OTHER_GROUPS的 業(yè)務(wù) 會 話 。
資 源管理 計(jì) 劃中MGMT_P* 設(shè) 置的百分比 值 可以理解 為 依據(jù)CPU個數(shù)的百分比來 計(jì) 算， 這 CPU 個數(shù) 則 來自CPU_COUNT參數(shù) 設(shè) 置的 值 。
在排查的過程中，發(fā)現(xiàn)當(dāng)前數(shù)據(jù)庫的CPU_COUNT僅設(shè)置為8，而實(shí)際上這臺主機(jī)有32個CPU 核數(shù)，64個邏輯CPU。
CPU_COUNT:
實(shí)際CPU Cores及邏輯cpu個數(shù)：
在oracle 官方文檔中已說明CPU_COUNT是依據(jù)CPU cores 的數(shù)量來指定的，并且也說明很多組件包括Resource Manager都是依靠這個cpu個數(shù)的。
這說明了，在資源管理計(jì)劃開啟時，受CPU_COUNT 為8的限制，數(shù)據(jù)庫只能使用到了主機(jī) 32個CPU 核數(shù)中的8個，即為1/4。
分析故障期間主機(jī)的CPU 使用情況，發(fā)現(xiàn)在資源管理計(jì)劃開啟后，CPU使用率逐漸升高，但始終不超過25%，直到9:30后手工禁用了資源管理計(jì)劃，CPU資源被放開，CPU使用率則立即上升到45%左右。
因此，可以看出，資
源管理
計(jì)
劃
打開期間，由于CPU_COUNT的設(shè)置過小，導(dǎo)致了數(shù)據(jù)庫只能最多使用到了主機(jī)25%的CPU資源，并且受以上資源管理計(jì)劃控制CPU機(jī)制的影響，業(yè)務(wù)會話可能只能用到這25% CPU資源中的70%，這就是導(dǎo)致數(shù)據(jù)庫在4月1日高峰期時數(shù)據(jù)庫達(dá)到了CPU了資源瓶頸的原因。
重慶分公司
重慶分公司
