SQL Server Service Broker: a small change in the activation procedure can spike CPU usage and why benchmarking matters

-

In this post, I will demonstrate how a small change in Service Broker code can significantly increase CPU usage. This post may be helpful for those troubleshooting high CPU consumption related to Service Broker if their case is similar to mine. 

CPU before and after the bug in Service Broker got fixed


However, the main purpose of the post is to highlight that even when following Microsoft's documentation to setup some database feature, things can still go wrong. This is why benchmarking and testing are crucial steps before deploying new features to your production system.


Additionally, it is interesting to see that a small change in the code can completely alter the service broker behavior. If you'd like, you can code along with me and see the results for yourself, provided you have SQL Server installed.


Architecture

The service broker setup I will use is as follows:

  • There are two services and two corresponding queues and their activation procedures: the initiator and the target
  • A conversation sends a message from the initiator to the target
  • Whenever the initiator or the target receive a message, we log a record
  • This setup involves a 5 second conversation timer. As timeout occurs, the initiator receives a dialog timer message and both sides end the conversation.

Code demonstration (what works)

Create a database

First, let's create a database dedicated for our demo and enable Query Store to capture some performance data.


  -- Create a database
  CREATE DATABASE ServiceBrokerDemo
  GO

  -- Enable Query Store
  ALTER DATABASE ServiceBrokerDemo SET QUERY_STORE (OPERATION_MODE = READ_WRITE)  
  GO

Create a log table

We will create a log table to record messages sent to each side of the conversation:


  USE ServiceBrokerDemo
  GO 
  
  DROP TABLE IF EXISTS DemoServiceBrokerLog;
  CREATE TABLE DemoServiceBrokerLog (
      ID INT IDENTITY(1,1) PRIMARY KEY,
      Date DATETIME,
      MessageTypeName sysname,
      ActivationFunction sysname, 
      MessageBody xml
  );

Create message queues


  USE ServiceBrokerDemo
  GO

  CREATE QUEUE dbo.InitiatorQueue WITH STATUS=ON ON [PRIMARY]
  GO

  CREATE QUEUE dbo.TargetQueue WITH STATUS=ON ON [PRIMARY]
  GO

Create activation procedures

The following procedure is activated when messages arrive at the target queue. It logs messages and performs tasks, handling 'endofconversation' and 'message' types:

Notice the while loop, it is used so the broker won't reactivate the procedure every time new message arrives. If there is no message being dequeued (@@ROWCOUNT=0), break from the loop and end the execution of the procedure.

CREATE OR ALTER PROCEDURE [dbo].[TargetQueueProcess]
AS
BEGIN
	SET NOCOUNT ON;
 
	DECLARE @conversationHandle UNIQUEIDENTIFIER
	DECLARE @messagetypename NVARCHAR(256)
	DECLARE @messagebody XML
 
	DECLARE @errorNumber AS int;
	DECLARE @errorMessage AS nvarchar(3000);
 
	WHILE (1=1)
	BEGIN
		;RECEIVE TOP(1) @conversationHandle = conversation_handle
			 , @messagetypename = message_type_name
			 , @messagebody = message_body
		  FROM [dbo].[TargetQueue]
		IF (@@ROWCOUNT=0)
		BEGIN
			BREAK
		END
 
		IF @conversationHandle IS NOT NULL
		BEGIN
			-- Log
			INSERT INTO DemoServiceBrokerLog VALUES (
						getdate(),
						@messageTypeName,
						'TargetQueueProcess', 
						@messagebody
				);
 
 
			IF @messageTypeName = 'http://my.dba.aventure/dbo/DemoServiceBroker/endofconversation' 
			BEGIN
				-- End the conversation 
				-- The initiator will receive an EndDialog message afterwards
				END CONVERSATION @conversationHandle;
			END
			ELSE IF @messageTypeName = 'http://my.dba.aventure/dbo/DemoServiceBroker/message' 
			BEGIN
				BEGIN TRY 
					-- Process the message
					PRINT ('Do the actual task in here')
				END TRY 
				BEGIN CATCH 
					-- Capture the error
					SELECT @errorNumber = ERROR_NUMBER()
					, @errorMessage = ERROR_MESSAGE()
 
					-- End the conversation with an error
					-- The initiator will receive an Error message afterwards
					END CONVERSATION @conversationHandle WITH ERROR = @errorNumber DESCRIPTION = @errorMessage;
				END CATCH 
			END
		END
	END
END
GO

Similarly, the initiator queue process handles "dialogtimer", "enddialog", and "error" messages sent to the initiator queue:

