WinDBG debug probleem

[smesjz]

Een webapplicatie die voor ons ontwikkeld is heeft stabiliteitsproblemen. De leverancier heeft gevraagd om WinDBG crashdumps maar aangezien dit probleem al ongeveer een jaar speelt, wil ik mij er zelf ook verdiepen. Van de leverancier hoeven we weinig te verwachten (Israelisch bedrijf, communicatie gaat erg stroef).
Zonder de broncode en PDB bestanden wordt het lastig, maar ik wil toch een poging wagen.

Na het laden van de crashdump zie ik dit:

code:

0:000> r
eax=0000002e ebx=7ffff000 ecx=72657354 edx=72657354 esi=041ea94c edi=0033fb90
eip=00640e2b esp=0033d81c ebp=0033f774 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00010202
mgrntw!CLIENT_CERTS_STORE::operator=+0x23357c:
00640e2b 888415cce0ffff  mov     byte ptr [ebp+edx-1F34h],al ss:0023:72994b94=??

Het valt mij op dat ecx en edx gelijk zijn maar dat kan geen kwaad denk ik.

code:

0:000> !vprot edx
!vprot: No containing memory region found
0:000> !vprot 72994b94
!vprot: No containing memory region found
0:000> ? ebp
Evaluate expression: 3405684 = 0033f774
0:000> !vprot ebp
BaseAddress:       00331000
AllocationBase:    00040000
AllocationProtect: 00000004  PAGE_READWRITE
RegionSize:        0000f000
State:             00001000  MEM_COMMIT
Protect:           00000004  PAGE_READWRITE
Type:              00020000  MEM_PRIVATE

!analyze -v bevestigt ook dat het schrijven naar 72994b94 de access violation veroorzaakt.

De callstack laat niks zinnigs zien omdat symbols niet aanwezig zijn.
Ik vraag me af hoe ik achterhalen waar edx de waarde 72657354 kreeg want dat lijkt het probleem te zijn.

Met uf kan ik wel iets zien, maar niet de flow achterhalen waar edx nu 72657354 kreeg.

code:

0:000> uf 00640e2b
mgrntw!CLIENT_CERTS_STORE::operator=+0x23350e:
00640dbd 8b95a8e0ffff    mov     edx,dword ptr [ebp-1F58h]
00640dc3 8b0a            mov     ecx,dword ptr [edx]
00640dc5 81c1103b0000    add     ecx,3B10h
00640dcb e8167bdcff      call    mgrntw!get_ctrl_hwnd_by_name+0x53b6 (004088e6)
00640dd0 83f801          cmp     eax,1
00640dd3 7f29            jg      mgrntw!CLIENT_CERTS_STORE::operator=+0x23354f (00640dfe)

*knip hele rij code*

Ik zie "LAST_CONTROL_TRANSFER: from 0066f5f9 to 00640e2b" maar vanuit daar loop ik last omdat uf 0066f5f9 alleen dit oplevert:

code:

0:000> uf 0066f5f9
mgrntw!CLIENT_CERTS_STORE::operator=+0x261d4a:
0066f5f9 8be5            mov     esp,ebp
0066f5fb 5d              pop     ebp
0066f5fc c20800          ret     8

Verder vind ik nergens meer die 0066f5f9 terug.

Die CLIENT_CERTS_STORE::operator zie ik dus overal, maar dat komt omdat er geen symbols zijn die het vertaalt naar de goede functie naam.

Moet ik dit debuggen via WinDBG maar opgeven of kan ik toch nog ergens inzicht krijgen in wat er gebeurt?

[H!GHGuY]

Als je't mij vraagt heb je een stack overflow. En als ik nog eens mag proberen is het omdat iemand vergeten is out-of-bounds checking te doen op een array op de stack of iets dergelijks.

[smesjz]

H!GHGuY schreef op dinsdag 03 juni 2008 @ 19:52:
Als je't mij vraagt heb je een stack overflow. En als ik nog eens mag proberen is het omdat iemand vergeten is out-of-bounds checking te doen op een array op de stack of iets dergelijks.

Ok, volgens !teb :

StackBase: 00330000
StackLimit: 00322000

0:000> ? 00330000 - 00322000
Evaluate expression: 57344 = 0000e000

Stack is dus 57344 bytes.

code:

0:000> dd 7fffe000+e0c L1
7fffee0c  00030000
0:000> ? 00030000
Evaluate expression: 196608 = 00030000
0:000> ? 00330000 - 00030000
Evaluate expression: 3145728 = 00300000

