Partager via

Analyse d’un problème d’appel bloqué

  • Article

Un problème courant se produit lorsqu’un processus effectue un appel RPC, directement ou indirectement, tout en conservant une section critique ou une ressource. Dans ce cas, l’appel RPC est envoyé à un autre processus ou à un autre ordinateur et est distribué à la routine du gestionnaire (routine serveur), qui se bloque ou prend trop de temps. Cela entraîne l’expiration d’un délai d’attente de section critique pour l’appelant d’origine.

Lorsqu’il est examiné via le débogueur, RPC se trouve au-dessus de la pile du thread qui possède la section critique, mais il n’est pas clair ce qu’il attend.

Voici un exemple d’une telle pile. De nombreuses variantes sont possibles.

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

Voici comment résoudre ce problème.

Résolution d’un problème d’appel bloqué - étape par étape

  1. Vérifiez que le débogueur débogue le processus qui possède la cellule bloquée. (Il s’agit du processus qui contient le thread client soupçonné d’être suspendu dans RPC.)

  2. Obtenez le pointeur de pile de ce thread. La pile ressemblera à celle présentée dans l’exemple précédent. Dans cet exemple, le pointeur de pile est 0x0068FBA0.

  3. Obtenez les informations d’appel pour ce thread. Pour ce faire, utilisez l’extension !rpcexts.rpcreadstack avec le pointeur de pile de threads comme paramètre, comme suit :

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)

Les informations affichées ici vous permettront de suivre l’appel.

  1. L’adresse réseau est vide, ce qui indique l’ordinateur local. Le point de terminaison est 1120. Vous devez déterminer quel processus héberge ce point de terminaison. Pour ce faire, transmettez ce numéro de point de terminaison à l’extension !rpcexts.getendpointinfo , comme suit :
    0:001> !rpcexts.getendpointinfo 1120
    Searching for endpoint info ...
    PID  CELL ID   ST PROTSEQ        ENDPOINT
    --------------------------------------------
    0278 0000.0001 01            TCP 1120
  1. À partir des informations précédentes, vous pouvez voir que le processus 0x278 contient ce point de terminaison. Vous pouvez déterminer si ce processus connaît quelque chose de cet appel à l’aide de l’extension !rpcexts.getcallinfo . Cette extension nécessite quatre paramètres : CallID, IfStart et ProcNum (qui ont été trouvés à l’étape 3), et le ProcessID de 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. Les informations de l’étape 5 sont utiles, mais quelque peu abrégées. L’ID de cellule est donné dans la deuxième colonne sous la forme 0000.0004. Si vous transmettez l’ID de processus et ce numéro de cellule à l’extension !rpcexts.getdbgcell , vous verrez un affichage plus lisible de cette cellule :
    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

Cela montre que l’appel est à l’état « dispatched », ce qui signifie que a quitté l’exécution RPC. L’heure de la dernière mise à jour est 470.25. Vous pouvez découvrir l’heure actuelle à l’aide de l’extension !rpcexts.rpctime :

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

Cela montre que le dernier contact avec cet appel remonte à environ 5 533 secondes, soit environ 92 minutes. Par conséquent, il doit s’agir d’un appel bloqué.

  1. En guise de dernière étape avant d’attacher un débogueur au processus serveur, vous pouvez isoler le thread qui doit actuellement traiter l’appel à l’aide de l’identificateur de thread de maintenance. Il s’agit d’un autre numéro de cellule ; il est apparu à l’étape 6 comme « 0x0.2 ». Vous pouvez l’utiliser comme suit :
    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)

Vous savez maintenant que vous recherchez des 0x1A4 de thread dans les 0x278 de processus.

Il est possible que le thread effectue un autre appel RPC. Si nécessaire, vous pouvez suivre cet appel en répétant cette procédure.

Note Cette procédure montre comment rechercher le thread de serveur si vous connaissez le thread client. Pour obtenir un exemple de la technique inverse, consultez Identification de l’appelant à partir du thread de serveur.