this post was submitted on 06 Feb 2024
14 points (100.0% liked)

C Sharp

1532 readers
2 users here now

A community about the C# programming language

Getting started

Useful resources

IDEs and code editors

Tools

Rules

Related communities

founded 1 year ago
MODERATORS
 

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.

all 15 comments
sorted by: hot top controversial new old
[–] Lmaydev 4 points 9 months ago* (last edited 9 months ago) (2 children)

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

TReturn RunWithLog<T, TResult>(ILogger logger, Func<T, TResult> function, T parameter1)
{
    logger.LogInformation(....);
    return function(parameter1);
}

void RunWithLog<T>(ILogger logger, Action<T> function, T parameter1)
{
    logger.LogInformation(....);
    function(parameter1);
}

You'd need to implement one for each number of parameters you want to accept.

You could also return a new func or action that contains the code in those methods to be called repeatedly. But I don't think there'd be any advantage to doing it that way. I guess you could then pass it as an argument.

Action<T> BuildRunWithLog<T>(ILogger logger, Action<T> function)
{
    return (T parameter1) => 
    {
        logger.LogInformation(....);
        function(parameter1);
    }
 }

Wrote that from memory so syntax may be wrong.

[–] pips34 2 points 9 months ago (1 children)

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! :)

[–] Lmaydev 1 points 9 months ago

No worries mate 🙂

[–] [email protected] 1 points 9 months ago (1 children)

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. https://learn.microsoft.com/en-us/dotnet/api/system?view=net-8.0#delegates

[–] Lmaydev 1 points 9 months ago

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.

[–] RonSijm 3 points 9 months ago* (last edited 9 months ago) (1 children)

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: https://autofac.readthedocs.io/en/latest/advanced/interceptors.html https://blog.zhaytam.com/2020/08/18/aspnetcore-dynamic-proxies-for-aop/

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


Logging wise, I'm not sure how familiar you are with dotnet, as you're saying you're just starting, I'd suggest inside your classes you stick with Microsoft.Extensions.Logging.Abstractions - so your classes - lets say a class MyService - would be

public class MyService(Microsoft.Extensions.Logging.ILogger<MyService> logger) { }

Then I'd suggest Serilog to use as concrete logger. You'd wire that in with:

     var configuration = new ConfigurationBuilder()
        .SetBasePath(Path.GetDirectoryName(Assembly.GetExecutingAssembly().Location)!)
        .AddJsonFile("appsettings.json")
        .Build();

    services.AddLogging(loggingBuilder =>
    {
        var logger = new LoggerConfiguration()
            .ReadFrom.Configuration(configuration)
            .CreateLogger();

        loggingBuilder.AddSerilog(logger, dispose: true);
    });

Sirilog is a very extendable framework that comes with 100s of different Sinks so you can very easily wire in a different output target, or wire in different enrichers without modifying any of your existing code

[–] pips34 1 points 9 months ago

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!

[–] [email protected] 1 points 9 months ago (1 children)

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;
    }
[–] Lmaydev 2 points 9 months ago (1 children)

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?

[–] [email protected] 2 points 9 months ago (1 children)

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.

[–] Lmaydev 1 points 9 months ago

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.

[–] [email protected] 1 points 9 months ago (1 children)
[–] pips34 2 points 9 months ago

Hi, my IDE is PyCharm with the Material theme

[–] atheken 1 points 9 months ago* (last edited 9 months ago)

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