Azure-functions-host: ILogger is not injected when using new DI functionality

[alexzheludov]

• Function App version: 2.0
• Microsoft.Net.Sdk.Function v. 1.0.28
• Microsoft.Azure.Functions.Extensions v.1.0.0

When using DI supplied with Function Extension nuget package, an instance of ILogger is not getting injected into dependent classes.

According to the article, we shouldn't have to setup our own logging, because functions have default application insights logging ("For Application Insights, Functions adds Application Insights automatically for you").

Is this intended functionality and article is inaccurate and we need to setup our logging in order to get ILogger to be injected, or is this a bug?

[assembly: FunctionsStartup(typeof(BBI.AzureDevOpsAutomation.Functions.Startup))]

namespace BBI.AzureDevOpsAutomation.Functions
{
    public class Startup : FunctionsStartup
    {
        public override void Configure(IFunctionsHostBuilder builder)
        {
               builder.Services.AddSingleton<IService, Service>();
        }
    }
}


public class Service
{
      private readonly ILogger _logger;
      public Service(ILogger logger)
      {
           _logger = logger ?? throw new ArgumentNullException(nameof(logger));
      }
}

When resolving an instance of the Service, constructor is throwing an exception, because ILogger is not injected.

[anarsen]

@alexzheludov Try asking for the type parameterized ILogger<>, i.e. ILogger<Service>. That'll work.

I used this example to reproduce it, but with Microsoft.NET.Sdk.Functions 1.0.28 and Microsoft.Azure.WebJobs.Script.ExtensionsMetadataGenerator 1.1.1.

[VaclavElias]

It also doesn't work in my project. @anarsen you saying that if you place ILogger log to your SampleGreeter.cs you can log?

[alexzheludov]

Thanks @anarsen, requesting ILogger<Service> worked!

@VaclavElias , yes, if you add ILogger<Service> into your constructor , it will inject an instance of a logger.

[VaclavElias]

Just to correct myself, it doesn't throw an exception in my case but it doesn't log anything.

[brettsam]

ILogger itself isn't a supported DI service. You need to use ILogger<T>: https://docs.microsoft.com/en-us/aspnet/core/fundamentals/logging/?view=aspnetcore-2.2#create-logs.

ILogger is the base interface, but it cannot be constructed via DI as there's no known category. When you use an ILogger<T>, it uses the type T to construct a category.

[older]

ILogger is the base interface, but it cannot be constructed via DI as there's no known category.

Yet it is working in ASP.NET Core.

[older]

Just to correct myself, it doesn't throw an exception in my case but it doesn't log anything.

Tested it and got the same result. ILogger gets injected but doesn't log anything to application insights. I added logger to the SampleGreeter this way:
```C#
public class SampleGreeter : IGreeter
{
private readonly ILogger logger;

    public SampleGreeter(ILogger<SampleGreeter> logger)
    {
        this.logger = logger;
    }

    public string CreateGreeting(string name)
    {
        logger.LogInformation("Logging from greeter");
        return $"Hello, {name}. I'm a sample greeter.";
    }
}

And added logging statement to the function body:
```C#
    log.LogInformation("Logging from function");

Nothing is logged from greeter, while logging from function works.

[VaclavElias]

@older, @brettsam it is all very cryptic, isn't it? :)

Finally, I made it working, tested locally only at the moment.

All you did is ok but you need to white list SampleGreeter according this (till this is fixed) https://github.com/Azure/azure-functions-host/issues/4345.

It didn't work for me just using SampleGreeter, I had to put there whole namespace Microsoft.Azure.Functions.Samples.DependencyInjectionBasic

in your host.json

{
  "version": "2.0",
  "logging": {
    "logLevel": {
      "Microsoft.Azure.Functions.Samples.DependencyInjectionBasic.SampleGreeter": "Information"
    }
  }
}

[brettsam]

Yes, that is an unfortunate issue; sorry I forgot to point that out here.

When we first built logging, we controlled all of the logging categories so we put a filter in place to weed out things coming from other components by default. Unfortunately it also weeds out custom categories, which is becoming more prevalent with DI opening up. I'll be addressing that soon so this filter can go away.

[brettsam]

