Diagnostiquer les délais de l’interface utilisateur causés par les extensions

Lorsque l’interface utilisateur devient non réactive, Visual Studio examine la trace d’appels du thread de l’interface utilisateur, en commençant par la feuille et en remontant vers la base. Si Visual Studio détermine qu’une trame de la trace d’appels appartient à un module faisant partie d’une extension installée et activée, il affiche une notification.

La notification informe l’utilisateur que le retard de l’interface utilisateur (c’est-à-dire la non-réactivité de l’interface utilisateur) pourrait être dû au code d’une extension. Elle propose également à l’utilisateur des options pour désactiver l’extension ou les notifications futures pour cette extension.

Ce document décrit comment vous pouvez diagnostiquer ce qui, dans le code de votre extension, provoque des notifications de retard de l’interface utilisateur.

Une vue d’ensemble du processus de diagnostic est la suivante :

1. Identifiez le scénario déclencheur.
2. Redémarrez Visual Studio avec la journalisation des activités activée.
3. Démarrez le traçage ETW.
4. Déclenchez à nouveau l’apparition de la notification.
5. Arrêtez le traçage ETW.
6. Examinez le journal d’activité pour obtenir l’ID du retard.
7. Analysez la trace ETW en utilisant l’ID de retard obtenu à l’étape 6.

Dans les sections suivantes, nous passerons en revue ces étapes en détail.

Identifiez le scénario déclencheur

Pour diagnostiquer un retard de l’interface utilisateur, vous devez d’abord identifier ce qui (séquence d’actions) fait que Visual Studio affiche la notification. Cela afin que vous puissiez déclencher la notification plus tard avec la journalisation activée.

Redémarrez Visual Studio avec la journalisation des activités activée

Visual Studio peut générer un « journal d’activité » qui fournit des informations utiles lors du débogage d’un problème. Pour activer la journalisation des activités dans Visual Studio, ouvrez Visual Studio avec l’option de ligne de commande /log. Après le démarrage de Visual Studio, le journal d’activité est stocké à l’emplacement suivant :

%APPDATA%\Microsoft\VisualStudio\<vs_instance_id>\ActivityLog.xml

Pour en savoir plus sur la façon de trouver l’ID de votre instance de Visual Studio, veuillez consulter la section Outils pour détecter et gérer les instances de Visual Studio. Nous utiliserons plus tard ce journal d’activité pour en savoir plus sur les retards de l’interface utilisateur et les notifications associées.

Démarrer le traçage ETW

Vous pouvez utiliser PerfView pour collecter une trace ETW. PerfView fournit une interface facile à utiliser à la fois pour collecter une trace ETW et pour l’analyser. Utilisez la commande suivante pour collecter une trace :

Perfview.exe collect C:\trace.etl /BufferSizeMB=1024 -CircularMB:2048 -Merge:true -Providers:*Microsoft-VisualStudio:@StacksEnabled=true -NoV2Rundown /kernelEvents=default+FileIOInit+ContextSwitch+Dispatcher

Cela active le fournisseur « Microsoft-VisualStudio », qui est le fournisseur utilisé par Visual Studio pour les événements liés aux notifications de retard de l’interface utilisateur. Il spécifie également le mot-clé pour le fournisseur du noyau que PerfView peut utiliser pour générer l’affichage Thread Time Stacks.

Déclenchez à nouveau l’apparition de la notification

Une fois que PerfView a démarré la collecte de traces, vous pouvez utiliser la séquence d’actions déclencheur (de l’étape 1) pour que la notification réapparaisse. Une fois la notification affichée, vous pouvez arrêter la collecte de traces pour que PerfView traite et génère le fichier de trace de sortie.

Arrêtez le traçage ETW

Pour arrêter la collecte de traces, utilisez simplement le bouton Arrêter la collecte dans la fenêtre PerfView. Après avoir arrêté la collecte de traces, PerfView traitera automatiquement les événements ETW et générera un fichier de trace de sortie.

Examinez le journal d’activité pour obtenir l’ID du retard

Comme mentionné précédemment, vous pouvez trouver le journal d’activité à %APPDATA%\Microsoft\VisualStudio<vs_instance_id>\ActivityLog.xml. Chaque fois que Visual Studio détecte un retard d’interface utilisateur dû à une extension, il écrit un nœud dans le journal d’activité avec UIDelayNotifications comme source. Ce nœud contient quatre informations sur le retard de l’interface utilisateur :

• L’ID du retard de l’interface utilisateur, un numéro séquentiel qui identifie de manière unique un retard d’interface utilisateur dans une session VS
• L’ID de session, qui identifie de manière unique votre session Visual Studio depuis le démarrage jusqu’à la fermeture
• Si une notification a été affichée ou non pour le retard de l’interface utilisateur
• L’extension qui a probablement causé le retard de l’interface utilisateur

