Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Prevent logging data from being affected by transactions. #392

Merged
merged 7 commits into from
Mar 7, 2022
Merged
Show file tree
Hide file tree
Changes from 3 commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
12 changes: 11 additions & 1 deletion README.md
Original file line number Diff line number Diff line change
Expand Up @@ -242,6 +242,7 @@ Basic settings of the sink are configured using the properties in a `MSSqlServer
* `TableName`
* `SchemaName`
* `AutoCreateSqlTable`
* `PreventEnlistInTransaction`
* `BatchPostingLimit`
* `BatchPeriod`
* `EagerlyEmitFirstEvent`
Expand All @@ -261,6 +262,15 @@ An optional parameter specifiying the database schema where the log events table

A flag specifiying if the log events table should be created if it does not exist. It defaults to `false`.

### PreventEnlistInTransaction

A flag to prevent logging SQL commands from taking part in ambient transactions. It defaults to `true`.
Logging operations could be affected from surrounding `TransactionScope�s in the code, leading to log data
being removed on a transation rollback. This is by default prevented by the sink adding `Enlist=false` to
the `ConnectionString` that is passed. This option can be used to change this behaviour so that no `Enlist=false`
is added and the passed `ConnectionString` is used as is and logging commands might be part of transations.
Only change this option to `false` if you really know what you are doing!
ckadluba marked this conversation as resolved.
Show resolved Hide resolved

### BatchPostingLimit

Specifies a maximum number of log events that the non-audit sink writes per batch. The default is 50.
Expand All @@ -280,7 +290,7 @@ This setting is not used by the audit sink as it writes each event immediately a

A flag specifiying to use Azure Managed Identities for authenticating with an Azure SQL server. It defaults to `false`. If enabled the property `AzureServiceTokenProviderResource` must be set as well.

**IMPORTANT:** Azure Managed Identities is only supported for the target frameworks .NET Framework 4.7.2+ and .NET Core 2.2+. Setting this to `true` when targeting a different framework results in an exception.
**IMPORTANT:** Azure Managed Identities is only supported for the target frameworks .NET Framework 4.7.2+ and .NET (Core) 2.2+. Setting this to `true` when targeting a different framework results in an exception.

See [Azure AD-managed identities for Azure resources documentation](https://docs.microsoft.com/en-us/azure/active-directory/managed-identities-azure-resources/) for details on how to configure and use Azure Managed Identitites.

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,7 @@ private static void ReadTableOptions(IConfigurationSection config, MSSqlServerSi
SetProperty.IfNotNull<string>(config["tableName"], val => sinkOptions.TableName = val);
SetProperty.IfNotNull<string>(config["schemaName"], val => sinkOptions.SchemaName = val);
SetProperty.IfNotNull<bool>(config["autoCreateSqlTable"], val => sinkOptions.AutoCreateSqlTable = val);
SetProperty.IfNotNull<bool>(config["preventEnlistInTransaction"], val => sinkOptions.PreventEnlistInTransaction = val);
}

private static void ReadBatchSettings(IConfigurationSection config, MSSqlServerSinkOptions sinkOptions)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -157,6 +157,12 @@ public ValueConfigElement AutoCreateSqlTable
get => (ValueConfigElement)base[nameof(AutoCreateSqlTable)];
}

[ConfigurationProperty(nameof(PreventEnlistInTransaction))]
public ValueConfigElement PreventEnlistInTransaction
{
get => (ValueConfigElement)base[nameof(PreventEnlistInTransaction)];
}

