Missing Ilogger parameters

[ollie10]

Package

Sentry

.NET Flavor

.NET Core

.NET Version

8.0.0

OS

Windows

SDK Version

8.0.0

Self-Hosted Sentry Version

No response

Steps to Reproduce

Hi everyone, I have a (maybe) dummy question. I'm using Sentry for Asp.NET using as logging methods the one shipped in the framework via Microsoft.Extensions.Logging

I'm logging errors and exceptions passing sometimes parameters like in this way:

_logger.LogError("ERROR - User Registration Failed Invalid Recaptcha", new { RegisterModel = registerModel, RecaptchaResponse = recaptchaResponse });

The question is: Where am I supposed to see these parameters in the Sentry interface? I mean, logging is working pretty fine, especially with the exceptions caught. I see everything I need; I just never see, in any case, those parameters.

Am I doing something wrong, or is this the expected behavior?

Expected Result

I would expect to see the parameters as a dictionary or a deserialized object in Sentry Event

Actual Result

Nothing about those parameters is shown on the event details

[jamescrosswell]

Hm, typically you log errors when you have an exception, in which case the exception can be passed as well and you get full stack trace details etc. on the Issues dashboard in Sentry):

sentry-dotnet/samples/Sentry.Samples.ME.Logging/Program.cs

Lines 65 to 73 in d6dc82b

	try
	{
	Dependency.Work("some work");
	}
	catch (Exception e)
	{
	// Handle an exception and log it:
	logger.LogError(e, "7 - An event that includes the scope key-value (A, B, C) and also the breadcrumbs: (2, 4, 6) and events (3, 5)");
	}

If you wanted additional information to be sent to Sentry, one way to do it would be via the logger state:

sentry-dotnet/samples/Sentry.Samples.ME.Logging/Program.cs

