Could you hire me? Contact me if you like what I’ve done in this article and think I can create value for your company with my skills.

July 20, 2012 / by Zsolt Soczó

Megoldás a deadlockos cikkhez

Heuréka! :)

Előzmény.

Az előzményben látható első deadlock lenyomata xmlben így néz ki:

<deadlock-list>
	<deadlock victim="process3c3dc8">
		<process-list>
			<process id="process3c3dc8"
					 taskpriority="0"
					 logused="236"
					 waitresource="KEY: 6:72057594959101952 (8194443284a0)"
					 waittime="8196"
					 ownerId="724347"
					 transactionname="user_transaction"
					 lasttranstarted="2012-07-17T13:30:06.643"
					 XDES="0x9dec3b0"
					 lockMode="U"
					 schedulerid="3"
					 kpid="2744"
					 status="suspended"
					 spid="85"
					 sbid="0"
					 ecid="0"
					 priority="0"
					 trancount="1"
					 lastbatchstarted="2012-07-17T13:30:06.643"
					 lastbatchcompleted="2012-07-17T13:30:06.643"
					 clientapp=".Net SqlClient Data Provider"
					 hostname="AlmaDEVWEB02"
					 hostpid="1312"
					 loginname="BuildAgentUser"
					 isolationlevel="repeatable read (3)"
					 xactid="724347"
					 currentdb="6"
					 lockTimeout="4294967295"
					 clientoption1="673316896"
					 clientoption2="128056">
				<executionStack>
					<frame procname="AlmaDev.dbo.spExecuteTransaction"
						   line="136"
						   stmtstart="7378"
						   stmtend="7554"
						   sqlhandle="0x0300060069e52875f254de0091a000000100000000000000">
						SELECT @toBalance = Balance FROM Account WITH (UPDLOCK) WHERE Id = @toAccountID
					</frame>
				</executionStack>
				<inputbuf>
					Proc [Database Id = 6 Object Id = 1965614441]
				</inputbuf>
			</process>
			<process id="processbe41288"
					 taskpriority="0"
					 logused="236"
					 waitresource="KEY: 6:72057594959101952 (8194443284a0)"
					 waittime="2505"
					 ownerId="724314"
					 transactionname="user_transaction"
					 lasttranstarted="2012-07-17T13:30:06.610"
					 XDES="0x9af4e80"
					 lockMode="X"
					 schedulerid="2"
					 kpid="4716"
					 status="suspended"
					 spid="108"
					 sbid="0"
					 ecid="0"
					 priority="0"
					 trancount="2"
					 lastbatchstarted="2012-07-17T13:30:06.610"
					 lastbatchcompleted="2012-07-17T13:30:06.610"
					 clientapp=".Net SqlClient Data Provider"
					 hostname="AlmaDEVWEB02"
					 hostpid="1312"
					 loginname="BuildAgentUser"
					 isolationlevel="repeatable read (3)"
					 xactid="724314"
					 currentdb="6"
					 lockTimeout="4294967295"
					 clientoption1="673316896"
					 clientoption2="128056">
				<executionStack>
					<frame procname="AlmaDev.dbo.spExecuteTransaction"
						   line="138"
						   stmtstart="7556"
						   stmtend="7830"
						   sqlhandle="0x0300060069e52875f254de0091a000000100000000000000">
						UPDATE Account SET
						Balance += (@amount - @commissionAmount)
						WHERE Id = @toAccountID
					</frame>
				</executionStack>
				<inputbuf>
					Proc [Database Id = 6 Object Id = 1965614441]
				</inputbuf>
			</process>
		</process-list>
		<resource-list>
			<keylock hobtid="72057594959101952"
					 dbid="6"
					 objectname="AlmaDev.dbo.Account"
					 indexname="PK_Account"
					 id="lockc99fc00"
					 mode="U"
					 associatedObjectId="72057594959101952">
				<owner-list>
					<owner id="processbe41288"
						   mode="U"/>
				</owner-list>
				<waiter-list>
					<waiter id="process3c3dc8"
							mode="U"
							requestType="convert"/>
				</waiter-list>
			</keylock>
			<keylock hobtid="72057594959101952"
					 dbid="6"
					 objectname="AlmaDev.dbo.Account"
					 indexname="PK_Account"
					 id="lockc99fc00"
					 mode="U"
					 associatedObjectId="72057594959101952">
				<owner-list>
					<owner id="process3c3dc8"
						   mode="S"/>
				</owner-list>
				<waiter-list>
					<waiter id="processbe41288"
							mode="X"
							requestType="convert"/>
				</waiter-list>
			</keylock>
		</resource-list>
	</deadlock>