Dit zou betekenen dat er nog genoeg ruimte (3.1MB?) is op de stack? Maar dat klopt niet of wel?
De 7fffe000 komt van !teb af. Ik snap niet waar e0c vandaan komt, MSDN (http://msdn.microsoft.com/en-us/library/cc267849.aspx) zegt hierover:
"The maximum stack size is stored in the field DeallocationStack. After some calculation, you can determine that this field's offset is 0xE0C. "

[DieterVDW]

Hmm veel succes ... Het is zeker mogelijk, maar wat je probeert te doen is écht niet eenvoudig.
Als er ergens iets fout gaat, dan is de kans dat je dat eenvoudig kan fixen in de ASM code erg klein.
Om te weten hoe je de bug oplost, moet je weten wat er mis is in de logica van het programma en hoe je dit correct oplost. Veel succes om dat allemaal uit te vissen ...

In ieder geval zou ik niet van onder naar boven werken, zoals je nu bezig bent. Je zal er ook wel geraken, maar je maakt het jezelf moeilijker. Ik denk dat het makkelijker is als je top-down gaat werken, eerst een de werking van het programma high-level doorlopen, en dan afzakken naar de methode die het probleem veroorzaakt. Je zal dan waarschijnlijk een veel beter idee hebben over wat juist de context van het programma is, waar de waardes voor staan, en waarom er een fout veroorzaakt wordt.

Met enkel waardes bekijken zonder semantiek ga je er volgens mij niet geraken..

[H!GHGuY]

code:

00640e2b 888415cce0ffff  mov     byte ptr [ebp+edx-1F34h],al ss:0023:72994b94=??

voor zover ik dit begrijp probeert men hier een byte te kopieren naar
dereference(ebp (stack base pointer) + waarde in edx - fixed offset)

Dus als edx een onhebbelijke waarde heeft, dan is die (ebp + edx - offset) ongeldig en is de kans dat de geheugenlocatie waarnaar dit wijst ook behoorlijk ongeldig is.

In c++ code zou je misschien zoiets kunnen doen

code:

char* ptrs[];
// opvullen
strcpy(ptrs[x], "blah");

waarbij x ~ edx.

[ Voor 14% gewijzigd door H!GHGuY op 03-06-2008 22:16 ]

[Anoniem: 74829]

Ik vind het altijd nogal verdacht als registers "ASCII bevatten" (ecx=edx=72657354 = "resT")... In welke technologie is deze webapp ontwikkeld? Iets waarin bufferoverflows eenvoudig mogelijk zijn?

Ik wens je veel succes — mijn schamele WinDBG-ervaring heb ik gelukkig kunnen opdoen in situaties waarin ik wél PDB's had...

[smesjz]

De webapp is gemaakt met Magic, een RAD-omgeving gemaakt in C++. De applicatie die wij gebruiken is al zo'n 12 jaar geleden gemaakt, toen nog als DOS app. Inmiddels is er een web variant en dat levert nu de problemen op. Of dit komt door de multithreaded aard van de app weet ik niet.

In het verleden hebben we vaker problemen gehad (null pointer dereference etc en andere access violation bugs), die wel gefixed zijn.

Het debuggen met alleen de assembly code (en zonder enige vorm van medewerking van de leverancier) is frustrend. Ik hoef ook niet het probleem te fixen in ASM, ik wil graag weten wanneer edx de waarde 72657354 krijgt en hopelijk zie ik dan nog iets anders wat mij een clue oplevert: leesbare ascii tekst (bijv. bestandsnaam, andere librarynamen bijv xerces_2.6 etc etc).
Willekeurig in het geheugen bladeren schiet ook niet op.

Als ik naar 0033f774 (ebp) ga en ik ga dan een paar bytes terug naar 0033f766 (8 bytes) zie ik van 0033d838 tot 0033f766 iedere keer ascii tekst ("User Initialization"). Die tekst kan ik op zich wel plaatsen, maar de relatie tot ebp mis ik hier. Een paar bytes verder dan esp (0033d81c) begint die User Initialization zich te herhalen.

Punt blijft dat ik wel een hoop data zie als ik door het geheugen scroll, maar dat ik niet snel kan zien of het gerelateerd is tot de problemen of niet.

[Anoniem: 74829]

Als ik naar 0033f774 (ebp) ga en ik ga dan een paar bytes terug naar 0033f766 (8 bytes) zie ik van 0033d838 tot 0033f766 iedere keer ascii tekst ("User Initialization").

"User"? Goh :-)

Ecx en edx zijn gelijk aan "User" min 1 (vanwege little-endianness staan de bytes achterstevoren in een DWORD). Kun je in de buurt toevallig iets vinden waar ecx en edx gedecrement worden (al ligt het meer voor de hand dat één van die registers op de een of andere manier een waarde krijgt, waarna het andere register vervolgens op diezelfde waarde wordt gezet...).

En voor wat betreft die "De callstack laat niks zinnigs zien omdat symbols niet aanwezig zijn." uit je topicstart: je kunt natuurlijk zelf gaan proberen om de stack uit te pluizen, door alle enigszins correct ogende DWORDs als return address van de caller te beschouwen, en dan het daaraan voorafgaande stukje geheugen te disassembleren. Geen feest, wel een optie (en mijn "veel succes" blijft staan :-)

[smesjz]

Anoniem: 74829 schreef op woensdag 04 juni 2008 @ 10:13:
[...]


"User"? Goh :-)

Ecx en edx zijn gelijk aan "User" min 1 (vanwege little-endianness staan de bytes achterstevoren in een DWORD). Kun je in de buurt toevallig iets vinden waar ecx en edx gedecrement worden (al ligt het meer voor de hand dat één van die registers op de een of andere manier een waarde krijgt, waarna het andere register vervolgens op diezelfde waarde wordt gezet...).

Dit is de callstack:

code:

