Light weight SQL Server procedure auditing without using SQL Server auditing version 2

  • Article

 

(The project is attached to this blog post, if you have any questions, feel free to send me a mail. You find the bits for download here.)

The most recent version can be found here

For all of you who haven´t been able to read my blog entry on logging yet, I suggest you to read the first version of the blog entry located here. It basically described the options for doing logging in your database and why I came up with this solution for you to share. To summarize the purpose of this logging solution, here are the basic steps:

The solution

The solution includes several procedures which need to be added to the database:

  • Log.SpApplyLoggingToStoredProcs
    Read the object definition of a stored proc and adds logging code, the logging code will write to a logging table information like
    • Which procedure was called
    • From which application
    • From which host
    • From which User
    • With which parameters
    • When the procedure was left
  • Log.SpRemoveLoggingFromProcedure
    • Removes the code snippet from the stored procs
  • Log.SpLogParameters
    • The procedure which simply does the Log insert
  • Log.SpUpdateLoggingForEndDate
    • If selected this will update the end time of the procedure call

In addition, these views are added in the database for getting the valuable information:

  • Log.v_ProcedureExecutionLog
    Getting the raw log information as well as the execute string to replay the proc
  • Log.v_ProcedureExecutionLog_PValues
    Getting the normalized parameter data from the log table
  • Log.v_ProcedureExecutionStats
    Getting valueable execution statistics about the procedure calls

You are sure free to add any Views that might fit your needs better. I f yes, let me know to include them for the public as well.

Performance

As being used in some projects now, the performance penalty you have from inserting logging information was that small, that you didn´t notice it at all compared to the execution of the procedure as a whole. The duration for doing the log plumbing was around ms only.

How to include this in your project

The easiest way for doing this is to take the project included to this blog entry and export that as a partial file project. (Partial project are a flavor of database projects in Visual Studio) This partial file project can be included then in your database project your are (hopefully) maintaining with Visual Studio Database projects. If you do want to include partial files in your project you can also achieve it by executing the procedures needed from´the project file on your database. If somebody is interested how to achieve adding it with a partial project and you need help on that, I will post the relevant information in a separate blog post.

How does it look like ?

Taking a really simple sample procedure which looks like:

 

image

the Logger will add the following to it:

image

This might seem much to you, but this is all done automatically and can be removed again with the removal procedure. Beside that, you business code may also be a bit longer than the comment in here Smile

After calling the procedure several times with varying parameters:

image

You can query the different views to get all the information about the calls:

The view [Log].[v_ProcedureExecutionLog] contains information of:

  • CallId
  • DatabaseName
  • ProcedureSchema
  • ProcedureName
  • CallTime
  • EndCallTime
  • CallingUser
  • CallingApplication
  • LoggingParameters
  • LoggingValues
  • ExecString
  • ExecStringRC

The interesting part is the time and the exec string, with this you can select the top xx worst queries and directly execute it:

image

The view [Log].[v_ProcedureExecutionLog_PValues] contains detailed information of:

  • CallID
  • DatabaseName
  • ProcedureSchema
  • ProcedureName
  • PName
  • PValue
  • CallTime
  • EndCallTime
  • CallingUser
  • CallingApplication
  • LoggingParameters
  • LoggingValues

image

The view [Log].[v_ProcedureExecutionLog_Stats] contains aggregated information of:

  • ProcedureName
  • ExecCount
  • LastRunUTC_DT
  • MaxRuntimeMS
  • AvgRuntimeMS
  • MinRuntimeMS
  • ExecString
  • ExecStringRC
  • LoggingParameters
  • LoggingValues

image

 

A really nice projects which helps you to track executions without using  profiler trace / server side trace or Change tracking due to limitations of the edition you are using.Feel free to give any comments and feedback.

You find the bits for download here.

-Jens