存储过程处理和错误日志

mou*_*iin 5 audit stored-procedures architecture sql-server-2014 logging

我曾经在一家拥有第三方数据仓库解决方案的公司工作。显然所有的对象和表都隐藏在支持数据库中,所以我不清楚某些存储过程中究竟发生了什么。我在那里看到了这个有趣的存储过程,并想在我自己的解决方案中复制它,但我无法理解它是如何工作的。我正在描述下面的存储过程,如果有人能给我一些关于如何实现这一点的想法,这将非常有帮助。如果你能建议我如何使这更好,那就更好了。

存储过程被称为进程日志。它有 DBID、ObjectId、Step、Status、Remarks、Reads、Inserts、Updates、Delete 等参数

我们要做的是,在每个存储过程中,我们必须执行这个存储过程,状态为 2(进行中)在增加值后,在每个步骤或部分结束时可​​以多次执行这个存储过程的过程的可变步长。根据插入更新选择和删除语句的行数,我们应该在各自的存储过程参数变量中记录值。最后,您可以执行状态为 3(已完成)的相同存储过程,或者如果该过程在 catch 块中结束,状态将为 4(失败)在备注部分,我们可以复制 SQL 的错误消息。

为了查看所有这些信息,我们获得了一份报告的访问权限,显然我没有源代码,但报告显示了存储过程完成的时间,状态是多少插入更新删除和读取它做过。如果失败,错误信息是什么?

我已经有一些改进存储的想法,谁开始的?,参数的值是多少?对于谁开始存储过程部分,我有一个困惑。大多数这些存储过程作为不同作业的一部分运行。我们所有的作业都以服务帐户用户身份运行,但作业由不同的用户手动启动。我需要找出哪个用户启动了它,作为内部存储过程,作为当前用户,它将始终显示服务帐户。同样对于参数值,是否有更好的动态方法来找出这一点?而不是手动设置变量的值。我想使用 INPUTBUFFER 的输出,但它只显示参数的名称而不是值。

如果有人可以指导我有关此审计 SP 的后端表结构和脚本,那将非常有帮助。也欢迎任何更多的改进想法。

我的主要困惑:我相信他们有一些存储这些存储过程值的表,如果 SP 已经在运行,他们会在记录中进行更新,然后进行插入,但是他们如何识别在场景中进行插入而不是更新其中存储过程严重失败并且未执行 catch 块。

Sol*_*zky 5

这是一个至少非常接近的结构。

没有获得参数的编程方式(不幸的是)。您需要将它们格式化为 XML 才能传入。

启动 SQL 代理作业的登录似乎只记录在, formessage列中。可以提取此值,但不能在作业执行期间提取。msdb.dbo.sysjobhistorystep_id = 0

您获得 ObjectID 以从@@PROCID.

下面是架构(2 个表)和存储过程(3 个过程)。这个概念是将“init”、“in process”和“completed (success or error)”日志分开。这使得只有在适当的时间设置某些列(例如,只需要一套DatabaseIDStartedAt等在开始的时候)。分离事件类型还可以更轻松地拥有特定于事件的逻辑(是的,即使在单个过程中也可以拥有它,但是当您只需要每个事件类型的一个子集时,您仍然拥有所有输入参数)。

“进程”记录通过其 IDENTITY(和集群 PK)值进行更新。这是具有“事件类型”分离的另一个好处:它可以更轻松地处理捕获SCOPE_IDENTITY()并将其传回以用于其他两个日志记录存储过程。如果存储过程失败并且没有转到CATCH块,那么无需担心意外更新该过程记录,因为下次任何存储过程(正在记录)启动时,它将获得一个新的/唯一的 ID更新。

清理(​​可选)和架构

/* -- 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
Run Code Online (Sandbox Code Playgroud)

表和索引

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
Run Code Online (Sandbox Code Playgroud)

在“记录”存储过程的最开始调用的存储过程

/* -- 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
Run Code Online (Sandbox Code Playgroud)

除了最后一步之外,要调用存储过程

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
Run Code Online (Sandbox Code Playgroud)

在最后一步和/或在 CATCH 块中调用的存储过程

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
Run Code Online (Sandbox Code Playgroud)

演示存储过程(输入参数格式为XML)

将“StepNumber”放入变量的原因是为了将值传递给CATCH块。该@StepNumber变量在每次操作之前递增。如果操作成功,则该值用于调用“Log”存储过程,该过程捕获该步骤受影响的行数和调用时间。如果操作失败,@StepNumber则使用相同的值调用“Stop”存储过程,该过程将过程标记为“失败”并传入错误消息。这使得数据不那么混乱,因为Step失败记录上的列将是发生错误时它实际处理的步骤。

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
Run Code Online (Sandbox Code Playgroud)

笔记:

  • 关于获取 SQL Server 代理作业的“调用者”登录名:step_id = 0在作业完成(成功或失败)之前,记录(这是此信息存在的唯一位置)不存在。因此,它在存储过程运行时不可用,更不用说在开始时了。现在,我们MAX(sjh.[instance_id]) FROM msdb.dbo.sysjobhistory sjh为当前会话捕获当前正在执行的作业。稍后(即在作业完成后),它可以被作业调用程序 Login 替换。

  • 我通常建议不要将这种类型的日志记录添加到非常频繁执行的存储过程中,因为额外的读写操作会对性能产生负面影响。


附录

这是一个内联表值函数 (ITVF),用于根据instance_id捕获到ProcessLog.StartedBy列中的值获取作业结果信息(包括“调用者”或计划或其他信息)。instance_id结果集中返回的值是 的行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
Run Code Online (Sandbox Code Playgroud)