THE SQL Server Blog Spot on the Web

Welcome to SQLblog.com - The SQL Server blog spot on the web Sign in | |
in Search

Maria Zakourdaev

Why would the system process lock the transaction log of the user database?

 

Yesterday I have noticed that the log file for one of the user databases grew much bigger than it should have been. First of all, I went to check the sys.databases catalog view. The reason for the log growth appeared to be an Active Transaction which is a quite common cause. For some reason, master database ( database id =1) log reuse process has also been waiting for the Active Transaction.

select database_id,log_reuse_wait_desc from sys.databases

image

Further investigation revealed that the oldest active transaction was held by the SIGNAL_HANDLER system user, session 8, which held a lock on the system table sysobjvalues in both databases, the transaction has started about a week ago when the server got restarted. I have used DBCC OPENTRAN to get the oldest transaction in the database and sys.dm_exec_requestssys.dm_tran_active_transactionssys.dm_tran_locks  and  sys.partitions catalog views:

-- find the oldest open transaction in the database

DBCC OPENTRAN

image

 

-- what the session 8 is, how many open transactions it holds and what is the transaction id

select * from sys.dm_exec_requests

image

-- transaction details

select * from sys.dm_tran_active_transactions

where transaction_id = 87868

image

-- resources held by the transaction, resource_associated_entity_id can show the object id or partition id 

select * from sys.dm_tran_locks

where request_session_id = 8

image

-- object id and name for the partition held by the transaction

select object_id,object_name(object_id)

from sys.partitions

where partition_id = 281474980642816

image

This table sys.sysobjvalues can be accessed only from DAC connection, otherwise you will be getting this error message

image

From DAC connection:

image

This table stores encrypted and unencrypted object values and properties. I saw there linked server names and connection strings, security audit path and many more other interesting things. I didn’t really need this table in order to fix the issue, I just wanted to understand who might be using it.

Who can change the system objects or their properties at the time of the server restart? There should be some upgrade process but I new that we have applied the last SP about a month ago.

After looking at the SQL Server Error Log, I clearly saw what session 8 was doing right after the server had restarted. It was executing the upgrade scripts. Looking back through the error log entries I saw that, every time that SQL Service got restarted, it tried to run this upgrade script and failed on every run. The marked out database on the screenshot below is the database with log growth issues. We haven't noticed this error message, server worked at usual and due to the fact that this user database is not heavily used so we haven’t noticed it’s log growth earlier.

image

The sp_vupgrade_replication stored procedure has failed because it couldn't find the MSreplication_subscriptions table. After the failure table locks were never released. The MSreplication_subscriptions table, in fact, should not be there. This table usually located on the subscriber database and my problematic database was a publisher and not subscriber. 3 other objects: MSreplication_objects, MSsubscription_agents and MSsubscription_properties  also should not be there, they are also part of the subscriber metadata. The reason why they are there that in the past this database was once a subscriber which was promoted into the publisher. Most probably subscription objects got not cleaned out properly.

image

As I am not quite sure where to clean the old subscription leftovers, I went ahead and have created the table. Here is a script for you so you don’t need to search for it if you happen to hit the same issue. After creating the table, I have executed the procedure sp_vupgrade_replication to make sure it works properly and it run successfully.

SET ANSI_NULLS OFF

GO

SET QUOTED_IDENTIFIER ON

GO

SET ANSI_PADDING ON

GO

 

CREATE TABLE [dbo].[MSreplication_subscriptions](

       [publisher] [sysname] NOT NULL,

       [publisher_db] [sysname] NULL,

       [publication] [sysname] NULL,

       [independent_agent] [bit] NOT NULL,

       [subscription_type] [int] NOT NULL,

       [distribution_agent] [sysname] NULL,

       [time] [smalldatetime] NOT NULL,

       [description] [nvarchar](255) NULL,

       [transaction_timestamp] [varbinary](16) NOT NULL,

       [update_mode] [tinyint] NOT NULL,

       [agent_id] [binary](16) NULL,

       [subscription_guid] [binary](16) NULL,

       [subid] [binary](16) NULL,

       [immediate_sync] [bit] NOT NULL DEFAULT ((1))

)

 

GO

SET ANSI_PADDING OFF

GO

I have restarted the SQL Server service, the upgrade script had started again and had finally finished without any errors. The databases statuses had returned to their normal state. ( At the beginning of the investigation, I have tried to set the problematic user database OFFLINE and then bring it ONLINE. This have solved the log reuse issue in the user database only, master database however had stayed locked. After the SQL service restart the issue have always returned.)

Only after finishing this investigation and after the issue has got resolved I finally have found a bug on this issue documented here: http://support2.microsoft.com/kb/2509302. The article not quite full, the issue happens also with the databases using Simple Recovery Model. Also, the transaction name was simple “user_transaction”, not like they claim in the article. Maybe this case was somewhat different bug but really close to what is described in the article.

Yours,

Maria

Published Monday, January 26, 2015 4:19 PM by Maria Zakourdaev

Comment Notification

If you would like to receive an email when updates are made to this post, please register here

Subscribe to this post's comments using RSS

Comments

 

Alex Friedman said:

Good investigation! If only Microsoft wrote proper error handling for their own code...

February 9, 2015 10:31 AM
 

Curt said:

Thank you, Maria!  This was very helpful.  Unexplained log growth is something we all have to deal with at times.  It is instructive to see someone else's approach.

February 9, 2015 10:40 AM
 

Dennis said:

Very nice investigation!

We run into the exact same "Feature". All disk space was used by the transaction log.

The short term fix was to increase the virtual disk size by 100 GB.

Then we followed the steps shown here. https://social.msdn.microsoft.com/Forums/sqlserver/en-US/b77799d2-a931-467a-928d-49426d83d5ce/since-upgrade-to-sp2-on-ss2208-transaction-log-on-database-with-simple-recovery-is-never-truncated?forum=sqlsetupandupgrade

I would have preferred to use your approach.

February 12, 2015 11:00 AM
 

Maria Zakourdaev said:

Alex, Curt, Dennis: thank you very much for your feedback!

February 15, 2015 9:36 AM

Leave a Comment

(required) 
(required) 
Submit

About Maria Zakourdaev

The shortest word in the English language that contains the letters: abcdef is… feedback! Let me know if I have touched something that is alive in the cosmos.
Privacy Statement