Import von Extended Events Ereignisdateien und Parsen von Deadlock-Graphen

Diesmal soll es um etwas gehen, das Extended Events direkt von Haus aus besser und leichter verfügbar machen, als sämtliche Techniken zuvor: Speichern von aufgetretenen Deadlock-Ereignissen, und das Analysieren der entsprechenden Deadlock-Graphen.

Deadlocks, die man hier erläutert finden kann, treten zwischen mindestens 2 Arbeits-Threads auf, oft aber sind mehr als 2 beteiligt. – Ich wähle „Thread“ absichtlich, da Prozess nicht genau genug wäre. Meistens treten Deadlocks zwar zwischen verschiedenen Sessions/Prozessen auf, aber es kann sich auch ein Prozess, der auf parallelen Threads ausgeführt wird, selbst blockieren. Die Fehlernummer für Deadlocks ist die sicherlich allen SQL Profis bekannte „1205“.

Um Deadlocks zu Tracen gab es vor SQL Server 2008 nur die folgenden Möglichkeiten:

Eine SQL Trace mit Profiler oder auch ohne GUI mit Protokollierung in trc-Datei oder live in der GUI
Trace Flags 1204, 1205 oder 1222, welche in das Errorlog des SQL Servers protokollieren – „wunderbar“ besonders auf „ereignisreichen“ Servern, und denkbar schwierig für die Analyse.

Manch einer mag sich noch an diese grausigen Einträge im Error-Log erinnern:

3. Event Notifications, welche die Daten per Service Broker Queue in XML-Format zur Verfügung stellen. Hier findet sich ein ausführliches Beispiel mit Speicherung in Tabelle und automatischem Mail-Versand mit Info über das Event.

4. Ein WMI-Alert, welcher die Daten ebenfalls per XML bereitstellt und mit einem Auftrag oder einer Benachrichtigung gekoppelt diesen protokollieren bzw. darüber informieren kann.

All diese Ansätze, so unterschiedliche Vorteile sie auch haben mögen haben eines gemeinsam: Sie müssen erst eingerichtet werden. Im Zweifelsfalle also nachdem die ersten Deadlocks aufgetreten sind.

Seit SQL Server 2008 jedoch werden sämtliche Deadlocks von Hause aus protokolliert.

Das geschieht durch die automatisch laufende system_health Extended Event session.

Diese speichert neben Deadlocks noch weitere wichtige Server-Ereignis- und Fehler-Informationen ab. Hier finden sich Details dazu.

Seit SQL Server 2012 protokolliert die system_health session neben dem Memory-Ziel „Ring_Buffer“ auch in die Ereignisdatei, womit Deadlocks und weitere Fehler auch nach Serverneustart noch eine ganze Weile (bis zu mehreren Tagen) zur Verfügung stehen – bis der Rollover der 5 Dateien stattgefunden hat.

Für SQL Server 2008 Instanzen empfehle ich, das Datei-Ziel hinzuzufügen.

Wie kann man diese Daten auslesen? Das geht per T-SQL relativ einfach, wenn man weiß, dass diese Daten über die DMV sys. dm_xe_session_targets verfügbar sind. So liest man das Ring-Buffer-Ziel aus:

SELECT

target_data

FROM

sys.dm_xe_session_targets AS dm_xe_session_targets

INNER JOIN sys.dm_xe_sessions AS dm_xe_sessions

ON dm_xe_session_targets.event_session_address = dm_xe_sessions.address

WHERE

dm_xe_sessions.name = ’system_health‘

AND target_name = ‚ring_buffer‘

„Target_data“ ist XML-text gespeichert als unicode-text-Blob, welches man bei entsprechender Konvertierung zu XML sogar in SSMS direkt öffnen kann. Um nur die Deadlock-Events dort heraus zu filtern, muss man die XQuery-Erweiterungen von T-SQL bemühen.

Das sieht dann vom Code her so aus:

Wenn man einen solchen Deadlock-Report in XML-Format in SSMS anklickt, bekommt man ihn in einem neuen Fenster als XML-Dokument angezeigt:

– im Bild habe ich zur Übersicht einige Knoten zugeklappt.

Wichtig hier sind: die victim-list, welche bei einem Multi-Victim-Deadlock dann je Victim eine Prozess-Id enthält, die man wiederum in der process-list näher untersuchen kann.

Im executionStack findet man dann denn ausgeführten SQL-Befehl und ggfl. sogar direkt den Prozedurnamen.

Darunter folgt in der resource-list eine Liste der beteiligten (gesperrten) Ressourcen.

Sämtliche Nodes sind mit Details wie der Zeilennummer, Objektname, Lock-Modus, Wartezeit, SPID und natürlich Zeitstempeln gespickt.

