end to end tracing with the new instrumentation using OWIN requests

DarthFubuMVC · Aug 26, 2015 · 3763b2a · 3763b2a
1 parent d2df0ab
commit 3763b2a
Show file tree

Hide file tree

Showing 11 changed files with 197 additions and 47 deletions.
diff --git a/src/FubuMVC.Core/Diagnostics/Instrumentation/ChainExecutionListener.cs b/src/FubuMVC.Core/Diagnostics/Instrumentation/ChainExecutionListener.cs
@@ -0,0 +1,63 @@
+using System;
+using FubuCore.Logging;
+using ExceptionReport = FubuCore.Logging.ExceptionReport;
+
+namespace FubuMVC.Core.Diagnostics.Instrumentation
+{
+    public class ChainExecutionListener : ILogListener
+    {
+        private readonly IChainExecutionLog _trace;
+
+        public ChainExecutionListener(IChainExecutionLog trace)
+        {
+            _trace = trace;
+        }
+
+        public bool ListensFor(Type type)
+        {
+            return true;
+        }
+
+        public void DebugMessage(object message)
+        {
+            _trace.Log(message);
+        }
+
+        public void InfoMessage(object message)
+        {
+            _trace.Log(message);
+        }
+
+        public void Debug(string message)
+        {
+            _trace.Log(new StringMessage(message));
+        }
+
+        public void Info(string message)
+        {
+            _trace.Log(new StringMessage(message));
+        }
+
+        public void Error(string message, Exception ex)
+        {
+            _trace.Log(new ExceptionReport(message, ex));
+        }
+
+        public void Error(object correlationId, string message, Exception ex)
+        {
+            _trace.Log(new ExceptionReport(message, ex){
+                CorrelationId = correlationId
+            });
+        }
+
+        public bool IsDebugEnabled
+        {
+            get { return true; }
+        }
+
+        public bool IsInfoEnabled
+        {
+            get { return true; }
+        }
+    }
+}
diff --git a/src/FubuMVC.Core/Diagnostics/Instrumentation/ChainExecutionLog.cs b/src/FubuMVC.Core/Diagnostics/Instrumentation/ChainExecutionLog.cs
@@ -80,7 +80,7 @@ public void LogException(Exception ex)
 
             _exceptions.Add(ex);
             HadException = true;
-            AddLog(new ExceptionReport(ex));
+            Log(new ExceptionReport(ex));
         }
 
         public void MarkFinished(Action<IDictionary<string, object>> writeResponse)
@@ -98,7 +98,7 @@ public IDictionary<string, object> Request
 
         public string SessionTag { get; set; }
 
-        public void AddLog(object log)
+        public void Log(object log)
         {
             current.AppendLog(requestTime(), log);
         }
@@ -110,7 +110,7 @@ public void Trace(string description, Action action)
             action();
             var finish = requestTime();
 
-            AddLog(new Trace
+            Log(new Trace
             {
                 Description = description,
                 Duration = finish - start

diff --git a/src/FubuMVC.Core/Diagnostics/Instrumentation/IChainExecutionLog.cs b/src/FubuMVC.Core/Diagnostics/Instrumentation/IChainExecutionLog.cs
@@ -9,7 +9,7 @@ public interface IChainExecutionLog
         void StartSubject(ISubject subject);
         void FinishSubject();
         void LogException(Exception ex);
-        void AddLog(object log);
+        void Log(object log);
         void Trace(string description, Action action);
         void RecordHeaders(IDictionary<string, object> env);
         void RecordBody(IDictionary<string, object> env);

diff --git a/src/FubuMVC.Core/DiagnosticsSettings.cs b/src/FubuMVC.Core/DiagnosticsSettings.cs
@@ -72,6 +72,8 @@ void IFeatureSettings.Apply(FubuRegistry registry)
 
                 registry.Services.IncludeRegistry(InstrumentationServices);
 
+                registry.Services.AddService<ILogListener, ChainExecutionListener>();
+
             }
 
             if (registry.Mode.InDevelopment() || TraceLevel == TraceLevel.Verbose)

diff --git a/src/FubuMVC.Core/FubuMVC.Core.csproj b/src/FubuMVC.Core/FubuMVC.Core.csproj
@@ -98,6 +98,7 @@
     <Compile Include="Diagnostics\Instrumentation\PerformanceHistoryQueueActivator.cs" />
     <Compile Include="Diagnostics\Instrumentation\ProductionExecutionLogger.cs" />
     <Compile Include="Diagnostics\Instrumentation\RequestStep.cs" />
+    <Compile Include="Diagnostics\Instrumentation\ChainExecutionListener.cs" />
     <Compile Include="Diagnostics\Instrumentation\Trace.cs" />
     <Compile Include="Diagnostics\Instrumentation\VerboseExecutionLogger.cs" />
     <Compile Include="FubuModeExtensions.cs" />

diff --git a/src/FubuMVC.Core/Http/HttpStandinServiceRegistry.cs b/src/FubuMVC.Core/Http/HttpStandinServiceRegistry.cs
@@ -1,5 +1,6 @@
 using System.Collections.Generic;
 using System.Web.Routing;
+using FubuMVC.Core.Diagnostics.Instrumentation;
 using FubuMVC.Core.Http.Owin;
 using FubuMVC.Core.Registration;
 
@@ -16,6 +17,8 @@ public HttpStandInServiceRegistry()
             For<ICurrentChain>().Use(new CurrentChain(null, null));
             For<RouteData>().Use(new RouteData());
             For<IDictionary<string, object>>().Use(new Dictionary<string, object>());
+
+            For<IChainExecutionLog>().Use<ChainExecutionLog>();
         }
     }
 }
