Log Shipping - Exclusive access could not be obtained because the database is in use

This story began as they almost always do - with a page at 4am local time...

--

'Alert: SQL Failed Jobs on InstanceName is Failed'

Job name: LSRestore_InstanceName_DatabaseName
Date & Message: 2014-07-31 05:24:00.0 The job failed. The Job was invoked by User DOMAIN\LOGIN. The last step to run was step 1 (Log shipping restore log job step.).

--

Sigh.  

I am not a fan of log shipping but I do acknowledge that it has its place.  In this case the client is using it to have a read-only standby database on a Standard Edition SQL Server (hence no mirroring+snapshot or Availability Group with readable secondary).  The database in question is large (>1TB) but with relatively small daily churn (~5GB of LOG backups per day).  Due to the traffic on the standby database during the day they have their log shipping on this database configured to only run restores during the overnight, keeping the standby database static and available for their users during the business day.

By the time I received the page, the LSRestore job has been failing for much of the overnight, with service desk'ers trying various things to try to resolve the issue.

When I signed on to the system I drilled into the job step history and found the following:

--

Microsoft (R) SQL Server Log Shipping Agent  [Assembly Version = 10.0.0.0, File Version = 10.50.1600.1 ((KJ_RTM).100402-1539 )]  Microsoft Corporation. All rights reserved.    2014-07-31 03:45:00.32 ----- START OF TRANSACTION LOG RESTORE   ----- 

2014-07-31 03:45:00.39 Starting transaction log restore. Secondary ID: '8f45136f-fb73-4815-b849-c7c1b391831b'  2014-07-31 03:45:00.39 Retrieving restore settings. Secondary ID: '8f45136f-fb73-4815-b849-c7c1b391831b'  2014-07-31 03:45:00.41 Retrieved common restore settings. Primary Server: 'InstanceName', Primary Database: 'DatabaseName', Backup Destination Directory: 'H:\LogShip\DatabaseName', File Retention Period: 1440 minute(s)  2014-07-31 03:45:00.42 Retrieved database restore settings. Secondary Database: 'DatabaseName', Restore Delay: 10, Restore All: True, Restore Mode: Standby, Disconnect Users: False, Last Restored File: H:\LogShip\DatabaseName\DatabaseName_20140730071500.trn, Block Size: Not Specified, Buffer Count: Not Specified, Max Transfer Size: Not Specified 

2014-07-31 03:45:20.77 *** Error: Could not apply log backup file 'H:\LogShip\DatabaseName\DatabaseName_20140730073000.trn' to secondary database 'DatabaseName'.(Microsoft.SqlServer.Management.LogShipping) ***  2014-07-31 03:45:20.77 *** Error: Exclusive access could not be obtained because the database is in use.  RESTORE LOG is terminating abnormally.(.Net SqlClient Data Provider) *** 

2014-07-31 03:45:21.05 *** Error: The log backup file 'H:\LogShip\DatabaseName\DatabaseName_20140730073000.trn' was verified but could not be applied to secondary database 'DatabaseName'.(Microsoft.SqlServer.Management.LogShipping) ***  2014-07-31 03:45:21.05 Deleting old log backup files. Primary Database: 'DatabaseName'  2014-07-31 03:45:21.06 The restore operation completed with errors. Secondary ID: '8f45136f-fb73-4815-b849-c7c1b391831b'  2014-07-31 03:45:21.06 ----- END OF TRANSACTION LOG RESTORE     -----    Exit Status: 1 (Error)  

 --

Seeing the "Exclusive access could not be obtained because the database is in use" error (buried in the middle of the messages), I went looking for something connected to the DatabaseName database.  Sure enough there it was:

spid	blocked	dbid	uid	login_time	last_batch	status	hostname
69	0	10	1	7/30/2014 11:07	7/30/2014 11:07	sleeping	ServerName
program_name		hostprocess	cmd	loginame	stmt_start	stmt_end	request_id
Microsoft SQL Server Management Studio - Query		5404	AWAITING COMMAND	Login1	0	0	0

Basically someone opened a Management Studio window on InstanceName as loginname Login1 at 11:07am the previous day, ran one or two queries (last_batch only one second after the login_time), and then left the window open, maintaining a connection to the DatabaseName database.

Log Shipping requires exclusive access (as noted in the error) to apply the log backups, so this single Management Studio connection was effectively breaking log shipping.

Because the SPID was "Awaiting Command" with a Last_Batch of some time ago I went ahead and killed SPID 69 and manually started the "LSRestore_ServerName_DatabaseName" job.  The job completed successfully, restoring the last day's worth of logs in about ten minutes.

--

How could this be prevented?  What was configured incorrectly?

When setting up a log shipping secondary as a read-only standby, there is an option to disconnect any existing connections before attempting log shipping restores.  This option is available whether you use the Management Studio GUI or T-SQL commands.

In Management Studio, the option is "Disconnect users in the database before restoring backups."  This option is on the "Restore Transaction Log" tab on the "Secondary Database Settings" window after you select to "Add" a secondary database.  The option is only exposed if you select Standby mode - there is no need for the option in No Recovery mode since users won't be able to connect to the secondary database anyway: 

Via T-SQL, the option is a parameter of the "sp_add_log_shipping_secondary_database" stored procedure.  Set "@disconnect_users = 1" to enable the disconnect functionality.

IMPORTANT NOTE - as seen in the screenshot above, this option is not enabled by default in Management Studio, and it is also not enabled by default by the stored procedure (default value is 0).  If you wish to use this functionality you need to go "out of your way" to turn it on. Be aware of the impact of this option *before* turning it on.  If use pattern/business rules of your standby database is such that queries against the standby are more important than successful restores, do *not* enable this option as it will terminate your queries with extreme prejudice.

http://sd.keepcalm-o-matic.co.uk/i/keep-calm-and-terminate-with-extreme-prejudice.png

Hope this helps!

Help - I Need a List of my Maintenance Plan Jobs *and* Schedules!

UPDATE - Jason Brimhall (blog/@sqlrnnr) pointed out after reading this post that there is a more inline way to do a lot of this work as shown in his post here.  Jason's post relates to SSRS reports (very similar logic since they also are SQL Agent jobs) and could easily be applied to this same maintenance plan problem - thanks Jason!


I have written over and over about how I dislike SQL Server's canned SSIS Maintenance Plans and how I strongly prefer Ola Hallengren's Maintenance Solution.  Another popular option for intelligent index maintenance are the scripts from Michelle Ufford (blog/@sqlfool), which also perform intelligent re-indexing.  The key advantage of Ola's code to me is that it is a full maintenance suite, handling backups, CHECKDB, *and* index maintenance.

All of that aside, as a Managed Services DBA I still have to frequently deal with Maintenance Plans and their repercussions on my innocent unsuspecting clients.

I recently received a request from one of my clients for all of the maintenance plan information and their related jobs for backup tasks.  I had a script to return maintenance plan information (using the updated tables and views present from SQL Server 2005+) but I didn't have an easy way to reference the jobs and job schedules - sure I knew how to pull basic info from sysjobs and sysjobschedules, but doing so is a complete mess of bit-wise mathematics to decipher the multi-values in a single field (bad Microsoft!) that is prevalent throughout the job tables and views.

A little Google-Fu brought me to Michelle's blog and an amazing entry where she already has all of the bit-wise-ness (bit-wisdom?) worked out in a very elegant query to pull the relevant information.  Her original blog post is about generating disable statements for the jobs, but I slightly modified her query to return a few extra fields and then hacked it together with my pre-existing maintenance plan information query to return the data I needed for my client:

/*
Backup information from maintenance plans - jobs, schedules, etc.

Andy Galbraith @DBA_ANDY

MSSQL 2005+

Heavily borrows from http://sqlfool.com/2009/02/view-sql-agent-jobs-tsql/
for the original job schedule CTE and base query - thanks Michelle!

I modified Michelle's original query slightly and then added
the maintenance plan information to match the jobs to their
parent maintenance plans.

The filter that makes the query relevant to backup subplans is:

"and smpld.line1 like '%Back Up%'"

Commenting out or removing this line will display information about
all maintenance plan subplans and their enabled jobs
*/

Declare @weekDay Table
(
    mask  int
    , maskValue varchar(32)
);

Insert Into @weekDay
    Select 1, 'Sunday'  UNION ALL
    Select 2, 'Monday'  UNION ALL
    Select 4, 'Tuesday'  UNION ALL
    Select 8, 'Wednesday'  UNION ALL
    Select 16, 'Thursday'  UNION ALL
    Select 32, 'Friday'  UNION ALL
    Select 64, 'Saturday';

With myCTE
As (
    Select sched.name As 'scheduleName'
    , sched.schedule_id
    , jobsched.job_id
    , Case
        When sched.freq_type = 1
            Then 'Once'
        When sched.freq_type = 4 And sched.freq_interval = 1
            Then 'Daily'
        When sched.freq_type = 4
            Then 'Every ' + Cast(sched.freq_interval As varchar(5)) + ' days'
        When sched.freq_type = 8
            Then Replace( Replace( Replace((
                Select maskValue
                From @weekDay As x
                Where sched.freq_interval & x.mask <> 0
                Order By mask For XML Raw)
    , '"/><row maskValue="', ', '), '<row maskValue="', ''), '"/>', '')
        + Case When sched.freq_recurrence_factor <> 0
        And sched.freq_recurrence_factor = 1
            Then '; weekly'
    When sched.freq_recurrence_factor <> 0
            Then '; every '
            + Cast(sched.freq_recurrence_factor As varchar(10)) + ' weeks'
        End
        When sched.freq_type = 16
            Then 'On day '
            + Cast(sched.freq_interval As varchar(10)) + ' of every '
            + Cast(sched.freq_recurrence_factor As varchar(10)) + ' months'
        When sched.freq_type = 32
            Then Case
            When sched.freq_relative_interval = 1
                Then 'First'
            When sched.freq_relative_interval = 2
                Then 'Second'
            When sched.freq_relative_interval = 4
                Then 'Third'
            When sched.freq_relative_interval = 8
                Then 'Fourth'
            When sched.freq_relative_interval = 16
                Then 'Last'
    End +
    Case
        When sched.freq_interval = 1
            Then ' Sunday'
        When sched.freq_interval = 2
            Then ' Monday'
        When sched.freq_interval = 3
            Then ' Tuesday'
        When sched.freq_interval = 4
            Then ' Wednesday'
        When sched.freq_interval = 5
            Then ' Thursday'
        When sched.freq_interval = 6
            Then ' Friday'
        When sched.freq_interval = 7
            Then ' Saturday'
        When sched.freq_interval = 8
            Then ' Day'
        When sched.freq_interval = 9
            Then ' Weekday'
        When sched.freq_interval = 10
            Then ' Weekend'
    End
    +
    Case
        When sched.freq_recurrence_factor <> 0
        And sched.freq_recurrence_factor = 1
            Then '; monthly'
        When sched.freq_recurrence_factor <> 0
            Then '; every '
    + Cast(sched.freq_recurrence_factor As varchar(10)) + ' months'
    End
    When sched.freq_type = 64
        Then 'StartUp'
    When sched.freq_type = 128
        Then 'Idle'
     End As 'frequency'
    , IsNull('Every ' + Cast(sched.freq_subday_interval As varchar(10)) +
    Case
        When sched.freq_subday_type = 2
            Then ' seconds'
        When sched.freq_subday_type = 4
            Then ' minutes'
        When sched.freq_subday_type = 8
            Then ' hours'
    End, 'Once') As 'subFrequency'
    , Replicate('0', 6 - Len(sched.active_start_time))
        + Cast(sched.active_start_time As varchar(6)) As 'startTime'
    , Replicate('0', 6 - Len(sched.active_end_time))
        + Cast(sched.active_end_time As varchar(6)) As 'endTime'
    , Replicate('0', 6 - Len(jobsched.next_run_time))
        + Cast(jobsched.next_run_time As varchar(6)) As 'nextRunTime'
    , Cast(jobsched.next_run_date As char(8)) As 'nextRunDate'
    From msdb.dbo.sysschedules As sched
    Join msdb.dbo.sysjobschedules As jobsched
    On sched.schedule_id = jobsched.schedule_id
    Where sched.enabled = 1
)
Select DISTINCT p.name as 'Maintenance_Plan'
, p.[owner] as 'Plan_Owner'
, sp.subplan_name as 'Subplan_Name'
, smpld.line3 as 'Database_Names'
, RIGHT(smpld.line4,LEN(smpld.line4)-6) as 'Backup_Type'
, job.name As 'Job_Name'
, sched.frequency as 'Schedule_Frequency'
, sched.subFrequency as 'Schedule_Subfrequency'
, SubString(sched.startTime, 1, 2) + ':'
    + SubString(sched.startTime, 3, 2) + ' - '
    + SubString(sched.endTime, 1, 2) + ':'
    + SubString(sched.endTime, 3, 2)
As 'Schedule_Time' -- HH:MM
, SubString(sched.nextRunDate, 1, 4) + '/'
    + SubString(sched.nextRunDate, 5, 2) + '/'
    + SubString(sched.nextRunDate, 7, 2) + ' '
    + SubString(sched.nextRunTime, 1, 2) + ':'
    + SubString(sched.nextRunTime, 3, 2)
As 'Next_Run_Date'
/*
Note: the sysjobschedules table refreshes every 20 min,
so Next_Run_Date may be out of date
*/
From msdb.dbo.sysjobs As job
Join myCTE As sched
On job.job_id = sched.job_id
join  msdb.dbo.sysmaintplan_subplans sp
on sp.job_id = job.job_id
inner join msdb.dbo.sysmaintplan_plans p
on p.id = sp.plan_id
JOIN msdb.dbo.sysjobschedules sjs
ON job.job_id = sjs.job_id
INNER JOIN msdb.dbo.sysschedules ss
ON sjs.schedule_id = ss.schedule_id
join msdb.dbo.sysmaintplan_log smpl
on p.id = smpl.plan_id
and sp.subplan_id =smpl.subplan_id
join msdb.dbo.sysmaintplan_logdetail smpld
on smpl.task_detail_id=smpld.task_detail_id
and smpld.line1 like '%Back Up%'
where job.[enabled] = 1
and smpld.line3<>''
Order By Next_Run_Date;

The output of the query will look like this (wrapped so it could be inserted at a readable font):

As can be seen from these results, this example instance has four Maintenance Plans, each with one sub-plan related to backups.  The "FULL SQLBKUP_DAILY_AllButSunday" maintenance plan runs weekly every day but Sunday once each day at 10:45pm.

Shout out again to Michelle for the CTE that compiles the job schedule bit-wise information - you saved me (and I'm sure many others) a lot of busywork!

--

Hope this helps!

Why Can't I Reinitialize My Subscriber?

I recently had a colleague request help with a replication problem he was having with a client.  The client was running transactional replication from a SQL Server 2005 Publisher to multiple SQL Server 2005 Subscribers and was having issues after attempting to add several articles (tables) to an existing publication.

--

The initial error reported on multiple subscribers looked like this in Replication Monitor:

“Unable to replicate a view or function because the referenced objects or columns are not present on the Subscriber.”

To me this said that some of the article changes that had been made during the publication change hadn’t been properly sent to the subscribers, so I decided to reinitialize all subscriptions:

(Another colleague pointed out that I could have reinitialized only the broken subscriptions one-by-one, but in this case a majority of the subscriptions were broken and the publication was relatively small.)

--

Three of the four subscriptions failed re-initialization with two different errors, one with a object reference error and the other two with a replication error.

--

The first subscription, on SubServer1, failed re-initialization with the following error:

Cannot DROP TABLE 'dbo.Table99' because it is being referenced by object 'View1'.

I found that the referenced view was created with SCHEMABINDING, which was preventing the related table from being dropped and recreated.  The view didn’t have any explicit permissions on it, so I scripted the view, dropped it, re-ran initialization for that subscription, which succeeded, and then recreated the view (again with SCHEMABINDING as it was originally).

--

SubServer2 and SubServer3 had a different but actually related issue:

In both of these cases, the re-initialization was failing because a table on the subscriber couldn’t drop a table being used in replication.  What this essentially means is:

In Publication #1, PubServer1 is publishing to SubServer2

In Publication #2, SubServer2 is publishing one or more of the tables from Publication #1 to some other server or servers.

In essence, SubServer2 is both a subscriber to Publication #1 and a publisher of Publication #2 (often called a “re-publisher”).  This results in the error seen above, because part of the default options for a re-initialization of a subscription is to drop and recreate the tables, and when a table is an article in a publication (in this case Publication #2 above) it cannot be dropped to reinitialize the subscription to Publication #1.

For information on re-publishing and the order of steps required to use it, see the TechNet article here and the blog post here.  There are many limitations on both the publications and the subscriptions involved in such an arrangement.

The fix to this is alter the properties of the offending articles, or all articles, in the publication (in this case the change was made to all articles, but it could have been made one-by-one as well:

 

Changing article properties in this fashion automatically marks all subscriptions for re-initialization (assuming you don’t cancel out of the above dialog box).  Your options are to accept the default as shown, in which case you need to manually run the snapshot agent job on the Distributor before the re-initialization will occur, or to check the “Generate the new snapshot now” box which will reach out to the Distributor and immediately  fire the snapshot agent job, beginning the re-initialization process right away.  

The decision on what to do here should be based on how critical the replication is to your infrastructure (if you need it fixed *now* you may have no alternative but to generate it right away) and how large the publication itself is (a large publication can be time- and resource-intensive to generate and transfer a snapshot during business hours).

In this case based on the tables included in the publication it was possible to “Generate the new snapshot now” because of its relatively small size.  This re-initialization completed successfully on all subscribers with the “Delete Data” option configured.

--

The final item here is that my notes above about the SCHEMABINDING view would not be completely relevant had I first discovered the republishing situation.  The SCHEMABINDING view broke that single subscriber because the SCHEMABINDING prevented the table from being dropped, but had the article's property been set to “Delete Data” rather than “Drop and Recreate” the SCHEMABINDING issue would have been handled without dropping and recreating the view.

--

Hope this helps!