Skip to content

Merged changes from dev #233

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

Merged
merged 6 commits into from
Mar 10, 2020
Merged
Show file tree
Hide file tree
Changes from all 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
13 changes: 11 additions & 2 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -99,7 +99,7 @@ var log = new LoggerConfiguration()
.WriteTo.MSSqlServer(
connectionString: logDB,
tableName: logTable,
columnOptions: opts
columnOptions: options
).CreateLogger();

```
Expand Down Expand Up @@ -368,7 +368,16 @@ This column stores the event level (Error, Information, etc.). For backwards-com

### TimeStamp

This column stores the time the log event was sent to Serilog as a SQL `datetime` type. While this may appear to be a good candidate as a clustered primary key, even relatively low-volume logging can emit identical timestamps forcing SQL Server to add a "uniqueifier" value behind the scenes (effectively an auto-incrementing identity-like integer). For frequent timestamp range-searching and sorting, a non-clustered index is better.
This column stores the time the log event was sent to Serilog as a SQL `datetime` (default) or `datetimeoffset` type. If `datetimeoffset` should be used, this can be configured as follows.

```csharp
var columnOptions = new ColumnOptions();
columnOptions.TimeStamp.DataType = SqlDbType.DateTimeOffset;
```

Please be aware that you have to configure the sink for `datetimeoffset` if the used logging database table has a `TimeStamp` column of type `datetimeoffset`. On the other hand you must not configure for `datetimeoffset` if the `TimeStamp` column is of type `datetime`. Failing to configure the data type accordingly can result in log table entries with wrong timezone offsets or no log entries being created at all due to exceptions during logging.

While TimeStamp may appear to be a good candidate as a clustered primary key, even relatively low-volume logging can emit identical timestamps forcing SQL Server to add a "uniqueifier" value behind the scenes (effectively an auto-incrementing identity-like integer). For frequent timestamp range-searching and sorting, a non-clustered index is better.

When the `ConvertToUtc` property is set to `true`, the time stamp is adjusted to the UTC standard. Normally the time stamp value reflects the local time of the machine issuing the log event, including the current timezone information. For example, if the event is written at 07:00 Eastern time, the Eastern timezone is +4:00 relative to UTC, so after UTC conversion the time stamp will be 11:00. Offset is stored as +0:00 but this is _not_ the GMT time zone because UTC does not use offsets (by definition). To state this another way, the timezone is discarded and unrecoverable. UTC is a representation of the date and time _exclusive_ of timezone information. This makes it easy to reference time stamps written from different or changing timezones.

Expand Down
12 changes: 6 additions & 6 deletions src/Serilog.Sinks.MSSqlServer/Properties/AssemblyInfo.cs
Original file line number Diff line number Diff line change
Expand Up @@ -3,10 +3,10 @@

[assembly: AssemblyTitle("Serilog.Sinks.MSSqlServer")]
[assembly: AssemblyDescription("Serilog sink for MSSqlServer")]
[assembly: AssemblyCopyright("Copyright © Serilog Contributors 2014")]
[assembly: AssemblyCopyright("Copyright © Serilog Contributors 2020")]

[assembly: InternalsVisibleTo("Serilog.Tests, PublicKey=0024000004800000940000000602000000240000525341310004000001000100fb8d13fd344a1c" +
"6fe0fe83ef33c1080bf30690765bc6eb0df26ebfdf8f21670c64265b30db09f73a0dea5b3db4c9" +
"d18dbf6d5a25af5ce9016f281014d79dc3b4201ac646c451830fc7e61a2dfd633d34c39f87b818" +
"94191652df5ac63cc40c77f3542f702bda692e6e8a9158353df189007a49da0f3cfd55eb250066" +
"b19485ec")]
[assembly: InternalsVisibleTo("Serilog.Sinks.MSSqlServer.Tests, PublicKey=0024000004800000940000000602000000240000525341310004000001000100fb8d13fd344a1c" +
"6fe0fe83ef33c1080bf30690765bc6eb0df26ebfdf8f21670c64265b30db09f73a0dea5b3db4c9" +
"d18dbf6d5a25af5ce9016f281014d79dc3b4201ac646c451830fc7e61a2dfd633d34c39f87b818" +
"94191652df5ac63cc40c77f3542f702bda692e6e8a9158353df189007a49da0f3cfd55eb250066" +
"b19485ec")]
Original file line number Diff line number Diff line change
Expand Up @@ -2,7 +2,7 @@

<PropertyGroup>
<Description>A Serilog sink that writes events to Microsoft SQL Server</Description>
<VersionPrefix>5.1.3</VersionPrefix>
<VersionPrefix>5.1.4</VersionPrefix>
<Authors>Michiel van Oudheusden;Serilog Contributors</Authors>
<TargetFrameworks>netstandard2.0;net452;netcoreapp2.0;net461</TargetFrameworks>
<TreatWarningsAsErrors>true</TreatWarningsAsErrors>
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -20,15 +20,15 @@ public TimeStampColumnOptions() : base()
}

/// <summary>
/// The TimeStamp column only supports the DateTime data type.
/// The TimeStamp column only supports the DateTime and DateTimeOffset data types.
/// </summary>
public new SqlDbType DataType
{
get => base.DataType;
set
{
if (value != SqlDbType.DateTime)
throw new ArgumentException("The Standard Column \"TimeStamp\" only supports the DateTime format.");
if (value != SqlDbType.DateTime && value != SqlDbType.DateTimeOffset)
throw new ArgumentException("The Standard Column \"TimeStamp\" only supports the DateTime and DateTimeOffset formats.");
base.DataType = value;
}
}
Expand Down
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
// Copyright 2018 Serilog Contributors
// Copyright 2020 Serilog Contributors
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
Expand All @@ -17,7 +17,6 @@
using System;
using System.Collections.Generic;
using System.Data;
using System.IO;
using System.Linq;
using System.Text;

Expand Down Expand Up @@ -120,7 +119,7 @@ internal KeyValuePair<string, object> GetStandardColumnNameAndValue(StandardColu
case StandardColumn.Level:
return new KeyValuePair<string, object>(columnOptions.Level.ColumnName, columnOptions.Level.StoreAsEnum ? (object)logEvent.Level : logEvent.Level.ToString());
case StandardColumn.TimeStamp:
return new KeyValuePair<string, object>(columnOptions.TimeStamp.ColumnName, columnOptions.TimeStamp.ConvertToUtc ? logEvent.Timestamp.ToUniversalTime().DateTime : logEvent.Timestamp.DateTime);
return GetTimeStampStandardColumnNameAndValue(logEvent);
case StandardColumn.Exception:
return new KeyValuePair<string, object>(columnOptions.Exception.ColumnName, logEvent.Exception != null ? logEvent.Exception.ToString() : null);
case StandardColumn.Properties:
Expand All @@ -132,6 +131,16 @@ internal KeyValuePair<string, object> GetStandardColumnNameAndValue(StandardColu
}
}

private KeyValuePair<string, object> GetTimeStampStandardColumnNameAndValue(LogEvent logEvent)
{
var dateTimeOffset = columnOptions.TimeStamp.ConvertToUtc ? logEvent.Timestamp.ToUniversalTime() : logEvent.Timestamp;

if (columnOptions.TimeStamp.DataType == SqlDbType.DateTimeOffset)
return new KeyValuePair<string, object>(columnOptions.TimeStamp.ColumnName, dateTimeOffset);

return new KeyValuePair<string, object>(columnOptions.TimeStamp.ColumnName, dateTimeOffset.DateTime);
}

private string LogEventToJson(LogEvent logEvent)
{
if (columnOptions.LogEvent.ExcludeAdditionalProperties)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -10,7 +10,7 @@
namespace Serilog.Sinks.MSSqlServer.Tests
{
[Collection("LogTest")]
public class ConfigurationExtensions : IDisposable
public sealed class ConfigurationExtensions : IDisposable
{
static string ConnectionStringName = "NamedConnection";
static string ColumnOptionsSection = "CustomColumnNames";
Expand Down
10 changes: 10 additions & 0 deletions test/Serilog.Sinks.MSSqlServer.Tests/DapperQueryTemplates.cs
Original file line number Diff line number Diff line change
Expand Up @@ -70,6 +70,16 @@ public class StringLevelStandardLogColumns
public string Level { get; set; }
}

public class TestTimeStampDateTimeOffsetEntry
{
public DateTimeOffset TimeStamp { get; set; }
}

public class TestTimeStampDateTimeEntry
{
public DateTime TimeStamp { get; set; }
}

public class TestTriggerEntry
{
public Guid Id { get; set; }
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,42 @@
using System;
using System.Data;
using Xunit;

namespace Serilog.Sinks.MSSqlServer.Tests.Sinks.MSSqlServer.ColumnOptions
{
public class TestTimeStampColumnOptions
{
[Trait("Bugfix", "#187")]
[Fact]
public void CanSetDataTypeDateTime()
{
// arrange
var options = new Serilog.Sinks.MSSqlServer.ColumnOptions();

// act - should not throw
options.TimeStamp.DataType = SqlDbType.DateTime;
}

[Trait("Bugfix", "#187")]
[Fact]
public void CanSetDataTypeDateTimeOffset()
{
// arrange
var options = new Serilog.Sinks.MSSqlServer.ColumnOptions();

// act - should not throw
options.TimeStamp.DataType = SqlDbType.DateTimeOffset;
}

[Trait("Bugfix", "#187")]
[Fact]
public void CannotSetDataTypeNVarChar()
{
// arrange
var options = new Serilog.Sinks.MSSqlServer.ColumnOptions();

// act and assert - should throw
Assert.Throws<ArgumentException>(() => options.TimeStamp.DataType = SqlDbType.NVarChar);
}
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,110 @@
using Serilog.Events;
using Serilog.Parsing;
using System;
using System.Collections.Generic;
using System.Data;
using System.Globalization;
using System.Linq;
using Xunit;

namespace Serilog.Sinks.MSSqlServer.Tests.Sinks.MSSqlServer
{
public class TestMSSqlServerSinkTraits
{
private MSSqlServerSinkTraits traits;
private LogEvent logEvent;

[Trait("Bugfix", "#187")]
[Fact]
public void GetColumnsAndValuesCreatesTimeStampOfTypeDateTimeAccordingToColumnOptions()
{
// arrange
var options = new Serilog.Sinks.MSSqlServer.ColumnOptions();
var testDateTimeOffset = new DateTimeOffset(2020, 1, 1, 9, 0, 0, new TimeSpan(1, 0, 0)); // Timezone +1:00
SetupTest(options, testDateTimeOffset);

// act
var columns = traits.GetColumnsAndValues(logEvent);

// assert
var timeStampColumn = columns.Single(c => c.Key == options.TimeStamp.ColumnName);
Assert.IsType<DateTime>(timeStampColumn.Value);
Assert.Equal(testDateTimeOffset.Hour, ((DateTime)timeStampColumn.Value).Hour);
}

[Trait("Bugfix", "#187")]
[Fact]
public void GetColumnsAndValuesCreatesUtcConvertedTimeStampOfTypeDateTimeAccordingToColumnOptions()
{
// arrange
var options = new Serilog.Sinks.MSSqlServer.ColumnOptions
{
TimeStamp = { ConvertToUtc = true }
};
var testDateTimeOffset = new DateTimeOffset(2020, 1, 1, 9, 0, 0, new TimeSpan(1, 0, 0)); // Timezone +1:00
SetupTest(options, testDateTimeOffset);

// act
var columns = traits.GetColumnsAndValues(logEvent);

// assert
var timeStampColumn = columns.Single(c => c.Key == options.TimeStamp.ColumnName);
Assert.IsType<DateTime>(timeStampColumn.Value);
Assert.Equal(testDateTimeOffset.Hour - 1, ((DateTime)timeStampColumn.Value).Hour);
}

[Trait("Bugfix", "#187")]
[Fact]
public void GetColumnsAndValuesCreatesTimeStampOfTypeDateTimeOffsetAccordingToColumnOptions()
{
// arrange
var options = new Serilog.Sinks.MSSqlServer.ColumnOptions
{
TimeStamp = { DataType = SqlDbType.DateTimeOffset }
};
var testDateTimeOffset = new DateTimeOffset(2020, 1, 1, 9, 0, 0, new TimeSpan(1, 0, 0)); // Timezone +1:00
SetupTest(options, testDateTimeOffset);

// act
var columns = traits.GetColumnsAndValues(logEvent);

// assert
var timeStampColumn = columns.Single(c => c.Key == options.TimeStamp.ColumnName);
Assert.IsType<DateTimeOffset>(timeStampColumn.Value);
var timeStampColumnOffset = (DateTimeOffset)timeStampColumn.Value;
Assert.Equal(testDateTimeOffset.Hour, timeStampColumnOffset.Hour);
Assert.Equal(testDateTimeOffset.Offset, timeStampColumnOffset.Offset);
}

[Trait("Bugfix", "#187")]
[Fact]
public void GetColumnsAndValuesCreatesUtcConvertedTimeStampOfTypeDateTimeOffsetAccordingToColumnOptions()
{
// arrange
var options = new Serilog.Sinks.MSSqlServer.ColumnOptions
{
TimeStamp = { DataType = SqlDbType.DateTimeOffset, ConvertToUtc = true }
};
var testDateTimeOffset = new DateTimeOffset(2020, 1, 1, 9, 0, 0, new TimeSpan(1, 0, 0)); // Timezone +1:00
SetupTest(options, testDateTimeOffset);

// act
var columns = traits.GetColumnsAndValues(logEvent);

// assert
var timeStampColumn = columns.Single(c => c.Key == options.TimeStamp.ColumnName);
Assert.IsType<DateTimeOffset>(timeStampColumn.Value);
var timeStampColumnOffset = (DateTimeOffset)timeStampColumn.Value;
Assert.Equal(testDateTimeOffset.Hour - 1, timeStampColumnOffset.Hour);
Assert.Equal(new TimeSpan(0), timeStampColumnOffset.Offset);
}

private void SetupTest(Serilog.Sinks.MSSqlServer.ColumnOptions options, DateTimeOffset testDateTimeOffset)
{
this.traits = new MSSqlServerSinkTraits("connectionString", "tableName", "schemaName",
options, CultureInfo.InvariantCulture, false);
this.logEvent = new LogEvent(testDateTimeOffset, LogEventLevel.Information, null,
new MessageTemplate(new List<MessageTemplateToken>()), new List<LogEventProperty>());
}
}
}
104 changes: 104 additions & 0 deletions test/Serilog.Sinks.MSSqlServer.Tests/TestTimeStamp.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,104 @@
using System;
using System.Data;
using System.Data.SqlClient;
using System.IO;
using Dapper;
using FluentAssertions;
using Xunit;

namespace Serilog.Sinks.MSSqlServer.Tests
{
[Collection("LogTest")]
public class TestTimeStamp : IDisposable
{
[Trait("Bugfix", "#187")]
[Fact]
public void CanCreateDatabaseWithDateTimeByDefault()
{
// arrange
var loggerConfiguration = new LoggerConfiguration();
Log.Logger = loggerConfiguration.WriteTo.MSSqlServer(
connectionString: DatabaseFixture.LogEventsConnectionString,
tableName: DatabaseFixture.LogTableName,
autoCreateSqlTable: true,
batchPostingLimit: 1,
period: TimeSpan.FromSeconds(10),
columnOptions: new ColumnOptions())
.CreateLogger();

// act
const string loggingInformationMessage = "Logging Information message";
Log.Information(loggingInformationMessage);
Log.CloseAndFlush();

// assert
using (var conn = new SqlConnection(DatabaseFixture.LogEventsConnectionString))
{
var logEvents = conn.Query<TestTimeStampDateTimeEntry>($"SELECT TimeStamp FROM {DatabaseFixture.LogTableName}");
logEvents.Should().NotBeEmpty();
}
}

[Trait("Bugfix", "#187")]
[Fact]
public void CanStoreDateTimeOffsetWithCorrectLocalTimeZone()
{
// arrange
var loggerConfiguration = new LoggerConfiguration();
Log.Logger = loggerConfiguration.WriteTo.MSSqlServer(
connectionString: DatabaseFixture.LogEventsConnectionString,
tableName: DatabaseFixture.LogTableName,
autoCreateSqlTable: true,
batchPostingLimit: 1,
period: TimeSpan.FromSeconds(10),
columnOptions: new ColumnOptions { TimeStamp = { DataType = SqlDbType.DateTimeOffset, ConvertToUtc = false }})
.CreateLogger();
var dateTimeOffsetNow = DateTimeOffset.Now;

// act
const string loggingInformationMessage = "Logging Information message";
Log.Information(loggingInformationMessage);
Log.CloseAndFlush();

// assert
using (var conn = new SqlConnection(DatabaseFixture.LogEventsConnectionString))
{
var logEvents = conn.Query<TestTimeStampDateTimeOffsetEntry>($"SELECT TimeStamp FROM {DatabaseFixture.LogTableName}");
logEvents.Should().Contain(e => e.TimeStamp.Offset == dateTimeOffsetNow.Offset);
}
}

[Trait("Bugfix", "#187")]
[Fact]
public void CanStoreDateTimeOffsetWithUtcTimeZone()
{
// arrange
var loggerConfiguration = new LoggerConfiguration();
Log.Logger = loggerConfiguration.WriteTo.MSSqlServer(
connectionString: DatabaseFixture.LogEventsConnectionString,
tableName: DatabaseFixture.LogTableName,
autoCreateSqlTable: true,
batchPostingLimit: 1,
period: TimeSpan.FromSeconds(10),
columnOptions: new ColumnOptions { TimeStamp = { DataType = SqlDbType.DateTimeOffset, ConvertToUtc = true } })
.CreateLogger();

// act
const string loggingInformationMessage = "Logging Information message";
Log.Information(loggingInformationMessage);
Log.CloseAndFlush();

// assert
using (var conn = new SqlConnection(DatabaseFixture.LogEventsConnectionString))
{
var logEvents = conn.Query<TestTimeStampDateTimeOffsetEntry>($"SELECT TimeStamp FROM {DatabaseFixture.LogTableName}");
logEvents.Should().Contain(e => e.TimeStamp.Offset == new TimeSpan(0));
}
}

public void Dispose()
{
DatabaseFixture.DropTable();
}
}
}