I have a bit of a unique challenge, I have a series of test databases I use for CI type database testing, generally with each release I will restore (overwrite) these databases from a backup, update them, then subject them to a series of tests while under load. However ever since I moved to using a SQL Server 2019 (from 2016) I have been experiencing periodic issues where one of my "CI" databases becomes unavailable periodically. I have not identified any patterns to when/how this occurs, it's seemingly random.
Typically this starts with one of my releases failing because the first step of my deployment "Reset Database" times out, namely this part of it:
ALTER DATABASE TestCI10 SET OFFLINE WITH ROLLBACK IMMEDIATE
It simply runs forever while repeating the following message (You get the same thing if you try to put it into Single User Mode):
Nonqualified transactions are being rolled back. Estimated rollback completion: 0%.
Now normally you might expect to see this on a large DB with a large transaction, but on this server the DB's are tiny, the backup file is around 17MB and it's mostly just Stored Procs, there is no table with more than 100 records in it, and no tests that take more than 1 second to run any command or proc in the DB.
I can't even access the database tables through the UI, SSMS displays when trying to display tables:
Lock request time out period exceeded. (Microsoft SQL Server, Error: 1222)
If you query who is active (sp_who2) filtered to active and examine the output you see the following:
SPID STATUS LOGIN HostName BlkBy DBName Command CPUTime DiskIO LastBatch ProgramName
72 SUSPENDED XXX\ServiceAccount DEV-XXX-200 72 TestCI10 KILLED/ROLLBACK 266 92 10/06 12:00:11 SQLAgent - TSQL JobStep (Job XXX: Step 3)
Killing this task has no effect. Examining it further (dm_exec_requests joined to a bunch of other stuff):
session_id request_id start_time status command sql_handle statement_start_offset statement_end_offset plan_handle database_id user_id connection_id blocking_session_id wait_type wait_time last_wait_type wait_resource open_transaction_count open_resultset_count transaction_id context_info percent_complete estimated_completion_time cpu_time total_elapsed_time scheduler_id task_address reads writes logical_reads text_size language date_format date_first quoted_identifier arithabort ansi_null_dflt_on ansi_defaults ansi_warnings ansi_padding ansi_nulls concat_null_yields_null transaction_isolation_level lock_timeout deadlock_priority row_count prev_error nest_level granted_query_memory executing_managed_code group_id query_hash query_plan_hash statement_sql_handle statement_context_id dop parallel_worker_count external_script_request_id is_resumable page_resource page_server_reads task_address task_state context_switches_count pending_io_count pending_io_byte_count pending_io_byte_average scheduler_id session_id exec_context_id request_id worker_address host_address parent_task_address dbid objectid number encrypted text
72 0 2020-10-06 12:00:11.870 suspended KILLED/ROLLBACK 0x010012002B85F21A209A3C439002000000000000000000000000000000000000000000000000000000000000 0 -1 0x060012002B85F21A609C70FA8D02000001000000000000000000000000000000000000000000000000000000 18 1 AC603F4F-5F34-4E0F-8C41-932AA9E1484C 72 LCK_M_SCH_M 7598636 LCK_M_SCH_M OBJECT: 2:-1293663577:0 0 1 0 0x 0 0 287 7599057 3 0x00000290A732A8C8 0 92 14273 1024 us_english mdy 7 1 0 1 0 1 1 1 1 2 -1 -5 0 0 3 0 0 1 NULL NULL NULL NULL 1 NULL NULL 0 NULL 0 0x00000290A732A8C8 SUSPENDED 126 0 0 0 3 72 0 0 0x000002879EB5A160 0x0000000000000000 NULL 18 NULL NULL 0 {Command that typically takes no time}
Doesn't reveal any more information on this, other than the task is stuck on a "LCK_M_SCH_M" wait. Stopping the associated SQL agent jobs doesn't seem to have any effect, restarting the SQL agent doesn't seem to have any effect either.
In this situation I've restored to stopping the SQL Server service, deleting my "CI" MDF and LDF files, starting the service and removing/deleting the instance via the SSMS UI, then rerunning the release (it will restore the instance from a backup). This is a labor intensive process and time consuming, I've not yet automated this logic as I don't want to restart the SQL Server service 10 times a day and it delays the rest of the CI releases.
I would like to:
Determine why my CI databases are locking up and prevent it in the first place.
OR
Find a easier way to nuke a instance and restore it from backup without having restart the entire SQL service.
If you google around with associated phrases such as "Inaccessible Database Instance" "Lock Request Timeout Exceeded" you will encounter more posts than can be ever possibly be read suggesting you use a combination of the methods mentioned above or to "simply wait", as I have attempted both with no success I wonder if anyone else has a alternative suggestion to address this issue?
Update 1
A coworker suggested that I look at the "AUTO_UPDATE_STATISTICS_ASYNC" option, it's been reported this can cause lockups with Single User Mode. I checked that all databases have this option set to false:
SELECT name, is_auto_update_stats_on, is_auto_update_stats_async_on
FROM sys.databases
So I don't believe this is the issue, because it isn't set on any of my CI databases...
This post claims that a better way to put a database into single user mode is to set the deadlock priority before executing the command:
SET DEADLOCK_PRIORITY 10;
ALTER DATABASE [YourDBName] SET SINGLE_USER WITH ROLLBACK IMMEDIATE;
I will try that before setting my DB offline in my "Reset Database" script, and update this post with the results as soon as I encounter another locked up instance.
Update 2
Since I have not received any answers to this yet I've added a script that reboots the SQL service before each CI run, like this(Powershell):
Stop-Service -Force "SQLSERVERAGENT"
Restart-Service -Force "MSSQLSERVER"
Start-Service -Force "SQLSERVERAGENT"
This clears up most of the issues with instances with instances only rarely experiences the issue after a service reset (and before the CI tests are run), still basically have the issue though, I see this more as a patch than a actual solution.
Update 3
I did more digging, this is a very similar post, same issue really, in my case it seems that the instance is always getting caught up in the same section of a proc that should take less than one second to run. Specifically it has "LCK_M_SCH_M" set on a temp table that's generated in that proc. Not sure why this is blocking continued execution, but it is, my difficulty comes in when you search around on this issue, everyone just says to restart SQL server, which I now am, every 15 minutes, all day...
Update 4
Ok so I dug so more, it's always a proc call with a specific set of parameters getting locked up on a particular temp table at a particular point in the proc. Thankfully the specific set of parameters passed in always guarantee that the number of records will be small so I've branched the proc into two sections, one for normal records (using the temp table), another for this specific set of parameters (using a massive nested query), and this works great, no more issues in CI I haven't seen the issue since...
Not really a solution, but the end of my investigation, I'm still convinced that there is a "bug" (or call it what you want to) with SQL server 2019 that under a certain set of conditions it will lock up a database, I just don't know how to reproduce properly with a single query or single process.
