Unable to inject ILogger in telemetry processor

[felpel]

Based on an existing .NET Core web app:

Repro Steps

1. Implement a minimal class that implements ITelemetryProcessor (e.g. CustomTelemetryProcessor);
2. Inject ILogger<CustomTelemetryProcessor> in the constructor;
3. Register your custom processor for dependency injection by calling:

// Telemetry
services.AddApplicationInsightsTelemetryProcessor<CustomTelemetryProcessor>();

4. Deploy your application in an Azure App Service;
5. After a while, try to access a well-known route, a 502 error is shown;
6. Open the Kudu portal, then pick your favorite shell;
7. Find your deployed app (e.g. /site/wwwroot/), then try to execute it with dotnet YourAssembly.dll;
8. Red logs appear indicating a StackOverflowException.

Actual Behavior

It seems that the application will not be able to start, because there might be a circular reference between the logger and the custom telemetry processor, as explained on this StackOverflow thread.

Expected Behavior

If I want to debug my telemetry processor, I should be able to log something to help our investigations.

Version Info

• SDK Version : Using Microsoft.ApplicationInsights.AspNetCore at 2.5.1 and Microsoft.ApplicationInsights at 2.8.1;
• .NET Version : Targetting netcoreapp2.2 in the Web project;
• How Application was onboarded with SDK (VisualStudio/StatusMonitor/Azure Extension) :
• OS : ?
• Hosting Info (IIS/Azure WebApps/ etc): the application is hosted on an Azure App Service that hosts the .NET Core 2.2 app.

[Dmitry-Matveev]

Telemetry Initializers and Telemetry Processors are executed synchronously to the place of TelemetryClient.Track*() invocation. Therefore, if any of them is producing telemetry that eventually is reported with TelemetryClient.Track() method - you'd have an infinite stack of Track invoking track.

My suspicion is that registering Processor with ILogger would produce some ILogger events for that Processor. If, at the same time, Application Insights is subscribed to ILogger events (which typically is the case) - you'd have a situation described above.

Can you please make sure that Processors do not produce AI telemetry and check if StackOverflow disappears in that case?

[paulirwin]

