26

I am trying to debug some problems in a legacy code base. I think is being caused by an exception being thrown because something can't be resolved from the Autofac container. However I think the exception is getting buried somewhere and I am not seeing the root cause. I am sure something is being requested from a controller that either can't be found or something that can be found has a dependency that can't be satisfied. There aren't any guard clauses etc. so I think I am getting a null reference issue. To try and debug this I want to see all requests that aren't found in the container.

Is there anyway to log all requests that Autofac couldn't resolve? Or alternatively just log all requests to the container?

GraemeMiller
  • 11,973
  • 8
  • 57
  • 111

4 Answers4

41

You can add logging for requests to the container by registering a special module that will catch the Preparing event for all registrations:

public class LogRequestsModule : Module
{
  protected override void AttachToComponentRegistration(
    IComponentRegistry componentRegistry,
    IComponentRegistration registration)
  {
    // Use the event args to log detailed info
    registration.Preparing += (sender, args) =>
      Console.WriteLine(
        "Resolving concrete type {0}",
        args.Component.Activator.LimitType);
  }
}

This is the simplest way to go and will probably get you what you want. Right after a Preparing event logs the information, you'll see the exception pop up and you'll know which component was throwing.

If you want to get fancier, you can set up some event handlers on the container ChildLifetimeScopeBeginning, ResolveOperationBeginning, ResolveOperationEnding, and CurrentScopeEnding events.

  • During ChildLifetimeScopeBeginning you'd need to set up something to automatically attach to any child lifetime ResolveOperationBeginning events.
  • During ResolveOperationBeginning you'd log what is going to be resolved.
  • During ResolveOperationEnding you'd log any exceptions coming out.
  • During CurrentScopeEnding you'd need to unsubscribe from any events on that scope so the garbage collector can clean up the lifetime scope with all of its instances.

The Whitebox profiler project has a module that implements some of this more advanced logging but it's not set up for the latest Autofac so you'd have to use it as a starting point, not a cut/paste sample.

Again, the easiest solution is that module I posted above.

Tobias
  • 4,999
  • 7
  • 34
  • 40
Travis Illig
  • 23,195
  • 2
  • 62
  • 85
  • 8
    I know SO frowns on thanks. However I really appreciate the effort you put into supporting Autofac questions. Answers are always really detailed – GraemeMiller Sep 03 '13 at 21:09
  • Just for less dependency injected, like myself, this is how you register this module: builder.RegisterModule(); – Sebastian K Apr 29 '14 at 16:50
  • Travis thank you for the answer, Could you please show a snippet how to Log the Scope name of the resolved type? – Cristian E. Sep 21 '14 at 10:03
  • Given that not all lifetime scopes have names, you might not get quite what you're looking for. But in your `ResolveOperationBeginning` handler, you could log `this.Tag` (which would be the lifetime scope's name, if it exists). You will get some confusing results, though, since an object in one scope might resolve dependencies from a different/parent scope. I do not have a code snippet for that. – Travis Illig Sep 21 '14 at 17:39
33

Just to build on an excellent answer by Travis, in case it helps someone in future.

If your class structure is very deep, it may be easier to spot the problematic path, if you display objects in a composition hierarchy. This can be accomplished with somehting like this:

using System;
using System.Text;
using Autofac;
using Autofac.Core;

namespace Tests
{
    public class LogRequestModule : Module
    {
        public int depth = 0;

        protected override void AttachToComponentRegistration(IComponentRegistry componentRegistry,
                                                              IComponentRegistration registration)
        {
            registration.Preparing += RegistrationOnPreparing;
            registration.Activating += RegistrationOnActivating;
            base.AttachToComponentRegistration(componentRegistry, registration);
        }

        private string GetPrefix()
        {
            return new string('-',  depth * 2);
        }

        private void RegistrationOnPreparing(object sender, PreparingEventArgs preparingEventArgs)
        {
            Console.WriteLine("{0}Resolving  {1}", GetPrefix(), preparingEventArgs.Component.Activator.LimitType);
            depth++;
        }

        private void RegistrationOnActivating(object sender, ActivatingEventArgs<object> activatingEventArgs)
        {
            depth--;    
            Console.WriteLine("{0}Activating {1}", GetPrefix(), activatingEventArgs.Component.Activator.LimitType);
        }
    }
}

Sample output:

--Resolving  SomeProject.Web.Integration.RestApiAdapter.RestApiAdapter
----Resolving  SomeProject.Web.Integration.RestApiAdapter.Client.ClientFactory
------Resolving  SomeProject.Web.Integration.RestApiAdapter.RestApiAdapterConfiguration
------Activating SomeProject.Web.Integration.RestApiAdapter.RestApiAdapterConfiguration
------Resolving  SomeProject.Web.Integration.RestApiAdapter.Client.Authentication.ApiClientAuthenticationService
--------Resolving  SomeProject.Web.Integration.RestApiAdapter.RestApiAdapterConfiguration
--------Activating SomeProject.Web.Integration.RestApiAdapter.RestApiAdapterConfiguration
------Activating SomeProject.Web.Integration.RestApiAdapter.Client.Authentication.ApiClientAuthenticationService
Sebastian K
  • 6,235
  • 1
  • 43
  • 67
  • 1
    Nitpicking, but surely 'depth' should be an instance property, not static. Chances of ever using two at the same time are clearly remote, but still... – piers7 Jul 31 '15 at 12:27
  • @piers7, correct, verified it will just fine with instance property, changed it – Sebastian K Jul 31 '15 at 13:40
  • 1
    Man, I can't get any of this to work :( It compiles and runs without errors, module added to container, however, never hits the Registration events.... – Jester Jun 26 '16 at 16:44
  • 1
    @Jester Have you added LogRequestModule to ContainerBuilder? `containerBuilder.RegisterModule();` – Artiom Oct 05 '16 at 14:40
  • 1
    `RegisterModule(new LogRequestModule());` did not work - didn't log anything and breakpoints in the logging code never hit. Registering the way you wrote it works. – DarthDerrr Dec 22 '16 at 12:55
6

The other answers to this question are good for Autofac up to version 5.x. Anybody looking for an answer to this for Autofac version 6.x should instead look into the built in support for Diagnostics & Logging. Autofac no longer requires custom logic to achieve the kinds of logging requested in this question.

The relevant parts of that are:

  • You no longer have to integrate this into your registration-level logic. Although you can if you wish, there is an example at the linked URL
  • Use a DefaultDiagnosticTracer to coordinate your diagnostics. This is a first-class part of Autofac. You set it up and then have your container subscribe to it.

Here's a minimal example which simply uses Console.WriteLine to log diagnostic content. You should replace that with whatever logging mechanism you wish to use for your app.

var tracer = new DefaultDiagnosticTracer();
tracer.OperationCompleted += (sender, args) =>
{
    Console.WriteLine(args.TraceContent);
};
container.SubscribeToDiagnostics(tracer);
Craig Fowler
  • 372
  • 2
  • 12
1

Adding to Craig’s answer the updated link for the Autofac.Diagnostics.DefaultDiagnosticTracer is here

autofac diagnostics

You can simply create a trace instance and watch all registrations.

Eric Williams
  • 35
  • 7