Mit PerfView und dotnet-trace die Ursache von „langsam“ finden — Praxis-Einstieg in die .NET-Performanceanalyse

Im vorherigen Beitrag, Einführung in Windows-Ereignisprotokoll und ETW, ging es darum, was ETW ist und wie eigene Ereignisse mit EventSource definiert werden; die Analyse mit PerfView blieb ausdrücklich außerhalb des Umfangs. Dieser Beitrag setzt dort an. Er behandelt den Ablauf, mit dem sich bei einer Geschäftsanwendung, die „langsam ist“, „die CPU dauerhaft auslastet“ oder „gelegentlich einfriert“, mit PerfView und dotnet-trace die verursachende Funktion finden lässt.

Dieser Beitrag konzentriert sich auf CPU- und Antwortzeitanalysen. Die Eingrenzung von Problemen mit stetig wachsendem Speicher behandelt GC-Wartezeit und Speicherlecks in .NET unterscheiden; für Abstürze siehe Crash Dumps mit WinDbg und SOS lesen.

1. Zuerst das Fazit

• „Langsam“ hat zwei unterschiedliche Formen: langsam, weil die CPU ausgelastet ist, CPU-bound, oder langsam, obwohl die CPU wenig tut und auf etwas gewartet wird, also blockiert wird. Für den ersten Fall ist CPU-Sampling nötig, für den zweiten ThreadTime-Erfassung mit Kontextwechseln. In der standardmäßigen CPU-Erfassung wird die Ursache des zweiten Falls nicht sichtbar.¹
• Wenn Sie unsicher sind, beginnen Sie mit dotnet-trace. Das plattformübergreifende Werkzeug basiert auf EventPipe und kann ohne Administratorrechte erfassen, wenn derselbe Benutzer den Zielprozess gestartet hat.² Die gesammelte Datei .nettrace lässt sich in PerfView und Visual Studio öffnen.³
• PerfView wird nötig, wenn Maschine, nativer Code und blockierte Zeit bis ins Detail sichtbar werden sollen. Da es auf ETW basiert, kann es auch Kernelereignisse und Stacks nativen Codes behandeln. Dafür sind zum Starten einer ETW-Sitzung Administratorrechte erforderlich.³
• CPU-Sampling erfolgt standardmäßig je Prozessor alle eine Millisekunde. Lesen Sie einen Sample als ungefähr eine Millisekunde CPU-Zeit und urteilen Sie erst nach mindestens 1.000, besser etwa 5.000 Samples. Die obersten Funktionen bei kleiner Samplezahl können Zufall sein.¹
• Ausgangspunkt jeder Zahlendeutung ist die Unterscheidung zwischen inclusive, eigene Zeit plus aufgerufene Zeit, und exclusive, nur eigene Zeit. Eine Funktion mit hohem exclusive-Wert ist dort, wo tatsächlich CPU verbraucht wird; ein hoher inclusive-Wert zeigt, dass irgendwo unterhalb dieser Funktion ein Engpass liegt.
• Fixieren Sie vor dem Messen die eine Operation, die „langsam“ ist. Mit einer allgemeinen Aussage wie „alles ist schwerfällig“ lässt sich keine Erfassung lesen. Legen Sie Operation und Dauer fest, etwa „Die Ausgabe dieses Berichts dauert 40 Sekunden“. Für die Vergleichsmessung vor und nach einer Verbesserung siehe auch Geschwindigkeit von Programmversionen unter Windows korrekt vergleichen.

Die folgende Entscheidungstabelle zeigt den Einstieg ausgehend vom Symptom.

2. Die Beziehung der Werkzeuge — ETW und EventPipe

Es erscheinen viele Werkzeuge, doch sie beruhen nur auf zwei Grundlagen.