@older -- Could you share how you got an ILogger in ASP.NET Core? I just tried it and get InvalidOperationException: Unable to resolve service for type 'Microsoft.Extensions.Logging.ILogger' while attempting to activate 'WebApplication18.MyService'.

I'm pretty sure they don't register an ILogger by default anywhere when you configure logging; just an ILogger<>: https://github.com/aspnet/Extensions/blob/master/src/Logging/Logging/src/LoggingServiceCollectionExtensions.cs#L41-L42

[older]

@brettsam My mistake. Just checked and you are right. Don't even know why I thought it was working...

[alexzheludov]

@brettsam @VaclavElias if your solution has common namespace, if you just reference it in the host.json, it will cover your whole solution.
for example all my project namespaces are MyCompany.SolutionName.ProjectName, so when I set host.json to this, everything gets logged.

{
  "version": "2.0",
  "logging": {
    "logLevel": {
      "MyCompany.SolutionName": "Information"
    }
  }
}

I don't see any issues with having to supply this configuration, because we should be controlling our log levels regardless. If you enable trace logging in dev environment, you probably don't want to enable it in production.

[VaclavElias]

Thanks @alexzheludov that is helpful and I agree. I am also ok with white listing.

Interestingly, once deployed when running manually it doesn't show the logs (except from functions) in the log-streaming

But I can see the logs in Monitor, including from my services. Anyway, logging is back so I am ok now.

[APIWT]

Do I need to put a filter for every class that depends on the logger? Or can I get away with just specifying my project namespaces?

[brettsam]

In short, you can typically just put your namespace... it finds the longest matching prefix and uses that rule. The logging docs have some more complex examples: https://docs.microsoft.com/en-us/aspnet/core/fundamentals/logging/?view=aspnetcore-2.2#how-filtering-rules-are-applied

[GFoley83]

@VaclavElias Did you find a solution for having the log information show up in the console when running the function manually?

[VaclavElias]

@GFoley83 nope, no solution found yet.

[Ozzian]

@VaclavElias Did you find a solution for having the log information show up in the console when running the function manually?

@GFoley83 nope, no solution found yet.

According to this hidden gem: There is a regex on your namespaces.

If your namespace starts with "Function", your log messages are pumped to the console. Otherwise you need to use the host file to configure the logging. related link

Example: (I bet that using this in production is a bad idea 🤔 )

{
    "version": "2.0",
    "logging": {
        "fileLoggingMode": "debugOnly",
        "logLevel": {
            "default": "Trace"
        }
    }
}

I hope this helps.

[brettsam]

If you're not seeing custom logger logs show up -- see this issue: https://github.com/Azure/azure-functions-host/issues/4345

[GFoley83]

The logs are coming through fine in App Insights, they're just not showing up in the log streaming service console when you run the Azure function manually in the Portal, as the screenshot shows here:
https://github.com/Azure/azure-functions-host/issues/4425#issuecomment-492709003

It just logs the default function started, function finished messages. I've added the correct filtering on the hosts.json, added the Console logging NuGet packet to my Startup.cs, still nothing. I thought I read on another thread somewhere (can't find it now) that it's a known issue related to how the logging has been implemented since switching over from TraceWriter.

When using the default ILogger that gets injected into the Azure function, everything works fine. It's just when I use ILogger<SomeClass> that gets injected automatically into my services.

[brettsam]

Ah yes -- that's because the only way we know how to direct the logs to that window are via the logger's category. If it matches the form Function.{FunctionName}.User category, we then know which function they came from, so we can show them there. There's likely a way to make this work, though -- I've opened #4689 to track this.

[VaclavElias]

@Ozzian, nope this doesn't make log streaming working.

It works only the way as @GFoley83 mentioned above.

I guess, we have to wait till #4689. And it was working couple of months ago..

[rocco-scaramuzzi]

Hello Guys,
could I please have some help in understanding if I am doing something wrong in instantiating a service which needs to log in Application Insights.

Thanks to your advices above, I am able to log via a simple service instantiated via DI inside FunctionStartup (please see GetServiceRequestQueryHandler inside below code snippet).
Instead I don't see any log inside Application Insights for a service for which we are injecting dependencies by concrete classes instantiated at startup. (please see ServiceRequestService inside below code snippet).

