Processamento de procedimentos armazenados e log de erros

Aqui está uma estrutura que é pelo menos muito próxima.

Não há nenhuma maneira programática de obter os parâmetros (infelizmente). Você precisa formatá-los em XML para passar.

O Login que inicia um trabalho do SQL Agent parece ser registrado apenas na messagecoluna de msdb.dbo.sysjobhistory, para step_id = 0. Este valor pode ser extraído, mas não durante a execução do trabalho.

Você obtém ObjectID para passar de @@PROCID.

Abaixo está o esquema (2 tabelas) e procedimentos armazenados (3 procs). O conceito é separar o log "init", "em processo" e "concluído (sucesso ou erro)". Isso permite definir certas colunas apenas no momento apropriado (por exemplo, só é necessário definir DatabaseID, StartedAt, etc. no início). Separar o tipo de evento também facilita a lógica específica do evento (sim, pode ter até mesmo em um único procedimento, mas você ainda tem todos os parâmetros de entrada quando precisa apenas de um subconjunto para cada tipo de evento).

Um registro de "processo" é atualizado por meio de seu valor IDENTITY (e PK em cluster). Este é outro benefício de ter a separação de "tipo de evento": torna muito mais fácil manipular a captura SCOPE_IDENTITY()e passá-lo de volta para ser usado para os outros dois procedimentos armazenados de registro. Se um procedimento armazenado falhar e não for para o CATCHbloco, não há necessidade de se preocupar em atualizar acidentalmente esse registro de processo, pois na próxima vez que qualquer procedimento armazenado (que está sendo registrado) for iniciado, ele obterá um ID novo/exclusivo atualizar.

Limpeza (opcional) e Esquema

