Sto utilizzando Windbg per analizzare un deadlock che si verifica in un server applicazioni di snapshot scritto in delphi."DebugInfo per CritSec non punta indietro alla sezione critica" durante l'analisi del deadlock
Quando eseguo
!analyze -hang -v
ottengo questo
:000:x86> !analyze -hang -v
*******************************************************************************
* *
* Exception Analysis *
* *
*******************************************************************************
GetPageUrlData failed, server returned HTTP status 404
URL requested: http://watson.microsoft.com/00000000.htm?Retriage=1
FAULTING_IP:
+6ced240
00000000 ?? ???
EXCEPTION_RECORD: ffffffffffffffff -- (.exr 0xffffffffffffffff)
ExceptionAddress: 0000000000000000
ExceptionCode: 80000003 (Break instruction exception)
ExceptionFlags: 00000000
NumberParameters: 0
FAULTING_THREAD: 0000000000000000
BUGCHECK_STR: HANG
DEFAULT_BUCKET_ID: APPLICATION_HANG
PROCESS_NAME: ********.exe
ERROR_CODE: (NTSTATUS) 0xcfffffff -
EXCEPTION_CODE: (NTSTATUS) 0xcfffffff -
MOD_LIST:
NTGLOBALFLAG: 0
APPLICATION_VERIFIER_FLAGS: 0
DERIVED_WAIT_CHAIN:
Dl Eid Cid WaitType
-- --- ------- --------------------------
0 c7c.2634 Critical Section
WAIT_CHAIN_COMMAND: ~0s;k;;
BLOCKING_THREAD: 0000000000002634
PRIMARY_PROBLEM_CLASS: APPLICATION_HANG
LAST_CONTROL_TRANSFER: from 0000000077138df4 to 000000007711f8b1
STACK_TEXT:
0018fc50 77138df4 00000c6c 00000000 00000000 ntdll_77100000!NtWaitForSingleObject+0x15
0018fcb4 77138cd8 00000000 00000000 03fe0940 ntdll_77100000!RtlpWaitOnCriticalSection+0x13e
0018fcdc 7369324f 736a3134 00000000 03fe0940 ntdll_77100000!RtlEnterCriticalSection+0x150
WARNING: Stack unwind information not available. Following frames may be wrong.
0018fcec 7369af5f 00000388 00000000 003d1e00 mswsock!GetLspGuid+0x19af
0018fd08 76366958 00000388 0018fd84 0018fd9c mswsock!GetLspGuid+0x96bf
0018fd38 0018fd58 763668cd 00000388 0018fd84 ws2_32!WSAAccept+0x84
00000000 00000000 00000000 00000000 00000000 0x18fd58
FOLLOWUP_IP:
mswsock!GetLspGuid+19af
7369324f 33db xor ebx,ebx
SYMBOL_STACK_INDEX: 3
SYMBOL_NAME: mswsock!GetLspGuid+19af
FOLLOWUP_NAME: MachineOwner
MODULE_NAME: C:\Windows\System32\mswsock
IMAGE_NAME: lld
DEBUG_FLR_IMAGE_TIMESTAMP: 4ce7c83d
STACK_COMMAND: ~0s ; kb
FAILURE_BUCKET_ID: APPLICATION_HANG_cfffffff_lld!Unloaded
BUCKET_ID: X64_HANG_mswsock!GetLspGuid+19af
WATSON_STAGEONE_URL: http://watson.microsoft.com/00000000.htm?Retriage=1
Followup: MachineOwner
---------
poi ho fatto
!locks -V
per vedere quale bloccarlo stava aspettando e con mia sorpresa è tornato questo,
0:000:x86> !locks -V CritSec ntdll!RtlCriticalSectionLock+0 at 0000000077057060 LockCount NOT LOCKED RecursionCount 0 OwningThread 0 EntryCount 0 ContentionCount 0 CritSec ntdll!LdrpLoaderLock+0 at 0000000077057490 LockCount NOT LOCKED RecursionCount 0 OwningThread 0 EntryCount 0 ContentionCount 0 CritSec ntdll!RtlpDynamicFunctionTableLock+0 at 0000000077057468 LockCount NOT LOCKED RecursionCount 0 OwningThread 0 EntryCount 0 ContentionCount 0 CritSec ntdll!FastPebLock+0 at 000000007705a900 LockCount NOT LOCKED RecursionCount 0 OwningThread 0 EntryCount 0 ContentionCount 0 CritSec ntdll!RtlpProcessHeapsListLock+0 at 000000007705a240 LockCount NOT LOCKED RecursionCount 0 OwningThread 0 EntryCount 0 ContentionCount 0 CritSec +270208 at 0000000000270208 LockCount NOT LOCKED RecursionCount 0 OwningThread 0 EntryCount 0 ContentionCount 1 CritSec ntdll!EtwProvCritSect+0 at 000000007705a120 LockCount NOT LOCKED RecursionCount 0 OwningThread 0 EntryCount 0 ContentionCount 0 CritSec ntdll!EtwPrivSessionCritSect+0 at 000000007705a1e0 LockCount NOT LOCKED RecursionCount 0 OwningThread 0 EntryCount 0 ContentionCount 0 CritSec +10208 at 0000000000010208 LockCount NOT LOCKED RecursionCount 0 OwningThread 0 EntryCount 0 ContentionCount 0 CritSec +276f40 at 0000000000276f40 LockCount NOT LOCKED RecursionCount 0 OwningThread 0 EntryCount 0 ContentionCount 0 Scanned 10 critical sections
Guardando la chiamata stack di
STACK_TEXT: 0018fc50 77138df4 00000c6c 00000000 00000000 ntdll_77100000!NtWaitForSingleObject+0x15 0018fcb4 77138cd8 00000000 00000000 03fe0940 ntdll_77100000!RtlpWaitOnCriticalSection+0x13e 0018fcdc 7369324f 736a3134 00000000 03fe0940 ntdll_77100000!RtlEnterCriticalSection+0x150 WARNING: Stack unwind information not available. Following frames may be wrong. 0018fcec 7369af5f 00000388 00000000 003d1e00 mswsock!GetLspGuid+0x19af 0018fd08 76366958 00000388 0018fd84 0018fd9c mswsock!GetLspGuid+0x96bf 0018fd38 0018fd58 763668cd 00000388 0018fd84 ws2_32!WSAAccept+0x84 00000000 00000000 00000000 00000000 00000000 0x18fd58
ho deciso che era in attesa di una sezione critica all'indirizzo 0x736a3134 (primo parametro passato a RtlEnterCriticalSection) così mi sono imbattuto questa
!critsec 736a3134
Che mi ha dato questo uscita
0:000:x86> !critsec 736a3134 DebugInfo for CritSec at 00000000736a3134 does not point back to the critical section NOT an initialized critical section. CritSec mswsock!WSPStartup+6f64 at 00000000736a3134 WaiterWoken Yes LockCount -1 RecursionCount 11028 OwningThread c6c EntryCount 1f49dad6 ContentionCount 88000000 *** Locked
Ora il centesimo è caduto, il puntatore alla sezione critica è diventato corru pted, probabilmente a causa di accesso simultaneo alle thread e mancanza di sincronizzazione altrove nel codice
La mia domanda è come rintracciare dove si trova o scoprire se si tratta di un altro problema?
PS: questo bug appare solo quando l'applicazione è sotto carico pesante con forse 700 clienti collegati
(esso utilizza un thread per ogni connessione e so applicazioni a 32 bit saranno limitate a aprox 2000 discussioni al filo di default stack size e questo non è l'approccio migliore)
PPS: Ho più crash dump in cui l'applicazione è sospesa in attesa su diverse sezioni critiche, in ogni caso il puntatore per la sezione critica sembra non puntare a una sezione critica.
È possibile riprodurre l'errore mentre è collegato il debugger delphi? Se è così puoi controllare i callstack e penso che nelle versioni successive di delphi anche alcune informazioni deadlock all'interno dell'IDE. Un'altra cosa da ricordare è che le sezioni critiche sono molto sensibili quando si effettuano inizializzazioni errate ad es. uno snipplet di codice come: critSect.Leave; critSect.Enter; può avere effetti collaterali molto negativi. Se non ti aiuta ti suggerisco di provare due cose: 1.) usa FastMM in modalità di debug completo (danneggiamento dell'heap) 2.) trascina la tua sezione di sezione critica e conta per tutte le chiamate di entrata e di uscita (eventualmente più una chiamata param). – mrabat
Abbiamo cercato di riprodurlo nel debugger Delphi e solo standalone ma non possiamo, da qui il motivo per usare windbg e gli crash dump. Sospettiamo che per ottenere l'errore sia necessario produrre un carico elevato sul server e che ciò giustifica anche la tempistica. Abbiamo esaminato tutto il codice e non siamo in grado di individuare facilmente un errore nell'ordine di blocco o in qualsiasi punto in cui abbiamo perso una serratura o necessità di sincronizzazione, ma pensiamo che ci sia qualcosa che ci è sfuggito. – MikeT
È improbabile che il puntatore identificato come puntatore alla sezione critica. Non fare affidamento sui parametri per rimanere corretti nello stack, perché potrebbero essere sovrascritti e riutilizzati. Per prima cosa, il puntatore 736a3134 è molto vicino al segmento di codice in mswsock, quindi è probabilmente uno dei puntatori di ritorno. –