Dela via

Analysera ett fastnat samtalsproblem

Ett vanligt problem uppstår när en process gör ett RPC-anrop, direkt eller indirekt, när du håller i ett kritiskt avsnitt eller en resurs. I det här fallet går RPC-anropet till en annan process eller dator och skickar till hanteringsrutinen (serverrutin), som sedan låser sig eller tar för lång tid. Detta gör att den ursprungliga anroparen stöter på en tidsgräns för en kritisk sektion.

När RPC granskas via felsökningsprogrammet ligger RPC ovanpå stacken i tråden som äger det kritiska avsnittet, men vad det väntar på är oklart.

Här är ett exempel på en sådan stack. Många varianter är möjliga.

0:002> ~1k
ChildEBP RetAddr
0068fba0 77e9e8eb ntdll!ZwWaitForSingleObject+0xb
0068fbc8 4efeff73 KERNEL32!WaitForSingleObjectEx+0x5a
0068fbe8 4eff0012 RPCRT4!UTIL_WaitForSyncIO+0x21
0068fc0c 4efe6e2b RPCRT4!UTIL_GetOverlappedResultEx+0x44
0068fc44 4ef973bf RPCRT4!WS_SyncRecv+0x12a
0068fc68 4ef98d5a RPCRT4!OSF_CCONNECTION__TransSendReceive+0xcb
0068fce4 4ef9b682 RPCRT4!OSF_CCONNECTION__SendFragment+0x297
0068fd38 4ef9a5a8 RPCRT4!OSF_CCALL__SendNextFragment+0x272
0068fd88 4ef9a9cb RPCRT4!OSF_CCALL__FastSendReceive+0x165
0068fda8 4ef9a7f8 RPCRT4!OSF_CCALL__SendReceiveHelper+0xed
0068fdd4 4ef946a7 RPCRT4!OSF_CCALL__SendReceive+0x37
0068fdf0 4efd56b3 RPCRT4!I_RpcSendReceive+0xc4
0068fe08 01002850 RPCRT4!NdrSendReceive+0x4f
0068ff40 01001f32 rtclnt+0x2850
0068ffb4 77e92ca8 rtclnt+0x1f32
0068ffec 00000000 KERNEL32!CreateFileA+0x11b

Så här felsöker du det här problemet.

Felsöka ett problem med fast samtal – steg för steg

  1. Kontrollera att felsökaren felsöker den process som äger cellen som fastnat. (Det här är den process som innehåller klienttråden som misstänks vara hängande i RPC.)

  2. Hämta stackpekaren för den här tråden. Stacken ser ut som den som visas i föregående exempel. I det här exemplet är stackpekaren 0x0068FBA0.

  3. Hämta samtalsinformationen för den här tråden. För att göra det, använd !rpcexts.rpcreadstack-tillägget med trådstackens pekare som parameter, enligt följande:

0:001> !rpcexts.rpcreadstack 68fba0
    CallID: 1
    IfStart: 19bb5061
    ProcNum: 0
            Protocol Sequence:      "ncacn_ip_tcp"  (Address: 00692ED8)
            NetworkAddress: ""      (Address: 00692F38)
            Endpoint:       "1120"  (Address: 00693988)

Informationen som visas här gör att du kan spåra anropet.

  1. Nätverksadressen är tom, vilket anger den lokala datorn. Slutpunkten är 1120. Du måste avgöra vilken process som hanterar den här slutpunkten. Detta kan göras genom att skicka det här slutpunktsnumret till !rpcexts.getendpointinfo-tillägget enligt följande:
    0:001> !rpcexts.getendpointinfo 1120
    Searching for endpoint info ...
    PID  CELL ID   ST PROTSEQ        ENDPOINT
    --------------------------------------------
    0278 0000.0001 01            TCP 1120
  1. Från föregående information kan du se att processen 0x278 innehåller den här slutpunkten. Du kan avgöra om den här processen vet något om det här anropet med hjälp av tillägget !rpcexts.getcallinfo. Det här tillägget behöver fyra parametrar: CallID, IfStartoch ProcNum (som hittades i steg 3) och ProcessID- i 0x278:
    0:001> !rpcexts.getcallinfo 1 19bb5061 0 278
    Searching for call info ...
    PID  CELL ID   ST PNO IFSTART  TIDNUMBER CALLFLAG CALLID   LASTTIME CONN/CLN
    ----------------------------------------------------------------------------
    0278 0000.0004 02 000 19bb5061 0000.0002 00000001 00000001 00072c09 0000.0003
  1. Informationen i steg 5 är användbar, men något förkortad. Cell-ID anges i den andra kolumnen som 0000.0004. Om du skickar process-ID:t och det här cellnumret till !rpcexts.getdbgcell-tillägget visas en mer läsbar visning av den här cellen:
    0:001> !rpcexts.getdbgcell 278 0.4
    Getting cell info ...
    Call
    Status: Dispatched
    Procedure Number: 0
    Interface UUID start (first DWORD only): 19BB5061
    Call ID: 0x1 (1)
    Servicing thread identifier: 0x0.2
    Call Flags: cached
    Last update time (in seconds since boot):470.25 (0x1D6.19)
    Owning connection identifier: 0x0.3

Detta visar att anropet är i tillståndet "dispatched", vilket innebär att det har lämnat RPC-körtiden. Den senaste uppdateringstiden är 470,25. Du kan lära dig den aktuella tiden med hjälp av tillägget !rpcexts.rpctime:

    0:001> !rpcexts.rpctime
    Current time is: 6003, 422

Detta visar att den senaste kontakten med det här samtalet var för cirka 5 533 sekunder sedan, vilket är cirka 92 minuter. Därför måste detta vara ett fastnat samtal.

  1. Som ett sista steg innan du kopplar ett felsökningsprogram till serverprocessen kan du isolera den tråd som för närvarande ska betjäna anropet med hjälp av servicetrådsidentifieraren. Det här är ett annat cellnummer. det visades i steg 6 som "0x0.2". Du kan använda den på följande sätt:
    0:001> !rpcexts.getdbgcell 278 0.2
    Getting cell info ...
    Thread
    Status: Dispatched
    Thread ID: 0x1A4 (420)
    Last update time (in seconds since boot):470.25 (0x1D6.19)

Nu vet du att du letar efter tråd 0x1A4 i process 0x278.

Det är möjligt att tråden gjorde ett annat RPC-anrop. Om det behövs kan du spåra det här anropet genom att upprepa den här proceduren.

Obs Den här proceduren visar hur du hittar servertråden om du känner till klienttråden. Ett exempel på omvänd teknik finns i Identifiera anroparen från servertråden.

  • Last updated on