I'm mostly posting this for community awareness, but feel free to give feedback if you think there is a solution other than coding around the problem as we are doing. Crossposting this from my bug submission here: https://feedback.azure.com/forums/908035-sql-server/suggestions/37351609-sql-server-2012-service-broker-ssbdt-spam-endi
We had a problem on some of our SQL 2014 and 2017 instances where the ERRORLOG was repeatedly posting messages like:
2019-03-20 08:36:13.87 spid26s SSBDT: Dialog timer delete during registration (did: 4334D97F-9C96-47BC-AB1C-B9BE5888F89A:Initiator, OpType: CloseDialog OpResult: Null)
I researched and the consensus was Microsoft indicates this is simply debug logging ( https://social.msdn.microsoft.com/Forums/en-US/86b8a5c8-a882-496e-a4c4-99a5bbf2f935/ssbdt-dialog-timer-delete-during-dispatch-with-sql-server-2012-sp3?forum=sqlsetupandupgrade ). However, it didn't change that our systems were intermittently bloating the ERRORLOG with this logging. After investigating, I found the following replication case:
- SQL Server 2012+
- Trace Flag 3605 is on. We are using it to log deadlock events to the ERRORLOG. We are planning to switch to Extended Events, but for now we are still using it for this reason. Turning it off means losing that.
- Have Service Broker conversations generated in a database
- SEND ON CONVERSATION NULL (sending a service broker message to a conversation_handle of NULL, which errors that it is missing the conversation handle but the problem doesn't start unless this has happened at least once)
- End any conversation.
When the first 4 requirements are met and every time 5 happens, it will log a message to ERRORLOG similar to the one I posted above. This seems to occur until SQL Server is restarted. I've attached SQL that recreates this in a new database for an example. In our case, we were getting a conversation handle for a target service but if the service didn't exist we didn't have NULL handling and tried sending the message anyways. This problem didn't exist in SQL2008R2. I felt with the given replication steps, this should be reconsidered as a bug in SQL server. For our part, we are adding NULL handling to our code.
The SQL to generate this problem:
-- 1. Turn on Trace Flag 3605. Required to generate the error DBCC TRACEON(3605,-1) GO -- Creating a test database IF EXISTS (SELECT name FROM sys.databases WHERE name = 'source') DROP DATABASE [source] GO CREATE DATABASE [source]; GO USE [source]; GO -- in case broker isn't enabled by default on a new database on this instance ALTER DATABASE [source] SET NEW_BROKER GO -- creating a source queue/service CREATE QUEUE [source_queue]; GO CREATE SERVICE [source_service] ON QUEUE [source_queue]; GO -- creating a target queue/service CREATE QUEUE [target_queue]; GO CREATE SERVICE [target_service] ON QUEUE [target_queue]; GO -- creating a dialog between them DECLARE @h UNIQUEIDENTIFIER; BEGIN DIALOG CONVERSATION @h FROM SERVICE [source_service] TO SERVICE N'target_service' WITH ENCRYPTION = OFF; GO -- sending a message to nowhere: note this does NOT interact with the dialog or queues/services we generated. It simply is a message to nothing at all. This generates an error that the conversation handle is missing. SEND ON CONVERSATION NULL; GO -- ending the conversation between those two services/queues. Error before that logs to ERRORLOG to stamp and after, to demonstrate that this action is the one causing the debug spam. DECLARE @h UNIQUEIDENTIFIER SELECT @h = conversation_handle FROM [source].sys.conversation_endpoints; DECLARE @error NVARCHAR(100) SET @error = 'Before the conversation end' RAISERROR(@error,16,1) WITH LOG END CONVERSATION @h WITH CLEANUP GO DECLARE @error NVARCHAR(100) SET @error = 'After the conversation end' RAISERROR(@error,16,1) WITH LOG GO USE [master]; GO