• ETW, Event Tracing for Windows: eine Trace-Grundlage für das gesamte Betriebssystem. Sie kann vom Kernel bis zur Anwendung auf derselben Zeitachse aufzeichnen, benötigt aber zum Starten und Stoppen einer Sitzung Administratorrechte und ist auf Windows beschränkt.³
• EventPipe: ein in die .NET-Laufzeit integrierter Trace-Mechanismus. Er braucht keine Administratorrechte und funktioniert auf allen Betriebssystemen ähnlich, zeigt aber nur verwalteten Code und die Laufzeit; Kernelereignisse und native Stacks lassen sich nicht erfassen.²

Mit dieser Zuordnung ergibt sich die Nutzung ganz natürlich: zuerst schnell mit dotnet-trace erfassen, und wenn das nicht reicht, mit PerfView einschließlich ETW erfassen.

3. Vor der Erfassung — zehn Minuten Trends mit dotnet-counters ansehen

Oft ist es schneller, nicht sofort einen Trace aufzuzeichnen, sondern zunächst mit dotnet-counters die wichtigsten Metriken der Laufzeit anzusehen.⁴

dotnet tool install --global dotnet-counters
dotnet-counters ps
dotnet-counters monitor --process-id <PID> --counters System.Runtime

Beobachten Sie hier CPU-Auslastung, Größe des GC-Heaps und Anzahl der GCs, Warteschlangenlänge und Threadanzahl des ThreadPool sowie die Zahl der Ausnahmen. Zeigt sich schon an dieser Stelle ein Muster wie „Der GC läuft mehrmals pro Sekunde“ oder „Die ThreadPool-Warteschlange wächst fortlaufend“, lässt sich die Art des nächsten Traces eingrenzen: Zuweisungen oder Blockierung. Die Interpretation von Speichertrends erläutert GC-Wartezeit und Speicherlecks in .NET unterscheiden ausführlicher.

4. Einen Trace mit dotnet-trace erfassen

dotnet-trace ist ein auf EventPipe basierendes Erfassungswerkzeug.⁵ Installation und grundlegende Erfassung sehen so aus:

dotnet tool install --global dotnet-trace
dotnet-trace ps
dotnet-trace collect --process-id <PID> --duration 00:00:00:30

Ohne weitere Optionen wird mit einem Standardprofil gesammelt, das wichtige Laufzeitereignisse und Thread-Sampling enthält. Das frühere Profil namens cpu-sampling wurde eingestellt; heute ist die Kombination aus dotnet-common und dotnet-sampled-thread-time der Standard.⁵ Je nach Zweck können auch --profile gc-verbose für GC und Sampling von Objektzuweisungen oder --profile gc-collect für eine ressourcenschonende Aufzeichnung nur der GC-Vorgänge gewählt werden.

Um den eigenen EventSource-Provider aus dem vorherigen Beitrag mit zu erfassen, ergänzen Sie --providers.

dotnet-trace collect --process-id <PID> --providers KomuraSoft-OrderService

Das Ergebnis ist eine Datei .nettrace. Sie lässt sich auf drei Arten öffnen: in Visual Studio, in PerfView oder nach der Umwandlung in das Speedscope-Format im Browser.⁵

dotnet-trace convert trace.nettrace --format Speedscope

Das Speedscope-Format bietet in speedscope.app eine schlanke Flamegraph-Ansicht und eignet sich, um intuitiv zu sehen, unter welcher Funktion Zeit verbraucht wurde. Für die genaue Ermittlung bis zum Funktionsnamen ist der Stack Viewer von PerfView stärker; deshalb geht es im nächsten Abschnitt dorthin weiter.

5. CPU mit PerfView untersuchen — den Stack Viewer lesen

PerfView ist ein von Microsoft kostenlos bereitgestelltes Werkzeug zur Leistungsanalyse. Es läuft, indem lediglich die eine Datei PerfView.exe von der GitHub-Release-Seite heruntergeladen wird; eine Installation ist nicht nötig.⁶

5.1 Erfassen

Über die Benutzeroberfläche öffnen Sie mit „Collect > Collect“ den Dialog und folgen Start Collection → Zieloperation reproduzieren → Stop Collection. In der Befehlszeile sieht es so aus; weil eine ETW-Sitzung gestartet wird, muss der Befehl als Administrator ausgeführt werden.³

