Slow SQL Server Backup and Restore with DBCC TRACEON (3004, 3605, -1)

SQLTop*, lightweight, simple and easy to use.

When a performance issue occurs, SQLTop* will show quick and easy entire SQL Server Performance on real-time, including waits, performance counters and sessions.

Slow SQL Server Backup and Restore with DBCC TRACEON (3004, 3605, -1)

07 May,2011 by Jack Vamvas

The trace flags 3004 and 3605 give an insight to the BACKUP and RESTORE process. I use these if troubleshooting a  SQL Server Backup and Restore performance decrease . The detailed output  can offer some clues.

 Trace Flag 3004

Instant file initialization  enables data files (not log files)  to skip the zeroing out steps in database CREATE. Not so obvious on a small database, but on larger databases such as 2 TB this saves a significant time.

The trace flag 3004 enables information generation. To view the information ,I enable  the trace flag 3605. If the service account   has Instant File initialization enabled , the zeroing out process is skipped , but if it’s not enabled – you’ll see a zeroing references in the out

Trace Flag 3605

In conjunction with some trace flags , such as 3004 , enabling trace flag 3605 sends information to the error logs.

 The syntax is :

view source

print?

1.DBCC TRACEON (3004, 3605, -1) 

2. 

3.DBCC TRACEOFF (3004, 3605, -1) 

 These are undocumented traces and remain unsupported by Microsoft.

 I’ve included an example of detailed output of 2 backups .Example 1 is a backup of a 100 GB database.Which ran as expected in 20 minutes

Example 2 – is a backup of the same database , but on a separate server , that experienced severe IO Subsystem performance  issues. I stopped the backup after 2 hrs. It is stuck at the Copying data point

 Example 1

 Date,Source,Severity,Message

05/06/2011 09:52:28,spid56,Unknown,DBCC TRACEOFF 3605<c/> server process ID (SPID) 56. This is an informational message only; no user action is required.

05/06/2011 09:52:28,spid56,Unknown,DBCC TRACEOFF 3004<c/> server process ID (SPID) 56. This is an informational message only; no user action is required.

05/06/2011 09:51:15,spid56,Unknown,BackupDatabase: Finished

05/06/2011 09:51:15,spid56,Unknown,Writing backup history records

05/06/2011 09:51:15,Backup,Unknown,Database backed up. Database: DB1<c/> creation date(time): 2011/05/05(18:47:32)<c/> pages dumped: 14253324<c/> first LSN: 824905:191:1<c/> last LSN: 824905:193:1<c/> number of dump devices: 1<c/> device information: (FILE=1<c/> TYPE=DISK: {'K:\myserver\db1.bak'}). This is an informational message only. No user action is required.

05/06/2011 09:51:15,spid56,Unknown,BackupDatabase: MBC done

05/06/2011 09:51:15,spid56,Unknown,BackupDatabase: Final configuration done

05/06/2011 09:51:15,spid56,Unknown,BackupDatabase: Log files done

05/06/2011 09:51:15,spid56,Unknown,BackupDatabase: Database files done

05/06/2011 09:51:15,spid56,Unknown,Padding MSDA with 524288 bytes

05/06/2011 09:26:13,spid56,Unknown,Backup:Copying data

05/06/2011 09:26:12,spid56,Unknown,BackupDatabase: Configuration section done

05/06/2011 09:26:12,spid56,Unknown,BackupDatabase: Work estimates done

05/06/2011 09:26:12,spid56,Unknown,BackupDatabase: Checkpoint done

05/06/2011 09:26:12,spid56,Unknown,Backup: Streams open

05/06/2011 09:26:12,spid56,Unknown,BackupDatabase: Database DB1

05/06/2011 09:26:06,spid56,Unknown,DBCC TRACEON 3605<c/> server process ID (SPID) 56. This is an informational message only; no user action is required.

05/06/2011 09:26:06,spid56,Unknown,DBCC TRACEON 3004<c/> server process ID (SPID) 56. This is an informational message only; no user action is required.

05/06/2011 09:16:37,Backup,Unknown,BACKUP failed to complete the command BACKUP DATABASE DB1. Check the backup application log for detailed messages.

 Example 2

 05/06/2011 10:57:44,spid83,Unknown,DBCC TRACEOFF 3605<c/> server process ID (SPID) 83. This is an informational message only; no user action is required.

05/06/2011 10:57:44,spid83,Unknown,DBCC TRACEOFF 3004<c/> server process ID (SPID) 83. This is an informational message only; no user action is required.

05/06/2011 10:57:40,Backup,Unknown,BACKUP failed to complete the command BACKUP DATABASE DB2. Check the backup application log for detailed messages.

05/06/2011 10:03:12,spid83,Unknown,Backup:Copying data

05/06/2011 10:03:12,spid83,Unknown,BackupDatabase: Configuration section done

05/06/2011 10:03:12,spid83,Unknown,BackupDatabase: Work estimates done

05/06/2011 10:03:12,spid83,Unknown,BackupDatabase: Checkpoint done

05/06/2011 10:03:11,spid83,Unknown,Backup: Streams open

05/06/2011 10:03:11,spid83,Unknown,BackupDatabase: Database DB2

05/06/2011 10:03:02,spid83,Unknown,DBCC TRACEON 3605<c/> server process ID (SPID) 83. This is an informational message only; no user action is required.

05/06/2011 10:03:02,spid83,Unknown,DBCC TRACEON 3004<c/> server process ID (SPID) 83. This is an informational message only; no user action is required.

Read More on Disk IO troubleshooting

 SQL Server - Disk IO performance and SQLIO - SQL Server DBA

SQL Server - IO Requests taking longer than 15 seconds to complete

Calculate disk IO throughput and MB per second - SQL Server DBA

SQL Server Storage and IO performance - SQL Server DBA