diff --git a/src/Umbraco.Core/CoreBootManager.cs b/src/Umbraco.Core/CoreBootManager.cs index 419f9cd873..3d84a75646 100644 --- a/src/Umbraco.Core/CoreBootManager.cs +++ b/src/Umbraco.Core/CoreBootManager.cs @@ -53,8 +53,9 @@ namespace Umbraco.Core if (_isInitialized) throw new InvalidOperationException("The boot manager has already been initialized"); - LogHelper.Info("Umbraco application starting"); - _timer = DisposableTimer.Start(x => LogHelper.Info("Umbraco application startup complete" + " (took " + x + "ms)")); + InitializeProfilerResolver(); + + _timer = DisposableTimer.Start("Umbraco application starting", x => LogHelper.Info("Umbraco application startup complete" + " (took " + x + "ms)")); //create database and service contexts for the app context var dbFactory = new DefaultDatabaseFactory(GlobalSettings.UmbracoConnectionName); @@ -94,6 +95,20 @@ namespace Umbraco.Core ApplicationContext = ApplicationContext.Current = new ApplicationContext(dbContext, serviceContext); } + /// + /// Special method to initialize the ProfilerResolver + /// + protected virtual void InitializeProfilerResolver() + { + //By default we'll initialize the Log profiler (in the web project, we'll override with the web profiler) + ProfilerResolver.Current = new ProfilerResolver(new LogProfiler()) + { + //This is another special resolver that needs to be resolvable before resolution is frozen + //since it is used for profiling the application startup + CanResolveBeforeFrozen = true + }; + } + /// /// Special method to initialize the ApplicationEventsResolver and any modifications required for it such /// as adding custom types to the resolver. @@ -186,9 +201,7 @@ namespace Umbraco.Core /// Create the resolvers /// protected virtual void InitializeResolvers() - { - //By default we'll initialize the Log profiler (in the web project, we'll override with the web profiler) - ProfilerResolver.Current = new ProfilerResolver(new LogProfiler()); + { //by default we'll use the standard configuration based sync ServerRegistrarResolver.Current = new ServerRegistrarResolver( diff --git a/src/Umbraco.Core/DisposableTimer.cs b/src/Umbraco.Core/DisposableTimer.cs index f2a6904b9f..6f8f40c5e1 100644 --- a/src/Umbraco.Core/DisposableTimer.cs +++ b/src/Umbraco.Core/DisposableTimer.cs @@ -1,6 +1,7 @@ using System; using System.Diagnostics; using Umbraco.Core.Logging; +using Umbraco.Core.Profiling; namespace Umbraco.Core { @@ -9,23 +10,52 @@ namespace Umbraco.Core /// /// /// + /// + /// using (DisposableTimer.TraceDuration{MyType}("starting", "finished")) + /// { + /// Thread.Sleep(567); + /// } + /// /// Console.WriteLine("Testing Stopwatchdisposable, should be 567:"); - // using (var timer = new DisposableTimer(result => Console.WriteLine("Took {0}ms", result))) - // { - // Thread.Sleep(567); - // } + /// using (var timer = new DisposableTimer(result => Console.WriteLine("Took {0}ms", result))) + /// { + /// Thread.Sleep(567); + /// } /// /// public class DisposableTimer : DisposableObject { private readonly Stopwatch _stopwatch = Stopwatch.StartNew(); private readonly Action _callback; + private readonly IDisposable _profilerStep; + [Obsolete("Use the other constructor instead to ensure that the output it sent to the current profiler")] protected DisposableTimer(Action callback) { _callback = callback; } + /// + /// Constructor which activates a step in the profiler + /// + /// + /// + /// + protected DisposableTimer(Type loggerType, string profileName, Action callback) + { + _callback = callback; + + try + { + _profilerStep = ProfilerResolver.Current.Profiler.Step(loggerType, profileName); + } + catch (InvalidOperationException) + { + //swallow this exception, it will occur if the ProfilerResolver is not initialized... generally only in + // unit tests. + } + } + public Stopwatch Stopwatch { get { return _stopwatch; } @@ -36,102 +66,122 @@ namespace Umbraco.Core /// /// The callback. /// + [Obsolete("Use the other overload instead to ensure that the output it sent to the current profiler")] public static DisposableTimer Start(Action callback) { return new DisposableTimer(callback); } - public static DisposableTimer TraceDuration(Func startMessage, Func completeMessage) - { - return TraceDuration(typeof(T), startMessage, completeMessage); - } + /// + /// Starts the timer and invokes the specified callback upon disposal. + /// + /// + /// + /// + public static DisposableTimer Start(string profileName, Action callback) + { + LogHelper.Info(profileName); + return new DisposableTimer(typeof(T), profileName, callback); + } - public static DisposableTimer TraceDuration(Type loggerType, Func startMessage, Func completeMessage) - { - LogHelper.Debug(loggerType, startMessage); - return new DisposableTimer(x => LogHelper.Info(loggerType, () => completeMessage() + " (took " + x + "ms)")); - } + #region TraceDuration + public static DisposableTimer TraceDuration(Func startMessage, Func completeMessage) + { + return TraceDuration(typeof(T), startMessage, completeMessage); + } - /// - /// Adds a start and end log entry as Info and tracks how long it takes until disposed. - /// - /// - /// - /// - /// - public static DisposableTimer TraceDuration(string startMessage, string completeMessage) - { - return TraceDuration(typeof(T), startMessage, completeMessage); - } + public static DisposableTimer TraceDuration(Type loggerType, Func startMessage, Func completeMessage) + { + var message = startMessage(); + LogHelper.Info(loggerType, message); + return new DisposableTimer(loggerType, message, x => LogHelper.Info(loggerType, () => completeMessage() + " (took " + x + "ms)")); + } - /// - /// Adds a start and end log entry as Info and tracks how long it takes until disposed. - /// - /// - /// - /// - /// - public static DisposableTimer TraceDuration(Type loggerType, string startMessage, string completeMessage) - { - LogHelper.Info(loggerType, () => startMessage); - return new DisposableTimer(x => LogHelper.Info(loggerType, () => completeMessage + " (took " + x + "ms)")); - } + /// + /// Adds a start and end log entry as Info and tracks how long it takes until disposed. + /// + /// + /// + /// + /// + public static DisposableTimer TraceDuration(string startMessage, string completeMessage) + { + return TraceDuration(typeof(T), startMessage, completeMessage); + } - /// - /// Adds a start and end log entry as Debug and tracks how long it takes until disposed. - /// - /// - /// - /// - /// - public static DisposableTimer DebugDuration(string startMessage, string completeMessage) - { - return DebugDuration(typeof(T), startMessage, completeMessage); - } + /// + /// Adds a start and end log entry as Info and tracks how long it takes until disposed. + /// + /// + /// + /// + /// + public static DisposableTimer TraceDuration(Type loggerType, string startMessage, string completeMessage) + { + LogHelper.Info(loggerType, () => startMessage); + return new DisposableTimer(loggerType, startMessage, x => LogHelper.Info(loggerType, () => completeMessage + " (took " + x + "ms)")); + } + #endregion - /// - /// Adds a start and end log entry as Debug and tracks how long it takes until disposed. - /// - /// - /// - /// - /// - public static DisposableTimer DebugDuration(Func startMessage, Func completeMessage) - { - return DebugDuration(typeof(T), startMessage, completeMessage); - } + #region DebugDuration + /// + /// Adds a start and end log entry as Debug and tracks how long it takes until disposed. + /// + /// + /// + /// + /// + public static DisposableTimer DebugDuration(string startMessage, string completeMessage) + { + return DebugDuration(typeof(T), startMessage, completeMessage); + } - /// - /// Adds a start and end log entry as Debug and tracks how long it takes until disposed. - /// - /// - /// - /// - /// - public static DisposableTimer DebugDuration(Type loggerType, string startMessage, string completeMessage) - { - LogHelper.Debug(loggerType, () => startMessage); - return new DisposableTimer(x => LogHelper.Debug(loggerType, () => completeMessage + " (took " + x + "ms)")); - } + /// + /// Adds a start and end log entry as Debug and tracks how long it takes until disposed. + /// + /// + /// + /// + /// + public static DisposableTimer DebugDuration(Func startMessage, Func completeMessage) + { + return DebugDuration(typeof(T), startMessage, completeMessage); + } - /// - /// Adds a start and end log entry as Debug and tracks how long it takes until disposed. - /// - /// - /// - /// - /// - public static DisposableTimer DebugDuration(Type loggerType, Func startMessage, Func completeMessage) - { - LogHelper.Debug(loggerType, startMessage); - return new DisposableTimer(x => LogHelper.Debug(loggerType, () => completeMessage() + " (took " + x + "ms)")); - } + /// + /// Adds a start and end log entry as Debug and tracks how long it takes until disposed. + /// + /// + /// + /// + /// + public static DisposableTimer DebugDuration(Type loggerType, string startMessage, string completeMessage) + { + LogHelper.Debug(loggerType, () => startMessage); + return new DisposableTimer(loggerType, startMessage, x => LogHelper.Debug(loggerType, () => completeMessage + " (took " + x + "ms)")); + } + + /// + /// Adds a start and end log entry as Debug and tracks how long it takes until disposed. + /// + /// + /// + /// + /// + public static DisposableTimer DebugDuration(Type loggerType, Func startMessage, Func completeMessage) + { + var msg = startMessage(); + LogHelper.Debug(loggerType, msg); + return new DisposableTimer(loggerType, msg, x => LogHelper.Debug(loggerType, () => completeMessage() + " (took " + x + "ms)")); + } + #endregion /// /// Handles the disposal of resources. Derived from abstract class which handles common required locking logic. /// protected override void DisposeResources() { + _profilerStep.DisposeIfDisposable(); _callback.Invoke(Stopwatch.ElapsedMilliseconds); } } diff --git a/src/Umbraco.Core/ObjectResolution/ManyObjectsResolverBase.cs b/src/Umbraco.Core/ObjectResolution/ManyObjectsResolverBase.cs index 4a5f7cbd99..4f3bc2665b 100644 --- a/src/Umbraco.Core/ObjectResolution/ManyObjectsResolverBase.cs +++ b/src/Umbraco.Core/ObjectResolution/ManyObjectsResolverBase.cs @@ -170,7 +170,7 @@ namespace Umbraco.Core.ObjectResolution get { // ensure we can - if (!CanResolveBeforeFrozen) + if (CanResolveBeforeFrozen == false) Resolution.EnsureIsFrozen(); // note: we apply .ToArray() to the output of CreateInstance() because that is an IEnumerable that diff --git a/src/Umbraco.Core/ObjectResolution/ResolverBase.cs b/src/Umbraco.Core/ObjectResolution/ResolverBase.cs index fd22a76610..d6bf59351d 100644 --- a/src/Umbraco.Core/ObjectResolution/ResolverBase.cs +++ b/src/Umbraco.Core/ObjectResolution/ResolverBase.cs @@ -13,7 +13,7 @@ namespace Umbraco.Core.ObjectResolution //add itself to the internal collection ResolverCollection.Add(this, resetAction); } - + } /// diff --git a/src/Umbraco.Core/ObjectResolution/SingleObjectResolverBase.cs b/src/Umbraco.Core/ObjectResolution/SingleObjectResolverBase.cs index 5d0e57c8f9..b4a54f66b6 100644 --- a/src/Umbraco.Core/ObjectResolution/SingleObjectResolverBase.cs +++ b/src/Umbraco.Core/ObjectResolution/SingleObjectResolverBase.cs @@ -69,6 +69,12 @@ namespace Umbraco.Core.ObjectResolution #endregion + /// + /// Gets or sets a value indicating whether the resolver can resolve objects before resolution is frozen. + /// + /// This is false by default and is used for some special internal resolvers. + internal bool CanResolveBeforeFrozen { get; set; } + /// /// Gets a value indicating whether the resolved object instance can be null. /// @@ -96,7 +102,10 @@ namespace Umbraco.Core.ObjectResolution { get { - Resolution.EnsureIsFrozen(); + // ensure we can + if (CanResolveBeforeFrozen == false) + Resolution.EnsureIsFrozen(); + using (new ReadLock(_lock)) { if (!_canBeNull && _value == null) diff --git a/src/Umbraco.Core/Profiling/IProfiler.cs b/src/Umbraco.Core/Profiling/IProfiler.cs index 720c71b555..4a3f7a8829 100644 --- a/src/Umbraco.Core/Profiling/IProfiler.cs +++ b/src/Umbraco.Core/Profiling/IProfiler.cs @@ -7,7 +7,6 @@ namespace Umbraco.Core.Profiling /// internal interface IProfiler { - /// /// Render the UI to display the profiler /// @@ -18,7 +17,7 @@ namespace Umbraco.Core.Profiling string Render(); /// - /// Profile a step + /// Profile an operation /// /// /// @@ -26,7 +25,7 @@ namespace Umbraco.Core.Profiling /// Use the 'using(' syntax /// IDisposable Step(string name); - + /// /// Start the profiler /// diff --git a/src/Umbraco.Core/Profiling/ProfilerExtensions.cs b/src/Umbraco.Core/Profiling/ProfilerExtensions.cs index 16b8ab3e96..d4bbeb6744 100644 --- a/src/Umbraco.Core/Profiling/ProfilerExtensions.cs +++ b/src/Umbraco.Core/Profiling/ProfilerExtensions.cs @@ -13,7 +13,23 @@ namespace Umbraco.Core.Profiling /// internal static IDisposable Step(this IProfiler profiler, string name) { - return profiler.Step(string.Format(typeof(T).Name + ", " + name)); + if (profiler == null) throw new ArgumentNullException("profiler"); + return profiler.Step(typeof (T), name); + } + + /// + /// Writes out a step prefixed with the type + /// + /// + /// + /// + /// + internal static IDisposable Step(this IProfiler profiler, Type objectType, string name) + { + if (profiler == null) throw new ArgumentNullException("profiler"); + if (objectType == null) throw new ArgumentNullException("objectType"); + if (name == null) throw new ArgumentNullException("name"); + return profiler.Step(string.Format("[{0}] {1}", objectType.Name, name)); } } } \ No newline at end of file diff --git a/src/Umbraco.Core/Profiling/ProfilerResolver.cs b/src/Umbraco.Core/Profiling/ProfilerResolver.cs index 82374a298d..e6b8bc7aab 100644 --- a/src/Umbraco.Core/Profiling/ProfilerResolver.cs +++ b/src/Umbraco.Core/Profiling/ProfilerResolver.cs @@ -33,5 +33,7 @@ namespace Umbraco.Core.Profiling { get { return Value; } } + + } } \ No newline at end of file diff --git a/src/Umbraco.Tests/TypeFinderTests.cs b/src/Umbraco.Tests/TypeFinderTests.cs index f246f9d951..c77620c11e 100644 --- a/src/Umbraco.Tests/TypeFinderTests.cs +++ b/src/Umbraco.Tests/TypeFinderTests.cs @@ -15,6 +15,7 @@ using NUnit.Framework; using SqlCE4Umbraco; using Umbraco.Core; using Umbraco.Core.IO; +using Umbraco.Core.Logging; using Umbraco.Tests; using Umbraco.Tests.TestHelpers; using Umbraco.Web.BaseRest; @@ -69,8 +70,7 @@ namespace Umbraco.Tests } - - [Test] + [Test] public void Find_Class_Of_Type_With_Attribute() { diff --git a/src/Umbraco.Web/WebBootManager.cs b/src/Umbraco.Web/WebBootManager.cs index e22554ced8..5f376a6e88 100644 --- a/src/Umbraco.Web/WebBootManager.cs +++ b/src/Umbraco.Web/WebBootManager.cs @@ -99,6 +99,17 @@ namespace Umbraco.Web UmbracoContext.EnsureContext(new HttpContextWrapper(UmbracoApplication.Context), ApplicationContext); } + /// + /// Ensure the current profiler is the web profiler + /// + protected override void InitializeProfilerResolver() + { + base.InitializeProfilerResolver(); + + //Set the profiler to be the web profiler + ProfilerResolver.Current.SetProfiler(new WebProfiler()); + } + /// /// Adds custom types to the ApplicationEventsResolver /// @@ -240,9 +251,6 @@ namespace Umbraco.Web { base.InitializeResolvers(); - //Set the profiler to be the web profiler - ProfilerResolver.Current.SetProfiler(new WebProfiler()); - //set the default RenderMvcController DefaultRenderMvcControllerResolver.Current = new DefaultRenderMvcControllerResolver(typeof(RenderMvcController));