/* -- 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

Tabelas e Índices

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
);
GO

Procedimento armazenado para chamar no início de procedimentos armazenados "logados"

CREATE PROCEDURE [Logging].[ProcessLog_Start]
(
  @DatabaseID INT,
  @ObjectID INT,
  @Params XML,
  @ProcessLogID INT = NULL OUTPUT
)
AS
SET NOCOUNT ON;

-- First, capture the MAX "instance_id" from sysjobhistory if this process is a SQL
-- Server Agent job (use later to get the "invoked by" Login), else grab the Login.
DECLARE @StartedBy [sysname];

IF (EXISTS(
           SELECT *
           FROM   sys.dm_exec_sessions sdes
           WHERE  sdes.[session_id] = @@SPID
           AND    sdes.[program_name] LIKE N'SQLAgent - TSQL JobStep (%'))
BEGIN
  DECLARE @JobID UNIQUEIDENTIFIER;

  SELECT @JobID = CONVERT(UNIQUEIDENTIFIER, 
                           CONVERT(BINARY(16),
                                   SUBSTRING(sdes.[program_name],
                                        CHARINDEX(N'(Job 0x', sdes.[program_name]) + 5,
                                             34), 1
                                  )
                          )
  FROM  sys.dm_exec_sessions sdes
  WHERE sdes.[session_id] = @@SPID;

--SELECT @JobID;

  SELECT @StartedBy = N'sysjobhistory.instance_id: '
                       + CONVERT(NVARCHAR(20), MAX(sjh.[instance_id]))
  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])
VALUES (@DatabaseID, @ObjectID, 0, 1, @Params, @StartedBy);

SET @ProcessLogID = SCOPE_IDENTITY();
GO

Procedimento armazenado para chamar depois de tudo, mas a etapa final

CREATE PROCEDURE [Logging].[ProcessLog_Log]
(
  @ProcessLogID INT,
  @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(@RowsInserted, pl.[RowsInserted]),
       pl.[RowsUpdated] = ISNULL(@RowsUpdated, pl.[RowsUpdated]),
       pl.[RowsDeleted] = ISNULL(@RowsDeleted, pl.[RowsDeleted])
FROM   [Logging].[ProcessLog] pl
WHERE  pl.[ProcessLogID] = @ProcessLogID;

IF (@@ROWCOUNT = 0)
BEGIN
 RAISERROR('No initial or in-process record for ProcessLogID = %d !', 16, 1,
           @ProcessLogID);
  RETURN;
END;
GO

Procedimento armazenado para chamar após a etapa final e/ou em um bloco CATCH

CREATE PROCEDURE [Logging].[ProcessLog_Stop]
(
  @ProcessLogID INT,
  @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])
FROM   [Logging].[ProcessLog] pl
WHERE  pl.[ProcessLogID] = @ProcessLogID;

IF (@@ROWCOUNT = 0)
BEGIN
 RAISERROR('No initial or in-process record for ProcessLogID = %d !', 16, 1,
           @ProcessLogID);
  RETURN;
END;
GO

Procedimento armazenado de demonstração (os parâmetros de entrada são formatados como XML)

A razão para colocar "StepNumber" em uma variável é para que o valor possa ser passado para o CATCHbloco. A @StepNumbervariável é incrementada antes de cada operação. Se a operação for bem-sucedida, esse valor é usado para chamar o procedimento armazenado "Log" que captura o número de linhas afetadas por essa etapa e a hora em que foi chamada. Se a operação falhar, esse mesmo @StepNumbervalor é usado para chamar o procedimento armazenado "Stop" que marca o processo como "falha" e transmite a mensagem de erro. Isso torna os dados menos confusos, pois a Stepcoluna nos registros com falha será a etapa em que ela estava realmente trabalhando quando ocorreu o erro.

CREATE PROCEDURE [dbo].[ProcessLogDemo]
(
  @Param1 INT,
  @Param2 DATETIME,
  @Param3 NVARCHAR(50) = NULL
)
AS
SET NOCOUNT ON;

DECLARE @ProcessID 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]
    @DatabaseID = @DB_ID,
    @ObjectID = @@PROCID,
    @Params = @Params,
    @ProcessLogID = @ProcessID OUTPUT;

  SET @StepNumber = 1;

  -- do something

  EXEC [Logging].[ProcessLog_Log]
    @ProcessLogID = @ProcessID,
    @Step = @StepNumber,
    @RowsSelected = @@ROWCOUNT;

  SET @StepNumber = 2;

  -- do something else

  EXEC [Logging].[ProcessLog_Log]
    @ProcessLogID = @ProcessID,
    @Step = @StepNumber,
    @RowsUpdated = @@ROWCOUNT;

  SET @StepNumber = 3;

  -- do final thingy

  EXEC [Logging].[ProcessLog_Stop]
    @ProcessLogID = @ProcessID,
    @Step = @StepNumber,
    @StatusID = 3, -- success
    @RowsInserted = @@ROWCOUNT;

END TRY
BEGIN CATCH
  DECLARE @ErrorMessage NVARCHAR(MAX) = ERROR_MESSAGE();

  EXEC [Logging].[ProcessLog_Stop]
    @ProcessLogID = @ProcessID,
    @Step = @StepNumber,
    @StatusID = 4, -- fail
    @Remarks = @ErrorMessage;
END CATCH;
GO

NOTAS:

• Com relação à obtenção do logon "invocado por" para trabalhos do SQL Server Agent: o step_id = 0registro (que é o único local onde essas informações existem) não existe até que o trabalho seja concluído (sucesso ou falha). Portanto, ele não está disponível enquanto o procedimento armazenado está em execução, muito menos no início. Por enquanto, capturamos o MAX(sjh.[instance_id]) FROM msdb.dbo.sysjobhistory sjhtrabalho atualmente em execução para a sessão atual. Mais tarde (ou seja, após a conclusão do trabalho), isso pode ser substituído pelo Login do invocador do trabalho.

• Eu geralmente não recomendaria adicionar esse tipo de log a procedimentos armazenados que são executados com muita frequência, pois as operações adicionais de leitura e gravação terão um impacto negativo no desempenho.

TERMO ADITIVO

Aqui está uma função de valor de tabela embutida (ITVF) para obter as informações do resultado do trabalho (incluindo o usuário "invocado por" ou agendamento ou qualquer outro) com base no instance_idvalor que foi capturado na ProcessLog.StartedBycoluna. O instance_idvalor retornado no conjunto de resultados é a linha para step_id = 0.

CREATE FUNCTION dbo.GetSqlServerAgentJobOutcome
(
  @InstanceID INT
)
RETURNS TABLE
AS RETURN

WITH cte AS
(
  SELECT TOP (1)
         sjh.[instance_id],
         sjh.job_id,
         sjh.[message],
         sjh.[run_date],
         sjh.[run_time],
         sjh.[run_duration],
         sjh.[run_status],
         sjh.[sql_message_id],
         sjh.[sql_severity],
         (CHARINDEX(N' was invoked by ', sjh.[message]) + 16) AS [invoker_begin],
         CHARINDEX(N'.  The last step to run', sjh.[message]) AS [invoker_end]
  FROM   msdb.dbo.sysjobhistory  sjh
  WHERE  sjh.[job_id] = (SELECT sjh2.[job_id]
                         FROM   msdb.dbo.sysjobhistory sjh2
                         WHERE  sjh2.[instance_id] = @InstanceID)
  AND    sjh.[step_id] = 0
  AND    sjh.[instance_id] >= @InstanceID
  ORDER BY instance_id ASC
)
SELECT [instance_id], [job_id],
       --[message],
       [run_date], [run_time],
       [run_duration], [run_status],
       [sql_message_id], [sql_severity],
       SUBSTRING([message], invoker_begin, ([invoker_end] - [invoker_begin]))
          AS [InvokedBy]
FROM   cte;
GO