0:000> kvL
ChildEBP RetAddr  Args to Child              
WARNING: Stack unwind information not available. Following frames may be wrong.
0033f774 0066f5f9 0033f79c 0033f72e 5b147844 mgrntw!CLIENT_CERTS_STORE::operator=+0x23357c
0033f788 0073fae9 0033f79c 0000002e 6529de30 mgrntw!CLIENT_CERTS_STORE::operator=+0x261d4a
0033f7b4 0085eb14 0033fb90 03f00000 00000000 mgrntw!CLIENT_CERTS_STORE::operator=+0x33223a
0033f890 00736db4 0033f8d8 6529de30 00000000 mgrntw!CLIENT_CERTS_STORE::operator=+0x451265
0033f8ac 00736532 0033f8d8 0033fb90 0406a94c mgrntw!CLIENT_CERTS_STORE::operator=+0x329505
0033f978 0072a9e4 5b144950 00000001 04637f60 mgrntw!CLIENT_CERTS_STORE::operator=+0x328c83
0033fa40 0072a5db 0040dcb0 00000000 0033fb90 mgrntw!CLIENT_CERTS_STORE::operator=+0x31d135
0033fa8c 00735282 0040dcb0 00000001 0033fb90 mgrntw!CLIENT_CERTS_STORE::operator=+0x31cd2c
0033fb00 00743a9a 00000a10 00080001 00000000 mgrntw!CLIENT_CERTS_STORE::operator=+0x3279d3
0033fb44 0041cac3 04066950 00000000 00000000 mgrntw!CLIENT_CERTS_STORE::operator=+0x3361eb
0033fb90 0041c217 00000000 00000000 00000000 mgrntw!CLIENT_CERTS_STORE::operator=+0xf214
0033fbb4 0041bf38 7fffffff 00000001 0406a920 mgrntw!CLIENT_CERTS_STORE::operator=+0xe968
0033fbd8 0060e947 ffffffff 00000001 00000000 mgrntw!CLIENT_CERTS_STORE::operator=+0xe689
0033feec 00608b4e 00000000 0000000a 00000000 mgrntw!CLIENT_CERTS_STORE::operator=+0x201098
0033ff34 0090aa6e 00400000 00000000 01bbeef7 mgrntw!CLIENT_CERTS_STORE::operator=+0x1fb29f
*** ERROR: Symbol file could not be found.  Defaulted to export symbols for kernel32.dll - 
0033ffc0 77e6f23b 00000000 00000000 7ffff000 mgrntw!CLIENT_CERTS_STORE::operator=+0x4fd1bf

Ik kan hier dus weinig van maken. Maar als ik hier mee moet gaan debuggen zou ik ieder argument moeten controleren om te kijken waar edx = ecx wordt OF edx de verkeerde waarde krijgt?
In WinDBG kan ik wel een "uf" doen (unassemble function) en dan vervolgens via '.ecr' (display context record) van context wisselen?
Zonder clue schiet dit ook niet op, ik hoopte dat ik de leverancier in de goede richting kon duwen maar zonder pdb is dit hopeloos.

Bedankt voor de hulp tot zo ver.

[Anoniem: 74829]

Inderdaad, je zou voor alle stackframes de registercontext kunnen switchen en een stukje kunnen disassembleren.

Maar ja, het blijft een grote hooiberg... En mocht je de naald al vinden, dan vrees ik dat het erg moeilijk zal zijn om het onderliggende probleem te pinpointen.

[smesjz]

Ik weet niet hoe betrouwbaar '!gle -all' is, maar als ik deze uitvoer krijg ik dit:

code:

0:000> !gle -all
Last error for thread 0:
LastErrorValue: (Win32) 0 (0) - De bewerking is voltooid.
LastStatusValue: (NTSTATUS) 0 - STATUS_WAIT_0

Last error for thread 1:
*** ERROR: Symbol file could not be found.  Defaulted to export symbols for USER32.dll - 
LastErrorValue: (Win32) 0 (0) - De bewerking is voltooid.
LastStatusValue: (NTSTATUS) 0 - STATUS_WAIT_0

Last error for thread 2:
LastErrorValue: (Win32) 0 (0) - De bewerking is voltooid.
LastStatusValue: (NTSTATUS) 0xc000007c - Er is geprobeerd te verwijzen naar een token dat niet bestaat. Dit wordt   vooral gedaan door het verwijzen naar een token dat is gekoppeld aan een   thread, terwijl de thread geen client imiteert.

Last error for thread 3:
LastErrorValue: (Win32) 0 (0) - De bewerking is voltooid.
LastStatusValue: (NTSTATUS) 0 - STATUS_WAIT_0

Last error for thread 4:
LastErrorValue: (Win32) 0 (0) - De bewerking is voltooid.
LastStatusValue: (NTSTATUS) 0 - STATUS_WAIT_0

Last error for thread 5:
LastErrorValue: (Win32) 0 (0) - De bewerking is voltooid.
LastStatusValue: (NTSTATUS) 0xc00000a3 - {Station niet gereed}  Het station is niet gereed voor gebruik; het is misschien niet gesloten. Controleer of er een schijf in station %hs is geplaatst  en of het station is gesloten.

Last error for thread 6:
LastErrorValue: (Win32) 0 (0) - De bewerking is voltooid.
LastStatusValue: (NTSTATUS) 0 - STATUS_WAIT_0

Ik heb geen F: schijf op mijn PC maar de target heeft dat wel, maar dat lijkt niet de oorzaak. Ik ga nu eens kijken of die gle (get last error) meldingen mij iets verder brengen.

[Anoniem: 74829]

Hmm, als ik "!gle -all" loslaat op een zojuist opgestarte Notepad, dan krijg ik ook allerlei "An invalid HANDLE was specified."- en "An invalid parameter was passed to a service or function."-resultaten.

Ik denk dat je "!gle -all" dus met een korreltje zout moet nemen.

[SKiLLa]

