Fastcopy – Scheduling through Scripting

Background

Have a need to schedule weekly restoration of Production DB unto BETA.

As our DB is a bit big, I just did not want to use DOS Copy/XCOPY and so was happy that fastcopy is already available on server.

Code

List of files

  1. Files.txt
    • full file names of each source file
    • Delimited by newline
  2. CopyFiles.cmd
    • Invokes the fastcopy.exe
    • Added options not to display error message as we will be scheduling on Server and so UI will be counter-productive
    • Added speed=7
      • Files are copied in parallel and if we are not careful, we can overwhelm network
  3. RestoreDB.cmd
    • Calls copyfiles.cmd
    • Pause
      • Added pause and left it commented out
      • Will enable it, if we need to debug MS Windows Task Scheduler

 

Files.txt


\\HRDBPROD\SQLBackups\HRDB\HRDB.bak

CopyFiles.cmd


set "app=D:\Downloads\FastCopy\FastCopy311_x64\fastcopy.exe"

@rem set "srcfile=D:\Scripts\SyncFiles\Backup\files.txt"
set "_HOME_DIR=%CD%"

set "_srcfile=files.txt"
set "_srcfileFull=%_HOME_DIR%\%_srcfile%"
set "_logFolder=%_HOME_DIR%\log\"

set "_destFolder=F:\Microsoft\SQLServer\SQLRestore"

@rem if Folder Log does not exist, please create it
if not exist log mkdir log

@rem Initiate Fastcopy
%app% /cmd=diff ^
	 /srcfile=%_srcfileFull% ^
         /auto_close /force_close ^
	 /estimate ^
	 /no_ui ^
	 /no_confirm_del ^
	 /no_confirm_stop ^
	 /log=true ^
	 /logfile=%_logFolder%\fastcopy.log ^
	 /filelog=%_logFolder%\filecopy.log ^
	 /speed=7 ^
	 /to=%_destFolder%"

RestoreDB.cmd

copyfiles.cmd
@rem pause

Fastcopy Log files

Fastcopy produces plentiful throughput and error info.

There are two file fastcopy.log and filecopy.log

fastcopy.log

Here is what fastcopy.log looks like:

fastcopy

 

Monitoring

Windows Task Manager

WindowsTaskManager-20160513-0918AM

Explanation

  1. Our process, fastcopy.exe, is using some I/O

Resource Monitor

One can monitor ongoing network and IO throughput via built-in MS Windows Resource Monitor.

Disk

ResourceMonitor-20160513-0847AM

Explanation

  1. Note that Image is not fastcopy.exe, but the system
  2. We are getting about 150MB/sec for our copying process
  3. Overall 180 MB/sec IO

 

Network

ResourceMonitor-NetworkIO-20160513-0907AM

 

Explanation

  1. Again, Image is not fastcopy.exe, but the system
  2. Remote Port is 445
  3. Marked Latency

It seems obvious that Network IO is not reflecting true and overall Network I/O

 

Scheduling

MS Windows Task Scheduler

Task – General

Customization

  1. Pay attention to “Configure for:
    • You are given the choices of
      • Windows 7, Windows Server 2008 R2
      • Windows Vista, Windows Server 2008
    • To avoid errors, please choose “Windows Server 2008” even on “Windows Server 2008/R2

 

Task-General

 

Task-General-ConfigureFor

 

Event Viewer

Looking through MS Windows Event Viewer is a great way to troubleshoot scheduled tasks.

The specific branch to look at is Microsoft-Windows-TaskScheduler/Operational

Branch

Branch-Microsoft-Windows

Branch-Microsoft-Windows-TaskScheduler-Operational

 

Filter

Again, there is a lot to choose from and so please filter on …

Filtering Elements

  1. Event ID :-
    • ID is 201
      • 201 means “Action Completed
    • User is the name the task is scheduled to “run as”

 

FilterCurrentLog

Sample Entries

Return Code – 4294967295

EventDetails-4294967295

Return Code – 1

EventDetails-1

Return Code – 0

EventDetails-0

 

Interpretation

Log – General Causation
 Task Scheduler successfully completed task “\Corp\Restore DB” , instance “{76835bc9-9cb6-4d08-82ae-1bbe783f4d71}” , action “C:\Windows\SYSTEM32\cmd.exe” with return code 4294967295. Invalid arguments passed to fast copy
 Task Scheduler successfully completed task “\Corp\Restore DB” , instance “{482d0822-91ea-43a3-abce-fd7a53d14e1d}” , action “C:\Windows\SYSTEM32\cmd.exe” with return code 1. The Task has been configured for “Windows 7, MS Windows 2008/R2“.  Please configure for “Windows Vista, MS Windows 2008“.
 Task Scheduler successfully completed task “\Corp\Restore DB” , instance “{a4c53952-7caa-49f9-8df2-85b11b259b13}” , action “C:\Windows\SYSTEM32\cmd.exe” with return code 0.  We are good

 

 

Performance Comparison

Microsoft Windows 2008/R2

Xcopy


set appLogger="D:\Program Files (x86)\GnuWin32\bin\tee.exe"
set _appLoggerOption=--append 
set "_HOME_DIR=%CD%"
set "_LOG_FOLDER=%CD%\LOG"
set "_LOG_FILE=%CD%\LOG\benchmark_%DATEANDTIME%.log"
set "_SRC_FILES=\\HRDB\f$\SQLBackups\*.bak"
set "_DEST_FOLDER=F:\Microsoft\SQLServer\SQLRestore\"
set "_OPTIONS_XCOPY=/D /Y"

if not exist %_LOG_FOLDER% mkdir %_LOG_FOLDER%

set DATESTAMP=%DATE:~10,4%_%DATE:~4,2%_%DATE:~7,2%
set TIMESTAMP=%TIME:~0,2%_%TIME:~3,2%_%TIME:~6,2%
set DATEANDTIME=%DATESTAMP%_%TIMESTAMP%

ECHO "Before Copy %DATEANDTIME%  .... " | %appLogger% %_appLoggerOption% %_LOG_FILE%

xcopy %_SRC_FILES%  %_DEST_FOLDER% %_OPTIONS_XCOPY% | %appLogger% %_appLoggerOption% %_LOG_FILE%

set DATESTAMP=%DATE:~10,4%_%DATE:~4,2%_%DATE:~7,2%
set TIMESTAMP=%TIME:~0,2%_%TIME:~3,2%_%TIME:~6,2%
set DATEANDTIME=%DATESTAMP%_%TIMESTAMP%

ECHO "After Copy %DATEANDTIME%" | %appLogger% %_appLoggerOption% %_LOG_FILE%

Resource Monitor

Disk I/O

xcopy-Disk-20160526-0939AM

 

Network I/O

xcopy-network-20160526-0939AM

 

Performance Monitor

PerfomanceMonitor-20160526-1212

 

Matrix

 

Tool Disk I/O Network I/O Time Taken
 fastcopy 165 MB/sec 4 Hours 30 minutes
 xcopy 110 MB/sec  115 MB/sec 1 Hour

 

 

Summary

I think the SMB protocol has been greatly optimized in MS Windows 2008/R2 and later OS and so this only applies to OSes prior to that version .

Even if then…

Leave a Reply

Please log in using one of these methods to post your comment:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s