The Login that initiates a SQL Agent job seems to only be logged in the message column of msdb.dbo.sysjobhistory, for step_id = 0. This value can probably be extracted if ORIGINAL_LOGIN() = NT SERVICE\SQLSERVERAGENT, but not during the execution of the job.
Below is the schema (2 tables) and stored procedures (3 procs). The concept is to separate "init", "in process", and "completed (success or error)" logging. This allows for setting certain columns only at the appropriate time (e.g. only need to set DatabaseID, StartedAt, etc at the very beginning). Separating the type of event also makes it easier to have event-specific logic (yes, can have it even in a single proc, but then you still have all the input parameters when you only need a subset per each event-type).
A "process" record get updated via a GUID thatits IDENTITY (and clustered PK) value. This is created at the beginninganother benefit of having the "logged""event type" separation: it makes it much easier to handle capturing the SCOPE_IDENTITY() and passing it back to be used for the two other logging stored procedureprocedures. If a stored procedure fails and doesn't go to the CATCH block, then there is no need to worry about accidentally updating that process record as that GUID won'tthe next time any stored procedure (that is being logged) starts, it will get generated againa new / unique ID to update.
CREATE TABLE Logging.[Status]
(
[StatusID] TINYINT NOT NULL
CONSTRAINT [PK_Status] PRIMARY KEY CLUSTERED,
[StatusName] VARCHAR(50) NOT NULL
);
CREATE TABLE [Logging].[ProcessLog]
(
ProcessLogID INT NOT NULL IDENTITY(-2147483648, 1) -- start at INT min value
CONSTRAINT [PK_ProcessLog] PRIMARY KEY CLUSTERED,
DatabaseID INT NOT NULL,
ObjectID INT NULL, -- NULL = ad hoc query
SessionID SMALLINT NOT NULL
CONSTRAINT [DF_ProcessLog_SessionID] DEFAULT (@@SPID),
Step TINYINT NOT NULL, -- if you have more than 255 steps, consult psychiatrist
StatusID TINYINT NOT NULL
CONSTRAINT [FK_ProcessLog_Status]
FOREIGN KEY REFERENCES [Logging].[Status]([StatusID]),
Remarks NVARCHAR(MAX) NULL, -- or maybe VARCHAR(MAX)?
Params XML NULL,
RowsSelected INT NULL,
RowsInserted INT NULL,
RowsUpdated INT NULL,
RowsDeleted INT NULL,
StartedBy [sysname] NULL,
StartedAt DATETIME2 NOT NULL
CONSTRAINT [DF_ProcessLog_StartedAt] DEFAULT (SYSDATETIME()),
UpdatedAt DATETIME2 NULL, -- use to show progress / "heartbeat"
StoppedAt DATETIME2 NULL,
ProcessGUID UNIQUEIDENTIFIER NULL -- NULL = Completed (Success or Fail)
);
CREATE NONCLUSTERED INDEX [IX_ProcessLog_ProcessGUID]
ON [Logging].[ProcessLog](ProcessGUID ASC)
WHERE [ProcessGUID] IS NOT NULL; -- omit completed entries (keeps index smaller / faster)
GO
CREATE PROCEDURE [Logging].[ProcessLog_Start]
(
@ProcessGUID UNIQUEIDENTIFIER,
@DatabaseID INT,
@ObjectID INT,
@Params XML,
@ProcessLogID INT = NULL OUTPUT
)
AS
SET NOCOUNT ON;
-- First, makecapture surethe thatMAX there"instance_id" from sysjobhistory if this process is noa existingSQL
-- recordServer Agent job (use later to get the "invoked by" Login), else grab the Login.
DECLARE @StartedBy [sysname];
IF (EXISTS(
SELECT *
FROM [Logging]sys.[ProcessLog]dm_exec_sessions plsdes
WHERE plsdes.[ProcessGUID][session_id] IS= NOT@@SPID
NULL -- might be needed to use filtered index
AND sdes.[program_name] LIKE N'SQLAgent - TSQL ANDJobStep (%'))
BEGIN
DECLARE @JobID pl.[ProcessGUID]UNIQUEIDENTIFIER;
SELECT @JobID = @ProcessGUIDCONVERT(UNIQUEIDENTIFIER,
) CONVERT(BINARY(16)
BEGIN,
DECLARE @GuidString CHAR SUBSTRING(36)sdes.[program_name],
= CONVERT CHARINDEX(CHARN'(36Job 0x', sdes.[program_name]) + 5,
@ProcessGUID 34);, 1
RAISERROR(N'ProcessGUID {%s} already exists. )
[ProcessLog_Start] is being called more than once, or something else went wrong )
FROM sys.dm_exec_sessions sdes
WHERE sdes.[session_id] = @@SPID;
--SELECT @JobID;
SELECT @StartedBy = N'sysjobhistory.instance_id: ',
16, 1 + CONVERT(NVARCHAR(20), @GuidStringMAX(sjh.[instance_id]);)
RETURN;FROM msdb.dbo.sysjobhistory sjh
WHERE sjh.[job_id] = @JobID;
END;
ELSE
BEGIN
SET @StartedBy = ORIGINAL_LOGIN();
END;
-- Now it should be safe to create a new entry
INSERT INTO [Logging].[ProcessLog] ([DatabaseID], [ObjectID], [Step], [StatusID],
[Params], [StartedBy], [ProcessGUID])
VALUES (@DatabaseID, @ObjectID, 0, 1, @Params, ORIGINAL_LOGIN(@StartedBy),;
SET @ProcessGUID@ProcessLogID = SCOPE_IDENTITY();
GO
CREATE PROCEDURE [Logging].[ProcessLog_Log]
(
@ProcessGUID@ProcessLogID UNIQUEIDENTIFIERINT,
@Step TINYINT,
@RowsSelected INT = NULL,
@RowsInserted INT = NULL,
@RowsUpdated INT = NULL,
@RowsDeleted INT = NULL
)
AS
SET NOCOUNT ON;
UPDATE pl
SET pl.[StatusID] = 2, -- In process
pl.[Step] = @Step,
pl.[UpdatedAt] = SYSDATETIME(),
pl.[RowsSelected] = ISNULL(@RowsSelected, pl.[RowsSelected]),
pl.[RowsInserted] = ISNULL(@RowsSelected, pl.[RowsInserted]),
pl.[RowsUpdated] = ISNULL(@RowsSelected, pl.[RowsUpdated]),
pl.[RowsDeleted] = ISNULL(@RowsSelected, pl.[RowsDeleted])
FROM [Logging].[ProcessLog] pl
WHERE pl.[ProcessGUID] IS NOT NULL -- might be needed to use filtered index
AND pl.[ProcessGUID][ProcessLogID] = @ProcessGUID;@ProcessLogID;
IF (@@ROWCOUNT = 0)
BEGIN
DECLARE @GuidString CHAR(36) = CONVERT(CHAR(36), @ProcessGUID);
RAISERROR('No initial or in-process record for ProcessGUIDProcessLogID {%s}= %d !', 16, 1, @GuidString@ProcessLogID);
RETURN;
END;
GO
CREATE PROCEDURE [Logging].[ProcessLog_Stop]
(
@ProcessGUID@ProcessLogID UNIQUEIDENTIFIERINT,
@Step TINYINT,
@StatusID TINYINT,
@Remarks NVARCHAR(MAX) = NULL,
@RowsSelected INT = NULL,
@RowsInserted INT = NULL,
@RowsUpdated INT = NULL,
@RowsDeleted INT = NULL
)
AS
SET NOCOUNT ON;
UPDATE pl
SET pl.[StatusID] = @StatusID, -- 3 = Success, 4 = Fail
pl.[Step] = @Step,
pl.[Remarks] = @Remarks,
pl.[StoppedAt] = SYSDATETIME(),
pl.[RowsSelected] = ISNULL(@RowsSelected, pl.[RowsSelected]),
pl.[RowsInserted] = ISNULL(@RowsSelected, pl.[RowsInserted]),
pl.[RowsUpdated] = ISNULL(@RowsSelected, pl.[RowsUpdated]),
pl.[RowsDeleted] = ISNULL(@RowsSelected, pl.[RowsDeleted]),
pl.ProcessGUID = NULL
FROM [Logging].[ProcessLog] pl
WHERE pl.[ProcessGUID] IS NOT NULL -- might be needed to use filtered index
AND pl.[ProcessGUID][ProcessLogID] = @ProcessGUID;@ProcessLogID;
IF (@@ROWCOUNT = 0)
BEGIN
DECLARE @GuidString CHAR(36) = CONVERT(CHAR(36), @ProcessGUID);
RAISERROR('No initial or in-process record for ProcessGUIDProcessLogID {%s}= %d !', 16, 1, @GuidString@ProcessLogID);
RETURN;
END;
GO
CREATE PROCEDURE [dbo].[ProcessLogDemo]
(
@Param1 INT,
@Param2 DATETIME,
@Param3 NVARCHAR(50) = NULL
)
AS
SET NOCOUNT ON;
DECLARE @GUID UNIQUEIDENTIFIER =@ProcessID NEWID()INT,
@DB_ID INT = DB_ID(),
@Params XML,
@StepNumber TINYINT;
SET @Params = (
SELECT @Param1 AS [Param1],
@Param2 AS [Param2],
@Param3 AS [Param3]
FOR XML PATH(N'Params')
); -- missing elements mean the value == NULL
--SELECT @Params;
BEGIN TRY
EXEC [Logging].[ProcessLog_Start]
@ProcessGUID@DatabaseID = @GUID@DB_ID,
@DatabaseID@ObjectID = @DB_ID@@PROCID,
@ObjectID@Params = @@PROCID@Params,
@Params@ProcessLogID = @Params;@ProcessID OUTPUT;
SET @StepNumber = 1;
-- do something
EXEC [Logging].[ProcessLog_Log]
@ProcessGUID@ProcessLogID = @GUID@ProcessID,
@Step = @StepNumber,
@RowsSelected = @@ROWCOUNT;
SET @StepNumber = 2;
-- do something else
EXEC [Logging].[ProcessLog_Log]
@ProcessGUID@ProcessLogID = @GUID@ProcessID,
@Step = @StepNumber,
@RowsUpdated = @@ROWCOUNT;
SET @StepNumber = 3;
-- do final thingy
EXEC [Logging].[ProcessLog_Stop]
@ProcessGUID@ProcessLogID = @GUID@ProcessID,
@Step = @StepNumber,
@StatusID = 3, -- success
@RowsInserted = @@ROWCOUNT;
END TRY
BEGIN CATCH
DECLARE @ErrorMessage NVARCHAR(MAX) = ERROR_MESSAGE();
EXEC [Logging].[ProcessLog_Stop]
@ProcessGUID@ProcessLogID = @GUID@ProcessID,
@Step = @StepNumber,
@StatusID = 4, -- fail
@Remarks = @ErrorMessage;
END CATCH;
GO
- I will try to incorporate the "initiating Login" for SQL Agent jobs tomorrow.
- Good news: I can extract the "The Job was invoked by User" username from
sysjobhistory.
- Bad news: the
step_id = 0 record does not exist until the job completes (success or failure), so it isn't available while the stored procedure is running, let alone at the beginning. For now we can capture the MAX(sjh.[instance_id]) FROM msdb.dbo.sysjobhistory sjh. Later, that can get replaced with the job invoker Login.
With regards to getting the "invoked by" Login for SQL Server Agent jobs: the step_id = 0 record (which is the only place that this info exists) does not exist until the job completes (success or failure). Hence, it isn't available while the stored procedure is running, let alone at the beginning. For now we capture the MAX(sjh.[instance_id]) FROM msdb.dbo.sysjobhistory sjh for the currently executing job for the current session. Later (i.e. after the job completes), that can get replaced with the job invoker Login.
- I would generally recommend against adding this type of logging to Stored Procedures that are executed very frequently as the additional read and write operations will have a negative impact on performance.
- And I just realized that it might even be easier to grab the new
ProcessLogID via SCOPE_IDENTITY() in the "Start" stored procedure, pass it back as an OUTPUT parameter, and use that instead of the GUID. I will make that change tomorrow. I would generally recommend against adding this type of logging to Stored Procedures that are executed very frequently as the additional read and write operations will have a negative impact on performance.