Lines 51 to 59 in d6dc82b

	using (logger.BeginScope(new Dictionary<string, string>
	{
	{"A", "some value"},
	{"B", "more value"},
	}))
	{
	logger.LogWarning("4 - Breadcrumb that only exists inside this scope");
	logger.LogError("5 - An event that includes the scoped key-value (A, B) above and also the breadcrumbs: (2, 4) and event (3)");

Under the hood that information gets passed through to Sentry like so:

sentry-dotnet/src/Sentry.Extensions.Logging/SentryLogger.cs

Lines 113 to 135 in 464fd4c

	switch (property.Value)
	{
	case string stringTagValue:
	@event.SetTag(property.Key, stringTagValue);
	break;
	case Guid guidTagValue when guidTagValue != Guid.Empty:
	@event.SetTag(property.Key, guidTagValue.ToString());
	break;
	case Enum enumValue:
	@event.SetTag(property.Key, enumValue.ToString());
	break;
	default:
	{
	if (property.Value?.GetType().IsPrimitive == true)
	{
	@event.SetTag(property.Key, Convert.ToString(property.Value, CultureInfo.InvariantCulture)!);
	}
	break;
	}
	}

So basically the State has to be an IEnumerable<KeyValuePair<string, object>> and the values can be string, Guid, Enum or some primitive (like int). If you want to pass a complex model like RegisterModel you'd need to first serialize this to JSON or something (so that it could be supplied as a string).

[ollie10]

Hello @jamescrosswell I see your point; that's said, the solution is not very user-friendly.
Besides that, there are plenty of cases in which you want to log an error without an exception, like in those cases where you have logic errors. That's why the LogError of ILogger has a method that doesn't need an exception to log the data.

Anyway, if there is no other way, I will give it a try with the scopes way. Many thanks for the help

[jamescrosswell]

Anyway, if there is no other way, I will give it a try with the scopes way. Many thanks for the help

Hey @ollie10 ,

I don't think there's any other way that Sentry could get data from the logger. In the code you provided above, you're making a call to this extension method:

        /// <summary>
        /// Formats and writes an error log message.
        /// </summary>
        /// <param name="logger">The <see cref="ILogger"/> to write to.</param>
        /// <param name="message">Format string of the log message in message template format. Example: <c>"User {User} logged in from {Address}"</c></param>
        /// <param name="args">An object array that contains zero or more objects to format.</param>
        /// <example>logger.LogError("Processing request from {Address}", address)</example>
        public static void LogError(this ILogger logger, string? message, params object?[] args)
        {
            logger.Log(LogLevel.Error, message, args);
        }

So the logger doesn't do anything with registerModel and recaptchaResponse. The params args in that extension method would only ever be used to format the message (if you were using message templating).

If you can think of an easier way to pass data from the logger to Sentry, we could look into it though. We're always looking for ways to make Sentry easier to use.

[ollie10]

@jamescrosswell you are totally and absolutely right, i don't know why I was thinking that it worked in another way, perhaps I was using another library.

Surely the way you mentioned could be to pass everything as parameters and then stringify those as parameters in the message, but at that point I would have everything in a single-line string on Sentry I suppose. It could help, but for bigger objects, it will be tricky.

I don't know if it could be helpful to adopt a solution like this one: https://github.com/serilog/serilog/wiki/Structured-Data or some similar thing.

In the other case, I could also create a custom Exception using the Data Property: Exception.Data property to add there my custom objects as properties; those surely would be available in the Sentry Dashboard, right?

I don't know if you want to give it some thought; if there could be an easier way, it could be a point of improvement

[jamescrosswell]

I don't know if it could be helpful to adopt a solution like this one: https://github.com/serilog/serilog/wiki/Structured-Data or some similar thing.

It's an interesting idea. We have this for Serilog already... Maybe there's a way to get structured data from it that we could turn into Sentry Context or Tags . I'll add a reference to your comment to that other issue.

[jamescrosswell]

In the other case, I could also create a custom Exception using the Data Property: Exception.Data property to add there my custom objects as properties; those surely would be available in the Sentry Dashboard, right?

Hm, I might need to ask someone else about that.

@bruno-garcia @bitsandfoxes I tried sending an exception like so:

async Task SecondFunctionAsync()
{
    var span = transaction.StartChild("function", nameof(SecondFunctionAsync));

    try
    {
        // Simulate doing some work
        await Task.Delay(100);

        // Throw an exception
        throw new ApplicationException("Something happened!");
    }
    catch (Exception exception)
    {
        // This is an example of capturing a handled exception.
        exception.Data["Foo"] = "Bar";
        SentrySdk.CaptureException(exception);
        span.Finish(exception);
    }

    span.Finish();
}

I see we do send that information along with the Exception to Sentry, in the Mechanism.Data:

sentry-dotnet/src/Sentry/Internal/MainExceptionProcessor.cs

Lines 202 to 206 in 2a8813a

	// Copy remaining exception data to mechanism data.
	foreach (var key in exception.Data.Keys.OfType<string>())
	{
	mechanism.Data[key] = exception.Data[key]!;
	}

And indeed I see it going across the wire:

  Debug: HttpTransport: Envelope '691d3aa1381e4d7b91c4bedad4cf8236' successfully sent. Content: {"sdk":{"name":"sentry.dotnet","version":"4.0.0-beta.8"},"event_id":"691d3aa1381e4d7b91c4bedad4cf8236","trace":{"trace_id":"b12c7bade97542f7b1562e9425e8fb82","public_key":"eb18e953812b41c3aeb042e666fd3b5c","sampled":"true","sample_rate":"1","release":"[email protected]\u002B2ff183322021b3be5213038f64f61e188d6bfcfc","environment":"production","transaction":"Program Main"},"sent_at":"2024-01-24T10:05:55.317283+00:00"} {"type":"event","length":4801} {"modules":{"System.Private.CoreLib":"6.0.0.0","Sentry.Samples.Console.Basic":"4.0.0.0","System.Runtime":"6.0.0.0","JetBrains.Microsoft.Extensions.DotNetDeltaApplier":"1.0.0.0","System.Linq":"6.0.0.0","System.Collections":"6.0.0.0","Sentry":"4.0.0.0","System.Collections.Concurrent":"6.0.0.0","System.Net.Primitives":"6.0.0.0","System.IO.Compression":"6.0.0.0","System.Text.Json":"6.0.0.0","System.IO.Pipes":"6.0.0.0","System.Console":"6.0.0.0","System.Text.RegularExpressions":"6.0.0.0","System.Threading":"6.0.0.0","System.Net.Sockets":"6.0.0.0","Microsoft.Win32.Primitives":"6.0.0.0","System.Diagnostics.Tracing":"6.0.0.0","System.Threading.ThreadPool":"6.0.0.0","System.Runtime.InteropServices.RuntimeInformation":"6.0.0.0","System.Threading.Thread":"6.0.0.0","System.Runtime.Loader":"6.0.0.0","System.Memory":"6.0.0.0","System.Reflection.Emit.ILGeneration":"6.0.0.0","System.Reflection.Emit.Lightweight":"6.0.0.0","System.Reflection.Primitives":"6.0.0.0","System.Diagnostics.Process":"6.0.0.0","System.Private.Uri":"6.0.0.0","System.ComponentModel.Primitives":"6.0.0.0","System.Net.Http":"6.0.0.0","System.Security.Cryptography.Algorithms":"6.0.0.0","System.Security.Cryptography.Primitives":"6.0.0.0","System.ObjectModel":"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.Text.Encodings.Web":"6.0.0.0","System.Runtime.Intrinsics":"6.0.0.0","System.Numerics.Vectors":"6.0.0.0","System.Runtime.InteropServices":"6.0.0.0","System.Net.NameResolution":"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.Encoding.Extensions":"6.0.0.0","System.Collections.NonGeneric":"6.0.0.0","System.Linq.Expressions":"6.0.0.0"},"event_id":"691d3aa1381e4d7b91c4bedad4cf8236","timestamp":"2024-01-24T10:05:55.082465+00:00","platform":"csharp","release":"[email protected]\u002B2ff183322021b3be5213038f64f61e188d6bfcfc","exception":{"values":[{"type":"System.ApplicationException","value":"Something happened!","module":"System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e","thread_id":9,"stacktrace":{"frames":[{"filename":"Program.cs","function":"async Task \u003C\u003Ec__DisplayClass0_0.\u003C\u003CMain\u003E$\u003Eg__SecondFunctionAsync|3(?)\u002BSecondFunctionAsync(?)","lineno":72,"colno":9,"abs_path":"/Users/jamescrosswell/code/sentry-dotnet/samples/Sentry.Samples.Console.Basic/Program.cs","in_app":true,"package":"Sentry.Samples.Console.Basic, Version=4.0.0.0, Culture=neutral, PublicKeyToken=fba2ec45388e2af0","instruction_addr":"0xa3","addr_mode":"rel:0","function_id":"0x18"}]},"mechanism":{"type":"generic","handled":true,"data":{"Foo":"Bar"}}}]},"level":"error","transaction":"Program Main","request":{},"contexts":{"Current Culture":{"name":"en-NZ","display_name":"English (New Zealand)","calendar":"GregorianCalendar"},"Dynamic Code":{"Compiled":true,"Supported":true},"Memory Info":{"allocated_bytes":2345336,"high_memory_load_threshold_bytes":96894462197,"total_available_memory_bytes":103079215104,"finalization_pending_count":0,"compacted":false,"concurrent":false,"pause_durations":[0,0]},"ThreadPool Info":{"min_worker_threads":12,"min_completion_port_threads":12,"max_worker_threads":32767,"max_completion_port_threads":1000,"available_worker_threads":32765,"available_completion_port_threads":1000},"app":{"type":"app","app_start_time":"2024-01-24T10:05:53.049926+00:00"},"device":{"type":"device","timezone":"NZ","timezone_display_name":"(UTC\u002B12:00) New Zealand Time","boot_time":"2024-01-20T04:23:06.8061818+00:00"},"os":{"type":"os","raw_description":"Darwin 23.2.0 Darwin Kernel Version 23.2.0: Wed Nov 15 21:55:06 PST 2023; root:xnu-10002.61.3~2/RELEASE_ARM64_T6020"},"runtime":{"type":"runtime","name":".NET","version":"6.0.22","raw_description":".NET 6.0.22","identifier":"osx.14-arm64"},"trace":{"type":"trace","span_id":"41e3d1affc6fd2ae","parent_span_id":"f21160b211bd7b69","trace_id":"b12c7bade97542f7b1562e9425e8fb82"}},"user":{"ip_address":"{{auto}}"},"environment":"production","sdk":{"packages":[{"name":"nuget:sentry.dotnet","version":"4.0.0-beta.8"}],"name":"sentry.dotnet","version":"4.0.0-beta.8"},"debug_meta":{"images":[{"type":"pe_dotnet","debug_id":"3e0d2c26-2c84-4161-807f-d467635c47ae-c55ba81a","debug_checksum":"SHA256:262c0d3e842c6161007fd467635c47ae1aa85b453a94bcd767648813662d37f3","debug_file":"/Users/jamescrosswell/code/sentry-dotnet/samples/Sentry.Samples.Console.Basic/obj/Debug/net6.0/Sentry.Samples.Console.Basic.pdb","code_id":"C1CAA825a000","code_file":"/Users/jamescrosswell/code/sentry-dotnet/samples/Sentry.Samples.Console.Basic/bin/Debug/net6.0/Sentry.Samples.Console.Basic.dll"}]}} {"type":"session","length":361} {"sid":"425689480c0b4c2da96a1cc39842a6fb","did":"537ae98e-9fee-46d6-8f2e-2adbb39bcc75","init":false,"started":"2024-01-24T23:05:54.574009+13:00","timestamp":"2024-01-24T10:05:55.148962+00:00","seq":1,"duration":0,"errors":1,"attrs":{"release":"[email protected]\u002B2ff183322021b3be5213038f64f61e188d6bfcfc","environment":"production"}}

But I can't find it anywhere in the Sentry UX. See the event created by that code above in the Sentry dashboard... Do you know if this is available anywhere?

[ollie10]

@jamescrosswell indeed, I changed my code to this, and I see it in Sentry in a weird way. I suppose RegisterModel is filtered because it contains an email, but I cannot extend the Recaptcha response, perhaps.

// lOGGING THE RECAPTCHA ERROR
WebException webEx = new WebException("ERROR - User Registration Failed, Invalid Recaptcha");
webEx.Data.Add("RegisterModel", JsonSerializer.Serialize(registerModel));
webEx.Data.Add("RecaptchaResponse", JsonSerializer.Serialize(recaptchaResponse));

_logger.LogError(webEx, "ERROR - User Registration Failed, Invalid Recaptcha");
registerModel.Result = IdentityResult.Failed();
return View(registerModel);

[jamescrosswell]

@jamescrosswell indeed, I changed my code to this, and I see it in Sentry in a weird way.

Ah cool... yes got it working too 👍🏻

I'll close this issue. There's a comment on the Serilog one to look into structured logging for that.

[jamescrosswell]

I don't know if it could be helpful to adopt a solution like this one: https://github.com/serilog/serilog/wiki/Structured-Data or some similar thing.

Actually @ollie10 I think I misdirected you... I was just looking through our ASP.NET Core sample and saw this:

sentry-dotnet/samples/Sentry.Samples.AspNetCore.Mvc/Controllers/HomeController.cs

Lines 59 to 64 in 24c159f

	// Exemplifies using the logger to raise a warning which will be sent as an event because MinimumEventLevel was configured to Warning
	// ALso, the stack trace of this location will be sent (even though there was no exception) because of the configuration AttachStackTrace
	_logger.LogWarning("A {route} '{value}' was requested.",
	// example structured logging where keys (in the template above) go as tag keys and values below:
	"/about",
	"null");

So I think structured logging is already supported for Microsoft.Extensions.Logging... as long as the keys/values can be serialized.

Apologies... seems like we're both learning here!

[ollie10]

Hello @jamescrosswell any news on this topic? I keep receiving logs without precious information in them. Having a stack trace is useful, but if the data from a form, generates decisions in your code, and you cannot see that data, it's not useful in this case
Many thanks

[jamescrosswell]

Hello @jamescrosswell any news on this topic? I keep receiving logs without precious information in them. Having a stack trace is useful, but if the data from a form, generates decisions in your code, and you cannot see that data, it's not useful in this case

Hey @ollie10, did you check the sample project illustrating this? Is that not the behaviour you're after?

[ollie10]

Hello @jamescrosswell yes but this works only for simple types. What if you have 40 parameters? Surely you can JsonSerializer.Serialize everything there, but you will have a whole chunk of parameters in the message. It's not very user-friendly.

At least you can do the same as I said in the comment but the interface won't show you everything as I told you in that message

[jamescrosswell]

Surely you can JsonSerializer.Serialize everything there, but you will have a whole chunk of parameters in the message.

I'm not sure if you saw the comment in the code for the sample:

// example structured logging where keys (in the template above) go as tag keys and values below:

So if you're using structured message templates with MEL, Sentry creates tags for each of the parameters passed to the message template.

Is that not what you're after?