Is there a pending reboot on my SQL Server?

As a DBA we make every effort to avoid bringing systems off line, however there are times where that is exactly what needs to happen.  From a Windows and SQL Server perspective there are a number of changes that require a reboot.  These reasons range from the application of Windows updates, the changing of Windows policies and changes to SQL Server settings.  Over the years there have been a number of times where I have connected to a server and found a message stating that there is a pending reboot.  When changes are made, of course we want the changes to take effect as soon as possible.  In some cases a change will not take effect until a reboot happens. In order to determine if there is a pending reboot, we need to look at a number of places, including both Windows and SQL Server.

Starting with Windows, there are some changes that require a reboot, including that application of Windows updates.  Checking for a pending reboot for Windows can be done using one of the newest friends of a DBA, Powershell.  The information that needs to be queried is in the registry.

This is the popup that I have seen a number of times showing that there is a pending update.  What makes this the less than ideal option is that I need to logon to the server.

Brian Wilhite has a very nice PowerShell module that you can use to check for pending reboots in Windows.  It can be found on GitHub here. It can also be found on PowerShellGallery.com here. You can also download the ps1 file here.

On August 20, 2018 he stated on Microsoft’s Script Center web site that he is no longer making updates to this on the Script Center site, you will need to get it from GitHub instead, link is above.  According to the Script Center site here are the versions of the OS it has been tested on.  I have tested it on Windows 10 and it appears to work just fine.

The script below will install the module and complete the check.

         # Install

Module -Name PendingReboot
# Run
Test-PendingReboot -Detailed -ComputerName localhost
In order to run this script, you must run the Powershell application as Administrator.  If you do not, you will see this error.
Below are the results of running the PendingReboot PowerShell script.  By adding the -Detailed switch you will see more information about what might have caused the need for the restart.  In addition, you can add the -ComputerName switch to check a remote computer.
What I like about this is that it allows me to test a remote computer.  Just as a precautionary measure, make sure to throughout research and exercise the appropriate caution prior to running any code obtained on the internet on production servers.
Of course knowing if there is a pending reboot in Windows is important, however there are a number of SQL Server settings that will also cause a need for a restart of the SQL Server service in order to take effect.  The above powershell script will not detect this.  There are a few ways using SQL Server Management Studio that can tell us if the service needs to be restarted.
The first method is to look at the settings of the SQL Server.  At the bottom you will see “Configured Value” and “Running Value”.  If you look at the images below, you can see that the Default index fill factor is different.  The configured value is 0, while the running value is 85.  This is a sign that the SQL Server service needs to be restarted.

 

 

 

 

 

 

 

The drawback of this type of check is that I need to manually go to each setting option and do a compare.  Luckily, Microsoft has added a view for us to use to programmatically check this.  The view is sys.configurations.  There are a number of columns that are important for what we are looking for.  Below I have listed the columns that are important for the purpose of this post.  Of course there are more columns that these.

Is_dynamic is the column that will tell us if a restart is needed if that value of the setting is changed. If this is true, a restart of the service is not needed if the value is changed.

is_advanced identifies if it is an advanced option

value_in_use is the column that will tells us the Running value

value will identify that configured value

When looking at this, if Value_in_use and value are different, then a service restart is needed.  In this case, the fill factor(%) is different.  The running value is use is 85% while the configured value is 0.

 

This is the code used to get the above result set.

SELECT    name
  , is_dynamic
  , is_advanced
  , value_in_use
  , value
FROM sys.configurations
WHERE is_dynamic = 0

In order to determine if a restart is needed, we need to add more to the WHERE clause.  We just need to do a simple comparison of the value_in_use and the value columns.  Of course we are also only looking at the settings that is_dynamic is set to FALSE or 0.  If this query below returns any rows, a restart of the service is needed in order to have it take effect.

SELECT    name
  , is_dynamic
  , is_advanced
  , value_in_use
  , value
FROM sys.configurations
WHERE is_dynamic = 0
  AND value <> value_in_use
IF @@ROWCOUNT >= 1
 BEGIN
  SELECT ‘Restart is needed’ AS ‘Restart Needed?’
 END
ELSE
 BEGIN
  SELECT ‘NO restart is needed’ AS ‘Restart Needed?’
 END
Hopefully you will find this information useful.
Thank you for visiting my blog.

How Often does SQL Server look for Deadlocks

Although life would be much easier for every DBA if deadlocks never happened, we all realize that they do happen.  There is a great deal of information out there on the causes of and solutions for deadlocks.  The focus of this post is more about how often does SQL Server check to see if a deadlock is happening.

Prior to getting into how SQL Server detects deadlocks, let’s take a few minutes to quickly go over exactly what a deadlock it.

Microsoft states this on their website:

“A deadlock occurs when two or more tasks permanently block each other by each task having a lock on a resource which the other tasks are trying to lock”

Because deadlocks happen when two task permanently block each other, without a deadlock, both process will simply block forever. Of course this could never be good in a production system.  It is important that these situations be identified and dealt with in some manner.  This is where SQL Server database engine steps in, it is frequently searching the lock manager looking for deadlocks.

Initially the interval the deadlock check takes place is every 5 seconds. This interval may decrease depending on if it finds a deadlock.  If a deadlock is not found, the check will remain at every 5 seconds.  As mentioned, 5 seconds is the default interval, it is also the maximum number of seconds between checks. If SQL Server finds deadlock, then the interval will be decreased and checks will happen more frequently.  The minimum interval is 100 ms.  Finally, if deadlocks were found at one point and they longer exist the interval will return to 5 seconds.

While there are many options that can be changed in SQL Server, the default frequency for deadlock checks is not among the list.  This option is not configurable.  These checks are very light weight and should not cause any issues on the system.  If SQL Server is checking more frequently than 5 seconds, that means it is finding deadlocks and your time and energy should be focused on addressing that.

In addition to the interval for the check of deadlocks, there are a few other items related to deadlocks that I feel are important to know as a DBA.  The most obvious is what are some of the causes of deadlocks. If you Google what causes deadlocks you will find a ton of information. I also feel that it is important to know how to get information about the deadlock as well as how SQL Server determines which process well be the victim.  I have a blog post on one of the methods SQL Server uses to determine to victim, it can be found here.  This post is about the DeadLock_priority option.  SQL Server will also use the cost to rollback as one of the criteria to determine of the victim.

A logical question would be how do I capture information about deadlocks.  There are a number of ways to do this within SQL Server.  I like to use Extended Events.  I have a blog post on how to use Extended Events to capture the deadlock graph.  It can be found here. You can either create your own Extended Event session or use the System_health session that already exists.  You can also use traceflags 1222 and 1204.  In older versions of SQL Server, the trace flags were the only way to capture this information.

You can also use a third part monitoring tool such as the SQL Monitor by Red-Gate.  This is a great tool!  Here is a link to a demo.

Here are some really good links on deadlocks

 How to Fix SQL Server deadlocks – Grant Fritchey at Red-Gate

 Overview of Deadlocks – www.sqlshack.com

 Analyzing Deadlocks – Microsoft

I will also be doing future blog posts on deadlocks from time to time.  Thank you for visiting my blog!!!

 

 

Azure SQL Database Connections work in SSMS but not with Azure Data Factory Connection

Over the past month or so, I have attended a number of sessions on Azure Data Factories.  Both presenters were amazing and I learned a ton.  However, as I usually do, I took the information and went off on my own to play with this new tool I hear a lot of people talking about. During both sessions I was able to connect to my Azure SQL Database with SQL Server Management Studio, but not with the connection in the Azure Data Factory. While I really didn’t get much of a chance to ask the presenter about my problem, I was finally able to.  He was able to give me the answer I was looking for.

Before getting to the solution, let’s go over what the problem actually was.  I have an Azure SQL Database that I have connected to many times via SSMS.  However, during both sessions I attempted to create a connection in ADF and the test of the connection failed every time.

So what did I check? Just to confirm, I again connected via SSMS as I had done many times in the past.  Again, no issues. Now I was convinced that the issue was not the database or the username\password. The next thing I thought of was the firewall rules.  I asked myself the following question: Could there be an issue with the firewall and the IP addresses?  Again, all appeared to be working just fine.  Then I decided to do one more check using a third technology, I connected to the database via the Azure SQL Editor, which requires a username and password to connect.  Again, all appeared to be fine.

At this point, I knew more about what was not causing the problem than what was causing the problem.  Finally I had a moment with one of the presenters and he was able to give me the cause and the solution. As is usually the case, it was a single setting that was causing this and a very simple fix.  That setting was the an Azure SQLDB setting, specifically the “Allow Access to Azure Services” setting.

To get to the setting, navigate to the settings of the Azure SQL DB and click on Overview, the orange box below.  Then you will see the “Set server Firewall” option, click that.

Once you do, you will see something like the image below.  Simply move the On\Off slider to On for the “Allow access to Azure service” setting.  Then click the Save button.

Once you do that, then you should be able to connect to your Azure SQL Database using the Azure Data Factory connection.  This made perfect sense, SSMS is not an Azure service, while Azure Data Factory is. Also keep in mind there are many reason that could create a similar situation, this was the cause of the issue I was seeing.  So make be prepared to continue to troubleshoot this issue if this does not work.

Thanks for visiting my blog!!!

Extended Events – Database Restore

Many of us have restored productions databases.  Of course no one wants to do it, but we all acknowledge that there are times in which that is exactly what we need to do, restore a database.  Have you ever wondered what steps SQL Server actually goes through to complete the restore?  Extended Events offers an event that will allow us to see inside the restore process.

When I did a search of what events are available for restore operations, I found two, backup_restore_progress_trace and databases_backup_restore_throughput. Backup_restore_progress_trace will be the focus of this post.

Backup_restore_progress_trace does exactly what you might think it would do, documents the internal steps of the restore process.

Below are all the steps that Backup_restore_progress_trace picked up during a restore of a very small database.  These are also in the order in which the steps took place.  These steps are for a restore to a database that does not exist yet.

RESTORE DATABASE started
Opening the backup set
Processing the leading metadata
Planning begins
Effective options: Checksum=0, Compression=0, Encryption=0, BufferCount=6, MaxTransferSize=64 KB
Planning is complete
Beginning OFFLINE restore
Attached database as DB_ID=5
Preparing containers
Containers are ready
Restoring the backup set
Estimated total size to transfer = 2838528 bytes
Transferring data
FileHandleCache: Initial CacheSize: 48
BackupStream(0): Processing MSDA of size 43 extents
6 percent (196608/2838528 bytes) processed
11 percent (327680/2838528 bytes) processed
16 percent (458752/2838528 bytes) processed
20 percent (589824/2838528 bytes) processed
25 percent (720896/2838528 bytes) processed
30 percent (851968/2838528 bytes) processed
36 percent (1048576/2838528 bytes) processed
41 percent (1179648/2838528 bytes) processed
46 percent (1310720/2838528 bytes) processed
50 percent (1441792/2838528 bytes) processed
55 percent (1572864/2838528 bytes) processed
60 percent (1703936/2838528 bytes) processed
66 percent (1900544/2838528 bytes) processed
71 percent (2031616/2838528 bytes) processed
76 percent (2162688/2838528 bytes) processed
80 percent (2293760/2838528 bytes) processed
85 percent (2424832/2838528 bytes) processed
90 percent (2555904/2838528 bytes) processed
96 percent (2752512/2838528 bytes) processed
BackupStream(0): Completed MSDA
Waiting for log zeroing to complete
Log zeroing is complete
BackupStream(0): Processing MSTL (FID=2, VLFID=36, size=65536 bytes)
100 percent (2838528/2838528 bytes) processed
Data transfer is complete
Backup set is restored
Offline roll-forward begins
Processing 8 VLF headers
Processing VLF headers is complete
First LSN: 36:4232:37, Last LSN: 36:4272:1
Stop LSN: 36:4272:1
Offline roll-forward is complete
Database fixup is complete
Transitioning database to ONLINE
Restarting database for ONLINE
PostRestoreContainerFixups begins
PostRestoreContainerFixups is complete
PostRestoreReplicationFixup begins
PostRestoreReplicationFixup is complete
Database is restarted
Resuming any halted Fulltext crawls
Writing history records
Writing history records is complete (elapsed = 58 ms)
MSDB maintenance is complete
RESTORE DATABASE finished

Many these steps are pretty straight forward.  They can also easily group the steps into phases.

The first few steps are simply to prepare for the restore.  Once SQL Server is done preparing, it then starts the restore.  You can see there are a number of steps in this process, including the assigning of a database ID.  Then you can see the increments in percent of where the restore stands.  Once the restore is complete, SQL Server moves on to the steps in which SQL Server a rolls forward transactions, brings the database online and starts the database.  After this, SQL Server the writes the history into the MSDB system tables.

While these steps are for a new database, many of the same steps will take place for the restore of an existing database.  The most noticeable additions to the steps are the acquiring of database locks.  As you can see below, these are Exclusive locks.

Acquiring X lock on the database

Acquired X lock on the database

SQL Server will spend varied amounts of time on each step.  As expected, the most time is spent on the actual transfer of data to the restored database. Below you will see a table with two columns, timestamp for each and the step name for the restored I completed for this test.  While this process only took a few seconds, a larger database would obviously take much more time.

Time Stamp At Start of Step Operation
00:11:38.457 RESTORE DATABASE started
00:11:38.457 Opening the backup set
00:11:38.473 Processing the leading metadata
00:11:38.473 Planning begins
00:11:38.490 Effective options: Checksum=0,

Compression=0, Encryption=0, BufferCount=6, MaxTransferSize=64 KB

00:11:38.490 Planning is complete
00:11:38.490 Beginning OFFLINE restore
00:11:38.490 Attached database as DB_ID=5
00:11:38.490 Preparing containers
00:11:38.577 Containers are ready
00:11:38.640 Restoring the backup set
00:11:38.640 Estimated total size

to transfer = 2838528 bytes

00:11:38.640 Transferring data
00:11:38.640 FileHandleCache: Initial CacheSize: 48
00:11:38.640 BackupStream(0): Processing

MSDA of size 43 extents

00:11:38.653 6 percent (196608/2838528 bytes) processed
00:11:38.657 11 percent (327680/2838528 bytes) processed
00:11:38.660 16 percent (458752/2838528 bytes) processed
00:11:38.667 20 percent (589824/2838528 bytes) processed
00:11:38.687 25 percent (720896/2838528 bytes) processed
00:11:38.687 30 percent (851968/2838528 bytes) processed
00:11:38.700 36 percent (1048576/2838528 bytes) processed
00:11:38.713 41 percent (1179648/2838528 bytes) processed
00:11:38.713 46 percent (1310720/2838528 bytes) processed
00:11:38.713 50 percent (1441792/2838528 bytes) processed
00:11:38.740 55 percent (1572864/2838528 bytes) processed
00:11:38.740 60 percent (1703936/2838528 bytes) processed
00:11:38.763 66 percent (1900544/2838528 bytes) processed
00:11:38.763 71 percent (2031616/2838528 bytes) processed
00:11:38.763 76 percent (2162688/2838528 bytes) processed
00:11:38.790 80 percent (2293760/2838528 bytes) processed
00:11:38.790 85 percent (2424832/2838528 bytes) processed
00:11:38.797 90 percent (2555904/2838528 bytes) processed
00:11:38.817 96 percent (2752512/2838528 bytes) processed
00:11:38.837 BackupStream(0): Completed MSDA
00:11:38.840 Waiting for log zeroing to complete
00:11:38.877 Log zeroing is complete
00:11:38.877 BackupStream(0): Processing MSTL (FID=2, VLFID=36, size=65536 bytes)
00:11:38.880 100 percent (2838528/2838528 bytes) processed
00:11:38.897 Data transfer is complete
00:11:38.910 Backup set is restored
00:11:38.957 Offline roll-forward begins
00:11:38.957 Processing 8 VLF headers
00:11:38.960 Processing VLF headers is complete
00:11:38.963 First LSN: 36:4232:37, Last LSN: 36:4272:1
00:11:38.963 Stop LSN: 36:4272:1
00:11:38.967 Offline roll-forward is complete
00:11:38.990 Database fixup is complete
00:11:38.993 Transitioning database to ONLINE
00:11:38.993 Restarting database for ONLINE
00:11:39.093 PostRestoreContainerFixups begins
00:11:39.097 PostRestoreContainerFixups is complete
00:11:39.100 PostRestoreReplicationFixup begins
00:11:39.267 PostRestoreReplicationFixup is complete
00:11:39.277 Database is restarted
00:11:39.297 Resuming any halted Fulltext crawls
00:11:39.307 Writing history records
00:11:39.367 Writing history records

is complete (elapsed = 58 ms)

00:11:39.367 MSDB maintenance is complete
00:11:39.370 RESTORE DATABASE finished

Hidden within the steps are some very useful tidbits of information.

    • Database ID
    • Number of Extents
    • Number of bytes restored
    • Beginning and Ending LSN for the roll forward
    • Total time to write history records

While the very small test database took about 60 steps to complete, I was wondering what if the database was bigger.  Using the AdventureWork2014 database, I completed a restore and there were many more steps, a total of 114 steps.  Below are the steps in order.

backup_restore_progress_trace 2019-06-18 11:17:01.5974587 +00:00 BACKUP LOG started

backup_restore_progress_trace 2019-06-18 11:17:01.5975148 +00:00 Acquiring U lock on the database

backup_restore_progress_trace 2019-06-18 11:17:01.5975471 +00:00 Synchronizing with other operations on the database is complete

backup_restore_progress_trace 2019-06-18 11:17:01.5988528 +00:00 Halting Fulltext crawls

backup_restore_progress_trace 2019-06-18 11:17:01.5994759 +00:00 Acquiring X lock on the database

backup_restore_progress_trace 2019-06-18 11:17:01.5995329 +00:00 Acquired X lock on the database

backup_restore_progress_trace 2019-06-18 11:17:01.6135276 +00:00 Writing a failover checkpoint

backup_restore_progress_trace 2019-06-18 11:17:01.6753875 +00:00 Failover checkpoint is complete

backup_restore_progress_trace 2019-06-18 11:17:01.6755993 +00:00 Failover FlushCache is complete

backup_restore_progress_trace 2019-06-18 11:17:01.6756137 +00:00 Opening the backup media set

backup_restore_progress_trace 2019-06-18 11:17:01.6801075 +00:00 The backup media set is open

backup_restore_progress_trace 2019-06-18 11:17:01.6801651 +00:00 Preparing the media set for writing

backup_restore_progress_trace 2019-06-18 11:17:01.6811968 +00:00 The media set is ready for backup

backup_restore_progress_trace 2019-06-18 11:17:01.6812025 +00:00 Effective options: Checksum=0, Compression=0, Encryption=0, BufferCount=7, MaxTransferSize=1024 KB

backup_restore_progress_trace 2019-06-18 11:17:01.6812297 +00:00 Start LSN: 500:27608:118, SERepl LSN: 0:0:0

backup_restore_progress_trace 2019-06-18 11:17:01.6812385 +00:00 First LSN: 630:28048:1

backup_restore_progress_trace 2019-06-18 11:17:01.6812477 +00:00 Estimated total size = 542920704 bytes (data size = 0 bytes, log size = 542920704 bytes)

backup_restore_progress_trace 2019-06-18 11:17:01.6812508 +00:00 Work estimation is complete

backup_restore_progress_trace 2019-06-18 11:17:01.6812559 +00:00 Last LSN: 663:7624:1

backup_restore_progress_trace 2019-06-18 11:17:01.6812606 +00:00 Scanning filestream data

backup_restore_progress_trace 2019-06-18 11:17:01.6819216 +00:00 Scanning filestream data is complete

backup_restore_progress_trace 2019-06-18 11:17:01.6819294 +00:00 Writing the leading metadata

backup_restore_progress_trace 2019-06-18 11:17:01.6819931 +00:00 BackupStream(0): Writing leading metadata to the device C:\Program Files\Microsoft SQL Server\MSSQL14.MSSQLSERVER\MSSQL\Backup\AdventureWorks2014_LogBackup_2019-06-18_06-16-59.bak

backup_restore_progress_trace 2019-06-18 11:17:01.6821581 +00:00 Copying filestream data

backup_restore_progress_trace 2019-06-18 11:17:01.6905789 +00:00 Copying filestream data is complete

backup_restore_progress_trace 2019-06-18 11:17:01.6905984 +00:00 Copying transaction log

