02DBLINK分布式事務(wù)失敗又遭遇RAC熱點(diǎn)塊爭(zhēng)用

DBLINK分布式事務(wù)失敗又遭遇RAC熱點(diǎn)塊爭(zhēng)用某天下午16點(diǎn)左右，該案例中的數(shù)據(jù)庫(kù)出現(xiàn)嚴(yán)重性能故障，主要表現(xiàn)為大量業(yè)務(wù)SQL無(wú)法正常運(yùn)行，同時(shí)訂單表無(wú)法正常插入數(shù)據(jù)，嚴(yán)重影響業(yè)務(wù)的正常運(yùn)行。最終通過(guò)重啟數(shù)據(jù)庫(kù)并開(kāi)啟一個(gè)節(jié)點(diǎn)運(yùn)行后，恢復(fù)正常。故障分析以下是截取問(wèn)題時(shí)段(16:00-17:00)crm2db兩節(jié)點(diǎn)AWR報(bào)告部分信息：節(jié)點(diǎn)1上DBTime是Elapsed時(shí)間的211倍，說(shuō)明節(jié)點(diǎn)1處于極其繁忙的狀態(tài)。而節(jié)點(diǎn)2上DBTime/Elapsed時(shí)間更是達(dá)到了276倍，遠(yuǎn)遠(yuǎn)高于數(shù)據(jù)庫(kù)可用CPU數(shù)128,同樣說(shuō)明節(jié)點(diǎn)2處于非常繁忙的狀態(tài)。大量的會(huì)話都處于等待狀態(tài)，大量的事務(wù)被掛起，數(shù)據(jù)庫(kù)實(shí)例處于不可用狀態(tài)。從TOP5等待事件來(lái)看，節(jié)點(diǎn)1的等待事件為:EventWaitsTimefs)Avgwart{ms)%DBtinK恤itClassenq:TX-contention19,006196,835103562&.71□tM「gcsuffersusyrelease193,824V9.08792423.39CJli引苗enq:TX-allocateITLentr^57.472125,173217S16.35ConfigurationDECPU53,335|gcsuffer:usyacquire332,03144,544|1171&.32Clust/「節(jié)點(diǎn)2的等待事件為:EventWaitsTimefs)Avgwait{ms)WaitClassgcaufferbusyacquire'305,410272,1704502716Clu閔日「enq:TX-allocateITLentr/123,916265,912214626.54Configurationenq:TX-contention22,201227,25510^3622.68Othergcoufferbusyrelea.se107.46993,9398749.38Cluster心filesequentialread4.955,73235,51273,55UserI/O兩個(gè)節(jié)點(diǎn)等待基本一致，大量的gc及tx相關(guān)等待，同時(shí)平均等待時(shí)間均處于幾百，上千甚至上萬(wàn)毫秒，這是數(shù)據(jù)庫(kù)正常運(yùn)行所無(wú)法忍受的。在11g中將gcbufferbusy分為gcbufferbusyacquire和gcbufferbusyrelease,其中前者是當(dāng)sessionl嘗試請(qǐng)求訪問(wèn)遠(yuǎn)程實(shí)例buffer，但是在sessionl之前已經(jīng)有相同實(shí)例上另外一個(gè)session2請(qǐng)求訪問(wèn)了相同的buffer，并且沒(méi)有完成，那么sessionl需要等待gcbufferbusyacquire。而后者是在sessionl之前已經(jīng)有遠(yuǎn)程實(shí)例的session2請(qǐng)求訪問(wèn)了相同的buffer，并且沒(méi)有完成，那么sessionl需要等待gcbufferbusyrelease。這通常是由于同一數(shù)據(jù)在不同數(shù)據(jù)庫(kù)實(shí)例上被請(qǐng)求訪問(wèn)，特別是在通過(guò)兩個(gè)節(jié)點(diǎn)頻繁執(zhí)行并發(fā)插入導(dǎo)致。而本次故障我們通過(guò)分析相關(guān)性能數(shù)據(jù)，可以看到問(wèn)題時(shí)段如下大量gc等待發(fā)生在insertorder_list視圖上（該視圖對(duì)應(yīng)的基表為customer_order訂單表）。

