Is it possible to use an aspect oriented approach to logging in an Azure function with Autofac and DynamicProxy Is it possible to use an aspect oriented approach to logging in an Azure function with Autofac and DynamicProxy azure azure

Is it possible to use an aspect oriented approach to logging in an Azure function with Autofac and DynamicProxy


This is possible using Autofac Type Interceptors, but as you've discovered configuring the interceptors can be tricky. The easiest method I know of to achieve this is using Functionless. Full disclosure, its an open source project I authored. I'm not interested in self-promotion, just trying to help others. I only mention it here because so far as I know its the easiest way to achieve your objective, I'll gladly yield to other better solutions if posted.

Here's a complete gist, FunctionAppLogingInterception, which you should be able to download, build and run, which demonstrates a simple logging interceptor. Here's a brief explanation ...

  1. Configure an appropriate log-level in host.json (see host.json reference for Azure Functions 2.x and later)
    "logLevel": {      "FunctionAppLogingInterception": "Debug"    }
  1. Add your logger IInterceptor implementation which will be automatically picked up and registered by Functionless.
    public class LoggingInterceptor : IInterceptor    {        public void Intercept(IInvocation invocation)        {            ...        }    }
  1. Add a class with one or more public overrideable (i.e. marked virtual or override) methods you'd like intercepted as explained by Autofac | Type Interceptors: Tips.
    public class ReportJob    {        [NewOrchestration]        public virtual async Task ExecuteAsync()        {            ...        }    }
  1. Invoke your class using Functionless's built in orchestrator or add your own function trigger to invoke your class and the interceptor.
POST /api/orchestrator?$method=ReportJob.<ExecuteAsync>()

Or ...

[FunctionName("reportjob-execute")]public async Task Execute(    [HttpTrigger] HttpRequest request,    [DurableClient] IDurableOrchestrationClient client){    await client.DurablyInvokeAsync(        async () => await this.reportJob.ExecuteAsync()    );}
POST /api/reportjob-execute
  1. Observe the intercepted log output. If using the aforementioned gist (FunctionAppLogingInterception) it should produce output similar to the following (note the lines that end with "invoked") ...
[2020-12-22T18:20:10.816Z] Host lock lease acquired by instance ID '000000000000000000000000D771FED2'.[2020-12-22T18:20:16.207Z] Executing 'orchestrator' (Reason='This function was programmatically called via the host APIs.', Id=bdc7d19e-1250-4692-bde2-98cf663cacb8)[2020-12-22T18:20:16.403Z] Executed 'orchestrator' (Succeeded, Id=bdc7d19e-1250-4692-bde2-98cf663cacb8, Duration=243ms)[2020-12-22T18:20:16.481Z] Executing 'orchestration' (Reason='(null)', Id=2d17ea99-959c-43ef-b7ba-ed194de38165)[2020-12-22T18:20:17.133Z] System.Threading.Tasks.Task ExecuteAsync() invoked[2020-12-22T18:20:17.272Z] Executed 'orchestration' (Succeeded, Id=2d17ea99-959c-43ef-b7ba-ed194de38165, Duration=793ms)[2020-12-22T18:20:17.339Z] Executing 'orchestration' (Reason='(null)', Id=ff5c08e7-f678-48a3-9a82-bc2e231195e3)[2020-12-22T18:20:17.582Z] System.Threading.Tasks.Task GenerateReportsAsync() invoked[2020-12-22T18:20:17.597Z] Executed 'orchestration' (Succeeded, Id=ff5c08e7-f678-48a3-9a82-bc2e231195e3, Duration=258ms)[2020-12-22T18:20:17.642Z] Executing 'activity' (Reason='(null)', Id=cc4f89ef-f64c-4851-8e7c-3b7acbfcc915)[2020-12-22T18:20:17.646Z] Executing 'activity' (Reason='(null)', Id=3a7747a6-5568-4561-a028-9c319263ccf7)[2020-12-22T18:20:17.659Z] Executing 'activity' (Reason='(null)', Id=caea5602-9c0b-463a-b0b0-112e512eaf25)[2020-12-22T18:20:17.808Z] System.Threading.Tasks.Task GenerateReportAsync() invoked[2020-12-22T18:20:17.808Z] System.Threading.Tasks.Task GenerateReportAsync() invoked[2020-12-22T18:20:17.808Z] System.Threading.Tasks.Task GenerateReportAsync() invoked[2020-12-22T18:20:18.536Z] Executed 'activity' (Succeeded, Id=caea5602-9c0b-463a-b0b0-112e512eaf25, Duration=878ms)[2020-12-22T18:20:18.540Z] Executed 'activity' (Succeeded, Id=cc4f89ef-f64c-4851-8e7c-3b7acbfcc915, Duration=901ms)[2020-12-22T18:20:18.541Z] Executed 'activity' (Succeeded, Id=3a7747a6-5568-4561-a028-9c319263ccf7, Duration=897ms)[2020-12-22T18:20:18.610Z] Executing 'orchestration' (Reason='(null)', Id=9500673c-7c4d-4d91-bfea-b6e095f51197)[2020-12-22T18:20:18.716Z] System.Threading.Tasks.Task GenerateReportsAsync() invoked[2020-12-22T18:20:18.728Z] Executed 'orchestration' (Succeeded, Id=9500673c-7c4d-4d91-bfea-b6e095f51197, Duration=120ms)[2020-12-22T18:20:18.782Z] Executing 'orchestration' (Reason='(null)', Id=8c9dc2d6-71f9-47b0-8c1a-4409da6b23d7)[2020-12-22T18:20:18.896Z] System.Threading.Tasks.Task ExecuteAsync() invoked[2020-12-22T18:20:18.901Z] Executed 'orchestration' (Succeeded, Id=8c9dc2d6-71f9-47b0-8c1a-4409da6b23d7, Duration=120ms)

For more about how Functionless makes this possible see its Autofac Module implementation which contains the following snippet that could be adapted to many other scenarios if you'd like to achieve a similar result with Autofac but without Functionless ...

assemblies.ForEach(    assembly => builder        .RegisterAssemblyTypes(assembly)        .Where(p => p.IsPublic && p.IsClass)        .AsSelf().AsImplementedInterfaces()        .PreserveExistingDefaults()        .EnableClassInterceptors()        .InterceptedBy(interceptorTypes));