New AlwaysOn_health Extended Events Session in SQL Server 2012 RC0

While setting up my new Availability Group using SQL Server 2012 RC0 tonight, I noticed an interesting new addition to Extended Events associated with Availability Group configuration in the Release Candidate.  When you setup an Availability Group in RC0, another default Event Session is created on the servers that participate in the Availability Group to provide monitoring of the health of the Availability Group overall.  The definition of the monitoring session is as follows:

CREATE EVENT SESSION [AlwaysOn_health] ON SERVER
ADD EVENT sqlserver.alwayson_ddl_executed,
ADD EVENT sqlserver.availability_group_lease_expired,
ADD EVENT sqlserver.availability_replica_automatic_failover_validation,
ADD EVENT sqlserver.availability_replica_manager_state_change,
ADD EVENT sqlserver.availability_replica_state_change,
ADD EVENT sqlserver.error_reported(
    WHERE ([error_number]=(9691) OR [error_number]=(35204) OR [error_number]=(9693) OR [error_number]=(26024) OR [error_number]=(28047) OR [error_number]=(26023) OR [error_number]=(9692) OR [error_number]=(28034) OR [error_number]=(28036) OR [error_number]=(28048) OR [error_number]=(28080) OR [error_number]=(28091) OR [error_number]=(26022) OR [error_number]=(9642) OR [error_number]=(35201) OR [error_number]=(35202) OR [error_number]=(35206) OR [error_number]=(35207) OR [error_number]=(26069) OR [error_number]=(26070) OR [error_number]>(41047) AND [error_number]<(41056) OR [error_number]=(41142) OR [error_number]=(41144) OR [error_number]=(1480) OR [error_number]=(823) OR [error_number]=(824) OR [error_number]=(829) OR [error_number]=(35264) OR [error_number]=(35265))),
ADD EVENT sqlserver.lock_redo_blocked
ADD TARGET package0.event_file(SET filename=N'AlwaysOn_health.xel',max_file_size=(5),max_rollover_files=(4))
WITH (MAX_MEMORY=4096 KB,EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,MAX_DISPATCH_LATENCY=30 SECONDS,MAX_EVENT_SIZE=0 KB,MEMORY_PARTITION_MODE=NONE,TRACK_CAUSALITY=OFF,STARTUP_STATE=ON)
GO

This Extended Event Session monitors a number of critical events in the system but one of the problems with figuring out what exactly this Event Session is monitoring is to figure out what all the predicate values on the sqlserver.error_reported event are actually firing on.  To that aspect of things, we can do a quick reuse of the predicate on this event be doing a replace SSMS on the [error_number] value with a replace for an alias to a query to sys.messages, on the message_id column from the DMV as follows:

SELECT message_id, severity, is_event_logged, text
FROM sys.messages AS m
WHERE m.language_id = SERVERPROPERTY('LCID')
  AND  (m.message_id=(9691)
        OR m.message_id=(35204)
        OR m.message_id=(9693)
        OR m.message_id=(26024)
        OR m.message_id=(28047)
        OR m.message_id=(26023)
        OR m.message_id=(9692)
        OR m.message_id=(28034)
        OR m.message_id=(28036)
        OR m.message_id=(28048)
        OR m.message_id=(28080)
        OR m.message_id=(28091)
        OR m.message_id=(26022)
        OR m.message_id=(9642)
        OR m.message_id=(35201)
        OR m.message_id=(35202)
        OR m.message_id=(35206)
        OR m.message_id=(35207)
        OR m.message_id=(26069)
        OR m.message_id=(26070)
        OR m.message_id>(41047)
        AND m.message_id<(41056)
        OR m.message_id=(41142)
        OR m.message_id=(41144)
        OR m.message_id=(1480)
        OR m.message_id=(823)
        OR m.message_id=(824)
        OR m.message_id=(829)
        OR m.message_id=(35264)
        OR m.message_id=(35265)
)

This will give us a list of the error messages that the Event Session will actually fire events for:

message_id

