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

Sentry. Serilog. Envelopes which are constructed from"Serilog style" log messages cause 400 response from server #1523

Closed
vlaterz opened this issue Mar 14, 2022 · 16 comments
Assignees
Labels
Bug Something isn't working Serilog

Comments

@vlaterz
Copy link

vlaterz commented Mar 14, 2022

Environment

How do you use Sentry?
Sentry SaaS

Which SDK and version?
.NET 5, Sentry.Serilog 3.14.1, Sentry sdk 3.13.0

Steps to Reproduce

I use Serilog with Sentry to write real time logs with caching (if connection is lost).

  1. I configure Sentry sink:
x.WriteTo.Sentry(o =>
                        {
                            o.MinimumBreadcrumbLevel = Serilog.Events.LogEventLevel.Debug;
                            o.MinimumEventLevel = Serilog.Events.LogEventLevel.Error;
                            o.Dsn = "http://e87a7650076d4287adf5fdd654bdeb64@10.0.225.69:9000/2";
                            o.AttachStacktrace = true;
                            o.TracesSampleRate = 1.0;
                            o.SampleRate = 1.0f;
                            o.MaxBreadcrumbs = 5;
                            o.DeduplicateMode = Sentry.DeduplicateMode.All;
                            o.MaxQueueItems = 10;
                            o.MaxCacheItems = 100;
                            o.InitCacheFlushTimeout = new TimeSpan(5000);
                            o.CacheDirectoryPath = Path.Combine(Environment.GetFolderPath(Environment.SpecialFolder.CommonApplicationData), "blah_blah", "SentryCachedLogs");
                            o.SendDefaultPii = true;
                        })
  1. I try to log some info in Serilog style:
for (int i = 0; i < numOfRepeat; i++)
            {
                    _loggerError.Error(@"TestError:  a{i}, {time}", i, DateTime.Now);
            }
  1. After running program logs are cached by Sentry and cleared from cache, as they have been sent, but they don`t get to server. Server responds with 400 status code 'Bad request'.
    Full error: Error: Sentry rejected the envelope afc2b865ade74406bf7aa914c5095a95. Status code: BadRequest. Error detail: invalid event envelope. Error causes: missing newline after header or payload.
    At the same time Sentry Debug says Debug: Successfully sent cached envelope: afc2b865ade74406bf7aa914c5095a95.

I tested sending simple strings as messages and envelopes were successfully received by server.
Like that:

for (int i = 0; i < numOfRepeat; i++)
            {
                    _loggerError.Error($"TestError:  a{i}, {DateTime.Now}");
            }

Expected Result

Envelopes which are constructed from "Serilog style" logging messages are successfully sent to server

Actual Result

image

@vlaterz
Copy link
Author

vlaterz commented Mar 16, 2022

I updated libs to:
Sentry.Serilog -> 3.15.0
Sentry -> 3.15.0
Sentry on server -> 22.3.0
Issue still exists. What am i doing wrong?

@mattjohnsonpint
Copy link
Contributor

@vlaterz - We think this might be a bug. We're looking into it and will get back to you. Thanks!

@SimonCropp
Copy link
Contributor

@vlaterz after taking a close look at this, i am having trouble reproducing it.

Can you capture the full "Failed envelope" text and share it? perhaps by piping the console output to a text file.

What Os+version are you using?

What .net runtime are you targetting?

here is my code that i used to repro

using Serilog;
using Serilog.Events;

internal static class Program
{
    private static void Main()
    {
        Log.Logger = new LoggerConfiguration()
            .Enrich.FromLogContext()
            .MinimumLevel.Debug()
            .WriteTo.Console()
            .WriteTo.Sentry(o =>
            {
                o.Debug = true;
                o.MinimumBreadcrumbLevel = LogEventLevel.Debug;
                o.MinimumEventLevel = LogEventLevel.Debug;
                o.Dsn = ".....";
                o.AttachStacktrace = true;
                o.SampleRate = 1.0f;
                o.MaxBreadcrumbs = 5;
                o.DeduplicateMode = Sentry.DeduplicateMode.All;
                o.MaxQueueItems = 10;
                o.MaxCacheItems = 100;
                o.TracesSampleRate = 1;
                o.InitCacheFlushTimeout = new TimeSpan(5000);
                o.SendDefaultPii = true;
            })
            .CreateLogger();
        for (int i = 0; i < 10; i++)
        {
            Log.Error(@"TestError:  a{i}, {time}", i, DateTime.Now);
        }
        Log.CloseAndFlush();

        Console.Read();
    }
}

can you try the above and see if it works for you

@SimonCropp
Copy link
Contributor

@vlaterz re Sentry rejected the envelope followed by Successfully sent cached envelope. yes that is confusing. i have raised it here #1542

@vlaterz
Copy link
Author

vlaterz commented Mar 21, 2022

@SimonCropp

Os+version

image

What .net runtime are you targetting?
Sorry, I made a mistake, i target Net6

image

can you try the above and see if it works for you
I tried without caching, as you suggested, and it worked
image

When i turn caching on, it starts to fail. Try to repro with caching on.

Full envelope

{
    "sdk": {
        "name": "sentry.dotnet",
        "version": "3.15.0"
    },
    "event_id": "5844eb0467ea45a1a0e7e0c6bc4b7158"
}{
    "type": "event",
    "length": 17725
}{
    "modules": {
        "System.Private.CoreLib": "6.0.0.0",
        "PRODUCT_NAME.Monitor": "1.1.0.0",
        "System.Runtime": "6.0.0.0",
        "Microsoft.Extensions.DotNetDeltaApplier": "6.0.0.0",
        "System.IO.Pipes": "6.0.0.0",
        "System.Linq": "6.0.0.0",
        "System.Collections": "6.0.0.0",
        "System.Console": "6.0.0.0",
        "System.Threading": "6.0.0.0",
        "System.Threading.Overlapped": "6.0.0.0",
        "System.Security.AccessControl": "6.0.0.0",
        "System.Security.Principal.Windows": "6.0.0.0",
        "System.Runtime.InteropServices": "6.0.0.0",
        "System.Security.Claims": "6.0.0.0",
        "Microsoft.Win32.Primitives": "6.0.0.0",
        "System.Runtime.Loader": "6.0.0.0",
        "System.Collections.Concurrent": "6.0.0.0",
        "Microsoft.Extensions.Hosting.Abstractions": "6.0.0.0",
        "netstandard": "2.1.0.0",
        "Microsoft.Extensions.Configuration.Abstractions": "6.0.0.0",
        "Microsoft.Extensions.Configuration": "6.0.0.0",
        "Microsoft.Extensions.Configuration.Json": "6.0.0.0",
        "Microsoft.Extensions.Configuration.Binder": "6.0.0.0",
        "Sentry": "3.15.0.0",
        "System.Net.Primitives": "6.0.0.0",
        "System.IO.Compression": "6.0.0.0",
        "Microsoft.Extensions.Configuration.FileExtensions": "6.0.0.0",
        "Microsoft.Extensions.FileProviders.Abstractions": "6.0.0.0",
        "Microsoft.Extensions.FileProviders.Physical": "6.0.0.0",
        "Microsoft.Extensions.Primitives": "6.0.0.0",
        "System.IO.FileSystem.Watcher": "6.0.0.0",
        "System.ComponentModel.Primitives": "6.0.0.0",
        "System.Memory": "6.0.0.0",
        "Microsoft.Extensions.FileSystemGlobbing": "6.0.0.0",
        "System.Text.Json": "6.0.0.0",
        "System.Text.Encoding.Extensions": "6.0.0.0",
        "System.Numerics.Vectors": "6.0.0.0",
        "System.Runtime.CompilerServices.Unsafe": "6.0.0.0",
        "System.Net.Http": "6.0.0.0",
        "System.Diagnostics.Process": "6.0.0.0",
        "System.Private.Uri": "6.0.0.0",
        "System.Diagnostics.Tracing": "6.0.0.0",
        "System.Diagnostics.DiagnosticSource": "6.0.0.0",
        "System.Net.Security": "6.0.0.0",
        "System.Security.Cryptography.X509Certificates": "6.0.0.0",
        "System.Security.Cryptography.Algorithms": "6.0.0.0",
        "System.Security.Cryptography.Primitives": "6.0.0.0",
        "System.Diagnostics.StackTrace": "6.0.0.0",
        "System.Reflection.Metadata": "6.0.0.0",
        "System.Collections.Immutable": "6.0.0.0",
        "System.Text.Encodings.Web": "6.0.0.0",
        "System.Runtime.Intrinsics": "6.0.0.0",
        "Microsoft.Extensions.Hosting": "6.0.0.0",
        "System.ComponentModel": "6.0.0.0",
        "Serilog": "2.0.0.0",
        "Serilog.Extensions.Hosting": "2.0.0.0",
        "Microsoft.Extensions.DependencyInjection.Abstractions": "6.0.0.0",
        "Microsoft.Extensions.Hosting.WindowsServices": "6.0.0.0",
        "Microsoft.Extensions.DependencyInjection": "6.0.0.0",
        "Microsoft.Extensions.Logging": "6.0.0.0",
        "System.Runtime.InteropServices.RuntimeInformation": "6.0.0.0",
        "System.Reflection.Emit.Lightweight": "6.0.0.0",
        "System.Reflection.Primitives": "6.0.0.0",
        "Microsoft.VisualStudio.Debugger.Runtime.NetCoreApp": "17.0.0.0",
        "Microsoft.IntelliTrace.TelemetryObserver.Common": "17.0.0.0",
        "Microsoft.IntelliTrace.TelemetryObserver.CoreClr": "17.0.0.0",
        "System.Reflection": "6.0.0.0",
        "System.Reflection.Extensions": "6.0.0.0",
        "System.Reflection.Emit.ILGeneration": "6.0.0.0",
        "Microsoft.Extensions.Configuration.EnvironmentVariables": "6.0.0.0",
        "Microsoft.Extensions.Options": "6.0.0.0",
        "Microsoft.Extensions.Logging.Abstractions": "6.0.0.0",
        "Microsoft.Extensions.Logging.EventLog": "6.0.0.0",
        "Microsoft.Extensions.Logging.Configuration": "6.0.0.0",
        "Microsoft.Extensions.Options.ConfigurationExtensions": "6.0.0.0",
        "Microsoft.Extensions.Logging.Console": "6.0.0.0",
        "Microsoft.Extensions.Logging.Debug": "6.0.0.0",
        "Microsoft.Extensions.Logging.EventSource": "6.0.0.0",
        "Serilog.Extensions.Logging": "2.0.0.0",
        "PRODUCT_NAME.Monitor.DataAccess": "1.1.0.0",
        "PRODUCT_NAME.Monitor.Utility": "1.1.0.0",
        "System.Runtime.Extensions": "6.0.0.0",
        "Microsoft.EntityFrameworkCore": "6.0.1.0",
        "Serilog.Settings.Configuration": "3.1.0.0",
        "Microsoft.Extensions.DependencyModel": "6.0.0.0",
        "Serilog.Sinks.Console": "4.0.1.0",
        "System.Buffers": "6.0.0.0",
        "System.Net.Sockets": "6.0.0.0",
        "System.Net.NameResolution": "6.0.0.0",
        "Serilog.Sinks.File": "5.0.0.0",
        "Sentry.Serilog": "3.15.0.0",
        "Serilog.AspNetCore": "2.0.0.0",
        "Serilog.Formatting.Compact": "1.1.0.0",
        "Serilog.Sinks.Kafka": "1.0.0.0",
        "Serilog.Sinks.Debug": "2.0.0.0",
        "System.Threading.ThreadPool": "6.0.0.0",
        "Serilog.Sinks.PeriodicBatching": "2.0.0.0",
        "System.Text.RegularExpressions": "6.0.0.0",
        "System.IO.FileSystem": "6.0.0.0",
        "Microsoft.Extensions.Caching.Abstractions": "6.0.0.0",
        "Microsoft.EntityFrameworkCore.Sqlite": "6.0.1.0",
        "Microsoft.EntityFrameworkCore.Relational": "6.0.1.0",
        "Microsoft.EntityFrameworkCore.Abstractions": "6.0.1.0",
        "System.Data.Common": "6.0.0.0",
        "System.Linq.Expressions": "6.0.0.0",
        "System.Transactions.Local": "6.0.0.0",
        "System.ComponentModel.TypeConverter": "6.0.0.0",
        "PRODUCT_NAME.Monitor.Model": "1.1.0.0",
        "Microsoft.Extensions.Caching.Memory": "6.0.0.0",
        "System.ComponentModel.Annotations": "6.0.0.0",
        "System.Net.NetworkInformation": "6.0.0.0",
        "System.ObjectModel": "6.0.0.0",
        "System.Threading.Thread": "6.0.0.0",
        "Microsoft.Data.Sqlite": "6.0.1.0",
        "SQLitePCLRaw.core": "2.0.6.1341",
        "SQLitePCLRaw.batteries_v2": "2.0.6.1341",
        "SQLitePCLRaw.provider.e_sqlite3": "2.0.6.1341"
    },
    "event_id": "5844eb0467ea45a1a0e7e0c6bc4b7158",
    "timestamp": "2022-03-21T13:14:02.3407787+00:00",
    "logentry": {
        "message": "TestError:  b{i}, {time}",
        "formatted": "TestError:  b13, 03/21/2022 16:14:02"
    },
    "platform": "csharp",
    "server_name": "...",
    "release": "PRODUCT_NAME.Monitor@1.1.0",
    "threads": {
        "values": [{
                "id": 1,
                "crashed": false,
                "current": true,
                "stacktrace": {
                    "frames": [{
                            "function": "int Program.\u003CMain\u003E(?)",
                            "in_app": true,
                            "package": "PRODUCT_NAME.Monitor, Version=1.1.0.0, Culture=neutral, PublicKeyToken=null"
                        }, {
                            "function": "Task\u003Cint\u003E Program.Main(string[] args)",
                            "in_app": true,
                            "package": "PRODUCT_NAME.Monitor, Version=1.1.0.0, Culture=neutral, PublicKeyToken=null",
                            "instruction_offset": 31
                        }, {
                            "function": "void AsyncMethodBuilderCore.Start\u003CTStateMachine\u003E(ref TStateMachine stateMachine)",
                            "in_app": false,
                            "package": "System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e",
                            "instruction_offset": 40
                        }, {
                            "filename": "C:\\Users\\MY_NAME\\Desktop\\PRODUCT_NAME.Monitor\\PRODUCT_NAME.Monitor\\Program.cs",
                            "function": "async Task\u003Cint\u003E Program.Main(string[] args)",
                            "lineno": 62,
                            "colno": 17,
                            "in_app": true,
                            "package": "PRODUCT_NAME.Monitor, Version=1.1.0.0, Culture=neutral, PublicKeyToken=null",
                            "instruction_offset": 164
                        }, {
                            "function": "Task HostingAbstractionsHostExtensions.RunAsync(IHost host, CancellationToken token)",
                            "in_app": false,
                            "package": "Microsoft.Extensions.Hosting.Abstractions, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60",
                            "instruction_offset": 36
                        }, {
                            "function": "void AsyncMethodBuilderCore.Start\u003CTStateMachine\u003E(ref TStateMachine stateMachine)",
                            "in_app": false,
                            "package": "System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e",
                            "instruction_offset": 40
                        }, {
                            "function": "async Task HostingAbstractionsHostExtensions.RunAsync(IHost host, CancellationToken token)",
                            "in_app": false,
                            "package": "Microsoft.Extensions.Hosting.Abstractions, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60",
                            "instruction_offset": 43
                        }, {
                            "function": "Task Host.StartAsync(CancellationToken cancellationToken)",
                            "in_app": false,
                            "package": "Microsoft.Extensions.Hosting, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60",
                            "instruction_offset": 36
                        }, {
                            "function": "void AsyncMethodBuilderCore.Start\u003CTStateMachine\u003E(ref TStateMachine stateMachine)",
                            "in_app": false,
                            "package": "System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e",
                            "instruction_offset": 40
                        }, {
                            "function": "async Task Host.StartAsync(CancellationToken cancellationToken)",
                            "in_app": false,
                            "package": "Microsoft.Extensions.Hosting, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60",
                            "instruction_offset": 196
                        }, {
                            "function": "T ServiceProviderServiceExtensions.GetService\u003CT\u003E(IServiceProvider provider)",
                            "in_app": false,
                            "package": "Microsoft.Extensions.DependencyInjection.Abstractions, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60",
                            "instruction_offset": 14
                        }, {
                            "function": "object ServiceProvider.GetService(Type serviceType, ServiceProviderEngineScope serviceProviderEngineScope) x 2",
                            "in_app": false,
                            "package": "Microsoft.Extensions.DependencyInjection, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60",
                            "instruction_offset": 13
                        }, {
                            "function": "TValue ConcurrentDictionary\u003CTKey, TValue\u003E.GetOrAdd(TKey key, Func\u003CTKey, TValue\u003E valueFactory)",
                            "in_app": false,
                            "package": "System.Collections.Concurrent, Version=6.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a",
                            "instruction_offset": 79
                        }, {
                            "function": "Func\u003CServiceProviderEngineScope, object\u003E ServiceProvider.CreateServiceAccessor(Type serviceType)",
                            "in_app": false,
                            "package": "Microsoft.Extensions.DependencyInjection, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60",
                            "instruction_offset": 57
                        }, {
                            "function": "object CallSiteRuntimeResolver.Resolve(ServiceCallSite callSite, ServiceProviderEngineScope scope)",
                            "in_app": false,
                            "package": "Microsoft.Extensions.DependencyInjection, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60",
                            "instruction_offset": 38
                        }, {
                            "function": "TResult CallSiteVisitor\u003CTArgument, TResult\u003E.VisitCallSite(ServiceCallSite callSite, TArgument argument)",
                            "in_app": false,
                            "package": "Microsoft.Extensions.DependencyInjection, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60",
                            "instruction_offset": 78
                        }, {
                            "function": "object CallSiteRuntimeResolver.VisitRootCache(ServiceCallSite callSite, RuntimeResolverContext context)",
                            "in_app": false,
                            "package": "Microsoft.Extensions.DependencyInjection, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60",
                            "instruction_offset": 97
                        }, {
                            "function": "TResult CallSiteVisitor\u003CTArgument, TResult\u003E.VisitCallSiteMain(ServiceCallSite callSite, TArgument argument)",
                            "in_app": false,
                            "package": "Microsoft.Extensions.DependencyInjection, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60"
                        }, {
                            "function": "object CallSiteRuntimeResolver.VisitIEnumerable(IEnumerableCallSite enumerableCallSite, RuntimeResolverContext context)",
                            "in_app": false,
                            "package": "Microsoft.Extensions.DependencyInjection, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60",
                            "instruction_offset": 20
                        }, {
                            "function": "TResult CallSiteVisitor\u003CTArgument, TResult\u003E.VisitCallSite(ServiceCallSite callSite, TArgument argument)",
                            "in_app": false,
                            "package": "Microsoft.Extensions.DependencyInjection, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60",
                            "instruction_offset": 78
                        }, {
                            "function": "object CallSiteRuntimeResolver.VisitRootCache(ServiceCallSite callSite, RuntimeResolverContext context)",
                            "in_app": false,
                            "package": "Microsoft.Extensions.DependencyInjection, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60",
                            "instruction_offset": 97
                        }, {
                            "function": "TResult CallSiteVisitor\u003CTArgument, TResult\u003E.VisitCallSiteMain(ServiceCallSite callSite, TArgument argument)",
                            "in_app": false,
                            "package": "Microsoft.Extensions.DependencyInjection, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60"
                        }, {
                            "function": "object CallSiteRuntimeResolver.VisitConstructor(ConstructorCallSite constructorCallSite, RuntimeResolverContext context)",
                            "in_app": false,
                            "package": "Microsoft.Extensions.DependencyInjection, Version=6.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60",
                            "instruction_offset": 57
                        }, {
                            "function": "object RuntimeConstructorInfo.Invoke(BindingFlags invokeAttr, Binder binder, object[] parameters, CultureInfo culture)",
                            "in_app": false,
                            "package": "System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e",
                            "instruction_offset": 115
                        }, {
                            "function": "object RuntimeMethodHandle.InvokeMethod(object target, in Span\u003Cobject\u003E arguments, Signature sig, bool constructor, bool wrapExceptions)",
                            "in_app": true,
                            "package": "System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e",
                            "instruction_offset": -1
                        }, {
                            "filename": "C:\\Users\\MY_NAME\\Desktop\\PRODUCT_NAME.Monitor\\PRODUCT_NAME.Monitor\\EventLogWorker.cs",
                            "function": "new EventLogWorker(IConfiguration configuration, IDataContainer dataContainer, ILogger logger)",
                            "lineno": 29,
                            "colno": 14,
                            "in_app": true,
                            "package": "PRODUCT_NAME.Monitor, Version=1.1.0.0, Culture=neutral, PublicKeyToken=null",
                            "instruction_offset": 76
                        }, {
                            "filename": "C:\\Users\\MY_NAME\\Desktop\\PRODUCT_NAME.Monitor\\PRODUCT_NAME.Monitor\\EventLogWorker.cs",
                            "function": "void EventLogWorker.calcTime(int numOfRepeat, bool formatted)",
                            "lineno": 56,
                            "colno": 21,
                            "in_app": true,
                            "package": "PRODUCT_NAME.Monitor, Version=1.1.0.0, Culture=neutral, PublicKeyToken=null",
                            "instruction_offset": 283
                        }, {
                            "function": "void Logger.Error\u003CT0, T1\u003E(string messageTemplate, T0 propertyValue0, T1 propertyValue1)",
                            "in_app": false,
                            "package": "Serilog, Version=2.0.0.0, Culture=neutral, PublicKeyToken=24c2f752a8e58a10"
                        }, {
                            "function": "void Logger.Write\u003CT0, T1\u003E(LogEventLevel level, string messageTemplate, T0 propertyValue0, T1 propertyValue1)",
                            "in_app": false,
                            "package": "Serilog, Version=2.0.0.0, Culture=neutral, PublicKeyToken=24c2f752a8e58a10",
                            "instruction_offset": 9
                        }, {
                            "function": "void Logger.Write(LogEventLevel level, Exception exception, string messageTemplate, params object[] propertyValues) x 2",
                            "in_app": false,
                            "package": "Serilog, Version=2.0.0.0, Culture=neutral, PublicKeyToken=24c2f752a8e58a10",
                            "instruction_offset": 88
                        }, {
                            "function": "void Logger.Dispatch(LogEvent logEvent)",
                            "in_app": false,
                            "package": "Serilog, Version=2.0.0.0, Culture=neutral, PublicKeyToken=24c2f752a8e58a10",
                            "instruction_offset": 41
                        }, {
                            "function": "void Logger.Serilog.Core.ILogEventSink.Emit(LogEvent logEvent)",
                            "in_app": false,
                            "package": "Serilog, Version=2.0.0.0, Culture=neutral, PublicKeyToken=24c2f752a8e58a10",
                            "instruction_offset": 14
                        }, {
                            "function": "void Logger.Dispatch(LogEvent logEvent)",
                            "in_app": false,
                            "package": "Serilog, Version=2.0.0.0, Culture=neutral, PublicKeyToken=24c2f752a8e58a10",
                            "instruction_offset": 41
                        }, {
                            "function": "void Logger.Serilog.Core.ILogEventSink.Emit(LogEvent logEvent)",
                            "in_app": false,
                            "package": "Serilog, Version=2.0.0.0, Culture=neutral, PublicKeyToken=24c2f752a8e58a10",
                            "instruction_offset": 14
                        }, {
                            "function": "void Logger.Dispatch(LogEvent logEvent)",
                            "in_app": false,
                            "package": "Serilog, Version=2.0.0.0, Culture=neutral, PublicKeyToken=24c2f752a8e58a10",
                            "instruction_offset": 41
                        }, {
                            "function": "void SafeAggregateSink.Emit(LogEvent logEvent)",
                            "in_app": false,
                            "package": "Serilog, Version=2.0.0.0, Culture=neutral, PublicKeyToken=24c2f752a8e58a10",
                            "instruction_offset": 15
                        }, {
                            "function": "void SecondaryLoggerSink.Emit(LogEvent logEvent)",
                            "in_app": false,
                            "package": "Serilog, Version=2.0.0.0, Culture=neutral, PublicKeyToken=24c2f752a8e58a10",
                            "instruction_offset": 21
                        }, {
                            "function": "void Logger.Write(LogEvent logEvent)",
                            "in_app": false,
                            "package": "Serilog, Version=2.0.0.0, Culture=neutral, PublicKeyToken=24c2f752a8e58a10",
                            "instruction_offset": 19
                        }, {
                            "function": "void Logger.Dispatch(LogEvent logEvent)",
                            "in_app": false,
                            "package": "Serilog, Version=2.0.0.0, Culture=neutral, PublicKeyToken=24c2f752a8e58a10",
                            "instruction_offset": 41
                        }, {
                            "function": "void FilteringSink.Emit(LogEvent logEvent)",
                            "in_app": false,
                            "package": "Serilog, Version=2.0.0.0, Culture=neutral, PublicKeyToken=24c2f752a8e58a10",
                            "instruction_offset": 34
                        }, {
                            "function": "void SafeAggregateSink.Emit(LogEvent logEvent)",
                            "in_app": false,
                            "package": "Serilog, Version=2.0.0.0, Culture=neutral, PublicKeyToken=24c2f752a8e58a10",
                            "instruction_offset": 15
                        }, {
                            "function": "void RestrictedSink.Emit(LogEvent logEvent)",
                            "in_app": false,
                            "package": "Serilog, Version=2.0.0.0, Culture=neutral, PublicKeyToken=24c2f752a8e58a10",
                            "instruction_offset": 34
                        }
                    ]
                }
            }
        ]
    },
    "level": "error",
    "request": {},
    "contexts": {
        "runtime": {
            "type": "runtime",
            "name": ".NET",
            "version": "6.0.2",
            "raw_description": ".NET 6.0.2"
        },
        "os": {
            "type": "os",
            "raw_description": "Microsoft Windows 10.0.18363"
        },
        "Dynamic Code": {
            "Compiled": true,
            "Supported": true
        },
        "ThreadPool Info": {
            "min_worker_threads": 4,
            "min_completion_port_threads": 4,
            "max_worker_threads": 32767,
            "max_completion_port_threads": 1000,
            "available_worker_threads": 32766,
            "available_completion_port_threads": 1000
        },
        "Current Culture": {
            "name": "ru-RU",
            "display_name": "Russian (Russia)",
            "calendar": "GregorianCalendar"
        },
        "app": {
            "type": "app",
            "app_start_time": "2022-03-21T13:13:17.9253475+00:00"
        },
        "device": {
            "type": "device",
            "timezone": "Russian Standard Time",
            "timezone_display_name": "(UTC\u002B03:00) Moscow, St. Petersburg",
            "boot_time": "2022-03-17T07:09:22.3358083+00:00"
        },
        "Current UI Culture": {
            "name": "en-US",
            "display_name": "English (United States)",
            "calendar": "GregorianCalendar"
        },
        "Memory Info": {
            "allocated_bytes": 33865256,
            "fragmented_bytes": 505400,
            "heap_size_bytes": 6188808,
            "high_memory_load_threshold_bytes": 7617938227,
            "total_available_memory_bytes": 8464375808,
            "memory_load_bytes": 7787225743,
            "total_committed_bytes": 11583488,
            "promoted_bytes": 357792,
            "pinned_objects_count": 0,
            "pause_time_percentage": 0.07,
            "index": 10,
            "generation": 0,
            "finalization_pending_count": 4,
            "compacted": true,
            "concurrent": false,
            "pause_durations": [1.604, 0]
        }
    },
    "user": {
        "ip_address": "{{auto}}",
        "username": "MY_NAME"
    },
    "environment": "debug",
    "sdk": {
        "packages": [{
                "name": "nuget:Sentry.Serilog",
                "version": "3.15.0"
            }, {
                "name": "nuget:sentry.dotnet",
                "version": "3.15.0"
            }
        ],
        "name": "sentry.dotnet.serilog",
        "version": "3.15.0"
    },
    "breadcrumbs": [{
            "timestamp": "2022-03-21T13:14:01.564Z",
            "message": "TestError:  b10, 21.03.2022 16:14:01",
            "level": "error"
        }, {
            "timestamp": "2022-03-21T13:14:01.791Z",
            "message": "TestError:  b11, 03/21/2022 16:14:01",
            "level": "error"
        }, {
            "timestamp": "2022-03-21T13:14:02.226Z",
            "message": "TestError:  b11, 21.03.2022 16:14:01",
            "level": "error"
        }, {
            "timestamp": "2022-03-21T13:14:02.308Z",
            "message": "TestError:  b12, 03/21/2022 16:14:02",
            "level": "error"
        }, {
            "timestamp": "2022-03-21T13:14:02.333Z",
            "message": "TestError:  b12, 21.03.2022 16:14:02",
            "level": "error"
        }
    ],
    "extra": {
        "i": 13,
        "time": "2022-03-21T16:14:02.3339927\u002B03:00",
        "Error": "Error"
    }
}

@SimonCropp
Copy link
Contributor

can you upload the raw file from you cache directory

@vlaterz
Copy link
Author

vlaterz commented Mar 28, 2022

@SimonCropp
Copy link
Contributor

@bruno-garcia @mattjohnsonpint i need some help on this one. I am not able to reproduce, and cannot see any difference in the above attached envelope file that should be causing problems.

@SimonCropp
Copy link
Contributor

@bruno-garcia @mattjohnsonpint seems that message is coming from the relay https://github.com/getsentry/relay/blob/master/relay-server/src/envelope.rs#L61
is there someone we can pull in from that team to have a look at the envelope files?

@mattjohnsonpint
Copy link
Contributor

@vlaterz - can you please see if you can recreate this on sentry.io?

@bruno-garcia
Copy link
Member

In self hosted older 20.06 this 400 status code is expected, because it doesn't have /envelope. But you said 22.3, this should work so testing against sentry.io is a good idea

@vlaterz
Copy link
Author

vlaterz commented Mar 31, 2022

@bruno-garcia @mattjohnsonpint What does that mean, "testing against sentry.io"?
Does that mean that i should send messages to sentry directly, without using Serilog sink?

Image of 22.3.0 on our ui
image

@SimonCropp
Copy link
Contributor

@vlaterz from your information above, it looks like you are using sentry in SAAS mode. So to work out if this is a problem specific to SASS, or is reproducible in the cloud hosting mode, we want you to try using the cloud model. See the getting started guide

@vlaterz
Copy link
Author

vlaterz commented Apr 3, 2022

@SimonCropp I tested once again, also using cloud sentry. I think i figured it out. It looks like the 400 error was because of DateTime.Now, which was sent like that:

  var testStr = "_someString_";
 _loggerError.Error(@"TestError:  {testStr}, {time}", testStr, DateTime.Now);

I tested sending messages with this method:

private void testDateTime()
        {
            var testStr = "_someString_";
            var guid = Guid.NewGuid().ToString();
            _loggerError.Error(@"TestError:  {testStr}, {guid}", testStr, guid);
            _loggerError.Error(@"TestError:  {testStr}, {time}", testStr, DateTime.Now);
            _loggerError.Error(@$"TestError:  {testStr}, {guid}");
            _loggerError.Error(@$"TestError:  {testStr}, {DateTime.Now}");
        }

So, in Console with Sentry Debug on:
The first message:
image
Send result is success:
image

The second message:
image
Send result is bad request
image

The last two are successes:
3:
image
4:
image

The problem is that i missed "ToString()" in DateTime.Now.
I tested with this, and everything was sent successfully:

  var testStr = "_someString_";
 _loggerError.Error(@"TestError:  {testStr}, {time}", testStr, DateTime.Now.ToString());

@vlaterz
Copy link
Author

vlaterz commented Apr 4, 2022

UPD:

Error happens when you send DateTime with DateTimeKind.Local.
If any DateTimeKind.utc or DateTimeKind.undefined is used, messages are sent without errors
DateTime.Now is DateTimeKind.Local by default

@mattjohnsonpint
Copy link
Contributor

I've figured this out, and since it's not related specifically to Serilog, I've opened a new issue. Please follow #1956 for updates. Closing this one. Thanks.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Bug Something isn't working Serilog
Projects
Archived in project
Development

No branches or pull requests

4 participants