T：KESIDE_3IDEVEXTJKAYESQL_IDSQL_TEXT15:59=50,121780sctu￡￡erbusyacquire5156ajj2p23hsinsert￡nt-o0RDER_LIST』15=59=5&12160-70730scbufferbusyacquireO5siLz5ziriFq9kinsertinto0RDER_LIST』16:00=03.19B137S0宇buffertusyacquire05zziLE5zdzTq9kinsertintoORDER_LLST』lEzOTzOa.1931037S0ectuffertus7acquire0SziiESziiz^rqSkinsertinto0RDER_LE3T』16:00:03.19S104790scbuf￡ertusyacquire5155ajj2p2Shein-aertint-QORDER_LIST<16:00=06.19S170780zctufferhu.syacquire5156ajj2p23hsinsextint-n0RDER_LI5T』16:00:09.1937S1730ecbufferbusyacquire515eajj2p23hzinsertinto0RDER_LIST』16:00:03.1937977B0穿buffs?busyacquire□15Gajj2p23heinsertintc0EDER_LZ5T‘ie：oo：oa.13S9297S0ecbuffertu37acquire□155ajj2p2Sheinsertinto0RDER_LI5T』16:00:08.19B919730bctuf￡ertusyacquireC5z:nE5ziirrq9kinssTtinto0RDER_LIST』16:00=06.1989337S0zctuffertusyacquire515fiajj2p23hginsextint-o0RDER_LIST』ifi：oo：oa.iaa9637aoschufferbusyacquire05su.E3ziorq9kinsertint-o0RLER_LIST』16:00:03.97S7B&ecbufferbusyacquire05z.iLESzizTq9kin.3ertinto0RDE-R_LI5T』16:W:0a.1333S27S0tuf￡ettus7acquire□15e.ajj2p2Sheinsertint-DORDER_LEST<16:00=08.19B11237&0gctuf￡ertusyacquire24-Tjc7zfaz5nibctinsertint-oORDER_LIST』16:00:03.挪1371730空buffertusyacquirA24n7zbzi.Tiitctinseitintc0RIiER_L-5r■16:00:08.19a15497S0scbufferbusyacquire5156ajj2p23hEinsertinto0RDER_LIST^-'---此處省略大量類似輸出同時(shí)從awr中同樣可以看到問(wèn)題時(shí)段gc爭(zhēng)用最為嚴(yán)重的為訂單表中的索引IDX_ORDER_LIST_OLNBR_1，該索引為右向增長(zhǎng)的數(shù)值索引，近一半的gc爭(zhēng)用發(fā)生在該索引上。OWMYTablespociBNameSut>DbiKlMarne|Obf.Type|GCBulterBusy(rlOtpEuroIGTQ.JNST7BS_ID^NS7223.757Te5-_D-t<_GEPITR^Cr.iHTl^SCTiQr^-LQt.If峭LE跑代.gg_l日STT&S=_DAT<JNSTCWSTOM￡R_qRDER|1ASLE72.Df331502C￡P(guān)Te$_DATA_CEPl&Xjr-JTEft-^TIQN.LQGJ.ISGSTATEIlNDEX57.515；11MCR'.l_iPPTBSLSITU泓pX_CRMJhJF_LQS_1507?1USDEX9.?41.74|接下來(lái)對(duì)于TX等待中的enq:TX-allocateITLentry事務(wù)槽分配的等待，該等待通常發(fā)生在DML并發(fā)操作頻繁的對(duì)象，可以看到問(wèn)題時(shí)段大量該等待同樣發(fā)生在如下insert訂單表上。

TIKESIDKiDEYINT_NAMEjfiL.ID3QL_IW15-59-53.1S1534fianq：H-allncatsITLai^+ryjj2p23hgirnii-tintoORnElt_LIET+姑皿皿也5E2G2321的玲：TI-2Lll-DC2.tqITLactry￡156ajj2p23kgimirt￡ntoORDER_LI815:59:53.121E￡li場(chǎng)g:TI-^ILacatQITLMtryO^nu^Emciorq^lcLiis-arlinto0RDER_LI2T416:00:03.1的涌1765沖：TI.-a.ll-7-ca.teITLentryO-^iiugEmc.K^aG'kxussirtinto0RDER_LI5Th15:00：｛?.19SEQ3□7&5erq：TI-^.113-ca.teITLentry51S6d.JJ2p23h§insectintoOfWEK_LIST+ie.00.0-3.ifiaE34Z31flenq：TZ-alld-caleITLentry5156ajj2p23hginssrlintoORLEK_LIST+74713eoq：Il-aiLocateITLentry515&ajj2p￡3hgimsartintoORDHR_LI5T*!E：OT：0-3.1S9"FeEq：TX-allocateITLEntry515&ajJ2pZ3h*LKEertinto€ftDER_LI5T+16:00:03.158933erq：II-allocateITLentryOSmigSmcsnraSLinaartisitaORDER_LIST+|16：00：03.1SS1S26455皿i：TI-allacat-eITLentry5156ajj2p23hsinsertin-toCRDEK_LIST16:00:08..19S對(duì)2358&3*T5-alla-cst-eITLentryOsTiuffSnidirpqSIcinsertinio0RUE135T-00:03.2134i467哄：TI-allac-ja"tqITLsntryEl5￡a.jJ2p23kjiziaarlint&ORUEU_LIET16-00:0-3q：TI-allacst-GiITLentry5156fl.jj2p22hjiansariintoCRI]ER_LIE---此處省略大量類似輸出而針對(duì)問(wèn)題時(shí)段出現(xiàn)的大量enq:TXcontention等待，通過(guò)相關(guān)性能數(shù)據(jù)的分析，看到大量業(yè)務(wù)SQL被sid為1969的會(huì)話所阻塞，而1969號(hào)進(jìn)程是oracle的RECO后臺(tái)進(jìn)程，簡(jiǎn)單說(shuō)該進(jìn)程負(fù)責(zé)處理失敗的分布式事務(wù)。而如果分布式事務(wù)失敗，在恢復(fù)處理過(guò)程中則會(huì)阻塞分布式事務(wù)中涉及表的查詢及DML操作?？梢钥吹饺缦聠?wèn)題時(shí)段大量正常會(huì)話被RECO進(jìn)程阻塞。二YE5ZDEiZL5QL_ZE-:&L二EXT15:59:56.653eo;a1363&nq：7X一eentGnticn幼。厘了上.*云6ITDA7EC7G_Z：G7/15:59:56.653she1363&nq：~X-cententisn33^d；l?:73trS7y5ELECT；1J卜7561325196^enqzTX-c-n-ntenti-dub6sq0je6d_2thfsslectb-o.bo_Hct*'16:OT:-06.75613231969enq：TX-c-n-ntenti-du8I36skklrScf'9ilsslectC-DUJlt(1)16:OT：-06.7561澎13S9&n4：IE-:=nt&nti:n5?8njs&dx.q.jtt3：三ELE二SLV二；卜7561374enq：TS-c-o-ntent￡-an■BxLCgSyjx^2-5F5G-irr-A：Ec7G_：y：7.*j16：O<｝：-06.756盤(pán)宮196^enqZTX-c-o-ntenti-anSncEtJmq寫(xiě)S6LFDA7EUG二W：16：OT：-06.75613S9wnq：~X-：intentisn;;kutpr3ut；p72IN3EETIXT030.&1L6：g：循,75fi3垢￡自nq：7X一mntEnSEINGEETIXTQ30.tl16:OT:-06.7562859196^enq：TK—c-c-ntenti-dudBbO'srcdwnjrexf興"混rc=7z?;c:Jie：OJ；:Oe.75S瀏31363&nq：~X-eentGnticnf37viu2nlhhh6sslectb-a.*'_e；o?；ce.7562332*濘自nq：:K-;?nt^ntisn&5n7tEf9dd.77aGselectBunt(尊)*'16:00:-06.7563073196^enqzTX-c-Es-ntenti-duF37'.^u2nlh｝ih6sslectb-D.stats^-1---此處省略大量類似輸出

