Add tests for tracing, and make sure the top-level operation is corre…

…ctly identified.

src/Autofac/Core/Diagnostics/DefaultDiagnosticTracer.cs

@@ -129,7 +129,11 @@ void IResolvePipelineTracer.OperationFailure(ResolveOperationBase operation, Exc
                 builder.AppendLine(TracerMessages.ExitBrace);
                 builder.AppendException(TracerMessages.OperationFailed, operationException);
 
-                OperationCompleted?.Invoke(this, new OperationTraceCompletedArgs(operation, builder.ToString()));
+                // If we're completing the root operation, raise the event.
+                if (operation.IsTopLevelOperation)
+                {
+                    OperationCompleted?.Invoke(this, new OperationTraceCompletedArgs(operation, builder.ToString()));
+                }
             }
         }
 

src/Autofac/Core/Resolving/ResolveOperationBase.cs

@@ -59,6 +59,7 @@ protected ResolveOperationBase(ISharingLifetimeScope mostNestedLifetimeScope)
         protected ResolveOperationBase(ISharingLifetimeScope mostNestedLifetimeScope, IResolvePipelineTracer? pipelineTracer)
         {
             TracingId = this;
+            IsTopLevelOperation = true;
             CurrentScope = mostNestedLifetimeScope;
             _pipelineTracer = pipelineTracer;
         }
@@ -74,6 +75,7 @@ protected ResolveOperationBase(ISharingLifetimeScope mostNestedLifetimeScope, IR
             : this(mostNestedLifetimeScope, pipelineTracer)
         {
             TracingId = tracingId;
+            IsTopLevelOperation = false;
         }
 
         /// <summary>

test/Autofac.Specification.Test/Diagnostics/DefaultDiagnosticTracerTests.cs

@@ -0,0 +1,113 @@
+using System;
+using Autofac.Core.Diagnostics;
+using Xunit;
+
+namespace Autofac.Specification.Test.Diagnostics
+{
+    public class DefaultDiagnosticTracerTests
+    {
+        [Fact]
+        public void DiagnosticTracerRaisesEvents()
+        {
+            var tracer = new DefaultDiagnosticTracer();
+
+            var containerBuilder = new ContainerBuilder();
+            containerBuilder.Register(ctxt => "Hello");
+
+            var container = containerBuilder.Build();
+
+            container.AttachTrace(tracer);
+
+            string lastOpResult = null;
+
+            tracer.OperationCompleted += (sender, args) =>
+            {
+                Assert.Same(tracer, sender);
+                lastOpResult = args.TraceContent;
+            };
+
+            container.Resolve<string>();
+
+            Assert.Contains("Hello", lastOpResult);
+        }
+
+        [Fact]
+        public void DiagnosticTracerRaisesEventsOnError()
+        {
+            var tracer = new DefaultDiagnosticTracer();
+
+            var containerBuilder = new ContainerBuilder();
+            containerBuilder.Register<string>(ctxt => throw new InvalidOperationException());
+
+            var container = containerBuilder.Build();
+
+            container.AttachTrace(tracer);
+
+            string lastOpResult = null;
+
+            tracer.OperationCompleted += (sender, args) =>
+            {
+                Assert.Same(tracer, sender);
+                lastOpResult = args.TraceContent;
+            };
+
+            try
+            {
+                container.Resolve<string>();
+            }
+            catch
+            {
+            }
+
+            Assert.Contains(nameof(InvalidOperationException), lastOpResult);
+        }
+
+        [Fact]
+        public void DiagnosticTracerDoesNotRaiseAnEventOnNestedOperations()
+        {
+            var tracer = new DefaultDiagnosticTracer();
+
+            var containerBuilder = new ContainerBuilder();
+            containerBuilder.RegisterType<Implementor>().As<IService>();
+            containerBuilder.RegisterDecorator<Decorator, IService>();
+
+            var container = containerBuilder.Build();
+
+            container.AttachTrace(tracer);
+
+            int traceCount = 0;
+            string lastOpResult = null;
+
+            tracer.OperationCompleted += (sender, args) =>
+            {
+                Assert.Same(tracer, sender);
+                lastOpResult = args.TraceContent;
+                traceCount++;
+            };
+
+            container.Resolve<IService>();
+
+            // Only a single trace (despite the nested operations).
+            Assert.Equal(1, traceCount);
+            Assert.Contains("Decorator", lastOpResult);
+        }
+
+        private interface IService
+        {
+        }
+
+        private class Decorator : IService
+        {
+            public Decorator(IService decorated)
+            {
+                this.Decorated = decorated;
+            }
+
+            public IService Decorated { get; }
+        }
+
+        private class Implementor : IService
+        {
+        }
+    }
+}

test/Autofac.Test/Core/Resolving/ResolveOperationTests.cs

@@ -1,5 +1,8 @@
 using System;
+using System.Collections.Generic;
 using System.Linq;
+using Autofac.Core;
+using Autofac.Core.Resolving;
 using Xunit;
 
 namespace Autofac.Test.Core.Resolving
@@ -22,5 +25,112 @@ public void AfterTheOperationIsFinished_ReusingTheTemporaryContextThrows()
             container.Resolve<object>();
             Assert.Throws<ObjectDisposedException>(() => ctx.Resolve<string>());
         }