PerfView collect /nogui /acceptEULA /maxCollectSec:30

Die Standarderfassung enthält auf allen Prozessoren CPU-Samples im Abstand von einer Millisekunde mit Call Stack sowie wichtige CLR-Ereignisse.¹ Der Overhead während der Erfassung wird in der Standardkonfiguration mit ungefähr wenigen Prozent angegeben.⁷

5.2 CPU Stacks lesen

Öffnen Sie das Ergebnis, .etl.zip, und wählen Sie im Bereich „CPU Stacks“ den Zielprozess. Dadurch öffnet sich der Stack Viewer. Als Erstes sind im Reiter By Name zwei Spalten wichtig:

• Exc (exclusive): Anzahl der Samples, während die Funktion selbst ausgeführt wurde. Das ist der Ort, der tatsächlich CPU verbraucht.
• Inc (inclusive): Summe der Samples dieser Funktion und aller von ihr aufgerufenen Funktionen. Das zeigt, dass irgendwo darunter ein Engpass liegt.

Das übliche Lesemuster ist, vom oberen Ende von Exc aus einzuordnen: eigener Code oder Laufzeit/Bibliothek? Steht eigener Code weit oben bei Exc, sind der Algorithmus oder die Schleife dieser Funktion das unmittelbare Ziel. Stehen System.String oder ein JSON-Serializer weit oben bei Exc, verfolgen Sie sie im Reiter Callers nach Inc zurück und finden heraus, welcher Teil des eigenen Codes sie in großer Menge aufruft.

Ebenso wichtig ist die Anzahl der Samples selbst. CPU-Sampling ist eine Statistik in Ein-Millisekunden-Abständen und bei geringer Samplezahl zufallsanfällig. Sammeln Sie insgesamt mindestens 1.000, besser etwa 5.000 Samples, bevor Sie entscheiden; fehlt es daran, wiederholen Sie die Zieloperation und verlängern Sie die Erfassung.¹

Erscheinen Funktionsnamen eigener Module nur als Adressen, können die Symbole, PDB, nicht aufgelöst werden. Die PDBs der Build-Artefakte bereitzuhalten, entscheidet damit direkt über die Untersuchbarkeit. Näheres dazu: Was ist eine PDB, Program Database?.

6. „Die CPU tut wenig, doch es ist langsam“ — blockierte Zeit mit ThreadTime sehen

Mehr als die Hälfte der praktischen Fälle von „langsam“ sind keine CPU-, sondern Warteprobleme: Warten auf Sperren, Datenbank- oder HTTP-Antworten, Datei-I/O oder eine beinahe deadlockartige Synchronisation über Task.Result. Solche Probleme erscheinen im CPU-Sampling als Zeit, in der überhaupt keine CPU genutzt wird, und die Standarderfassung zeigt ihre Ursache deshalb nicht.

Aktivieren Sie bei der PerfView-Erfassung die Option Thread Time. Dann werden zusätzlich Ereignisse zu Kontextwechseln aufgezeichnet, sodass sich für jeden Thread sowohl die Zeit auf der CPU als auch die blockierte Zeit zusammen verfolgen lässt.¹

PerfView collect /nogui /acceptEULA /threadTime /maxCollectSec:30

In der Analyse öffnen Sie die Ansicht „Thread Time Stacks“. Sie nutzt denselben Stack Viewer wie CPU Stacks, enthält aber neben CPU-Zeit auch BLOCKED_TIME, also blockierte Zeit. Grenzen Sie zuerst das Zeitfenster der langsamen Operation ein. Prüfen Sie dann, auf welchem Stack, also welchem Warten, BLOCKED_TIME des ausführenden Threads aufläuft. So ergibt sich etwa: „Von insgesamt 40 Sekunden entfielen 35 Sekunden auf das Warten auf diesen HTTP-Aufruf.“