Kun je eens de code rond (en dan vooral voorafgaand aan) 0x00640e2b posten ?
Zoals al eerder gezegd zouden ECX en EDX (volgens het MOV commando) een offset/index moeten bevatten en niet een string. Dat kan dus inderdaad duiden op gebruik van een uninitialized variabled of hergebruik ervan zonder een reset (= 0) of een simpele buffer overflow (mogelijk zelfs iets simpels als b.v. max 256 users --> 255 + 1 = 0 --> krak, te lange gebruikersnaam, etc.)

Wie weet geeft het codeblock een goede indicatie van "waar" (qua functionaliteit) je het moet vinden.

[smesjz]

Ik heb thuis alleen een oude crashdump op basis van een ander servicepack van de applicatie, dit verklaart de andere adressen maar de crash treedt daar ook op zo te zien.

Met ub eip L30 kreeg ik dit. Waarbij L30 staat voor de lengte en ub voor disassemble backwards vanaf eip (dus de 0x00640e2b equivalent die SkiLLa bedoelt)

code:

0:000> r
eax=0000002e ebx=7ffff000 ecx=72657354 edx=72657354 esi=01678004 edi=0032fb90
eip=006434fb esp=0032d81c ebp=0032f774 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00010202
mgrntw!CLIENT_CERTS_STORE::operator=+0x235aa3:
006434fb 888415cce0ffff  mov     byte ptr [ebp+edx-1F34h],al ss:0023:72984b94=??
0:000> ub eip L30
mgrntw!CLIENT_CERTS_STORE::operator=+0x2359b9:
00643411 8b8da8e0ffff    mov     ecx,dword ptr [ebp-1F58h]
00643417 8b09            mov     ecx,dword ptr [ecx]
00643419 81c1103b0000    add     ecx,3B10h
0064341f e82141dcff      call    mgrntw!get_ctrl_hwnd_by_name+0x3ddb (00407545)
00643424 8b95a8e0ffff    mov     edx,dword ptr [ebp-1F58h]
0064342a 8b0a            mov     ecx,dword ptr [edx]
0064342c 81c1103b0000    add     ecx,3B10h
00643432 e8e79edcff      call    mgrntw!CLIENT_CERTS_STORE::CLIENT_CERTS_STORE+0xc03 (0040d31e)
00643437 8b85a8e0ffff    mov     eax,dword ptr [ebp-1F58h]
0064343d 8b08            mov     ecx,dword ptr [eax]
0064343f 81c1103b0000    add     ecx,3B10h
00643445 e87756dcff      call    mgrntw!get_ctrl_hwnd_by_name+0x5357 (00408ac1)
0064344a 83f801          cmp     eax,1
0064344d 0f84e6010000    je      mgrntw!CLIENT_CERTS_STORE::operator=+0x235be1 (00643639)
00643453 6a01            push    1
00643455 8b8da8e0ffff    mov     ecx,dword ptr [ebp-1F58h]
0064345b 8b09            mov     ecx,dword ptr [ecx]
0064345d 81c1103b0000    add     ecx,3B10h
00643463 e8155edcff      call    mgrntw!get_ctrl_hwnd_by_name+0x5b13 (0040927d)
00643468 833800          cmp     dword ptr [eax],0
0064346b 740c            je      mgrntw!CLIENT_CERTS_STORE::operator=+0x235a21 (00643479)
0064346d c785c0e0ffff01000000 mov dword ptr [ebp-1F40h],1
00643477 eb0a            jmp     mgrntw!CLIENT_CERTS_STORE::operator=+0x235a2b (00643483)
00643479 c785c0e0ffff00000000 mov dword ptr [ebp-1F40h],0
00643483 c785ace0ffff321f0000 mov dword ptr [ebp-1F54h],1F32h
0064348d 8b95a8e0ffff    mov     edx,dword ptr [ebp-1F58h]
00643493 8b0a            mov     ecx,dword ptr [edx]
00643495 81c1103b0000    add     ecx,3B10h
0064349b e82156dcff      call    mgrntw!get_ctrl_hwnd_by_name+0x5357 (00408ac1)
006434a0 83f801          cmp     eax,1
006434a3 7f29            jg      mgrntw!CLIENT_CERTS_STORE::operator=+0x235a76 (006434ce)
006434a5 8b85a8e0ffff    mov     eax,dword ptr [ebp-1F58h]
006434ab 8b08            mov     ecx,dword ptr [eax]
006434ad 81c1103b0000    add     ecx,3B10h
006434b3 e80956dcff      call    mgrntw!get_ctrl_hwnd_by_name+0x5357 (00408ac1)
006434b8 83f801          cmp     eax,1
006434bb 0f8517010000    jne     mgrntw!CLIENT_CERTS_STORE::operator=+0x235b80 (006435d8)
006434c1 83bdc0e0ffff00  cmp     dword ptr [ebp-1F40h],0
006434c8 0f850a010000    jne     mgrntw!CLIENT_CERTS_STORE::operator=+0x235b80 (006435d8)
006434ce 83bdc4e0ffff00  cmp     dword ptr [ebp-1F3Ch],0
006434d5 740c            je      mgrntw!CLIENT_CERTS_STORE::operator=+0x235a8b (006434e3)
006434d7 c785c4e0ffff00000000 mov dword ptr [ebp-1F3Ch],0
006434e1 eb1f            jmp     mgrntw!CLIENT_CERTS_STORE::operator=+0x235aaa (00643502)
006434e3 8b8dace0ffff    mov     ecx,dword ptr [ebp-1F54h]
006434e9 83e901          sub     ecx,1
006434ec 898dace0ffff    mov     dword ptr [ebp-1F54h],ecx
006434f2 8b95ace0ffff    mov     edx,dword ptr [ebp-1F54h]
006434f8 8a450c          mov     al,byte ptr [ebp+0Ch]

