Serverbasierter Trace

Oft stellt sich einem die Frage, wie beobachtet man am besten ein Ereignis auf dem SQLServer was nur sporadisch auftritt. Seit Einführung des Profilers hat man eine einfache Möglichkeit über ein GUI live am Geschehen teilzunehmen. Nur wer möchte so ein GUI am Client oder Server über Wochen laufen lassen um einem Problem auf die Spur zu kommen?

Spurensuche bei Bedarf

Abhilfe schafft hier die Möglichkeit einen Trace aufzusetzen, der nur bei Bedarf die wichtigen Informationen in eine Datei schreibt und ansonsten die Performance des Servers nicht beeinträchtigt. Auch macht man sich nicht von der Verfügbarkeit eines Clients abhängig, sondern arbeitet absolut autark. Bei größeren Datenmengen kann die Aufbereitung im GUI außerdem einen Performance-Engpass darstellen und man läuft Gefahr einzelne Ereignisse zu verpassen.

Wie Kalen Delaney in ihrem Artikel Tracking down Event Clues ausführt, teilt der SQL Server 2000 die Tracing Funktionalität in zwei separate aber miteinander verbundene Komponenten. Auf der Serverseite ist die SQL Trace Maschinerie, welche die Warteschlangen der Ereignisse kontrolliert. Ein anderer Thread, welcher "consumer thread" genannt wird, liest diese Ereignisse aus der Warteschlange und filtert diese bevor sie an den anfragenden Prozess gesendet werden. Überhaupt dreht sich alles um diese Ereignisse (Events) und ein Ereignis kann wirklich alles sein, was innerhalb vom SQLServer passiert, oder bei der Kommunikation vom SQLServer und Client auftritt.

Basisfunktionen

Der SQLServer stellt hierzu einige grundlegende Prozeduren zur Verfügung. Eine sehr ausführliche Beschreibung findet sich in der Online-Doku des SQLServers (BOL) wieder.
Man kommt in der Regel mit vier Prozeduren aus:

Prozedur Name Funktion
sp_trace_create Dient zur grundlegenden Einrichtung eines Traces und benennt u. a. den Namen der Ausgabedatei. Der Rückgabewert ist eine Zahl, die zur weiteren Definition und Kontrolle benötigt wird.
sp_trace_setevent Definiert, welche Ereignisse beobachtet werden.
sp_trace_setfilter Definiert Filter auf die beobachteten Daten.
sp_trace_setstatus Startet, stoppt, und entfernt einen Trace.

Definition von Ereignissen

An dieser Stelle soll noch einmal auf die Definition der Ereignisse eingegangen werden. Anders als im GUI, wo Ereignisse und Datenspalten auf zwei Laschen unabhängig voneinander geführt werden, ist hier die Definition einer Datenspalte in Verbindung mit einem Ereignis notwendig.
So soll z. B. das Ereignis "Login Failed" beobachtet werden. Hierzu soll die Datenspalte "ClientHostName" protokolliert werden. Laut BOL sind die Event_ID 20 und die Column_ID 8 zu kombinieren. Der Befehl für sp_trace_setevent lautet also vollständig:

sp_trace_setevent @TraceID, 20, 8, @ON

wobei die lokalen Variablen @TraceID und @ON auf entsprechende Werte zu setzen sind. @TraceID ist die eindeutige Nummer der Ablaufverfolgung, die geändert werden soll. @On wird als Schalter definiert um einzelne Ereignisse gezielt an- oder abschalten zu können.

Basierend auf den Listen in der Online-Doku lässt sich eine entsprechende Matrix aufbauen, die alle Ereignisse und die zu beobachtenden Datenspalten enthält. Falls man mehrere Ereignisse im gleichen Trace protokolliert, kann man unterschiedliche Datenspalten je Ereignis auswählen. Später erscheinen bei der Betrachtung der Trace-Datei mit dem Profiler die Spalten leer, die nicht zu dem jeweiligen Ereignis definiert wurden. Dieses Bild unterscheidet sich eindeutig von der gleichgefüllten Protokolldatei bei der Definition über das GUI. So ist z. B. bei der Auswahl der Spalte NTDomainName für das Ereignis ExistingConnection und den Datenspalten TextData, NTUSerName, NTDomainName, StartTime für AuditLoginFailed folgendes Ergebnis denkbar:

Event ClassTextDataNTUserNameNTDomainNameSPIDStartTime
TraceStart 97 2005-04-04 11:29:10.250
ExistingConnection meineDomäne 94
ExistingConnection meineDomäne 95
AuditLoginFailed Login failed for user 'test'. meinWindowsUser meineDomäne 97 2005-04-04 11:29:11.233
TraceStop 97 2005-04-04 11:29:12.150

Grundlegender Ablauf