</deadlock-list>

Figyeljük meg, hogy mindkét processz a “KEY: 6:72057594959101952 (8194443284a0)” kulcson várakozik, ezen vesztek össze.

Viszont az xmlben nem az van, mint a képen!!!

Az xml vége felé látszik ki-mit ownol. owner-list/owner elemek:

		<resource-list>
				<owner-list>
					<owner id="processbe41288" mode="U"/>
				</owner-list>
				<waiter-list>
					<waiter id="process3c3dc8" mode="U" requestType="convert"/>
				</waiter-list>
			</keylock>
				<owner-list>
					<owner id="process3c3dc8" mode="S"/> <!-- Ez nem U !!! -->
				</owner-list>
				<waiter-list>
					<waiter id="processbe41288" mode="X" requestType="convert"/>
				</waiter-list>
			</keylock>
		</resource-list>

A második processz nem U lockot tart az erőforráson, hanem S-t, Shared lockot! De miért U látszik a képen? A bugos kutya életbe!
Így már kristálytiszta a dolog. Azt nem értettem, hogy tudott kiadni az SQL Server két U lockot ugyanarra az erőforrásra. Sehogy, az elmélet jó. Csak az SSMS bugos.

Tehet, mit látunk itt tképpen? Az egyik processz tart U lockot a közös erőforrásra (owner id=”processbe41288″ mode=”U”), a másik pedig egy Shared lockot (owner id=”process3c3dc8″ mode=”S”). Miért shared az egyik? Mivel valamelyik korábbi sorban (ez nem látszik az xmlből, már lefutott) lemaradt a with(updlock) a select utáni tábla mögül.
Ez az alapállás. Aztán az egyik Update lockra akar konvertálni (waiter id=”process3c3dc8″ mode=”U” requestType=”convert”, ez nem teljesen világos miért, mivel eleve az van neki. A másik Sharedről eXclusive-ra akar konvertálni. Ez már a nem megy, mivel az X nem kompatibilis az U-val, így az nem adható ki, a második processznek várnia kell, de mivel az első által kért U sem a U-val, így összeakadnak.
Míg most sem teljesen tiszta minden, az XML-ben sem látni az összes részletet, pl. miért van az U-U konverzió, de a megoldás viszonylag 100%-ra a következő: át kell nézni a beteg tárolt eljárást, és meg kell keresni benne olyan select-et, amely az Account táblát nem updlockkal érik el. Ezekre fel kell rakni az updlockot, és valószínűleg kiesik a deadlock.
Tanulság: nem elég a deadlock graph grafikus nézetét megnézni, bele kell kukkantani az xml-be is, ha valami nem logikus.
Ezt tudva már más is találkozott ezzel: http://rusanu.com/2010/05/12/the-puzzle-of-u-locks-in-deadlock-graphs/
Szóval még nem teljesen tiszta minden, de az IT már csak ilyen, félinformációk alapján is tudni kell hibát keresni.

Could you hire me? Contact me if you like what I’ve done in this article and think I can create value for your company with my skills.

LEAVE A COMMENT

4 COMMENTS

  • Zsolt October 3, 2012

    Múltkor futottam bele olyanba, hogy egy SELECT nolock hinttel lockolt egy másik folyamatot :-)

  • Soczó Zsolt October 11, 2012

    Na, ezt hogy csinálta?

  • Zsolt October 21, 2012

    Hát úgy, hogy mégse a nolock okozta a problémát, csak még lenne mit javítani a lockok trace-lésén.

    Két dolog volt a gyanús.
    1.) Két olyan tábla akadt össze, ami egymástól független.
    2.) Nolock hint lockol.

    Aztán kis törpengéssel rájöttem, hogy olyan műveletet kell keressek a trace-ekben, ahol a két tábla 1 tranzakcióban van.

    Meg is lett, demózom:

    SESSION 1 első batch:
    BEGIN TRAN

    SESSION 1 második batch:
    UPDATE egyiktábla SET valami …

    SESSION 1 harmadik batch:
    SELECT … FROM másiktábla (NOLOCK) …

    SESSION 2:
    SELECT count(*) FROM egyiktábla

    SESSION 1 még nincs egy ideig negyik batch.

    És a lock trace nem az egész tranzakciót tette bele, csak a NOLOCK-os batch-et, azaz a legutolsó batch-et a tranzakcióból, mint lockoló folyamat.

  • Soczó Zsolt October 22, 2012

    Óh, ez a szopás ismerős. Látsz valamit, de nem is az volt a gond okozója. Köszi az infót.