severityis_event_loggedtext
823241The operating system returned error %ls to SQL Server during a %S_MSG at offset %#016I64x in file '%ls'. Additional messages in the SQL Server error log and system event log may provide more detail. This is a severe system-level error condition that threatens database integrity and must be corrected immediately. Complete a full database consistency check (DBCC CHECKDB). This error can be caused by many factors; for more information, see SQL Server Books Online.
824241SQL Server detected a logical consistency-based I/O error: %ls. It occurred during a %S_MSG of page %S_PGID in database ID %d at offset %#016I64x in file '%ls'.  Additional messages in the SQL Server error log or system event log may provide more detail. This is a severe error condition that threatens database integrity and must be corrected immediately. Complete a full database consistency check (DBCC CHECKDB). This error can be caused by many factors; for more information, see SQL Server Books Online.
829211Database ID %d, Page %S_PGID is marked RestorePending, which may indicate disk corruption. To recover from this state, perform a restore.
1480100The %S_MSG database "%.*ls" is changing roles from "%ls" to "%ls" because the mirroring session or availability group failed over due to %S_MSG. This is an informational message only. No user action is required.
9642160An error occurred in a Service Broker/Database Mirroring transport connection endpoint, Error: %i, State: %i. (Near endpoint role: %S_MSG, far endpoint address: '%.*hs')
9691100The %S_MSG endpoint has stopped listening for connections.
9692160The %S_MSG endpoint cannot listen on port %d because it is in use by another process.
9693160The %S_MSG endpoint cannot listen for connections due to the following error: '%.*ls'.
26022101Server is listening on [ %hs <%hs> %d].
26023161Server TCP provider failed to listen on [ %hs <%hs> %d]. Tcp port is already in use.
26024161Server failed to listen on %hs <%hs> %d. Error: %#x. To proceed, notify your system administrator.
26069101Started listening on virtual network name '%ls'. No user action is required.
26070101Stopped listening on virtual network name '%ls'. No user action is required.
28034100Connection handshake failed. The login '%.*ls' does not have CONNECT permission on the endpoint. State %d.
28036100Connection handshake failed. The certificate used by this endpoint was not found: %S_MSG. Use DBCC CHECKDB in master database to verify the metadata integrity of the endpoints. State %d.
28047101%S_MSG login attempt failed with error: '%.*ls'. %.*ls
28048101%S_MSG login attempt by user '%.*ls' failed with error: '%.*ls'. %.*ls
28080100Connection handshake failed. The %S_MSG endpoint is not configured. State %d.
28091100 Starting endpoint for %S_MSG with no authentication is not supported.
35201100A connection timeout has occurred while attempting to establish a connection to availability replica '%ls' with id [%ls]. Either a networking or firewall issue exists, or the endpoint address provided for the replica is not the database mirroring endpoint of the host server instance.
35202100A connection for availability group '%ls' from availability replica '%ls' with id  [%ls] to '%ls' with id [%ls] has been successfully established.  This is an informational message only. No user action is required.
35204100The connection between server instances '%ls' with id [%ls] and '%ls' with id [%ls] has been disabled because the database mirroring endpoint was either disabled or stopped. Restart the endpoint by using the ALTER ENDPOINT Transact-SQL statement with STATE = STARTED.
35206100A connection timeout has occurred on a previously established connection to availability replica '%ls' with id [%ls].  Either a networking or a firewall issue exists or the availability replica has transitioned to the resolving role.
35207160Connection attempt on availability group id '%ls' from replica id '%ls' to replica id '%ls' failed because of error %d, severity %d, state %d.
35264100AlwaysOn Availability Groups data movement for database '%.*ls' has been suspended for the following reason: "%S_MSG" (Source ID %d; Source string: '%.*ls'). To resume data movement on the database, you will need to resume the database manually. For information about how to resume an availability database, see SQL Server Books Online.
35265100AlwaysOn Availability Groups data movement for database '%.*ls' has been resumed. This is an informational message only. No user action is required.
41048101AlwaysOn Availability Groups: Local Windows Server Failover Clustering service has become unavailable. This is an informational message only. No user action is required.
41049101AlwaysOn Availability Groups: Local Windows Server Failover Clustering node is no longer online. This is an informational message only. No user action is required.
41050101AlwaysOn Availability Groups: Waiting for local Windows Server Failover Clustering service to start. This is an informational message only. No user action is required.
41051101AlwaysOn Availability Groups: Local Windows Server Failover Clustering service started. This is an informational message only. No user action is required.
41052101AlwaysOn Availability Groups: Waiting for local Windows Server Failover Clustering node to start. This is an informational message only. No user action is required.
41053101AlwaysOn Availability Groups: Local Windows Server Failover Clustering node started. This is an informational message only. No user action is required.
41054101AlwaysOn Availability Groups: Waiting for local Windows Server Failover Clustering node to come online. This is an informational message only. No user action is required.
41055101AlwaysOn Availability Groups: Local Windows Server Failover Clustering node is online. This is an informational message only. No user action is required.
41142160The availability replica for availability group '%.*ls' on this instance of SQL Server cannot become the primary replica. One or more databases are not synchronized or have not joined the availability group, or the WSFC cluster was started in Force Quorum mode. If the cluster was started in Force Quorum mode or the availability replica uses the asynchronous-commit mode, consider performing a forced manual failover (with possible data loss). Otherwise, once all local secondary databases are joined and synchronized, you can perform a planned manual failover to this secondary replica (without data loss). For more information, see SQL Server Books Online.
41144160The local availability replica of availability group '%.*ls' is in a failed state.  The replica failed to read or update the persisted configuration data (SQL Server error: %d).  To recover from this failure, either restart the local Windows Server Failover Clustering (WSFC) service or restart the local instance of SQL Server.

