Availability Group Readable Secondaries – Just Say No

Posted on: January 10, 2019 2:11 pm

Since SQL Server 2012, Microsoft has put a lot of efforts into marketing AlwaysOn Availability Groups as a feature and solution for both high availability/disaster recovery for SQL Server, and scalability for read-only workloads. Over the last six years, I have talked more clients out of using Availability Groups than I have actually implemented for SQL Server for a lot of different reasons. As easy as Microsoft has made it to build an Availability Group, restore and synchronize the databases, join secondary servers, etc. the simple fact is that once they are in production usage, you had better know what not to do that could break things, the impact having a readable secondary, and how to troubleshoot problems when they occur, because they will.

A lot of the implementation questions I get for Availability Groups are generally looking at leveraging a secondary replica for High Availability or Disaster Recovery and often times also for offloading reporting or readable workloads. Readable Secondary copies of the database are really simple at the surface conceptually, but there are a lot of additional considerations I make that could lead you to another technology entirely like Transactional Replication or Log Shipping with Standby. Let’s look at how these three stack up against each other for different data access requirements.

Real-time Data

First things first, for real-time data access, you only have one option, the primary writeable copy of the database. In replication this is the publisher database, log shipping calls it the log shipped primary, and Availability Groups refers to it as the primary replica. None of the secondary copies of the data, even in a synchronous Availability Group replica, is ever guaranteed to actually be real-time data. A synchronous Availability Group only guarantees that the log records for an operation are hardened in the synchronous secondary replicas transaction log allowing them to later be redone on the secondary database when a transaction commits. Depending on the volume of activity that is occurring, and whether the secondary replica is being used for read-only workloads or has sufficient hardware, the redo thread can typically be anywhere from a few hundred milliseconds to a few seconds behind the actual primary replica. This means that if you insert data into a table, scope the identity value and return it back to the application, then attempt to read that record immediately from the read-only secondary, it could actually not be there (Yes, this actually does happen).

Near Real-time Data

For near real time data access, both Replication and the Availability Group can meet the requirement for near real-time data. Replication typically will have slightly more latency than an Availability Group readable secondary in either commit mode by a few seconds due to the way replication functions. The log reader agent has to read the transaction log, write replication changes to the distribution database, and then the distribution agent has to pickup those changes up and apply them to the subscriber. This typically has a latency of 3-7 seconds under normal conditions, where an Availability Group readable secondary could have less latency depending on the volume of activity. The big difference between the two is entirely in the implementation and features supported.

If you need a non-clustered index to support the read-only workload, that index must be created on the primary database of an Availability Group for it to be available on the readable secondary. This means you have to backup and maintain that index and the maintenance will affect all servers in the Availability Group as a logged operation requiring redo on secondary replicas. This is not the case with transactional replication, where the subscriber database is a writeable copy of the database and can have a completely different indexing design from the publisher database that is based on just the read-only workload. Since the subscriber database is writeable, that also means that you can use features like Query Store, plan forcing, and automatic plan correction for the read-only workload; all of these are unavailable for a readable secondary replica in an Availability Group because the database is an exact duplicate of the primary (which can be enabled for Query Store and use these features).

Another consideration is the impact of the 14-byte row-version tag generation to support Read Committed Snapshot Isolation (RCSI) for the read-only replica in an Availability Group. This can only be generated on the primary replica database, but is not required on the publisher database for transactional replication. Why does this matter? It can lead to page splits that cause logical fragmentation of the indexes. Moving to a readable secondary may require monitoring index fragmentation and introducing fill factor changes where you wouldn’t have needed them previously. If you have read the incredibly bad information online telling you that you can ignore index fragmentation entirely with SSDs, or that you don’t need to rebuild indexes with an Availability Group, consider this: logical scan fragmentation may not matter much from a performance standpoint on fast storage, but a low page density caused by page splits and fragmentation affects every single replica copy and wastes space on disk and in memory in the buffer pool, and affects plan select due to query costing by the optimizer. With replication, all of this is avoided entirely unless you use RCSI for your publisher workload anyway, but that does not impact the subscribers in anyway since they are only replicated copies of the data modification operations, not the pages themselves.

Point-in-time Data

For point in time data access, I often go low tech and suggest using Log Shipping with Standby and delayed restore to create a warm copy of the database that is restored to a point in time. This can be useful for accounting reporting on the previous days sales transactions, performing ETL into a data mart or data warehouse, and it also provides the benefit of having a second copy of the database at a known point in time for DR purposes. You can also do this type of reporting off of the near real-time data provided by Replication and Availability Groups typically as well. The table below breaks down the features and requirements of each of these three technologies for providing a readable copy of the database.

	Real Time Data	Secondary Delay	Readable Workload Indexes	Row-version Tag Overhead	Query Store Support	Automatic Plan Correction	Partial Data Only
Availability Groups (Sync)	Primary Only	Depends on Redo typically within a few seconds	Must be created on Primary	Primary database with Readable Secondary	Primary Only	Primary Only	No
Availability Groups (Async)	Primary Only	Depends on Log Send Queue and Redo typically within a few seconds	Must be created on Primary	Primary database with Readable Secondary	Primary Only	Primary Only	No
Replication	Publisher Only	Depends on log reader and distribution agent typically within a few seconds	May be created on subscriber copy only	Only if RCSI enabled	Publisher and Subscribers	Publisher and Subscribers	Yes
Log Shipping	Primary Only	Depends on restore job configuration and standby – Point in time only, updates require disconnecting users	Must be created on Primary	Only if RCSI enabled	Primary Only	Primary Only	No

Complexity and Manageability

So what about complexity and manageability of these different options?

In the opening paragraph of this post I pointed out how easy Microsoft has made it to build an Availability Group to handle read-only copies of a database or group of databases. Setting up an Availability Group is really quite simple but that doesn’t mean it’s not lacking in complexity. First you need to know what kind of Availability Group are you going to implement. What started as a single feature has morphed over each release into:

Basic Availability Groups – Standard Edition (single database)
Enterprise Availability Groups – Enterprise Edition (one or many databases)
Distributed Availability Groups – Support for up to 17 readable secondaries without daisy-chaining
Domain Independent Availability Groups – Environments without Active Directory
Read-scale Availability Groups – No clustering requirement or HA

Add Linux into the mix of options as well as whether or not you need failover clustering as a part of that configuration, and this isn’t as simple as it seems. One of the common areas of failure with Availability Groups that I’ve seen is with choosing the correct quorum configuration for the Windows Failover Cluster configuration, though Microsoft has made this easier in Windows Server 2012 R2 and higher. An error in quorum configuration can result in your High Availability solution failing and taking the databases offline as a result.

Replication tends to get a bad rap when it comes to complexity and manageability. The reality is that the technology just isn’t well understood by most SQL Server professionals, and it is really easy to configure (there’s a great UI in SSMS for it also), and as long as you don’t play with it or modify data on the subscriber databases, it usually just works without a hitch. Change management is something that has to be planned out with Replication, where it wouldn’t have to be with Availability Groups. New tables have to be added to replication manually as an article, and certain operations like dropping and recreating a table or truncating a table are not allowed when the table is being replicated (sorry, no more using SSMS designer to insert a column in the middle of a table). Compared to Availability Groups, just for change management, Replication is much more complex and requires more work to manage over time, but the types of changes that require manual intervention in Replication typically are not occurring at a frequent pace for established applications and databases.

