Logs do not get saved into Logs table

Question

I'm trying to save any logs I received from the application into a log table in my db and so far, nothing gets saved. I'm using Log4net and AdoNetAppender for saving the logs into my table inside SQL Server. This code sits inside a Web API project on the server side of my app.

I set up the logs as follows:

1) Setup the XML in my Web.Config:

<log4net>
    <appender name="AdoNetAppender" type="log4net.Appender.AdoNetAppender">
      <bufferSize value="1" />
      <connectionType value="System.Data.SqlClient.SqlConnection, System.Data, Version=1.0.3300.0, Culture=neutral, PublicKeyToken=token" />
      <connectionString value="data source=db;Initial Catalog=dbname;Trusted_Connection=True;" providerName="System.Data.SqlClient" />
      <commandText value="dbo.procLogs_Insert" />
      <commandType value="StoredProcedure" />
      <parameter>
        <parameterName value="@log_timestamp" />
        <dbType value="DateTime" />
        <layout type="log4net.Layout.RawTimeStampLayout" />
      </parameter>
      <parameter>
        <parameterName value="@log_recordNum" />
        <dbType value="Int32" />
        <size value="32" />
        <layout type="log4net.Layout.RawPropertyLayout" />
      </parameter>
      <parameter>
        <parameterName value="@log_computerName" />
        <dbType value="String" />
        <size value="128" />
        <layout type="log4net.Layout.PatternLayout">
          <conversionPattern value="%X{machine}" />
        </layout>
      </parameter>
      <parameter>
        <parameterName value="@log_processTimeStamp" />
        <dbType value="DateTime" />
        <layout type="log4net.Layout.RawTimeStampLayout" />
      </parameter>
      <parameter>
        <parameterName value="@log_group" />
        <dbType value="StringFixedLength" />
        <size value="1" />
        <layout type="log4net.Layout.PatternLayout">
          <conversionPattern value="%message" />
        </layout>
      </parameter>
      <parameter>
        <parameterName value="@log_type" />
        <dbType value="StringFixedLength" />
        <size value="1" />
        <layout type="log4net.Layout.PatternLayout">
          <conversionPattern value="%message" />
        </layout>
      </parameter>
      <parameter>
        <parameterName value="@log_eventId" />
        <dbType value="Int32" />
        <size value="32" />
        <layout type="log4net.Layout.RawPropertyLayout" />
      </parameter>
      <parameter>
        <parameterName value="@log_userId" />
        <dbType value="Int32" />
        <size value="32" />
        <layout type="log4net.Layout.PatternLayout">
          <conversionPattern value="%identity" />
        </layout>
      </parameter>
      <parameter>
        <parameterName value="@log_line" />
        <dbType value="Int32" />
        <size value="32" />
        <layout type="log4net.Layout.PatternLayout">
          <conversionPattern value="%line" />
        </layout>
      </parameter>
      <parameter>
        <parameterName value="@log_description" />
        <dbType value="AnsiString" />
        <size value="4000" />
        <layout type="log4net.Layout.PatternLayout">
          <conversionPattern value="%message%newline %exception" />
        </layout>
      </parameter>
      <parameter>
        <parameterName value="@log_source" />
        <dbType value="AnsiString" />
        <size value="4000" />
        <layout type="log4net.Layout.PatternLayout">
          <conversionPattern value="%file" />
        </layout>
      </parameter>
      <parameter>
        <parameterName value="@log_data" />
        <dbType value="AnsiString" />
        <size value="4000" />
        <layout type="log4net.Layout.PatternLayout">
          <conversionPattern value="%logger" />
        </layout>
      </parameter>
      <parameter>
        <parameterName value="@log_addTimeStamp" />
        <dbType value="DateTime" />
        <layout type="log4net.Layout.RawTimeStampLayout" />
      </parameter>
      <parameter>
        <parameterName value="@log_deviceId" />
        <dbType value="StringFixedLength" />
        <size value="10" />
        <layout type="log4net.Layout.PatternLayout" />
      </parameter>
    </appender>
    <appender name="asyncForwarder" type="Log4Net.Async.AsyncForwardingAppender,Log4Net.Async">
      <appender-ref ref="AdoNetAppender" />
    </appender>
    <root>
      <level value="ALL" />
      <appender-ref ref="asyncForwarder" />
    </root>
  </log4net>

