Nlog: Parameters empty (or not supplied to CommandText) when using NLog with ASP.NET Core and Sqlite

[Niels-R]

I've set up NLog in an ASP.NET Core MVC application using the examples in the documentation. Logging to a file (target=file) works without any problems.

However, logging to the Sqlite database results in an exception:

2018-10-30 20:04:41.4394 Error DatabaseTarget(Name=db): Error when writing to database. Exception: System.InvalidOperationException: Must add values for the following parameters: @MachineName, @Logged, @Level, @Message, @Logger, @Callsite, @Exception at Microsoft.Data.Sqlite.SqliteCommand.ExecuteReader(CommandBehavior behavior) at Microsoft.Data.Sqlite.SqliteCommand.ExecuteNonQuery() at NLog.Targets.DatabaseTarget.WriteEventToDatabase(LogEventInfo logEvent) at NLog.Targets.DatabaseTarget.Write(LogEventInfo logEvent)

Any ideas why the values of these parameters are empty? Or maybe the parameters are not passed at all?

NLog configuration file:

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

<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
      xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">

  <targets>
    <target xsi:type="File" name="file" fileName="nlog-${shortdate}.log"
            layout="${longdate}|${machinename}|${level:upperCase=true}|${logger}|${callsite}|${message} ${exception:tostring}" />

    <target xsi:type="Database"
            name="db"
            dbProvider="Microsoft.Data.Sqlite.SqliteConnection, Microsoft.Data.Sqlite"
            connectionString="Data Source=database.db;">

      <commandText>
        INSERT INTO Log (MachineName, Logged, Level, Message, Logger, CallSite, Exception)
        VALUES (@MachineName, @Logged, @Level, @Message, @Logger, @Callsite, @Exception);
      </commandText>

      <parameter name="@MachineName" layout="${machinename}" />
      <parameter name="@Logged" layout="${longdate}" />
      <parameter name="@Level" layout="${level:upperCase=true}" />
      <parameter name="@Message" layout="${message}" />
      <parameter name="@Logger" layout="${logger}" />
      <parameter name="@CallSite" layout="${callsite}" />
      <parameter name="@Exception" layout="${exception:tostring}" />
    </target>
  </targets>

  <rules>
    <logger name="*" minlevel="Trace" writeTo="file" />
    <logger name="*" minlevel="Info" writeTo="db" />
  </rules>
</nlog>

[304NotModified]

Please fill in the template, so we could help you with your issue, thanks!

[snakefoot]

@Niels-R Think you also need to enable the Internal Logger (internalLogLevel=Trace), so more output is availabe (As it is also requested in the Github-New-issue-template).

https://github.com/NLog/NLog/wiki/Internal-Logging

The NLog Unit tests with SqlLite works just fine with inserting into SqLite-database. Maybe the NLog.config you have pasted here is not the NLog.config being deployed/loaded?

[Niels-R]

@304NotModified Sorry if this sounds oblivious, but what template? I can't seem to find a reference to a template for support issues.

@snakefoot I've used the internal logging file at "Info" level, but I've updated it to "Trace" and added the result log file to this message. As you can see the values for the parameters are set, but an exception is thrown by Microsoft.Data.Sqlite.SqliteCommand.ExecuteReader.

2018-11-01 14:51:41.1982 Trace   DatabaseTarget: Parameter: '@MachineName' = 'RHINO' (String)
2018-11-01 14:51:41.2152 Trace   DatabaseTarget: Parameter: '@Logged' = '2018-11-01 14:51:41.1982' (String)
2018-11-01 14:51:41.2152 Trace   DatabaseTarget: Parameter: '@Level' = 'INFO' (String)
2018-11-01 14:51:41.2152 Trace   DatabaseTarget: Parameter: '@Message' = 'Request finished in 409.7024ms 200 text/html; charset=utf-8' (String)
2018-11-01 14:51:41.2152 Trace   DatabaseTarget: Parameter: '@Logger' = 'Microsoft.AspNetCore.Hosting.Internal.WebHost' (String)
2018-11-01 14:51:41.2152 Trace   DatabaseTarget: Parameter: '@CallSite' = 'Microsoft.AspNetCore.Hosting.Internal.HostingApplicationDiagnostics.LogRequestFinished' (String)
2018-11-01 14:51:41.2152 Trace   DatabaseTarget: Parameter: '@Exception' = '' (String)
2018-11-01 14:51:41.2152 Error DatabaseTarget(Name=db): Error when writing to database. Exception: System.InvalidOperationException: Must add values for the following parameters: @MachineName, @Logged, @Level, @Message, @Logger, @Callsite, @Exception
   at Microsoft.Data.Sqlite.SqliteCommand.ExecuteReader(CommandBehavior behavior)
   at Microsoft.Data.Sqlite.SqliteCommand.ExecuteNonQuery()
   at NLog.Targets.DatabaseTarget.WriteEventToDatabase(LogEventInfo logEvent)
   at NLog.Targets.DatabaseTarget.Write(LogEventInfo logEvent)
2018-11-01 14:51:41.2152 Trace DatabaseTarget(Name=db): Close connection because of error
2018-11-01 14:51:41.2152 Trace DatabaseTarget(Name=db): Close connection (KeepConnection = false).

internal-nlog-copy.txt

[snakefoot]

@Niels-R There is a green "New Issue"-button for creating new Github-issue. It points to this link: https://github.com/NLog/NLog/issues/new/choose (It will generate an issue prefilled with the template-text)

@Niels-R Looks like something goes wrong in the SqlLite-engine when doing the prepare of the command. Not an expert on SqlLite, so I can only suggest that you re-check our SqlLite-database creation and connection-string:

SourceCode here: https://github.com/aspnet/Microsoft.Data.Sqlite/blob/master/src/Microsoft.Data.Sqlite.Core/SqliteCommand.cs#L283

[Niels-R]

Just an update: I've fixed the issue by switching to System.Data.SQLite

Remove the Microsoft.Data.Sqlite reference and add a reference System.Data.SQLite (1.0.109.2 at the time of writing) in your _.csproj_ file. Update the dbProvider attribute value in _nlog.config_ to System.Data.SQLite.SQLiteConnection, System.Data.SQLite and you're set.

_.csproj file_

<ItemGroup>
    <PackageReference Include="NLog.Web.AspNetCore" Version="4.7.0" />
    <PackageReference Include="System.Data.SQLite" Version="1.0.109.2" />
    ...
</ItemGroup>

_nlog.config_

<target xsi:type="Database"
            name="db"
            dbProvider="System.Data.SQLite.SQLiteConnection, System.Data.SQLite"
            connectionString="Data Source=database.db;">
   ...
</target>

[snakefoot]

@Niels-R Guess you can resolve the issue then, since it doesn't seem to be a problem with NLog, but with the DbProvider.