Log4net, ADONetAppender and Stored Procedure: Set Precision & Scale?

Question

Combination of what I assume is small things are stopping my application from database logging as I expect it.

• The Text command works. Both INSERT and EXEC commands work and data gets entered into the database
• if I uncomment ExecutionTime parameter it stops working., I know that one was working at some point, but I can't figure out why uncommenting the parameter, much less adding it, causes the Appender to fail silently.
• • Found error now that debug is working. Listed below and updated with addition of Precision and Scale.
• I'm trying to enable internal debugging and it doesn't seem to want to work. Found the issue. Moved the config sections to the right place (not under log4net).
• If I switch commandType to StoredProcedure it stops working, even tho the text version works
• • Still an issue. Trying different things, but haven't had much luck

SQL:

DROP TABLE [LOG];
GO
CREATE TABLE [dbo].[LOG] (
     [Id] [int] IDENTITY(1,1) NOT NULL
    ,[Origin] [varchar](55) null
    ,[LogDate] [datetime] NOT NULL
    ,[Thread] [varchar](32) NOT NULL
    ,[Context] [varchar](10) NOT NULL
    ,[Level] [varchar](10) NOT NULL
    ,[Logger] [varchar](255) NOT NULL
    ,[Message] [varchar](4000) Not NULL
    ,[MethodName] [varchar](200) NULL
    ,[Parameters] [varchar](4000) NULL
    ,[Exception] [varchar](4000) NULL
    ,[ExecutionTime] [decimal](14, 4) NULL
)
GO

DROP PROCEDURE InsertLog
GO
CREATE PROCEDURE [dbo].[InsertLog]
     @LogDate DateTime
    ,@Thread varchar(32)
    ,@Context varchar(10)
    ,@Level varchar(10)
    ,@Logger varchar(255)
    ,@Message varchar(4000)
    ,@MethodName varchar(200) = null
    ,@Parameters varchar(4000) = null
    ,@Exception varchar(4000) = null
    ,@ExecutionTime decimal(14,4) = null
AS
BEGIN
    SET NOCOUNT ON;

    INSERT INTO [dbo].[LOG] ([Origin],[LogDate],[Thread],[Level],[Logger],[Message],[MethodName],[Parameters],[Exception],[Context]) 
    VALUES ('InsertLog',@LogDate, @Thread, @Level, @Logger, @Message, @MethodName, @Parameters, @Exception, @Context)
END
GO

App.config

<?xml version="1.0" encoding="utf-8"?>
<configuration>
    <configSections>
        <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" />
        ...
    </configSections>
    <connectionStrings>...</connectionStrings>
    <applicationSettings>...</applicationSettings>
    <log4net configSource="Log4Net.config" />
<appSettings>
    <add key="log4net.Internal.Debug" value="true" />
</appSettings>
<system.diagnostics>
    <trace autoflush="true">
        <listeners>
            <add name="textWriterTraceListener" type="System.Diagnostics.TextWriterTraceListener" initializeData=".\log4net.log" />
        </listeners>
    </trace>
</system.diagnostics>
</configuration>

log4net.config

