Handling Blocking in SQL 2005 with LOCK_TIMEOUT and TRY CATCH statements

Handing Blocking and Deadlocks in SQL Stored Procedures

We recently had an issue at night during the period in which daily banner hit/view data is transferred from the daily table to the historical table.

During this time our large website was being hammered by BOTs and users and we were getting lots of timeout errors reported due the the tables we wanted to insert our hit records into being DELETED and UPDATED causing locks.

The default lock time is -1 (unlimited) but we had set it to our default command timeout of 30 seconds.

However if the DELETE or UPDATE in the data transfer job took over 30 seconds then the competing INSERT (to insert a banner hit or view) would time out and error with a database timeout due to the Blocking process not allowing our INSERT to do its job.

We tried a number of things including:

• Ensuring all tables were covered by indexes to speed up any record retrieval

• Reducing the DELETE into small batches of 1000 or 100 at a time in a WHILE loop to reduce the length of time the LOCK was held each time.

• Ensuring any unimportant SELECT statements from these tables were using WITH (NOLOCK) to get round any locking issues.

However none of these actually helped solve the problem so in the end we rewrote our stored procedure (SQL 2005 - 2008) so that it handled the LOCK TIMEOUT error and didn't return an error.

In SQL 2005 you can make use of TRY CATCH statements which meant that we could try a certain number of times to insert our data and if it failed we could just return quickly without an error as we also used a TRANSACTION to enable us to ROLLBACK or COMMIT the transaction.

We also set the LOCK_TIMEOUT to 500 milliseconds (so x 3 = 1.5 seconds) as if the insert couldn't be done in that time frame then there was no point logging it. We could have inserted it into another table to be added to our statistics later on but that is another point.

The code is below and shows you how to trap BLOCKING errors including DEADLOCKS and handle them.

Obviously this doesn't fix anything it just "masks" the problem from the end user and reduces the number of errors due to database timeouts due to long waiting blocked processes.

CREATE PROCEDURE [dbo].[usp_net_update_banner_hit]

@BannerIds varchar(200), -- CSV of banner IDs e.g 100,101,102

@HitType char(1) = 'V', -- V = banner viewed, H = banner hit

AS

SET NOCOUNT ON

SET LOCK_TIMEOUT 500 -- set to half a second


DECLARE @Tries tinyint

-- start at 1
SELECT @Tries = 1


-- loop for 3 attempts

WHILE @Tries <= 3

  BEGIN

 BEGIN TRANSACTION

 BEGIN TRY

  -- insert our banner hits we are only going to wait half a second

  INSERT INTO tbl_BANNER_DATA
  (BannerFK, HitType, Stamp)
  SELECT  [Value], @HitType, getdate()
  FROM dbo.udf_SPLIT(@BannerIds,',') -- UDF that splits a CSV into a table variable
  WHERE [Value] > 0

  --if we are here its been successful ie no deadlock or blocking going on
  COMMIT    

  -- therefore we can leave our loop
  BREAK

 END TRY

 -- otherwise we have caught an error!
 BEGIN CATCH

  --always rollback   
  ROLLBACK

  -- Now check for Blocking errors 1222 or Deadlocks 1205 and if its a deadlock wait for a while to see if that helps

  IF ERROR_NUMBER() = 1205 OR ERROR_NUMBER() = 1222

    BEGIN

   -- if its a deadlock wait 2 seconds then try again
   IF ERROR_NUMBER() = 1205
     BEGIN

    -- wait 2 seconds to see if that helps the deadlock
    WAITFOR DELAY '00:00:02'

     END   

       -- no need to wait for anything for BLOCKING ERRORS as our LOCK_TIMEOUT is going to wait for half a second anyway
       -- and if it hasn't finished by then (500ms x 3 attempts = 1.5 seconds) there is no point waiting any longer

    END      

  -- increment and try again for 3 goes
  SELECT @Tries = @Tries + 1

  -- we carry on until we reach our limit i.e 3 attempts
  CONTINUE    

   END CATCH

  END

System Tables - sys.processes

Analyse current processes with sysprocesses

The following SQL is based on an article about the sys.processes system view on SQLServerCentral I read today and is another good example of using SQL system views and the new DMV's (Data Management Views).

I have combined some of the example code from the article into a helpful query for analysing your current processes to find long running queries that maybe causing issues with your system. Read the comments within the code for more details.

-- Using the sys.processes system table to find current process details

DECLARE @oldStats TABLE( os_thread_id int, kernel_time bigint, usermode_time bigint)

/* Insert current threads

The KPID is useful in that it helps us tie up what has been passed to the operating system to run commands and is actually working.
Although the SPID is constant throughout the life of the connection a KPID is allocated to each task that needs to be carried out.

The KPID maps back to an actual windows thread and so it is possible using performance monitor to get actual physical statistics
about a task instead of the purely logical statistics which SQL shows through the CPU column.

The KPID is the actual o/s thread id and you can use the "Thread" performance counter using "ID Thread" and "% Processor Time" to
match the thread to the actual cpu stats.
*/
INSERT INTO @oldStats
SELECT os_thread_id, kernel_time, usermode_time
FROM sys.dm_os_threads
WHERE os_thread_id IN (SELECT KPID
FROM sys.sysprocesses
WHERE kpid <> 0
 AND spid>50)

-- wait for 2 seconds
WAITFOR DELAY '0:0:2'

/* Compare previous data to our current processes to see which task are consuming
the most CPU.

If records appear with a KPID of 0 and Physical Time of NULL then it means the
O/S thread is no longer active.

Investigate processes that have high physical times, high CPU, long wait times, and blocked
*/
SELECT sp.KPID, sp.SPID, sp.CPU AS LogicalCPU
,(new.kernel_time + new.usermode_time) - (old.kernel_time + old.usermode_time) AS PhysicalTime
,waittime,lastwaittype,blocked
,blockingSQL = CASE WHEN blocked > 0 AND blocked <> sp.SPID THEN  (SELECT SUBSTRING((SELECT TEXT FROM fn_get_sql(sql_handle)), stmt_start/2,
CASE stmt_end
WHEN -1 THEN LEN(CONVERT(VARCHAR(8000), (SELECT TEXT FROM fn_get_sql(sql_handle)))) - (stmt_end/2)
WHEN 0 THEN LEN(CONVERT(VARCHAR(8000), (SELECT TEXT FROM fn_get_sql(sql_handle))))
ELSE stmt_end /2
END
) FROM sys.sysprocesses WHERE SPID = sp.blocked) ELSE NULL END
,last_batch,open_tran,sp.status,loginame,hostname,cmd
,(SELECT SUBSTRING((SELECT TEXT FROM fn_get_sql(sql_handle)), stmt_start/2,
CASE stmt_end
WHEN -1 THEN LEN(CONVERT(VARCHAR(8000), (SELECT TEXT FROM fn_get_sql(sql_handle)))) - (stmt_end/2)
WHEN 0 THEN LEN(CONVERT(VARCHAR(8000), (SELECT TEXT FROM fn_get_sql(sql_handle))))
ELSE stmt_end /2
END
) FROM sys.sysprocesses WHERE SPID = sp.SPID) as TSQL
FROM sys.sysprocesses SP
LEFT OUTER JOIN
@oldStats old
ON SP.kpid = old.os_thread_id
LEFT OUTER JOIN
sys.dm_os_threads new
ON sp.kpid = new.os_thread_id
ORDER BY PhysicalTime DESC

Store and Analyse Blocked Processes

To view your blocked processes in more detail either set up a loop with a WAITFOR DELAY or an MS Agent job that runs once a minute to log into a table the output from the following SQL. The SQL make use of a recursive CTE to link together all the processes affected by a blocking action which is useful for seeing the action that has caused the blocking and all the processes being affected by the blocking. You can view all databases on the server or filter by a particular database name or partial name.

DECLARE @DatabaseName nvarchar(255) --leave null to use current DB OR 'ALL' For all DBS
DECLARE @PROCESSES TABLE(SPID int, blockingSPID int, databaseName nvarchar(255), programName nvarchar(500), loginName nvarchar(255), ObjectName nvarchar(max), Definition nvarchar(max))
INSERT INTO @PROCESSES
SELECT s.spid, BlockingSPID = s.blocked, DatabaseName = DB_NAME(s.dbid),
s.program_name, s.loginame, ObjectName = OBJECT_NAME(objectid,s.dbid),
Definition = CAST(text AS VARCHAR(MAX))
FROM sys.sysprocesses s
CROSS APPLY
sys.dm_exec_sql_text (sql_handle)
WHERE s.spid > 50 AND
1 = CASE
WHEN @DatabaseName IS NULL AND s.dbid = db_id() THEN 1
WHEN @DatabaseName = 'ALL' THEN 1
WHEN COALESCE(@DatabaseName,'')<>'' AND DB_NAME(s.dbid) LIKE @DatabaseName  + '%' THEN 1
END


;WITH Blocking(SPID, BlockingSPID, DatabaseName, BlockingStatement, RowNo, LevelRow)
AS
(
SELECT s.SPID, s.BlockingSPID, s.DatabaseName, s.Definition,
ROW_NUMBER() OVER(ORDER BY s.SPID),
0 AS LevelRow
FROM @PROCESSES s
JOIN @PROCESSES s1 ON s.SPID = s1.BlockingSPID
WHERE s.BlockingSPID = 0
UNION ALL
SELECT r.SPID,  r.BlockingSPID, r.DatabaseName, r.Definition,
d.RowNo,
d.LevelRow + 1
FROM @PROCESSES r
JOIN Blocking d ON r.BlockingSPID = d.SPID
WHERE r.BlockingSPID > 0
)
SELECT * FROM Blocking
ORDER BY RowNo, LevelRow