2) Here's the code inside my Global.asax.cs:

public class WebApiApplication : System.Web.HttpApplication
{
    private static readonly ILog _log = LogManager.GetLogger(MethodBase.GetCurrentMethod().DeclaringType);

    protected void Application_Start()
    {
        XmlConfigurator.Configure();
        _log.Info("Service Started");
        GlobalConfiguration.Configure(WebApiConfig.Register);
    }

    public static void Register(HttpConfiguration config)
    {
        // Web API routes
        config.MapHttpAttributeRoutes();
    }
}

3) Added the Stored Procedure to the db:

SET ANSI_NULLS ON
GO
SET QUOTED_IDENTIFIER ON
GO

CREATE PROCEDURE dbo.procLogs_Insert 
  @log_timestamp datetime, 
  @log_recordNum int, 
  @log_computerName varchar(128), 
  @log_processTimeStamp datetime, 
  @log_group char(1), 
  @log_type char(1), 
  @log_eventId int, 
  @log_userId varchar(128), 
  @log_line int, 
  @log_description text, 
  @log_source text, 
  @log_data text, 
  @log_addTimeStamp datetime, 
  @log_deviceId char(10)
AS
BEGIN
    SET NOCOUNT ON;

  insert into dbo.BS_ApplicationLogs(LogTimestamp, RecordNum, ComputerName, ProcessTimestamp, LogGroup, [Type],EventId,UserId,Line,[Description],[Source],[Data],AddTimestamp,DeviceID)
  values (@log_timestamp,  @log_recordNum, @log_computerName, @log_processTimeStamp, @log_group, @log_type, @log_eventId, @log_userId, @log_line,@log_description,@log_source,@log_data,@log_addTimeStamp,@log_deviceId)

END
GO

Question: Where should this stored procedure be saved in SSMS? When I save the stored procedure, it automatically defaults it to Documents\SSMS but I want to save it under DB/Programmability/StoredProcedures folder but I don't see it there. However, I did execute the stored procedure successfully without any errors.

4) added logs to other files inside my app project outside of the global.asax.cs file. Does Log4Net know to log those as well?

So yeah I'm not sure what I did wrong and nothing gets logged to my table in SQL Server. Did I miss a step in the process of setting up Log4Net?

EDIT: Internal debugger says:

log4net: Created Appender [AdoNetAppender]
log4net: Created Appender [asyncForwarder]
log4net: Adding appender named [asyncForwarder] to logger [root].
log4net: Hierarchy Threshold []
log4net:ERROR [AdoNetAppender] ErrorCode: GenericFailure. Exception while writing to database
System.ArgumentNullException: Key cannot be null.
Parameter name: key
   at System.Collections.Hashtable.get_Item(Object key)
   at log4net.Util.PropertiesDictionary.get_Item(String key)
   at log4net.Core.LoggingEvent.LookupProperty(String key)
   at log4net.Layout.RawPropertyLayout.Format(LoggingEvent loggingEvent)
   at log4net.Appender.AdoNetAppenderParameter.FormatValue(IDbCommand command, LoggingEvent loggingEvent)
   at log4net.Appender.AdoNetAppender.SendBuffer(IDbTransaction dbTran, LoggingEvent[] events)
   at log4net.Appender.AdoNetAppender.SendBuffer(LoggingEvent[] events)

What key?

Misrepresent

Saving the stored procedure to a file is not relevant. You need to make sure you actually execute the sql commands which creates the stored procedure inside the SQL database. (Which should show up in SSMS under Programmability/Stored Procedures) – Mainsail

@Mainsail I'm able to excecute the stored procedure but it still won't save to db. Do you know if I'm missing any steps or configs from above code? – Misrepresent

Your question isn't very clear, but one thing wrong is that your log4net configuration seems to expect a stored procedure 'dbo.procLog_Insert' while your SP is called 'dbo.procLogs_Insert'. Also if you enable log4net internal logging, you may get more of a clue as to what's going on. – Injun

@Injun Ohh, good catch! Let me fix that and see if it helps! How do I enable Log4Net internal logging? Thanks! – Misrepresent

@Misrepresent - google has a number of suggestions for enabling log4net internal debugging, including this: #756625 – Injun

