Extended Events : 101 - The Basics

Introducing the Extended Events User Interface

extended_events — Wed, 13 Jul 2011 22:50:00 GMT

Check out What's new for Extended Events in SQL Server Codenamed "Denali" CTP3 for an overview of all of the new functionality released in CTP3. This post details the new user interface. In my overview post I mentioned that the user interface is built directly into management studio (SSMS) and that there are four parts:

The session list in Object Explorer.
A Create Session wizard.
A Create Session dialog.
A display grid.

This post focuses on the mechanisms for creating event sessions and displaying event session data.

Creating and modifying event sessions

The New Session Wizard and dialog share many common UI elements, so I’ll just cover the dialog. If a notable difference exists for the wizard, I’ll call it out at the appropriate place. A picture is worth a thousand words, so here is the pictorial tour of the new user interface.

General page

The General page collects the basic information about the session:

· Name – You can figure this one out.

· Template – We’ve carried over the idea of templates similar to SQL Profiler. You can export any session you’ve created to a template (Expand the context menu of your event session and click Export Session…). If you save the template to the default location, it will show up in this dropdown under the User Templates category.

· Schedule – You can choose to make this an Autostart event session, start the session immediately after you complete the dialog and even choose to start up the event stream viewer. (More on that later.)

· Causality Tracking – Turn on the correlation ids in your trace.

Wizard differences: These options are spread across three different wizard steps.

Event page - Library

The Event page has a couple parts. The Event Library allows you to select which events you want to add to your event session. The library supports Excel-like filtering using dropdown lists for Category and Channel. You can also search for specific events by just typing in the search text box. You choose an event by double-clicking or by selecting it and clicking the right arrow to move it to the Selected events list. We support Shift+Click and Ctrl+Click for choosing multiple events at once.

Event page – Configure

In Extended Events, each event can be extended to include additional data or cause a specific action, only fire under defined conditions and to enable optional fields. Clicking on the Configure button takes you to the advanced event configuration options. You configure an event by selecting it in the Selected events list and then setting the configuration options on one of the tabs. When you select multiple events, the configuration options will apply to all selected events.

The Global Fields (Actions) tab allows you select the list of Actions that you want to append to the event(s).

The Filter (Predicate) tab is used to define the conditions under which the event will be collected.

The Event Fields table allows you to enable or disable the collection of optional fields. (Fields without a checkbox are always collected.) You can also see the description and data type of each field on this tab.

Wizard differences: Global Fields and Predicates apply to all selected events. You cannot configure the events individually.

Data Storage page

You determine how the event session data is stored on this page by specifying the target for the session. You can specify more than one target for any session, but you can only use each target once. Each target will present a set of configuration options on the bottom of the page.

Wizard differences: The wizard supports only the event file and ring buffer targets.

Advanced page

Configure the options for the entire event session here. We use the same defaults you would get with the DDL syntax.

Wizard differences: You cannot configure the event session options in the wizard, the defaults are used.

Other stuff

You may have noticed from the screen shots that you can script out your configured event session from the user interface using the button at the top of the page. The button becomes enabled as soon as you have enough of the event session configured such that the DDL would execute without error.

You can change the configuration of an event session by right-clicking the session name in Object Explorer and clicking Properties. The same user interface will be presented showing all your configured settings. Most settings can be changed on a running session, but you’ll need to stop the session to change the Advanced options. You cannot change the target configuration (Data Storage page) on an existing target, you’ll need to delete the target and re-add it to change that. You will also find that the Script button is not enabled in the Properties dialog, you can still script your event session to DDL, but you’ll need to do it from Object Explorer by right-clicking the session name and choosing one of the Script Session as… commands.

Wizard differences: The wizard is not re-entrant. Sessions created in the wizard can be modified using the Property dialog just like any other session.

Viewing event session data

SSMS includes an event session data viewer for all of the supported targets with the exception of the ETW file target. (There are many other tools for working with ETL files.) There are basically two different types of event session data display.

In-memory targets

The in-memory targets include: ring buffer, event counter, histogram and event pairing. The data from these targets is displayed in a simple grid format.