+
+        [Fact]
+        public void OperationRaisesSuccessTraceEvents()
+        {
+            var builder = new ContainerBuilder();
+
+            builder.RegisterInstance("Hello");
+
+            var container = builder.Build();
+
+            var scope = container.Resolve<ILifetimeScope>() as ISharingLifetimeScope;
+
+            var mockTracer = Mocks.GetTracer();
+
+            var resolveOp = new ResolveOperation(scope, mockTracer);
+
+            var raisedEvents = new List<string>();
+
+            var request = new ResolveRequest(new TypedService(typeof(string)), scope.RegistrationFor<string>(), Enumerable.Empty<Parameter>());
+
+            mockTracer.OperationStarting += (op, req) =>
+            {
+                raisedEvents.Add("opstart");
+                Assert.Equal(resolveOp, op);
+                Assert.Equal(request, req);
+            };
+
+            mockTracer.RequestStarting += (op, ctxt) =>
+            {
+                raisedEvents.Add("reqstart");
+                Assert.Equal(resolveOp, op);
+                Assert.Equal(request.Service, ctxt.Service);
+            };
+
+            mockTracer.RequestSucceeding += (op, ctxt) =>
+            {
+                raisedEvents.Add("reqsuccess");
+                Assert.Equal(resolveOp, op);
+            };
+
+            mockTracer.OperationSucceeding += (op, instance) =>
+            {
+                raisedEvents.Add("opsuccess");
+                Assert.Equal("Hello", instance);
+            };
+
+            resolveOp.Execute(request);
+
+            Assert.Equal(new[] { "opstart", "reqstart", "reqsuccess", "opsuccess" }, raisedEvents);
+        }
+
+        [Fact]
+        public void OperationRaisesFailureTraceEvents()
+        {
+            var builder = new ContainerBuilder();
+
+            builder.Register<string>(ctxt => throw new InvalidOperationException());
+
+            var container = builder.Build();
+
+            var scope = container.Resolve<ILifetimeScope>() as ISharingLifetimeScope;
+
+            var mockTracer = Mocks.GetTracer();
+
+            var resolveOp = new ResolveOperation(scope, mockTracer);
+
+            var raisedEvents = new List<string>();
+
+            var request = new ResolveRequest(new TypedService(typeof(string)), scope.RegistrationFor<string>(), Enumerable.Empty<Parameter>());
+
+            mockTracer.OperationStarting += (op, req) =>
+            {
+                raisedEvents.Add("opstart");
+                Assert.Equal(resolveOp, op);
+                Assert.Equal(request, req);
+            };
+
+            mockTracer.RequestStarting += (op, ctxt) =>
+            {
+                raisedEvents.Add("reqstart");
+                Assert.Equal(resolveOp, op);
+                Assert.Equal(request.Service, ctxt.Service);
+            };
+
+            mockTracer.RequestFailing += (op, ctxt, ex) =>
+            {
+                raisedEvents.Add("reqfail");
+                Assert.Equal(resolveOp, op);
+                Assert.IsType<DependencyResolutionException>(ex);
+            };
+
+            mockTracer.OperationFailing += (op, ex) =>
+            {
+                raisedEvents.Add("opfail");
+                Assert.IsType<DependencyResolutionException>(ex);
+            };
+
+            try
+            {
+                resolveOp.Execute(request);
+            }
+            catch
+            {
+            }
+
+            Assert.Equal(new[] { "opstart", "reqstart", "reqfail", "opfail" }, raisedEvents);
+        }
     }
 }