@Joe, thanks for your help! I changed the typo to the correct string (see edit) and I added internal debugging but I think I found the exception but I'm not sure what it is referring to. It says "Key cannot be null" but I'm not sure which key? – Misrepresent

@Misrepresent - I suspect the problem is with "%X{machine}" which hasn't been populated with the machine name. You may be able to replace this by "%property{log4net:HostName}" which will avoid you needing to call MDC.Set("machine", Environment.MachineName)` See #163310 – Injun

@Injun I changed it to the correct hostname property but I'm still getting the same exception. How does Log4net know what should be saved in the log table from the code above? Does it just take the message or exception I log and send it via the parameter %message to log it? Like I'm wondering if it's because I don't have a conversion pattern for some of the RawPropertyLayout properties? E.g. log_eventId, log_recordNum? – Misrepresent

@Misrepresent - as far as I can see the RawPropertyLayout element should contain a Key element, so that may be the problem. But I think we're straying from your original question, and it may be worth posting a specific question about RawPropertyLayout if you can't get it working. – Injun

Answer 1

3) Sounds like you've created the Stored Procedure, however its ended up in the Master database (Master/Programmability/StoredProcedures).

You should either select the DropDownList and change from Master to your DB or you can use the syntax USE YourDB before the stored proc and click the Execute button:

USE YourDB

SET ANSI_NULLS ON
GO
SET QUOTED_IDENTIFIER ON
GO

CREATE PROCEDURE dbo.procLogs_Insert 
  @log_timestamp datetime, 
  @log_recordNum int, 
  @log_computerName varchar(128), 
  @log_processTimeStamp datetime, 
  @log_group char(1), 
  @log_type char(1), 
  @log_eventId int, 
  @log_userId varchar(128), 
  @log_line int, 
  @log_description text, 
  @log_source text, 
  @log_data text, 
  @log_addTimeStamp datetime, 
  @log_deviceId char(10)
AS
BEGIN
    SET NOCOUNT ON;

  insert into dbo.BS_ApplicationLogs(LogTimestamp, RecordNum, ComputerName, ProcessTimestamp, LogGroup, [Type],EventId,UserId,Line,[Description],[Source],[Data],AddTimestamp,DeviceID)
  values (@log_timestamp,  @log_recordNum, @log_computerName, @log_processTimeStamp, @log_group, @log_type, @log_eventId, @log_userId, @log_line,@log_description,@log_source,@log_data,@log_addTimeStamp,@log_deviceId)

END
GO

Circumstantiate

Answer 2

This is a file I have that works, writing to a MS SQL server

It refers to user defined properties %property{xxx}, that are populated in code like this

GlobalContext.Properties["user"] = Environment.UserName;

Maybe you can replace some of your properties with that to figure out which one is causing the issue

<appender name="AppenderDB" type="log4net.Appender.AdoNetAppender">

<bufferSize value="0" />
<reconnectOnError value="true" />
<connectionType value="System.Data.SqlClient.SqlConnection, System.Data, Version=4.0.0.0, Culture=neutral" />
<connectionString value="Data Source=MYDB\DB;Initial Catalog=XXX;Integrated Security=True;" />    
<commandText value="EXECUTE WriteLogEntry @time, @recipeName, @userId, @timeSeries, @loadTimeMs" />

<parameter>
  <parameterName value="@time" />
  <dbType value="DateTime" />
  <layout type="log4net.Layout.RawUtcTimeStampLayout" />
</parameter>


<parameter>
  <parameterName value="@recipeName" />
  <dbType value="String" />
  <size value="1024" />
  <layout type="log4net.Layout.PatternLayout">
    <conversionPattern value="%property{recipeName}" />
  </layout>
</parameter>

<parameter>
  <parameterName value="@userId" />
  <dbType value="String" />
  <size value="20" />
  <layout type="log4net.Layout.PatternLayout" value="%property{user}"/>
</parameter>
<parameter>
  <parameterName value="@timeSeries" />
  <dbType value="String" />
  <size value="1024" />
  <layout type="log4net.Layout.PatternLayout" value="%property{timeSeries}"/>
</parameter>

<parameter>
  <parameterName value="@loadTimeMs" />
  <dbType value="Int32" />
  <size value="50" />
  <layout type="log4net.Layout.PatternLayout" value="%property{loadTimeMs}"/>
</parameter>

`

Chromatogram