Programming Answer: How to log in T-SQL

I'm using ADO.NET to access SQL Server 2005 and would like to be able to log from inside the T-SQL stored procedures that I'm calling. Is that somehow possible?

I'm unable to see output from the 'print'-statement when using ADO.NET and since I want to use logging just for debuging the ideal solution would be to emit messages to DebugView from SysInternals.

From stackoverflow

You can either log to a table, by simply inserting a new row, or you can implement a CLR stored procedure to write to a file.

Be careful with writing to a table, because if the action happens in a transaction and the transaction gets rolled back, your log entry will disappear.

HLGEM : What we did to avoid the problem of the logging disappearing is to write log entries to a table variable then insert the table variable data into the log table after the transaction is committed or rolled back.
Logging from inside a SQL sproc would be better done to the database itself. T-SQL can write to files but it's not really designed for it.
I think writing to a log table would be my preference.

Alternatively, as you are using 2005, you could write a simple SQLCLR procedure to wrap around the EventLog.

Or you could use xp_logevent if you wanted to write to SQL log
There's the PRINT command, but I prefer logging into a table so you can query it.
You could use output variables for passing back messages, but that relies on the proc executing without errors.
```
create procedure usp_LoggableProc 

@log varchar(max) OUTPUT 

as

-- T-SQL statement here ...

select @log = @log + 'X is foo'
```
And then in your ADO code somehwere:
```
string log = (string)SqlCommand.Parameters["@log"].Value;
```
You could use raiserror to create your own custom errors with the information that you require and that will be available to you through the usual SqlException Errors collection in your ADO code:
```
RAISERROR('X is Foo', 10, 1)
```
Hmmm but yeah, can't help feeling just for debugging and in your situation, just insert varchar messages to an error table like the others have suggested and select * from it when you're debugging.
You can write rows to a log table from within a stored procedure. As others have indicated, you could go out of your way to write to some text file or other log with CLR or xp_logevent, but it seems like you need more volume than would be practical for such uses.