Based on this output, and the output of the following query:

SELECT name, description
FROM sys.dm_xe_objects
WHERE NAME IN (
'alwayson_ddl_executed',
'availability_group_lease_expired',
'availability_replica_automatic_failover_validation',
'availability_replica_manager_state_change',
'availability_replica_state_change',
'error_reported',
'lock_redo_blocked')

We can deduce the following about the Event Session:

CREATE EVENT SESSION [AlwaysOn_health] ON SERVER
–Occurs when AlwaysOn DDL is executed including CREATE, ALTER or DROP
ADD EVENT sqlserver.alwayson_ddl_executed,
–Occurs when there is a connectivity issue between the cluster and the Availability Group resulting
–in a failure to renew the lease
ADD EVENT sqlserver.availability_group_lease_expired,
–Occurs when the failover validates the readiness of replica as a primary. For instance, the failover
–validation will return false when not all databases are synchronized or not joined
ADD EVENT sqlserver.availability_replica_automatic_failover_validation,
–Occurs when the state of the Availability Replica Manager has changed.
ADD EVENT sqlserver.availability_replica_manager_state_change,
–Occurs when the state of the Availability Replica has changed.
ADD EVENT sqlserver.availability_replica_state_change,
–Occurs when an error is reported based on the previously listed table
ADD EVENT sqlserver.error_reported(
    WHERE ([error_number]=(9691) OR [error_number]=(35204) OR [error_number]=(9693) OR [error_number]=(26024) OR [error_number]=(28047) OR [error_number]=(26023) OR [error_number]=(9692) OR [error_number]=(28034) OR [error_number]=(28036) OR [error_number]=(28048) OR [error_number]=(28080) OR [error_number]=(28091) OR [error_number]=(26022) OR [error_number]=(9642) OR [error_number]=(35201) OR [error_number]=(35202) OR [error_number]=(35206) OR [error_number]=(35207) OR [error_number]=(26069) OR [error_number]=(26070) OR [error_number]>(41047) AND [error_number]<(41056) OR [error_number]=(41142) OR [error_number]=(41144) OR [error_number]=(1480) OR [error_number]=(823) OR [error_number]=(824) OR [error_number]=(829) OR [error_number]=(35264) OR [error_number]=(35265))),
