3

We normally perform backups across the network to a file share on a different SAN. This works very well for all but 1 of our database servers. The problem machine is a new server running Windows Server 2012R2 as the OS, and SQL Server 2012 Standard Edition for the database instance. The network latency between the server and backup share is sub-MS.

The actual backup of the data and log file happen quickly (sub-second), however, it seems to get stuck at 100% completed (when viewed through sp_WhoIsActive) with a BACKUPTHREAD wait type. If I perform the same backup but to a local drive, it does not experience this problem.

Here is a sample backup command we are running for the MODEL (only 5MBs) database:

USE MASTER
GO

BACKUP DATABASE MODEL
TO  DISK = N'\\<FileShareServer>\SQL_Backup\MODEL.BAK'     
WITH  NAME = N'MODEL-Full Database Backup'
    ,NOFORMAT, INIT,  SKIP, NOREWIND, NOUNLOAD,  STATS = 10
    ,CHECKSUM, COPY_ONLY, COMPRESSION;

GO

Here are the stats for the backup, with Trace Flag 3604, 3213 turned on:

Backup/Restore buffer configuration parameters

Memory limit: 36855MB

BufferCount:                7

Sets Of Buffers:            3

MaxTransferSize:            64 KB

Min MaxTransferSize:        64 KB

Total buffer space:         1 MB

Tabular data device count:  1

Fulltext data device count: 0

Filestream device count:    0

TXF device count:           0

Filesystem i/o alignment:   512

Media Buffer count:            7

Media Buffer size:            64KB

Encode Buffer count:           7

10 percent processed.
20 percent processed.
30 percent processed.
40 percent processed.
51 percent processed.
61 percent processed.
71 percent processed.
81 percent processed.
91 percent processed.

Processed 312 pages for database 'MODEL', file 'modeldev' on file 1.
100 percent processed.
Processed 2 pages for database 'MODEL', file 'modellog' on file 1.
-- Up to here happens sub-second as expected
BACKUP DATABASE successfully processed 314 pages in 252.372 seconds (0.009 MB/sec).

I've tried playing around with stripped backups as well as setting the BUFFERCOUNT and MAXTRANSFERSIZE to higher numbers, to no avail.

Thanks in advanced for your input!

Based on Aaron Bertrand's suggestion, I turned on trace flags 3605, 3004, and 3014 and got the following additional information (only pasting in the portion from where it gets to 100% and then sits waiting):

慂正灵慄慴慢敳退邐邐邐邐坖呁啁荈⃬튅襌⑴䱘粉怤ཁ쒔譌䣹솁̘ : Log files done

Backup: Trailing config done

Backup: MBC done

BackupDatabase: Writing history records

Writing backup history records

BACKUP DATABASE successfully processed 314 pages in 251.106 seconds (0.009 MB/sec).
BackupDatabase: Finished

