Event Notifications - another curve

Another learning curve, after getting 98% there with Extended Events (see previous post).  For many things XE is a better tool, but for my purposes (DDL tracking over time) EN is better (again, thanks Jonathan for a great post on it: http://sqlskills.com/blogs/jonathan/post/Event-Notifications-vs-Extended-Events.aspx).  


Note that EN is NOT the same as SQL Server Notification Services, which has been dropped by MS and was for Reporting Services.

Event Notifications started with 2005, and are woefully underutilized.
Here's my annotated basic attempt at tracking all DDL changes on a server.  Next up (probably next post) is creating a routable SB to a secondary server, which would have an activated SP which would write records to a table.  As is, this is a proof of concept that writes to a queue. DO NOT JUST LEAVE IT RUNNING, as it'll fill up your queue, grow your database and you'll never figure out where the space is (since queues are sorta-hidden when it comes to space used)

TL;DR: Event Notifications tracks events, and routes them through service broker. This gives power and danger.

Code cribbed from both Jonathan Kehayias (http://www.sqlservercentral.com/articles/Event+Notifications/68831/) and Arshad Ali (http://www.mssqltips.com/sqlservertip/2121/event-notifications-in-sql-server-for-tracking-changes/).


ALTER DATABASE db_stuff SET ENABLE_BROKER;

go
USE db_stuff
go
CREATE QUEUE EventNotificationQueue   -- the reason you frequently see \\servername\queuename is because it needs to be unique
GO
create SERVICE EventNotificationService ON QUEUE EventNotificationQueue ([http://schemas.microsoft.com/SQL/Notifications/PostEventNotification])
GO
use db_stuff
go
CREATE EVENT NOTIFICATION CaptureErrorLogEvents
 ON SERVER
 WITH FAN_IN
 FOR DDL_EVENTS, ALTER_SERVER_CONFIGURATION
 TO SERVICE 'EventNotificationService', 'current database';
GO
create table blah (id int identity)
go
drop table blah
go
SELECT * FROM db_stuff..EventNotificationQueue

SELECT CAST(message_body AS XML) AS message_body_xml
FROM db_stuff.dbo.EventNotificationQueue

with MESSAGE_DATA as (SELECT queuing_order, CAST(message_body AS XML) AS message_body_xml
FROM db_stuff.dbo.EventNotificationQueue
)
SELECT
 message_body_xml.value('(/EVENT_INSTANCE/EventType)[1]', 'varchar(128)' ) as EventType,
 message_body_xml.value('(/EVENT_INSTANCE/PostTime)[1]', 'varchar(128)') AS PostTime,
 message_body_xml.value('(/EVENT_INSTANCE/SPID)[1]', 'varchar(128)') AS SPID,
 message_body_xml.value('(/EVENT_INSTANCE/LoginName)[1]', 'varchar(128)' ) AS LoginName,
 message_body_xml.value('(/EVENT_INSTANCE/UserName)[1]', 'varchar(128)' ) AS UserName,
 message_body_xml.value('(/EVENT_INSTANCE/ServerName)[1]', 'varchar(128)' ) AS ServerName,
 message_body_xml.value('(/EVENT_INSTANCE/DatabaseName)[1]', 'varchar(128)' ) AS DatabaseName,
 message_body_xml.value('(/EVENT_INSTANCE/SchemaName)[1]', 'varchar(128)' ) AS SchemaName,
 message_body_xml.value('(/EVENT_INSTANCE/ObjectName)[1]', 'varchar(128)' ) AS ObjectName,
 message_body_xml.value('(/EVENT_INSTANCE/ObjectType)[1]', 'varchar(128)' ) AS ObjectType,
 message_body_xml.value('(/EVENT_INSTANCE/TSQLCommand/CommandText)[1]', 'varchar(max)' ) AS CommandText,
 *
from message_data order by queuing_order
go

DROP EVENT NOTIFICATION CaptureErrorLogEvents on server
go
DROP SERVICE EventNotificationService
GO
DROP QUEUE EventNotificationQueue

go

Annotated:

ALTER DATABASE db_stuff SET ENABLE_BROKER;

turn on service broker on the database.  It's on by default in MSDB, but let's not play god in system databases today.

USE db_stuff
CREATE QUEUE EventNotificationQueue GO
create the service broker queue in "db_stuff".  EN uses service broker.

create SERVICE EventNotificationService ON QUEUE EventNotificationQueue ([http://schemas.microsoft.com/SQL/Notifications/PostEventNotification])
The notification sends to the service which sends to the queue. It needs a schema, MS has provided that (the http).

CREATE EVENT NOTIFICATION CaptureErrorLogEvents
 ON SERVER
can be server-wide, database-wide, etc.  I'm tracking all DDL changes on the server, so server it is.

 WITH FAN_IN
prevents multiple inserts from the same event into the same queue.

 FOR DDL_EVENTS, ALTER_SERVER_CONFIGURATION
the things I'm actually tracking.  you could do them individually, but there's over 1000, so I'm using "event groups". Here, I'm looking for server-level config changes, and DDL events (this includes UPDATE STATISTICS, which means it can fire a LOT)

 TO SERVICE 'EventNotificationService', 'current database';
send it to the service,  And yes "current database" is the proper format.  Do Not Like that name.

SELECT * FROM db_stuff..EventNotificationQueue
As of the CREATE EVENT NOTIFICATION, the queue is on and catching data.  Let's see what it's caught.  Not really legible, is it?  Let's change that.

SELECT CAST(message_body AS XML) AS message_body_xml
FROM db_stuff.dbo.EventNotificationQueue



So at this point, we'll use a CTE (or you could use a derived table; whatever) to provide a useful query that pulls out most of the provided fields.
with MESSAGE_DATA as (SELECT queuing_order, CAST(message_body AS XML) AS message_body_xml
FROM db_stuff.dbo.EventNotificationQueue
)
SELECT
 message_body_xml.value('(/EVENT_INSTANCE/EventType)[1]', 'varchar(128)' ) as EventType,
 message_body_xml.value('(/EVENT_INSTANCE/PostTime)[1]', 'varchar(128)') AS PostTime,
 message_body_xml.value('(/EVENT_INSTANCE/SPID)[1]', 'varchar(128)') AS SPID,
 message_body_xml.value('(/EVENT_INSTANCE/LoginName)[1]', 'varchar(128)' ) AS LoginName,
 message_body_xml.value('(/EVENT_INSTANCE/UserName)[1]', 'varchar(128)' ) AS UserName,
 message_body_xml.value('(/EVENT_INSTANCE/ServerName)[1]', 'varchar(128)' ) AS ServerName,
 message_body_xml.value('(/EVENT_INSTANCE/DatabaseName)[1]', 'varchar(128)' ) AS DatabaseName,
 message_body_xml.value('(/EVENT_INSTANCE/SchemaName)[1]', 'varchar(128)' ) AS SchemaName,
 message_body_xml.value('(/EVENT_INSTANCE/ObjectName)[1]', 'varchar(128)' ) AS ObjectName,
 message_body_xml.value('(/EVENT_INSTANCE/ObjectType)[1]', 'varchar(128)' ) AS ObjectType,
 message_body_xml.value('(/EVENT_INSTANCE/TSQLCommand/CommandText)[1]', 'varchar(max)' ) AS CommandText,
 *
from message_data order by queuing_order



And finally, a list of all the events, courtesy BOL.

WITH DirectReports(name, parent_type, type, level, sort) AS
(
    SELECT CONVERT(varchar(255),type_name), parent_type, type, 1, CONVERT(varchar(255),type_name)
    FROM sys.trigger_event_types
    WHERE parent_type IS NULL
    UNION ALL
    SELECT  CONVERT(varchar(255), REPLICATE ('|   ' , level) + e.type_name),
        e.parent_type, e.type, level + 1,
    CONVERT (varchar(255), RTRIM(sort) + '|   ' + e.type_name)
    FROM sys.trigger_event_types AS e
        INNER JOIN DirectReports AS d
        ON e.parent_type = d.type
)
SELECT parent_type, type, name
FROM DirectReports
ORDER BY sort;

Extended Events - climbing the learning curve

I recently spent an evening climbing the learning curve on XE (Extended Events), not the least of which because it acted slightly differently between SQL Server 2008 and SQL Server 2012.  I'd initially got it working, but couldn't reproduce that success for another couple of hours because I was running the code on 2008 (which lacks certain events that 2012 has - doh!).


Here's what I've learned, mostly here as a basic HOWTO, but also to remind me later.


1) It's actually pretty easy!  
2) It's the future - Profiler as we know it is going away (but you have a couple of years).  This is the replacement.
3) Jonathan Kehayias is awesome. He's gone through a bunch of pain - use his lessons learned.
4) SSMS 2012 offers it natively.  There's a plugin for SSMS 2008/R2 (Extended Event Session Explorer) that adds an option under the "View" menu.  Yes it works, but use it to assist what you're doing, don't just be the "GUI guy".
5) BOL is pretty good, but some of the obvious pages are hidden.  http://msdn.microsoft.com/en-us/library/bb630284(v=sql.105).aspx is a good example. (Somehow hadn't seen it before today)
6) Once you go through an example, all the giant blocks of code on the web make perfect sense.  That alone is a good reason to go through this exercise.


Here's an example I'm using now  You can run just this first block of code, pop open a new window, run a command, come back and see what happens.  Go on do it, I'll wait.  This works in 2008 and 2012.


CREATE EVENT SESSION [web_users_XE] ON SERVER
ADD EVENT sqlserver.rpc_completed
(
    ACTION(sqlserver.sql_text,sqlserver.username)
    WHERE ([sqlserver].[username]<>'web_users')
)
ADD TARGET package0.asynchronous_file_target(SET filename=N'C:\web_users_XE.xel'
, metadatafile='c:\web_users_XE.xem')
WITH (STARTUP_STATE=OFF)
GO
ALTER EVENT SESSION [web_users_XE] ON SERVER STATE = START
go
--at this point open a new window and run a command or two, hit an SP if you can...
sp_help
go
waitfor delay '00:00:30'
go
ALTER EVENT SESSION [web_users_XE] ON SERVER STATE = STOP
go
DROP EVENT SESSION [web_users_XE] ON SERVER;

--2008


So what's that mean and do?  Let's cover one part at a time.


CREATE EVENT SESSION [web_users_XE] ON SERVER 

pretty explanatory.  mandatory to create it. this creates the actual session.


ADD EVENT sqlserver.rpc_completed(
Now let's see: there are sessions, events, actions, and targets.  The SESSION is like the full sql trace.  The EVENTs are just like Trace Events (RPC:Completed, etc). There's even a table in 2012 that gives you a "this in trace is this in XE".  This is RPC:Completed.


    ACTION(sqlserver.sql_text,sqlserver.username)

what are we going to save? ACTIONS are "columns" in the trace (textdata, etc).  So here we savehe SQL_Text and the Username of the user running the query.  Note that this is for this particular event.  Which means you can do stuff like "event A you save these fields, for event B you save these other fields", etc, etc.


    WHERE ([sqlserver].[username]='web_users')
our filter - for this EVENT, only save from user "web_users".  As with the ACTION, it's per event.


ADD TARGET package0.event_file(SET filename=N'C:\SQL_Log\web_users_XE.xel')
OR

ADD TARGET package0.asynchronous_file_target(SET filename=N'C:\web_users_XE.xel'
, metadatafile='c:\web_users_XE.xem')


targets are "where the data goes".
Wait, why are there 2 versions?  The one in the block of code runs in both 2008/2012.  But the new name is "event_file".  Also, in 2008 you needed a metadata file to be able to parse it; they got rid of that in 2012.  It WILL NOT CREATE ONE, even if specified.  Nor do you need it to parse.
Targets: The 3 most-common are ring, file, and histogram.  
* File is a file. It's XML so it needs to be parsed, but easy enough.
* Ring is a first-in-first-out set of memory.  As you save to it, older things get kicked out.
* Histogram is a series of buckets, grouped by whatever you choose.  Why is that useful?  Kehayias does a clever example with object_id and page splits.  Everytime the split occurs, it either adds or increments a bucket with the object_id and count.  So rather than having to parse a list of events and group to see which objects are used, it's already done by the histogram - just see what buckets have the highest count, and that gives you the object ID.


WITH (STARTUP_STATE=OFF)
should this automatically start when the server starts?


ALTER EVENT SESSION [web_user_XE] ON SERVER STATE = START
actually start the session.

sp_help
Run something so we have an event.


waitfor delay '00:00:30'
There can be a 30 second delay before things are written to the file (to be lower-impact, it waits until a buffer fills).  There's a setting for this, but the default is 30 seconds.


ALTER EVENT SESSION [web_user_XE] ON SERVER STATE = STOP

stop the session.  It still exists, it's just not running.

DROP EVENT SESSION [web_users_XE] ON SERVER;

drop the session entirely.

Now, how do we parse it?  Parts cribbed from Kehayias again, notably getting the sql_text.

SELECT 

event_data.value('(event/@name)[1]', 'varchar(50)') AS event_name,

DATEADD(hh, DATEDIFF(hh, GETUTCDATE(), CURRENT_TIMESTAMP), 

event_data.value('(event/@timestamp)[1]', 'datetime2')) AS [timestamp],

event_data.value('(event/data[@name="cpu"]/value)[1]', 'int') AS [cpu],

        event_data.value('(event/data[@name="duration"]/value)[1]', 'bigint') AS [duration],

        event_data.value('(event/data[@name="reads"]/value)[1]', 'bigint') AS [reads],

        event_data.value('(event/data[@name="writes"]/value)[1]', 'bigint') AS [writes],

event_data.value('(event/action[@name="username"]/value)[1]', 'varchar(50)') AS username,

event_data.value('(event/action[@name="client_app_name"]/value)[1]', 'varchar(50)') AS application_name,

event_data.value('(event/action[@name="attach_activity_id"]/value)[1]', 'varchar(50)') AS attach_activity_id,

        REPLACE(event_data.value('(event/action[@name="sql_text"]/value)[1]', 'nvarchar(max)'), CHAR(10), CHAR(13)+CHAR(10)) AS [sql_text],

        event_data

FROM 

 (

 SELECT CAST(event_data AS xml)  AS 'event_data'

FROM sys.fn_xe_file_target_read_file('c:\sql_log\web_users*.xel', 'c:\sql_log\web_users*.xem', NULL, NULL)

)a ORDER BY DATEADD(hh, DATEDIFF(hh, GETUTCDATE(), CURRENT_TIMESTAMP), 

event_data.value('(event/@timestamp)[1]', 'datetime2')) 

Since it's XML, you need to parse it.  We convert it to XML from binary data, then use "value" to extract info.  One change between 2012 and 2008 is fn_xe_file_target_read_file.  On 2008 you need the metadatafile location.  On 2012 you don't need it, but it won't complain if it's there.

THAT'S IT!

Man, didn't that look more difficult?