分析调用阻塞问题

项目
03/01/2024

当进程在直接或间接地执行 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

这表明调用处于“已调度”状态，意味着已离开 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 调用。如有必要，可以通过重复此过程来跟踪此调用。

注意此过程演示在已知客户端线程的情况下如何查找服务器线程。有关反向技术的示例，请参阅从服务器线程识别调用方。

通过

分析调用阻塞问题

逐步排除调用阻塞问题

反馈

其他资源