使用子记录器的 Serilog 审计日志

Question

我正在尝试使用Serilog为一部分日志事件编写审计日志。

也就是说，所有记录的事件中，应该使用子记录器记录子集到我选择的汇聚处，并且如果失败，我希望它能够发出异常噪声。

我的Serilog记录器配置如下：

var logger = new LoggerConfiguration()
    .MinimumLevel.Debug()
    .AuditTo.Logger(l => 
    {
        // Customising the SQL Server sink
        // The as-yet-not-created table will match these customisations.
        var sqlSinkOpts = new MSSqlServerSinkOptions
        {
            TableName = "LogTable",
            AutoCreateSqlTable = false
        };
        var sqlSinkColOpts = new ColumnOptions
        {
            AdditionalColumns = new Collection<SqlColumn> {
                new SqlColumn { ColumnName = "Something", DataType = SqlDbType.UniqueIdentifier },
                new SqlColumn { ColumnName = "SomethingElse", DataType = SqlDbType.NVarChar }
            }
        };
        sqlSinkColOpts.Level.StoreAsEnum = true;
        sqlSinkColOpts.Store.Remove(StandardColumn.MessageTemplate);
        sqlSinkColOpts.Store.Remove(StandardColumn.Properties);

        // Configure the logger
        l.Filter.ByIncludingOnly(Matching.FromSource("Namespace.We.Care.About"))
         .AuditTo.MSSqlServer(connectionString: ConfigurationManager.ConnectionStrings["Database"].ConnectionString,
                              sinkOptions: sqlSinkOpts,
                              columnOptions: sqlSinkColOpts);
    })
    .CreateLogger();

这里的意图是仅记录生成自Namespace.We.Care.About的日志事件到数据库的LogTable中，使用MS SQL Server sink。如果失败，应该大声失败;我们需要这些日志。

目前，我通过尚未在数据库中创建日志表来进行测试。因此，我希望它会失败。

我不确定我的配置是否不正确 - 允许使用子记录器进行审计日志的事实首先意味着这种配置是有效和受支持的 - 或者我在其他地方遇到了不同的问题。 我目前的假设是使用子记录器进行审计日志可能无法正常工作（正如我所预期的），或者我在配置上做错了什么。 另一个潜在相关点：我还使用Serilog.Extensions.Logging来允许使用Microsoft.Extensions.Logging。相关的日志事件就是这样生成的（也就是说，Namespace.We.Care.About中的代码使用Microsoft.Extensions.Logging.ILogger<Whatever>的实例来生成其日志事件，而且不知道Serilog的存在）。我不希望这会产生任何影响，但我想提一下这个事实，以防万一。 编辑 我已经检查了Serilog的SelfLog，写日志事件的异常出现如预期。只是在审计日志记录场景中没有像我所期望的那样传播回应用程序。

2022-10-25T10:26:18.1939244Z Failed to write event through SerilogLogger: System.AggregateException: Failed to emit a log event. ---> System.AggregateException: Failed to emit a log event. ---> Microsoft.Data.SqlClient.SqlException: Invalid object name 'dbo.LogTable'.
   at Microsoft.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction) in D:\a\_work\1\s\src\Microsoft.Data.SqlClient\netfx\src\Microsoft\Data\SqlClient\SqlConnection.cs:line 2363
   at Microsoft.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose) in D:\a\_work\1\s\src\Microsoft.Data.SqlClient\netfx\src\Microsoft\Data\SqlClient\TdsParser.cs:line 1775
   at Microsoft.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady) in D:\a\_work\1\s\src\Microsoft.Data.SqlClient\netfx\src\Microsoft\Data\SqlClient\TdsParser.cs:line 0
   at Microsoft.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption, Boolean shouldCacheForAlwaysEncrypted) in D:\a\_work\1\s\src\Microsoft.Data.SqlClient\netfx\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 5718
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest) in D:\a\_work\1\s\src\Microsoft.Data.SqlClient\netfx\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 5544
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry) in D:\a\_work\1\s\src\Microsoft.Data.SqlClient\netfx\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 5148
   at Microsoft.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource`1 completion, String methodName, Boolean sendToPipe, Int32 timeout, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry) in D:\a\_work\1\s\src\Microsoft.Data.SqlClient\netfx\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 2032
   at Microsoft.Data.SqlClient.SqlCommand.ExecuteNonQuery() in D:\a\_work\1\s\src\Microsoft.Data.SqlClient\netfx\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 1475
   at Serilog.Sinks.MSSqlServer.Platform.SqlLogEventWriter.WriteEvent(LogEvent logEvent)
   at Serilog.Core.Sinks.AggregateSink.Emit(LogEvent logEvent)
   --- End of inner exception stack trace ---
   at Serilog.Core.Sinks.AggregateSink.Emit(LogEvent logEvent)
   at Serilog.Core.Sinks.FilteringSink.Emit(LogEvent logEvent)
   at Serilog.Core.Sinks.AggregateSink.Emit(LogEvent logEvent)
   --- End of inner exception stack trace ---
   at Serilog.Core.Sinks.AggregateSink.Emit(LogEvent logEvent)
   at Serilog.Extensions.Logging.SerilogLogger.Write[TState](LogEventLevel level, EventId eventId, TState state, Exception exception, Func`3 formatter)
   at Serilog.Extensions.Logging.SerilogLogger.Log[TState](LogLevel logLevel, EventId eventId, TState state, Exception exception, Func`3 formatter)
---> (Inner Exception #0) System.AggregateException: Failed to emit a log event. ---> Microsoft.Data.SqlClient.SqlException: Invalid object name 'dbo.LogTable'.
   at Microsoft.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction) in D:\a\_work\1\s\src\Microsoft.Data.SqlClient\netfx\src\Microsoft\Data\SqlClient\SqlConnection.cs:line 2363
   at Microsoft.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose) in D:\a\_work\1\s\src\Microsoft.Data.SqlClient\netfx\src\Microsoft\Data\SqlClient\TdsParser.cs:line 1775
   at Microsoft.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady) in D:\a\_work\1\s\src\Microsoft.Data.SqlClient\netfx\src\Microsoft\Data\SqlClient\TdsParser.cs:line 0
   at Microsoft.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption, Boolean shouldCacheForAlwaysEncrypted) in D:\a\_work\1\s\src\Microsoft.Data.SqlClient\netfx\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 5718
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest) in D:\a\_work\1\s\src\Microsoft.Data.SqlClient\netfx\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 5544
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry) in D:\a\_work\1\s\src\Microsoft.Data.SqlClient\netfx\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 5148
   at Microsoft.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource`1 completion, String methodName, Boolean sendToPipe, Int32 timeout, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry) in D:\a\_work\1\s\src\Microsoft.Data.SqlClient\netfx\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 2032
   at Microsoft.Data.SqlClient.SqlCommand.ExecuteNonQuery() in D:\a\_work\1\s\src\Microsoft.Data.SqlClient\netfx\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 1475
   at Serilog.Sinks.MSSqlServer.Platform.SqlLogEventWriter.WriteEvent(LogEvent logEvent)
   at Serilog.Core.Sinks.AggregateSink.Emit(LogEvent logEvent)
   --- End of inner exception stack trace ---
   at Serilog.Core.Sinks.AggregateSink.Emit(LogEvent logEvent)
   at Serilog.Core.Sinks.FilteringSink.Emit(LogEvent logEvent)
   at Serilog.Core.Sinks.AggregateSink.Emit(LogEvent logEvent)