Log Shipping is just stupid simple low-tech and easy to manage. I mean for real how difficult is taking a backup and restoring it on another server? You might be surprised, but the configuration wizard and Agent Jobs automate this so that you typically don’t have to do anything but let it do its thing. Even third party backup tools offer their own flavor of implementation of log shipping as a part of their backup products for SQL Server typically. If something ever gets out of sync for log shipping, it usually means that someone took a manual log backup of the database, or switched recovery models and broke the log chain, and the standby database will have to be reinitialized from a new FULL backup of the primary to resume the restores (or you can manually apply the missing backup if a manual log backup was performed to close the gap).

Summary

While Availability Groups have become the Go To technology for providing a readable copy of data for SQL Server, they are not the only feature available to meet this requirement. It is important to understand the requirements and the limitations of any feature that you are considering using, and to also evaluate the other available features that might be a better fit for the needs of the environment. I have used transactional replication for nearly 10 years to solve read-only workload and reporting requirements for SQL Server and continue to use it over Availability Groups where as a technology, it is just a better fit for the requirements. Being able to reduce indexing on the primary writeable copy of the database and only having readable workload non-clustered indexes on the subscribers can be a huge benefit for some workloads. For one client it was the difference between a 800GB publisher database and a 1.7TB primary AG replica which affected their backup/restore times and RTO SLAs. Collect the requirements, evaluate the technologies and limitations, then choose the appropriate way to solve a problem.

Posted in: Uncategorized

10 Comments

CPU Ready Impact on SOS_SCHEDULER_YIELD

By: Jonathan Kehayias

Posted on: January 4, 2019 1:53 pm

At the end of May 2017, Paul and I had a discussion about SOS_SCHEDULER_YIELD waits and whether or not they could become skewed in SQL Server as a result of hypervisor scheduling issues for a VM running SQL Server. I did some initial testing of this in my VM lab using both Hyper-V and VMware and was able to create the exact scenario that Paul was asking about, which he explains in this blog post. I’ve recently been working on reproducing another VM scheduling based issue that shows up in SQL Server, where again the behaviors being observed are misleading as a result of the hypervisor being oversubscribed, only this time it was not for the SQL Server VM, it was instead for the application servers, and while I was building a repro of that in my lab, I decided to take some time and rerun the SOS_SCHEDULER_YIELD tests and write a blog post to show the findings in detail.

The test environment that I used for this is a portable lab I’ve used for demos for VM content over the last eight years teaching our Immersion Events. The ESX host has 4 cores and 8GB RAM and hosts three virtual machines, a 4vCPU SQL Server with 4GB RAM, and two 2vCPU Windows Server VM’s with 2GB RAM that are used strictly to run Geekbench to produce load. Within SQL Server, I a reproducible workload that drives parallelism and is repeatable consistently, that I have also used for years in teaching classes.

For the tests, I first ran a baseline where the SQL Server VM is the only machine executing any tasks/workload at all, but the other VMs are powered on and just sitting there on the hose. This establishes a base metric in the host and had 1% RDY time average during the workload execution, after which I collected the wait stats for SOS_SCHEDULER_YIELD.

Then I reran the tests but ran four copies of GeekBench on one of the application VM’s to drive the CPU usage for that VM and keep it having to be scheduled by the hypervisor, and then reran the SQL Server workload. This put the SQL Server VM at 5% RDY time in the hypervisor during the tests, which is my low watermark for where you would expect performance issues to start showing. When the SQL workload completed, I recorded the waits again.

Then I repeated the test again, but with both of the application VM’s running four copies of Geekbench. The SQL Server VM had an average of 28% RDY time, and when the workload completed the waits were recorded a final time.

As you can see below there is a direct increase in the wait occurrence with the increase in RDY%.

Test	AVG RDY%	wait_type	waiting_tasks_count	wait_time_ms	max_wait_time_ms	signal_wait_time_ms	Duration
2 APP VM	28.4	SOS_SCHEDULER_YIELD	10455	22893	124	22803	3:59
1 APP VM	5.1	SOS_SCHEDULER_YIELD	2514	3618	62	3608	1:57
Baseline	1.2	SOS_SCHEDULER_YIELD	1392	974	12	963	1:32

High CPU Ready time is something that should be consistently monitored for with SQL Server VM’s where low latency response times are required. It also should be monitored for application VMs where latency is important as well. One thing to be aware of with any of the wait types on a virtualized SQL Server, not just the SOS_SCHEDULER_YIELD wait, is that the time spent waiting is going to also include time the VM has to wait to be scheduled by the hypervisor as well. The SOS_SCHEDULER_YIELD wait type is unique in that the number of occurrences of the wait type increases because of the time shifts that happen causing quantum expiration internally for a thread inside of SQLOS forcing it to yield, even if it actually didn’t get to make progress due to the hypervisor not scheduling the VM.

Posted in: Internals, SQL Server, Virtualization

6 Comments

Simplifying Availability Group Troubleshooting

By: Jonathan Kehayias

Posted on: March 19, 2018 7:31 am

The AlwaysOn_health event session in Extended Events is intended to make analyzing problems with Availability Groups possible after they have occurred. While this event session goes a long way towards making it possible to piece together the puzzle of what went wrong in a lot of situations, it can still be a difficult task. One of the things I wish Microsoft had included in the AlwaysON_health event session definition is the sqlserver.server_instance_name action for every event, and this is something that I usually recommend clients add to each of their AG servers using a script after I work with them the first time. Why would this be useful, since if the files come from a specific server we should know the events are for that server right? Well, when we are working with AG configurations with more than two servers and trying to see the big picture of what is happening across the servers, it can be difficult to follow timelines with multiple files from multiple servers open. It’s not impossible, but it does make things more difficult.

Merging Extended Events Files

When the UI for Extended Events was introduced in SSMS 2012, Microsoft included the ability to merge multiple XEL files into a single view in the UI, which can be really useful during AG problem analysis. All you have to do is grab the AlwaysOn_health*.xel files from each of the replica servers, copy them into a folder and point the UI to the folder using the File > Open > Merge Extended Event Files… menu item and you can see all of the events from all of the servers in a single place.

Adding server_instance_name to Events

EXCEPT…. there is no server instance name contained in the events by default so this becomes of limited use without modifying the AlwaysOn_health event session to add the sqlserver.server_instance_name action to all of the events. This is easily accomplished in the UI using the multi-select options of the Configure tab on the event session properties as shown below, or may also be accomplished using the simple DDL script included at the bottom of this post.

ALTER EVENT SESSION [AlwaysOn_health] ON SERVER 
DROP EVENT sqlserver.alwayson_ddl_executed, 
DROP EVENT sqlserver.availability_group_lease_expired, 
DROP EVENT sqlserver.availability_replica_automatic_failover_validation, 
DROP EVENT sqlserver.availability_replica_manager_state_change, 
DROP EVENT sqlserver.availability_replica_state, 
DROP EVENT sqlserver.availability_replica_state_change, 
DROP EVENT sqlserver.error_reported, 
DROP EVENT sqlserver.hadr_db_partner_set_sync_state, 
DROP EVENT sqlserver.lock_redo_blocked;
GO

ALTER EVENT SESSION [AlwaysOn_health] ON SERVER 
ADD EVENT sqlserver.alwayson_ddl_executed(
    ACTION(sqlserver.server_instance_name)), 
ADD EVENT sqlserver.availability_group_lease_expired(
    ACTION(sqlserver.server_instance_name)), 
ADD EVENT sqlserver.availability_replica_automatic_failover_validation(
    ACTION(sqlserver.server_instance_name)), 
ADD EVENT sqlserver.availability_replica_manager_state_change(
    ACTION(sqlserver.server_instance_name)), 
ADD EVENT sqlserver.availability_replica_state(
    ACTION(sqlserver.server_instance_name)), 
ADD EVENT sqlserver.availability_replica_state_change(
    ACTION(sqlserver.server_instance_name)), 
ADD EVENT sqlserver.error_reported(
    ACTION(sqlserver.server_instance_name)
    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) OR [error_number]=(41188) OR [error_number]=(41189))), 
ADD EVENT sqlserver.hadr_db_partner_set_sync_state(
    ACTION(sqlserver.server_instance_name)), 
ADD EVENT sqlserver.lock_redo_blocked(
    ACTION(sqlserver.server_instance_name))
GO

Once the event session is modified, the files can easily be merged together in the UI for all future troubleshooting and each event will have the originating server_instance_name attached to it by the action.

Posted in: Availability Groups, Database Administration, Extended Events, SQL Server 2012, SQL Server 2014, SQL Server 2016

1 Comment

Database Master Keys and Availability Groups

By: Jonathan Kehayias

Posted on: February 22, 2018 7:04 am

Recently I received an email from a client experimenting with Availability Groups for the first time in a development environment that had run into an issue with adding one database out of fifteen to the Availability Group in the UI. The database in question had Password required beside it in the UI instead of the Meets prerequisites link all the other databases had. Clicking the Password required link produced a non-informative popup dialog saying “This database is encrypted by database master key, you need to provide valid password when adding it to the availability group.”

This was something I ran into a couple of years ago, and I did an Insider Demo video of this UI behavior for our SQLskills Insider Newsletter to demonstrate how the UI changed in SSMS 2016 to support encrypted databases and databases with encrypted content not using TDE as well. This is not caused by TDE, but by a database master key (DMK) that is protecting something like a certificate or an encrypted column in a table. The UI actually has a Password column next to the Status column, though it’s not very intuitive or clear that there are text boxes available for each database that you can click on to provide the password for the database master key.

In the screenshot above, the SSISDB requires a password to be added to the Availability Group, and the password has been provided in the Password column of the UI. To do this, actually requires a series of steps that aren’t exactly intuitive.

First, double click in the Password column and it will become a text box that is editable.
Type the password in.
Click Refresh at the bottom of the screen which will make the check box for the database enabled.
Check the checkbox for the database.
Click Refresh a second time, which will enable the Next button at the bottom.
Click Next to progress to the next screen in the wizard.

This took me 20 minutes to figure out in the back of the room during one of our Immersion Events after SQL Server 2016 released so I could answer a question for someone that wasn’t even related to this UI functionality about the SSISDB catalog and how it behaved in an Availability Group if an failover occurs during package execution.

Posted in: Availability Groups, Database Administration, SQL Server 2016

2 Comments

Downgrading SQL Server Editions

By: Jonathan Kehayias

Posted on: July 19, 2017 10:22 am

At some point in your career working with SQL Server, you will run into a situation where the wrong edition of SQL Server has been installed on a server and will need to change the edition for licensing reasons. Whether it is Enterprise Edition where Standard Edition should have been installed, Enterprise Edition where Developer Edition should have been used, or my favorite, Evaluation Edition where the 180 day trial has expired and Enterprise Edition isn’t going to be used, the only route available for downgrading the edition is to uninstall and reinstall SQL Server entirely. SQL Server Setup makes upgrading editions a piece of cake with SKUUPGRADE as a command line option for going from Standard/Developer/Evaluation to Enterprise, but anything else requires a full uninstall and reinstall to change the SKU/Edition and then restore all of the system and user databases to the new instance, which typically means a lot of work. I hate having to restore system databases and avoid having to do it if possible, so here is how I do this process and minimize the work required:

No matter what you are going to have to do an uninstall and reinstall of the SQL Server instance to downgrade the SKU. However, you can save yourself some time and the headache of trying to restore the system databases if you are careful about what you do. I have done a plenty of SKU downgrades in the past and the easiest way to do it, and I am not saying this is the Microsoft supported way but that it works if done correctly, is to:

Take a good backup of all of your databases (system and user).
Run SELECT @@VERSION and note the specific build number of SQL Server that you are currently on.
Shut down your existing instance of SQL Server.
Copy the master, model, and msdb database files (both mdf and ldf), don’t move them copy them, from the current location to a new folder that you mark as readonly.
Uninstall SQL Server from the system.
Reboot the server.
Install SQL Server Standard Edition.
Apply the necessary Service Pack and/or Cumulative Updates to bring the instance up to your previous build number.
Shutdown SQL Server.
Copy the master, model, and msdb database files (both mdf and ldf) from the folder you saved them in to the correct location for the new install and remove the readonly flag from the files, and change the file ACL’s so that the SQL Service account has Full Control over the files.
Startup SQL Server and if you did it correctly it will startup and be exactly where you were before you made any changes, with all of your user databases online and you should be ready to let applications connect and resume operations.

If you screw something up in the above, you still have your backups and you can run setup to rebuild the system databases and then go about following the Microsoft supported path for restoring the system databases and then user databases into the system to bring it online. Essentially the file copy is no different that what would occur through attach/detach you are just doing it with system databases which is not explicitly supported, but it does work. The key is to have your backups from before you do anything so you have the supported route available if you encounter an issue. The only issue I have ever had doing this set of steps is that I didn’t set the file ACL’s correctly and the database engine threw Access Denied errors and failed to start until I fixed the ACL’s correctly. This can save you many hours of frustration and downtime trying to restore everything since the database files are already there and it is just some small copy operations to put them where you need them to be.

Posted in: Database Administration, General, SQL Server, SQL Server 2008, SQL Server 2012, SQL Server 2014, SQL Server 2016

16 Comments

SQL 101: Parallelism Inhibitors – Scalar User Defined Functions

By: Jonathan Kehayias

Posted on: June 7, 2017 4:51 pm

As Kimberly blogged about recently, SQLskills is embarking on a new initiative to blog about basic topics, which we’re calling SQL101. We’ll all be blogging about things that we often see done incorrectly, technologies used the wrong way, or where there are many misunderstandings that lead to serious problems. If you want to find all of our SQLskills SQL101 blog posts, check out SQLskills.com/help/SQL101.

At the spring SQLintersection conference in Orlando, one of the attendees asked me a question about why a query wouldn’t go parallel even though the cost for the plan was in the hundreds. There are actually a number of different reasons why a query might execute serially, but usually one of the first things that comes to mind is scalar user defined functions. Developers love to use scalar user defined functions inside of SQL Server because it lets them compartmentalize code and easily reuse it, which is a common goal in object-oriented programming, but it’s also a performance anti-pattern for SQL Server as I’ll demonstrate in this post.

For the purposes of this post, I’m using the WorldWideImporters Standard Edition example database, and I’m going to recreate a scalar user defined function that I recently saw in a client engagement that was used to format the output of a column strictly for client presentation purposes. Using the [Warehouse].[ColdRoomTemperatures_Archive] table, which stores 5 second intervals of temperature readings as the basis for my example report, we are going to calculate the delta temperature between samples. For the delta if the number is greater than zero, then we want it to show with a + sign before the value and it if is below zero a – sign. An example query to provide the basic data set for the report would be:

USE [WideWorldImporters]
GO
SELECT 
    a.ColdRoomSensorNumber,
    a.Temperature AS StartingTemp, 
    b.Temperature AS EndingTemp, 
    a.ValidFrom, 
    a.ValidTo, 
    b.Temperature - a.Temperature AS Delta 
FROM Warehouse.ColdRoomTemperatures_Archive AS a
INNER JOIN Warehouse.ColdRoomTemperatures_Archive AS b 
   ON a.ValidTo = b.ValidFrom 
      AND a.ColdRoomSensorNumber = b.ColdRoomSensorNumber
WHERE a.ValidFrom BETWEEN '05/01/2016' AND '05/02/2016'
ORDER BY ColdRoomSensorNumber, ValidFrom;

For the sake of argument, the scenario I am using is a presentation layer issue, and the argument can be made that this problem should be handled by the presentation/application tier to do the formatting requested. However, there could be scenarios where the same data is needed in more than one application, reports, API feeds, etc. so for consistency the formatting is determined to be required for the SQL output. This is where a developer might write a function to handle the formatting so the code can be reused anytime we need to output temperature deltas to make sure that everything does it exactly the same way.

IF OBJECT_ID('dbo.GetFormatedTemperatureDelta') IS NOT NULL
    DROP FUNCTION dbo.GetFormatedTemperatureDelta;
GO
CREATE FUNCTION dbo.GetFormatedTemperatureDelta
(@StartingTemperature decimal(10,2), @EndingTemperature decimal(10,2))
RETURNS VARCHAR(10)
AS 
BEGIN
    DECLARE @Result VARCHAR(10);
    SET @Result =    CASE 
                        WHEN @StartingTemperature-@EndingTemperature > 0 
                            THEN '+'+CAST(@StartingTemperature-@EndingTemperature AS VARCHAR)
                        WHEN @StartingTemperature-@EndingTemperature < 0 
                            THEN CAST(@StartingTemperature-@EndingTemperature AS VARCHAR)
                        ELSE '0.00' 
                    END;    
    RETURN(@Result);
END
GO

SELECT 
    a.ColdRoomSensorNumber,
    a.Temperature AS StartingTemp, 
    b.Temperature AS EndingTemp, 
    a.ValidFrom, 
    a.ValidTo, 
    dbo.GetFormatedTemperatureDelta(b.Temperature, a.Temperature) AS Delta 
FROM Warehouse.ColdRoomTemperatures_Archive AS a
INNER JOIN Warehouse.ColdRoomTemperatures_Archive AS b 
   ON a.ValidTo = b.ValidFrom 
      AND a.ColdRoomSensorNumber = b.ColdRoomSensorNumber
WHERE a.ValidFrom BETWEEN '05/01/2016' AND '05/02/2016'
ORDER BY ColdRoomSensorNumber, ValidFrom;

As soon as they apply this formatting to the reporting query using the function, performance may or may not be noticeably impacted. Using the above two queries the duration of execution for both is just above 1 second of time based on the current data being requested for the report as shown by the STATISTICS TIME output for both:

SQL Server Execution Times:
CPU time = 1155 ms, elapsed time = 643 ms.

SQL Server Execution Times:
CPU time = 1250 ms, elapsed time = 1680 ms

However, notice the difference in the duration for the original statement vs the statement using the user defined function. The user defined function took over 2.5 times the duration. This problem gets worse as the size of the data set gets larger, but what we don’t see is the impact that this had to the way the query executes. Comparing the before function use and after function use execution plans:

Plan Without Function

Plan With Function

Before using the function, we had a parallel execution and after the plan is now serial. If we look at what happens for each statements execution with Extended Events using the sqlserver.sql_statement_completed and sqlserver.module_end events, filtered to my specific session_id and tracking how events relate to each other with TRACK_CAUSLITY=ON for the session, we’ll find that the function is executing for every row returned by the query, turning our set based operation into a RBAR (row-by-agonizing-row) operation.

CREATE EVENT SESSION [TrackFunctions] ON SERVER 
ADD EVENT sqlserver.module_end(
    WHERE ([sqlserver].[session_id]=(85))),
ADD EVENT sqlserver.sql_statement_completed(
    WHERE ([sqlserver].[session_id]=(85)))
WITH (TRACK_CAUSALITY=ON)
GO

Extended Event Session Results (grouped by activity_id)

We could change the function to do nothing at all and the impacts would be exactly the same. The query with the scalar user defined function will always run serially and row-by-row with the exception of if the function is created using SQLCLR which does allow scalar user defined functions that DO NOT perform data access to leverage parallelism. However, for this simple logic SQLCLR wouldn’t be required or recommended just to gain parallel query execution back. The easier fix is to simply inline the code to the original query:

SELECT 
    a.ColdRoomSensorNumber,
    a.Temperature AS StartingTemp, 
    b.Temperature AS EndingTemp, 
    a.ValidFrom, 
    a.ValidTo, 
    CASE WHEN b.Temperature - a.Temperature > 0 THEN '+'+CAST(b.Temperature-a.Temperature AS VARCHAR)
        WHEN b.Temperature - a.Temperature < 0 THEN CAST(b.Temperature-a.Temperature AS VARCHAR)
        ELSE '0.00' END         
         AS Delta 
FROM Warehouse.ColdRoomTemperatures_Archive AS a
INNER JOIN Warehouse.ColdRoomTemperatures_Archive AS b 
   ON a.ValidTo = b.ValidFrom 
      AND a.ColdRoomSensorNumber = b.ColdRoomSensorNumber
WHERE a.ValidFrom BETWEEN '05/01/2016' AND '05/02/2016'
ORDER BY ColdRoomSensorNumber, ValidFrom
GO

SQL Server Execution Times:
CPU time = 1233 ms, elapsed time = 676 ms.

Plan with inline expression

Here we have the fast execution time with a parallel plan but we are sacrificing the reuse of the code for other places where we might want to encapsulate the same logic. However, that doesn’t have to be the case since this logic can be done inline to the query, it can also be written into an inline-table valued function.

IF OBJECT_ID('dbo.GetFormatedTemperatureDelta_tvf') IS NOT NULL
    DROP FUNCTION dbo.GetFormatedTemperatureDelta_tvf;
GO
CREATE FUNCTION dbo.GetFormatedTemperatureDelta_tvf
(@StartingTemperature decimal(10,2), @EndingTemperature decimal(10,2))
RETURNS TABLE
AS 
RETURN (SELECT Delta =CASE 
                        WHEN @StartingTemperature-@EndingTemperature > 0 
                            THEN '+'+CAST(@StartingTemperature-@EndingTemperature AS VARCHAR)
                        WHEN @StartingTemperature-@EndingTemperature < 0 
                            THEN CAST(@StartingTemperature-@EndingTemperature AS VARCHAR)
                        ELSE '0.00' 
                    END)
GO

SELECT 
    a.ColdRoomSensorNumber,
    a.Temperature AS StartingTemp, 
    b.Temperature AS EndingTemp, 
    a.ValidFrom, 
    a.ValidTo, 
    Delta 
FROM Warehouse.ColdRoomTemperatures_Archive AS a
INNER JOIN Warehouse.ColdRoomTemperatures_Archive AS b 
   ON a.ValidTo = b.ValidFrom 
      AND a.ColdRoomSensorNumber = b.ColdRoomSensorNumber
CROSS APPLY dbo.GetFormatedTemperatureDelta_tvf(b.Temperature, a.Temperature)
WHERE a.ValidFrom BETWEEN '05/01/2016' AND '05/02/2016'
ORDER BY ColdRoomSensorNumber, ValidFrom
GO

SQL Server Execution Times:
CPU time = 1251 ms, elapsed time = 729 ms.

Plan With TVF

Here we get the best of both worlds, a parallel execution plan and the ability to reuse this logic in other places where we need the formatted output. If you look closely at the plan and the Compute Scalar operator, you will find that it is identical to the plan with inline code shown above. As a consultant, I’ve done a lot of conversions of scalar user defined functions to inline table valued functions to resolve performance issues and improve code scalability for clients. This is a very common problem to see in engagements and understanding the impacts of scalar user defined functions to performance is important for fast performance and optimizing TSQL code.

Posted in: Performance Tuning, SQL101

Be the first to Reply!

Reducing Long R720 POST Boot Time

By: Jonathan Kehayias

Posted on: June 5, 2017 9:00 am

I was recently working with a client that uses R720 servers for SQL Server and during restarts of the server, the POST (Power On Self Test) would stall for as long as 15 minutes before the Windows Server OS would actually begin starting. I did some searching and found the Dell PowerEdge 12G Server Bios PDF which covers PCIe Slot Disablement, which allows the PCIe slots to be set to Boot Driver Disabled to prevent the Option ROM from running during the POST to allow for quicker boot times. What this does is disable the preboot services for the device when it is a non-bootable device, while allowing the device to remain available to the OS. On the systems where the boot times were taking over 15 minutes, none of the PCIe devices were used for booting the server, and were PCIe SSDs and NIC’s. Setting the slots to Boot Driver Disabled reduced the POST time and allowed the server to reboot significantly faster.

To change these settings, first press F2 to enter into the BIOS during POST. You will have to wait for all of the preboot before the System Setup screen will show up. Then click on the Integrated Devices menu item:

Then click on the Slot Disablement menu item:

Then set the slots that are not required for bootable devices to Boot Driver Disabled:

Save the configuration and reboot the server and the POST should complete significantly faster now that it doesn’t have to initialize the device preboot and load the Option ROM from the device to allow it to be used for a bootable device. Since the OS driver is still available once the OS boots, the device will function inside of Windows, but as with anything your mileage may vary and you need to test this change before introducing it on production systems.

Posted in: Hardware

Be the first to Reply!

Tracking Compiles with Extended Events

By: Jonathan Kehayias

Posted on: June 2, 2017 11:45 am

This post comes from a question by Tara Kizer on DBA StackExchange related to Compilations/Sec in PerfMon and using Extended Events to try and track the compilations that were happening in SQL Server for one of their clients. There are a number of events in Extended Events that relate to plans in SQL Server, and Tara was using the sqlserver.query_pre_execution_showplan event as a way of tracking compiles with Extended Events. When I read the post on StackExchange this stood out to me as not being the correct event for tracking an actual compilation, and I would have selected the query_post_compilation_showplan event instead. These two events have similar descriptions, but they differ by one specific word:

query_pre_execution_showplan

Occurs after a SQL statement is compiled. This event returns an XML representation of the estimated query plan that is generated when the query is optimized. Using this event can have a significant performance overhead so it should only be used when troubleshooting or monitoring specific problems for brief periods of time.

query_post_compilation_showplan

Occurs after a SQL statement is compiled. This event returns an XML representation of the estimated query plan that is generated when the query is compiled. Using this event can have a significant performance overhead so it should only be used when troubleshooting or monitoring specific problems for brief periods of time.

NOTE: Both of these event descriptions state “Using this event can have a significant performance overhead so it should only be used when troubleshooting or monitoring specific problems for brief periods of time.” There are only a handful of events in Extended Events that include this warning in their description and each can introduce significant performance impacts to production workloads, so using them in live workloads is not something I’d recommend. (query_post_execution_showplan impact post)

The events aren’t exactly the same in description and occur at different times using the repro example from the StackExchange post. Using a much larger event session definition that includes additional events, it is easy to see where compilations actually are happening. The event session definition used for proofing this is:

CREATE EVENT SESSION [Compiles] ON SERVER
ADD EVENT sqlserver.query_post_compilation_showplan(
    ACTION(sqlserver.client_app_name,sqlserver.sql_text)
    WHERE ([sqlserver].[is_system]=(0))),
ADD EVENT sqlserver.query_pre_execution_showplan(
    ACTION(sqlserver.client_app_name,sqlserver.sql_text)
    WHERE ([sqlserver].[is_system]=(0))),
ADD EVENT sqlserver.sp_cache_hit(
    ACTION(sqlserver.client_app_name,sqlserver.sql_text)
    WHERE ([sqlserver].[is_system]=(0))),
ADD EVENT sqlserver.sp_cache_insert(
    ACTION(sqlserver.client_app_name,sqlserver.sql_text)
    WHERE ([sqlserver].[is_system]=(0))),
ADD EVENT sqlserver.sp_cache_miss(
    ACTION(sqlserver.client_app_name,sqlserver.sql_text)
    WHERE ([sqlserver].[is_system]=(0))),
ADD EVENT sqlserver.sp_cache_remove(
    ACTION(sqlserver.client_app_name,sqlserver.sql_text)
    WHERE ([sqlserver].[is_system]=(0))),
ADD EVENT sqlserver.sp_statement_completed(
    ACTION(sqlserver.client_app_name,sqlserver.sql_text)
    WHERE ([sqlserver].[is_system]=(0))),
ADD EVENT sqlserver.sp_statement_starting(
    ACTION(sqlserver.client_app_name,sqlserver.sql_text)
    WHERE ([sqlserver].[is_system]=(0))),
ADD EVENT sqlserver.sql_batch_completed(
    ACTION(sqlserver.client_app_name,sqlserver.sql_text)
    WHERE ([sqlserver].[is_system]=(0))),
ADD EVENT sqlserver.sql_batch_starting(
    ACTION(sqlserver.client_app_name,sqlserver.sql_text)
    WHERE ([sqlserver].[is_system]=(0))),
ADD EVENT sqlserver.sql_statement_completed(
    ACTION(sqlserver.client_app_name,sqlserver.sql_text)
    WHERE ([sqlserver].[is_system]=(0))),
ADD EVENT sqlserver.sql_statement_recompile(
    ACTION(sqlserver.client_app_name,sqlserver.sql_text)
    WHERE ([sqlserver].[is_system]=(0))),
ADD EVENT sqlserver.sql_statement_starting(
    ACTION(sqlserver.client_app_name,sqlserver.sql_text)
    WHERE ([sqlserver].[is_system]=(0))),
ADD EVENT sqlserver.uncached_sql_batch_statistics(
    ACTION(sqlserver.client_app_name,sqlserver.sql_text)
    WHERE ([sqlserver].[is_system]=(0)))
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=ON,
      STARTUP_STATE=OFF)
GO

Using part of the repro example from the StackExchange post with slight changes to include clearing the plan cache and also to break the steps down into individual batches and then individual statements we can show how the plans were being used from cache and where compiles actually are occurring.

CREATE TABLE t1 (transaction_id int, Column2 varchar(100));
CREATE TABLE t2 (Column1 varchar(max), Column2 varchar(100));
GO

CREATE TRIGGER t2_ins
ON t2
AFTER INSERT
AS

INSERT INTO t1
SELECT (SELECT TOP 1 transaction_id FROM sys.dm_tran_active_transactions), Column2
FROM inserted;
GO

DBCC FREEPROCCACHE
GO

--Both of these show compilation events
INSERT INTO t2 VALUES ('row1', 'value1');
INSERT INTO t2 VALUES ('row2', 'value2');
GO

--Both of these show compilation events
INSERT INTO t2 VALUES ('row1', 'value1');
INSERT INTO t2 VALUES ('row2', 'value2');
GO

--Both of these show compilation events
INSERT INTO t2 VALUES ('row1', 'value1');
GO

INSERT INTO t2 VALUES ('row2', 'value2');
GO

Here you can see the first compilation happening for the INSERT statements as prepared plans being auto-parameterized in the green box. The trigger is compiled in the red box and the plan is inserted into the cache as shown by the sp_cache_insert event. Then in the orange box the trigger execution gets a cache hit and reuses the trigger plan for the second INSERT statement in the batch, so it’s not compiling every execution of the INSERT command and the plan does get reused as you can see with the sp_cache_hit event for the trigger. The uncached_sql_batch_statistics event also fires for the initial batch since it doesn’t have a plan in cache and has to compile.

If we run the two INSERT statements individually again after the first execution the trigger doesn’t compile again as shown in the events below:

Here the first statement encounters a cache hit for the prepared auto-parameterized version of the statement in cache but a miss for the adhoc batch that was submitted. The trigger gets a cache hit and doesn’t compile again as shown in the red block of events. The green block of events repeats this behavior for the second INSERT statement run as a separate batch. However, in every case you still see the query_pre_execution_showplan event firing which I can only attribute to the difference in being optimized vs compiled in the event description, but the trigger isn’t compiling for every execution as shown by these series of events. The query_post_compilation_showplan event only fires when the plan is actually being compiled for the statements and/or trigger.

Posted in: Extended Events, Internals, Performance Tuning, Plan Cache

3 Comments

SQL Server 2016 Distributed Replay Errors

By: Jonathan Kehayias

Posted on: May 31, 2017 12:23 pm

If you’ve tried to install and configure Distributed Replay in SQL Server 2016, I wouldn’t be surprised to hear that you ran into all sorts of problems and probably didn’t end up getting it to work in a multi-client setup and eventually gave up. For whatever reason, Microsoft didn’t make the initial configuration of Distributed Replay in 2012, 2014 or 2016 very user friendly, and the error messages that you get when something isn’t correctly configured are less than helpful. For example:

2017-05-31 10:05:25:211 Error DReplay Unexpected error occurred!

Critical Error: code=[c8503012], msg=Unexpected error occurred!

Security violation with invalid remote caller.

Error Code: 0xC8502002

None of these errors help to pinpoint the cause of the problems, all of which are security/permissions related from what I’ve run into so far, but it’s not easy to figure it out unless you already know a fair bit about Distributed Replay and how it SHOULD be configured so you can spot where problems might be and try making changes.

Defaults After Installation

For my 2016 environment, I installed a Distributed Replay Controller and two separate Distributed Replay Clients, all of which used Service SIDs and were configured to use the correct controller following the installer information in my 2012 post. The only difference, aside from server names, was that I didn’t setup domain service accounts and let the installer setup Service SIDs for the controller and client services. When I start the controller service I get the following in the log using Windows Server 2016 and SQL Server 2016:

2017-05-31 11:05:29:669 OPERATIONAL [Controller Service] Microsoft SQL Server Distributed Replay Controller – 13.0.1601.5.
2017-05-31 11:05:29:669 OPERATIONAL [Controller Service] © Microsoft Corporation.
2017-05-31 11:05:29:669 OPERATIONAL [Controller Service] All rights reserved.
2017-05-31 11:05:29:684 OPERATIONAL [Controller Service] Current edition is: [Enterprise Edition].
2017-05-31 11:05:29:684 OPERATIONAL [Controller Service] The number of maximum supported client is 16.
2017-05-31 11:05:29:684 OPERATIONAL [Controller Service] Windows service “Microsoft SQL Server Distributed Replay Controller” has started under service account “NT SERVICE\SQL Server Distributed Replay Controller”. Process ID is 6572.
2017-05-31 11:05:29:684 OPERATIONAL [Controller Service] Time Zone: Eastern Standard Time.
2017-05-31 11:05:29:684 OPERATIONAL [Common] Initializing dump support.
2017-05-31 11:05:29:684 OPERATIONAL [Common] Failed to get DmpClient. [HRESULT=0x8007007F]

The Failed to get DmpClient error seems to be pretty common from Google search results, but isn’t actually a problem. So if I start the clients, I get the following in the logs:

2017-05-31 11:12:16:672 OPERATIONAL [Client Service]      Microsoft SQL Server Distributed Replay Client – 13.0.1601.5.
2017-05-31 11:12:16:672 OPERATIONAL [Client Service]      © Microsoft Corporation.
2017-05-31 11:12:16:672 OPERATIONAL [Client Service]      All rights reserved.
2017-05-31 11:12:16:672 OPERATIONAL [Client Service]      Current edition is: [Enterprise Edition].
2017-05-31 11:12:16:672 OPERATIONAL [Common]              Initializing dump support.
2017-05-31 11:12:16:672 OPERATIONAL [Common]              Failed to get DmpClient. [HRESULT=0x8007007F]
2017-05-31 11:12:16:672 OPERATIONAL [Client Service]      Windows service “Microsoft SQL Server Distributed Replay Client” has started under service account “NT SERVICE\SQL Server Distributed Replay Client”. Process ID is 7008.
2017-05-31 11:12:16:672 OPERATIONAL [Client Service]      Time Zone: Eastern Standard Time.
2017-05-31 11:12:16:688 OPERATIONAL [Client Service]      Controller name is “SQL2K16-AG01”.
2017-05-31 11:12:16:688 OPERATIONAL [Client Service]      Working directory is “C:\Program Files (x86)\Microsoft SQL Server\130\Tools\DReplayClient\WorkingDir”.
2017-05-31 11:12:16:688 OPERATIONAL [Client Service]      Result directory is “C:\Program Files (x86)\Microsoft SQL Server\130\Tools\DReplayClient\ResultDir”.
2017-05-31 11:12:16:688 OPERATIONAL [Client Service]      Heartbeat Frequency(ms): 3000
2017-05-31 11:12:16:688 OPERATIONAL [Client Service]      Heartbeats Before Timeout: 3

Notice that the last line DOES NOT say it was registered with the controller. It should say Registered with controller “SQL2K16-AG01” if it had successfully registered, but it doesn’t so something isn’t allowing the client to register correctly with the controller. To prove this, if we attempt a replay operation using the controller, it will output the following:

C:\DRUDemo>dreplay replay -s SQL2K16-AG01 -w “SQL2K16-AG02, SQL2K16-AG03” -f 10 -d “C:\DRUDemo\ReplayFiles” -o -c “c:\DRUDemo\DReplay.Exe.Replay.config”

2017-05-31 11:14:24:467 Error DReplay The client ‘SQL2K16-AG02’ is not a registered distributed replay client. Make sure that the SQL Server Distributed Replay Client services is running on ‘SQL2K16-AG02’, and that the client is registered with controller ‘localhost’.

So this confirms that out-of-the-box 2016 DRU won’t work and permissions changes will be required to make it work properly.

Configuring Component Services Permissions

On the Distributed Replay Controller machine, permissions need to be set in Component Services to allow the Distributed Replay Client Service accounts Launch and Activate permissions remotely on the COM component. The service accounts also need to be in the Distributed COM Users group in Windows. So in Component Services, expand Computers > My Computer > DCOM Config > DReplayController and right-click and open the Properties for the COM Component.

Edit the Launch and Activation Permissions and add the Service Account for the clients, in this case because a Service SID is being used, the computer account from Active Directory for each client machine, and allow Local Launch, Remote Launch, Local Activation and Remote Activation. Then edit the Access permissions and set Local Access and Remote Access for the Service accounts again.

Now as I mentioned above, the service accounts also need to be in the Distributed COM Users group in Windows. So make sure that the service accounts have been added to that group, and restart the services on the controller and clients. Checking the Client log file should now show:

2017-05-31 11:20:27:454 OPERATIONAL [Client Service]      Microsoft SQL Server Distributed Replay Client – 13.0.1601.5.
2017-05-31 11:20:27:454 OPERATIONAL [Client Service]      © Microsoft Corporation.
2017-05-31 11:20:27:454 OPERATIONAL [Client Service]      All rights reserved.
2017-05-31 11:20:27:454 OPERATIONAL [Client Service]      Current edition is: [Enterprise Edition].
2017-05-31 11:20:27:454 OPERATIONAL [Common]              Initializing dump support.
2017-05-31 11:20:27:454 OPERATIONAL [Common]              Failed to get DmpClient. [HRESULT=0x8007007F]
2017-05-31 11:20:27:454 OPERATIONAL [Client Service]      Windows service “Microsoft SQL Server Distributed Replay Client” has started under service account “NT SERVICE\SQL Server Distributed Replay Client”. Process ID is 6172.
2017-05-31 11:20:27:454 OPERATIONAL [Client Service]      Time Zone: Eastern Standard Time.
2017-05-31 11:20:27:454 OPERATIONAL [Client Service]      Controller name is “SQL2K16-AG01”.
2017-05-31 11:20:27:454 OPERATIONAL [Client Service]      Working directory is “C:\Program Files (x86)\Microsoft SQL Server\130\Tools\DReplayClient\WorkingDir”.
2017-05-31 11:20:27:454 OPERATIONAL [Client Service]      Result directory is “C:\Program Files (x86)\Microsoft SQL Server\130\Tools\DReplayClient\ResultDir”.
2017-05-31 11:20:27:454 OPERATIONAL [Client Service]      Heartbeat Frequency(ms): 3000
2017-05-31 11:20:27:454 OPERATIONAL [Client Service]      Heartbeats Before Timeout: 3
2017-05-31 11:21:21:798 OPERATIONAL [Client Service]      Registered with controller “SQL2K16-AG01”.

However, when we try a replay operation now, we get:

C:\DRUDemo>dreplay replay -s SQL2K16-AG01 -w “SQL2K16-AG02, SQL2K16-AG03” -f 10 -d “C:\DRUDemo\ReplayFiles” -o -c “c:\DRUDemo\DReplay.Exe.Replay.config”

2017-05-31 11:21:33:203 Error DReplay Unexpected error occurred!

Yep that’s really helpful, so lets go check the controller log and see what it has:

2017-05-31 11:21:31:374 OPERATIONAL [Controller Service] Event replay in progress. Detailed options:
2017-05-31 11:21:31:374 OPERATIONAL [Controller Service]      Target DB Server: [SQL2K16-AG01].
2017-05-31 11:21:31:374 OPERATIONAL [Controller Service]      Controller Working Directory: [C:\DRUDemo\ReplayFiles].
2017-05-31 11:21:31:374 OPERATIONAL [Controller Service]      Generate Result Trace: [Yes].
2017-05-31 11:21:31:374 OPERATIONAL [Controller Service]      Sequencing Mode: [SYNC].
2017-05-31 11:21:31:374 OPERATIONAL [Controller Service]      Connect Time Scale: [100].
2017-05-31 11:21:31:374 OPERATIONAL [Controller Service]      Think Time Scale: [100].
2017-05-31 11:21:31:374 OPERATIONAL [Controller Service]      Healthmon Polling Interval: [60].
2017-05-31 11:21:31:374 OPERATIONAL [Controller Service]      Query Timeout: [3600].
2017-05-31 11:21:31:374 OPERATIONAL [Controller Service]      Data Provider Type: [ODBC].
2017-05-31 11:21:31:374 OPERATIONAL [Controller Service]      Threads Per Client: [255].
2017-05-31 11:21:31:374 OPERATIONAL [Controller Service]      Record Row Count: [Yes].
2017-05-31 11:21:31:374 OPERATIONAL [Controller Service]      Record Result Set: [No].
2017-05-31 11:21:31:374 OPERATIONAL [Controller Service]      Connection Pooling Enabled: [Yes].
2017-05-31 11:21:31:374 OPERATIONAL [Controller Service]      Stress Scale Granularity: [Connection].
2017-05-31 11:21:31:374 OPERATIONAL [Controller Service]      Replay Clients: [SQL2K16-AG02, SQL2K16-AG03].
2017-05-31 11:21:33:203 CRITICAL     [Controller Service] **** Critical Error ****
2017-05-31 11:21:33:203 CRITICAL     [Controller Service] Machine Name: SQL2K16-AG01
2017-05-31 11:21:33:203 CRITICAL     [Controller Service] Error Code: 0xC8502002
2017-05-31 11:21:33:203 OPERATIONAL [Controller Service] Event replay completed.
2017-05-31 11:21:33:203 OPERATIONAL [Controller Service] Elapsed time: 0 day(s), 0 hour(s), 0 minute(s), 1 second(s).

You can try and Google/Bing that error code, hopefully you already did and it brought you to this blog post. So lets go back and check the client logs again, and we find these added messages:

2017-05-31 11:21:33:189 CRITICAL     [Client Service]      Security violation with invalid remote caller.
2017-05-31 11:21:33:189 CRITICAL     [Client Service]      Caller auth level is 2.
2017-05-31 11:21:33:189 CRITICAL     [Client Service]      Caller impersonation level is 1.
2017-05-31 11:21:33:189 CRITICAL     [Client Service]      Caller identity is SQLSKILLSDEMOS\SQL2K16-AG01$.
2017-05-31 11:21:33:189 CRITICAL     [Client Service]      Controller account is NT SERVICE\SQL Server Distributed Replay Controller.

So this points to another security issue, but I wasn’t sure how to go about troubleshooting this further using s Service SID, so at this point I changed from Service SIDs to Active Directory User accounts to run the services, DReplayClient for the clients and DReplayController for the controller. I reset all the permissions in Component Services on the controller machine and assigned the DReplayClient account to the Distributed COM Users group on the controller machine and gave it another shot.

C:\DRUDemo>dreplay replay -s SQL2K16-AG01 -w “SQL2K16-AG02, SQL2K16-AG03” -f 10 -d “C:\DRUDemo\ReplayFiles” -o -c “c:\DRUDemo\DReplay.Exe.Replay.config”

2017-05-31 11:37:51:189 Info DReplay    Dispatching in progress.
2017-05-31 11:37:51:189 Info DReplay    0 events have been dispatched.
2017-05-31 11:37:58:892 Info DReplay    Dispatching has completed.
2017-05-31 11:37:58:892 Info DReplay    0 events dispatched in total.
2017-05-31 11:37:58:892 Info DReplay    Elapsed time: 0 day(s), 0 hour(s), 0 minute(s), 0 second(s).
2017-05-31 11:37:58:892 Info DReplay    Event replay in progress.
2017-05-31 11:37:58:892 Info DReplay    Event replay has completed.
2017-05-31 11:37:58:892 Info DReplay    0 events (100 %) have been replayed in total. Pass rate 0.00 %.
2017-05-31 11:37:58:892 Info DReplay    Elapsed time: 0 day(s), 0 hour(s), 0 minute(s), 9 second(s).
2017-05-31 11:37:58:892 Error DReplay   Unexpected error occurred!

Well at least this time there was slightly more progress, it attempts to begin dispatching events, but ends miserably with another not so helpful error message. Looking at the replay client logs, the following information is output:

2017-05-31 11:35:56:969 OPERATIONAL [Controller Service] Event replay in progress. Detailed options:
2017-05-31 11:35:56:985 OPERATIONAL [Controller Service]      Target DB Server: [SQL2K16-AG01].
2017-05-31 11:35:56:985 OPERATIONAL [Controller Service]      Controller Working Directory: [C:\DRUDemo\ReplayFiles].
2017-05-31 11:35:56:985 OPERATIONAL [Controller Service]      Generate Result Trace: [Yes].
2017-05-31 11:35:56:985 OPERATIONAL [Controller Service]      Sequencing Mode: [SYNC].
2017-05-31 11:35:56:985 OPERATIONAL [Controller Service]      Connect Time Scale: [100].
2017-05-31 11:35:56:985 OPERATIONAL [Controller Service]      Think Time Scale: [100].
2017-05-31 11:35:56:985 OPERATIONAL [Controller Service]      Healthmon Polling Interval: [60].
2017-05-31 11:35:56:985 OPERATIONAL [Controller Service]      Query Timeout: [3600].
2017-05-31 11:35:56:985 OPERATIONAL [Controller Service]      Data Provider Type: [ODBC].
2017-05-31 11:35:56:985 OPERATIONAL [Controller Service]      Threads Per Client: [255].
2017-05-31 11:35:56:985 OPERATIONAL [Controller Service]      Record Row Count: [Yes].
2017-05-31 11:35:56:985 OPERATIONAL [Controller Service]      Record Result Set: [No].
2017-05-31 11:35:56:985 OPERATIONAL [Controller Service]      Connection Pooling Enabled: [Yes].
2017-05-31 11:35:56:985 OPERATIONAL [Controller Service]      Stress Scale Granularity: [Connection].
2017-05-31 11:35:56:985 OPERATIONAL [Controller Service]      Replay Clients: [SQL2K16-AG02, SQL2K16-AG03].
2017-05-31 11:35:59:048 OPERATIONAL [Controller Service] Event dispatch in progress.
2017-05-31 11:36:05:766 OPERATIONAL [Controller Service] Event replay completed.
2017-05-31 11:36:05:766 OPERATIONAL [Controller Service] Elapsed time: 0 day(s), 0 hour(s), 0 minute(s), 8 second(s).

Not much help there either, and this is where I would expect that most people would end up giving up because there is nothing really actionable here at all.

Client Service Account Permissions on Target SQL Server

While nothing is documented about changes in Distributed Replay behavior in SQL Server 2016, this last error is different than the behavior of previous versions of Distributed Replay. The problem is that the DReplayClient service account doesn’t have permissions in the target SQL Server to connect. To prove this, here is a trace capture of User Error Message events from the last replay operation attempt:

Each of the Replay clients is attempting to connect to the target server and failing. If we add the DReplayClient login to the target SQL Server and retry the reply, everything checks out and it actually begins to dispatch the events for the replay operation:

C:\DRUDemo>dreplay replay -s SQL2K16-AG01 -w “SQL2K16-AG02, SQL2K16-AG03” -f 10 -d “C:\DRUDemo\ReplayFiles” -o -c “c:\DRUDemo\DReplay.Exe.Replay.config”

2017-05-31 11:45:14:376 Info DReplay    Dispatching in progress.
2017-05-31 11:45:14:376 Info DReplay    0 events have been dispatched.
2017-05-31 11:45:24:377 Info DReplay    30753 events have been dispatched.
2017-05-31 11:45:34:377 Info DReplay    68262 events have been dispatched.
2017-05-31 11:45:44:377 Info DReplay    106677 events have been dispatched.
2017-05-31 11:45:54:393 Info DReplay    144226 events have been dispatched.
2017-05-31 11:46:04:408 Info DReplay    183595 events have been dispatched.
2017-05-31 11:46:14:424 Info DReplay    221378 events have been dispatched.
2017-05-31 11:46:24:424 Info DReplay    257754 events have been dispatched.
2017-05-31 11:46:34:455 Info DReplay    298436 events have been dispatched.
2017-05-31 11:46:44:471 Info DReplay    336026 events have been dispatched.
2017-05-31 11:46:54:471 Info DReplay    373717 events have been dispatched.
2017-05-31 11:47:04:486 Info DReplay    410378 events have been dispatched.
2017-05-31 11:47:14:502 Info DReplay    449949 events have been dispatched.
2017-05-31 11:47:24:518 Info DReplay    486431 events have been dispatched.
2017-05-31 11:47:34:533 Info DReplay    526228 events have been dispatched.
2017-05-31 11:47:44:549 Info DReplay    563484 events have been dispatched.
2017-05-31 11:47:48:361 Info DReplay    Dispatching has completed.
2017-05-31 11:47:48:361 Info DReplay    573630 events dispatched in total.
2017-05-31 11:47:48:361 Info DReplay    Elapsed time: 0 day(s), 0 hour(s), 2 minute(s), 35 second(s).
2017-05-31 11:47:48:361 Info DReplay    Event replay in progress.

Conclusion

Permissions, permissions, permissions… While having some of the worst error messages imaginable, the problems with getting Distributed Replay in SQL Server 2016 configured have so far boiled down to permissions issues and ensuring that the permissions for the service accounts are set correctly on the Controller machine, and on the Target Server for the replay operation should resolve the issues. Don’t forget to configure Firewall rules to allow access to the network appropriately as described in the original 2012 DRU post I wrote a few years back. Hopefully this post will save someone the trouble of trying to figure this all out blindly.

Posted in: Benchmarking, Building a Test Environment, Distributed Replay, Security, SQL Server 2016

4 Comments

Using Group Managed Service Accounts for SQL Server

By: Jonathan Kehayias

Posted on: May 30, 2017 5:25 pm

This afternoon I ran into an issue after rebooting one of my lab environment VM’s for SQL Server 2016 to give the VM more memory to allow some tests I’m doing with in-memory OLTP. When the VM rebooted I tried to connect to SQL Server with SSMS and the connection failed. So I opened up SQL Server Configuration Manager and found that the instance of SQL Server didn’t start when Windows started, so I tried to manually start the instance and received the following error:

When I opened up the SQL Server ERRORLOG file, I found the following errors:

2017-05-30 17:08:17.65 spid11s     Error: 17190, Severity: 16, State: 1.
2017-05-30 17:08:17.65 spid11s     Initializing the FallBack certificate failed with error code: 1, state: 20, error number: 0.
2017-05-30 17:08:17.66 spid11s     Unable to initialize SSL encryption because a valid certificate could not be found, and it is not possible to create a self-signed certificate.
2017-05-30 17:08:17.66 spid11s     Error: 17182, Severity: 16, State: 1.
2017-05-30 17:08:17.66 spid11s     TDSSNIClient initialization failed with error 0x80092004, status code 0x80. Reason: Unable to initialize SSL support. Cannot find object or property.
2017-05-30 17:08:17.66 spid11s     Error: 17182, Severity: 16, State: 1.
2017-05-30 17:08:17.66 spid11s     TDSSNIClient initialization failed with error 0x80092004, status code 0x1. Reason: Initialization failed with an infrastructure error. Check for previous errors. Cannot find object or property.
2017-05-30 17:08:17.66 spid11s     Error: 17826, Severity: 18, State: 3.
2017-05-30 17:08:17.66 spid11s     Could not start the network library because of an internal error in the network library. To determine the cause, review the errors immediately preceding this one in the error log.
2017-05-30 17:08:17.66 spid11s     Error: 17120, Severity: 16, State: 1.
2017-05-30 17:08:17.66 spid11s     SQL Server could not spawn FRunCommunicationsManager thread. Check the SQL Server error log and the Windows event logs for information about possible related problems.

This is when I remembered that I had set this lab VM up to use a Group Managed Service Account (gMSA) for SQL Server, and my Active Directory Domain Controller for the Lab environment wasn’t running. The instance couldn’t start because it couldn’t talk to the domain controller to obtain the credentials for the gMSA which as the service account for SQL Server is at the top of the Encryption Hierarchy for the instance. So a lesson learned on lab environment VM’s that use managed service accounts, you have to have the Active Directory Domain controller running or the instance won’t start because it can’t retrieve the credential information for the service account to run the instance. This can also happen in production environments where a domain controller might not be local to a SQL Server installation and networking issues prevent the SQL instance from being able to retrieve the credentials to start the server.

Posted in: Building a Test Environment, Security, SQL Server 2016

1 Comment

The Rambling DBA

Real-time Data

Near Real-time Data

Point-in-time Data

Complexity and Manageability

Summary

Merging Extended Events Files

Adding server_instance_name to Events

Defaults After Installation

Configuring Component Services Permissions

Client Service Account Permissions on Target SQL Server

Conclusion