Wie geht man nun am besten bei der Beobachtung von Ereignissen vor? Man sollte dies in folgende Schritte unterteilen:

  1. Definition eines Trace mit Ausgabedatei
  2. Definition der zu beobachtenden Ereignisse und Daten
  3. Definition von Filterkriterien
  4. Starten eines Trace
  5. Beobachten, ob der Trace noch lebt
  6. Entscheiden, wann ein Trace beendet wird
    Dies kann z. B. auf Grund von Einträgen im Protokoll des SQLServers geschehen, oder nach Meldung von Besonderheiten durch die Anwender
  7. Anhalten eines Trace
    Man kann diesen dann auch einfach wieder starten
  8. Beenden eines Trace
  9. Auswertung mittels Profiler
    Das GUI ist halt auch hier sinnvoll einsetzbar

Ein Praxisbeispiel

Die Beobachtung von fehlerhaften Anmeldungen kann zwar direkt durch den SQLServer erfolgen und wird dort auch im Protokoll vermerkt, nur erhält man keinen Hinweis darauf, wer genau dieses fehlerhafte Login versuchte. Es wäre doch schön herauszufinden, von welcher Maschine diese Anforderung kam, welche Applikation diese auslöste, oder welcher Domänen-User dafür verantwortlich ist. All dies kann man mit einem Trace herausfinden.

Entsprechend der oben beschriebenen Liste sollen hier die konkreten Schritte aufgezeigt werden, welche zur Spurensuche für fehlerhafte Anmeldungen notwendig sind. Die Ermittlung des Return-Codes der einzelnen Aufrufe macht natürlich wenig Sinn, falls keine Fehlerbehandlung erfolgt. Aus Gründen der Übersichtlichkeit wurde an dieser Stelle auf die Auswertung verzichtet.

AktionT-SQL
1. Definition eines Trace mit Ausgabedatei
Die Endung .trc ist die Standardeinstellung. Der Trace kann nicht angelegt werden, falls die Ausgabedatei bereits existiert. Als Rückgabewert @RC erhält man dann 12. Bei erfolgreicher Anlage 0.
DECLARE @ReturnCode int, @TraceID int, @ON bit
SET @ON = 1
EXEC @ReturnCode = sp_trace_create @TraceID OUTPUT, 0, N'C:\TraceLogin'
SELECT 'RC'= @ReturnCode, 'TraceID'= @TraceID
2. Definition der zu beobachtenden Ereignisse und Daten
>-- Login failed, start time
EXEC @ReturnCode = sp_trace_setevent @TraceID, 20, 14, @ON

-- Login failed, NT Domain Name
EXEC @ReturnCode = sp_trace_setevent @TraceID, 20, 7, @ON

-- Login failed, Host Name
EXEC @ReturnCode = sp_trace_setevent @TraceID, 20, 8, @ON

-- Login failed, Text Data
EXEC @ReturnCode = sp_trace_setevent @TraceID, 20, 1, @ON

-- Login failed, ApplicationName
EXEC @ReturnCode = sp_trace_setevent @TraceID, 20, 10, @ON

-- Login failed, NTUserName
EXEC @ReturnCode = sp_trace_setevent @TraceID, 20, 6, @ON

-- Login failed, SQLSecurityLoginName
EXEC @ReturnCode = sp_trace_setevent @TraceID, 20, 11, @ON
3. Starten eines Trace
-- Starte Trace (status 1 = start).
EXEC  sp_trace_setstatus @TraceID, 1
4. Beobachten, ob der Trace noch lebt
Dies kann bei einer längeren Lebensdauer schon mal notwendig sein, wenn man nicht sicher ist, dass niemand anderes evtl. einen Trace abbricht. Auch ist nach Neustart des Servers der Trace nicht mehr vorhanden. Dies könnte man durch eine Autostart-Prozedur natürlich umgehen.
-- Zeige Information
SELECT * FROM :: fn_trace_getinfo(default)
5. Anhalten eines Trace
-- Stopp Trace (status 0 = stop).
-- Die Function fn_trace_getinfo() zeigt weiterhin den Trace und
--    man kann diesen durch zurücksetzen des Status auf 1 wieder starten.
-- Die in spitzen Klammern gesetzte Zahl muss durch die entsprechende Trace-ID
-- ersetzt werden.
EXEC  sp_trace_setstatus <1>, 0
6. Beenden eines Trace
-- Beende Trace (status 2 = remove).
-- Die Function fn_trace_getinfo() zeigt nicht mehr den Trace an
--    und er kann auch nicht neu gestartet werden.
-- Die in spitzen Klammern gesetzte Zahl muss durch die entsprechende Trace-ID
-- ersetzt werden.
EXEC  sp_trace_setstatus <1>, 2
7. Starten des Profilers und auswerten der Spurensuche

Ereignisse filtern

In der Regel will man ja nicht alle Ereignisse auf dem Server protokollieren, sondern gezielt einzelne Sessions oder Statements beobachten. Hierzu gibt es die Möglichkeit entsprechende Filter zu definieren.