edx/ecx bevat dus "resT" maar dit moet ik lezen als "Tser"? Het staat dus bijna tegen User Initialization aan.
Het kan ook een gevolg zijn van de crash, de applicatie kan 11 threads gebruiken en geeft een thread vrij nadat een request is afgelopen. Het is dus te vergelijken met een webserver behalve dat XML op en neer wordt gestuurd tussen het activex component in de browser en de server. Statische data (plaatjes, css, downloads) verzorgt IIS. In de praktijk zijn die 11 threads meer dan genoeg, alleen we zien dat wanneer we WinDBG gebruiken de threads niet meer vrij komen en dus alle 11 op gevreten worden. Dit zorgt er dus voor dat gebruikers niet meer kunnen inloggen.

Dus ik weet niet of die User Initialization nu een gevolg is van fouten of de oorzaak.

[SKiLLa]

Je kan de leverancier in ieder geval al aangeven dat het dus fout gaat in/rond de functie: mgrntw!CLIENT_CERTS_STORE. De routine ziet eruit als validatie, waarbij ECX en EDX inderdaad van de stack komen (de certificaat structure zal wel op de stack staan) en er dus een fout in de validatie zit (gemiste fout-situatie als b.v. verlopen certificaat ?) ...

[smesjz]

SKiLLa schreef op woensdag 04 juni 2008 @ 19:31:
Je kan de leverancier in ieder geval al aangeven dat het dus fout gaat in/rond de functie: mgrntw!CLIENT_CERTS_STORE. De routine ziet eruit als validatie, waarbij ECX en EDX inderdaad van de stack komen (de certificaat structure zal wel op de stack staan) en er dus een fout in de validatie zit (gemiste fout-situatie als b.v. verlopen certificaat ?) ...

Komt dat niet door het ontbreken van de PDB files? Ik weet niet of ik mij blind hier op mag staren omdat ik buiten die CLIENT_CERTS_STORE maar 1 ander symbol zie van mgrntw (get_ctrl_hwnd_by_name). Kan toeval zijn maar ik weet niet of ik die output zo maar kan vertrouwen?

Maar die disassemby via ub zegt jou verder ook niks of wel?

[SKiLLa]

Public/Exported names zie je ook zonder PDB files, dus ik neem aan dat die naam gewoon klopt. Daarom zie je ook die naam + hex offset voor de (private) subroutines.

Gebruik zelf veel liever OllyDBG (die je ook als JIT debugger kunt instellen), dus garanderen durf ik niets met WinDBG, daar werk ik er te weinig mee, maar de hex opcodes liegen niet

"Tser" zal inderdaad van "User" komen; waarbij de -1 off mogelijk een bitwise status moet voorstellen. Het zou echter ook een "array start index = -1 --> out of range" kunnen betekenen.

Voor de leverancier moet het probleem echter (met je dumfile en de code @EIP) redelijk goed te achterhalen zijn. Deadlistings zonder context analyseren is erg tricky en tijdrovend.

Je kan nog wel - met behulp van de stack data - achterhalen welke data er nou eigenlijk "geparsed" werd toen de fout optrad ... Je ziet dan meteen of het b.v. een buffer-overflow is of niet (overschreven certificaat data op de stack of niet). Het zegt echter niets over de oorzaak ... het zou inderdaad ook zo kunnen zijn dat een thread ge-dead-lockt is en zodanig geen cleanup doet, waardoor deze code uiteindelijk crasht zonder iets fout te doen.

Als de situatie reproduceerbaar is, zou je nog "debug sessies" kunnen proberen met b.v. Datarescue IDA Pro of OllyDBG, maar dat is weer een vak apart

[smesjz]

SKiLLa schreef op woensdag 04 juni 2008 @ 20:14:
Public/Exported names zie je ook zonder PDB files, dus ik neem aan dat die naam gewoon klopt. Daarom zie je ook die naam + hex offset voor de (private) subroutines.

Ok, maar die CLIENT_CERTS_STORE is dus iets wat gedeclareerd moet zijn in die mgrntw? Het kan dus geen symbol zijn dat van bijv. de openssl lib af komt?

"Tser" zal inderdaad van "User" komen; waarbij de -1 off mogelijk een bitwise status moet voorstellen. Het zou echter ook een "array start index = -1 --> out of range" kunnen betekenen.

Interessant, ik had niet eens nagedacht over het feit dat User en Tser zo dicht bij elkaar zitten, scheelt idd maar 1 positie. Kan je dat laatste eens uitleggen? Dat begrijp ik niet helemaal.


Voor de leverancier moet het probleem echter (met je dumfile en de code @EIP) redelijk goed te achterhalen zijn. Deadlistings zonder context analyseren is erg tricky en tijdrovend.

Je kan nog wel - met behulp van de stack data - achterhalen welke data er nou eigenlijk "geparsed" werd toen de fout optrad ... Je ziet dan meteen of het b.v. een buffer-overflow is of niet (overschreven certificaat data op de stack of niet). Het zegt echter niets over de oorzaak ... het zou inderdaad ook zo kunnen zijn dat een thread ge-dead-lockt is en zodanig geen cleanup doet, waardoor deze code uiteindelijk crasht zonder iets fout te doen.
[/quote]
Maar moet ik dan niet ergens de data-typen weten? Als het een struct is met pointers bijv dan weet ik niet welke ik moet dereferencen of wel? Als ik maar iets leesbaars kan zien zoals een path....

