Tag Archives: Debuggin

Windows Atom szivárgás nyomozása I.

Egy nem hétköznapi hibát mutatok most be.

Ez az első része a cikknek, a második itt olvasható.

A managed memory leakeket elég könnyű megfogni allocation profilerekkel, mint pl. a DotMemory. Általában a nehézséget (nekem) az okozza, hogy megértsem az ügyfél kódját annyira, hogy legyen fogalmam róla, mit tekintünk károsan soknak, vagy minek szabad tartósan benn lenne memóriában, és minek nem.

A normál memory leak tüneti kezeléssel gyógyítható, csak meg kell szüntetni a szivárgó processzt, és máris visszakaptuk a feleslegesen lefoglalt memóriát.

A mostani szivárgás viszont egy sokkal aljasabb fajta. Hiába lövöd ki az inkontinens processzt, a lefoglalt erőforrások továbbra is beragadnak, ki kell lépetni a felhasználót és vissza, csak akkor kapjuk vissza az erőforrásokat.

A hiba egy saját WPF programomban jött elő, ami mindig vasárnap éjféltől péntek éjfélig fut. Van tehát ideje szivárogtani, ha akar. A hibajelenség az volt, hogy csütörtök táján elkezdett megdögleni a Windows. Nem indult el az Explorer, nem jött be a Task Manager se. Minden program a “Not enough storage available to process this command” hibával szállt el. Logoff-logon megoldotta.

A processek handle countja normális. A memória felhasználásuk normális. Ezért normál eszközökkel nem utal semmi a hiba forrására.

A “Not enough storage available to process this command” szövegre keresve az Atom táblákra terelődik a gyanú. Ez egy név-érték tároló, ami 16 bites kulcsokat használ. Ez már rögtön gyanús a mai világban, sokan nem is éltek még az olvasók közöl, amikor 16 bites rendszerek voltak. :) DDE és egyes Windowing függvények használják. Nagyon hasonló, mint a .NET CLR String Intern táblája.

Az atom táblák monitorozása nem olyan egyszerű, nincs rá performance counter, debuggerből nem látszik nyilvánvalóan.

Szerencsére egy kolléga írt hozzá egy kis céleszközt. Ez a GetClipboardFormatName API függvény sokféle paraméterrel történő hívásával végigkeresteti a 16 bites teljes tartományt, így láthatóvá válnak, mely címek vannak elfoglalva.

A képen bal oldalán láthatók a bugos program által lefoglalt atomok. Lehet regexekkel színezni a képet, a róaszín az én kis bugos drágaszágom.

Atomszivárgás

Egy nap múlva már durvább a helyzet:

Egy nappal később

A képeken a local atom table látszik, a global atom table nem hízott.

A leírások alapján a RegisterWindowMessage hívások pakolnak be ide tételeket. Maguk a problémás, szaporodó atomokat ezt a szöveget tartalmazzák:

DA13 = HwndWrapper[Trader;;0def0780-e17c-49d0-a243-149008a6b29e] –RWM

Managed kód esetén simán debuggerben megállnánk, amikor be akar szúrni a program egy atomot. De az Atom API csak kernel módban debugolható, egy szerveren ilyet nem fogok csinálni.

Azonban a RegisterWindowMessage-et esetleg el tudom kapni. Igaz, ez se managed funkció, de azért managed programból is ki lehet debugolni a nem managed, de user módú hívásokat.

De előtte azért szét szoktunk nézni, mentális debuggingot alkalmazunk. A WPF forráskódjában ezeken a helyeken van RegisterWindowMessage hivatkozás.

Ami az első ábrán érdekes, hogy vasárnap 18 óráig (EST) nem volt leak, csak utána indul meg a jobb oldali chart felfelé. Akkor indul ugyanis a kereskedés, onnantól érkeznek adatok, amiket a program feldolgoz. Az adatok feldolgozása másodpercenként egyszer történik, mert így adja az adatokat az adatforrás. Mivel az adatokat háttérszálon érkeznek, ezért a GUI részére át kell dispatch-elni a hívásokat a főszálra. Valószínűleg ehhez a WPF valamilyen Windows Window mechanizmust használ, tehát érzésre ezen a környéken lesz a probléma forrása.

Logikus lenne a forráskód változásait visszanézni a múltban, és megnézni, mi változott benne, ami kiváltotta a hibát. A nehézség az, hogy a beteg program általában egy példányban fut csak, és akkor kiírja egy hétig a Windows, nem telik be az atom tábla. De mostanában két példányban futtatom, ezért jött elő a hiba. Így viszont nem tudom, melyik verzióval jött be. (Visszaállni meg üzleti okok miatt nem lehet).

Azon az úton azonban el lehet indulni, hogy vagy a GUI részen történt valami módosítás, ahol a háttérszálas adatokat veszem ki, vagy az adatforrásnál.

Az adatforrásban egy ilyen kis változtatás volt szeptember végén:

Ha már úgyis async volt a külső metódus, akkor egy szinkron hívást is kicseréltem asyncre, hogy szép legyen. Lehet hogy ez okozza a problémát? Hamarosan kiderül.