By default you see a “point in time” view of the data when you opened the display. You can either manually refresh the data or have it refresh on a schedule from the context menu. The ring buffer is a bit special in that the display shows you a single row containing the XML output of the ring buffer. You can double-click the row to open an XML document, but there is no event by event grid view for the ring buffer, sorry.

Event stream and event file

You can open a “live view” of a running session by right-clicking on the session name and choosing the Watch Live Data menu item. This will open a page in SSMS that provides you with a scrolling display of the events as they come from the event session. This is similar to the behavior that exists in SQL Profiler with the major difference being that Extended Events does not cause the performance degradation that you might be used to with SQL Profiler. Extended Events will never block the server waiting for the client event stream view; we’re so serious about this that the event stream is disconnected if the client becomes too slow that it will block the server workload. (Remember the prime directive – this is one of those tradeoffs.) If you have a very busy server (eg. lots of events) the file target will be a more appropriate target.

The event file target uses the XEL extension by default, and that extension is associated with SSMS so that you can open an event file by double-clicking or simply dragging it onto the SSMS window. You can also open event files in two different ways from the File menu:

File | Open | File – Pick an XEL file and click Open

File | Open | Merge Extended Event files – Use the dialog to collect multiple files to be merged

Both the event steam and event files are displayed in the same user interface:

The picture is a bit small, but you get the idea. Open up an XEL file in SSMS to get the full experience.

The first thing you won’t notice, but now you will because I’m telling you, is that there is a custom toolbar for Extended Events; there is also a menu added. You can control all the functionality of the display UI using these. The first thing you will notice is that the default view has only two columns, name and timestamp, all the other columns for an event are shown in the Details pane when you select a specific row in the grid. There is a bunch of functionality in this UI, almost too much to fit into a summary such as this, so I’ll hit the high points and let you explore.

· You can add additional columns to the grid by either right-clicking the in the Details pane and choosing Show Column in Table or by clicking the Choose Columns button to open the Choose Columns dialog.

· You can Find event records using the typical SSMS find behavior.

· You can Bookmark records of interest and move between bookmarked records.

· You can apply a filter to the results using a flexible criteria builder. (This is worth a picture; so much better than SQL Profiler!)

· You can use the Grouping and Aggregation commands to do some basic analysis of your data directly in the display UI.

· You can save the configuration of the display table (columns, filter, sorting and group/aggregation) using the View Settings button. (Note: This button name may change before RTM.)

· You can export the list of events to a SQL Server table, CSV or XEL using the Export to menu item. (Note: This is only on the menu, not the command bar.)

· You can Start and Stop the collection of the data and control the scrolling of the data in the window for the event stream.

That about wraps up the pictorial tour of the new Extended Events user interface. Take it out for a spin and let us know what you think. If you find any problems, or have suggestions for future versions, please post them to Microsoft Connect. If you have questions, post them to the SQL Server Database Engine forum.

Happy Eventing!

- Mike

What’s New for Extended Events in SQL Server Codenamed “Denali” CTP3

extended_events — Wed, 13 Jul 2011 22:25:00 GMT

CTP3 is finally here and the crowd goes wild! Since I’m sure everyone has been anticipating the CTP3 updates to Extended Events (because, let’s face it, Extended Events is the most important part of the product, right?) let’s get to it.

Introduction

I’m going to cover the new features at a high level in this post and then drill into a couple specific features in more detail in posts dedicated to that topic. Before I get into the “meat” of this post I wanted to spend a few sentence writing about the design philosophy we’ve followed as we’ve created Extended Events. Every feature gets to a point where a trade-off has to be made and the design philosophy guides us in making those trade-offs.

Foremost is our prime directive (not that I’m a Star Trek™ fan):

The most important workload on the server is the customer workload; diagnostic systems should not prevent the customer workload from running.

This doesn’t mean that a diagnostic workload won’t impact server performance, it will. It means that in cases where we have to make a choice between the activity of the customer workload and the diagnostic workload, the customer workload wins, period. This has been the prime directive of the Extended Events team since the beginning and it didn’t change in “Denali.”

