Job history template using SQL Server Agent tokens

To log the execution and output from all steps in a SQL Server Agent job into a single logfile, you can use SQL Server tokens and macros to create the logfile in the default SQL Server LOG-folder, and let each jobstep add their output to the file. The default SQL Server LOG-folder is also the folder where SQL Server places Errorlog files (ERRORLOG.nn) and tracefiles (.trc) from default trace.

The first jobstep is a dummy step that only initialize the logfile on a normal job execution.
The jobstep can be created with
EXECUTE [msdb].[dbo].[sp_add_jobstep]
@job_id=@jobId,
@step_name=N'Job Begin',
@step_id=1,
@cmdexec_success_code=0,
@on_success_action=3,
@on_success_step_id=0,
@on_fail_action=2,
@on_fail_step_id=0,
@retry_attempts=0,
@retry_interval=0,
@os_run_priority=0,
@subsystem=N'TSQL',
@command=N'DECLARE @errmsg nvarchar(2047);
SET @errmsg = LEFT(CONVERT(nvarchar(128), GETUTCDATE(), 127), 22) + N''Z : Job Begin...'';
RAISERROR(@errmsg,0,0) WITH NOWAIT;',
@database_name=N'master',
@output_file_name=N'$(ESCAPE_SQUOTE(SQLDIR))\LOG\MacroTest.$(ESCAPE_SQUOTE(STRTDT))T$(ESCAPE_SQUOTE(STRTTM)).log',
@flags=0;
The output filename is created in the default SQL Server Log with „$(ESCAPE_SQUOTE(SQLDIR))\LOG\“ and the name of the file is created with a name like the jobname, a timestamp and the filetype „log“.
I miss two things as a token; the jobname and the time where the job began in UTC. Right now I will have to enter a jobname manually and take care of the local time when we switch between summer- and wintertime (Daylight saving time).
The logfiles initial output is generated by a RAISERROR call. Please notice that I give the errormessage a UTC timestamp in a ISO 8601 format.

A actual job step will the add the output to the logfile. A jobstep could be created with
EXECUTE [msdb].[dbo].[sp_add_jobstep]
@job_id=@jobId,
@step_name=N'Job Execution 01',
@step_id=2,
@cmdexec_success_code=0,
@on_success_action=3,
@on_success_step_id=0,
@on_fail_action=2,
@on_fail_step_id=0,
@retry_attempts=0,
@retry_interval=0,
@os_run_priority=0,
@subsystem=N'TSQL',
@command=N'DECLARE @errmsg nvarchar(2047);
SET @errmsg = LEFT(CONVERT(nvarchar(128), GETUTCDATE(), 127), 22) + N''Z : Job Executing {01}...'';
RAISERROR(@errmsg,0,0) WITH NOWAIT;',
@database_name=N'master',
@output_file_name=N'$(ESCAPE_SQUOTE(SQLDIR))\LOG\MacroTest.$(ESCAPE_SQUOTE(STRTDT))T$(ESCAPE_SQUOTE(STRTTM)).log',
@flags=2;
The value 2 to the parameter @flag append the output to the logfile.

When the job has executed all (real) steps, the logfile is ended a dummy step, that enter a final timestamp. This can be used for execution time comparisons. The jobstep can be created with
EXECUTE [msdb].[dbo].[sp_add_jobstep]
@job_id=@jobId,
@step_name=N'Job End',
@step_id=3,
@cmdexec_success_code=0,
@on_success_action=1,
@on_success_step_id=0,
@on_fail_action=2,
@on_fail_step_id=0,
@retry_attempts=0,
@retry_interval=0,
@os_run_priority=0,
@subsystem=N'TSQL',
@command=N'DECLARE @errmsg nvarchar(2047);
SET @errmsg = LEFT(CONVERT(nvarchar(128), GETUTCDATE(), 127), 22) + N''Z : Job End.'';
RAISERROR(@errmsg,0,0) WITH NOWAIT;',
@database_name=N'master',
@output_file_name=N'$(ESCAPE_SQUOTE(SQLDIR))\LOG\MacroTest.$(ESCAPE_SQUOTE(STRTDT))T$(ESCAPE_SQUOTE(STRTTM)).log',
@flags=2;

A execution of a job with three steps where one is the actual job execution could generate a output like this
Job 'MacroTest' : Step 1, 'Job Begin' : Began Executing 2012-11-28 08:21:51

2012-11-28T07:21:51.95Z : Job Begin... [SQLSTATE 01000]
Job 'MacroTest' : Step 2, 'Job Execution 01' : Began Executing 2012-11-28 08:21:51

2012-11-28T07:21:51.98Z : Job Executing {01}... [SQLSTATE 01000]
Job 'MacroTest' : Step 3, 'Job End' : Began Executing 2012-11-28 08:21:52

2012-11-28T07:21:52.01Z : Job End. [SQLSTATE 01000]
If the job is started from another step than the initial step, the output is still caught in a logfile. In this case a new file is created implicit by adding output to it. A partial execution could generate a output like this
Job 'MacroTest' : Step 2, 'Job Execution 01' : Began Executing 2012-11-28 09:50:21

2012-11-28T08:50:21.81Z : Job Executing {01}... [SQLSTATE 01000]
Job 'MacroTest' : Step 3, 'Job End' : Began Executing 2012-11-28 09:50:21

2012-11-28T08:50:21.84Z : Job End. [SQLSTATE 01000]

SQL Server Agent tokens and macros are documented in „Use Tokens in Job Steps“ on MSDN Library.

A more complex and dynamic creation of SQL Server Agent jobsteps can be studied in the SQL Server Maintenance Solution from Ola Hallengren.