log4net:ERROR [AdoNetAppender] ErrorCode: GenericFailure. Exception while writing to database

Question

I've been having a issue with Log4net on my server. FYI - The Web Development server has SQL installed on it. I have coded and implemented on my local dev machine and it logs to my local db without issue. I deployed all code and scripts to the server environment. Log4net is not logging to SQL at all, for whatever reason. I re-configured my local machine to use the SQL on the development server and it logs successfully.

When running the code from the server I'm able to attach and walk through the code and it executes the log4net methods without any exceptions. It never writes to the database. I enabled internal debugging and the error I found is below. However I have no idea what section is generating this error.

log4net: Adding appender named [UserTrackingAppender] to logger [root].
log4net: Hierarchy Threshold []
log4net:ERROR [AdoNetAppender] ErrorCode: GenericFailure. Exception while writing to database
System.Data.SqlClient.SqlException: The incoming tabular data stream (TDS) remote procedure call (RPC) protocol stream is incorrect. Parameter 5 ("@Error"): Data type 0xE7 has an invalid data length or metadata length.
   at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection)
   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj)
   at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj)
   at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString)
   at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async)
   at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result)
   at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(DbAsyncResult result, String methodName, Boolean sendToPipe)
   at System.Data.SqlClient.SqlCommand.ExecuteNonQuery()
   at log4net.Appender.AdoNetAppender.SendBuffer(IDbTransaction dbTran, LoggingEvent[] events)
   at log4net.Appender.AdoNetAppender.SendBuffer(LoggingEvent[] events)
log4net:ERROR [AdoNetAppender] ErrorCode: GenericFailure. Exception while writing to database
System.Data.SqlClient.SqlException: The incoming tabular data stream (TDS) remote procedure call (RPC) protocol stream is incorrect. Parameter 5 ("@Error"): Data type 0xE7 has an invalid data length or metadata length.
   at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection)
   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj)
   at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj)
   at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString)
   at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async)
   at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result)
   at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(DbAsyncResult result, String methodName, Boolean sendToPipe)
   at System.Data.SqlClient.SqlCommand.ExecuteNonQuery()
   at log4net.Appender.AdoNetAppender.SendBuffer(IDbTransaction dbTran, LoggingEvent[] events)
   at log4net.Appender.AdoNetAppender.SendBuffer(LoggingEvent[] events)

Table design- I have two different tables that are designed the same on for tracking and the other for exceptions. ID int Unchecked Date datetime Unchecked Thread varchar(255) Unchecked [Level] varchar(50) Unchecked Logger varchar(255) Unchecked Message varchar(4000) Unchecked Exception varchar(2000) Checked

The Log4NetLogger class Public Class Log4NetLogger Private _logger1 As ILogger Private _logger As ILog

    Public Sub New()
        _logger = LogManager.GetLogger(Me.[GetType]())
    End Sub

    Public Sub Info(message As String)
        _logger.Info(message)
    End Sub

    Public Sub Warn(message As String)
        _logger.Warn(message)
    End Sub

    Public Sub Debug(message As String)
        _logger.Debug(message)
    End Sub

    Public Sub [Error](message As String)
        _logger.[Error](message)
    End Sub

    Public Sub [Error](x As Exception)
        [Error](LogUtility.BuildExceptionMessage(x))
    End Sub

    Public Sub [Error](message As String, x As Exception)
        _logger.[Error](message, x)
    End Sub

    Public Sub Fatal(message As String)
        _logger.Fatal(message)
    End Sub

    Public Sub Fatal(x As Exception)
        Fatal(LogUtility.BuildExceptionMessage(x))
    End Sub
End Class

Code I use to call either Info or Error _log4Net.Info("User - " + _userName + "'s membership is valid. SessionID = " + Session.SessionID)

_log4NetLogger.Error("Agent: " + Session("agentNumber").ToString() + " User: " + Membership.GetUser().UserName + " Error: bla bla routine Exception in doColumnConfiguration. SessionID = " + Session.SessionID, ex)

UPDATE - FOR THE CONFIG FIX. PER SAMY REQUEST TO POST THIS.

ORIGINAL

FIX copied from Apache's website

  <parameter>
    <parameterName value="@log_date" />
    <dbType value="DateTime" />
    <layout type="log4net.Layout.RawTimeStampLayout" />
  </parameter>
  <parameter>
    <parameterName value="@thread" />
    <dbType value="String" />
    <size value="255" />
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%thread" />
    </layout>
  </parameter>
  <parameter>
    <parameterName value="@log_level" />
    <dbType value="String" />
    <size value="50" />
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%level" />
    </layout>
  </parameter>
  <parameter>
    <parameterName value="@logger" />
    <dbType value="String" />
    <size value="255" />
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%logger" />
    </layout>
  </parameter>
  <parameter>
    <parameterName value="@message" />
    <dbType value="String" />
    **<size value="4000" />**
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%message" />
    </layout>
  </parameter>
  <parameter>
    <parameterName value="@exception" />
    <dbType value="String" />
    <size value="2000" />
    <layout type="log4net.Layout.ExceptionLayout" />
  </parameter>

UPDATE - I hope this will help someone else. This issue is the config file in which the order of the parameters are listed. I know this doesn't make any sense because it worked in my local development environment. First I separated out the log4net into it's own config file. Tested it with zero success. As I was reviewing the config file I noticed the parameters for @error was at the top of the config so I decided to restructure it. I went to apache website and copy their config. Test it and all is good now. Thank you for your participation. — RockingCoder
Wow, that's really strange... Could you post the before /after config file for people to have some reference regarding the incorrect configuration? Congrats on solving this one — samy
UPDATE - The Final solution is the @ERROR was defined at 5000 instead of 4000. Boy do I feel stupid. Right in front of me the whole time and I missed it. — RockingCoder
Sometimes it's useful to rubberduck a bit :) So if i understand correctly the configuration file on both machines was the culprit. Good catch — samy

samy samy · Accepted Answer · 2014-03-26T15:06:40

The error code looks pretty explicit to me:

System.Data.SqlClient.SqlException: The incoming tabular data stream (TDS)
remote procedure call (RPC) protocol stream is incorrect. Parameter 5 
("@Error"): Data type 0xE7 has an invalid data length or metadata length.

The fifth parameter doesn't conform to what expected by the SQL server. Try looking into it. If the parameter should be allowed into the DB, please post the db schema

It looks like a SQL bug according to Microsoft

When you specify an NVarChar parameter with SqlParameter.Size between 4001 and 8000, SqlClient will throw the following exception.
A first chance exception of type 'System.Data.SqlClient.SqlException' occurred in System.Data.dll Source: .Net SqlClient Data Provider

The incoming tabular data stream (TDS) remote procedure call (RPC) protocol stream is incorrect. Parameter ("@"): Data type 0xE7 has an invalid data length or metadata length.

Resolution according to the same link:

To work around this issue, use one of the following options:

Set Sqlparamter.size property to -1 to ensure that you are getting the entire data from the backend without truncation.

When working with String DbTypes whose sizes are greater than 4000, explicitly map them to another SqlDBType like NText instead of using NVarchar(which also is the default SqlDBType for strings).

Use a value that is not between 4001 and 8000 for Sqlparameter.size.

log4net:ERROR [AdoNetAppender] ErrorCode: GenericFailure. Exception while writing to database

1 Answers