Het probleem is niet op commando reproduceerbaar en aangezien er meerdere gebruikers gelijktijdig ingelogd zijn of acties op de achtergrond starten (creeren van een rapport e.d.) is het niet duidelijk wat het probleem triggert.

De leverancier hoort dit op te lossen, maar blijft in mijn ogen in gebreke omdat dit probleem zich al een jaar voor doet. Aangezien het een productie omgeving is, kan ik niet zo maar andere debuggers gebruiken. WinDBG met geconfigureerde global flags is op verzoek van de leverancier.

Maar ik leer nu zelf een hoop, dus het is niet alleen maar verloren tijd.

[ Voor 0% gewijzigd door smesjz op 04-06-2008 21:00 . Reden: typo in laatste zin ]

[bommel]

Misschien kun je dit beter te lijf gaan met Ida? Er is tegenwoordig zelfs een freeware versie: http://www.hex-rays.com/idapro/idadownfreeware.htm

[smesjz]

bommel schreef op woensdag 04 juni 2008 @ 20:57:
Misschien kun je dit beter te lijf gaan met Ida? Er is tegenwoordig zelfs een freeware versie: http://www.hex-rays.com/idapro/idadownfreeware.htm

Ik graag een tool hebben voor post-mortem debuggen zodat dit niet op de server zelf hoeft. Ik zie het voordeel van lda niet t.o.v. WinDBG.
Maar ik kan er eens naar kijken, de full licenties zijn te duur..zeker voor het doel dat ik er mee voor ogen heb.

[SKiLLa]

smesjz schreef op woensdag 04 juni 2008 @ 20:38:
[...]
Ok, maar die CLIENT_CERTS_STORE is dus iets wat gedeclareerd moet zijn in die mgrntw? Het kan dus geen symbol zijn dat van bijv. de openssl lib af komt?
[...]

Nee, want de naam van de module staat ervoor ("mgrntw!CLIENT_CERTS_STORE"). Tevens kun je aan de hex-codes zien dat de address-space binnen het geheugengebied van "mgrntw", al die jmp zijn "short/relative jmps" (= 0xEB 0x<offset>). In het geval van een call naar een andere module zou er b.v. USER32!MessageBoxA staan (of in het geval van OpenSSL vermoedelijk iets als "ssleay32!FunctionName")

[...]
Interessant, ik had niet eens nagedacht over het feit dat User en Tser zo dicht bij elkaar zitten, scheelt idd maar 1 positie. Kan je dat laatste eens uitleggen? Dat begrijp ik niet helemaal.
[...]

ECX en EDX bevatten in dit geval niet een pointer naar de string (string-reference), maar de daadwerkelijke ASCII code. Het zijn 32 bits registers --> 4 bytes, dus kun je 4 ASCII karakters erin kwijt. De "-1 off" kan verschillende oorzaken hebben, maar ik vermoed dat de code rond EIP helemaal geen ASCII waardes in ECX/EDX verwacht (en het dus eigenlijk misleidende human-readable bagger is), maar het gewoon als status of offset register gebruikt. Bit 0 is dus "gereset" (= ASCII "T", bit 0 = 0) tov. de orginele waarde (ASCII "U", bit 0 = 1).

x86 CPUs slaan multi-byte data in "Little Endian" volgorde op (zie ook b.v. hier op Wikipedia), vandaar de "rare/gemangelde" volgorde in ECX/EDX.

Maar moet ik dan niet ergens de data-typen weten? Als het een struct is met pointers bijv dan weet ik niet welke ik moet dereferencen of wel? Als ik maar iets leesbaars kan zien zoals een path....

Dat "weten" moet je "achterhalen" middels reverse engineering. Je hebt de stack-data en je weet de code, match deze data (een groot gemis in WinDBG, waar OllyDBG en IDA juist steengoed in zijn) en analyseer de boel. In de code zie je de stack-referenties; als je daar als commentaar de daadwerkelijke waardes achter zet, zie je al veel beter wat er gebeurd en kun je b.v. beoordelen welke conditionele jumps wel en niet uitgevoerd zijn (en of die data dan weer een pointer is of echte "waardes").

Misschien kun je een test-omgeving opzetten waarbij je het proces wel kunt debuggen met OllyDBG of IDA, dan kun je de code volgen en de structuren veel beter analyseren (mbv. breakpoints, logging, etc.).

[bommel]

De grootste voordelen van Ida tov WinDBG zijn dat je in de disassembly kunt kijken zonder de code te runnen en dat Ida geeft in grote mate inzicht in de structuur/flow van de code en de functies/api call's die worden aangeroepen. Vaak kun je de parameters van functies al zien in Ida en in elk geval het aantal parameters. Daarnaast kun je uiteraard ook attachen en breakpoints zetten, registerinhoud bekijken/wijzigen en dus de flow volgen terwijl de code runt.

