Here is a structure that is at least very close.
There is no programmatic way to get the parameters (unfortunately). You need to format them into XML to pass in.
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`.
You get ObjectID to pass in from `@@PROCID`.
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 that is created at the beginning of the "logged" stored procedure. 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't get generated again.
**Cleanup (optional) and Schema**
/* -- optional cleanup
DROP PROCEDURE [dbo].[ProcessLogDemo];
DROP PROCEDURE [Logging].[ProcessLog_Log];
DROP PROCEDURE [Logging].[ProcessLog_Start];
DROP PROCEDURE [Logging].[ProcessLog_Stop];
DROP TABLE [Logging].[ProcessLog];
DROP TABLE Logging.[Status];
DROP SCHEMA [Logging];
*/
CREATE SCHEMA [Logging];
GO
**Tables and Indexes**
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
**Stored Procedure to call at the very beginning of "logged" stored procedures**
<!-- language: lang-sql -->
CREATE PROCEDURE [Logging].[ProcessLog_Start]
(
@ProcessGUID UNIQUEIDENTIFIER,
@DatabaseID INT,
@ObjectID INT,
@Params XML
)
AS
SET NOCOUNT ON;
-- First, make sure that there is no existing record
IF (EXISTS(SELECT *
FROM [Logging].[ProcessLog] pl
WHERE pl.[ProcessGUID] IS NOT NULL -- might be needed to use filtered index
AND pl.[ProcessGUID] = @ProcessGUID
))
BEGIN
DECLARE @GuidString CHAR(36) = CONVERT(CHAR(36), @ProcessGUID);
RAISERROR(N'ProcessGUID {%s} already exists.
[ProcessLog_Start] is being called more than once, or something else went wrong.',
16, 1, @GuidString);
RETURN;
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(), @ProcessGUID);
GO
**Stored Procedure to call after all but the final step**
<!-- language: lang-sql -->
CREATE PROCEDURE [Logging].[ProcessLog_Log]
(
@ProcessGUID UNIQUEIDENTIFIER,
@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] = @ProcessGUID;
IF (@@ROWCOUNT = 0)
BEGIN
DECLARE @GuidString CHAR(36) = CONVERT(CHAR(36), @ProcessGUID);
RAISERROR('No initial or in-process record for ProcessGUID {%s}!', 16, 1, @GuidString);
RETURN;
END;
GO
**Stored Procedure to call after the final step and/or in a CATCH block**
<!-- language: lang-sql -->
CREATE PROCEDURE [Logging].[ProcessLog_Stop]
(
@ProcessGUID UNIQUEIDENTIFIER,
@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] = @ProcessGUID;
IF (@@ROWCOUNT = 0)
BEGIN
DECLARE @GuidString CHAR(36) = CONVERT(CHAR(36), @ProcessGUID);
RAISERROR('No initial or in-process record for ProcessGUID {%s}!', 16, 1, @GuidString);
RETURN;
END;
GO
**Demo stored procedure (input parameters are formatted as XML)**
The reason for putting "StepNumber" in a variable is so that the value can get passed to the `CATCH` block. The `@StepNumber` variable is incremented prior to each operation. If the operation succeeds, that value is used to call the "Log" stored procedure that captures the number of rows affected for that step and the time it was called. If the operation fails, that same `@StepNumber` value is used to call the "Stop" stored procedure that marks the process as "failed" and passes in the error message. This makes the data less confusing since the `Step` column on failed records will be the step it was actually working on when the error occurred.
CREATE PROCEDURE [dbo].[ProcessLogDemo]
(
@Param1 INT,
@Param2 DATETIME,
@Param3 NVARCHAR(50) = NULL
)
AS
SET NOCOUNT ON;
DECLARE @GUID UNIQUEIDENTIFIER = NEWID(),
@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 = @GUID,
@DatabaseID = @DB_ID,
@ObjectID = @@PROCID,
@Params = @Params;
SET @StepNumber = 1;
-- do something
EXEC [Logging].[ProcessLog_Log]
@ProcessGUID = @GUID,
@Step = @StepNumber,
@RowsSelected = @@ROWCOUNT;
SET @StepNumber = 2;
-- do something else
EXEC [Logging].[ProcessLog_Log]
@ProcessGUID = @GUID,
@Step = @StepNumber,
@RowsUpdated = @@ROWCOUNT;
SET @StepNumber = 3;
-- do final thingy
EXEC [Logging].[ProcessLog_Stop]
@ProcessGUID = @GUID,
@Step = @StepNumber,
@StatusID = 3, -- success
@RowsInserted = @@ROWCOUNT;
END TRY
BEGIN CATCH
DECLARE @ErrorMessage NVARCHAR(MAX) = ERROR_MESSAGE();
EXEC [Logging].[ProcessLog_Stop]
@ProcessGUID = @GUID,
@Step = @StepNumber,
@StatusID = 4, -- fail
@Remarks = @ErrorMessage;
END CATCH;
GO
NOTES:
* 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.
* 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.