Wer hier ansetzen möchte, kann das XML natürlich weiter auseinandernehmen und einzelne Knoten versuchen relational in Spaltenform darzustellen. Dafür muss man zunächst den Deadlock-Graphen extrahieren:

CAST(XEventData.XEvent.query(‚(data/value/deadlock)[1]‘) AS xml) AS DeadlockGraph

Von dort aus kann man leicht die einzelnen Knoten parsen. An das Transaction Isolation Level kommt man z.B. mit der value-Methode, wenn man einmal weiß, auf welcher Ebene/in welchem Knoten des Graphen sie sich befindet:

XMLCol.value(‚(/deadlock/process-list/process)[1]/@isolationlevel‘, ‚varchar(100)‘)

Auf die Weise kann man mit fast allen Attributen und Elementen verfahren. Bei den Sperr-Informationen stößt man dabei jedoch an die Grenzen der statischen relationalen Darstellung, da dort je nach gesperrter Resource völlig andere Attribute auftauchen.

Das zweite Problem tritt dann auf, wenn man Multi-Victim-Deadlocks vor sich hat.

Potentiell kann es ja eine Unmenge an gesperrten und gekillten Victim-Prozessen geben, so dass man da kaum ein immer ausreichendes Schema aufbauen kann.

Hier ein Beispiel eines Multi-Victim-Deadlocks, dargestellt mit der XEvents GUI (Profiler beherrschte das, wie so vieles, nicht)

Letzten Monat habe ich meinen SQL Deadlock-Collector & Parser bei codeplex frei downloadbar veröffentlicht.

– hier der direkte Link: SQL Deadlock Collector & Parser

– Hier zum Artikel mit ausführlicher Beschreibung:

freier Deadlock-Sammler & -Parser basierend auf Erweiterten Ereignissen

Dort habe ich mich so entschieden, immer die beiden ersten Prozesse gegenüberzustellen, was bei den meisten Deadlocks schon sehr weiterhilft. Das sieht dann so aus:

Wie kann man nun die ja ebenfalls von der system_health-session geschriebenen Event-Dateien einlesen?

Dafür wird die Systemfunktion sys.fn_xe_file_target_read_file bereitgestellt. Diese benötigt den Pfad zur xel-Datei und den Namen der ersten Datei, welche eingelesen werden soll. Die Dateien liegen übrigens im Log-Verzeichnis der SQL Server Instanz. Wenn man den Dateinamen nicht angibt, werden alle Dateien im Verzeichnis eingelesen. Was die Funktion jedoch wirklich praktisch macht, ist, dass man bereits den Pfad mit einer Wildcard für den Dateinamen versehen kann, dass man den Dateinamen praktisch kaum noch benötigt.

So kann das dann aussehen:

1503_fn_xe_file_target_read_file_system_health_deadlocks

Wer bereits den Deadlock-Collector zum Parsen und Speichern seiner Deadlocks verwendet, kann damit ebenfalls manuell Deadlocks von X-beliebigen Systemen in die SQL_Analysis_Data-Datenbank importieren. Dafür verwendet man einfach die Prozedur Locking.ins_DeadLock in der Datenbank SQL_Analysis_Code mit dem Parameter @XESource.

Dieser ist standardmäßig auf die Verwendung des Ring_Buffers geschaltet. Aber man kann auch einfach den Pfad + Dateinamen der zu importierenden xel-Datei übergeben:

USE SQL_Analysis_Code;

DECLARE @DeadlocksCollected int;

EXECUTE Locking.ins_DeadLock

@XESource = ‚D:\LogFiles\SQLServer\SQL2012Dev\system_health_*.xel‘

, @DeadlocksCollected = @DeadlocksCollected OUTPUT;

SELECT @DeadlocksCollected AS [Number of new Deadlocks collected:];

Anschließend kann man die Deadlocks wie hier beschrieben über Sichten oder Ad-Hoc T-SQL bequem halbwegs in relationaler Struktur analysieren.

Hinweis:

Es ist möglich, dass Deadlocks aufreten, die nicht in den system_health_session-Speicherzielen, also weder in Ring_Buffer noch in der Eventdate zu finden sind. Das geschieht, wenn der Deadlock-Graph zu groß für den Puffer-Speicher ist. Um sicherzustellen, dass auch größere Deadlocks gesammelt werden können, empfehle ich, den Puffer-Speicher der system_health-session zu erhöhen.

Und wer jetzt immer noch auf Profiler & SQL Trace setzt (seit SQL Server 2012 aus gutem Gründen deprecated), hier noch ein Tipp: So sieht ein MultiVictim-Deadlock im Profiler aus:

Das sieht eher wie ein „Multi-Winner-Deadlock“ aus 😉

Und so stellt sich dieser in der XEvents GUI dar: