This is the problem a software developer in my started facing, intermittently, in the database. Execution Timeout Expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
I started looking at the exception, but nothing really stood up. Except for the Stored Procedure that was taking more than 30 seconds to run. So, I went to the database server and executed that stored procedure with the parameters that were causing the issue.
After cleaning the cache with DBCC FREEPROCCACHE, The stored procedure was taking less than a second. Logical reads were not bad either since We were getting than 100 for logical-reads.
Another day went by and the same issue happened again, but this time a different stored procedure was the problem. When we tried that procedure by itself in the database server, it was completely fine.
Execution plan for both were reasonable. There were no warnings and indexes were being used properly. So, the next step was to go to SQL profiler and set up a trace for locks.
Locks were the only thing I could think of at that time. So, I set that up and waited. Since, the problem was intermittent, I would have to hope to see that issue coming as soon as possible.
I did not want to have the trace running forever, but here I was waiting on this hint from the trace that never came after couple of days. Have you ever notice that when you put a gossip solution in place, the machines start working just fine. So, for the next 2 days nothing happened and the trace was there and I did not want to have this trace running any longer. Neither did I want to be monitoring this machine until something happens.
So, instead of working for the machine, I decided to make it work for me. In this article, I will show you how I used the service-broker feature in Microsoft SQL Server to tell me when a lock happened, who cause the lock and whos was locked. I will also show how to make the system send me an email using Database Mail, as soon as the lock is happening.
The objects used in this demonstration are EVENT NOTICE, SERVICE, QUEUE, PROCEDURE and TRIGGER. I will use CONTRACT and MESSAGE TYPE already specified by the system, so no need to create them.
Configuring the database server
I will be doing this in my local machine. For that purpose, I created a table called Lock and inserted 1 single row.
To be able to test it, I will need to lock this table I just created and make sure that once I do that, my solution works. Ready? Come with me!
First, we will set SQL SERVER to configuration mode.
sp_configure 'show advanced options', 1 GO RECONFIGURE GO sp_configure 'Blocked process threshold', 6 GO RECONFIGURE GO
By default, no blocked process reports are produced. These server configuration can be from 5 to 86,400. This number represents seconds. it means that it will check every period of time specified to see if a lock is happening. We can set to less than 5 seconds, however, no responses, will be produced.
Checking on SQL SERVER Profiler
Choose the number that makes sense for your system. For testing purposes, I chose 6. Once we did that, we can now configure in SQL Server Profiler to make sure it captures those locks every 6 seconds. To configure that, let’s do this. Open the profiler and click on File-> New trace ->Connect (Whatever server you will test this)-> Event Selection tab -> Errors and Warnings -> Blocked process report -> Run
Let’s purposely create a lock. In one session run this script, based on the table you want to lock. If you create a table called Lock, you can just run the script below, otherwise change it appropriately.
BEGIN TRANSACTION UPDATE l SET LockName = 'Row Locking Everthin' FROM Lock l WITH (TABLOCK) WHERE id = 1
Notice that I missed the COMMIT statement on purpose. I also used the hint TABLOCK to ensure the lock is in place. This table is now locked.
In a different session, let execute another query.
SELECT * FROM Lock
Look at the messages coming to the trace
It looks like SQL Server can see that. We are now, eternally grateful for that SQL Profiler. However, I am lazy and I want more from the server. I want it to tell when it happened WHNEVER IT HAPPENS! No time for babysitting the profiler.
In the same session where we ran the update, let’s commit so we can release that lock.
COMMIT
Let’s stop the trace and get this script going!
I already mentioned above the objects we will create to make this happen. But here is how we want to structure this and how these objects will behave among each other.
How will it work?
EVENT NOTIFICATION is a predefined MESSAGE TYPE. Hence, we don’t need to create a MESSAGE TYPE in this case. This event object, will send information about events to a Service Broker service.
SERVICE will receive this information from the EVENT NOTIFICATION and based on a CONTRACT, in this case, the CONTRACT is already predefined, it will transmit that information to a QUEUE.
Think of a QUEUE just like a table waiting for information from the service. The QUEUE will specify a listener, in this case a Sored Procedure, so that, every time a message comes from the SERVICE to the QUEUE, the PROCEDURE, will be executed and will get the information from the QUEUE and insert into a table.
I will call that the first part of a process with parts. This part alone, may be enough for you, if you want to check that table everyday and see if any lock happen lately.
But again, we are lazy, right? Let’s have that information there, but also have the server to tell me at the time it happens by sending me an email.
The second part of the process will be to create wo more objects.
The first object will be a PROCEDURE that will send me an email.
The second object will be an after_insert TRIGGER on the table that will be inserted when the PROCEDURE in the listening to QUEUE gets called.
The Objects
I will call ,the table holding QUEUE messages, MonitorEventLockInformation.
CREATE TABLE MonitorEventLockInformation ( Id BIGINT IDENTITY(1,1), MessageBody XML, DatabaseID INT, Process XML )
I will call the PROCEDURE listening to the QUEUE spProductionMonitorService.
CREATE OR ALTER PROCEDURE spProductionMonitorService AS BEGIN DECLARE @message TABLE ( message_body XML NOT NULL, message_sequence_number INT NOT NULL );RECEIVE message_body, message_sequence_number
FROM LockQueue
INTO @message;
INSERT INTO Utility.MonitorEventLockInformation(MessageBody,DatabaseID,Process)
SELECT message_body,
DatabaseId = CAST( message_body AS XML ).value( '(/EVENT_INSTANCE/DatabaseID)[1]', 'int' ),
Process = CAST( message_body AS XML ).query( '/EVENT_INSTANCE/TextData/blocked-process-report/blocked-process/process' )
FROM @message
ORDER BY message_sequence_number
END
Pay attention on the keyword RECEIVE. This is where the magic happens. It is how the stored procedure capture information from the QUEUE.
Let’s now create the QUEUE. I will name it LockQueue.
CREATE QUEUE LockQueue WITH STATUS = ON, RETENTION = OFF, ACTIVATION ( STATUS = ON, PROCEDURE_NAME = spProductionMonitorService, MAX_QUEUE_READERS = 10, EXECUTE AS SELF )
There are a lot talk about here, but I want to focus on one thing only the PROCEDURE_NAME attribute. This is how the stored procedure gets called.
lets create the SERVICE. I will name it LockService.
CREATE SERVICE LockService ON QUEUE LockQueue ( [http://schemas.microsoft.com/SQL/Notifications/PostEventNotification] )
This is the CONTRACT I am specifying.
[http://schemas.microsoft.com/SQL/Notifications/PostEventNotification]. It is predefined so no need to do anything else.
Finally, we will create EVENT NOTIFICATION.
CREATE EVENT NOTIFICATION NotifyLocks ON SERVER WITH fan_in FOR blocked_process_report TO SERVICE 'LockService', 'current database';
There we go, we are done! Wait, not so fast is service broker enabled? Let’s check by executing this query:
SELECT is_broker_enabled FROM sys.databases WHERE NAME= (SELECT DB_NAME())
If we get 0 then we must enable by running this.
ALTER DATABASE YourDatabase SET ENABLE_BROKER WITH ROLLBACK IMMEDIATE;
If we are running this in production, make sure you understand that ROLLBACK WITH IMMEDIATE will kick every single process out. CAUTION!!!
Once we are done with this first part, we can again cause a lock, using same script we used previously.
Go back to the session with the UPDATE and execute this:
BEGIN TRANSACTION UPDATE l SET LockName = 'Row Locking Everthin' FROM Lock l WITH (TABLOCK) WHERE id = 1
In another session execute this:
SELECT * FROM Lock
After 6 seconds and in a different session try this.
SELECT * FROM MonitorEventLockInformation
Congratulations!!! it worked. Well, congratulations for some of us because for others, maybe, it did not work just yet. This is when we should check SQL Server Logs.
On my side I found this error:
The activated proc ‘[dbo].[spProductionMonitorService]’ running on queue ‘Practice.dbo.LockQueue’ output the following: ‘Could not obtain information about Windows NT group/user ‘username’, error code 0x54b.’
I am running this with Windows Authentication and if you are too, you will get this error. In production, there was an actual login that had same issue. If that is the case, make sure you add that user to the group.
If everything worked fine for you, then you are done with first part, If not, then do this. Either way, run COMMIT where the TRANSACTION is hanging to make sure the lock is released.
If you see this error, you have two paths to take:
- Check this article on how to solve user issues.
- Assign ‘sa’ as the dbowner of this database
The second ne is much easier for testing purposes, so, why not? Let’s see who is the current dbowner.
SELECT suser_sname(owner_sid) FROM sys.databases WHERE NAME = 'Practice'
We saw this as expected!
We changed the owner to sa
EXEC sp_changedbowner 'sa'
Execute this again
SELECT suser_sname(owner_sid) FROM sys.databases WHERE NAME = 'Practice'
No we see this
Let’s try this again. In one session execute this.
BEGIN TRANSACTION UPDATE l SET LockName = 'Row Locking Everthin' FROM Lock l WITH (TABLOCK) WHERE id = 1
In a diferent session execute this.
SELECT * FROM Lock
After 6 seconds and in a different session, try this again.
SELECT * FROM MonitorEventLockInformation
You should see something like this.
The QUEUE is up and running. You can come anytime to this table and see who is causing the issue. The format, as you saw when the table was created is XML. Later on this article we will write something more readable.
What I am looking for now is to get SQL server to send me an email letting me know as soon as this lock takes place. Make sure that before you proceed you release your lock by running COMMIT again on the session with the opened transaction.
Sending emails
To be able to send email using DatabaseMail, we need to configure first.
Let’s open configuration mode again and make sure we set Database Mail XPs to 1.
Execute this.
sp_configure 'show advanced options', 1 GO RECONFIGURE GO sp_configure 'Database Mail XPs', 1 GO RECONFIGURE GO
We will also need an email server. You can use any of your choice. For testing purposes, I tried using Gmail, but I could not get it to work. For the purpose of this test I am using SMTP2GO. It is free for up to 1000 emails per month. There is a limit of 25 per hour as well. So when testing, I would advise to increase the lock time to make sure you do not run out of emails within an hour. Other than that it works perfectly for what I need.
Let’s configure Database Mail. Go to Management -> Database Mail. Rigth click and click on Configure Database Mail.
This will pop up.
Click Next
Click Next and give name to Profile name. In this case I just named TestUser
Click the add button and we will see this next screen. I already have an account name in place, that is why I see mrivanlima. If you don’t have an account name, nothing will be there, as expected!
Click on New Account
Insert the information based on the email server you have.
Click OK
Check mark public and click Next
This profile is ready to go
Let’s try to send an email using sp_send_dbmail to an email that we have acces. Use this command based on the @profile_name you just created.
EXEC msdb.dbo.sp_send_dbmail @profile_name='TestUser', @recipients='junk@misterivanlima.com', @subject='Test message', @body= 'it worked!'
If you see this message, is because it worked. Funny enough, the Database Mail uses the service broker to QUEUE.
Checking my junk email.
Now that we know that QUEUE is working and that the Database Mail is also working, we just need to create the PROCEDURE to send the email and the TRIGGER.
I will call my PROCEDURE spSendEmail.
CREATE OR ALTER PROCEDURE spSendEmail @BlockedCommand VARCHAR(MAX), @BlockingCommand VARCHAR(MAX) AS BEGIN DECLARE @message VARCHAR(MAX) = 'Command ' + @BlockedCommand + ' is blocking ' + @BlockingCommand; EXEC msdb.dbo.sp_send_dbmail @profile_name='TestUser', @recipients='junk@misterivanlima.com', @subject='Locking alert', @body= @message END
I will call my TRIGGER TriggerLockingEmailAlert
CREATE OR ALTER TRIGGER TriggerLockingEmailAlert ON dbo.MonitorEventLockInformation AFTER INSERT AS BEGIN DECLARE @BlockedCommand VARCHAR(MAX); DECLARE @BlockingCommand VARCHAR(MAX); SELECT @BlockedCommand = MessageBody.value( '(/EVENT_INSTANCE/TextData/blocked-process-report/blocked-process/process)[1]', 'varchar(max)' ), @BlockingCommand = MessageBody.value( '(/EVENT_INSTANCE/TextData/blocked-process-report/blocking-process/process)[1]', 'varchar(max)' ) FROM inserted EXEC spSendEmail @BlockedCommand = @BlockedCommand, @BlockingCommand = @BlockingCommand END
Let’s test it again. Let’s run the UPDATE command, as we did it previously without COMMIT. Run the SELECT statement as well on a different session.
AND JUST LIKE MAGIC, IT DID NOT WORK! DANG IT!
Let’s go back to the SQL SERVER logs and see what is going on. If it did not work, you probably got something like this.
The activated proc ‘[dbo].[spProductionMonitorService]’ running on queue ‘Practice.dbo.LockQueue’ output the following: ‘The EXECUTE permission was denied on the object ‘sp_send_dbmail’, database ‘msdb’, schema ‘dbo’.’
Thanks goodness this is an easy fix. You just need to grant EXECUTE to that msdb stored procedure. For testing purposes, I am granting that stored procedure to public. In production, you will have to think better who to GRANT it to.
Run this.
USE msdb GRANT EXECUTE ON msdb.dbo.sp_send_dbmail TO [public]
Let’s run it again.
Voila!!!!!
This time we got it!
Let me know if it worked for you! If it did not work, let me know what errors you are getting.
Want to use this code? Copy from Github
Great article! I found your perspective on this topic both enlightening and thought-provoking. The way you break down complex ideas into understandable insights is truly commendable. It’s interesting to see how these developments could shape our future. I’m particularly intrigued by your point about potential challenges and would love to dive deeper into that.
For those who are interested in exploring this topic further, I recommend checking out this resource for more detailed information: comprehensive guide. It offers additional insights that complement what’s discussed here.
Looking forward to hearing others’ thoughts and continuing this discussion. Thanks for sharing such valuable information!