pips34

Suggestions on a design pattern for logging in .NET?

https://programming.dev/post/9618289

Suggestions on a design pattern for logging in .NET? - programming.dev

Hello! I’m starting a personal project in .NET. For a logging solution, I want to achieve something similar to what I have in a Python REST API I wrote a while back using the decorator pattern (example in the image). In the example, the outter “log” function receives the logger I want to use, the decorator function receives a function and returns the decorated function ready to be called (this would be the decorator), and the wrapper function receives the same arguments as the function to be decorated (which is a generic (*args, **kwargs) ofc, because it’s meant to decorate any function) and returns whatever the return type of the function is (so, Any). In lines 17 - 24 I just call the passed in “func” with the passed in arguments, but in between I wrap it in a try except block and log that the function with name func.__name__ started or finished executing. In practice, using this decorator in Python looks like this: import logging from my.decorator.module import log _logger = logging.getLogger(__name__) @log(_logger) def my_func(arg1: Arg1Type, arg2: Arg2Type) -> ReturnType: ... Ofc it’s a lot simpler in Python, however I was wondering if it would be possible or even recommended to attempt something similar in C#. I wouldn’t mind having to call the function and wrap it manually, something like this: return RunWithLogs(MyFunction, arg1, arg2); What I do want to avoid is manually writing the log statements inside the service’s business logic, or having to write separate wrappers for each method I want to log. Would be nice to have one generic function or class that I can somehow plug-in to any method and have it log when the call starts and finishes. Any suggestions? Thanks in advance.

Feb 6, 2024 at 6:30amWeb
Show threadtheit8514Feb 6, 2024

C# does not really implement decorators like that, which can execute autonomously. You would still need to wrap all the functions you want to call.

You can wrap the action using a Func<> or Action, and get the calling member name (e.g. name would be ‘Main’). The Arguments are a pain, as you have to drill down the Expression tree to get them. This case only handles ConstantExpression values, you would also need to handle MemberExpression and probably others.

using System.Linq.Expressions; using System.Runtime.CompilerServices; public static void Main() { var n = LogWrapper(() => MyMethod("Hello, World!")); Console.WriteLine(n); } private static int MyMethod(string test) { Console.WriteLine(test); return 42; } private static T LogWrapper(Expression> func, [CallerMemberName] string name = null) { // Do begin logging var body = func.Body as MethodCallExpression; var firstArgument = body?.Arguments.First() as ConstantExpression; Console.WriteLine("name={0} param={1}", name, firstArgument?.Value); var result = func.Compile().Invoke(); // Do end logging Console.WriteLine("end name={0}", name); return result; }
Show threadLmaydevFeb 6, 2024
Won’t you need to handle all the different expressions the parameter could be with this method? It won’t always be a constant right?
Show threadtheit8514Feb 6, 2024
Yes, as I stated other expression types might be needed. You could also wrap the argument expression in Expression.Lambda() and execute it to get the value. None of these options are necessarily fast, and you’ll likely get double executions which could lead to unanticipated side effects.
Show threadLmaydevFeb 6, 2024
I think taking the parameters as parameters and creating a function for each parameter count is better then you can just call the func/action normally.
Show threadLmaydevFeb 6, 2024

It’s certainly possible. You could use the Action and Func delegates.

TReturn RunWithLog(ILogger logger, Func<T, TResult> function, T parameter 1) { logger.LogInformation(....); function(parameters); }
Show threadtheit8514Feb 6, 2024
The primary issue with this approach is that you’ll need a RunWithLog for each number of parameters. Which is why Func and all the ones in between exists. learn.microsoft.com/en-us/dotnet/api/system?view=…
System Namespace

Contains fundamental classes and base classes that define commonly-used value and reference data types, events and event handlers, interfaces, attributes, and processing exceptions.

Show threadLmaydevFeb 6, 2024

Yeah I did say that. It’s a pain but chances are you only need 5 or 6.

You could do it with reflection and params but then you lose type safety etc.

Show threadpips34Feb 6, 2024
Love it! Works great for me, since most of my services receive only 2 params, and even if I didn’t, having 2 or 3 wrappers is no big deal. Tysm! :)
Show threadLmaydevFeb 6, 2024
No worries mate 🙂
Show threadKairosFeb 6, 2024
Hi. Is that Atom/Pulsar?
Show threadpips34Feb 6, 2024

Hi, my IDE is PyCharm with the Material theme

Show threadRonSijmFeb 6, 2024

The current answers using a Func or an Action are correctish, but with that approach you will have logging cross-cutting hard-wired into all your classes before invoking the methods.

If you want true AOP or decorators, you probably want to use Type Interceptors. And Castle DynamicProxy. See: autofac.readthedocs.io/en/…/interceptors.html blog.zhaytam.com/…/aspnetcore-dynamic-proxies-for…

A dynamic proxy will give you a method like this:

public void Intercept(IInvocation invocation) { _output.Write("Calling method {0} with parameters {1}... ", invocation.Method.Name, string.Join(", ", invocation.Arguments.Select(a => (a ?? "").ToString()).ToArray())); invocation.Proceed(); _output.WriteLine("Done: result was {0}.", invocation.ReturnValue); }

Intercept is called before invoking a method, you can do stuff before the method starts, then you call invocation.Proceed(); - that invokes the method, and then you can log the result.

Note that your class methods either need to be virtual, or it needs to have an interface, I’d suggest an interface.

This way you can wire the logging part in through dependency injection in your container, and your classes itself don’t contain logging cross-cutting logic

Type Interceptors — Autofac 7.0.0 documentation

Show threadpips34Feb 7, 2024
Beautiful! I only reply just now because I JUST got it working. This is exactly what I was looking for, thank you sooo much :) I’m keeping both approaches in a lil template project I have, and definitely checking Serilog next!
Show threadathekenFeb 6, 2024

Not that I would recommend it, but you can also try something like extension methods on Func.

public static RunAndLog(this Func<T> f) { LogStart(f); var x = f(); LogEnd(f); return x; }

I think you may have enough diagnostic info with reflection to write something meaningful, and you can add overloads with generic parameters for for the func params, and/or Action.

You may also create an IDisposable that logs a start and end statement around a function call:

using var _ = CallLogger(“func name”) { f(); }

Personally, I wouldn’t do either of these. This level of logging produces an enormous amount of noise, making finding signal very difficult. I would focus more energy on writing unique and helpful messages where they are important, and using git grep to find the related source code when they show up in production logs (assuming you don’t log a stack trace). This level of call logging can be temporarily useful while debugging or reasoning through an app, but rarely belongs in production.

Show threadCatPoopFeb 6, 2024

I can see the appeal of having a generic way to log particular methods, it’s a bit jank to intercept your own code, and it’s easier to debug in general with explicit log messages with more detail.

Also recommend serilog as another commentor mentioned, and you can combine this with global static using Serilog.Log once in your project and then you only need to call Debug(“something”) etc. anywhere else in the code.

FYI the try finally statement has different behavior in dot net, if you use the same pattern use

try { } catch { throw; }

Use throw and not throw ex to preserve the stack trace.