[ConfigurationProperty(nameof(BatchPostingLimit))]
public ValueConfigElement BatchPostingLimit
{
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,8 @@ private static void ReadTableOptions(MSSqlServerConfigurationSection config, MSS
SetProperty.IfProvided<string>(config.SchemaName, nameof(config.SchemaName.Value), value => sinkOptions.SchemaName = value);
SetProperty.IfProvided<bool>(config.AutoCreateSqlTable, nameof(config.AutoCreateSqlTable.Value),
value => sinkOptions.AutoCreateSqlTable = value);
SetProperty.IfProvided<bool>(config.PreventEnlistInTransaction, nameof(config.PreventEnlistInTransaction.Value),
value => sinkOptions.PreventEnlistInTransaction = value);
}

private static void ReadBatchSettings(MSSqlServerConfigurationSection config, MSSqlServerSinkOptions sinkOptions)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@
using Serilog.Formatting;
using Serilog.Sinks.MSSqlServer.Output;
using Serilog.Sinks.MSSqlServer.Platform;
using Serilog.Sinks.MSSqlServer.Platform.SqlClient;

namespace Serilog.Sinks.MSSqlServer.Dependencies
{
Expand All @@ -19,7 +20,9 @@ internal static SinkDependencies Create(

var sqlConnectionFactory =
new SqlConnectionFactory(connectionString,
sinkOptions?.PreventEnlistInTransaction ?? true,
sinkOptions?.UseAzureManagedIdentity ?? default,
new SqlConnectionStringBuilderWrapper(),
new AzureManagedServiceAuthenticator(
sinkOptions?.UseAzureManagedIdentity ?? default,
sinkOptions.AzureServiceTokenProviderResource,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,7 @@ public class MSSqlServerSinkOptions
public MSSqlServerSinkOptions()
{
SchemaName = MSSqlServerSink.DefaultSchemaName;
PreventEnlistInTransaction = true;
BatchPostingLimit = MSSqlServerSink.DefaultBatchPostingLimit;
BatchPeriod = MSSqlServerSink.DefaultPeriod;
EagerlyEmitFirstEvent = true;
Expand Down Expand Up @@ -47,6 +48,11 @@ internal MSSqlServerSinkOptions(
/// </summary>
public bool AutoCreateSqlTable { get; set; }

/// <summary>
/// Flag to prevent logging SQL commands from taking part in ambient transactions (default: true)
/// </summary>
public bool PreventEnlistInTransaction { get; set; }
ckadluba marked this conversation as resolved.
Show resolved Hide resolved

/// <summary>
/// Limits how many log events are written to the database per batch (default: 50)
/// </summary>
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,8 @@
namespace Serilog.Sinks.MSSqlServer.Platform.SqlClient
{
internal interface ISqlConnectionStringBuilderWrapper
{
string ConnectionString { get; set; }
bool Enlist { set; }
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,29 @@
#if NET452
using System.Data.SqlClient;
#else
using Microsoft.Data.SqlClient;
#endif

namespace Serilog.Sinks.MSSqlServer.Platform.SqlClient
{
internal class SqlConnectionStringBuilderWrapper : ISqlConnectionStringBuilderWrapper
{
private readonly SqlConnectionStringBuilder _sqlConnectionStringBuilder;

public SqlConnectionStringBuilderWrapper()
{
_sqlConnectionStringBuilder = new SqlConnectionStringBuilder();
}

public string ConnectionString
{
get => _sqlConnectionStringBuilder.ConnectionString;
set => _sqlConnectionStringBuilder.ConnectionString = value;
}

public bool Enlist
{
set => _sqlConnectionStringBuilder.Enlist = value;
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -7,19 +7,35 @@ internal class SqlConnectionFactory : ISqlConnectionFactory
{
private readonly string _connectionString;
private readonly bool _useAzureManagedIdentity;
private readonly ISqlConnectionStringBuilderWrapper _sqlConnectionStringBuilderWrapper;
private readonly IAzureManagedServiceAuthenticator _azureManagedServiceAuthenticator;

public SqlConnectionFactory(string connectionString, bool useAzureManagedIdentity, IAzureManagedServiceAuthenticator azureManagedServiceAuthenticator)
public SqlConnectionFactory(
string connectionString,
bool preventEnlistInTransaction,
bool useAzureManagedIdentity,
ISqlConnectionStringBuilderWrapper sqlConnectionStringBuilderWrapper,
IAzureManagedServiceAuthenticator azureManagedServiceAuthenticator)
{
if (string.IsNullOrWhiteSpace(connectionString))
{
throw new ArgumentNullException(nameof(connectionString));
}

_connectionString = connectionString;
_useAzureManagedIdentity = useAzureManagedIdentity;
_sqlConnectionStringBuilderWrapper = sqlConnectionStringBuilderWrapper
?? throw new ArgumentNullException(nameof(sqlConnectionStringBuilderWrapper));
_azureManagedServiceAuthenticator = azureManagedServiceAuthenticator
?? throw new ArgumentNullException(nameof(azureManagedServiceAuthenticator));

// Add 'Enlist=false', so that ambient transactions (TransactionScope) will not affect/rollback logging
// unless sink option PreventEnlistInTransaction is set to false.
_sqlConnectionStringBuilderWrapper.ConnectionString = connectionString;
if (preventEnlistInTransaction)
{
_sqlConnectionStringBuilderWrapper.Enlist = false;
}
_connectionString = _sqlConnectionStringBuilderWrapper.ConnectionString;

_useAzureManagedIdentity = useAzureManagedIdentity;
}

public ISqlConnectionWrapper Create()
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -15,7 +15,7 @@ public void MSSqlServerAuditSinkFactoryCreateReturnsInstance()
var sut = new MSSqlServerAuditSinkFactory();

// Act
var result = sut.Create("TestConnectionString", sinkOptions, null, new MSSqlServer.ColumnOptions(), null);
var result = sut.Create(DatabaseFixture.LogEventsConnectionString, sinkOptions, null, new MSSqlServer.ColumnOptions(), null);

// Assert
Assert.IsType<MSSqlServerAuditSink>(result);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -15,7 +15,7 @@ public void MSSqlServerSinkFactoryCreateReturnsInstance()
var sut = new MSSqlServerSinkFactory();

// Act
var result = sut.Create("TestConnectionString", sinkOptions, null, new MSSqlServer.ColumnOptions(), null);
var result = sut.Create(DatabaseFixture.LogEventsConnectionString, sinkOptions, null, new MSSqlServer.ColumnOptions(), null);

// Assert
Assert.IsType<MSSqlServerSink>(result);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -76,6 +76,20 @@ public void ConfigureSinkOptionsSetsAutoCreateSqlTable()
Assert.True(result.AutoCreateSqlTable);
}

[Fact]
public void ConfigureSinkOptionsSetsPreventEnlistInTransaction()
{
// Arrange
_configurationSectionMock.Setup(s => s["preventEnlistInTransaction"]).Returns("false");
var sut = new MicrosoftExtensionsSinkOptionsProvider();

// Act
var result = sut.ConfigureSinkOptions(new MSSqlServerSinkOptions(), _configurationSectionMock.Object);

// Assert
Assert.False(result.PreventEnlistInTransaction);
}

[Fact]
public void ConfigureSinkOptionsSetsBatchPostingLimit()
{
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -23,5 +23,21 @@ public void ConfigureSinkOptionsReadsBatchSettings()
// Assert
Assert.True(sinkOptions.EagerlyEmitFirstEvent);
}

[Fact]
public void ConfigureSinkOptionsReadsPreventEnlistInTransaction()
{
// Arrange
var configSection = new MSSqlServerConfigurationSection();
configSection.PreventEnlistInTransaction.Value = "false";
var sinkOptions = new MSSqlServerSinkOptions { PreventEnlistInTransaction = true };
var sut = new SystemConfigurationSinkOptionsProvider();

// Act
sut.ConfigureSinkOptions(configSection, sinkOptions);

// Assert
Assert.False(sinkOptions.PreventEnlistInTransaction);
}
}
}
68 changes: 68 additions & 0 deletions test/Serilog.Sinks.MSSqlServer.Tests/MiscFeaturesTests.cs
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
using System;
using System.Collections.Generic;
using System.Data;
using System.Transactions;
using FluentAssertions;
using Serilog.Sinks.MSSqlServer.Tests.TestUtils;
using Xunit;
Expand Down Expand Up @@ -291,5 +292,72 @@ public void LogEventStoreAsEnum()
VerifyCustomQuery<LogEventColumn>($"SELECT Id from {DatabaseFixture.LogTableName}",
e => e.Should().HaveCount(1));
}

[Fact]
public void LogsAreNotAffectedByTransactionsByDefault()
{
// Arrange
Log.Logger = new LoggerConfiguration()
.WriteTo.MSSqlServer
(
connectionString: DatabaseFixture.LogEventsConnectionString,
new MSSqlServerSinkOptions
{
TableName = DatabaseFixture.LogTableName,
AutoCreateSqlTable = true,
EagerlyEmitFirstEvent = false,
BatchPeriod = TimeSpan.FromSeconds(30),
}
)
.CreateLogger();

using (var scope = new TransactionScope(TransactionScopeAsyncFlowOption.Enabled))
{
// Act
Log.Logger.Information("Logging message");

// Flush message so it is written on foreground thread instead of timer
// So we can test if it is affected by transaction
Log.CloseAndFlush();
}

// Assert after rollback, the message should still be persisted
VerifyCustomQuery<LogEventColumn>($"SELECT Id from {DatabaseFixture.LogTableName}",
e => e.Should().HaveCount(1));
}

[Fact]
public void LogsAreAffectedByTransactionsIfPreventEnlistInTransactionIsFalse()
{
// Arrange
Log.Logger = new LoggerConfiguration()
.WriteTo.MSSqlServer
(
connectionString: DatabaseFixture.LogEventsConnectionString,
new MSSqlServerSinkOptions
{
TableName = DatabaseFixture.LogTableName,
AutoCreateSqlTable = true,
PreventEnlistInTransaction = false,
EagerlyEmitFirstEvent = false,
BatchPeriod = TimeSpan.FromSeconds(30),
}
)
.CreateLogger();

using (var scope = new TransactionScope(TransactionScopeAsyncFlowOption.Enabled))
{
// Act
Log.Logger.Information("Logging message");

// Flush message so it is written on foreground thread instead of timer
// So we can test if it is affected by transaction
Log.CloseAndFlush();
}

// Assert after rollback, the message should still be persisted
VerifyCustomQuery<LogEventColumn>($"SELECT Id from {DatabaseFixture.LogTableName}",
e => e.Should().HaveCount(0));
}
}
}
Original file line number Diff line number Diff line change
@@ -1,7 +1,7 @@
<Project Sdk="Microsoft.NET.Sdk">

<PropertyGroup>
<TargetFrameworks>net452;net462;netcoreapp3.1</TargetFrameworks>
<TargetFrameworks>net452;net462;net472;netcoreapp3.1</TargetFrameworks>
<TargetFrameworks Condition=" '$(OS)' != 'Windows_NT' ">netstandard2.0</TargetFrameworks>
<TreatWarningsAsErrors>true</TreatWarningsAsErrors>
<AssemblyName>Serilog.Sinks.MSSqlServer.Tests</AssemblyName>
Expand Down Expand Up @@ -40,6 +40,7 @@

<ItemGroup Condition=" '$(TargetFramework)' == 'net452' ">
<Reference Include="System" />
<Reference Include="System.Transactions" />
<Reference Include="Microsoft.CSharp" />
<PackageReference Include="xunit" Version="2.4.1" />
<PackageReference Include="xunit.runner.visualstudio" Version="2.4.1" />
Expand All @@ -48,6 +49,7 @@

<ItemGroup Condition=" '$(TargetFramework)' == 'net462' ">
<Reference Include="System" />
<Reference Include="System.Transactions" />
<Reference Include="Microsoft.CSharp" />
<PackageReference Include="xunit" Version="2.4.1" />
<PackageReference Include="xunit.runner.visualstudio" Version="2.4.1" />
Expand All @@ -56,6 +58,18 @@
<Compile Include="Sinks\MSSqlServer\Platform\AzureManagedServiceAuthenticatorStubTests.cs" />
</ItemGroup>

<ItemGroup Condition=" '$(TargetFramework)' == 'net472' ">
<Reference Include="System" />
<Reference Include="System.Transactions" />
<Reference Include="Microsoft.CSharp" />
<PackageReference Include="xunit" Version="2.4.1" />
<PackageReference Include="xunit.runner.visualstudio" Version="2.4.1" />
<Compile Remove="Sinks\MSSqlServer\Platform\AzureManagedServiceAuthenticatorStubTests.cs" />
<Compile Include="Configuration\Extensions\Hybrid\**\*.cs" />
<Compile Include="Configuration\Implementations\System.Configuration\**\*.cs" />
<Compile Include="Sinks\MSSqlServer\Platform\AzureManagedServiceAuthenticatorTests.cs" />
</ItemGroup>

<ItemGroup Condition=" '$(TargetFramework)' == 'netcoreapp3.1' ">
<PackageReference Include="System.Collections" Version="4.3.0" />
<PackageReference Include="System.Runtime.InteropServices" Version="4.3.0" />
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -8,7 +8,7 @@
using Serilog.Sinks.MSSqlServer.Tests.TestUtils;
using Xunit;

namespace Serilog.Sinks.MSSqlServer.Tests.Sinks.MSSqlServer.Platform.SqlClient
namespace Serilog.Sinks.MSSqlServer.Tests.Platform.SqlClient
{
[Trait(TestCategory.TraitName, TestCategory.Unit)]
public class SqlBulkCopyWrapperTests
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -8,7 +8,7 @@
using Serilog.Sinks.MSSqlServer.Tests.TestUtils;
using Serilog.Sinks.MSSqlServer.Platform.SqlClient;

namespace Serilog.Sinks.MSSqlServer.Tests.Sinks.MSSqlServer.Platform.SqlClient
namespace Serilog.Sinks.MSSqlServer.Tests.Platform.SqlClient
{
[Trait(TestCategory.TraitName, TestCategory.Unit)]
public class SqlCommandWrapperTests
Expand Down
Loading