Sql-server – What event information can I get by default from SQL Server

extended-eventssql server

I often see questions where people want to know if a certain thing happened, or when it happened, or who performed the action. In a lot of cases, SQL Server just doesn't track this information on its own. For example:

  • Who last executed stored procedure dbo.MyProcedure?
  • Who updated the salary column in the dbo.Employees table?
  • Who last queried the dbo.Orders table from Management Studio?

But there are several other events that SQL Server does track temporarily by default, and can natively answer questions about, such as:

  • When was the last time an auto-grow happened in the AdventureWorks database, and how long did it take?
  • Who deleted the dbo.EmployeeAuditData table and when?
  • How many memory-related errors have happened today?

How do I get this information, and how long does it stay available?

Best Answer

There is quite a bit of valuable information that SQL Server tracks for you by default. Since SQL Server 2005 there has been a "default trace" that runs in the background, and since SQL Server 2008 there has been an Extended Events session automatically running, called system_health.

You can also find certain information from the SQL Server error log, the SQL Server Agent log, Windows event logs, and additional logging from things like SQL Server Audit, Management Data Warehouse, Event Notifications, DML Triggers, DDL Triggers, SCOM / System Center, your own server-side traces or Extended Events sessions, or third-party monitoring solutions (like those made by SentryOne). You can also optionally enable a so-called "Blackbox trace" to assist in troubleshooting.

But for this post I'm going to focus the scope on things that are generally enabled most everywhere: the default trace, Extended Events sessions, and the error log.

Default Trace

The default trace is usually running on most systems, unless you have disabled it using sp_configure. As long as it is enabled, this can be a rich source of valuable information. The following lists the trace events that are captured:

DECLARE @TraceID INT;

SELECT @TraceID = id FROM sys.traces WHERE is_default = 1;

SELECT t.EventID, e.name as Event_Description
  FROM sys.fn_trace_geteventinfo(@TraceID) t
  JOIN sys.trace_events e ON t.eventID = e.trace_event_id
  GROUP BY t.EventID, e.name;

You can get into more detail by joining to sys.trace_columns to see which events come with which data, but I'm going to skip that for now, since you can see what you have when you actually query the trace data for specific events. These are the events that are available on my system (you should run the query on yours to be sure they match, though this is still the same set of events through SQL Server 2019 CTP 2.4):

EventID  Event_Description
-------  ----------------------------------------------
18       Audit Server Starts And Stops
20       Audit Login Failed
22       ErrorLog
46       Object:Created
47       Object:Deleted
55       Hash Warning
69       Sort Warnings
79       Missing Column Statistics
80       Missing Join Predicate
81       Server Memory Change
92       Data File Auto Grow
93       Log File Auto Grow
94       Data File Auto Shrink
95       Log File Auto Shrink
102      Audit Database Scope GDR Event
103      Audit Schema Object GDR Event
104      Audit Addlogin Event
105      Audit Login GDR Event
106      Audit Login Change Property Event
108      Audit Add Login to Server Role Event
109      Audit Add DB User Event
110      Audit Add Member to DB Role Event
111      Audit Add Role Event
115      Audit Backup/Restore Event
116      Audit DBCC Event
117      Audit Change Audit Event
152      Audit Change Database Owner
153      Audit Schema Object Take Ownership Event
155      FT:Crawl Started
156      FT:Crawl Stopped
164      Object:Altered
167      Database Mirroring State Change
175      Audit Server Alter Trace Event
218      Plan Guide Unsuccessful

Note that the default trace uses rollover files and so the data available to you will only go back so far - the date range of available data depends on how many of the above events are being captured and at what frequency. If you want to ensure that you keep a longer history, you can set up a job that periodically archives away the currently inactive files associated with the trace.

Examples

In the question I asked a couple of questions that I have found. Here are example queries for pulling that specific information from the default trace.

Question: When was the last time an auto-grow happened in the AdventureWorks database, and how long did it take?

This query will pull all of the AutoGrow events in the AdventureWorks database, for both log and data files, that are still in the default trace log files:

DECLARE @path NVARCHAR(260);

SELECT 
   @path = REVERSE(SUBSTRING(REVERSE([path]), 
   CHARINDEX(CHAR(92), REVERSE([path])), 260)) + N'log.trc'