I am unsure if this is the same issue or a separate one, but we noticed the same problem with IDataProtectionProvider instead of ILogger, but it only started happening after upgrading from .NET Core 2.2 to .NET Core 3.1. (We use IDataProtectionProvider to unprotect a cookie value, and were setting that to the requestTelemetry's AccountId property.) The app will not start up, and if you really debug deep into it (which is not easy) you find a stack overflow like described above.

I hope you can easily reproduce this by simply adding IDataProtectionProvider to the constructor of the custom telemetry initializer class.

Please let me know if I should file a separate GitHub issue for this or if it is the same problem.

[Dmitry-Matveev]

@paulirwin , this does look like a separate issue from stack overflow on telemetry collection I am familiar with. However, at the same time, it may be the same issue that ILogger DI above is about.

I tried small repro with TelemetryInitializer accepting IDataProtectionProvider in DI, and the application hangs well before first telemetry item is even collected - it hangs right in the configuration of the web host. Multiple threads seem to be deadlocked in dependency injection (and one is growing its stack alternating between CallSiteRuntimeResolver() and CallSiteVisitor()).

This indicates DI initialization issue, not the telemetry collection issue. Not sure what caused it, but might be related to the fact that custom initializer is getting registered in DI but that initializer requires Data Protector from DI?

[chadsowald]

I ran into this same problem also when upgrading from .NET Core 2.2 to 3.1. Specifically, I already had 3 TelemetryProcessors that worked. All of them required an ILogger in their constructor. When I upgraded to 3.1, my app hangs during startup. I did not have much luck looking through AI changelogs and the code compiles.

Note that it only hangs when I also updated my AI AspNetCore NuGet:

<PackageReference Include="Microsoft.ApplicationInsights.AspNetCore" Version="2.6.1" /> TO <PackageReference Include="Microsoft.ApplicationInsights.AspNetCore" Version="2.14.0" />

Without that change, my app still starts up. But, my understanding is that .NET Core 3.1 requires at least AI 2.8. So, I figured I would upgrade to the latest.

Did anyone find a solution to this? For 2 of my processors, I could probably just remove the ILogger on the constructor. For one of them, it's essential.

[cijothomas]

https://github.com/microsoft/ApplicationInsights-dotnet/issues/1536#issuecomment-573903440 This explains the reason. Since application insights logger provider is added, there is circular dependency now. TelemetryProcessors require Ilogger injected. Ilogger requires TelemetryConfig to be created, which requires TelemetryProcessors.

This issue hasn't been solved, and at this point, only workaround seems like removing Ilogger from the TelemetryProcessors constructor. If you cannot remove this, then the only other workaround (non trivial) is not NOT register applicationinsights using services.AddApplicationInsights(). Instead manually construct every module and telemetryconfguration.

[chadsowald]

Thanks @cijothomas makes sense. I'll keep an eye on this issue and do what I can to mitigate the issue with our processors. Your quick reply was much appreciated :-)

[IanKemp]

Sooo... when, if ever, is this going to be addressed? Should be highest priority IMO since it's breaking people upgrading from Core 2.x.

[cijothomas]

This is not being addressed in the next 2 releases. (i.e no fix at least until end of 2020). Only recommendation is to use the workaround of removing ilogger from telemetryprocessors.

[IanKemp]

This is not being addressed in the next 2 releases. (i.e no fix at least until end of 2020). Only recommendation is to use the workaround of removing ilogger from telemetryprocessors.

Logging is one of the most vital building blocks of any application. To say that not having logging is a "workaround" for logging breaking telemetry processors/initializers entirely, is like saying that removing your arm is preferable to having it broken.

I have to go back to my manager and tell him that we can't have this logging because Microsoft deems it unimportant. He will relay this to our CTO, who is already sceptical of Azure and Microsoft's out-of-the-box solutions. At the end of the day, if our CTO decrees that everything must be hosted in-house and written bespoke because Microsoft's solutions can't be trusted, the only one that loses out is Microsoft.

Think very carefully about your priorities, or lack thereof. Companies choose Microsoft because it has a reputation for reliability and consistency and quality. Issues like these damage that reputation; refusing to treat said issues as critical, when they manifestly are, does a lot more damage. It takes 20 years to build a reputation, and 5 minutes to destroy it. Choose carefully whether this issue is those 5 minutes.

[surenderssm]

Not sure if this is related, let me try reusing this thread instead of creating a new issue as it is also related to injection in implementation of ITelemetryProcessor.

Is this behavior just limited to to ILogger or applicable in other dependencies as well ? In my case intent was to inject IOpReporter (custom reporter), somehow this do not works for me. Am i missing something fundamental here ?

public OpMetricTelemetryProcessor(ITelemetryProcessor next, IOpReporter reporter) { _next = next; _opReporter = reporter; }

Hence ended up doing the following workaround :

public OpMetricTelemetryProcessor(ITelemetryProcessor next) { _next = next; _opReporter = OpReporterProvider.Reporter; }

Environment details

• dotnet - 3.1.403
• Microsoft.ApplicationInsights.AspNetCore - 2.12.1

[Zenuka]

Ran into this annoying issue again today, any updates on this?

[dmcweeney]

Me too

[PierreHenry63]

We have this issue as well in .net 5.0, although it's manifesting itself as a DI circular dependency involving TelemetryConfiguration.

We're trying to implement an ITelemetryInitializer which attaches some user metadata to app insights messages. This goes to a user cache that depends on IMemoryCache as implemented by Microsoft.Extensions.Caching.Memory.MemoryCache. MemoryCache is then dependent on ILoggerFactory, and LoggerFactory eventually depends on TelemetryConfiguration.

So we have in essence TelemetryConfiguration -> MyUserTelemetryInitializer -> MyUserCache -> MemoryCache -> LoggerFactory -> TelemetryConfiguration.

[Rayzbam]

I ran into this issue too. It's not ILogger but using TelemetryClient in the DI has the same issue and preventing the program to start. I was able to start the program using the runtime DI via IServiceScopeFactory and resolving the TelemetryClient at runtime like this.

/* condition to prevent looping for ever */
if(item is ExceptionTelemetry expTelem && !(item as ISupportProperties).Properties.ContainsKey(DEMYSTIFY))
{
    using (var scope = _factory.CreateScope())
    {             
          var telemetry = scope.ServiceProvider.GetRequiredService<TelemetryClient>();
          /* some code here */
          demystifyItem.Properties.Add(DEMYSTIFY, true.ToString());
          telemetry.TrackException(demystifyItem);
    }
}

After that you'll need to check by yourself not making an infinite loop with your telemetryClient.TrackXXX calls. Here i just added a custom properties to say "job is done on this exception" so the next call will not execute the same job. Let me know if it can help you or if you have any better idea/workaround.

[MostefaKamalLala]

I have the same issue with my ITelemetryInitializer. I wanted to use a service which brings more context to the initializer which has a Logger that is injected. Result: Circular Dependency Detected. I need the logger in that service so what would be the solution? I'm using .net core 3.1 and Microsoft.ApplicationInsights.AspNetCore 2.15.0

[github-actions[bot]]

This issue is stale because it has been open 300 days with no activity. Remove stale label or this will be closed in 7 days. Commenting will instruct the bot to automatically remove the label.

[felpel]

This is still an issue, please remove the stale label

[pavlexander]

Not sure if the same issue, but definitely related. For the TelemetryInitializer.

• <TargetFramework>net7.0</TargetFramework>
• <PackageReference Include="Microsoft.ApplicationInsights" Version="2.22.0" />
• <PackageReference Include="Microsoft.ApplicationInsights.AspNetCore" Version="2.22.0" />

Given the following code

Program.cs

        builder.Services.AddHttpClient();
        builder.Services.AddSingleton<IEventReporter, SomeClient>();
        builder.Services.AddSingleton<ITelemetryInitializer, CustomInitializer>();
        builder.Services.AddApplicationInsightsTelemetry();

CustomInitializer

public class CustomInitializer : ITelemetryInitializer
{
    private readonly IEventReporter _reporter;

    public CustomInitializer(
        IEventReporter reporter)
    {
        _reporter = reporter;
    }

    public void Initialize(ITelemetry telemetry)
    {
        //...
    }
}

SomeClient

public interface IEventReporter
{
    Task ReportEventAsync(EventTelemetry request);
}

public class SomeClient : IEventReporter
{
    //private readonly ILogger<SomeClient> _logger;
    private readonly IHttpClientFactory _httpClientFactory;

    public SomeClient (
        //ILogger<SomeClient> logger,
        IHttpClientFactory httpClientFactory, 
        IOptions<ApiSettings> options)
    {
        //_logger = logger;
        _httpClientFactory = httpClientFactory;
    }

    public async Task ReportEventAsync(
        EventTelemetry request)
    {
        // ...
    }
}

you would get a black/blank console screen - no errors, no exceptions. The app simply not starting in debug mode. Though it looks like something is running.

in case if you add an Ilogger injection into the SomeClient - you'd get the exception upon app startup:

InvalidOperationException: A circular dependency was detected for the service of type 'Microsoft.Extensions.Logging.ILoggerFactory'.

It feels like there is something wrong with the telemetry related classes and methods.. especially when it comes to DI. I would strongly suggest looking into refactoring the code, or at least throw some meaningful errors if there is something wrong with the configuration.

edit also, I am not sure if it counts as the solution to the problem, but what I ended up doing is basically creating a wrapper around the TelemetryClient, i.e.

public interface ITelemetryAbstaction
{
    void TrackEvent(string eventName, IDictionary<string, string> properties = null, IDictionary<string, double> metrics = null);
}

public class TelemetryAbstraction : ITelemetryAbstaction
{
    private readonly ILogger<TelemetryAbstraction> _logger;
    private readonly TelemetryClient _telemetry;
    private readonly IEventReporter2 _someClient;

    public TelemetryAbstraction (
        ILogger<TelemetryAbstraction> logger,
        TelemetryClient telemetry,
        IEventReporter2 someClient
        )
    {
        _logger = logger;
        _telemetryInitializer = telemetry;
        _someClient = someClient;
    }

    public void TrackEvent(string eventName, IDictionary<string, string> properties = null, IDictionary<string, double> metrics = null)
    {
        _telemetry.TrackEvent(eventName, properties, metrics);
        _someClient.ReportEventAsync(eventName, properties);
    }
}

so now instead of calling the TrackEvent on the TelemetryClient I instead call it on TelemetryAbstraction, which has a proper access to logging and other DIs. Not ideal, but works for me.