The goal for “Denali” has been twofold:

Provide a diagnostic tracing facility, built on Extended Events, that will not just replace the existing SQL Trace/SQL Profiler based system, but exceed it.
Drastically improve the usability of Extended Events.

A significant part of meeting our first goal was accomplished in CTP1 by providing data parity with SQL Trace event classes. I’ve already discussed migration from SQL Trace to Extended Events in the blog, so I won’t go into details about that work here. With that preamble, let’s take a look and how we accomplished the second goal.

Extended Events User Interface

Get more details: Introducing the Extended Events User Interface

This won’t be a surprise to many of you, but we’ve created a user interface for Extended Events and you’ll find it in CTP3. Having a user interface was the most common user request, by far, and we listened. SQL Profiler is too important to not have equivalent functionality. Making it much easier to configure and read event sessions is the primary way we delivered on our usability goal. The Extended Events user interface is built directly into SSMS and there are four primary pieces:

Session list – You will find a list of sessions within the Object Explorer under the node Management | Extended Events | Sessions.
New Session Wizard – A wizard (duh) that provides a simplified experience for creating an event session. Only the most common options and functionality is exposed with everything else being configured automatically. Expand the context menu of the Sessions node and click New Session Wizard.
New Session dialog – The complete set of Extended Events configuration in handy dialog format. Expand the context menu of the Sessions node and click New Session…. The same dialog is used for creating new sessions and for modifying existing sessions (click Properties on the context menu).
Extended Events display – A collection of SSMS pages (tabs like the Query window) that display Extended Events trace data.

The user interface you designed…really

We didn’t just listen to the feedback that we needed a user interface, we also listened to the feedback we got throughout the design and development process. This UI represents more than just the work of the Microsoft development team, but also the feedback of many SQL Server MVPs, usability study participants and anyone who would talk to us at the various conferences where we presented the UI. We took something useful away from every customer interaction and made significant changes based on that feedback. Thanks to everyone who took the time to provide your feedback. (And keep it coming – as you explore CTP3 send us your feedback using Microsoft Connect.)

You might want to sit down for this next section

It’s an unpopular word, but I have to say it … Deprecation.

Yeah, I said it; we are announcing deprecation of SQL Trace in Denali. Before everyone goes off the deep end, remember, this is only the announce phase which means that nothing actually changes in Denali, we’re just letting you know that we’re phasing it out in favor of the new system over the next few releases so now is a good time to start investigating how to migrate. (See the link in the Introduction for more details.)

Programming Extended Events

Get more details: Introducing the Extended Events Reader

Another important aspect of creating a usable diagnostic system is a programmatic interface. (Not everyone loves DDL as much as we do apparently.) We’ve covered this in two pieces:

A “management” API that lets you create and modify event sessions as well as explore the Extended Events metadata on a server. This API was release in CTP1 and I’ve already provided examples in my post Introducing the Extended Events Object Model.
A “reader” API that provides functionality for reading event files (XEL) and event streams coming from a running event session.

The UI is built on top of these APIs so you have all the capabilities you need to write your own customized tools for working with Extended Events.

The “other” stuff

There are always a host of little things that we add, change or fix when we’re improving a feature. I don’t want to deprive anyone of the “Joy of Discovery” that comes with finding these little bits and pieces, so stop reading now if you want to hunt them down on your own. For the rest of you, here is the list of bits and pieces that we hope will make the Extended Events world a little better for you.

Some (target) names have been changed to protect the innocent

We’ve changed the names of some of the targets to be friendlier:

Old Target Name	New Target Name
asynchronous_file_target	event_file
synchronous_event_counter	event_counter
asynchronous_bucketizer	histogram
synchronous_bucketizer	histogram (I’ll explain below)

To make this change easier we’ve done some work under the covers:

ADD TARGET with the old target names will still work. We do name fixup inside SQL Server when we execute the DDL.
DROP TARGET with the old target names will not work. We fixed up the names so there are no records in the catalog with the old names.
The target_name field of dm_xe_session_targets will be fixed up to have the new target names for any running sessions during Upgrade.
The name field of server_event_session_targets will be fixed up to have the new target names for any configured session during Upgrade.

