Use sent_at instead of sentry_timestamp to reduce clock skew (#1690)

CHANGELOG.md

@@ -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

src/Sentry/Envelopes/Envelope.cs

@@ -6,6 +6,7 @@
 using System.Threading;
 using System.Threading.Tasks;
 using Sentry.Extensibility;
+using Sentry.Infrastructure;
 using Sentry.Internal;
 using Sentry.Internal.Extensions;
 
@@ -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.
@@ -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) &&
@@ -47,33 +50,51 @@ value is string valueString &&
                 ? 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)
         {
+            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
@@ -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
@@ -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()
             };
         }

src/Sentry/Http/HttpTransportBase.cs

@@ -46,7 +46,7 @@ protected HttpTransportBase(SentryOptions options,
             ISystemClock? clock = default)
         {
             _options = options;
-            _clock = clock ?? new SystemClock();
+            _clock = clock ?? SystemClock.Clock;
             _getEnvironmentVariable = getEnvironmentVariable ?? Environment.GetEnvironmentVariable;
         }
 
@@ -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)
             };
         }
 
@@ -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);
@@ -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}",
@@ -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:
@@ -393,7 +392,7 @@ private async Task HandleFailureAsync(HttpResponseMessage response, Envelope env
             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);
 
 

src/Sentry/Infrastructure/SystemClock.cs

@@ -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.

src/Sentry/Internal/ClientReportRecorder.cs

@@ -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)

src/Sentry/Internal/Extensions/CollectionsExtensions.cs

@@ -50,6 +50,10 @@ public static IEnumerable<KeyValuePair<TKey, TValue>> WhereNotNullValue<TKey, TV
             }
         }
 
+        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

src/Sentry/Internal/Http/EnvelopeHttpContent.cs

@@ -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
@@ -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)
             {
@@ -44,7 +47,7 @@ internal void SerializeToStream(Stream stream)
         {
             try
             {
-                _envelope.Serialize(stream, _logger);
+                _envelope.Serialize(stream, _logger, _clock);
             }
             catch (Exception e)
             {

src/Sentry/Internal/Polyfills.cs

@@ -61,6 +61,24 @@ public static IEnumerable<T> SkipLast<T>(this IEnumerable<T> source, int count)
 }
 #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
 {

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
@@ -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();
@@ -21,18 +22,36 @@ public static async Task<string> SerializeToStringAsync(
             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);

test/Sentry.AspNetCore.Tests/MiddlewareLoggerIntegration.cs

@@ -7,6 +7,7 @@
 using Microsoft.AspNetCore.Http.Features;
 using Microsoft.Extensions.Logging;
 using Sentry.Extensions.Logging;
+using Sentry.Testing;
 
 namespace Sentry.AspNetCore.Tests;
 
@@ -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>>();
@@ -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);

test/Sentry.DiagnosticSource.Tests/ApiApprovalTests.Run.Core3_1.verified.txt

@@ -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() { }
     }

test/Sentry.DiagnosticSource.Tests/ApiApprovalTests.Run.DotNet5_0.verified.txt

@@ -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() { }
     }