If you’ve ever watched a CSI television show episode, you know that forensic evidence is crucial in solving mysteries. Forensic data, together with skillful analysis, is often the key to identifying the root cause of problems that would otherwise remain unresolved. This Stairway article will show how to manage the pre-configured default and black box SQL Server traces and analyze collected data in several scenarios.
The Default Trace
The default trace is so named because it is on by default when SQL Server is installed. Unlike user-defined traces, the default trace is managed using sp_configure rather than sp_trace* stored procedures. The SQL Server Management Studio GUI does not provide a method to turn the default trace off or on. I suspect this was a conscious design decision by Microsoft to encourage DBAs to leave the default trace enabled at all times and to ensure this valuable data are collected even in environments with no formal DBA. The default trace is very lightweight so there is rarely a need to disable it. The T-SQL script in Listing 1 displays the current default trace enabled setting and toggles the value.
-- 'default trace enabled' is an advanced configuration option EXEC sp_configure 'show advanced options' ,1; RECONFIGURE ; -- show current default trace setting EXEC sp_configure 'default trace enabled'; -- turn off default trace EXEC sp_configure 'default trace enabled', 0; RECONFIGURE ; -- turn on default trace EXEC sp_configure 'default trace enabled' ,1; RECONFIGURE ;
Listing 1: Display and toggle ‘default trace enabled’ configuration option
The definition of the default trace is predetermined and cannot be modified. The default trace definition specifies the trace file rollover option with a maximum of 5 files and a file size of 20MB. These trace file properties limit default trace data to no more than 100MB of disk space. Default trace files are created in the log folder for the SQL Server instance, each with the file name “log” followed by an integer uniqueifier and “.trc” extension (e.g. “C:\Program Files\Microsoft SQL Server\MSSQL10_50.MSSQLSERVER\MSSQL\LOG\log_183.trc”).
The first article in this Stairway included a query to list the events collected by the default trace along with the individual event columns. The listing in Figure 1 summarizes the dozens of events captured by the default trace. These events typically occur infrequently during normal workloads so the overhead of default trace data collection is negligible.
|Event Category||Event Class|
|Database||Data File Auto Grow|
|Database||Data File Auto Shrink|
|Database||Database Mirroring State Change|
|Database||Log File Auto Grow|
|Database||Log File Auto Shrink|
|Errors and Warnings||ErrorLog|
|Errors and Warnings||Hash Warning|
|Errors and Warnings||Missing Column Statistics|
|Errors and Warnings||Missing Join Predicate|
|Errors and Warnings||Sort Warnings|
|Full text||FT:Crawl Aborted|
|Full text||FT:Crawl Started|
|Full text||FT:Crawl Stopped|
|Performance||Plan Guide Unsuccessful|
|Security Audit||Audit Add DB User Event|
|Security Audit||Audit Add Login to Server Role Event|
|Security Audit||Audit Add Member to DB Role Event|
|Security Audit||Audit Add Role Event|
|Security Audit||Audit Addlogin Event|
|Security Audit||Audit Backup/Restore Event|
|Security Audit||Audit Change Audit Event|
|Security Audit||Audit Change Database Owner|
|Security Audit||Audit Database Scope GDR Event|
|Security Audit||Audit DBCC Event|
|Security Audit||Audit Login Change Property Event|
|Security Audit||Audit Login Failed|
|Security Audit||Audit Login GDR Event|
|Security Audit||Audit Schema Object GDR Event|
|Security Audit||Audit Schema Object Take Ownership Event|
|Security Audit||Audit Server Alter Trace Event|
|Security Audit||Audit Server Starts And Stops|
|Server||Server Memory Change|
Figure 1: Events collected by the default trace
Viewing and Analyzing Default Trace Data
Data collected by the default trace can be viewed using Profiler (FileàOpenàTrace File) or the fn_trace_gettable T-SQL function (discussed in
Level 2 of this Stairway). Personally, I usually use fn_trace_gettable to import trace data into a denormalized table for adhoc querying and filtering. The script in Listing 2 imports all available default trace files from the log folder of the default instance into a temporary table along with the event class and subclass names obtained from the sys.trace_events and sys.trace_subclass_valuescatalog views.
SELECT te.name AS EventClassName ,tsv.subclass_name AS EventSubClassName ,t.* INTO #DefaultTraceData FROM fn_trace_gettable('C:\Program Files\Microsoft SQL Server\MSSQL10.MSSQLSERVER\MSSQL\Log\log.trc', DEFAULT) AS t JOIN sys.trace_events AS te ON te.trace_event_id = t.EventClass LEFT JOIN sys.trace_subclass_values AS tsv ON tsv.trace_event_id = t.EventClass AND tsv.subclass_value = t.EventSubClass ;
Listing 2: Import default trace data into temp table
Once imported, the trace data can be easily queried for particular events of interest. The query in Listing 3 reports file auto-grow events along with the relevant data columns. A SQL Server DBA best practice is to size database files appropriately for anticipated needs and specify auto-grow only as a safety net. This practice avoids physical file fragmentation and the overhead of expansion during normal operation. Since auto-grow events for both data and log files are captured by the default trace, it’s is easy determine if and when file growths occur so that the files can be expanded proactively in anticipation of future needs.
SELECT EventClassName ,DatabaseName ,FileName ,IntegerData * 8 AS IncreasedSizeInKB ,ApplicationName ,StartTime ,EndTime ,Duration / 1000 AS DurationMicroseconds FROM #DefaultTraceData WHERE EventClassName IN ( 'Data File Auto Grow', 'Log File Auto Grow' ) ;
Listing 3: Query to display captured file auto grow events
The default trace captures several events of the errors and warnings category that indicate performance concerns. The query in Listing 4 displays hash and sort warning events. A hash warning occurs when hash partitions are written to disk (work tables in tempdb) due to insufficient memory. This event usually happens because SQL Server underestimated hash table memory requirements due to statistics on indexes and columns that were missing or stale. Frequent hash warnings can not only affect performance of the problem queries, but overall server performance may be impacted due to memory and tempdb contention.
Similarly, a sort warning occurs when a query sort operator cannot be performed in memory. A sort warning with event sub class “Multiple” is of particular concern because multiple passes over the data were needed to perform the sort operation. Avoiding hash and sort warnings can be as simple as creating or updating statistics. In other cases, query and index tuning may be needed to mitigate such warnings.
SELECT EventClassName ,EventSubClassName ,DatabaseName ,ApplicationName ,StartTime ,IntegerData FROM #DefaultTraceData WHERE EventClassName IN ( 'Hash Warning', 'Sort Warnings' ) ;
Listing 4: Query to display captured hash and sort warning events
The Blackbox Trace
You may have guessed from the name that a blackbox trace captures details of recent SQL Server activity, analogous to an aircraft flight recorder. A blackbox trace is not used routinely. The typical use of a blackbox trace is to gather activity information that precedes a reoccurring problem, such as a sporadic SQL Server access violation or service interruption. The recent activity leading up to the problem may help DBAs or support engineers identify the root cause.
The blackbox trace is a pre-defined unfiltered trace that includes the events listed in Figure 2. Filters and other events cannot be specified. A blackbox trace is created using sp_trace_create with option value 8 (TRACE_PRODUCE_BLACKBOX). The blackbox trace option can’t be combined with other trace options and includes trace file rollover. A trace file name is not specified because the black box trace file name is predetermined (N'%SQLDIR%\MSSQL\DATA\blackbox.trc').
Figure 2: Blackbox trace events
Unless otherwise specified, the blackbox trace rollover file count is 2 and the max file size is 5MB. Listing 5 shows a script to create and start a black box trace with the default file size and rollover file count. Like other traces, a blackbox trace is started, stopped and deleted using sp_trace_setstatus with status values 1, 0 and 2 respectively. Be prepared to stop the blackbox trace soon after the targeted problem event (e.g. server crash, unresponsiveness) so that recently collected data is not lost due to subsequent activity that causes file rollovers. Data from the blackbox trace may be viewed using Profiler or fn_trace_gettable as I described previously for the default trace, but changing the file location to the blackbox trace file in the data folder.
DECLARE @TraceID INT ; EXEC sp_trace_create @traceid = @TraceID OUTPUT ,@options = 8 ; SELECT @TraceID ; EXEC sp_trace_setstatus @TraceID ,1 ;
Listing 5: Create and start black box trace with default 5MB file size and 2 rollover files
Remember that the blackbox trace is unfiltered and includes potentially high-frequency events (RPC and Batch starting). Although the collected information is potentially invaluable for troubleshooting purposes, be aware that the overhead of collecting voluminous against a busy OLTP server may be considerable. Use a blackbox trace with caution against very busy servers and consider specifying a file size and/or number of rollover files greater than the default to ensure forensic data leading up to the problem event are not lost. Listing 6 shows a black-box trace create script with a file size of 100MB and rollover file count of 10, thus providing up to 1GB of the most recently collected black-box trace data.
DECLARE @TraceID INT ; DECLARE @maxfilesize2 bigint ; SET @maxfilesize2 = 100 ; EXEC sp_trace_create @traceid = @TraceID OUTPUT ,@options = 8 ,@tracefile = NULL ,@maxfilesize = @maxfilesize2 ,@stoptime = NULL ,@filecount = 10 ; SELECT @TraceID ; EXEC sp_trace_setstatus @TraceID ,1 ;
Listing 6: Create and start black box trace with 100MB file size and 10 rollover files
The pre-defined default and blackbox traces provide forensics for proactive analysis and troubleshooting. Both are created and managed using T-SQL rather than a GUI, yet are easy to administer using simple T-SQL scripts. In the next article of this Stairway, I’ll discuss techniques on how to view and manage SQL traces.