backup_restore_progress_trace 2019-06-18 11:17:01.6907865 +00:00 MediaFamily(0): FID=2, VLFID=630, DataStreamSize=2424832 bytes

backup_restore_progress_trace 2019-06-18 11:17:01.7037592 +00:00 MediaFamily(0): FID=2, VLFID=631, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:01.7704909 +00:00 MediaFamily(0): FID=2, VLFID=632, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:01.8050246 +00:00 5 percent (27590656/542920704 bytes) processed

backup_restore_progress_trace 2019-06-18 11:17:01.8396719 +00:00 MediaFamily(0): FID=2, VLFID=633, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:01.9147575 +00:00 MediaFamily(0): FID=2, VLFID=634, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:01.9238444 +00:00 10 percent (54853632/542920704 bytes) processed

backup_restore_progress_trace 2019-06-18 11:17:01.9810017 +00:00 MediaFamily(0): FID=2, VLFID=635, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:02.0323014 +00:00 15 percent (82116608/542920704 bytes) processed

backup_restore_progress_trace 2019-06-18 11:17:02.0498153 +00:00 MediaFamily(0): FID=2, VLFID=636, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:02.1195952 +00:00 MediaFamily(0): FID=2, VLFID=637, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:02.1464469 +00:00 20 percent (109379584/542920704 bytes) processed

backup_restore_progress_trace 2019-06-18 11:17:02.1877744 +00:00 MediaFamily(0): FID=2, VLFID=638, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:02.2570845 +00:00 25 percent (136642560/542920704 bytes) processed

backup_restore_progress_trace 2019-06-18 11:17:02.2573724 +00:00 MediaFamily(0): FID=2, VLFID=639, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:02.3263001 +00:00 MediaFamily(0): FID=2, VLFID=640, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:02.3702739 +00:00 30 percent (163905536/542920704 bytes) processed

backup_restore_progress_trace 2019-06-18 11:17:02.3941585 +00:00 MediaFamily(0): FID=2, VLFID=641, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:02.4635771 +00:00 MediaFamily(0): FID=2, VLFID=642, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:02.4768947 +00:00 35 percent (190119936/542920704 bytes) processed

backup_restore_progress_trace 2019-06-18 11:17:02.5315044 +00:00 MediaFamily(0): FID=2, VLFID=643, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:02.5872516 +00:00 40 percent (217382912/542920704 bytes) processed

backup_restore_progress_trace 2019-06-18 11:17:02.6020868 +00:00 MediaFamily(0): FID=2, VLFID=644, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:02.6732336 +00:00 MediaFamily(0): FID=2, VLFID=645, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:02.7043113 +00:00 45 percent (244645888/542920704 bytes) processed

backup_restore_progress_trace 2019-06-18 11:17:02.7416025 +00:00 MediaFamily(0): FID=2, VLFID=646, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:02.8128799 +00:00 MediaFamily(0): FID=2, VLFID=647, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:02.8199368 +00:00 50 percent (271908864/542920704 bytes) processed

backup_restore_progress_trace 2019-06-18 11:17:02.8834042 +00:00 MediaFamily(0): FID=2, VLFID=648, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:02.9338510 +00:00 55 percent (299171840/542920704 bytes) processed

backup_restore_progress_trace 2019-06-18 11:17:02.9552501 +00:00 MediaFamily(0): FID=2, VLFID=649, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:03.0292680 +00:00 MediaFamily(0): FID=2, VLFID=650, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:03.0524488 +00:00 60 percent (326434816/542920704 bytes) processed

backup_restore_progress_trace 2019-06-18 11:17:03.0999388 +00:00 MediaFamily(0): FID=2, VLFID=651, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:03.1645396 +00:00 65 percent (353697792/542920704 bytes) processed

backup_restore_progress_trace 2019-06-18 11:17:03.1683370 +00:00 MediaFamily(0): FID=2, VLFID=652, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:03.2374707 +00:00 MediaFamily(0): FID=2, VLFID=653, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:03.2742992 +00:00 70 percent (380960768/542920704 bytes) processed

backup_restore_progress_trace 2019-06-18 11:17:03.3044229 +00:00 MediaFamily(0): FID=2, VLFID=654, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:03.3723517 +00:00 MediaFamily(0): FID=2, VLFID=655, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:03.4062676 +00:00 75 percent (408223744/542920704 bytes) processed

backup_restore_progress_trace 2019-06-18 11:17:03.4598903 +00:00 MediaFamily(0): FID=2, VLFID=656, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:03.5105134 +00:00 80 percent (434438144/542920704 bytes) processed

backup_restore_progress_trace 2019-06-18 11:17:03.5290138 +00:00 MediaFamily(0): FID=2, VLFID=657, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:03.6010196 +00:00 MediaFamily(0): FID=2, VLFID=658, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:03.6293332 +00:00 85 percent (461701120/542920704 bytes) processed

backup_restore_progress_trace 2019-06-18 11:17:03.6878991 +00:00 MediaFamily(0): FID=2, VLFID=659, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:03.7633069 +00:00 90 percent (488964096/542920704 bytes) processed

backup_restore_progress_trace 2019-06-18 11:17:03.7636287 +00:00 MediaFamily(0): FID=2, VLFID=660, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:03.8362761 +00:00 MediaFamily(0): FID=2, VLFID=661, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:03.8837162 +00:00 95 percent (516227072/542920704 bytes) processed

backup_restore_progress_trace 2019-06-18 11:17:03.9154381 +00:00 MediaFamily(0): FID=2, VLFID=662, DataStreamSize=16777216 bytes

backup_restore_progress_trace 2019-06-18 11:17:03.9883764 +00:00 MediaFamily(0): FID=2, VLFID=663, DataStreamSize=3932160 bytes

backup_restore_progress_trace 2019-06-18 11:17:04.0073959 +00:00 100 percent (542920704/542920704 bytes) processed

backup_restore_progress_trace 2019-06-18 11:17:04.0187093 +00:00 Copying transaction log is complete

backup_restore_progress_trace 2019-06-18 11:17:04.0187231 +00:00 Writing the trailing metadata

backup_restore_progress_trace 2019-06-18 11:17:04.0188013 +00:00 BackupStream(0): Writing trailing metadata to the device C:\Program Files\Microsoft SQL Server\MSSQL14.MSSQLSERVER\MSSQL\Backup\AdventureWorks2014_LogBackup_2019-06-18_06-16-59.bak

backup_restore_progress_trace 2019-06-18 11:17:04.0188753 +00:00 Writing the end of backup set

backup_restore_progress_trace 2019-06-18 11:17:05.1136445 +00:00 Resuming any halted Fulltext crawls

backup_restore_progress_trace 2019-06-18 11:17:05.1145570 +00:00 Writing history records

backup_restore_progress_trace 2019-06-18 11:17:05.1570406 +00:00 Writing history records is complete (elapsed = 43 ms)

backup_restore_progress_trace 2019-06-18 11:17:05.1571172 +00:00 BACKUP LOG finished

backup_restore_progress_trace 2019-06-18 11:17:05.1846587 +00:00 Acquiring U lock on the database

backup_restore_progress_trace 2019-06-18 11:17:05.1846855 +00:00 RESTORE DATABASE started

backup_restore_progress_trace 2019-06-18 11:17:05.1846983 +00:00 Acquiring X lock on the database

backup_restore_progress_trace 2019-06-18 11:17:05.1847096 +00:00 Acquired X lock on the database

backup_restore_progress_trace 2019-06-18 11:17:05.1848243 +00:00 Opening the backup set

backup_restore_progress_trace 2019-06-18 11:17:05.1929402 +00:00 Processing the leading metadata

backup_restore_progress_trace 2019-06-18 11:17:05.1941467 +00:00 Planning begins

backup_restore_progress_trace 2019-06-18 11:17:05.2423481 +00:00 Effective options: Checksum=0, Compression=0, Encryption=0, BufferCount=6, MaxTransferSize=1024 KB

backup_restore_progress_trace 2019-06-18 11:17:05.2423558 +00:00 Planning is complete

backup_restore_progress_trace 2019-06-18 11:17:05.2426545 +00:00 Beginning OFFLINE restore

backup_restore_progress_trace 2019-06-18 11:17:05.8613121 +00:00 Preparing containers

backup_restore_progress_trace 2019-06-18 11:17:05.9191974 +00:00 Preparing FileStream container: c:\data\imoltp_mod1

backup_restore_progress_trace 2019-06-18 11:17:06.1012537 +00:00 Prepared FileStream container: c:\data\imoltp_mod1

backup_restore_progress_trace 2019-06-18 11:17:06.1013026 +00:00 Containers are ready

backup_restore_progress_trace 2019-06-18 11:17:06.1842403 +00:00 Restoring the backup set

backup_restore_progress_trace 2019-06-18 11:17:06.1842624 +00:00 Estimated total size to transfer = 2909552640 bytes

backup_restore_progress_trace 2019-06-18 11:17:06.1855198 +00:00 Transferring data

backup_restore_progress_trace 2019-06-18 11:17:06.1856031 +00:00 FileHandleCache: Initial CacheSize: 48

backup_restore_progress_trace 2019-06-18 11:17:06.1883666 +00:00 BackupStream(0): Processing MSDA of size 8288 extents

backup_restore_progress_trace 2019-06-18 11:17:07.5410761 +00:00 5 percent (145752064/2909552640 bytes) processed

backup_restore_progress_trace 2019-06-18 11:17:08.9161089 +00:00 10 percent (291504128/2909552640 bytes) processed

backup_restore_progress_trace 2019-06-18 11:17:10.3224426 +00:00 15 percent (437256192/2909552640 bytes) processed

backup_restore_progress_trace 2019-06-18 11:17:11.4572357 +00:00 BackupStream(0): Completed MSDA

backup_restore_progress_trace 2019-06-18 11:17:11.4580438 +00:00 BackupStream(0): Processing PH6(filestream) data

backup_restore_progress_trace 2019-06-18 11:17:11.5794020 +00:00 BackupStream(0): Completed PH6(filestream) data

backup_restore_progress_trace 2019-06-18 11:17:11.5894867 +00:00 Waiting for log zeroing to complete

There are a lot more steps to a restore than I ever thought there would be.  If you are interested, here is the code I used to create the Extended Event session.  If you decide to use this, please make sure you change the name to something that works for you and change the path for the target files.

CREATE EVENT SESSION [RestoreDatabase] ON SERVER
ADD EVENT sqlserver.backup_restore_progress_trace(
ACTION(sqlos.worker_address,sqlserver.client_hostname,sqlserver.nt_username,sqlserver.sql_text))
ADD TARGET package0.event_file(SET filename=N‘RestoreDatabase’)
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

To read the data, you can utilize SSMS or use TSQL.  If you use SSMS, once you right click on the target and view the data, you can then go to the Extended Events menu item and at the bottom, you will see an option to Export the data.  With this, you can export the data to a table so you can then use TSQL to view the data.

Or you can use the code below.  If you place the .xel file in a different location than the default, you will need to update the path to the files in the function, fn_xe_file_target_read_file.

SELECT event_data = convert(xml, event_data)
INTO #eeTable
FROM sys.fn_xe_file_target_read_file(N’RestoreDatabase*.xel’, null, null, null);

SELECT * FROM #eeTable

SELECT
ts = event_data.value(N'(event/@timestamp)[1]’, N’datetime’),
[StepDescription] = event_data.value(N'(event/date[@name=”trace_message”]/value)[1]’, N’nvarchar(max)’)
FROM #eeTable
ORDER BY ts

DROP TABLE #eeTable

 

Thanks for stopping by my blog!!!

 

Extended Events Session Filters in SSMS

Recently during a demo at a SQL Saturday the query to pull the Extended Event session data, didn’t return the expected results. The session I used for the demo was the create database statement.

Prior to the session, I deleted the Create Database session, however did not delete the target files because they are part of the demo.  Then I recreated the session, just as I had done before.  However, this time was there was a difference when I attempted to read the target data.  The entry for the newly created database was not showing up when I used the GUI, however was showing up when I read the XML.  During the session, I was not able to figure out why that was the case.

When I got home I did some more testing.  As I turns out, when I had done the same session the previous week at a different SQL Saturday, I created a filter for the data and that filter persisted, even though I had deleted the session and created it again.

So I decided to do some testing.  I made sure there were no longer any filters on the session data, then deleted the Create Database session.  Just to have a clean slate, I then restarted the SQL Server service.

Then I created two databases, test4 and test5.  As you can see below, they are both showing up when reading the event file using the GUI.

Then I added a filter to only show the test5 database by right clicking on the test5 value and then clicking, “Filter by this value”.

This resulted in only the test5 database showing in the grid.

Now that the session was up and running, I create another database, test6.   I restarted the Extended Event session to force the new database event to be written to the target.  Then I read the target again.  As you can see below, not only is test4 not showing up, but the newly created test6 is also not appearing.

I right clicked the test5 value and then to “Filter by this value”.  What I saw kind of surprised me a bit.  Below is a screenshot of what I saw, two entries for the test5 value.  This means that one had to exist before I tried to filter by the value again.

I clicked the Clear All button, and sure enough, all three databases now appear.  Just as in the image below.

What I found interesting is that the filter persists, even after deleting the session and creating it again.  Of course, deleting sessions is not a common task and recreating it with the same name and storing the target files in the same location is even less likely to happen.  However, I did find this interesting.

 

Thanks for stopping by my blog!!!!

Create Database Event – When does it fire?

Recently when presenting my Extended Event session at a SQL Saturday an attendee asked if the Create Database session I used as a demo would pick up the Tempdb that is recreated at start up. The answer is that it will not.  But this question got me thinking, what about a restore or attaching a database, would the event pick that up?

I have to admit, while I suspected that it would not pick up the TempDB creation, I was not 100% certain on whether or not the Create Database event fires on start up.  So I wanted to do a quick test and the answer is that the event does not fire when the SQL Server service is restarted.

What about when a database is attached?  When attaching a database, this event does indeed fire.  Which of course makes sense, at least to me, you are creating a new database when attaching the database files.

What about when a database is restored?  Although a restore is in reality a drop and recreate the database, it does NOT fire the Create Database event.  I tried both restoring the database with the same name and a different name and neither one was picked up by the Create Database event.

Thanks for visiting my blog!!!

 

Create a New Dashboard in Azure Portal

Dashboards can be used in many different products and can be very helpful for many reasons.  Azure has a default dashboard, but it allows you to create your own dashboards to easily get the information that is important to you.

If you look at the screenshot of an Azure portal dashboard, you can see I get quite a bit of information quickly.  In this case I can see three reports on activity for my subscription, a list of my resources and the current cost.

To get to the dashboard you need to click the “Dashboard” menu item on the portal menu on the left side of the screen.  Now that we are at the “Main” dashboard we can either leave it or edit it.

When you look at the dashboard the first time, you will see the default dashboard. An example of this is in the image below.

Create A New Dashboard

If the default dashboard does not meet my needs, Azure provides an option to create your own. To create a new dashboard, simply click “New Dashboard” on the menu that appeared at the top of the screen.

Once you click on “New Dashboard” you will see an empty dashboard as below.

The first item you should consider changing is the title.  Of course this should reflect what the dashboard is to display.

Add items to a Dashboard

Now we are at the point we need to add the tiles that will display the information you are looking for. On the left side you will see the “Tile Gallery”.  These are some of the items you can add to your dashboard.

To add the item you can either drag\drop the item to the dashboard or you can click the “Add” item to the right of the tile title.

When you click the “Add” item, Azure will place the tile in the next available location.  Azure will add the tile to the right of the tile in the top row.  In the image below, I added four items and Azure kept adding them to the right.  With the exception of the “User Sign-ins”.  Because the clock and the “User Sign=ins” are not as tall as the others, Azure placed the “User Sign-ins” under the clock.  However, with most of the tiles they will be placed to the right of the last tile on the top row.

Another method of adding tiles is to drag and drop the tiles from the Tile Gallery.  When you use this method, Azure will place a shadow outline on the screen that will show you where the tile will be placed, similar to the image below.

Once I have added the item I can change the size if the default size is not what I am looking for.  In the upper right corner of the tile you will see a garbage can and a box with three dots when you float your cursor over this area.  To change the size, click the box with three dots and a size context menu will appear.  You can then pick the size you would like for the tile.

Now that we have added a few tiles and have everything we need.  We can now click “Done Customizing” at the top of the screen.  When you do Azure will take you to your dashboard.

Change Dashboards

Now that we have added a dashboard, we should have two, the one we created and the default dashboard.  To change what dashboard you are viewing, you click the drop down and pick the dashboard you would like to view from the menu.

 

Edit an Existing Dashboard

If you have an existing dashboard you would like to edit, simply navigate to the dashboard and click “Edit” menu item on the menu across the top.

Now you can add tiles, removed tiles, resize tiles and change the order and placement of the tiles.

Add Metrics Reports

In a previous blog post, I talked about how to create a metrics report.  In this same blog I mention how to add a metrics report to a dashboard.  Here is the link to that post.

 

Thanks for visiting my blog!!!

 

 

Azure Storage Explorer Lock

In the Azure Storage Explorer, you are able to view files that you have stored in your Azure storage account. As you can see by the image below, it looks very much like the Windows file explorer.

Of course you have the file name, last modified date, type, size as well as a few other bits of information.  You also can see the little lock that is to the left of the second file.  This tells that there is a “lease” on this file.

According to Microsoft this is the definition of a lease:

“manages a lock on a blob for write and delete operations. “

This is pretty much the same as a lock on the file in Windows.  By having the lease, there are some limitations on what you can do with the file, like delete it.  If you try to delete a file in Azure Storage Explorer you will see this error and you will not be able to delete it until the lease is removed.

In this case I am using an Extended Event target as the file.

Here is another nice post on the leases of blog files. It is an older post on Red-Gates Simple Talk site, however I think much of it is still relevant today.

If you are using Azure Storage accounts and do not have the Azure Storage Explorer, I would recommend that you download it and take a look at it.  It could make life a bit easier.  Here is the link to download it.

Thanks for stopping by my blog!

Track Failed Logins with Extended Events

Many things in life have opposites.  There are stop and go, beginning and end and of course in and out.  SQL Server is not any different, you have BEGIN TRAN…COMMIT TRAN, successful login and failed login as well as a few others.  Using Extended Events there is just a login event, not a successful or failed login event.  If you look at the description of the login event this is what you will see:

Occurs when a successful connection is made to the Server. This event is fired for new connection or when connections are reused from a connection pool

Notice is states successful connections.  What if I want to use Extended Events to track failed logins. Logic would say that if there is an event for successful logins, there would be an event for failed logins.  In this case, logic would be wrong.

If you do a search for the work “fail” in the events a number of events will be returned.  Many of the are related to column store and none of them are related to failed logins, most are related to column store.

Although, when I think of Extended Events, I usually think about how I can use it to capture performance related information. However, there are somethings, like failed logins, that could be helpful as well.  Well how can I capture failed logins if there is not an event to do so.

To do this, you have to use the error_reported event and use predicates(filters) to return just failed logins.

As you can see in the above image, there are two filters we need to configure.

Severity is set to equal 14, this one is optional but might help eliminate unnecessary rows

error_number is set to equal 18456

state is set to greater than 8, this can be set to 1 as well

These combined allow you to capture failed logins. If you do a Google search on the error number you will find that the Microsoft documentation states this.

“When a connection attempt is rejected because of an authentication failure that involves a bad password or user name, a message similar to the following is returned to the client: “Login failed for user ‘<user_name>’. (Microsoft SQL Server, Error: 18456)”.”

This might have you wondering why the other predicates are needed.  Well, it is to help eliminate similar rows. If you look at the image below, the two rows that are highlighted are the same failed login event.  One has a severity of 1 and the other has a severity of 8.  The other difference is the error message. As you can see, there is just a bit more information with severity 8 than with severity 1.

Severity 1 message: Login failed for user ‘testgrant’.

Severity 8 message: “Login failed for user ‘testgrant’. Reason: Password did not match that for the login provided. [CLIENT: <local machine>]”

Just a little side note, to read the event file for Extended Events, simply right click on the target file in SQL Server Management Studio and click “View Target Data”.

 

This can be very useful information and in my opinion, might be a bit easier to query than reading the log file.  It is always nice to have options. This works for an on-prem instance of SQL Server, I have not been able to get it to work on an Azure SQL Database yet.  This could be due to the fact that in an Azure SQL Database, Extended Events are set up in the database.  I am still working on that so look for a future blog post on that.

Thanks for visiting my blog.