Anders als das GUI, welches oft nur LIKE kennt und Filter zu einer Option in der Regel über ODER verknüpft, ist es möglich bei der manuellen Erstellung eines Trace (zu deutsch Ablaufverfolgung) deutlich spezifischer vorzugehen.
Hierfür kommt sp_trace_setfilter zum Einsatz. Diese Prozedur kennt insgesamt fünf Parameter:

  1. @traceid: Basis ist hier natürlich auch wieder die Nummer der vorab definierten Ablaufverfolgung.
  2. @columnid: Wieder kommt es darauf an zu einer Spalte, deren Nummer man sich wieder aus der Online-Doku besorgt verschiedene Angaben zu machen. Die Liste steht aber nur im Kapitel zu sp_trace_setevent!
  3. @logical_operator: Der dritte Parameter definiert, ob es sich um eine UND- (0) bzw. ODER-Verknüpfung (1) zu den bestehenden Filter-Kriterien handelt.
  4. @comparison_operator: Der vierte Parameter öffnet einem das weite Feld der möglichen Vergleichsoperatoren (=, <>, Like, ...). Die vollständige Liste findet sich wieder in der Online-Doku.
  5. @value: Als letztes muss natürlich der Vergleichswert angegeben werden.

Noch ein Praxisbeispiel

Das folgende Beispiel verdeutlicht die Möglichkeiten:

-- Filter setzen auf TextData(1) ODER verknüpft mit bisherigen anderen Filtern(1) like (6)
EXEC sp_trace_setfilter @TraceID, 1, 1, 6, N'%select%'

-- Filter setzen auf TextData(1) UND verknüpft mit bisherigen anderen Filtern(0) like (6)
EXEC sp_trace_setfilter @TraceID, 1, 0, 6, N'%author%'

-- Filter setzen auf DatabaseID(3) UND verknüpft mit bisherigen anderen Filtern(1) equal (0)
declare @myID int
select @myid = dbid from master..sysdatabases
where name = 'pubs'
EXEC sp_trace_setfilter @TraceID, 3, 0, 0, @myid

Hier werden also nur Statements, die ein SELECT verbunden mit AUTHOR gegen die Datenbank PUBS durchführen protokolliert. Man könnte die Abfrage des Statements natürlich auch in einem Filter zusammenfassen, aber dieses Beispiel soll vor allem die Möglichkeiten veranschaulichen. Ändert man nämlich den zweiten Filter wie folgt ab:

-- Filter setzen auf TextData(1) UND verknüpft mit bisherigen anderen Filtern(0) not like (7)
EXEC sp_trace_setfilter @TraceID, 1, 0, 7, N'%author%'

so erhält man plötzlich alle SELECT-Statements, die nicht im Zusammenhang mit AUTHOR stehen.

Ablaufverfolgung überwachen und verwalten

Wer sich nach erfolgreicher Definition einen Überblick über die aktuellen Filterkriterien eines gestarteten Traces verschaffen will, kann diese mit der Funktion fn_trace_getfilterinfo(1) tun.

-- Show Filter information
SELECT * FROM :: fn_trace_getfilterinfo(1)

Die Ausgabe ist leider wieder nur eine Auflistung der vorab definierten Parametern.

Wer sich weiter mit der Überwachung und Verwaltung von Ablaufverfolgungen beschäftigen will, sollte sich diesen Artikel aus der Knowledge-Base zu Gemüte führen: INF: How to Monitor SQL Server 2000 Traces
Hier bleiben eigentlich keine Wünsche offen und man gewinnt schnell einen Überblick über die definierten Ablaufverfolgungen und ihre Parameter.

Ergänzung für SQLServer2005

Für die Version SQLServer2005 gibt es zusätzliche Spalten, die im Trace enthalten sein können. Um auch diese Informationen entsprechend ausgeben zu können, ergänze man die Prozedur für den SQLServer2000 nach der Zeile

insert @columns values (44,'ColumnPermissionsSet')

wie folgt:

--
-- Ergänzung für SQLServer2005
--
insert @columns values (45, 'LinkedServerName')
insert @columns values (46, 'ProviderName')
insert @columns values (47, 'MethodName')
insert @columns values (48, 'RowCounts')
insert @columns values (49, 'RequestID')
insert @columns values (50, 'XactSequence')
insert @columns values (51, 'EventSequence')
insert @columns values (52, 'BigintData1')
insert @columns values (53, 'BigintData2')
insert @columns values (54, 'GUID')
insert @columns values (55, 'IntegerData2')
insert @columns values (56, 'ObjectID2')
insert @columns values (57, 'Type')
insert @columns values (58, 'OwnerID')
insert @columns values (59, 'ParentName')
insert @columns values (60, 'IsSystem')
insert @columns values (61, 'Offset')
insert @columns values (62, 'SourceDatabaseID')
insert @columns values (63, 'SqlHandle')
insert @columns values (64, 'SessionLoginName')

Skript erstellen lassen

Wem die manuelle Definition zu mühsam ist, kann auch den Trace im Profiler definieren und sich anschliessend ein Skript (wahlweise für die Version 7.0 oder 2000) erstellen lassen. Dies geschieht einfach über das Menü "Datei" und dann den Punkt "Skript für Ablaufverfolgung erstellen". Allerdings muss man dann mit den Einschränkungen, die im Abschnitt "Ereignisse filtern" beschrieben wurden leben, oder man kann einfach das Skript als Vorlage für eigene Ablaufverfolgungen verwenden.