–Occurs when the redo thread blocks when trying to acquire a lock.
ADD EVENT sqlserver.lock_redo_blocked
–Writes to the file target for persistence in the system beyond failovers and service restarts
ADD TARGET package0.event_file(SET filename=N'AlwaysOn_health.xel',max_file_size=(5),max_rollover_files=(4))
WITH (MAX_MEMORY=4096 KB, EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS, MAX_DISPATCH_LATENCY=30 SECONDS, MAX_EVENT_SIZE=0 KB, MEMORY_PARTITION_MODE=NONE, TRACK_CAUSALITY=OFF, STARTUP_STATE=ON)
GO

What is really cool is that this Event Session is used by the Availability Groups Dashboard to provide an overall status of the health of the Availability Group in Management Studio.

Performing a Distributed Replay with Multiple Clients using SQL Server 2012 Distributed Replay

In the first post in this blog series on using SQL Server 2012 Distributed Replay, Installing and Configuring SQL Server 2012 Distributed Replay, we looked at how to configure a Distributed Replay environment using multiple clients and a dedicated replay controller.  In this post we’ll actually make use of the previously configured servers to perform a distributed replay using a random workload that has been generated against the AdventureWorks2008R2 database installed on our Replay SQL Server.

Collecting the Replay Trace Data

For the purposes of generating a random workload against AdventureWorks2008R2, I created a workload generator that can be found on my blog post The AdventureWorks2008R2 Books Online Random Workload Generator.  I used this with 2 different PowerShell Windows from SQL2012-DRU1 and SQL2012-DRU2 to run a random workload across multiple sessions against the SQL2012-DB1 server.  To capture the trace data required for performing the replay, SQL Server Profiler was used along with the TSQL_Replay template to create the capture.

image

For production systems, the best way to go about capturing a Replay Trace is to script the trace definition to a file, and then create the trace as a server side trace that is writing to a trace file on local disks for the server.  This has a significantly lower impact that tracing directly from Profiler, which uses the rowset provider for Trace.  With the replay trace running, and the workload generating events I waited for the trace to collect around 80000 rows of data and then shutdown the trace so that I could access the trace file to copy it from the SQL2012-DB1 server to the SQL2012-DRU server where the Distributed Replay Controller is installed.

Preprocessing the Trace File(s)

At the point that I went to perform the preprocessing of the trace file for replay, I realized a difference in my environment using multiple servers to build this blog series versus my original setup using a single server for learning how to use Distributed Replay.  In order to preprocess the trace file for replay, you have to have the Management Tools Basic installed on the server that will be used for preprocessing the trace data.  If you have been following this blog series to learn how to use Distributed Replay, you will need to run Setup on the SQL2012-DRU server to add this feature before it can be used for pre-processing the trace file.  This is necessary to administer Distributed Replay.

image

Once the Management Tools Basic have been installed the server will have to be restarted and then it is possible to make use of the DReplay.Exe executable to administer the Distributed Replay components on the controller server. The DReplay executable has multiple options that can be discovered by using a –? from the command line as follows:

C:\Program Files (x86)\Microsoft SQL Server\110\Tools\Binn>dreplay -?
Info DReplay    Usage:
DReplay.exe {preprocess|replay|status|cancel} [options] [-?]}

Verbs:
preprocess Apply filters and prepare trace data for intermediate file on controller.
replay     Transfer the dispatch files to the clients, launch and synchronize replay.
status     Query and display the current status of the controller.
cancel     Cancel the current operation on the controller.
-?         Display the command syntax summary.

Options:
dreplay preprocess [-m controller] -i input_trace_file -d controller_working_dir [-c config_file] [-f status_interval]
dreplay replay [-m controller] -d controller_working_dir [-o] [-s target_server] -w clients [-c config_file] [-f status_interval]
dreplay status [-m controller] [-f status_interval]
dreplay cancel [-m controller] [-q]
Run dreplay <verb> -? for detailed help on each verb.

