Wednesday 25 November 2015

Analyzing SQL Server Error Logs / Agent Logs using T-SQL

Even though you design our SQL Scripts with the best methods using best practices, or configure the SQL Server to perform correctly and in the optimized manner, you cannot prevent things going wrong. Luckily SQL Server does a great job on logging all the issues which we will be encountering during the course. Things could have been worse if you need to go through the error log file using only a text editor like the ‘Note Pad’ application (Favorite text editor of majority people). But fortunately SQL Server had provided us some help when you need to dig deep into Error Log.

image

But things could get more complicated if the Error Log contains lots of records and in those records if you require to swim for the issue which you are looking for.

image

Even though it provides you some searching and filtering capabilities, it could still be very challenging and time consuming.

image

image

However we do have another workaround which might come in handy. That’s to query the Error Logs using T-SQL. This can be done using the system procedure ‘sys.sp_readerrorlog’. This consists with few parameters.
USE [master]
GO
/****** Object:  StoredProcedure [sys].[sp_readerrorlog]    Script Date: 24/11/2015 7:11:36 PM ******/
SET ANSI_NULLS ON
GO
SET QUOTED_IDENTIFIER OFF
GO
ALTER proc [sys].[sp_readerrorlog](
    @p1        int = 0,
    @p2        int = NULL,
    @p3        nvarchar(4000) = NULL,
    @p4        nvarchar(4000) = NULL)
as
begin

    if (not is_srvrolemember(N'securityadmin') = 1)
    begin
       raiserror(15003,-1,-1, N'securityadmin')
       return (1)
    end
    
    if (@p2 is NULL)
        exec sys.xp_readerrorlog @p1
    else 
        exec sys.xp_readerrorlog @p1,@p2,@p3,@p4   