diff --git a/src/FubuMVC.Tests/Diagnostics/DiagnosticSettings_TraceLevel_Registration_Tester.cs b/src/FubuMVC.Tests/Diagnostics/DiagnosticSettings_TraceLevel_Registration_Tester.cs
@@ -89,7 +89,7 @@ public void verbose_registrations()
 
                 c.DefaultSingletonIs<IExecutionLogger, VerboseExecutionLogger>();
 
-
+                c.ShouldHaveRegistration<ILogListener, ChainExecutionListener>();
             });
         }
 
@@ -105,6 +105,8 @@ public void production_registration()
 
                 c.DefaultSingletonIs<IExecutionLogger, ProductionExecutionLogger>();
 
+                c.ShouldHaveRegistration<ILogListener, ChainExecutionListener>();
+
             });
         }
 
@@ -120,7 +122,7 @@ public void trace_level_is_none_registration()
 
                 c.DefaultSingletonIs<IExecutionLogger, NulloExecutionLogger>();
 
-
+                c.ShouldNotHaveRegistration<ILogListener, ChainExecutionListener>();
             });
         }
     }

diff --git a/src/FubuMVC.Tests/Diagnostics/Instrumentation/ChainExecutionHistoryTester.cs b/src/FubuMVC.Tests/Diagnostics/Instrumentation/ChainExecutionHistoryTester.cs
@@ -0,0 +1,44 @@
+using System.Linq;
+using FubuMVC.Core;
+using FubuMVC.Core.Diagnostics.Instrumentation;
+using FubuMVC.Core.Diagnostics.Runtime;
+using NUnit.Framework;
+using Shouldly;
+
+namespace FubuMVC.Tests.Diagnostics.Instrumentation
+{
+    [TestFixture]
+    public class ChainExecutionHistoryTester
+    {
+        [Test]
+        public void only_cache_up_to_the_setting_limit()
+        {
+            var settings = new DiagnosticsSettings
+            {
+                MaxRequests = 10
+            };
+
+            var cache = new ChainExecutionHistory(settings);
+
+            cache.Store(new ChainExecutionLog());
+            cache.Store(new ChainExecutionLog());
+            cache.Store(new ChainExecutionLog());
+            cache.Store(new ChainExecutionLog());
+            cache.Store(new ChainExecutionLog());
+            cache.Store(new ChainExecutionLog());
+            cache.Store(new ChainExecutionLog());
+            cache.Store(new ChainExecutionLog());
+            cache.Store(new ChainExecutionLog());
+
+            cache.RecentReports().Count().ShouldBe(9);
+
+            cache.Store(new ChainExecutionLog());
+            cache.Store(new ChainExecutionLog());
+            cache.Store(new ChainExecutionLog());
+            cache.Store(new ChainExecutionLog());
+            cache.Store(new ChainExecutionLog());
+
+            cache.RecentReports().Count().ShouldBe(settings.MaxRequests);
+        }
+    }
+}
diff --git a/src/FubuMVC.Tests/Diagnostics/Instrumentation/ChainExecutionListenerTester.cs b/src/FubuMVC.Tests/Diagnostics/Instrumentation/ChainExecutionListenerTester.cs
@@ -0,0 +1,69 @@
+using FubuCore.Logging;
+using FubuMVC.Core.Diagnostics.Instrumentation;
+using FubuMVC.Core.Diagnostics.Runtime.Tracing;
+using FubuMVC.Tests.TestSupport;
+using NUnit.Framework;
+using Rhino.Mocks;
+using Shouldly;
+
+namespace FubuMVC.Tests.Diagnostics.Instrumentation
+{
+    [TestFixture]
+    public class ChainExecutionListenerTester : InteractionContext<ChainExecutionListener>
+    {
+        private void assertMessageWasLogged(object message)
+        {
+            MockFor<IChainExecutionLog>().AssertWasCalled(x => x.Log(message));
+        }
+
+        [Test]
+        public void debugging_is_enabled()
+        {
+            ClassUnderTest.IsDebugEnabled.ShouldBeTrue();
+        }
+
+        [Test]
+        public void info_is_enabled()
+        {
+            ClassUnderTest.IsInfoEnabled.ShouldBeTrue();
+        }
+
+        [Test]
+        public void debug_message_delegates()
+        {
+            var message = new object();
+
+            ClassUnderTest.DebugMessage(message);
+
+            assertMessageWasLogged(message);
+        }
+
+        [Test]
+        public void debug_string_delegates()
+        {
+            ClassUnderTest.Debug("some stuff");
+
+            assertMessageWasLogged(new StringMessage("some stuff"));
+        }
+
+        [Test]
+        public void info_message_delegates()
+        {
+            var message = new object();
+
+            ClassUnderTest.InfoMessage(message);
+
+            assertMessageWasLogged(message);
+        }
+
+        [Test]
+        public void info_string_delegates()
+        {
+            ClassUnderTest.Info("some stuff");
+
+            assertMessageWasLogged(new StringMessage("some stuff"));
+        }
+
+
+    }
+}
diff --git a/src/FubuMVC.Tests/Diagnostics/Instrumentation/ChainExecutionLogTester.cs b/src/FubuMVC.Tests/Diagnostics/Instrumentation/ChainExecutionLogTester.cs
@@ -2,7 +2,6 @@
 using System.Collections.Generic;
 using System.Linq;
 using FubuCore.Logging;
