Failed to Update Read-Only Database on Backup

A problem at work recently – the Netbackup-driven SQL backups were failing for just one database on a particular server. The database in question was, like one other, set to read-only.

I ran DBCC CHECKDB, on the off-chance that this was the problem; everything was fine.

The database was, like one other database on that server, set to READ_ONLY – and that database wasn’t having problems.

Troubleshooting

I checked in Windows Event Log, and all I got was:

BACKUP failed to complete the command BACKUP DATABASE <<name>>. Check the backup application log for detailed messages.

The Netbackup logs were of no help either.

To get an accurate error message, I ran a native SQL backup, and, in addition to the normal backup / filegroup / page messages, got the following error:

Msg 3906, Level 16, State 1, Line 35
Failed to update database "<<name>>" because the database is read-only.
Msg 3013, Level 16, State 1, Line 35
BACKUP DATABASE is terminating abnormally.

Checking the SQL Server error logs gave a clue:

[INFO] getMaxUnrecoverableCheckpointId(). Database ID: [6]. Start of Log LSN: 00000022:00000097:0023 used to trim unrecoverable checkpoint files tables during full backup.
[INFO] HkHostBackupDeleteContext(). Database ID: [6]. Cleaned up all the allocated buffers.

Hk? That sounds as though it might mean Hekaton. Checking the database properties, it was, indeed, a database with in-memory objects.

Replicating the Problem

A script to replicate the problem. Note that I’m writing to the NUL: device, a hangover from the good old days – it means the whole backup process is running, but I’m just not saving the backup files.

--First, create the database and run a backup
CREATE DATABASE ROInMemBackupTest;
GO
ALTER DATABASE ROInMemBackupTest SET READ_ONLY WITH ROLLBACK IMMEDIATE;
GO
BACKUP DATABASE RoInMemBackupTest TO DISK='NUL:';
GO
/*
Processed 344 pages for database 'RoInMemBackupTest', file 'ROInMemBackupTest' on file 1.
Processed 1 pages for database 'RoInMemBackupTest', file 'ROInMemBackupTest_log' on file 1.
BACKUP DATABASE successfully processed 345 pages in 0.064 seconds (42.091 MB/sec).
*/

--Now we add a filegroup to contain memory optimized data
ALTER DATABASE ROInMemBackupTest SET READ_WRITE;
GO
ALTER DATABASE [ROInMemBackupTest] ADD FILEGROUP [InMemData] CONTAINS MEMORY_OPTIMIZED_DATA;
GO
ALTER DATABASE ROInMemBackupTest SET READ_ONLY WITH ROLLBACK IMMEDIATE;
GO
BACKUP DATABASE RoInMemBackupTest TO DISK='NUL:';
GO
/*
Processed 360 pages for database 'RoInMemBackupTest', file 'ROInMemBackupTest' on file 1.
Processed 3 pages for database 'RoInMemBackupTest', file 'ROInMemBackupTest_log' on file 1.
BACKUP DATABASE successfully processed 363 pages in 0.057 seconds (49.633 MB/sec).
*/

--Now we add a container to hold memory optimized data
ALTER DATABASE ROInMemBackupTest SET READ_WRITE;
GO
ALTER DATABASE ROInMemBackupTest 
ADD FILE 
(
    NAME='MemOptData', 
    FILENAME='C:\Program Files\Microsoft SQL Server\MSSQL13.MSSQLSERVER\MSSQL\DATA\ROInMemBackupTest_MemOptData'
)
TO FILEGROUP InMemData;
GO

--Set to RO & try another backup
ALTER DATABASE ROInMemBackupTest SET READ_ONLY WITH ROLLBACK IMMEDIATE;
GO
BACKUP DATABASE ROInMemBackupTest TO DISK='NUL:';
GO
/*
Processed 360 pages for database 'ROInMemBackupTest', file 'ROInMemBackupTest' on file 1.
Processed 0 pages for database 'ROInMemBackupTest', file 'MemOptData' on file 1.
Processed 2 pages for database 'ROInMemBackupTest', file 'ROInMemBackupTest_log' on file 1.
Msg 3906, Level 16, State 1, Line 35
Failed to update database "ROInMemBackupTest" because the database is read-only.
Msg 3013, Level 16, State 1, Line 35
BACKUP DATABASE is terminating abnormally.
*/

ALTER DATABASE ROInMemBackupTest SET READ_WRITE;
GO
BACKUP DATABASE ROInMemBackupTest TO DISK='NUL:';
GO
/*
Processed 360 pages for database 'ROInMemBackupTest', file 'ROInMemBackupTest' on file 1.
Processed 0 pages for database 'ROInMemBackupTest', file 'MemOptData' on file 1.
Processed 2 pages for database 'ROInMemBackupTest', file 'ROInMemBackupTest_log' on file 1.
BACKUP DATABASE successfully processed 362 pages in 0.069 seconds (40.895 MB/sec).
*/


--Tidy up after we're finished
DROP DATABASE ROInMemBackupTest;

Disclaimer

This has been tested on SQL2016SP2, as that’s what this server is, and also on SQLServer 2016 SP2 CU5. I’ve not yet tested it on anything else – feel free to let me know in the comments if it works / fails on other versions of SQL Server.

Advertisements

Redgate SQLPrompt – Backup your code snippets

You’ve got a new computer? And you want to copy your code snippets over?

Or you’ve got a new colleague and want to share your stuff?

Or you’ve got multiple machines an want to keep snippets in sync?

You’ll want to know about C:\Users\YourLoginName\AppData\Local\Red Gate\SQL Prompt 9\Snippets

Go on, have a look. You’ll see an assortment of XML-format files, with the extension .sqlpromptsnippet. Those are the files you’re looking for. Knock yourselves out.

Error: There is not enough space on the disk

I was running a query in SQL Server Management Studio (SSMS), nothing too complicated, and got this error, unexpectedly:

An error occurred while executing batch. Error message is: There is not enough space on the disk.

There’s plenty of space on the server, so what’s the problem? The problem is that we’re running a query in SSMS, and SSMS caches resultsets to your %TEMP% directory. And there’s no way to configure that, other than changing where %TEMP% actually *is*.

Just to demonstrate the problem, navigate to %TEMP% – it’s buried somewhere in the user profile AppData directory, so it’s quicker just to open a new explorer window and type %TEMP% into the navigation bar:

Look! SSMS!

However, no sign of any files containing anything useful. Open a command window at this location – quick way is to just put “cmd” into the Navbar and hit return:

That opens up a command window in the right location. Look for hidden files:

There’s the culprit (OK, it’s only 14KB here, bu tit’s a small query just to prove a point…)

To really prove the point, on this particular server, I can do it just by running this:

USE [msdb];

SELECT *
FROM [dbo].[backupset] AS [bs1],
     [dbo].[backupset] AS [bs2],
     [dbo].[backupset] AS [bs3];

…but that would risk crashing the server. So I won’t do that.

What do we learn from this, though? The main points (for me):

• Don’t run SSMS on servers
• Make sure there’s plenty of disk space

OBJECT_ID()’s second parameter

I received a supplier-supplied maintenance / check / troubleshooting script that did a whole heap of looking-to see-if-a-default-value-exists-and-if-it-doesn’t-then=create-it type stuff.

As you would expect, it’s a load of

IF NOT EXISTS (SELECT * FROM dbo.sysobjects WHERE id = OBJECT_ID(N'<<DefaultName>>') AND type = 'D')

BEGIN

    ALTER TABLE ... ADD CONSTRAINT...

END

They could have saved themselves a bit of typing (or, let’s be honest, copying-and-pasting) by replacing all those IF NOT EXISTS with

IF OBJECT_ID(N'<<DefaultName>>', N'D') IS NULL

BEGIN

    ALTER TABLE ... ADD CONSTRAINT...

END

Yes. OBJECT_ID can take a second parameter, which is the type of object to look for.

It might be worth noting that, although the type value in sys.objects is of type char(2), the type parameter in OBJECT_ID is implicitly converted to nvarchar if it’s not declared as such. Is this some far-sighted future-proofing? Check the documentation for sys.objects to see the possible values for the type field.

SQL Server Availability Groups and SQL Server Reporting Services – A Brief Rant Triggered By Someone Failing Something Over Without Understanding The Full Implications, Or, Pay Attention To Your DBA Because He Knows This Stuff And That’s What You Pay Him For

Is the headline longer than the body? Not now I’ve included the fix for this situation as well as the initial rant. Maybe next time.

Yes, you may have an availability group – well done – and you may have installed SSRS on both servers. But you’ve only set up the reporting application to point to one of those? And you’ve given the link https://<<Listener_Name>>/reports out to the users? Head/desk. I told you at the time that SSRS doesn’t play nicely with AGs. [Nearly misposted as SSRS doesn’t play nicely with SSRS, which, while valid, isn’t the point here…]

Here’s what you need to do to fix this / make sure it doesn’t happen:

1. Install the reports on the active server
2. Failover
3. Install the reports on the now-active server
4. On each server, change the report data source to use the listener as the source, not (localserver)
5. On each server, set up the security group(s) and permissions your users require

[Disclaimer – this worked for this situation. It might not work for yours. Support here is worth what you paid for it. Don’t Drink and DBA.]

Only then will you be able to get away with distributing the AG Listener as the SSRS URL. I said this much at the time… Yes, I know things were a bit…difficult back then, but still. Oh well.

Where’s my LART? Or my coffee? Either will do

SQL Server Error 18456 Severity: 14 State: 73

A question asked on one of the forums today wasn’t easily answerable by Googling. Summary of the question “I have error 18456 State 73 – why?”

Google seemed remarkably quiet on the subject of that particular state code. Even Aaron Bertrand’s list of causes of state codes for SQL Server error 18456 missed this one.

However, some searching did find a link to what appears to be some in-depth VMWare VSAN training documentation that includes that error in some logging information, which made me wonder if it was related to the error 18456 state 38 that followed. The log excerpt in question:

2017-08-17 23:16:47.690 spid52 Setting database option SINGLE_USER to ON for database for 'tpcc'.
2017-08-17 23:18:28.490 Logon Error: 18456, Severity: 14, State: 73.
2017-08-17 23:18:28.490 Logon Login failed for user 'SQL2016-SA-03\Administrator'.  Reason: Failed to open the database 'tpcc' configured in the session recovery object while recovering the connection. [CLIENT: ]
2017-08-17 23:18:31.330 Logon Error: 18456, Severity: 14, State: 38.
2017-08-17 23:18:31.330 Logon Login failed for user 'SQL2016-SA-03\Administrator'.  Reason: Failed to open the explicitly specified database 'tpcc'. [CLIENT: ]

The full text of the error in the SQL Server event log is “Failed to open the database ” configured in the session recovery object while recovering the connection”. That, combined with the error state 38 – Failed to open the explicitly specified database – led me to think that a connection had been dropped and the database dropped or made otherwise unavailable before the user tried to reopen the query session.

A test

Fire up SSMS, and create a database:

CREATE DATABASE Test73;
GO

In another query window, run the following:

USE Test73;
SELECT DB_Name(), SPID();

Make a note of that SPID, and feed it into the following SQL that you run in the first window:

KILL 55;
GO
DROP DATABASE Test73;
GO

Now go back to the second query window, and hit F5 to refresh / rerun the batch.

Oops.

The error text:

TITLE: Microsoft SQL Server Management Studio

---

The connection is broken and recovery is not possible. The client driver attempted to recover the connection one or more times and all attempts failed. Increase the value of ConnectRetryCount to increase the number of recovery attempts. (Microsoft SQL Server, Error: 0)

For help, click: http://go.microsoft.com/fwlink?ProdName=Microsoft%20SQL%20Server&EvtSrc=MSSQLServer&EvtID=0&LinkId=20476

---

ADDITIONAL INFORMATION:

Cannot open database “Test73” requested by the login. The login failed.
Login failed for user ‘SomeDomain\RUSHTONT’. (Microsoft SQL Server, Error: 4060)

For help, click: http://go.microsoft.com/fwlink?ProdName=Microsoft%20SQL%20Server&EvtSrc=MSSQLServer&EvtID=4060&LinkId=20476

To confirm this series of errors, check the SQL Server Error Log in SSMS, and you’ll see:

Suspicion proved!

Now all we have to do is test to see if there are other possibilities for this issue, but I need to step away from the keyboard…

Longrunning Query – xp_cmdshell?

Flicking through the ol’ Solarwinds activity monitor, I spotted this one day:

That four day purple thing on the right? Not good.

(The remaining images are from a reconstruction, partly to protect the not-so-innocent, and partly because the first job was (as always) fix the finance department’s server…)

Running Adam Machanic’s (b|t) excellent sp_WhoIsActive gave us the following:

Except, in reality, the first column was over 3 days, and the wait_info & CPU fields were waaaay higher. And the login_name field gave me the name of the perpetrator.

I wanted to know what he was up to, but the sql_text field only gives “xp_cmdshell”, not anything useful that might help to identify what went wrong.

So we have to go to Taskmanager on the server. On the “Process Details” page, you can select which detail columns you want to see. We want to see the Command Line, as that’ll tell us if it’s some manually-launched batch job that’s failed or something else going wrong.

Click on OK, and find the process (in this case, the only process) named “cmd.exe” that’s been launched by the SQL Server service.

Oh my. Launching “calc.exe”? Why?

But this shows just what can go wrong if you don’t think about what you’re doing when launching xp_cmdshell – it can (and does) give you the ability to launch anything – and the problem with that is that you can’t control applications with a User Interface when they’re launched from a service account on a server – all you can do is hope you find what you’ve done, and that you can kill it.

…which I could, in this case. Fortunately, the only harm in this case was a red face (not mine, for a change).