x002548's Blog

Not Just a Number - Brett Kaiser
posts - 89, comments - 586, trackbacks - 39

Stored Procedure Logging

Every so often, someone asks, "How do I know who executed a SQL Statement against my database".

Well you can either have SQL Profiler running all the time (which can be very expensive), or you can use Lumingent's Log Explorer.

I have taken a different tack lately.

Any Access to a database I am supporting will be done ONLY Through stored procedures.  OK, that's not "lately", but the part I've added is that the developers MUST call the sproc below.  What this does is to log every stored procedure call.  I now have statistics as to what's being called when, and how long the operation takes.  There are several benefits, but the best being that I can see which developers don't have their thinking cap on in dev, and we can proactiveley review these sprocs.

OK, now you say, how do you know that developer is callin the logging sproc, and the short answer is, that in dev, I don't.  However, No sprocs get moved to QA without a reivew by me or someone on the DBA team.  Once it's in QA, they can't touch the code.  After QA Sign off, the that code gets moved to UAT, then up to PROD.

In any case I find it useful, and the execution of the logging is in the microseconds.  I guess the downside of a app that gets slammed with millions of hits is that this could add up and affect performance, but shy of that, we have not noticed any impact.  In any case, for what it's worth here's the sproc and the table DDL.  One other note, I do this on other platforms as well, for example DB2 OS/390...only problem there is the need to monitor the tablespace for this table, since you coul blow out on extents...which is not really a problem on SQL Server...except that you potentially could run out of disk space...In either case, you need to monitor that, and archive the data.  Any comments are appreciated.

if exists (select * from dbo.sysobjects where id = object_id(N'[dbo].[usp_LogProcCalls]') and OBJECTPROPERTY(id, N'IsProcedure') = 1)
drop procedure [dbo].[usp_LogProcCalls]
GO

SET QUOTED_IDENTIFIER OFF
GO
SET ANSI_NULLS ON
GO


CREATE PROCEDURE [dbo].[usp_LogProcCalls] (
   @SprocName  sysname
 , @TranStart  datetime
 , @TranEnd  datetime
 , @Rows  int
 , @Err   int
 , @Paramters varchar(255)
 , @rc   int OUTPUT)
AS
SET NOCOUNT ON

Declare @error int, @RowCount int, @Error_Message varchar(255), @Error_Type int, @Error_Loc int

BEGIN TRAN
 DECLARE @LogStart datetime
 SELECT @rc = 0, @LogStart = GetDate()
  IF (SELECT @@TRANCOUNT) <> 1
   BEGIN
    SELECT @Error_Loc = 1
         , @Error_Message =  'The logging procedure must be executed outside of any transaction.  @@TRANSCOUNT='
   + CONVERT(varchar(5),@@TRANCOUNT)
         , @Error_Type = 50002, @rc = -6661
    GOTO usp_LogProcCalls_Error
   END

 INSERT INTO Sproc_Log (
   [SprocName]
 , [TranStart]
 , [TranEnd]
 , [LogStart]
 , [LogEnd]
 , [Rows]
 , [Err]
 , [Paramters])
 SELECT
   @SprocName
 , @TranStart
 , @TranEnd
 , @LogStart
 , GetDate()
 , @Rows
 , @Err
 , @Paramters

  Select @RowCount = @@ROWCOUNT, @error = @@error
 
  IF @error <> 0
   BEGIN
    SELECT @Error_Loc = 2, @Error_Type = 50001, @rc = -6662
    GOTO usp_LogProcCalls_Error
   END
 
  IF @RowCount <> 1
   BEGIN
    SELECT @Error_Loc = 3
         , @Error_Message =  'Expected 1 row to be inserted in to the sproc log.  Actual Number inserted = '
   + CONVERT(varchar(5),@RowCount)
         , @Error_Type = 50002, @rc = -6663
    GOTO usp_LogProcCalls_Error
   END

COMMIT TRAN

usp_LogProcCalls_Exit:

RETURN

usp_LogProcCalls_Error:

Rollback TRAN

If @Error_Type = 50001
 BEGIN

  Select @error_message = (Select 'Location: ' + ',"' + RTrim(Convert(char(3),@Error_Loc)) 
          + ',"' + '  @@ERROR: ' + ',"' + RTrim(Convert(char(6),error))
          + ',"' + ' Severity: ' + ',"' + RTrim(Convert(char(3),severity))
          From master..sysmessages
        Where error = @error)
 END

If @Error_Type = 50002

 BEGIN
  Select @Error_Message = 'Location: ' + ',"' + RTrim(Convert(char(3),@Error_Loc))
                   + ',"' + ' Severity:  UserLevel '
              + ',"' + ' Message: ' + ',"' + RTrim(@Error_Message)
 END

RAISERROR @Error_Type @Error_Message

GOTO usp_LogProcCalls_Exit
GO
SET QUOTED_IDENTIFIER OFF
GO
SET ANSI_NULLS ON
GO

 

if exists (select * from dbo.sysobjects where id = object_id(N'[dbo].[Sproc_Log]') and OBJECTPROPERTY(id, N'IsUserTable') = 1)
drop table [dbo].[Sproc_Log]
GO

CREATE TABLE [dbo].[Sproc_Log] (
 [SprocName] [sysname] NOT NULL ,
 [TranStart] [datetime] NOT NULL ,
 [TranEnd] [datetime] NOT NULL ,
 [SYSTEM_USER] [char] (30) COLLATE SQL_Latin1_General_CP1_CI_AS NOT NULL ,
 [LogStart] [datetime] NOT NULL ,
 [LogEnd] [datetime] NOT NULL ,
 [Rows] [int] NOT NULL ,
 [Err] [int] NOT NULL ,
 [Paramters] [varchar] (255) COLLATE SQL_Latin1_General_CP1_CI_AS NULL
) ON [PRIMARY]
GO

 

 

Print | posted on Thursday, September 21, 2006 9:38 AM | Filed Under [ SQL Server ]

Feedback

Gravatar

# re: Stored Procedure Logging

I like this idea very much but hit an error when compiling the sProc:

Msg 137, Level 15, State 1, Procedure usp_LogProcCalls, Line 78
Must declare the scalar variable "@error_message".
9/25/2006 10:55 AM | Tom Hamilton
Gravatar

# re: Stored Procedure Logging

Case ! Change @error_message to @Error_Message
fixes problem
9/25/2006 10:57 AM |
Gravatar

# re: Stored Procedure Logging

Sorry, my databases are never set up to be Case Sensitive...I mean, what's the point

9/26/2006 1:36 PM | Brett
Gravatar

# re: Stored Procedure Logging

how do call a stored procedure with out parameters. i.e
Procedure proeno (Peno IN Number,
PEname IN Varchar2,
Sal OUT Number)
AS
Leno number(7);
LEname varchar2(10);
Lsal Number(10,2);
Begin
select eno,ename,sal into Leno,LEname,Lsal from emp where eno = peno;
end;
to execute this i have 2 pass values .
& wat shud the out parameter values shud be.
12/4/2006 4:03 AM | pankaj
Comments have been closed on this topic.

Powered by:
Powered By Subtext Powered By ASP.NET