FROM    sys.traces
WHERE   is_default = 1;

SELECT 
   DatabaseName,
   [FileName],
   SPID,
   Duration,
   StartTime,
   EndTime,
   FileType = CASE EventClass WHEN 92 THEN 'Data' ELSE 'Log' END
FROM sys.fn_trace_gettable(@path, DEFAULT)
WHERE EventClass IN (92,93)
AND DatabaseName = N'AdventureWorks'
ORDER BY StartTime DESC;

Question: Who deleted the dbo.EmployeeAuditData table and when?

This will return any DROP events for an object named EmployeeAuditData. If you want to make sure that it only detects DROP events for tables, you can add a filter: ObjectType = 8277 (the full list is documented here). If you want to restrict the search space to a specific database, you can add a filter: DatabaseName = N'db_name'.

DECLARE @path NVARCHAR(260);

SELECT 
   @path = REVERSE(SUBSTRING(REVERSE([path]), 
   CHARINDEX(CHAR(92), REVERSE([path])), 260)) + N'log.trc'
FROM    sys.traces
WHERE   is_default = 1;

SELECT 
  LoginName,
  HostName,
  StartTime,
  ObjectName,
  TextData
FROM sys.fn_trace_gettable(@path, DEFAULT)
WHERE EventClass = 47    -- Object:Deleted
AND EventSubClass = 1
AND ObjectName = N'EmployeeAuditData'
ORDER BY StartTime DESC;

There is a complication here, and it is very edge case but thought it prudent to mention anyway. If you use multiple schemas and may have the same object name in multiple schemas, you won't be able to tell which one this is (unless its counterpart(s) still exist). There is an outside case that UserA might have dropped SchemaB.Tablename while UserB might have dropped SchemaA.Tablename. The default trace does not track the schema of the object (nor does it capture TextData for this event), and the ObjectID included in the trace is not useful for a direct match (because the object was dropped and no longer exists). Including that column in the output in this case might be useful to cross-reference against any copies of the table with the same name that still exist, but if the system is in this much disarray (or if all such copies have been deleted) there still might not be a reliable way to guess at which copy of the table was dropped by whom.

Extended Events

The following was the list of data you could cull from the system_health session in SQL Server 2008 and 2008 R2 (that list is more complete in modern versions):

  • The sql_text and session_id for any sessions that encounter an error with severity >=20
  • The sql_text and session_id for any sessions that encounter a "memory" type of error such as 17803, 701, etc (we added this because not all memory errors are severity >=20)
  • A record of any "non-yielding" problems (you have sometimes seen these in the ERRORLOG as Msg 17883)
  • Any deadlocks that are detected
  • The callstack, sql_text, and session_id for any sessions who have waited on latches (or other interesting resources) for > 15 seconds
  • The callstack, sql_text, and session_id for any sessions who have waited on locks for > 30 seconds
  • The callstack, sql_text, and session_id for any session that have waited for an extended period of time for "external" waits or "pre-emptive waits".

From Use the system_health event session (MSDN), the list is somewhat expanded in SQL Server 2012 (and remains the same for SQL Server 2014):

  • The sql_text and session_id for any sessions that encounter an error that has a severity >=20.
  • The sql_text and session_id for any sessions that encounter a memory-related error. The errors include 17803, 701, 802, 8645, 8651, 8657 and 8902.
  • A record of any non-yielding scheduler problems. (These appear in the SQL Server error log as error 17883.)
  • Any deadlocks that are detected.
  • The callstack, sql_text, and session_id for any sessions that have waited on latches (or other interesting resources) for > 15 seconds.
  • The callstack, sql_text, and session_id for any sessions that have waited on locks for > 30 seconds.
  • The callstack, sql_text, and session_id for any sessions that have waited for a long time for preemptive waits. The duration varies by wait type. A preemptive wait is where SQL Server is waiting for external API calls.
  • The callstack and session_id for CLR allocation and virtual allocation failures.
  • The ring_buffer events for the memory broker, scheduler monitor, memory node OOM, security, and connectivity.
  • System component results from sp_server_diagnostics.
  • Instance health collected by scheduler_monitor_system_health_ring_buffer_recorded.
  • CLR Allocation failures.
  • Connectivity errors using connectivity_ring_buffer_recorded.
  • Security errors using security_error_ring_buffer_recorded.