Auch Symptome wie eine eingefrorene Oberfläche, die einige Sekunden nicht reagiert, sind meist eine Blockierung des UI-Threads. Nachdem ThreadTime gezeigt hat, worauf dieser Thread wartet, sollte die dauerhafte Korrektur synchrones Warten in ein asynchrones Design überführen. Den Entwurfsaspekt erläutert async und UI-Thread in WPF/WinForms auf einen Blick.

Beachten Sie, dass ThreadTime-Erfassung bei jedem Kontextwechsel ein Ereignis aufzeichnet und daher deutlich mehr Daten als die Standarderfassung erzeugt. Halten Sie die Erfassungsdauer kurz und vermeiden Sie lange Erfassungen in der Produktion.

7. Mit EventSource arbeiten — den langsamen Abschnitt in der Sprache des Geschäfts abgrenzen

CPU Stacks und Thread Time sind Aggregationen über den gesamten Prozess. Soll die Untersuchung nach einer Geschäftseinheit wie „An welcher Stelle einer Bestellverarbeitung ist es langsam?“ abgegrenzt werden, helfen die Start-/Stop-Ereignisse von EventSource aus dem vorherigen Beitrag.

• In der Anwendung Ereignisse wie OrderProcessingStart und OrderProcessingStop instrumentieren; die Implementierung zeigt der vorherige Beitrag.
• In der Ansicht „Events“ von PerfView den Zeitpunkt des Ereignisses prüfen und das Zeitfenster des Stack Viewers mit den Filtern Start/End auf diesen Abschnitt begrenzen.
• Innerhalb des begrenzten Bereichs die Aufteilung von CPU- und blockierter Zeit lesen.

Damit lässt sich nur der eine langsame Durchlauf analysieren, ohne im Rauschen des Normalbetriebs unterzugehen. Eigene Ereignisse können mit dotnet-trace genauso erfasst werden. Ist die Instrumentierung einmal vorhanden, funktioniert dieselbe Untersuchungsmethode auf Entwicklungs- und Produktionsrechnern. In der Praxis entscheidet bei Performanceanalysen weniger die Beherrschung des Werkzeugs als die Frage, ob die Anwendung selbst Beobachtungspunkte besitzt.

Fazit

• Am Anfang steht die Trennung von CPU-bound und blockierter Ursache. Der erste Fall braucht CPU-Sampling, ein Sample entspricht ungefähr einer Millisekunde; der zweite wird ohne ThreadTime-Erfassung nicht sichtbar.
• Als Grundregel gilt: zuerst dotnet-trace ohne Administratorrechte, und PerfView, wenn Maschine, nativer Code oder blockierte Zeit benötigt werden. Die gesammelte .nettrace in PerfView zu lesen, ist eine gängige Kombination.
• Im Stack Viewer ist die Unterscheidung zwischen exclusive und inclusive der Kern der Interpretation; prüfen Sie immer, ob die Samplezahl ausreicht.
• Mit eigenen EventSource-Ereignissen können Geschäftsabschnitte abgegrenzt werden, was die Genauigkeit der Untersuchung deutlich erhöht.

Komura Soft LLC unterstützt bei der Untersuchung von Leistungsproblemen in Windows-Geschäftsanwendungen, etwa „langsam“, „eingefroren“ oder „CPU dauerhaft ausgelastet“, sowie bei Instrumentierung und Design, die eine Messung erst ermöglichen. Liegen Reproduktionsschritte und eine Trace-Datei vor, kann auch nur die Analyse darauf aufbauen.

Verwandte Artikel

• Einführung in Windows-Ereignisprotokoll und ETW — Geschäftsanwendungs-Logs in die Standardmechanismen des Betriebssystems einordnen
• GC-Wartezeit und Speicherlecks in .NET unterscheiden — wachsenden Speicher beobachten, vergleichen und nachweisen
• Crash Dumps mit WinDbg und SOS lesen — praktische Einführung in die Analyse nach der Erfassung
• Einführung in die Sammlung von Windows-Crash-Dumps — WER, ProcDump und WinDbg
• Was ist eine PDB, Program Database? — Debug-Informationen, Symbole und Source Link verstehen
• Geschwindigkeit von Programmversionen unter Windows korrekt vergleichen
• async und UI-Thread in WPF/WinForms auf einen Blick