end



  1. @p1 –> This represents the error log which you need to inspect (0 ~ Current | 1 ~ Archive #1 etc..)
  2. @p2 –> Type of the error log which you want to inspect (NULL or 1 ~ Error Log | 2 ~ SQL Agent Log)
  3. @p3 –> 1st Search Parameter (A value which you want to search the contents for)
  4. @p4 –> 2nd Search Parameter (A value which you want to search to further refine the result set)

**Please note: Aforementioned parameters are optional. Therefore if you don’t provide any parameters, it will return the whole contents of the current/active Error Log.

Few Examples

1. This will return all entries in the current Error Log
EXEC sys.xp_readerrorlog @p1 = 0


2. This will return all the entries in the current SQL Agent Log
EXEC sys.xp_readerrorlog @p1 = 0, @p2 = 2


3. This will return all the entries in the current SQL Error log where ever the value ‘CLR’ consist.
EXEC sys.sp_readerrorlog @p1=0, @p2=1, @p3='CLR'


image


4. This will return the entries in the current SQL Error log when the value ‘CLR’ and ‘Framework’ exist.
EXEC sys.sp_readerrorlog @p1=0, @p2=1, @p3='CLR', @p4='Framework'


image

When we execute the stored procedure ‘sys.sp_readerrorlog’, inside it will call an extended stored procedure which will accept 7 parameters, which is  ‘sys.xp_readerrorlog’. The parameter details are as follows:

Param #ParameterDetails
1Log Number0 – Current / 1 – Archive #1 / 2 – Archive #2 etc…
2Log Type1 – SQL Error Log / 2 – SQL Agent Log
3Search Text 1Search term which will be searched on the Text column
4Search Text 2Search term which will be searched on the Text column. **If both search texts are supplied it will return rows containing both texts.
5Start DateLog entries which the ‘Log Date’ is newer than the date provided. (including the date provided)
6End DateLog entries which is between the Start Date and End Date
7Sort OrderASC – Ascending / DESC - Descending

Eg:

EXEC sys.xp_readerrorlog 0,1,N'',N'', '20151124','20151125','DESC'    


I hope this information will help you when you need to query the Error Log in order to troubleshoot an issue.

Sunday 22 November 2015

Enabling Instant File Initialization in SQL Server

Technorati Tags:

Every time the SQL data file or log file expands, it fills the newly allocated (expanded) space with zero. There are few good and bad having this feature (Zeroing the allocated space). One downside of this is, this process will block all the sessions which are writing to these files (data and log files), during this initialization period. One might debate this time period will be very small, but it could be an extremely critical one for some process.

However enabling the Instant File Initialization behavior will make sure that the aforementioned issue will not have any effects when SQL Data file is expanded. But there will be a security risk enabling this feature. When this is enabled, it could be a possibility that unallocated part of the SQL data file could contain information related to previously deleted files (OS related information). There are tools which can examine this data and people who will be having access to the data file (most probably DB Administrators) can easily see the underlying data of these unallocated areas.

Before enabling this we will check how SQL will behave with this option disabled:

DBCC TRACEON(3004,3605,-1)
GO

CREATE DATABASE Sample_Database
GO

EXEC sys.sp_readerrorlog
GO

DROP DATABASE Sample_Database
GO

DBCC TRACEOFF(3004,3605,-1)
GO


 


image


You can clearly see that SQL had an operation to zero out both data and the log file. (I have only highlighted the data file [.mdf])


Enabling Instant File Initialization can be done by adding a ‘SA_MANAGE_VOLUME_NAME’ permission (also know as ‘Perform Volume Maintenance Task’) to the SQL Server Startup account. This can be done as follows:


Open the Local Security Policy Management Application. (execute secpol.msc from the run command or from command line). Double click on the ‘Perform Volume Maintenance Tasks’ which can be found In Security Settings –> Local Policies –> User Rights Assignment.


image 


And add the SQL Server start up account to the list.


image


 


SQL Server startup account can be found in ‘Log On’ Tab in ‘SQL Server <Instance>’ in the Services.


image


 


*** Please note: SQL will check whether this feature is enabled or disable during start up. Therefore we need to restart the service once it’s enabled or disabled. Also we can only enable this for SQL data files only. We cannot enable this for log files.


After restarting the SQL Service we will execute the code snippet which we executed earlier. You will be able to see that SQL is only zeroing the log file now.


image

Thursday 19 November 2015

Capturing and Analyzing deadlocks in SQL Server

No matter how perfect your code and how optimized the way you have written is, facing a situation of getting a deadlock is inevitable. And it would make the situation even more complex when you know that a deadlock had occurred but you have no clue which the victim and perpetrator was.

There are few ways to capture and analyze a deadlock. I will explain two ways in this post.

  1. Enabling trace flags to capture/log deadlock information into SQL Log
  2. Use SQL Profiler to capture a deadlock.

 

Enabling trace flags to capture/log deadlock information into SQL Log

This method will make sure that the deadlock details are logged in the SQL log file (not the transaction log). Even though the details which are captured via this method is textual  it gives you the option of inspecting the details at a later time.

First you need to enable the trace flags using the following syntax:

DBCC TRACEON (1222, 1204, -1)


 

Afterwards we will simulate a deadlock : (in reality you don’t need to do this if you are facing such issue)

First create two sample tables and insert few records which we will use to produce a deadlock.


-- Create a Sample Tables --

CREATE TABLE SampleDeadLock_1(
Item_Code INT
,Item_Desc VARCHAR(100)
,Qty INT
)

CREATE TABLE SampleDeadLock_2(
Item_Code INT
,Item_Desc VARCHAR(100)
,Qty INT
)

-- Insert couple of records to each table --

INSERT INTO dbo.SampleDeadLock_1(
Item_Code
,Item_Desc
,Qty
)
VALUES
(1,'CPU', 10)
,(2, '20 GB - Hard Disk', 20)

INSERT INTO dbo.SampleDeadLock_2(
Item_Code
,Item_Desc
,Qty
)
VALUES
(3,'Monitor', 15)
,(4, 'Keyboard & MOuse', 25)


 


Now open two query windows in SQL Server Management Studio (Window 1 & Window 2) and paste the following code to ‘Window 1’


BEGIN TRAN

UPDATE dbo.SampleDeadLock_1 SET Qty = 100 WHERE Item_Code = 1

WAITFOR DELAY '00:00:30'

UPDATE dbo.SampleDeadLock_2 SET Qty = 200 WHERE Item_Code = 3


And paste the following code to ‘Window 2’


BEGIN TRAN

WAITFOR DELAY '00:00:10'

UPDATE dbo.SampleDeadLock_2 SET Qty = 300 WHERE Item_Code = 3
UPDATE dbo.SampleDeadLock_1 SET Qty = 400 WHERE Item_Code = 1


 


Afterwards execute the code in Window 1 and immediately execute the code in Window 2. After few seconds (30+) you will see a deadlock error message in Window 1.


image


And when you checked on the ERRORLOG file, you will be able to find out the relevant details which relates to the deadlock. (I have highlighted the deadlock victim details in Red and the perpetrator details in blue)


image


 


Using SQL Profiler to capture a deadlock (Deadlock Graph)


One of the issues we have in the aforementioned method is that we need to look into lots of textual information in order to extract the details which is relevant for the deadlock. In this example it’s somewhat easier since we had chosen a simple situation. But things could get real hard during an actual situation where the processes are bit complex.


In such case (any case), we can use the SQL Profiler to detect the deadlock in a more user friendly manner.


** Please Note: Down-side of this method is you need to have the profiler running during the time that the deadlock had occurred. And this isn’t the best way if you need to troubleshoot in a Production Environment.


How ever for the sake of understanding we will see how we can achieve this.


Open the SQL Profiler and connect to the relevant SQL Server. And in the ‘Trace Properties’ window choose ‘TSQL_Locks’ as the template.


image


And in the ‘Event Selection’ tab, please choose the following options.



  • Deadlock graph
  • Lock:Deadlock
  • Lock:Deadlock Chain

image


Before click on running the profiler, Rollback the transaction which is running from the first example (The one which didn’t become the Deadlock Victim)


Start the profiler by clicking the ‘Run’ button. And once the profiler is running, execute the code on Query Window 1 and afterwards execute the code in Query Window 2.


Once the deadlock occurs the Profiler will display the relevant information in a graphical manner. This will contain all the relevant details which is required in order to troubleshoot the deadlock. And if you hover the cursor over the processes in the graph (shown in ellipses) a tooltip will be displayed along with the statement which has been executed, which caused the deadlock to occur.


image


I hope this will help you in order to troubleshoot a deadlock situation.