Note on histogram target – There is not strong evidence to support that people are using both the synchronous and asynchronous bucketizer together in a single session so we used the renaming event to also eliminate this duplication. We have a single histogram target now that is asynchronous.

There can be only one – file that is

We’ve eliminated the metadata file all together. That’s right, no more XEM file, it just didn’t make sense and it’s kind of a pain to have to worry about dragging the extra file around if you’re sending logs to other folks. Both the server reader function, fn_xe_file_target_read_file and the new Reader API are fully backwards compatible with the SQL Server 2008 and SQL Server 2008 R2 “dual file” format.

Note: We do not support the XEL/XEM files created in SQL Server Codenamed “Denali” CTP1.

The single file model has some downstream implications for event_file target and the fn_xe_file_target_read_file function.

event_file – You no longer need to set the metadatafile attribute but it is still available (but optional) so as not to break your DDL scripts. If you do provide a value for metadatafile it will be ignored for valid paths and it will throw an error for invalid paths.

fn_xe_file_target_read_file – The mdpath attribute is optional and ignored (but will throw if you provide an invalid path) when the filename path represents “Denali” XEL version files. You should just pass ‘NULL’ for mdpath as you would for all other optional attributes.

New options available for some targets

We’ve added a few new options to make some of the targets a bit more flexible.

pair_matching – In order to help prevent the pair_matching target from running amok in cases where you have an excessive number of orphaned records we’ve added the max_orphans option to the target with a default of 10000. As you might surmise, this option controls the number of orphaned records that will be maintained in the pair_matching target.

ring_buffer – We’ve introduce the max_events_limit for the ring_buffer to provide a deterministic way to control the number of events in the target. The default value is 1000 and we’ve changed the default for max_memory to be unlimited, meaning that the ring_buffer will use as much memory as required to store 1000 events by default. You can set one or both of these. When both are set we’ll honor the one that is hit first.

Wrapping up

Now that you have the overview go ahead and take Extended Events out for a spin. Dig into the detailed posts for more information about the UI and the programmatic APIs. If you find any issues or have suggestions for future advancements please post an item into Microsoft Connect so that others can vote on it. If you have questions, post them to the SQL Server Database Engine forum.

Happy Eventing!

- Mike

Today’s Subject: Predicates

extended_events — Thu, 24 Jun 2010 07:11:00 GMT

Don’t worry, I haven’t suddenly switched the topic of this blog to English grammar, but if you want to learn more about Predicates as they apply to sentence constriction you can start with this article on WikipediA. Rather, today’s topic is about predicates in Extended Events. You can find a brief description of predicates in Using SQL Server 2008 Extended Events (by Jonathan Kehayias) so I’ll try to extend your knowledge a bit beyond what that says.

Pre versus Post processing

There is usually more than one way to accomplish almost everything so it’s worth taking a moment to consider two different ways to process and event log. Post-processing describes the case where you allow the tracing system to collect every event and then you worry about reducing your data set after you’ve collected the data. Support for this doesn’t really depend on the diagnostic system you use since you can post-process any log that you can get into a tool that supports filtering, for example Excel. Some diagnostic systems have built in tools to do this as well. Pre-processing is when the filtering of events happens as part of the event generation code and therefore can “short-circuit” the event from firing. Extended Events support this type of pre-processing and that is what a Predicate if for.

Pre-processing has some cost associated with evaluating the predicate which is why some diagnostic systems choose not to offer this functionality, ETW is an example of a diagnostic system that does not support pre-processing of events.

Aside: Some ETW gurus (I don’t claim to be one) may argue that ETW does support pre-processing because you have the ability to define which events are collected based on Channel, Keyword and Level. For our purposes I’m defining pre-processing as requiring a finer level of control than that; you can decide if this is a semantic point or not.

The obvious question is: why would you want to use predicates if there is a potential cost? There are a couple of reasons for using a predicate, and as always, whether it is worth it for you to use is going to depend on your situation. The first common reason you might want to use predicates is when the performance hit of collection is higher than the performance hit of evaluating the predicate. Extended Events supports the ability to collect additional data such as call stacks or memory dumps and these can be expensive operations. In order to reduce the performance impact of these expensive operations you can use a predicate to increase the specificity of your event collection. Another common reason to use a predicate is to reduce the volume of events being collected. Many events can occur at extremely high volume, particularly those in the Analytic and Debug channels, and result in “log flooding”, or the behavior of putting many thousands (hundreds of thousands?) of events into the log that are not related to the problem you’re actually troubleshooting. All this extra data makes it hard to analyze the real issue and can cause the log files to be large enough to cause a disk space problem. Again, the solution is to increase the specificity of your event collection which will reduce the number of events you are looking at. Here are a few ways that you might use a predicate to increase specificity of your event collection:

Only collect events that occur within a specific database or session_id.
Only collect a sampling of events from your system. (I’ve described sampling in this post.)

So, how much do I save?

So now you’re wondering what you’re getting for your trouble and for that we need to take a look at what is actually going on inside Extended Events when an event is fired. For our purposes you can think of firing an event as requiring five steps as shown below.

The predicate evaluation happens at step three, but don’t let the fact that this is the “middle step” fool you, the amount of work required to generate an event is not equally distributed across these steps. Take the earlier example of collecting a memory dump, this is an expensive operation that happens in step 4 and when combined with publishing the event to a target is easily more costly than collecting the event data itself. The ability to evaluate a predicate right after the minimum amount of event data is collected can significantly reduce the cost of event collection in the cases where you are looking for a specific set of data.

Aside: SQL Trace/SQL Profiler also support pre-processing through the use of a filter (sp_trace_setfilter) but the filter is not applied until the entire Event Class and associated data has been collected resulting in relatively little performance savings.

OK, so how do predicates work

We’re finally to the actual topic of this post – thanks for sticking with me through all the preliminary stuff…

Predicates in Extended Events are very similar to the WHERE clauses that you’ve probably used in T-SQL; they’re Boolean expressions that can be evaluated against two types of data:

Local event data (Now you understand why we need to collect EventData first.)
Global state

Local event data is any of the fields that are automatically collect when an event fires. You can examine the list of local data fields for any given event by running a query against one of the DMVs for Extended Events; for example this query shows the fields for the wait_info event.

SELECT name, type_name
FROM sys.dm_xe_object_columns
WHERE object_name = 'wait_info' and column_type = 'data'

Field Name	Type
wait_type	wait_types
opcode	event_opcode
duration	uint64
max_duration	uint64
total_duration	uint64
signal_duration	uint64
completed_count	uint64

Global state represents data that is available in thread local storage (TLS) at all points in time in the SQL Server instances, or at least at most points in time. Examples of global state are things such as the session ID or the name of the client application. We call these predicate sources (pred_source for short) and you can query the list of predicate sources using a DMV.

SELECT name, description,
(SELECT name FROM sys.dm_xe_packages WHERE guid = o.package_guid) package
FROM sys.dm_xe_objects o
WHERE object_type = 'pred_source'
ORDER BY name

If you’re familiar with Extended Events you’ll notice that there is a strong correlation between predicate sources and actions. This correlation is on purpose so that you can write predicates against the same set of global data that you can collect using actions. But don’t let the similarities in names trick you into believing these are the same thing; the difference is the timing. Think back to the steps involved in firing an event – the point where the predicate is analyzed is where we collect the pred_source if there is a predicate that uses it. It’s not until after a predicate has evaluated as True that the system collects action data. This is the kind of technical detail that will make you sound cool at conferences when you overhear someone say “I used a predicate on the session_id action.” and you can explain that the predicate does not, in fact, use the session_id action, but rather the session_id predicate source. You would then further explain how the predicate sources allow for the creation of predicates over global data that is similar to that in actions, but that it can be done without having to collect the actions, therefore improving performance by short circuiting the action collection on events that are not of interest.

Now that we have an understanding of where the data comes from, lets look at a few predicates; we’ll use the wait_info event described above:

Only collect the event if the duration is more than 500 milliseconds.	ADD EVENT wait_info (WHERE duration > 500)
Only collect the event for session 52.	ADD EVENT wait_info (WHERE sqlserver.session_id = 52)
Only collect the event for NETWORK_IO waits.	ADD EVENT wait_info (WHERE wait_type = 99)

You can infer a couple rules from this list which I’ll state explicitly:

You only need to use the field name when building a predicate on local event data. (duration > 500)
You need to use the package name when using a predicate source. (sqlserver.session_id = 52)
You need to pay Mike to learn the secret translation of specific wait types to the number that represents them.

The secret translation of wait types into numbers (Maps): OK, so I’m not going to make much money from this secret, oh well. In order to make collection of some data a bit more efficient we created something called maps which simply map an integer to a more friendly string value. You can recognize map fields as those with data types that don’t seem to match with any type you’ve seen before, for example “wait_types”. You can look up the integer to friendly name comparison in the dm_xe_map_values DMV and matching the field’s type to the name column in the DMV. So to get a list of the numeric representation of the various waits, use the following query:

SELECT *
FROM sys.dm_xe_map_values
WHERE name = 'wait_types'

The final twist

Another long post but there is just one more thing to discuss before I bring it to a close and that is predicate comparators(pred_compare for short). As you’ve probably guessed from the name, predicate comparators are the operators in the Extended Events predicate system. We’ve done the work to map the standard mathematical operators (=, <, >, !=, <=, etc.) to the appropriate predicate comparators so that you don’t have to see the gory details. Under normal circumstances you probably won’t need to go beyond using these mapped operators and your predicates will look very similar to what you’d expect if you have a working knowledge of the WHERE clause in T-SQL. There may be an occasional need to walk on the wild side and do something out of the ordinary. For these times you have a whole list of interesting pred_comps to play with. You can see the list by querying a DMV:

SELECT name, description,
(SELECT name FROM sys.dm_xe_packages WHERE guid = o.package_guid) package
FROM sys.dm_xe_objects o
WHERE object_type = 'pred_compare'
ORDER BY name

As you scan down the list you’ll see that most pred_compare operators have obvious mappings to a mathematical operator for a specific data type, for example, greater_than_int64 is mapped to > for 64 bit integers. If you look closely you will find a small number that don’t have an obvious mathematical equivalent, such as greater_than_max_int64 or less_than_min_int64. These pred_compare operators are special in that they do more than a simple comparison, in fact, in the case of the two mentioned, they actually maintain state within the predicate and use that stat for the comparison. Let’s consider greater_than_max_int64: this pred_compare will maintain the maximum value of the field passed to it and only fire when it encounters a value that is greater than the current maximum, at which point it sets a new max value and waits until the next time it is exceeded. You might find this useful if you have a statement that is degrading over time and you only want to capture the event data at the points that a degradation actually happens in order to examine what else is happening at those times. Sure, you could capture all the query events and draw a graph to find the points of degradation, but this pred_compare does it for you automatically.

Calling a pred_compare directly follows this syntax:

package_name.pred_compare(field/pred_source, value)

Lets look at the duration predicate described before, but this time collect only when the duration exceeds 500 and is larger than the last maximum duration:

ADD EVENT wait_info (WHERE package0.greater_than_max_int64(duration, 500)

Wrapping it all up

Despite my single criteria example, you can actually build a predicate statement with multiple criteria using the common AND/OR syntax. Order is important and you should put your most specific criteria first because the the event will short circuit as soon as it hits the first part of the predicate that makes it false. So lets pull the entire post together with a predicate that will only return events for the NETWORK_IO wait type when it occurs on sessions with an ID of 52 and only when the duration is larger than the max duration but never less than 500 milliseconds. (I bet you knew that would be the example.)

ADD EVENT wait_info
(WHERE wait_type = 99 AND sqlserver.session_id = 52 AND
package0.greater_than_max_int64(duration, 500))

Whew! Hopefully that gives you an idea how Predicates can help you create very specific event sessions and even do some interesting analysis directly in the session. Let me know if there is a topic you’d like to see covered in this blog and we’ll add your request to the topic list.

- Mike