Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Reduce the verbosity of activator exception messages #962

Merged
merged 3 commits into from Mar 4, 2019

Conversation

nblumhardt
Copy link
Member

Hello! Briefly discussed in an offline chat - this PR proposes to cut down the (now ridiculously) verbose exception messages that result from failures deep in the construction of a dependency graph.

For example, before the change C -> B -> A results in this monster:

An error occurred during the activation of a particular registration. See the inner exception
for details. Registration: Activator = C (ReflectionActivator), Services =
[Autofac.Test.ExceptionReportingTests+C], Lifetime = Autofac.Core.Lifetime.CurrentScopeLifetime,
Sharing = None, Ownership = OwnedByLifetimeScope ---> An error occurred during the activation of
a particular registration. See the inner exception for details. Registration: Activator = B
(DelegateActivator), Services = [Autofac.Test.ExceptionReportingTests+B], Lifetime =
Autofac.Core.Lifetime.CurrentScopeLifetime, Sharing = None, Ownership = OwnedByLifetimeScope --->
An error occurred during the activation of a particular registration. See the inner exception for
details. Registration: Activator = A (ReflectionActivator), Services =
[Autofac.Test.ExceptionReportingTests+A], Lifetime = Autofac.Core.Lifetime.CurrentScopeLifetime,
Sharing = None, Ownership = OwnedByLifetimeScope ---> An exception was thrown while invoking the
constructor 'Void .ctor()' on type 'A'. ---> This is the original exception. (See inner exception
for details.) (See inner exception for details.) (See inner exception for details.) (See inner
exception for details.)

(Note four repeats of the phrase "See inner exception for details" :-) ... the inner exception here turns out to be a similarly verbose Autofac exception/message, nested several deep, before we eventually hit something more useful.)

After:

An exception was thrown while activating DependencyResolutionExceptionTests+C -> 
λ:DependencyResolutionExceptionTests+B -> DependencyResolutionExceptionTests+A.

The new message no longer attempts to embed the inner exception message (reverts #343), and does not direct the user to it, because inner exceptions are common .NET machinery and the broad convention is for code that displays exceptions to include them, rather than for them to be duplicated by the wrapping exception. See, for example, Exception.ToString(), which performs this walk of the inner exception tree:

Autofac.Core.DependencyResolutionException: An exception was thrown while activating 
Autofac.Test.Core.DependencyResolutionExceptionTests+C -> 
λ:Autofac.Test.Core.DependencyResolutionExceptionTests+B -> 
Autofac.Test.Core.DependencyResolutionExceptionTests+A. ---> 
Autofac.Core.DependencyResolutionException: An exception was thrown while invoking the constructor 
'Void .ctor()' on type 'A'. ---> System.InvalidOperationException: This is the original exception.
   at Autofac.Test.Core.DependencyResolutionExceptionTests.A..ctor()
   at lambda_method(Closure , Object[] )
   at Autofac.Core.Activators.Reflection.ConstructorParameterBinding.Instantiate()
...

There's also a new shorthand for delegate activators λ:{type}, which will reduce the potential for confusion when the delegate's return type is an interface or other non-specific type.

The full component information is no longer included, but, this can be obtained by inspecting the ComponentRegistry in rare cases where multiple implementations might share the same limit type.

Thoughts?

}

[Fact(Skip = "Issue #648")]
[Fact]
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It appears #648 is resolved.

@tillig
Copy link
Member

tillig commented Mar 3, 2019

I'll have to check this out locally and try it. I'd like to see what it looks like for things like where the cause is something like an unfulfilled dependency - the innermost exception actually being a DependencyResolutionException. As long as it's still clear, I'm pretty fine with making the exception simpler to read.

I'd be curious if there's a way to both provide a simpler message and keep some of the more detailed data. Then again, did folks use that extra data? Maybe not.

{
var fullName = activator.LimitType.FullName ?? "";
return activator is DelegateActivator ?
$"λ:{fullName}" :
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Would it be interesting to have info about whether it was reflection or provided instance activation?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Possibly; I didn't add this because there are few (no?) scenarios where a provided instance will trigger an activation exception.

I also was aiming to describe the type of the component, rather than its internal representation in Autofac - delegates are the special case because their LimitType might be surprising, e.g. System.Object when the actual component is one of several other alternatives.

@nblumhardt
Copy link
Member Author

Thanks for taking a look 👍

Because the unwrapping only takes place when the DependencyResolutionException is tagged with an ActivatorChain, cases that involve other kinds of exceptions will utilise the InnerException. These should be much friendlier to view via the usual means, such as Console.WriteLine(), since this will perform the chaining together of outer and inner exceptions. If you're just examining the exceptions in a debugger, you need to expand InnerException to see all of the details, now.

@alexmg
Copy link
Member

alexmg commented Mar 4, 2019

I was actually hit by the verbose exception message today looking for the cause of an exception. The first sign of the actual error that I needed to find was at column 891. Without word wrap this was way off screen on my 4K monitor. With word wrap on it was a wall of hard to digest text. Let's take this in and iterate on it if we find any shortcomings. The delegate indicator is a nice touch too.

@alexmg alexmg merged commit 7ff61cc into autofac:develop Mar 4, 2019
@alexmg
Copy link
Member

alexmg commented Mar 4, 2019

I never looked into why #648 is passing now but have decided to count it as a win and move on. 😄

@nblumhardt
Copy link
Member Author

Awesome 😄 I feel almost like a useful contributor again! Thanks for giving this one a shot, I'll pull it into our own dev branch and see if I can spot any problems in practical use over the next few weeks 👍

@nblumhardt
Copy link
Member Author

Published as https://www.myget.org/feed/autofac/package/nuget/Autofac/4.9.1-develop-00528 - just a thought, should this be a 4.10.0 or similar?

@alexmg
Copy link
Member

alexmg commented Mar 6, 2019

I've bumped SemVer to 4.9.2 for a different bug fix. I'm not sure this should push it to 4.10.0. Feels like a bit of a grey area. I'm not sure if we are adding, removing or replacing functionality in a non-breaking manner. 😃

@tillig
Copy link
Member

tillig commented Mar 6, 2019

I'd stick with the 0.0.1 - the behavior is different but not in any area that should be relied upon at a programmatic level.

That said, devil's advocate, if someone had a logging system with triggers on the exception message via regex or something... We'd be breaking that, so a 1.0.0 full version change could also be justified.

But me, personally... 0.0.1 increment and done.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants