Search This Blog

Monday, 19 January 2015

SQL Backup Error

Today's challenge was understanding why I was getting the following error message when trying to back up MS-SQL with Data Protector.


[Normal] From: [email protected] "INST01"  Time: 19/01/2015 4:59:46 PM
SQL statement:
BACKUP DATABASE (Frobnob_Report) TO 
VIRTUAL_DEVICE = 'Data Protector_INST01_Frobnob_Report_055943030_0'
WITH NAME = 'Data Protector: 2015/01/19 0010', COPY_ONLY, BLOCKSIZE = 4096, MAXTRANSFERSIZE = 65536;

[Critical] From: [email protected] "INST01"  Time: 19/01/2015 4:59:46 PM
Virtual Device Interface reported error:
The object was not open.

See also Data Protector debug.log and SQL Server error log for details.

[Normal] From: [email protected] "INST01"  Time: 19/01/2015 4:59:47 PM
Backup Profile:

Run Time ........... 0:00:01
Backup Speed ....... 0.00 MB/s

[Normal] From: [email protected] "INST01"  Time: 19/01/2015 4:59:47 PM
Completed OB2BAR Backup: mssql.ifost.org.au:/INST01/Frobnob_Report/0 "MSSQL"

[Major] From: [email protected] "INST01"  Time: 19/01/2015 4:59:47 PM
Aborting connection to BSM. Abort code -2.

[Major] From: [email protected] "INST01"  Time: 19/01/2015 4:59:48 PM
Error has occurred while executing a SQL statement.
Error message: 'SQLSTATE:[42000] CODE:(3202) MESSAGE:[Microsoft][ODBC SQL Server Driver][SQL Server]Write on "Data Protector_INST01_Frobnob_Report_055943030_0" failed: 995(The I/O operation has been aborted because of either a thread exit or an application request.)
SQLSTATE:[42000] CODE:(3271) MESSAGE:[Microsoft][ODBC SQL Server Driver][SQL Server]A nonrecoverable I/O error occurred on file "Data Protector_INST01_Frobnob_Report_055943030_0:" 995(The I/O operation has been aborted because of either a thread exit or an application request.).
SQLSTATE:[42000] CODE:(3013) MESSAGE:[Microsoft][ODBC SQL Server Driver][SQL Server]BACKUP DATABASE is terminating abnormally.
'

The debug.log and SQL server error logs were uninformative as well, giving exactly the same information as the last message above.

The Windows event log had numerous copies of the same error message, but the very first one said this:

SQLVDI: Loc=ClientBufferAreaManager::SyncWithGlobalTable. Desc=Open(hBufferMemory). ErrorCode=(5)Access is denied.

. Process=4380. Thread=3820. Client. Instance=INST01. VD=Global\Data Protector_INST01_Frobnob_Report_060932541_0_SQLVDIMemoryName_0. 

A lot of investigation later and I discovered that this only happens when using Windows Authentication. I can work around this by changing the DataProtector INET service to run as the user I was wanting to run the SQL backups with and then to use Integrated Authentication.

I still don't quite know what's causing this. I'm guessing that the VDI process is running as a different user or in a different context.

Greg Baker is an independent consultant who happens to do a lot of work on HP DataProtector. He is the author of the only published books on HP Data Protector (http://www.ifost.org.au/press/#dp). He works with HP and HP partner companies to solve the hardest big-data problems (especially around backup). See more at IFOST's DataProtector pages at http://www.ifost.org.au/dataprotector