Dit is bijvoorbeeld een stukje uit Notepad.exe (functie SetTitle)
.text:0100297C ; int __stdcall SetTitle(LPCWSTR lpString1)
.text:0100297C _SetTitle@4 proc near ; CODE XREF: NPInit(x,x,x)+36Dp
.text:0100297C ; LoadFile(x,x)+2ACp ...
.text:0100297C
.text:0100297C FindFileData = _WIN32_FIND_DATAW ptr -7C8h
.text:0100297C var_578 = word ptr -578h
.text:0100297C String = word ptr -370h
.text:0100297C lParam = dword ptr -104h
.text:0100297C var_4 = dword ptr -4
.text:0100297C lpString1 = dword ptr 8
.text:0100297C
.text:0100297C ; FUNCTION CHUNK AT .text:01002CDB SIZE 0000005C BYTES
.text:0100297C ; FUNCTION CHUNK AT .text:01003B8D SIZE 00000018 BYTES
.text:0100297C
.text:0100297C mov edi, edi
.text:0100297E push ebp
.text:0100297F mov ebp, esp
.text:01002981 sub esp, 7C8h
.text:01002987 mov eax, ___security_cookie
.text:0100298C xor eax, ebp
.text:0100298E mov [ebp+var_4], eax
.text:01002991 and word ptr [ebp+lParam], 0
.text:01002999 push ebx
.text:0100299A push esi
.text:0100299B mov esi, [ebp+lpString1]
.text:0100299E push 0FEh ; size_t
.text:010029A3 lea eax, [ebp+lParam+2]
.text:010029A9 push 0 ; int
.text:010029AB push eax ; void *
.text:010029AC call _memset
.text:010029B1 add esp, 0Ch
.text:010029B4 push _szUntitled ; lpString2
.text:010029BA push esi ; lpString1
.text:010029BB call ds:__imp__lstrcmpW@8 ; lstrcmpW(x,x)
...
...

[ Voor 74% gewijzigd door bommel op 04-06-2008 22:18 ]

[Anoniem: 74829]

Interessant, ik had niet eens nagedacht over het feit dat User en Tser zo dicht bij elkaar zitten, scheelt idd maar 1 positie.

Umm, dat schreef ik vanochtend:

Ecx en edx zijn gelijk aan "User" min 1 (vanwege little-endianness staan de bytes achterstevoren in een DWORD). Kun je in de buurt toevallig iets vinden waar ecx en edx gedecrement worden (al ligt het meer voor de hand dat één van die registers op de een of andere manier een waarde krijgt, waarna het andere register vervolgens op diezelfde waarde wordt gezet...).

:-)

En nu je een stukje disassembly hebt gepost, kunnen we inderdaad constateren dat dat het geval is:

code:

006434e3 8b8dace0ffff    mov     ecx,dword ptr [ebp-1F54h]
006434e9 83e901          sub     ecx,1
006434ec 898dace0ffff    mov     dword ptr [ebp-1F54h],ecx
006434f2 8b95ace0ffff    mov     edx,dword ptr [ebp-1F54h]
006434f8 8a450c          mov     al,byte ptr [ebp+0Ch]

Kortom, er wordt iets in ecx gestopt, ecx wordt gedecrement en weer opgeslagen, waarna edx diezelfde waarde krijgt. Vergelijkbaar met:

C++:

a = --b;

Voor wat betreft die "mgrntw!CLIENT_CERTS_STORE::operator=": gegeven het feit dat de offset erachter zo'n 2MB bedraagt, zou ik me van die naam niet teveel aantrekken. Het betekent alleen maar dat "operator=" het dichtstbijzijnde exported symbol is (waarbij dat "dichtbij" dus niet zodanig dichtbij is dat je er iets uit kunt concluderen).

[smesjz]

Anoniem: 74829 schreef op woensdag 04 juni 2008 @ 22:16:
Umm, dat schreef ik vanochtend:
:-)

I know, ik bedoelde dat het mij niet eerder was opgevallen totdat jij er over begon

En nu je een stukje disassembly hebt gepost, kunnen we inderdaad constateren dat dat het geval is:

code:

00640e13 8b8dace0ffff    mov     ecx,dword ptr [ebp-1F54h]
00640e19 83e901          sub     ecx,1
00640e1c 898dace0ffff    mov     dword ptr [ebp-1F54h],ecx
00640e22 8b95ace0ffff    mov     edx,dword ptr [ebp-1F54h]
00640e28 8a450c          mov     al,byte ptr [ebp+0Ch]

Kortom, er wordt iets in ecx gestopt, ecx wordt gedecrement en weer opgeslagen, waarna edx diezelfde waarde krijgt. Vergelijkbaar met:

C++:

a = --b;

Ik was op zoek naar iets als mox ecx,edx maar dat gebeurt dus door bovenstaande sequence. Nu is het helder. Maar zou b niet geinitialiseerd kunnen zijn? Zou dat iets kunnen verklaren?

Memory inhoud (volgens WinDBG):

code:

0033d813 63 74 f7 33 00 d0 0d 64 00 44 f8 02 63 54 73 65 72 20 49 6e 69 74 69 61 6c 69 7a 61 74 69 6f 6e 00 73 65 72 20  ct.3...d.D..cTser Initialization.ser 
0033d838 00 00 00 00 69 61 6c 69 7a 61 74 69 6f 6e 2e 55 73 65 72 20 49 6e 69 74 69 61 6c 69 7a 61 74 69 6f 6e 2e 55 73  ....ialization.User Initialization.Us
0033d85d 65 72 20 49 6e 69 74 69 61 6c 69 7a 61 74 69 6f 6e 2e 55 73 65 72 20 49 6e 69 74 69 61 6c 69 7a 61 74 69 6f 6e  er Initialization.User Initialization
0033d882 2e 55 73 65 72 20 49 6e 69 74 69 61 6c 69 7a 61 74 69 6f 6e 2e 55 73 65 72 20 49 6e 69 74 69 61 6c 69 7a 61 74  .User Initialization.User Initializat