To perform the preprocessing, you will need to do a couple of different steps.  The first thing you need to do is edit any options that you want to set for the pre-processing by editing the DReplay.Exe.Preproces.config file in the C:\Program Files (x86)\Microsoft SQL Server\110\Tools\Binn path on the server.  There are two configuration files for DReplay.Exe as highlighted below.  At this time make sure that you are only editing the Preprocess.config file.

image

The DReplay.Exe.Preproces.config file contains a schema defined XML document that controls the configuration of the preprocessing.  In general the options set for preprocessing should not need to be changed but if you want to include system sessions as a part of the replay, you can change the options in the XML, which is listed below.

<?xml version="1.0" encoding="utf-8"?>
<Options>
    <PreprocessModifiers>
        <IncSystemSession>No</IncSystemSession>
        <MaxIdleTime>-1</MaxIdleTime>
    </PreprocessModifiers>
</Options>

To preprocess the trace data, open a new command prompt window and change directories to the C:\Program Files (x86)\Microsoft SQL Server\110\Tools\Binn path.  The trace file has been copied onto the SQL2012-DRU server as C:\DReplay\SQL2012_ReplayTrace.trc.  To preprocess this file first start the “SQL Server Distributed Replay Controller” service by using NET START:

NET START "SQL Server Distributed Replay Controller"

Then execute the following command from within the Binn path to actually preprocess the trace file and output:

dreplay preprocess -i "C:\DReplay\SQL2012_ReplayTrace.trc" -d "C:\DReplay"

This will process the trace file and output the working files for performing the Distributed Replay to the C:\DReplay path.  Below is a screenshot of the full window for preprocessing the trace file.

image

Note: The dreplay executable can be called from any path within the server because the Binn path is a part of the Path Environmental variables.  However, the executable has to be called from within the Binn folder to access the necessary .config files and .xsd schema files for the configuration.  If you want to be able to run this executable from another location on the server, you will need to copy the .config and .xsd files out of the Binn folder to the folder that you want to be able to run dreplay within for it to work.

Performing the Replay

The first step in performing the replay is to start the “SQL Server Distributed Replay Client” service on each of the replay clients using NET START.

NET START "SQL Server Distributed Replay Client"

You will want to verify that each of the clients was able to successfully connect to the controller in the logs as shown in the previous post in this series.  Once this has been done, your environment is almost ready for replay.  For the purposes of this blog series, a SELECT only workload has been generated for replay against AdventureWorks2008R2.  However, in most environments you won’t have a SELECT only workload, so you will have to plan for and prepare your replay environment using a BACKUP/RESTORE of the production database from a point within the captured workload so that the database can be replayed against without having problems associated with Primary Key constraint violations during the replay.

If you want to change any of the parameters associated with the replay operation, you can edit the DReplay.Exe.Replay.config file in the C:\Program Files (x86)\Microsoft SQL Server\110\Tools\Binn path.  The default contents of the configuration file are shown below:

<?xml version="1.0" encoding="utf-8"?>
<Options>
    <ReplayOptions>
        <Server></Server>
        <SequencingMode>stress</SequencingMode>
        <ConnectTimeScale>100</ConnectTimeScale>
        <ThinkTimeScale>100</ThinkTimeScale>
        <HealthmonInterval>60</HealthmonInterval>
        <QueryTimeout>3600</QueryTimeout>
        <ThreadsPerClient>255</ThreadsPerClient>
        <EnableConnectionPooling>No</EnableConnectionPooling>
        <StressScaleGranularity>SPID</StressScaleGranularity>
    </ReplayOptions>
    <OutputOptions>
        <ResultTrace>
            <RecordRowCount>Yes</RecordRowCount>
            <RecordResultSet>No</RecordResultSet>
        </ResultTrace>
    </OutputOptions>
</Options>