-using FubuMVC.Core;
 using FubuMVC.Core.Diagnostics.Instrumentation;
 using FubuMVC.Core.Http.Owin;
 using NUnit.Framework;
@@ -34,7 +33,7 @@ public void logging_sets_the_request_time_and_activity_at_parent()
             var log = new StubbedChainExecutionLog();
             log.RequestTime = 111;
 
-            log.AddLog(new object());
+            log.Log(new object());
 
             log.Activity.Steps.Single().RequestTime.ShouldBe(111);
             log.Activity.Steps.Single().Activity.ShouldBe(log.Activity);
@@ -81,19 +80,19 @@ public void deep_activity_logging()
 
             var log = new StubbedChainExecutionLog();
             log.RequestTime = 1;
-            log.AddLog(x1);
+            log.Log(x1);
 
             log.StartSubject(subject1);
             log.RequestTime = 5;
-            log.AddLog(x2);
+            log.Log(x2);
 
             log.RequestTime = 10;
             log.StartSubject(subject2);
-            log.AddLog(x3);
+            log.Log(x3);
 
             log.RequestTime = 15;
             log.FinishSubject();
-            log.AddLog(x4);
+            log.Log(x4);
 
             var steps = log.Activity.AllSteps().OrderBy(x => x.RequestTime).ToArray();
 
@@ -198,39 +197,4 @@ protected override double requestTime()
             return RequestTime;
         }
     }
-
-    [TestFixture]
-    public class ChainExecutionHistoryTester
-    {
-        [Test]
-        public void only_cache_up_to_the_setting_limit()
-        {
-            var settings = new DiagnosticsSettings
-            {
-                MaxRequests = 10
-            };
-
-            var cache = new ChainExecutionHistory(settings);
-
-            cache.Store(new ChainExecutionLog());
-            cache.Store(new ChainExecutionLog());
-            cache.Store(new ChainExecutionLog());
-            cache.Store(new ChainExecutionLog());
-            cache.Store(new ChainExecutionLog());
-            cache.Store(new ChainExecutionLog());
-            cache.Store(new ChainExecutionLog());
-            cache.Store(new ChainExecutionLog());
-            cache.Store(new ChainExecutionLog());
-
-            cache.RecentReports().Count().ShouldBe(9);
-
-            cache.Store(new ChainExecutionLog());
-            cache.Store(new ChainExecutionLog());
-            cache.Store(new ChainExecutionLog());
-            cache.Store(new ChainExecutionLog());
-            cache.Store(new ChainExecutionLog());
-
-            cache.RecentReports().Count().ShouldBe(settings.MaxRequests);
-        }
-    }
 }
diff --git a/src/FubuMVC.Tests/FubuMVC.Tests.csproj b/src/FubuMVC.Tests/FubuMVC.Tests.csproj
@@ -106,6 +106,8 @@
     <Compile Include="Diagnostics\FakeFubuDiagnostics.cs" />
     <Compile Include="Diagnostics\Instrumentation\ActivityTester.cs" />
     <Compile Include="Diagnostics\Instrumentation\BehaviorTracerTester.cs" />
+    <Compile Include="Diagnostics\Instrumentation\ChainExecutionHistoryTester.cs" />
+    <Compile Include="Diagnostics\Instrumentation\ChainExecutionListenerTester.cs" />
     <Compile Include="Diagnostics\Instrumentation\ChainExecutionLogTester.cs" />
     <Compile Include="Diagnostics\Instrumentation\PerformanceHistoryTester.cs" />
     <Compile Include="Diagnostics\Instrumentation\ProductionExecutionLoggerTester.cs" />
-Original file line number
+Diff line change
@@ Expand Up / @@ -72,6 +72,8 @@ void IFeatureSettings.Apply(FubuRegistry registry) @@
                     registry.Services.IncludeRegistry(InstrumentationServices);
+                    registry.Services.AddService<ILogListener, ChainExecutionListener>();
                 }
                 if (registry.Mode.InDevelopment() || TraceLevel == TraceLevel.Verbose)
@@ Expand Down @@