Ik weet niet of hier iets uit op te maken is. De 55 is U en 54 is T.

[ Voor 27% gewijzigd door smesjz op 05-06-2008 11:00 . Reden: Aanvulling memory inhoud ]

[Anoniem: 74829]

Maar zou b niet geinitialiseerd kunnen zijn? Zou dat iets kunnen verklaren?

Ik heb zojuist nog eens even verder zitten kijken naar de rest van de disassembly. "b" wordt wel degelijk geinitialiseerd:

code:

00643483 c785ace0ffff321f0000 mov dword ptr [ebp-1F54h],1F32h

Maar misschien wordt die assignment wel veranderd door een van de tussenliggende calls naar mgrntw!get_ctrl_hwnd_by_name+0x5357 (00408ac1). Je zou kunnen kijken wat er voor code op dat adres te vinden is, om te zien of die iets met [ebp-1F54h] doet.

Andere mogelijkheid is dat de crashende code van elders wordt aangeroepen, zonder langs de initialisatie te gaan. Da's denk ik niet eenvoudig te achterhalen.

Maar ik neig toch het meest naar de volgende gok: het gaat hier om global state, die door thread Y ge(her)initialiseerd wordt, terwijl thread X er nog gebruik van maakt. En wat die "User Initialization."-stringetjes betreft: misschien vult Magic gealloceerd geheugen met dat patroon.

[smesjz]

Weer wat nieuws van de leverancier: "Every one of the crashes appear when the engine tries to terminate a thread that has reached a timeout.In this process it tries to close a certain form and then reaches a situation where an ancestor for does not exist."

Lekker vaag nog steeds, maar het komt zo te zien overeen met wat amg stelt. Toch? Bedankt voor het meedenken iig.

[smesjz]

Een schopje, inmiddels hebben we afgelopen vrijdag een fix gekregen van de leverancier maar nu lopen we weer tegen null pointer problemen aan.
Het aantal crashes is wel teruggelopen, maar het is nog steeds niet goed.

code:

(c4c.102c): Access violation - code c0000005 (first chance)
First chance exceptions are reported before any exception handling.
This exception may be expected and handled.
eax=00000004 ebx=7125ef80 ecx=000000d7 edx=749bdfc0 esi=00000004 edi=60a1eff4
eip=00878e3e esp=749bdf68 ebp=749bdf7c iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00010202
*** WARNING: Unable to verify checksum for mgrntw.exe
*** ERROR: Symbol file could not be found.  Defaulted to export symbols for mgrntw.exe - 
mgrntw!CLIENT_CERTS_STORE::operator=+0x46b58f:
00878e3e 8948fc          mov     dword ptr [eax-4],ecx ds:0023:00000000=????????

eax is null en eax-4 is nog steeds null, iets er naar toe schrijven levert dus een access violation op.

uf op 00878e3e levert dit op:

code:

0:007> uf 00878e3e
mgrntw!CLIENT_CERTS_STORE::operator=+0x46b58f:
00878e3e 8948fc          mov     dword ptr [eax-4],ecx
00878e41 8be5            mov     esp,ebp
00878e43 5d              pop     ebp
00878e44 c3              ret

Maar zowel 00878e3e als 00878e44 zie ik nergens terug op de stack:

code:

0:007> kb
ChildEBP RetAddr  Args to Child              
WARNING: Stack unwind information not available. Following frames may be wrong.
749bdf7c 00878cb1 749bdfc0 00000001 000000cd mgrntw!CLIENT_CERTS_STORE::operator=+0x46b58f
749bdfc4 0073de86 744f0fa8 00000001 744f0fac mgrntw!CLIENT_CERTS_STORE::operator=+0x46b402
749bdff4 00739ec8 749be028 0000000d 00000000 mgrntw!CLIENT_CERTS_STORE::operator=+0x3305d7
749be00c 00880c0f 749be028 6e504fc8 7384afd0 mgrntw!CLIENT_CERTS_STORE::operator=+0x32c619
749be118 008810cd 00973f28 00000000 00000001 mgrntw!CLIENT_CERTS_STORE::operator=+0x473360
749be12c 00464f9b 00973f28 00000000 00000001 mgrntw!CLIENT_CERTS_STORE::operator=+0x47381e
......

Is ergens te zien waar die eax nu eindelijk null wordt? Nog steeds heb ik geen PDB of broncode gekregen, maar misschien is hier iets zinnigs over te zeggen?

[Anoniem: 74829]

Sorry, schopje gemist... Is dit nog actueel? Zo ja, zou je dan nog wat meer code voorafgaand aan 00878e3e kunnen disassembleren?

[smesjz]

Het is gelukkig niet meer actueel, de leverancier heeft na veel gezeur het probleem blijkbaar opgelost.
Maar het heeft uiteindelijk nog 3 patches geduurd voordat ook andere problemen zijn aangepakt.
We zitten nu nog wel een performance probleem (applicatie blijft soms in een LOCK/UNLOCK loop hangen) als we kijken met Process Monitor, maar dat is minder spannend dan deze crashes.

Ik kan voor de vorm morgen wel eens wat disassemblen als je nog wil kijken.

[Anoniem: 74829]

Mooi dat het eindelijk verholpen is.

Voor de vorm disassemblen hoef je voor mij niet te doen — ik vond het twee maanden geleden leuk om naar te kijken, maar nou ook weer niet zo leuk dat ik me geroepen voel om naar x86-assembly te kijken als het niet hoeft :-)