Before performing the actual replay, make sure that the account being used to run the SQL Server Distributed Replay Client service has been granted appropriate access to the target SQL Server and database to be able to perform the replay operations.  Once this has been done replay can be performed using the command line options for DReplay.Exe by providing the appropriate switches, or you can alternately provide the –c command line switch to specify the configuration file that should be used for performing the replay.  If you change any of the default values listed above in the DReplay.Exe.Replay.config file, you will need to specify the –c command line switch for those to take effect.  To perform a replay with the defaults, the following command line execution can be run:

dreplay replay -s "SQL2012-DB1" -d "C:\DReplay" -w "SQL2012-DRU1, SQL2012-DRU2"

Once this is executed, the Distributed Replay Controller will take read in the preprocessed replay file, and then synchronize the replay across all of the clients specified with the –w command line parameter.  While the replay operation occurs, the command window for the controller will output periodic updates about the current status of the replay process.

image

The frequency of the status updates can be controlled using the –f command line switch to specify the number of seconds between each of the updates.  Each of the status updates will provide information about each of the clients including the total number of events that have been replayed, the success rate of the replay operations per client, as well as an estimate for the total amount of time remaining to complete the replay operation.  When the replay completes the total elapsed time and pass rate for the events is output.

image

In the next and final post in this series, we’ll look at some of the common problems with using Distributed Replay and how to resolve them, including manually configuring the Controller and add additional Client Service accounts to the environment after Setup has been completed.

The AdventureWorks2008R2 Books Online Random Workload Generator

Over time, I’ve had a number of reasons to need to run a random workload against SQL Server to be able to demonstrate troubleshooting, how SQLOS works, and most recently how to capture a Replay Trace for my series on the Distributed Replay Utility in SQL Server 2012.  For a while I’ve maintained a large workload script that I would run using multiple sqlcmd command line windows to fire off the workload, but one of the problems with this has been that it was incredibly predictable, and it didn’t scale the way I really wanted it to.

When I was working with Distributed Replay, this became somewhat problematic with generating a randomized workload to capture a Replay Trace off of, so I took a few hours and went back to the drawing board with my idea.  What I came up with was a large script file that contains all of the SELECT statement examples from the SQL Server Books Online (http://msdn.microsoft.com/en-us/library/ms187731.aspx).  This script is divided into separate sections using a delimiter, and then I wrote a PowerShell script that reads the file and breaks it down into individual scripts that are randomly executed against the configured SQL Server using SMO.

The two files required to make use of this are attached to this blog post and can be used with minimal modifications against any SQL Server 2008+ system that has the AdventureWorks2008R2 database attached to it.  To make use of the PowerShell script, you will either have to sign it, or if you work like I do in my VMs, allow unsigned script execution with Set-ExecutionPolicy Unrestricted.

The PowerShell script is incredibly simple code wise.  It loads the SMO assembly, splits the file contents on the delimiter, then inside a infinite loop, it picks a random query and executes it against the SQL Server.

# Load the SMO assembly
[void][reflection.assembly]::LoadWithPartialName("Microsoft.SqlServer.Smo");

# Set the server to run the workload against
$ServerName = "SQL2012-DB1";

# Split the input on the delimeter
$Queries = Get-Content -Delimiter "——" -Path "AdventureWorks BOL Workload.sql"

WHILE(1 -eq 1)
{
    # Pick a Random Query from the input object
    $Query = Get-Random -InputObject $Queries;

    #Get a server object which corresponds to the default instance
    $srv = New-Object -TypeName Microsoft.SqlServer.Management.SMO.Server $ServerName

    # Use the AdventureWorks2008R2 database
    $srv.ConnectionContext.set_DatabaseName("AdventureWorks2008R2")

    # Execute the query with ExecuteNonQuery
    $srv.ConnectionContext.ExecuteNonQuery($Query);

    # Disconnect from the server
    $srv.ConnectionContext.Disconnect();
   
    # Sleep for 100 miliseconds between loops
    Start-Sleep -Milliseconds 100
}

To generate random workloads, I generally fire up 3-5 copies of this script on a client concurrently and leave it running in the background to generate the load. 

AdventureWorks BOL Workload.zip (6.35 kb)