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

Use sent_at instead of sentry_timestamp to reduce clock skew #1690

Merged
merged 18 commits into from Jul 22, 2022
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.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
1 change: 1 addition & 0 deletions CHANGELOG.md
Expand Up @@ -4,6 +4,7 @@

### Features

- Use `sent_at` instead of `sentry_timestamp` to reduce clock skew ([#1690](https://github.com/getsentry/sentry-dotnet/pull/1690))
- Send project root path with events ([#1739](https://github.com/getsentry/sentry-dotnet/pull/1739))

### Fixes
Expand Down
46 changes: 35 additions & 11 deletions src/Sentry/Envelopes/Envelope.cs
Expand Up @@ -6,6 +6,7 @@
using System.Threading;
using System.Threading.Tasks;
using Sentry.Extensibility;
using Sentry.Infrastructure;
using Sentry.Internal;
using Sentry.Internal.Extensions;

Expand All @@ -16,7 +17,9 @@ namespace Sentry.Protocol.Envelopes
/// </summary>
public sealed class Envelope : ISerializable, IDisposable
{
private const string SdkKey = "sdk";
private const string EventIdKey = "event_id";
private const string SentAtKey = "sent_at";

/// <summary>
/// Header associated with the envelope.
Expand All @@ -38,7 +41,7 @@ public Envelope(IReadOnlyDictionary<string, object?> header, IReadOnlyList<Envel
}

/// <summary>
/// Attempts to extract the value of "sentry_id" header if it's present.
/// Attempts to extract the value of "event_id" header if it's present.
/// </summary>
public SentryId? TryGetEventId() =>
Header.TryGetValue(EventIdKey, out var value) &&
Expand All @@ -47,33 +50,51 @@ public Envelope(IReadOnlyDictionary<string, object?> header, IReadOnlyList<Envel
? new SentryId(guid)
: null;

private async Task SerializeHeaderAsync(Stream stream, IDiagnosticLogger? logger, CancellationToken cancellationToken)
private async Task SerializeHeaderAsync(
Stream stream,
IDiagnosticLogger? logger,
ISystemClock clock,
CancellationToken cancellationToken)
mattjohnsonpint marked this conversation as resolved.
Show resolved Hide resolved
{
var headerItems = Header.Append(SentAtKey, clock.GetUtcNow());
var writer = new Utf8JsonWriter(stream);

#if NET461 || NETSTANDARD2_0
using (writer)
await using (writer)
#else
await using (writer.ConfigureAwait(false))
#endif
{
writer.WriteDictionaryValue(Header, logger);
writer.WriteDictionaryValue(headerItems, logger);
await writer.FlushAsync(cancellationToken).ConfigureAwait(false);
}
}

private void SerializeHeader(Stream stream, IDiagnosticLogger? logger)
private void SerializeHeader(Stream stream, IDiagnosticLogger? logger, ISystemClock clock)
{
var headerItems = Header.Append(SentAtKey, clock.GetUtcNow());
using var writer = new Utf8JsonWriter(stream);
writer.WriteDictionaryValue(Header, logger);
writer.WriteDictionaryValue(headerItems, logger);
writer.Flush();
}

// Gets the header and adds a sent_at timestamp

/// <inheritdoc />
public async Task SerializeAsync(Stream stream, IDiagnosticLogger? logger, CancellationToken cancellationToken = default)
public Task SerializeAsync(
Stream stream,
IDiagnosticLogger? logger,
CancellationToken cancellationToken = default) =>
SerializeAsync(stream, logger, SystemClock.Clock, cancellationToken);

internal async Task SerializeAsync(
Stream stream,
IDiagnosticLogger? logger,
ISystemClock clock,
CancellationToken cancellationToken = default)
{
// Header
await SerializeHeaderAsync(stream, logger, cancellationToken).ConfigureAwait(false);
await SerializeHeaderAsync(stream, logger, clock, cancellationToken).ConfigureAwait(false);
await stream.WriteByteAsync((byte)'\n', cancellationToken).ConfigureAwait(false);

// Items
Expand All @@ -85,10 +106,13 @@ public async Task SerializeAsync(Stream stream, IDiagnosticLogger? logger, Cance
}

/// <inheritdoc />
public void Serialize(Stream stream, IDiagnosticLogger? logger)
public void Serialize(Stream stream, IDiagnosticLogger? logger) =>
Serialize(stream, logger, SystemClock.Clock);

internal void Serialize(Stream stream, IDiagnosticLogger? logger, ISystemClock clock)
{
// Header
SerializeHeader(stream, logger);
SerializeHeader(stream, logger, clock);
stream.WriteByte((byte)'\n');

// Items
Expand Down Expand Up @@ -123,7 +147,7 @@ public void Serialize(Stream stream, IDiagnosticLogger? logger)

return new Dictionary<string, object?>(2, StringComparer.Ordinal)
{
["sdk"] = SdkHeader,
[SdkKey] = SdkHeader,
[EventIdKey] = eventId.Value.ToString()
};
}
Expand Down
17 changes: 8 additions & 9 deletions src/Sentry/Http/HttpTransportBase.cs
Expand Up @@ -46,7 +46,7 @@ public abstract class HttpTransportBase
ISystemClock? clock = default)
{
_options = options;
_clock = clock ?? new SystemClock();
_clock = clock ?? SystemClock.Clock;
_getEnvironmentVariable = getEnvironmentVariable ?? Environment.GetEnvironmentVariable;
}

Expand Down Expand Up @@ -184,16 +184,15 @@ protected internal HttpRequestMessage CreateRequest(Envelope envelope)
var authHeader =
$"Sentry sentry_version={_options.SentryVersion}," +
$"sentry_client={SdkVersion.Instance.Name}/{SdkVersion.Instance.Version}," +
$"sentry_key={dsn.PublicKey}," +
(dsn.SecretKey is { } secretKey ? $"sentry_secret={secretKey}," : null) +
$"sentry_timestamp={_clock.GetUtcNow().ToUnixTimeSeconds()}";
$"sentry_key={dsn.PublicKey}" +
(dsn.SecretKey is { } secretKey ? $",sentry_secret={secretKey}" : null);

return new HttpRequestMessage
{
RequestUri = dsn.GetEnvelopeEndpointUri(),
Method = HttpMethod.Post,
Headers = {{"X-Sentry-Auth", authHeader}},
Content = new EnvelopeHttpContent(envelope, _options.DiagnosticLogger)
Content = new EnvelopeHttpContent(envelope, _options.DiagnosticLogger, _clock)
};
}

Expand Down Expand Up @@ -286,7 +285,7 @@ private void HandleSuccess(Envelope envelope)
{
if (_options.DiagnosticLogger?.IsEnabled(SentryLevel.Debug) is true)
{
var payload = envelope.SerializeToString(_options.DiagnosticLogger);
var payload = envelope.SerializeToString(_options.DiagnosticLogger, _clock);
_options.LogDebug("Envelope '{0}' sent successfully. Payload:\n{1}",
envelope.TryGetEventId(),
payload);
Expand All @@ -302,7 +301,7 @@ private async Task HandleSuccessAsync(Envelope envelope, CancellationToken cance
{
if (_options.DiagnosticLogger?.IsEnabled(SentryLevel.Debug) is true)
{
var payload = await envelope.SerializeToStringAsync(_options.DiagnosticLogger, cancellationToken)
var payload = await envelope.SerializeToStringAsync(_options.DiagnosticLogger, _clock, cancellationToken)
.ConfigureAwait(false);

_options.LogDebug("Envelope '{0}' sent successfully. Payload:\n{1}",
Expand Down Expand Up @@ -338,7 +337,7 @@ private void HandleFailure(HttpResponseMessage response, Envelope envelope)
// If debug level, dump the whole envelope to the logger
if (_options.DiagnosticLogger?.IsEnabled(SentryLevel.Debug) is true)
{
var payload = envelope.SerializeToString(_options.DiagnosticLogger);
var payload = envelope.SerializeToString(_options.DiagnosticLogger, _clock);
_options.LogDebug("Failed envelope '{0}' has payload:\n{1}\n", envelope.TryGetEventId(), payload);

// SDK is in debug mode, and envelope was too large. To help troubleshoot:
Expand Down Expand Up @@ -393,7 +392,7 @@ private void HandleFailure(HttpResponseMessage response, Envelope envelope)
if (_options.DiagnosticLogger?.IsEnabled(SentryLevel.Debug) is true)
{
var payload = await envelope
.SerializeToStringAsync(_options.DiagnosticLogger, cancellationToken).ConfigureAwait(false);
.SerializeToStringAsync(_options.DiagnosticLogger, _clock, cancellationToken).ConfigureAwait(false);
_options.LogDebug("Failed envelope '{0}' has payload:\n{1}\n", envelope.TryGetEventId(), payload);


Expand Down
13 changes: 13 additions & 0 deletions src/Sentry/Infrastructure/SystemClock.cs
Expand Up @@ -8,10 +8,23 @@ namespace Sentry.Infrastructure
/// <seealso cref="ISystemClock" />
public sealed class SystemClock : ISystemClock
{
/// <summary>
/// Constructs a SystemClock instance.
/// </summary>
/// <remarks>
/// This constructor should have been private originally. It will be removed in a future major version.
/// </remarks>
[Obsolete("This constructor will become private in a future major version. Use the `SystemClock.Clock` singleton instead.")]
public SystemClock()
{
}

/// <summary>
/// System clock singleton.
/// </summary>
#pragma warning disable CS0618
public static readonly SystemClock Clock = new();
#pragma warning restore CS0618

/// <summary>
/// Gets the current time in UTC.
Expand Down
2 changes: 1 addition & 1 deletion src/Sentry/Internal/ClientReportRecorder.cs
Expand Up @@ -17,7 +17,7 @@ internal class ClientReportRecorder : IClientReportRecorder
public ClientReportRecorder(SentryOptions options, ISystemClock? clock = default)
{
_options = options;
_clock = clock ?? new SystemClock();
_clock = clock ?? SystemClock.Clock;
}

public void RecordDiscardedEvent(DiscardReason reason, DataCategory category)
Expand Down
4 changes: 4 additions & 0 deletions src/Sentry/Internal/Extensions/CollectionsExtensions.cs
Expand Up @@ -50,6 +50,10 @@ internal static class CollectionsExtensions
}
}

public static IEnumerable<KeyValuePair<TKey, TValue>> Append<TKey, TValue>(
this IEnumerable<KeyValuePair<TKey, TValue>> source, TKey key, TValue value) =>
source.Append(new KeyValuePair<TKey, TValue>(key, value));

public static IReadOnlyList<T> AsReadOnly<T>(this IList<T> list) =>
list is IReadOnlyList<T> readOnlyList
? readOnlyList
Expand Down
9 changes: 6 additions & 3 deletions src/Sentry/Internal/Http/EnvelopeHttpContent.cs
Expand Up @@ -4,6 +4,7 @@
using System.Net.Http;
using System.Threading.Tasks;
using Sentry.Extensibility;
using Sentry.Infrastructure;
using Sentry.Protocol.Envelopes;

#if NET5_0_OR_GREATER
Expand All @@ -16,18 +17,20 @@ internal class EnvelopeHttpContent : HttpContent
{
private readonly Envelope _envelope;
private readonly IDiagnosticLogger? _logger;
private readonly ISystemClock _clock;

public EnvelopeHttpContent(Envelope envelope, IDiagnosticLogger? logger)
public EnvelopeHttpContent(Envelope envelope, IDiagnosticLogger? logger, ISystemClock clock)
{
_envelope = envelope;
_logger = logger;
_clock = clock;
}

protected override async Task SerializeToStreamAsync(Stream stream, TransportContext? context)
{
try
{
await _envelope.SerializeAsync(stream, _logger).ConfigureAwait(false);
await _envelope.SerializeAsync(stream, _logger, _clock).ConfigureAwait(false);
}
catch (Exception e)
{
Expand All @@ -44,7 +47,7 @@ internal void SerializeToStream(Stream stream)
{
try
{
_envelope.Serialize(stream, _logger);
_envelope.Serialize(stream, _logger, _clock);
}
catch (Exception e)
{
Expand Down
18 changes: 18 additions & 0 deletions src/Sentry/Internal/Polyfills.cs
Expand Up @@ -61,6 +61,24 @@ internal static class PolyfillExtensions
}
#endif

#if NET461
namespace System.Linq
{
internal static class PolyfillExtensions
{
public static IEnumerable<TSource> Append<TSource>(this IEnumerable<TSource> source, TSource element)
{
foreach (var item in source)
{
yield return item;
}

yield return element;
}
}
}
#endif

#if !NET5_0_OR_GREATER
internal static partial class PolyfillExtensions
{
Expand Down
27 changes: 23 additions & 4 deletions src/Sentry/Internal/SerializableExtensions.cs
@@ -1,8 +1,8 @@
using System.IO;
using System.Text;
using System.Threading;
using System.Threading.Tasks;
using Sentry.Extensibility;
using Sentry.Infrastructure;
using Sentry.Protocol.Envelopes;

namespace Sentry.Internal
Expand All @@ -12,6 +12,7 @@ internal static class SerializableExtensions
public static async Task<string> SerializeToStringAsync(
this ISerializable serializable,
IDiagnosticLogger logger,
ISystemClock? clock = null,
CancellationToken cancellationToken = default)
{
var stream = new MemoryStream();
Expand All @@ -21,18 +22,36 @@ internal static class SerializableExtensions
await using (stream.ConfigureAwait(false))
#endif
{
await serializable.SerializeAsync(stream, logger, cancellationToken).ConfigureAwait(false);
if (clock != null && serializable is Envelope envelope)
{
await envelope.SerializeAsync(stream, logger, clock, cancellationToken).ConfigureAwait(false);
}
else
{
await serializable.SerializeAsync(stream, logger, cancellationToken).ConfigureAwait(false);
}

stream.Seek(0, SeekOrigin.Begin);
using var reader = new StreamReader(stream);
return await reader.ReadToEndAsync().ConfigureAwait(false);
}
}

public static string SerializeToString(this ISerializable serializable, IDiagnosticLogger logger)
public static string SerializeToString(
this ISerializable serializable,
IDiagnosticLogger logger,
ISystemClock? clock = null)
{
using var stream = new MemoryStream();
serializable.Serialize(stream, logger);

if (clock != null && serializable is Envelope envelope)
{
envelope.Serialize(stream, logger, clock);
}
else
{
serializable.Serialize(stream, logger);
}

stream.Seek(0, SeekOrigin.Begin);
using var reader = new StreamReader(stream);
Expand Down
4 changes: 2 additions & 2 deletions test/Sentry.AspNetCore.Tests/MiddlewareLoggerIntegration.cs
Expand Up @@ -7,6 +7,7 @@
using Microsoft.AspNetCore.Http.Features;
using Microsoft.Extensions.Logging;
using Sentry.Extensions.Logging;
using Sentry.Testing;

namespace Sentry.AspNetCore.Tests;

Expand All @@ -20,7 +21,6 @@ private class Fixture : IDisposable
public IHub Hub { get; set; }
public Func<IHub> HubAccessor { get; set; }
public ISentryClient Client { get; set; } = Substitute.For<ISentryClient>();
public ISystemClock Clock { get; set; } = Substitute.For<ISystemClock>();
public SentryAspNetCoreOptions Options { get; set; } = new();
public IHostingEnvironment HostingEnvironment { get; set; } = Substitute.For<IHostingEnvironment>();
public ILogger<SentryMiddleware> MiddlewareLogger { get; set; } = Substitute.For<ILogger<SentryMiddleware>>();
Expand All @@ -44,7 +44,7 @@ public Fixture()
var hub = new Hub(new SentryOptions { Dsn = ValidDsn });
hub.BindClient(Client);
Hub = hub;
var provider = new SentryLoggerProvider(hub, Clock, loggingOptions);
var provider = new SentryLoggerProvider(hub, new MockClock(), loggingOptions);
_disposable = provider;
SentryLogger = provider.CreateLogger(nameof(SentryLogger));
_ = HttpContext.Features.Returns(FeatureCollection);
Expand Down
Expand Up @@ -1125,6 +1125,8 @@ namespace Sentry.Infrastructure
public sealed class SystemClock : Sentry.Infrastructure.ISystemClock
{
public static readonly Sentry.Infrastructure.SystemClock Clock;
[System.Obsolete("This constructor will become private in a future major version. Use the `SystemCl" +
"ock.Clock` singleton instead.")]
public SystemClock() { }
public System.DateTimeOffset GetUtcNow() { }
}
Expand Down
Expand Up @@ -1125,6 +1125,8 @@ namespace Sentry.Infrastructure
public sealed class SystemClock : Sentry.Infrastructure.ISystemClock
{
public static readonly Sentry.Infrastructure.SystemClock Clock;
[System.Obsolete("This constructor will become private in a future major version. Use the `SystemCl" +
"ock.Clock` singleton instead.")]
public SystemClock() { }
public System.DateTimeOffset GetUtcNow() { }
}
Expand Down