---> (Inner Exception #0) Microsoft.Data.SqlClient.SqlException (0x80131904): Invalid object name 'dbo.LogTable'.
   at Microsoft.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction) in D:\a\_work\1\s\src\Microsoft.Data.SqlClient\netfx\src\Microsoft\Data\SqlClient\SqlConnection.cs:line 2363
   at Microsoft.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose) in D:\a\_work\1\s\src\Microsoft.Data.SqlClient\netfx\src\Microsoft\Data\SqlClient\TdsParser.cs:line 1775
   at Microsoft.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady) in D:\a\_work\1\s\src\Microsoft.Data.SqlClient\netfx\src\Microsoft\Data\SqlClient\TdsParser.cs:line 0
   at Microsoft.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption, Boolean shouldCacheForAlwaysEncrypted) in D:\a\_work\1\s\src\Microsoft.Data.SqlClient\netfx\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 5718
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest) in D:\a\_work\1\s\src\Microsoft.Data.SqlClient\netfx\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 5544
   at Microsoft.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry) in D:\a\_work\1\s\src\Microsoft.Data.SqlClient\netfx\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 5148
   at Microsoft.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource`1 completion, String methodName, Boolean sendToPipe, Int32 timeout, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry) in D:\a\_work\1\s\src\Microsoft.Data.SqlClient\netfx\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 2032
   at Microsoft.Data.SqlClient.SqlCommand.ExecuteNonQuery() in D:\a\_work\1\s\src\Microsoft.Data.SqlClient\netfx\src\Microsoft\Data\SqlClient\SqlCommand.cs:line 1475
   at Serilog.Sinks.MSSqlServer.Platform.SqlLogEventWriter.WriteEvent(LogEvent logEvent)
   at Serilog.Core.Sinks.AggregateSink.Emit(LogEvent logEvent)
ClientConnectionId:c4b0f48e-f50c-4c32-8772-edb4a388538f
Error Number:208,State:1,Class:16<---
<---

- Mark Embling

Answer 1

原来这与Serilog.Extensions.Logging有关，我使用的子记录器/审计配置实际上没有任何问题。

我并没有真正解决这个问题，但至少我知道了问题所在。因此，我将其作为答案发布，以便使用特定组合并遇到相同行为的任何其他人都知道根本原因，并且不会像我一样花费数小时追踪认为是配置错误。

我可以通过让Namespace.We.Care.About中的代码直接依赖于Serilog并直接使用它进行日志记录来解决该问题。虽然这不是我想要做的事情，但由于我对该代码以及我的调用代码具有完全控制权，因此这是一个选项。

我意识到，在发布此答案时，这可能不是对于那些与期望Microsoft.Extensions.Logging.ILogger实例的日志记录一起使用Serilog/Serilog.Extensions.Logging的第三方库的任何人都可行的选项。

因此，我在serilog-extensions-logging的Github存储库上提出了一个问题，详细说明了问题的具体情况。

- Mark Embling