test/Autofac.Test/Mocks.cs

@@ -26,6 +26,11 @@ public static MockComponentRegistration GetComponentRegistration()
             return new MockComponentRegistration();
         }
 
+        public static MockTracer GetTracer()
+        {
+            return new MockTracer();
+        }
+
         internal class MockConstructorFinder : IConstructorFinder
         {
             public ConstructorInfo[] FindConstructors(Type targetType)
@@ -78,5 +83,68 @@ public void BuildResolvePipeline(IComponentRegistryServices registryServices)
                 PipelineBuilding?.Invoke(this, new ResolvePipelineBuilder());
             }
         }
+
+        internal class MockTracer : IResolvePipelineTracer
+        {
+            public MockTracer()
+            {
+            }
+
+            public event Action<ResolveOperationBase, ResolveRequest> OperationStarting;
+
+            public event Action<ResolveOperationBase, ResolveRequestContextBase> RequestStarting;
+
+            public event Action<ResolveOperationBase, ResolveRequestContextBase, IResolveMiddleware> EnteringMiddleware;
+
+            public event Action<ResolveOperationBase, ResolveRequestContextBase, IResolveMiddleware, bool> ExitingMiddleware;
+
+            public event Action<ResolveOperationBase, ResolveRequestContextBase, Exception> RequestFailing;
+
+            public event Action<ResolveOperationBase, ResolveRequestContextBase> RequestSucceeding;
+
+            public event Action<ResolveOperationBase, Exception> OperationFailing;
+
+            public event Action<ResolveOperationBase, object> OperationSucceeding;
+
+            public void OperationStart(ResolveOperationBase operation, ResolveRequest initiatingRequest)
+            {
+                OperationStarting?.Invoke(operation, initiatingRequest);
+            }
+
+            public void RequestStart(ResolveOperationBase operation, ResolveRequestContextBase requestContext)
+            {
+                RequestStarting?.Invoke(operation, requestContext);
+            }
+
+            public void MiddlewareEntry(ResolveOperationBase operation, ResolveRequestContextBase requestContext, IResolveMiddleware middleware)
+            {
+                EnteringMiddleware?.Invoke(operation, requestContext, middleware);
+            }
+
+            public void MiddlewareExit(ResolveOperationBase operation, ResolveRequestContextBase requestContext, IResolveMiddleware middleware, bool succeeded)
+            {
+                ExitingMiddleware?.Invoke(operation, requestContext, middleware, succeeded);
+            }
+
+            public void RequestFailure(ResolveOperationBase operation, ResolveRequestContextBase requestContext, Exception requestException)
+            {
+                RequestFailing?.Invoke(operation, requestContext, requestException);
+            }
+
+            public void RequestSuccess(ResolveOperationBase operation, ResolveRequestContextBase requestContext)
+            {
+                RequestSucceeding?.Invoke(operation, requestContext);
+            }
+
+            public void OperationFailure(ResolveOperationBase operation, Exception operationException)
+            {
+                OperationFailing?.Invoke(operation, operationException);
+            }
+
+            public void OperationSuccess(ResolveOperationBase operation, object resolvedInstance)
+            {
+                OperationSucceeding?.Invoke(operation, resolvedInstance);
+            }
+        }
     }
 }