Woher kommt SQL Trace 1?

Eine erste Spur

Wer beim SQL Server 2005 einen genauen Blick auf das SQLServer-Protokoll nach einem Neustart wirft, wird dort folgende Zeile finden:

SQL Trace ID 1 was started by login "sa".

Wer sich noch nicht mit Traces beschäftigt hat und etwas Hintergrund benötigt, kann hier nachlesen: Serverbasierter Trace
Wer aber hat nur diesen Trace definiert und zu welchem Zweck?

Auf der Suche nach dem Auslöser

Also versucht man erst mal herauszufinden, was der Trace denn so protokolliert. Hierzu greifen wir nochmal zurück auf den bereits oben erwähnten Artikel und den Hinweis auf die Knowledge-Base. INF: How to Monitor SQL Server 2000 Traces
Eine neue Version für SQLServer 2005 findet sich hier:
How to use a stored procedure to monitor traces in SQL Server 2005

Hat man sich die dort beschriebene Prozedur installiert und ruft diese für den Trace 1 auf, so erhält man bei (Verwendung der Version für SQL Server 2000) folgende Informationen:

PROPERTY
-------------------------------------------------------------------------
Trace number 1 results are in file E:\MSSQL.1\MSSQL\LOG\log_40.trc.trc.
Trace number 1 max file size is 20 megabytes.
Trace number 1 is running.
Trace number 1 does not automatically stop on any date and time.
Trace number 1 creates a new file when max file size is reached.

EVENT
-----------------------------------------------------------------------
Trace number 1 is tracing event 18, ServiceControl.
Trace number 1 is tracing event 20, Login Failed.
Trace number 1 is tracing event 22, ErrorLog.
Trace number 1 is tracing event 46, Object:Created.
Trace number 1 is tracing event 47, Object:Deleted.
Trace number 1 is tracing event 55, Hash Warning.
Trace number 1 is tracing event 69, Sort Warnings.
Trace number 1 is tracing event 79, Missing Column Statistics.
Trace number 1 is tracing event 80, Missing Join Predicate.
Trace number 1 is tracing event 81, Server Memory Change.
Trace number 1 is tracing event 92, Data File Auto Grow.
Trace number 1 is tracing event 93, Log File Auto Grow.
Trace number 1 is tracing event 94, Data File Auto Shrink.
Trace number 1 is tracing event 95, Log File Auto Shrink.
Trace number 1 is tracing event 102, Audit Statement GDR.
Trace number 1 is tracing event 103, Audit Object GDR.
Trace number 1 is tracing event 104, Audit Add/Drop Login.
Trace number 1 is tracing event 105, Audit Login GDR.
Trace number 1 is tracing event 106, Audit Login Change Property.
Trace number 1 is tracing event 108, Audit Add Login to Server Role.
Trace number 1 is tracing event 109, Audit Add DB User.
Trace number 1 is tracing event 110, Audit Add Member to DB.
Trace number 1 is tracing event 111, Audit Add/Drop Role.
Trace number 1 is tracing event 115, Audit Backup/Restore.
Trace number 1 is tracing event 116, Audit DBCC.

COLUMN
------------------------------------------------------------------------
Trace number 1 is tracing column 1, TextData.
Trace number 1 is tracing column 3, DatabaseID.
Trace number 1 is tracing column 4, TransactionID.
Trace number 1 is tracing column 5, Reserved.
Trace number 1 is tracing column 6, NTUserName.
Trace number 1 is tracing column 7, NTDomainName.
Trace number 1 is tracing column 8, ClientHostName.
Trace number 1 is tracing column 9, ClientProcessID.
Trace number 1 is tracing column 10, ApplicationName.
Trace number 1 is tracing column 11, SQLSecurityLoginName.
Trace number 1 is tracing column 12, SPID.
Trace number 1 is tracing column 13, Duration.
Trace number 1 is tracing column 14, StartTime.
Trace number 1 is tracing column 15, EndTime.
Trace number 1 is tracing column 19, Permissions.
Trace number 1 is tracing column 20, Severity.
Trace number 1 is tracing column 21, EventSubClass.
Trace number 1 is tracing column 22, ObjectID.
Trace number 1 is tracing column 23, Success.
Trace number 1 is tracing column 24, IndexID.
Trace number 1 is tracing column 25, IntegerData.
Trace number 1 is tracing column 26, ServerName.
Trace number 1 is tracing column 28, ObjectType.
Trace number 1 is tracing column 29, NestLevel.
Trace number 1 is tracing column 30, State.
Trace number 1 is tracing column 31, Error.
Trace number 1 is tracing column 34, ObjectName.
Trace number 1 is tracing column 35, DatabaseName.
Trace number 1 is tracing column 36, Filename.
Trace number 1 is tracing column 37, ObjectOwner.
Trace number 1 is tracing column 38, TargetRoleName.
Trace number 1 is tracing column 39, TargetUserName.
Trace number 1 is tracing column 40, DatabaseUserName.
Trace number 1 is tracing column 41, LoginSID.
Trace number 1 is tracing column 42, TargetLoginName.
Trace number 1 is tracing column 43, TargetLoginSID.
Trace number 1 is tracing column 44, ColumnPermissionsSet.
Trace number 1 is tracing column 49, RequestID.
Trace number 1 is tracing column 50, XactSequence.
Trace number 1 is tracing column 51, EventSequence.
Trace number 1 is tracing column 56, ObjectID2.
Trace number 1 is tracing column 59, ParentName.
Trace number 1 is tracing column 60, IsSystem.
Trace number 1 is tracing column 64, SessionLoginName.