二旺三E三二壬_IDFRAGPAYlewoeL9S3■oracle^cTzzZibl:既郁泰leccieiseaoracle^cTuZiibl:EK*LSGC27L9S3oracle^ciziZiibl；既匚招甲16^371353勺le^CTZZ^ilbl:晾"1&0047L9SD勺le@cizz2ibl:REUM16W57L3S3oracl@?CTn2ibl:EK*100107.353■匚m匚le@cj^2d.bl:E￡3；z1&0117L9S3oracIs^cTzzZibl:REZW1&0127igeaorac1巨色工2dM:EE3；#---此處省略大量類似輸出同時(shí)，我們進(jìn)一步從告警日志發(fā)現(xiàn)在7月2日下午開(kāi)始，存在十幾次由于遠(yuǎn)端數(shù)據(jù)庫(kù)問(wèn)題，導(dǎo)致分布式事務(wù)失敗的告警信息，以下列舉距離問(wèn)題時(shí)段最近的一次告警信息如下：rtuJu.10215:5-0:^2015*JErrar1013-tTapjGdin2FCtramsaitiM4?5.13.25St7S0.Cleaningrp.ErrcrstackzeturnedttruseiZ+J□RJH02053:事務(wù)劉理435.13.25S476O已搓總某些程數(shù)據(jù)庫(kù)可I藉問(wèn)題-OKA-01013Z用戶清求取消當(dāng)前的噪作射rtuJu.102拓：5上卻2015+JDZSTRIETRMCKW2DE.7563^1^.435.S3.^5S47e&+Jislocaltran435.13.25S47fiO0ieh=1蠟.面.2宥Ob船時(shí)insertpendlnEcszziz11eitxarL.sen—14131603195715\JiEi=cda.-45Std3ahJZhuTill也15:56:^2015+JDiaTRiDCR3I2DB.7565elf3.435.S3.25317^3Iccal-izran435.13.2ES4=?GOfhe-=lb3.Cd.2770b3}J』deletependingZD~ittiedtraji.3cn=14131fiM19671iLhei=:da.iSEhdSat：^TkuJu.10215:56:=22015*-'ErrrT-W13tTkfi：e!i￡n2FCtntransactitn171.1.4797^35.CiEknin?nj!.4Erxcrstackd0user；*-1DI^TRIETRA2；CEM2DE.756belfS.171.1.479F435*JisIdcqItran171.1.4=7374-35ChKt=at.{H.曲33fbWQRA7-Q2054;未決事荊H里171.1.4797435insETtpenidlnzprepared,tran.zcn=1413160921257G(hE3=cda.iSad^aOJ+?*□KA-0W13：用戶恰求取消當(dāng)前的蹈DZ3TRIETR必CRH2DE.7565elfS.171.S.4797435^islocaltran171.1.4=7374-35(hei=al].01.4333fb)^匚人皿弱psxidin?區(qū)買女曰。trsn.sgil=141321257^{h^x=^da.laBcl-GaO)^1topezidlnzcollectzn