The tough cases occur (and it's these that you really need your log for) when transactions fail. Since any logging that occurs during these transactions will be rolled back along with the transaction that they are part of, it is best to have a logging API that your clients can use to log errors. This can be a simple DAL that either logs to the same database, or to a shared one.

-- The following DDL sql will create you the table to store the log data USE [db] GO

/****** Object:  Table [dbo].[tbData_Debug]    Script Date: 02/12/2009 22:30:03 ******/
SET ANSI_NULLS ON
GO

SET QUOTED_IDENTIFIER ON
GO

SET ANSI_PADDING ON
GO

CREATE TABLE [dbo].[tbData_Debug](
    [colTimeStamp] [timestamp] NULL,
    [colNiceTime] [varchar](200) NULL,
    [colDomain_User] [varchar](200) NULL,
    [colMsg] [varchar](4000) NULL,
    [colDebugLevel] [int] NULL,
    [colDebugMsg] [varchar](4000) NULL,
    [colPageName] [varchar](200) NULL,
    [colClassName] [varchar](200) NULL,
    [colMethodName] [varchar](200) NULL,
    [colMethodNameGui] [varchar](4000) NULL,
    [colRet] [int] NULL,
    [colLineNumber] [int] NULL,
    [colLineNumberGui] [int] NULL,
    [colProcedureName] [varchar](200) NULL,
    [colProcedureStep] [varchar](4000) NULL
) ON [PRIMARY]

GO

SET ANSI_PADDING OFF
GO




-- This stored procedure does write to the log table

USE [db]
GO
/****** Object:  StoredProcedure [dbo].[procUtils_AppDebug]    Script Date: 02/12/2009 22:29:24 ******/
SET ANSI_NULLS ON
GO
SET QUOTED_IDENTIFIER ON
GO

ALTER PROCEDURE [dbo].[procUtils_AppDebug] (                  

@ret int = null OUT,     
@msgIn varchar(4000) = null ,   -- the msg which the user has seen   
@msgOut varchar(4000) = null OUT ,   -- the msg which the user has seen   
@domain_user varchar(200) = null ,                 -- the domain user echoing the message  
@debugMsgIn varchar(4000) = null  ,   -- the debug msg for internal use  
@debugMsgOut varchar(4000) = null  OUT,   -- the debug msg for internal use  
@pageName varchar(200) = null ,   -- the pageName originator of error  
@className varchar(200) = null ,   -- the class Name orinator of error  
@methodName varchar(200) = null ,   -- the methodName where the last error occured  
@methodNameGui varchar(4000) = null ,   -- the methodNameOfTheGui where the last error occured  
@lineNumber int = null ,  -- the line number of the line issueing the error  
@lineNumberGui int = null,   -- the line number of the line issueing the error               
@procedureName varchar(200) = null , -- the procedureName currently envoked
@procedureStep varchar(4000)  = null -- the steps of the procedure concatenated
)    

AS                  
BEGIN -- proc start                
 SET NOCOUNT ON;                

BEGIN TRY        --begin try      

declare @debugLevel int     
select @debugLevel =  Debug_Level from User_tb where Domain_Name = @domain_user  

/*                  
select * from tbData_Debug    order by 1 desc              
delete from tbData_Debug              
*/    


insert into tbData_Debug ( colNiceTime , colDomain_User , colMsg , colDebugLevel ,   
colDebugMsg , colPageName , colClassName , colMethodName , colMethodNameGui ,   
colRet , colLineNumber , colLineNumberGui , colProcedureName , colProcedureStep) values (
 dbo.funcGetNiceTime() , @domain_user  , @msgIn , @debugLevel ,@debugMsgIn , 
 @pageName , @className , @methodName  ,@MethodNameGui , @ret , 
 @lineNumber , @lineNumberGui , @procedureName , @procedureStep)     

set @debugMsgOut = @debugMsgIn  
set @msgOut = 'Action Registered'  
set @ret = @@ERROR     
return @ret                



END TRY        --end try      

BEGIN CATCH            
 PRINT 'In CATCH block.             
 Error number: ' + CAST(ERROR_NUMBER() AS varchar(10)) + '            
 Error message: ' + ERROR_MESSAGE() + '            
 Error severity: ' + CAST(ERROR_SEVERITY() AS varchar(10)) + '            
 Error state: ' + CAST(ERROR_STATE() AS varchar(10)) + '            
 XACT_STATE: ' + CAST(XACT_STATE() AS varchar(10));            

 set  @debugMsgOut = 'error at [procUtils_AppDebug]--- Error number: ' + CAST(ERROR_NUMBER() AS varchar(10)) + 'Error message: ' + ERROR_MESSAGE() + 'Error severity: ' +   
CAST(ERROR_SEVERITY() AS varchar(10)) + 'Error state: ' + CAST(ERROR_STATE() AS varchar(10)) + 'XACT_STATE: ' + CAST(XACT_STATE() AS varchar(10))            
set @msgIn= 'error while saving application error info into database'  
insert into tbData_Debug ( colMsg ) values ( @msgIn )     

set @debugMsgOut = @debugMsgIn +  @debugMsgOut  
set @msgOut = 'Action Registration failed'  
set @ret = 1           

END CATCH            


return  @ret                       
END --procedure end                 

/*       
<procedureDocumentation>      

<procedurename>procUtils_AppDebug<procedurename>      
<procedureDescription> Records events from the Application Layer </procedureDescription>    
<created>20090121</created>      
<createdby>Yordan Georgiev</createdby>      
<change>      

<changewhen><changewhen>      
<changeDescription></changeDescription>      
<changedBy></changedBy>      
</change>      


<testUsage>    

USE [db]    
GO    

DECLARE @return_value int,    
  @ret int,    
  @msgIn varchar(max),    
  @debugmsg varchar(4000)    

SELECT @ret = 1    
SELECT @msgIn = N'msg'    
SELECT @debugmsg = N'before'    

EXEC @return_value = [dbo].[procUtils_AppDebug]    
  @ret = @ret OUTPUT,    
  @msgIn = @msgIn OUTPUT,    
  @domain_user = N'domain_user',    
  @debugmsg = @debugmsg OUTPUT,    

  @methodName = N'methodName'    

SELECT @ret as N'@ret',    
  @msgIn as N'@msgIn',    
  @debugmsg as N'@debugmsg'    

SELECT 'Return Value' = @return_value    
select * from tbData_Debug order by 1 desc    
GO    

</testUsage>      
</procedureDocumentation>      
*/

I solved this by writing a SQLCLR-procedure as Eric Z Beard suggested. The assembly must be signed with a strong name key file.

using System;
using System.Data;
using System.Data.SqlClient;
using System.Data.SqlTypes;
using Microsoft.SqlServer.Server;

public partial class StoredProcedures
{
    [Microsoft.SqlServer.Server.SqlProcedure]
    public static int Debug(string s)
    {
        System.Diagnostics.Debug.WriteLine(s);
            return 0;
        }
    }
}

Created a key and a login:

USE [master]
CREATE ASYMMETRIC KEY DebugProcKey FROM EXECUTABLE FILE =
'C:\..\SqlServerProject1\bin\Debug\SqlServerProject1.dll'

CREATE LOGIN DebugProcLogin FROM ASYMMETRIC KEY DebugProcKey 

GRANT UNSAFE ASSEMBLY TO DebugProcLogin

Imported it into SQL Server:

USE [mydb]
CREATE ASSEMBLY SqlServerProject1 FROM
'C:\..\SqlServerProject1\bin\Debug\SqlServerProject1.dll' 
WITH PERMISSION_SET = unsafe

CREATE FUNCTION dbo.Debug( @message as nvarchar(200) )
RETURNS int
AS EXTERNAL NAME SqlServerProject1.[StoredProcedures].Debug

Then I was able to log in T-SQL procedures using

exec Debug @message = 'Hello World'

Learning : ha ha .. this surely needs to be classifies as bug. Accepting your own answer :)

For what it's worth, I've found that when I don't assign an InfoMessage handler to my SqlConnection:

sqlConnection.InfoMessage += new SqlInfoMessageEventHandler(MySqlConnectionInfoMessageHandler);

where the signature of the InfoMessageHandler looks like this:

MySqlConnectionInfoMessageHandler(object sender, SqlInfoMessageEventArgs e)

then my PRINT statements in my Stored Procs do not appear in DbgView.
You may want to check Log4TSQL. It provides Database-Logging for Stored Procedures and Triggers in SQL Server 2005 - 2008. You have the possibility to set separate, independent log-levels on a per Procedure/Trigger basis.

Sincerely, Daniel Pavic

Programming Answer

Thursday, March 31, 2011

How to log in T-SQL

0 comments:

Post a Comment

Blog Archive