<entry>
  <record>271</record>
  <time>2018/02/03 12:02:52.867</time>
  <type>Information</type>
  <source>UIDelayNotifications</source>
  <description>A UI delay (Delay ID = 0) has been detected. (Session ID=16e49d4b-26c2-4247-ad1c-488edeb185e0; Blamed extension="UIDelayR2"; Notification shown? Yes.)</description>
</entry>

Après avoir trouvé le retard correct dans le journal d’activité, notez l’ID de retard d’interface utilisateur spécifié dans le nœud. Vous utiliserez l’ID pour rechercher l’événement ETW correspondant dans l’étape suivante.

Analyser la trace ETW

Ensuite, ouvrez le fichier de trace. Vous pouvez le faire en utilisant la même instance de PerfView ou en démarrant une nouvelle instance et en définissant le chemin du dossier actuel en haut à gauche de la fenêtre à l’emplacement du fichier de trace.

Ensuite, sélectionnez le fichier de trace dans le volet de gauche et ouvrez-le en choisissant Ouvrir depuis le clic droit ou le menu contextuel.

Cela peut prendre plusieurs minutes à PerfView pour traiter et ouvrir la trace. Une fois la trace ouverte, une liste de divers « affichages » apparaît en dessous.

Nous utiliserons d’abord l’affichage Événements pour obtenir la plage de temps du retard de l’interface utilisateur :

1. Ouvrez l’affichage Événements en sélectionnant le nœud Events sous la trace et en choisissant Ouvrir depuis le clic droit ou le menu contextuel.
2. Sélectionnez « Microsoft-VisualStudio/ExtensionUIUnresponsiveness » dans le volet de gauche.
3. Appuyez sur Entrée

La sélection est appliquée et tous les événements ExtensionUIUnresponsiveness s’affichent dans le volet droit.

Chaque ligne dans le volet droit correspond à un retard de l’interface utilisateur. L’événement inclut une valeur « ID de retard » qui devrait correspondre à l’ID de retard dans le journal d’activité de l’étape 6. Étant donné que ExtensionUIUnresponsiveness est déclenché à la fin du retard de l’interface utilisateur, l’horodatage de l’événement marque (environ) l’heure de fin du retard de l’interface utilisateur. L’événement contient également la durée du retard. Nous pouvons soustraire la durée de l’horodatage de fin pour obtenir l’horodatage du début du retard de l’interface utilisateur.

Dans la capture d’écran précédente, par exemple, l’horodatage de l’événement est 12 125,679 et la durée du retard est de 6 143,085 (ms). Donc

• Le début du retard est 12 125,679 - 6 143,085 = 5 982,594.
• La plage de temps du retard de l’interface utilisateur est de 5 982,594 à 12 125,679.

Une fois que nous avons la plage de temps, nous pouvons fermer l’affichage Événements et ouvrir l’affichage Thread Time (with StartStop Activities) Stacks. Cet affichage est particulièrement utile car souvent les extensions qui bloquent le thread de l’interface utilisateur attendent simplement d’autres threads ou une opération liée à une E/S. Ainsi, l’affichage CPU Stack, qui est l’option par défaut pour la plupart des cas, peut ne pas capturer le temps pendant lequel le thread est bloqué puisqu’il n’utilise pas le CPU pendant cette période. L’affichage Thread Time Stacks résout ce problème en montrant correctement le temps bloqué.

Lors de l’ouverture de l’affichage Thread Time Stacks, choisissez le processus devenv pour commencer l’analyse.

Dans l’affichage Thread Time Stacks, dans le coin supérieur gauche de la page, vous pouvez définir la plage de temps sur les valeurs que nous avons calculées à l’étape précédente et appuyer sur Entrée pour ajuster les piles à cette plage de temps.

Vous pouvez également filtrer davantage cet affichage en n’incluant que les piles qui contiennent des modules de votre package.

• Définissez GroupPats sur un texte vide pour supprimer tout regroupement ajouté par défaut.
• Définissez IncPats pour inclure une partie du nom de votre assembly en plus du filtre de processus existant. Dans ce cas, cela devrait être devenv;UIDelayR2.

PerfView propose des instructions détaillées dans le menu Aide que vous pouvez utiliser pour identifier les goulots d’étranglement des performances dans votre code. De plus, les liens suivants fournissent plus d’informations sur la façon d’utiliser les API de threading de Visual Studio pour optimiser votre code :

• https://github.com/Microsoft/vs-threading/blob/master/doc/index.md
• https://github.com/Microsoft/vs-threading/blob/master/doc/cookbook_vs.md

Vous pouvez également utiliser les nouveaux analyseurs statiques Visual Studio pour extensions (paquet NuGet ici), qui fournissent des conseils sur les bonnes pratiques pour écrire des extensions efficaces. Voir la liste des analyseurs VSSDK et analyseurs de threading.