<?xml version="1.0" encoding="utf-8" ?>
<log4net>
    <root>
        <level value="ALL" />
        <!-- ColoredConsoleAppender works, so It's not listed below -->
        <appender-ref ref="ColoredConsoleAppender"/>
        <appender-ref ref="ADONetAppender" />
        <appender-ref ref="OutputDebugStringAppender" />
        <appender-ref ref="TraceAppender" />
    </root>
    <appender name="ADONetAppender" type="log4net.Appender.ADONetAppender">
        <threshold value="ALL"/>
        <bufferSize value="1" />
        <lossy value="false"/>
        <param name="UseTransactions" value="False" />
        <connectionType value="System.Data.SqlClient.SqlConnection, System.Data, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089"/>
        <connectionString value="..." />
        <!--<commandText value="
            INSERT INTO [Log] ([Origin],[LogDate],[Thread],[Context],[Level],[Logger],[Message],[MethodName],[Parameters],[Exception])
            VALUES ('ADONetAppender',@log_date,@thread,@Context,@Level,@Logger,@Message,@MethodName,@Parameters,@Exception);"
        />-->
        <commandText value="
            exec InsertLog @log_date,@thread,@Context,@Level,@Logger,@Message,@MethodName,@Parameters,@Exception;"
        />
        <!--<commandType value="StoredProcedure" />-->
        <!--<commandText value="InsertLog" />-->
        <parameter name="LogDate">
            <parameterName value="@log_date"/>
            <dbType value="DateTime"/>
            <layout type="log4net.Layout.RawTimeStampLayout"/>
        </parameter>
                    ...
        <!-- This causes appender to fail silently. -->
        <parameter name="ExecutionTime">
            <parameterName value="@ExecutionTime"/>
            <dbType value="Decimal"/>
            <precision value="14"/>
            <scale value="4"/>
            <layout type="log4net.Layout.PatternLayout" value="%property{execution_time}" />
        </parameter>
    </appender>
    <appender name="OutputDebugStringAppender" type="log4net.Appender.OutputDebugStringAppender">
        <layout type="log4net.Layout.PatternLayout">
            <conversionPattern value="%date %-5level %logger (%file:%line) - %message%newline" />
        </layout>
    </appender>
    <appender name="TraceAppender" type="log4net.Appender.TraceAppender">
        <layout type="log4net.Layout.PatternLayout">
            <conversionPattern value="%date %-5level - %message%newline" />
        </layout>
    </appender>
</log4net>

Update 1 Now that I have the Trace thingy working... it's complaining that the DB Command needs explicitly set precision and scale. Not sure how to do that, since none of the examples I've seen have that set

log4net:ERROR [AdoNetAppender] ErrorCode: GenericFailure. Could not prepare database command [ exec InsertLog @log_date,@thread,@Context,@Level,@Logger,@Message,@MethodName,@Parameters,@Exception; ] System.InvalidOperationException: SqlCommand.Prepare method requires parameters of type 'Decimal' have an explicitly set Precision and Scale. at System.Data.SqlClient.SqlParameter.Prepare(SqlCommand cmd) at System.Data.SqlClient.SqlCommand.Prepare() at log4net.Appender.AdoNetAppender.InitializeDatabaseCommand()

Update 2 With the addition of Precision/Scale the error changes. It now complains:

log4net:ERROR [AdoNetAppender] ErrorCode: GenericFailure. Failed in DoAppend System.FormatException: Failed to convert parameter value from a String to a Decimal. ---> System.FormatException: Input string was not in a correct format.

Answer 1

There are two parameters that are part of the AdoNetAppenderParameter class you can add to your ExecutionTime parameter in the xml file, Precision and Scale:

<parameter name="ExecutionTime">
    <parameterName value="@ExecutionTime"/>
    <dbType value="Decimal"/>
    <precision value="14"/>
    <scale value="4"/>
    <layout type="log4net.Layout.PatternLayout" value="%property{execution_time}" />
</parameter>

Answer 2

• Enabled debuggin and found the complaint about Precision and Scale
• Next up was NULL values. They are turned into the literal (null) and it chokes on translating that into a decimal.
• Converted Log4net.config to STRING and added some conversion logic to Stored Procedure
• Converted ExecutionTime to Int since the code I'm using is in Milliseconds.

