중단된 통화 문제 분석

아티클
06/15/2023

일반적인 문제는 프로세스가 중요한 섹션 또는 리소스를 보유하는 동안 직접 또는 간접적으로 RPC를 호출할 때 발생합니다. 이 경우 RPC 호출은 다른 프로세스 또는 컴퓨터로 이동하여 관리자 루틴(서버 루틴)으로 디스패치한 다음 중단되거나 너무 오래 걸립니다. 이렇게 하면 원래 호출자가 중요한 섹션 시간 초과가 발생합니다.

디버거를 통해 검사할 때 RPC는 중요한 섹션을 소유한 스레드 스택의 맨 위에 있지만 무엇을 기다리고 있는지는 명확하지 않습니다.

이러한 스택의 한 가지 예는 다음과 같습니다. 다양한 변형이 가능합니다.

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

이 문제를 해결하는 방법은 다음과 같습니다.

중단된 통화 문제 해결 - 단계별

디버거가 중단된 셀을 소유하는 프로세스를 디버깅하고 있는지 확인합니다. (RPC에 매달려 있는 것으로 의심되는 클라이언트 스레드를 포함하는 프로세스입니다.)
이 스레드의 스택 포인터를 가져옵니다. 스택은 앞의 예제와 같이 표시됩니다. 이 예제에서는 스택 포인터가 0x0068FBA0.
이 스레드에 대한 호출 정보를 가져옵니다. 이렇게 하려면 다음과 같이 스레드 스택 포인터를 매개 변수로 사용하여 !rpcexts.rpcreadstack 확장을 사용합니다.

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)

여기에 표시된 정보를 사용하면 호출을 추적할 수 있습니다.

로컬 컴퓨터를 나타내는 네트워크 주소가 비어 있습니다. 엔드포인트는 1120입니다. 이 엔드포인트를 호스트하는 프로세스를 결정해야 합니다. 이 작업은 다음과 같이 이 엔드포인트 번호를 !rpcexts.getendpointinfo 확장에 전달하여 수행할 수 있습니다.

    0:001> !rpcexts.getendpointinfo 1120
    Searching for endpoint info ...
    PID  CELL ID   ST PROTSEQ        ENDPOINT
    --------------------------------------------
    0278 0000.0001 01            TCP 1120

앞의 정보에서 프로세스 0x278 이 엔드포인트를 포함하는 것을 볼 수 있습니다. !rpcexts.getcallinfo 확장을 사용하여 이 프로세스에서 이 호출에 대해 아무것도 알 수 있는지 확인할 수 있습니다. 이 확장에는 CallID, IfStart 및 ProcNum (3단계에서 발견됨) 및 0x278 ProcessID 의 네 가지 매개 변수가 필요합니다.

    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

5단계의 정보는 유용하지만 다소 약어입니다. 셀 ID는 두 번째 열에 0000.0004로 지정됩니다. 프로세스 ID와 이 셀 번호를 !rpcexts.getdbgcell 확장에 전달하면 이 셀의 더 읽기 쉬운 표시가 표시됩니다.

    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

이는 호출이 "dispatched" 상태임을 보여 하며, 이는 가 RPC 런타임을 떠났다는 것을 의미합니다. 마지막 업데이트 시간은 470.25입니다. !rpcexts.rpctime 확장을 사용하여 현재 시간을 알아볼 수 있습니다.

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

이 호출의 마지막 접촉은 약 5533초(약 92분)였다는 것을 보여줍니다. 따라서 이 호출은 중단된 호출이어야 합니다.

서버 프로세스에 디버거를 연결하기 전 마지막 단계로 서비스 스레드 식별자를 사용하여 현재 호출을 처리해야 하는 스레드를 격리할 수 있습니다. 다른 셀 번호입니다. 6단계에서 "0x0.2"로 표시되었습니다. 다음과 같이 사용할 수 있습니다.

    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)

이제 프로세스 0x278 스레드 0x1A4 찾고 있습니다.

스레드가 다른 RPC 호출을 하고 있었던 것일 수 있습니다. 필요한 경우 이 절차를 반복하여 이 호출을 추적할 수 있습니다.

참고 이 절차에서는 클라이언트 스레드를 알고 있는 경우 서버 스레드를 찾는 방법을 보여줍니다. 역방향 기술의 예는 서버 스레드에서 호출자 식별을 참조하세요.

다음을 통해 공유

중단된 통화 문제 분석

중단된 통화 문제 해결 - 단계별

피드백

추가 리소스