Verwandte Beratungsbereiche

• Fehleruntersuchung und Ursachenanalyse
• Windows-Anwendungsentwicklung
• Technische Beratung und Design-Review
• Kontakt

Referenzen

Verwandte Artikel

Aktuelle Artikel mit denselben Schlagwörtern führen zu verwandten Themen weiter.

Verwandte Themen

Diese Seiten ordnen den Artikel in einen größeren Leistungs- und Entscheidungskontext ein.

Leistungen zu diesem Thema

Dieser Artikel ist direkt mit den folgenden Leistungen verbunden.

Häufige Fragen

Fragen, die in Beratungen zu diesem Artikelthema häufig gestellt werden.

Sollte ich PerfView oder dotnet-trace verwenden?

Beginnen Sie am besten mit dotnet-trace. Es funktioniert ohne Administratorrechte, kann nur den Zielprozess erfassen und benötigt nur eine Befehlszeile. PerfView auf ETW-Basis ist dagegen nötig, wenn auch native Code-Stacks, der Zustand der gesamten Maschine einschließlich anderer Prozesse und des Kernels oder blockierte Zeit auf Ebene einzelner Kontextwechsel sichtbar werden sollen. Die mit dotnet-trace gesammelte .nettrace-Datei anschließend in PerfView zu öffnen und dort zu analysieren, ist ebenfalls alltäglich.

Wie verhält sich das zum Profiler von Visual Studio?

Lässt sich das Problem auf einem Entwicklungsrechner reproduzieren, sind das CPU-Auslastungswerkzeug und die Speicherwerkzeuge von Visual Studio bequemer; zunächst genügt das meist. PerfView und dotnet-trace sind besonders nützlich, wenn auf einem Prüf- oder Produktionsrechner ohne Visual Studio gesammelt wird, wenn Erfassung und Analyse auf verschiedene Rechner verteilt werden sollen oder wenn ETW-Ereignisse einschließlich eigener EventSource- und Kernelereignisse sichtbar werden müssen. Visual Studio kann auch die von dotnet-trace erzeugten .nettrace-Dateien öffnen.

Ist die Ausführung auf einem Produktionsserver sicher?

Beide Werkzeuge sind für kurze Erfassungen in der Produktion ausgelegt, jedoch nicht bedingungslos. Begrenzen Sie die Erfassung auf einige zehn Sekunden bis wenige Minuten, probieren Sie denselben Befehl zunächst in der Testumgebung aus und prüfen Sie dabei Overhead, Dateigröße und freien Speicherplatz. Gerade ThreadTime-Erfassung mit Kontextwechseln und Zuweisungstracing erzeugen sehr viele Ereignisse, sodass die Datei schnell wächst. Da ein Trace auch Informationen wie Befehlszeilenargumente enthalten kann, muss die erzeugte Datei sorgfältig behandelt werden.

Wie grenze ich WPR und WPA ab?

WPR, Windows Performance Recorder, und WPA, Windows Performance Analyzer, sind stärker am Betriebssystem orientierte Analysewerkzeuge auf derselben ETW-Grundlage. Für eine detaillierte Analyse des Gesamtsystems, etwa Datenträger-I/O, Energieverbrauch oder Startzeit, sind WPR und WPA stark. Für CPU, GC und blockierte Zeit einer .NET-Anwendung ist PerfView leichter lesbar, weil seine Darstellung für verwalteten Code optimiert ist. Für die Untersuchung einer Geschäftsanwendung reichen PerfView und dotnet-trace in den meisten Fällen aus.

Autorenprofil

Profilseite des Artikelautors.

Go Komura

Geschäftsführer von KomuraSoft LLC

Spezialisiert auf Windows-Softwareentwicklung, technische Beratung und Fehleranalyse, insbesondere bei bestehenden Systemen und schwer reproduzierbaren Störungen.