SQL:

    DROP TABLE [LOG];
    GO
    CREATE TABLE [dbo].[LOG] (
         [Id] [int] IDENTITY(1,1) NOT NULL
        ,[LogDate] [datetime] NOT NULL
        ,[Thread] [varchar](32) NOT NULL
        ,[Level] [varchar](10) NOT NULL
        ,[Logger] [varchar](255) NOT NULL
        ,[Message] [varchar](4000) NOT NULL
        ,[Exception] [varchar](4000) NULL
        ,[Context] [varchar](10) NULL
        ,[MethodName] [varchar](200) NULL
        ,[Parameters] [varchar](4000) NULL
        ,[ExecutionTime] int NULL
        --,[Origin] [varchar](55) NOT NULL
        --,[ExecutionRaw] [varchar](4000) NULL
    )
    GO

    DROP PROCEDURE InsertLog
    GO
    CREATE PROCEDURE [dbo].[InsertLog]
         @LogDate DateTime
        ,@Thread varchar(32)
        ,@Level varchar(10)
        ,@Logger varchar(255)
        ,@Message varchar(4000)
        ,@Exception varchar(4000) = null
        ,@Context varchar(10) = null
        ,@MethodName varchar(200) = null
        ,@Parameters varchar(4000) = null
        ,@ExecutionTime varchar(32) = null
    AS
    BEGIN
        SET NOCOUNT ON;
        --DECLARE @ETChar varchar(32); set @ETChar = @ExecutionTime;

        if @Exception     = '' set @Exception = null;
        if @Context       = '(null)' set @Context = null;
        if @MethodName    = '(null)' set @MethodName = null;
        if @Parameters    = '(null)' set @Parameters = null;        
        if @ExecutionTime = '(null)' set @ExecutionTime = null;

        DECLARE @ETInt int;          set @ETInt  = convert(int, @ExecutionTime);

        INSERT INTO [dbo].[LOG] (
             [LogDate]
            ,[Thread]
            ,[Level]
            ,[Logger]
            ,[Message]
            ,[Exception]
            ,[Context]
            ,[MethodName]
            ,[Parameters]
            ,[ExecutionTime]
            --,[Origin]
            --,[ExecutionRaw]
            )
        VALUES (
             @LogDate
            ,@Thread
            ,@Level
            ,@Logger
            ,@Message
            ,@Exception
            ,@Context
            ,@MethodName
            ,@Parameters
            ,@ETInt
            --,'InsertLog'
            --,@ETChar
            )

        SET NOCOUNT OFF;
    END
    GO

    DROP INDEX [IX_LEVEL] ON [LOG]
    GO
    CREATE NONCLUSTERED INDEX [IX_Level] ON [dbo].[LOG] ( [Level] ASC ); 
    GO

Log4Net.config:

<?xml version="1.0" encoding="utf-8"?>

<log4net>
  <root>
    <level value="DEBUG" />
    <appender-ref ref="ADONetAppender" />
  </root>
  <appender name="ADONetAppender" type="log4net.Appender.ADONetAppender">
    <threshold value="ALL" />
    <bufferSize value="1" />
    <lossy value="false" />
    <param name="UseTransactions" value="False" />
    <connectionType value="System.Data.SqlClient.SqlConnection, System.Data, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089" />
    <connectionString value="..." />
    <commandType value="StoredProcedure" />
    <commandText value="InsertLog" />
    <parameter name="LogDate">
      <parameterName value="@LogDate" />
      <dbType value="DateTime" />
      <layout type="log4net.Layout.RawTimeStampLayout" />
    </parameter>
    <parameter name="Thread">
      <parameterName value="@Thread" />
      <dbType value="String" />
      <size value="32" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%thread" />
      </layout>
    </parameter>
    <parameter name="Level">
      <parameterName value="@Level" />
      <dbType value="String" />
      <size value="10" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%level" />
      </layout>
    </parameter>
    <parameter name="Logger">
      <parameterName value="@Logger" />
      <dbType value="String" />
      <size value="255" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%logger" />
      </layout>
    </parameter>
    <parameter name="Message">
      <parameterName value="@Message" />
      <dbType value="String" />
      <size value="4000" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%message" />
      </layout>
    </parameter>
    <parameter name="Exception">
      <parameterName value="@Exception" />
      <dbType value="String" />
      <size value="4000" />
      <layout type="log4net.Layout.ExceptionLayout" />
    </parameter>
    <parameter name="Context">
      <parameterName value="@Context" />
      <dbType value="String" />
      <size value="10" />
      <layout type="log4net.Layout.PatternLayout" value="%x" />
    </parameter>
    <parameter name="MethodName">
      <parameterName value="@MethodName" />
      <dbType value="String" />
      <size value="200" />
      <layout type="log4net.Layout.PatternLayout" value="%property{method_name}" />
    </parameter>
    <parameter name="Parameters">
      <parameterName value="@Parameters" />
      <dbType value="String" />
      <size value="4000" />
      <layout type="log4net.Layout.PatternLayout" value="%property{properties}" />
    </parameter>
    <parameter name="ExecutionTime">
      <parameterName value="@ExecutionTime" />
      <dbType value="String" />
      <size value="32" />
      <layout type="log4net.Layout.PatternLayout" value="%property{execution_time}" />
    </parameter>
  </appender>
</log4net>