In SQL Server 2016, two more events are captured:

  • When a process is killed using the KILL command.
  • When SQL Server shutdown has been started.

(The documentation hasn't been updated yet, but I blogged about how I discover these and other changes.)

To get the more cryptic configuration applicable for your specific version, you can always run the following query directly, but you'll have to interpret the names and parse the predicates to match up to the more natural language lists above:

SELECT e.package, e.event_id, e.name, e.predicate
  FROM sys.server_event_session_events AS e
  INNER JOIN sys.server_event_sessions AS s
  ON e.event_session_id = s.event_session_id
 WHERE s.name = N'system_health'
 ORDER BY e.package, e.name;

If you are using Availability Groups, there are also two new sessions that you will find running: AlwaysOn_failover and AlwaysOn_health. You can see the data they collect with the following query:

SELECT s.name, e.package, e.event_id, e.name, e.predicate
  FROM sys.server_event_session_events AS e
  INNER JOIN sys.server_event_sessions AS s
  ON e.event_session_id = s.event_session_id
 WHERE s.name LIKE N'AlwaysOn[_]%'
 ORDER BY s.name, e.package, e.name;

These event sessions use ring buffer targets to store the data, so - like the buffer pool and the plan cache - older events will get phased out, so you won't necessarily be able to pull events from the date range you want.

Example

In the question I posed this fictitious question:

How many memory-related errors have happened today?

Here is a sample (and probably not very efficient) query that can pull this information from the system_health session:

;WITH src(x) AS
(
  SELECT y.query('.')
  FROM
  (
    SELECT x = CONVERT(XML, t.target_data)
      FROM sys.dm_xe_sessions AS s
      INNER JOIN sys.dm_xe_session_targets AS t
      ON s.[address] = t.event_session_address
      WHERE s.name = N'system_health'
  ) AS x
  CROSS APPLY x.x.nodes('/RingBufferTarget/event') AS y(y)
)
SELECT 
  x, ts = CONVERT(DATETIME, NULL), err = CONVERT(INT, NULL)
INTO #blat FROM src;

DELETE #blat WHERE x.value('(/event/@name)[1]', 'varchar(255)') <> 'error_reported';

UPDATE #blat SET ts = x.value('(/event/@timestamp)[1]', 'datetime');

UPDATE #blat SET err = x.value('(/event/data/value)[1]', 'int');

SELECT err, number_of_events = COUNT(*)
  FROM #blat
  WHERE err IN (17803, 701, 802, 8645, 8651, 8657, 8902)
  AND ts >= CONVERT(DATE, CURRENT_TIMESTAMP)
  GROUP BY err;

DROP TABLE #blat;

(This example borrows loosely from Amit Banerjee's introductory blog post on the system_health session.)

For more information on Extended Events (including many examples where you can query for specific data), see this 31-part blog series by Jonathan Kehayias:

https://www.sqlskills.com/blogs/jonathan/an-xevent-a-day-31-days-of-extended-events/

Error Log

SQL Server by default keeps the current plus 6 most recent error log files (but you can change this). Plenty of information is stored there, including startup information (how many cores are in use, whether lock pages in memory is set, authentication mode, etc) as well as errors and other scenarios severe enough to be documented (and not captured elsewhere). One recent example was someone looking for when a database was taken offline. You can determine this by scanning through each of the most recent 7 error logs for the text Setting database option OFFLINE:

EXEC sys.sp_readerrorlog 0,1,'Setting database option OFFLINE';
EXEC sys.sp_readerrorlog 1,1,'Setting database option OFFLINE';
EXEC sys.sp_readerrorlog 2,1,'Setting database option OFFLINE';
EXEC sys.sp_readerrorlog 3,1,'Setting database option OFFLINE';
EXEC sys.sp_readerrorlog 4,1,'Setting database option OFFLINE';
EXEC sys.sp_readerrorlog 5,1,'Setting database option OFFLINE';
EXEC sys.sp_readerrorlog 6,1,'Setting database option OFFLINE';

I covered some other details in this recent answer, and there is also some good background information at toadworld and also in the official documentation.

One group of "errors" the error log does track by default - and can make important information fall off the tail much quicker - is every successful backup message. You can prevent these from filling up the error log with noise by enabling trace flag 3226.