Most likely the problem is because I am creating an ILogger via a new LoggerFactory which is not the same as the Logger automatically injected inside the Function. I cannot let ServiceRequestService dependencies to be automatically resolved by the DI, gatewayService needs to be instantiated with the right settings (ie cosmodb connection string etc).

Could you please advise what should be the right approach to have ILogger working inside my ServiceRequestService?

Please find the code snippets below.

public override void Configure(IFunctionsHostBuilder builder)
        {        
            //gatwewayService is created by passing external service accounts, cosmosdb connection strings etc... 
            var gatewayService = BuildGatewayService(); //implementation omitted     

            var logFactory = new LoggerFactory();
            var serviceRequestLogger = logFactory.CreateLogger<IServiceRequestService>();

            //Logs  NOT displayed in App Insights via ServiceRequestService
            builder.Services.AddSingleton<IServiceRequestService, ServiceRequestService>(x => new ServiceRequestService(gatewayService, serviceRequestLogger));

            //Logs displayed in App Insights via GetServiceRequestQueryHandler 
            builder.Services.AddSingleton<IQueryHandler<GetServiceRequestQueryCriteria, GetServiceRequestQueryResult>, GetServiceRequestQueryHandler>();

        }

public class ServiceRequestService : IServiceRequestService
    {
        private readonly IGatewayService gatewayService;
        private readonly ILogger<IServiceRequestService> logger;

        public ServiceRequestService(IGatewayService gatewayService, ILogger<IServiceRequestService> logger)
        {
            this.gatewayService = gatewayService;
            this.logger = logger;
        }

        public Task<ServiceRequest> GetServiceRequest(
            string referenceNumber,
            ServiceProviderId serviceProviderId)
        {
            logger.LogTrace("GetServiceRequestService triggered");
            //...
        }
    }

 public class GetServiceRequestQueryHandler : IQueryHandler<GetServiceRequestQueryCriteria, GetServiceRequestQueryResult>
    {
        private readonly IServiceRequestService serviceRequestService;
        private readonly ILogger<IQueryHandler<GetServiceRequestQueryCriteria, GetServiceRequestQueryResult>> logger;

        public GetServiceRequestQueryHandler(IServiceRequestService serviceRequestService,
            ILogger<IQueryHandler<GetServiceRequestQueryCriteria, GetServiceRequestQueryResult>> logger)
        {
            this.serviceRequestService = serviceRequestService;
            this.logger = logger;
        }

        public async Task<GetServiceRequestQueryResult> Execute(GetServiceRequestQueryCriteria criteria)
        {
            logger.LogTrace("GetServiceRequestQueryHandler triggered");

            //...
        }
    }

Thanks a lot,
Rocco

[optiks]

var serviceRequestLogger = logFactory.CreateLogger();

        //Logs  NOT displayed in App Insights via ServiceRequestService
        builder.Services.AddSingleton<IServiceRequestService, ServiceRequestService>(x => new ServiceRequestService(gatewayService, serviceRequestLogger));

Have you tried builder.Services.AddSingleton<IServiceRequestService, ServiceRequestService>(x => new ServiceRequestService(gatewayService, x.GetRequiredService<ILogger<IServiceRequestService>>()))?

[rocco-scaramuzzi]

@optiks brilliant, that fixed my issue! Thanks a lot!

[fschaal]

Setting the filter in the host.json did not work for me. I got the logs working by adding

        services.AddLogging(options =>
            {
                options.AddFilter("<SolutionName>", LogLevel.Information);
            });

to my startup class. This basicly shows logs from all projects in your solution that are referenced by the function.

[Loreno10]

@fschaal I tried both host.json and also configuration from code, as you presented, but it does not change anything in my case. I put in a filter a common part of namespace that all solution's projects use and in both Monitoring and Azure Insights I still see only the messages that are logged by funcion's ILogger.

[brettsam]

@Loreno10 can you share your code that shows how you're using your loggers? I can try to reproduce it and see what the issue is.

[Loreno10]

Thanks @brettsam I managed to fix it myself. I was registering my dependencies in my own IServiceCollection, instead of creating a Startup class. As soon as I switched to having Startup class and using IServiceCollection provided by it, logging started to work. Although still, not everywhere. Seems that it works only from classes that exist under my Azure Function project. When I log from classes that are in other projects (and that are referenced by Azure Function project), they are not visible in log stream. I put in host.json the common part of namespace that all my projects share.