USE ServiceBrokerDemo
GO
CREATE OR ALTER PROCEDURE [dbo].[InitiatorQueueProcess]
AS
BEGIN
	SET NOCOUNT ON;
 
	DECLARE @conversationHandle UNIQUEIDENTIFIER
	DECLARE @messageTypeName SYSNAME
	DECLARE @messagebody XML
 
	DECLARE @errorCode int;
	DECLARE @errorMessage nvarchar(3000);
 
	;RECEIVE TOP(1) @conversationHandle = conversation_handle
		, @messageTypeName = message_type_name
		, @messagebody = message_body 
	FROM [dbo].[InitiatorQueue]
 
	IF @conversationHandle IS NOT NULL
	BEGIN
		INSERT INTO DemoServiceBrokerLog VALUES (
						getdate(),
						@messageTypeName,
						'InitiatorQueueProcess', 
						@messagebody
		)
 
	    IF @messageTypeName = 'http://schemas.microsoft.com/SQL/ServiceBroker/DialogTimer' 
	    BEGIN
		;SEND ON CONVERSATION @conversationHandle MESSAGE TYPE [http://my.dba.aventure/dbo/DemoServiceBroker/endofconversation];
	    END
	    ELSE IF @messageTypeName = 'http://schemas.microsoft.com/SQL/ServiceBroker/EndDialog' 
	    BEGIN
		END CONVERSATION @conversationHandle;
	    END
	    ELSE IF @messageTypeName = 'http://schemas.microsoft.com/SQL/ServiceBroker/Error'
	    BEGIN 
		-- Log the error before ending the conversation
		SET @errorCode = 
				(SELECT @messagebody.value(
				N'declare namespace 
				brokerns="http://schemas.microsoft.com/SQL/ServiceBroker/Error"; 
				(/brokerns:Error/brokerns:Code)[1]', 'int'));
 
		SET @errorMessage = (SELECT @messagebody.value(
				'declare namespace
				brokerns="http://schemas.microsoft.com/SQL/ServiceBroker/Error";
				(/brokerns:Error/brokerns:Description)[1]', 'nvarchar(3000)'));
 
		-- do something with the error 
		PRINT('log the errors to some table')
 
		-- End conversation on the initiator side
		END CONVERSATION @conversationHandle;	
	    END
	END
END
GO

Then we associate the two queues to the two newly created activation procedures:

  USE ServiceBrokerDemo
  GO
  ALTER QUEUE dbo.TargetQueue WITH STATUS = ON, RETENTION = OFF, ACTIVATION (STATUS = ON, PROCEDURE_NAME = dbo.TargetQueueProcess, MAX_QUEUE_READERS = 1, EXECUTE AS SELF) , POISON_MESSAGE_HANDLING (STATUS = OFF) 
  GO 
  ALTER QUEUE dbo.InitiatorQueue WITH STATUS = ON, RETENTION = OFF, ACTIVATION (STATUS = ON, PROCEDURE_NAME = dbo.InitiatorQueueProcess, MAX_QUEUE_READERS = 1, EXECUTE AS SELF) , POISON_MESSAGE_HANDLING (STATUS = OFF) 
  GO

Create custom message types for our application:

  CREATE MESSAGE TYPE [http://my.dba.aventure/dbo/DemoServiceBroker/message]
  CREATE MESSAGE TYPE [http://my.dba.aventure/dbo/DemoServiceBroker/endofconversation]

Create contracts

  CREATE CONTRACT [http://my.dba.aventure/dbo/DemoServiceBroker/contract] 
  (
      [http://my.dba.aventure/dbo/DemoServiceBroker/message] SENT BY INITIATOR, 
      [http://my.dba.aventure/dbo/DemoServiceBroker/endofconversation] SENT BY INITIATOR
  )

Create services corresponding to the two queues

CREATE SERVICE [http://my.dba.aventure/dbo/DemoServiceBroker/InitiatorService] 
ON QUEUE [dbo].[InitiatorQueue]	([http://my.dba.aventure/dbo/DemoServiceBroker/contract])

CREATE SERVICE [http://my.dba.aventure/dbo/DemoServiceBroker/TargetService] 
ON QUEUE [dbo].[TargetQueue] ([http://my.dba.aventure/dbo/DemoServiceBroker/contract])

Start a conversation and send a message from the initiator to the target

USE ServiceBrokerDemo;
 
DECLARE @conversationHandle UNIQUEIDENTIFIER
DECLARE @fromService SYSNAME = 'http://my.dba.aventure/dbo/DemoServiceBroker/InitiatorService'
DECLARE @toService SYSNAME = 'http://my.dba.aventure/dbo/DemoServiceBroker/TargetService'
DECLARE @contract SYSNAME = 'http://my.dba.aventure/dbo/DemoServiceBroker/contract'
 
-- Craft a contrived message body
DECLARE @messageBody XML = '<messagebody><msg>some message</msg></messagebody>'
 
 
BEGIN DIALOG CONVERSATION @conversationHandle
FROM SERVICE @fromService
TO SERVICE @toService
ON CONTRACT @contract
WITH ENCRYPTION = OFF;
 
BEGIN CONVERSATION TIMER (@conversationHandle) TIMEOUT = 5
 
;SEND ON CONVERSATION @conversationHandle
	MESSAGE TYPE [http://my.dba.aventure/dbo/DemoServiceBroker/message] 
	(@messageBody)

Check the log table

  SELECT * FROM DemoServiceBrokerLog

The result shows all messages sent and received by the initiator and the target. 

The messages sent to the initiator and the target through the conversation - SQL query result

Check the queues' status and their activated tasks

After 5 second conversation, the queues' status should be INACTIVE and there should be no activated procedures:

  SELECT * FROM sys.dm_broker_activated_tasks;
 
  SELECT *
  FROM sys.dm_broker_queue_monitors AS m
  INNER JOIN sys.service_queues q
  ON m.queue_id = q.object_id
  
The queues' states are INACTIVE and there is no activated task - Query result


Minor Tweak, Major CPU Usage Impact

Now, we will make a small change to the target queue's activation procedure. The change is in how the loop is constructed.


-- CREATE TWO ACTIVATION FUNCTIONS: for the two queues
-- This is for the target queue
CREATE OR ALTER PROCEDURE [dbo].[TargetQueueProcess]
AS
BEGIN
	SET NOCOUNT ON;
 
	DECLARE @conversationHandle UNIQUEIDENTIFIER
	DECLARE @messagetypename NVARCHAR(256)
	DECLARE @messagebody XML
 
	DECLARE @errorNumber AS int;
	DECLARE @errorMessage AS nvarchar(3000);
 
	WHILE EXISTS(SELECT 1 FROM dbo.TargetQueue)
	BEGIN
		;RECEIVE TOP(1) @conversationHandle = conversation_handle
			 , @messagetypename = message_type_name
			 , @messagebody = message_body
		  FROM [dbo].[TargetQueue]
 
		IF @conversationHandle IS NOT NULL
		BEGIN
			-- Log
			INSERT INTO DemoServiceBrokerLog VALUES (
						getdate(),
						@messageTypeName,
						'TargetQueueProcess', 
						@messagebody
				);
 
 
			IF @messageTypeName = 'http://my.dba.aventure/dbo/DemoServiceBroker/endofconversation' 
			BEGIN
				-- End the conversation 
				-- The initiator will receive an EndDialog message afterwards
				END CONVERSATION @conversationHandle;
			END
			ELSE IF @messageTypeName = 'http://my.dba.aventure/dbo/DemoServiceBroker/message' 
			BEGIN
				BEGIN TRY 
					-- Process the message
					PRINT ('Do the actual task in here')
				END TRY 
				BEGIN CATCH 
					-- Capture the error
					SELECT @errorNumber = ERROR_NUMBER()
					, @errorMessage = ERROR_MESSAGE()
 
					-- End the conversation with an error
					-- The initiator will receive an Error message afterwards
					END CONVERSATION @conversationHandle WITH ERROR = @errorNumber DESCRIPTION = @errorMessage;
				END CATCH 
			END
		END
	END
END
GO

Let's also refresh everything by turning the queues off and then turning them back on; and truncating the log table:

  -- Turn off the queues
  ALTER QUEUE dbo.InitiatorQueue WITH STATUS = OFF;
  ALTER QUEUE dbo.TargetQueue WITH STATUS = OFF;

  -- Turn on the queues
  ALTER QUEUE dbo.InitiatorQueue WITH STATUS = ON;
  ALTER QUEUE dbo.TargetQueue WITH STATUS = ON;

  -- Remove things in the log table
  TRUNCATE TABLE dbo.DemoServiceBrokerLog

After making all necessary changes, let's another time start a conversation and send a message through the conversation

USE  ServiceBrokerDemo
 
DECLARE @conversationHandle UNIQUEIDENTIFIER
DECLARE @fromService SYSNAME = 'http://my.dba.aventure/dbo/DemoServiceBroker/InitiatorService'
DECLARE @toService SYSNAME = 'http://my.dba.aventure/dbo/DemoServiceBroker/TargetService'
DECLARE @contract SYSNAME = 'http://my.dba.aventure/dbo/DemoServiceBroker/contract'
 
-- Craft a contrived message body
DECLARE @messageBody XML = 'some message'
 
 
BEGIN DIALOG CONVERSATION @conversationHandle
FROM SERVICE @fromService
TO SERVICE @toService
ON CONTRACT @contract
WITH ENCRYPTION = OFF;
 
BEGIN CONVERSATION TIMER (@conversationHandle) TIMEOUT = 5
 
;SEND ON CONVERSATION @conversationHandle
	MESSAGE TYPE [http://my.dba.aventure/dbo/DemoServiceBroker/message] 
	(@messageBody)

Let's wait for 5 seconds, then run the following code to check:

  SELECT * FROM sys.dm_broker_activated_tasks;
 
  SELECT *
  FROM sys.dm_broker_queue_monitors AS m
  INNER JOIN sys.service_queues q
  ON m.queue_id = q.object_id

You'll notice that the TargetQueue's state is always RECEIVES_OCCURING instead of being INACTIVE. The TargetQueueProcess procedure seems to run infinitely, even when there is no message in the target queue.

The broker keeps reactivating the target queue's procedure even there is no message in the queue - Query result


The execution count of the procedure TargetQueueProcess went up to 4 million after one hour, which means the broker constantly reactivates the procedure.

Thoughts

WHILE (1=1) ... IF (@@ROWCOUNT=0) ... BREAK and WHILE EXISTS(SELECT 1 FROM dbo.TargetQueue) are supposed to do the same thing. However, for some reason, the latter causes the broker to reactive the target queue process procedure. My guess without any proper evidence is that, somehow the cleanup after the message being processed hasn't finished. I did post a question in StackOverflow, hopefully someone can help me to find out why. Or if you reader can find the reason, please let me know.

In my company system, we have the same incorrect setup as above for many years. Until when I troubleshooted and fixed the WHILE loop, the CPU cut in half. Testing and benchmarking are important because we never think that such small code change can make a huge difference to the system resources.

Comments

Post a Comment

Popular posts from this blog

SQL SERVER INDEX (Part 1): Index Seek vs Index Scan and Statistics

-
Image
Firstly, I recommend watching this  How to Think Like the Engine - YouTube  by Brent Ozar on YouTube (all parts). It is incredibly helpful foundational material before you begin your SQL performance tuning journey. The SQL Server optimizer   is responsible for determining which operations —such as scans or seeks — should be used to query the least number of 8KB pages. However, the optimizer sometimes needs a DBA's intervention. For example, an ideal index for a query might not exist yet. In such cases, it is up to the DBA to create the index so that the optimizer can make use of it. Similarly, inaccurate row count estimations on the execution plan can lead to suboptimal choices by the optimizer. As DBAs, we may need to update statistics or tune the code depending on the cause of the misestimations. When we have accurate indexes and correct row estimations , the optimizer's choices are usually optimal, and we can stop our part of tuning the query. In this post, I will...
Read more

SQL SERVER INDEX (Part 4): Statistics

-
Image
Firstly, I recommend watching this  How to Think Like the Engine - YouTube  by Brent Ozar on YouTube (all parts). It is incredibly helpful foundational material before you begin your SQL performance tuning journey. Throughout my SQL Server Index series, I have emphasized the importance of accurate statistics in helping SQL Server choose the best execution plan. I've mentioned that if a query has accurate indexes and correct cardinality estimates , the optimizer's choices are usually optimal. However, I haven't discussed the scenario when row estimates are inaccurate , leading the optimizer to make suboptimal choices. This post will cover some examples of that. To demonstrate, I will use the  StackOverflow2010  database.  Feel free to follow along with my examples.  (If you haven't, please checkout  Tools I Used During Query Performance Troubleshooting  to see how I setup to obtain execution plan and logical reads info.) Problem Consider the follow...
Read more

📐 SQL Server Performance: Troubleshooting Memory Grant Overestimation using SQL Diagnostic Manager and SQL Server execution plan

-
Image
Have you ever wondered how SQL Server uses memory? Have you ever encountered a memory issue in SQL Server? Did you know that SQL Server isn't smart sometimes and it can overestimate and grant a significant amount of memory just for a single query to run —up to one-fifth of the server’s total memory 😱? If you are curious to learn more, read on 🤓. Introduction In SQL Server, before executing a query, a compilation phase may be triggered to generate an execution plan. An execution plan determines 3 key aspects: the order in which source tables are accessed, the operations used to retrieve data (e.g. seek, index/table scan), and the methods for joining, filtering, sorting, or aggregating data ( Execution plan overview - SQL Server | Microsoft Learn ). SQL Server can bypass the compilation phase if it finds a reusable cached plan for the query. During the compilation phase, SQL Server estimates how much data each operation (e.g. read, join, sort, aggregate) will handle and...
Read more