Just to clarify the entries above, starting with, what I'm guessing are Chinese characters, only display once the backup completes. However, looking in the log file, up to the "Backup: MBC done" entry has the same timestamp as all the previous entries. "BackupDatabase: Writing history records" has a timestamp 4 minutes later.

  • 1
    Any chance trace flags 1806 or 3042 are enabled? Have you tried turning on 3605, 3004, and 3014, then reviewing the data in the logs? I give a little bit of info on these flags here. – Aaron Bertrand May 27 '15 at 21:38
  • Only trace flags 1118 and 3226 are running globally. I'll try 3605, 3004, and 3014 to see if there is any thing out of the ordinary. Thanks Aaron. – SQL3D May 27 '15 at 21:44
  • what service pack you are running on ? Since you are backing up to fileshare - \\<FileShareServer>\SQL_Backup, check with your network guys to see if there are any problems with the fileshare. How many VLFs does this small database have ? Is the power plan set to High Performance mode ? I would recommend to take backups locally and have a PowerShell job to move them to SAN. – Kin Shah May 27 '15 at 23:46
  • Kin, we are on SQL Server 11.0.5582 (SP2 with CU 5). The small database in question is the Model database which has a 1MB log file with only 3 VLFs. Power plan is set to High Performance and the BIOS settings for CPU power settings have also been set to high performance (verified with CPUZ). Backing up locally and then copying with PS is an option, however for DR planning and consistency sake, we would prefer to do all our backups using the same method. – SQL3D May 28 '15 at 14:46
  • As for the file share itself, we use the same file share for multiple SQL Server instances, and have no issues with any other servers (and yes, I've made sure to test all of this while no other instance is in the process of backing up to that file share). – SQL3D May 28 '15 at 14:46
4

Since the additional trace flags allowed you to narrow the delay down to the stage where the process tries to write to msdb, I'm willing to bet one or both of these returns high numbers:

SELECT MAX(row_count), SUM(in_row_reserved_page_count)
  FROM msdb.sys.dm_db_partition_stats 
  WHERE [object_id] = OBJECT_ID('msdb.dbo.backupset');

SELECT database_name, [type], c = COUNT(*)
  FROM msdb.dbo.backupset
  GROUP BY database_name, [type]
  ORDER BY c DESC;

You can consider whittling away at some of the data in that table. Of course, only you can know if you have reasons to keep backup history that otherwise should probably be cleaned up in most cases (for example, the first rule I declare to identify junk history data is for databases that no longer exist - but what if you have renamed a database recently?). So please think about each of these rules and only delete backups where the rules make sense to you based on these scenarios. For example:

CREATE TABLE #bs(id INT, ms INT);

-- Databases that no longer exist on this server:
INSERT #bs(id,ms) SELECT backup_set_id, media_set_id
FROM msdb.dbo.backupset 
WHERE database_name NOT IN (SELECT name FROM sys.databases);

-- All copy_only backups (because who cares?):
INSERT #bs(id,ms) SELECT backup_set_id, media_set_id
FROM msdb.dbo.backupset 
WHERE is_copy_only = 1;

-- All diffs except the most recent:
;WITH x AS 
(
  SELECT backup_set_id, media_set_id, 
    rn = ROW_NUMBER() OVER (PARTITION BY database_name 
      ORDER BY backup_set_id DESC)
  FROM msdb.dbo.backupset
  WHERE [type] = 'I'
  AND backup_finish_date IS NOT NULL
)
INSERT #bs(id,ms) SELECT backup_set_id, media_set_id
FROM x WHERE rn > 1;

...

-- All log backups prior to the most recent full:
INSERT #bs(id,ms) SELECT backup_set_id, media_set_id
FROM msdb.dbo.backupset AS l
WHERE [type] = 'L' AND EXISTS
(
  SELECT 1 
    FROM msdb.dbo.backupset AS bs2
    WHERE database_name = l.database_name
    AND [type] = 'D' 
    AND backup_finish_date > l.backup_finish_date
);

-- All fulls except the most recent successful non-copy-only full backup:
;WITH x AS 
(
  SELECT backup_set_id, media_set_id, 
    rn = ROW_NUMBER() OVER (PARTITION BY database_name 
      ORDER BY backup_set_id DESC)
  FROM msdb.dbo.backupset
  WHERE [type] = 'D'
  AND is_copy_only = 0
  AND backup_finish_date IS NOT NULL
)
INSERT #bs(id,ms) SELECT backup_set_id, media_set_id
FROM x WHERE rn > 1;

Need to also delete some file and filegroup information:

DELETE msdb.dbo.backupfile
WHERE backup_set_id IN (SELECT id FROM #bs);

DELETE msdb.dbo.backupfilegroup
WHERE backup_set_id IN (SELECT id FROM #bs);

DELETE mf
FROM msdb.dbo.backupmediafamily AS mf
WHERE media_set_id IN (SELECT ms FROM #bs)
AND NOT EXISTS (SELECT 1 FROM msdb.dbo.backupset
  WHERE media_set_id = mf.media_set_id);

DELETE ms
FROM msdb.dbo.backupmediaset AS ms
WHERE media_set_id IN (SELECT ms FROM #bs)
AND NOT EXISTS (SELECT 1 FROM msdb.dbo.backupset
  WHERE media_set_id = ms.media_set_id);

You also need to delete associated restore history:

DELETE msdb.dbo.restorefilegroup WHERE restore_history_id IN
(SELECT restore_history_id FROM msdb.dbo.restorehistory
  WHERE backup_set_id IN (SELECT id FROM #bs));

DELETE msdb.dbo.restorefile WHERE restore_history_id IN
(SELECT restore_history_id FROM msdb.dbo.restorehistory
  WHERE backup_set_id IN (SELECT id FROM #bs));

DELETE msdb.dbo.restorehistory
  WHERE backup_set_id IN (SELECT id FROM #bs);

And then finally the main rows can be deleted without violating any constraints:

DELETE msdb.dbo.backupset 
WHERE backup_set_id IN (SELECT id FROM #bs);

DROP TABLE #bs;

This whole process will not likely be fast - I highly recommend doing it during a maintenance window or slow period, and most certainly suspend all backup jobs while doing this.

On Standard Edition there's no real clean way to do this as an online operation, but after you've deleted all those rows, you'll likely benefit most from a full rebuild:

ALTER INDEX ALL ON msdb.dbo.backupset REBUILD;

The above was based partially on the logic included in the system procedure dbo.sp_delete_backuphistory, which leaves out some of the above criteria, has a reputation for locking up the entire set of backup- and restore-related msdb tables, and only allows a singular filter on date (which may not be very helpful depending on a variety of factors, including the percentage of bloat attributed to log backups prior to their most recent fulls, never mind the fact that different databases may be on completely different schedules). You can see where most of my logic came from, though, by looking at the definition for yourself:

EXEC msdb.sys.sp_helptext @objname = N'dbo.sp_delete_backuphistory';
  • Thanks Aaron! While this didn't solve the problem, this is some great information that I'm adding to my admin scripts. – SQL3D May 28 '15 at 15:40
0

I've been having our network infrastructure team look into the issue as well, and it appears that the problem was on their end. Here were the steps they took, that fixed the problem (which still doesn't really answer why the problem existed in the first place):

1- Disabled any IPV6 for active NIC’s.
2- Made sure any NIC’s not being used were disabled.
3- Restarted both servers.

To Aaron's point below, it could have just been the fact that restarting the servers threw out a bad plan to update the MSDB tables, when the backup completed.

  • 1
    This doesn't really explain why the only delay was observed while writing history to msdb, which should be entirely local and not have anything at all to do with the network... – Aaron Bertrand May 28 '15 at 15:54
  • I completely agree. It makes no sense to me. I really wish I had something more to give you. I'm still going to run more test on this server to make sure, but as of right now, the issue has been resolved. If I find out any more, I'll make sure to post it. – SQL3D May 28 '15 at 16:13
  • 3
    Could have been that you had a bad update plan stuck and perhaps with bad estimates combined with very large tables in msdb, and restarting SQL Server threw out the bad plan(s). Might not have been anything to do with the nic changes. – Aaron Bertrand May 28 '15 at 16:27

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.