3

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:

  1. Determine why my CI databases are locking up and prevent it in the first place.

    OR

  2. 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.

  • Could you try a new server/instance where SQL Server 2019 is installed from scratch instead of upgraded in place? – Aaron Bertrand Oct 7 '20 at 3:13
  • 1
    @AaronBertrand apologies on as I didn't explain this well, when I upgraded what I did was simply migrated to a new server, by backing up and restoring each instance, I did not do a "in place" upgrade, more a migration. – David Rogers Oct 7 '20 at 13:22
  • Still might help to create a second instance and test it there, this should indicate whether it's a SQL Server 2019 problem or a specific instance/config problem. – Aaron Bertrand Oct 7 '20 at 13:35
  • @AaronBertrand I'd love to, the difficult is the specific CI and database combination I have is quite expensive (cloud server costs) and I only see the issue every once in a while maybe one every 5 or 10 CI runs (25 DB deployments per CI), outside of the CI I've not seen this issue on the new SQL version, it's just not yet practical for me to spend X dollars and X days trying to chase this down on a parallel set of hardware and CI stack. I am however working with a DBA at my company to further investigate this inaccessible state, I will update if I have results from that line of investigation. – David Rogers Oct 19 '20 at 21:43