[joeyeng]

Thanks @brettsam I managed to fix it myself. I was registering my dependencies in my own IServiceCollection, instead of creating a Startup class. As soon as I switched to having Startup class and using IServiceCollection provided by it, logging started to work. Although still, not everywhere. Seems that it works only from classes that exist under my Azure Function project. When I log from classes that are in other projects (and that are referenced by Azure Function project), they are not visible in log stream. I put in host.json the common part of namespace that all my projects share.

Setting the filter in the host.json did not work for me. I got the logs working by adding

        services.AddLogging(options =>
            {
                options.AddFilter("<SolutionName>", LogLevel.Information);
            });

to my startup class. This basicly shows logs from all projects in your solution that are referenced by the function.

@Loreno10 According to this it sounds like logging should work for other referenced projects as well. No luck for me so far though. Anybody else have any luck?

[brettsam]

Anything that is using Microsoft.Extensions.ILogger in your process all goes through the same logging infrastructure. We apply a default filter in order to prevent a flood of default logs from other libraries, but using the technique above you can allow any log you want to flow through the filter. You need to know what the category they are using (that's what the filter uses). If it's using ILogger<T>, the category of that filter is the full type name of T.

[joeyeng]

@brettsam I'm not getting any logs to app insights with this setup. I'm using generics on the service class to set the logger category.

Service class in other project:

public class Service<T> {
    public Service<T>(ILogger<T> logger) {
        ...
    }
}

Function startup:

builder.Services.AddLogging(options =>
            {
                options.AddFilter(typeof(T).FullName, LogLevel.Information);
            });

builder.Services.AddSingleton<Service<T>>();

[brettsam]

I tried this and it seemed to work for me -- see my gist to see if there's something I've set up differently: https://gist.github.com/brettsam/f0cb90806d7a9dff5d0aaa3068fa71bd.

Note that when I call _service.Log(), it logs three messages:

public void Log()
{
    _logger.LogTrace("Trace");
    _logger.LogInformation("Information");
    _logger.LogError("Error");
}

In App Insights I query with:

| extend category = customDimensions.Category
| where timestamp > ago(1h)
| project timestamp, category, message

And I can see the "Error" and "Information" logs. I do not see "Trace", as expected, as the filter only allows Information+ through.

[joeyeng]

@brettsam The only difference I can spot is that my Service class is in another project that I'm referencing from the function project, but that shouldn't matter, right? Also, my T in this case is the Function class. Other than that all I should have to do is set the APPINSIGHTS_INSTRUMENTATIONKEY app setting, correct?

[brettsam]

Yup, that should be it. Can you share how you're writing your logs? Also, is there anything else important in your Startup.cs that could be affecting this? That may be worth sharing as well.

[joeyeng]

@brettsam

Service.cs:

public async Task FooBar(Action<ILogger<T>> action) 
{
    using (_logger.BeginScope(buildScope())
    {
      _logger.LogInformation("FooBar log - running action");
      action(_logger);
      _logger.LogInformation("FooBar log - finished running action");
    }
}

Function.cs:

[FunctionName("MyTrigger")]
public async Task Run([ServiceBusTrigger("myTopic", "mySubscription")] Message message)
{
  await _service.FooBar(logger => {
    logger.LogInformation("MyTrigger log");
  });
}

In Startup.cs I'm doing the following in addition to adding Service<T> and logging:

• Adding configuration from appsettings.{env}.json
• Adding clients: BlobContainerClient, KeyVaultClient, etc.

[joeyeng]

@brettsam I forgot to mention I'm also using Azure Gov cloud. Does the function host/runtime take that into account? Or do I need to somehow specify the full connection string to my app insights instance?

InstrumentationKey=MYKEY;EndpointSuffix=applicationinsights.us

[brettsam]

Ah. No, it does not. But you shouldn't be seeing any logs in App Insights in gov cloud. There's a DI-based workaround in this comment: https://github.com/Azure/azure-webjobs-sdk/issues/2263#issuecomment-511998264. We have this added to the current sprint, so we hope to have this settable in the host.json soon.