Trace number 1 has no filters.

Wenden wir uns dem ersten Teil zu der mit PROPERTY überschrieben ist. Der dort aufgeführte Pfad ist das Standard-Log-Verzeichnis dieser Installation. Der Dateiname enthält irrtümlicherweise zweimal .trc als Suffix.
Fasst man diese Informationen zusammen, so werden laufend Protokoll-Dateien geschrieben. Sobald die Größe von 20 MB erreicht ist, wird die nächste Datei angefangen. Welche Ereignisse diese Protokollierung auslösen, ist unter EVENTS beschrieben, welche Daten protokolliert werden steht unter COLUMNS. Hier kann sich jeder erst mal selber ein Bild machen.

Interessanter ist es schon mit dem Profiler eine dieser Dateien zu öffnen und etwas drin rum zu stöbern.

Wieviel wird protokolliert?

Nun könnte man sich ja darüber freuen, dass man alle Informationen seit Anbeginn des Servers an, hier abrufen kann. Andererseits könnte man aber auch Bedenken bezüglich der Menge der Informationen bekommen. Wieviel Plattenplatz benötigt das ganze also nun?
Im fraglichen Verzeichnis findet man in der Regel die letzten 5 Dateien, die kontinuierlich nummeriert sind. Der Name lautet immer log_nn.trc. Ältere Dateien werden anscheinend beim Serverneustart entfernt. Damit hat sich das Thema mit unbegrenzten Historiendaten schon erledigt.
Auf einem Entwicklungsserver, wurde im Zeitraum von 1 Monat nur eine Datei angelegt, dann wurde der Server gebootet. Diese Datei war ca. 3 MB groß und enthielt fast 14.000 Zeilen. Also ist das ganze nicht in dem Bereich, dass man sich ernsthaft Gedanken über den benötigten Plattenplatz machen muss.

Am Ende fragt man sich aber sicher: Warum das ganze?

Zweck der ganzen Aktion

Ein tolles Feature des SQL Server 2005 sind die Reports, die auch im Management Studio verwendet werden um diverse Informationen bereit zu stellen. Hier finden sich unter Ansicht/Zusammenfassung (Summary in der englischen Version) interessante Informationen über den Zustand und das Verhalten des Servers.
Schaut man sich beispielsweise mal den Bericht zur Datenträgerverwendung über eine Datenbank (z. B. tempdb) an, so gibt es hier z. B. einen Abschnitt über die "Ereignisse zur automatischen Vergrößerung/Verkleinerung für Daten-/Protokolldateien".

Da sehr häufig die tempdb beim Serverstart zu klein ist, wird man hier recht bald diverse Informationen über eine Vergrößerung finden. Interessanterweise brechen diese Informationen aber irgendwo in der Vergangenheit ab, lange bevor man zum Installationsdatum des Servers kommt.

Betrachtet man nun parallel die älteste Log-Datei des Trace 1 und den Bericht, so findet man schnell eine Übereinstimmung. Das Datum der ältesten Information stimmt überein, und auch die anderen Informationen wird man hier wiederfinden. Neben dem Event "Log File Auto Grow" steht der Filename templog und die EndTime zeigt, dass man hier den passenden Eintrag gefunden hat.

Löscht man den ältesten Trace-File, so wird auch der Bericht entsprechend kürzer. Ähnliches scheint auch der SQLServer gelegentlich zu tun, da man nur 5 Dateien zum Trace 1 in diesem Verzeichnis findet. Startet man beispielsweise einen Entwicklungsserver mehrfach am Tag durch, so wird man sich schwertun mit den Berichten des Management Studios wesentliche Informationen zu erhalten.

Ändern des Trace

Versucht man den Trace zu stoppen, z. B. über die oben erwähnte Prozedur, so erhält man folgende Meldung

Meldung 19070, Ebene 16, Status 1, Prozedur sp_trace_setstatus, Zeile 1
The default trace cannot be stopped or modified. Use SP_CONFIGURE to turn it off.

Mit sp_Configure findet man die Option "default trace enabled". Hierzu steht in der Online-Doku dann endlich mal ein versteckter Hinweis auf die Hintergründe. Ausserdem ist hier folgendes vermerkt:

Bei einem Wert von 1 aktiviert die Option default trace enabled die Standardablaufverfolgung. Der Standardwert für diese Option ist 1 (EIN). Durch einen Wert von 0 wird die Ablaufverfolgung beendet. Bei der Option default trace enabled handelt es sich um eine erweiterte Option. Bei Einstellungsänderungen mithilfe der gespeicherten Systemprozedur sp_configure können Sie die Option default trace enabled nur ändern, wenn für show advanced options der Wert 1 festgelegt ist. Die Einstellung ist ohne einen Neustart des Servers sofort wirksam.

Man kann also immerhin den Trace abschalten, wenn man ihn nicht benötigt.

Fazit

Man bekommt durch die Kombination von serverbasiertem Trace und den geschickten Einsatz der Reporting Services einen guten Überblick über einige Aktionen, die auf dem Server ablaufen.
Sowohl der Performance-Overhead, als auch der benötigte Plattenplatz sind vernachlässigbar.
Allerdings hätte man sich gewünscht in der Online-Dokumentation einen Hinweis auf die Hintergründe der Zusammenfassungsseite oder den mysteriösen Eintrag zu Trace 1 im Protokoll des SQL Server zu finden.