yv01p/Umbraco-CMS
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Upgraded DisposableTimer to wrap the profiler... now we should really just use DisposableTimer for all profiling.

Browse Source
This commit is contained in:
Shannon Deminick
2013-05-13 21:11:03 -10:00
parent b6f52bf782
commit 5890fe1849
10 changed files with 196 additions and 99 deletions
Download Patch File Download Diff File Expand all files Collapse all files

23
src/Umbraco.Core/CoreBootManager.cs
View File

@@ -53,8 +53,9 @@ namespace Umbraco.Core
if (_isInitialized)
throw new InvalidOperationException("The boot manager has already been initialized");
LogHelper.Info<CoreBootManager>("Umbraco application starting");
_timer = DisposableTimer.Start(x => LogHelper.Info<CoreBootManager>("Umbraco application startup complete" + " (took " + x + "ms)"));
InitializeProfilerResolver();
_timer = DisposableTimer.Start<CoreBootManager>("Umbraco application starting", x => LogHelper.Info<CoreBootManager>("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);
}
/// <summary>
/// Special method to initialize the ProfilerResolver
/// </summary>
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
};
}
/// <summary>
/// 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
/// </summary>
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(

214
src/Umbraco.Core/DisposableTimer.cs
View File

@@ -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
/// </summary>
/// <example>
/// <code>
///
/// 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);
/// }
/// </code>
/// </example>
public class DisposableTimer : DisposableObject
{
private readonly Stopwatch _stopwatch = Stopwatch.StartNew();
private readonly Action<long> _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<long> callback)
{
_callback = callback;
}
/// <summary>
/// Constructor which activates a step in the profiler
/// </summary>
/// <param name="loggerType"></param>
/// <param name="profileName"></param>
/// <param name="callback"></param>
protected DisposableTimer(Type loggerType, string profileName, Action<long> 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
/// </summary>
/// <param name="callback">The callback.</param>
/// <returns></returns>
[Obsolete("Use the other overload instead to ensure that the output it sent to the current profiler")]
public static DisposableTimer Start(Action<long> callback)
{
return new DisposableTimer(callback);
}
public static DisposableTimer TraceDuration<T>(Func<string> startMessage, Func<string> completeMessage)
{
return TraceDuration(typeof(T), startMessage, completeMessage);
}
/// <summary>
/// Starts the timer and invokes the specified callback upon disposal.
/// </summary>
/// <param name="profileName"></param>
/// <param name="callback"></param>
/// <returns></returns>
public static DisposableTimer Start<T>(string profileName, Action<long> callback)
{
LogHelper.Info<T>(profileName);
return new DisposableTimer(typeof(T), profileName, callback);
}
public static DisposableTimer TraceDuration(Type loggerType, Func<string> startMessage, Func<string> completeMessage)
{
LogHelper.Debug(loggerType, startMessage);
return new DisposableTimer(x => LogHelper.Info(loggerType, () => completeMessage() + " (took " + x + "ms)"));
}
#region TraceDuration
public static DisposableTimer TraceDuration<T>(Func<string> startMessage, Func<string> completeMessage)
{
return TraceDuration(typeof(T), startMessage, completeMessage);
}
/// <summary>
/// Adds a start and end log entry as Info and tracks how long it takes until disposed.
/// </summary>
/// <typeparam name="T"></typeparam>
/// <param name="startMessage"></param>
/// <param name="completeMessage"></param>
/// <returns></returns>
public static DisposableTimer TraceDuration<T>(string startMessage, string completeMessage)
{
return TraceDuration(typeof(T), startMessage, completeMessage);
}
public static DisposableTimer TraceDuration(Type loggerType, Func<string> startMessage, Func<string> completeMessage)
{
var message = startMessage();
LogHelper.Info(loggerType, message);
return new DisposableTimer(loggerType, message, x => LogHelper.Info(loggerType, () => completeMessage() + " (took " + x + "ms)"));
}
/// <summary>
/// Adds a start and end log entry as Info and tracks how long it takes until disposed.
/// </summary>
/// <param name="loggerType"></param>
/// <param name="startMessage"></param>
/// <param name="completeMessage"></param>
/// <returns></returns>
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)"));
}
/// <summary>
/// Adds a start and end log entry as Info and tracks how long it takes until disposed.
/// </summary>
/// <typeparam name="T"></typeparam>
/// <param name="startMessage"></param>
/// <param name="completeMessage"></param>
/// <returns></returns>
public static DisposableTimer TraceDuration<T>(string startMessage, string completeMessage)
{
return TraceDuration(typeof(T), startMessage, completeMessage);
}
/// <summary>
/// Adds a start and end log entry as Debug and tracks how long it takes until disposed.
/// </summary>
/// <typeparam name="T"></typeparam>
/// <param name="startMessage"></param>
/// <param name="completeMessage"></param>
/// <returns></returns>
public static DisposableTimer DebugDuration<T>(string startMessage, string completeMessage)
{
return DebugDuration(typeof(T), startMessage, completeMessage);
}
/// <summary>
/// Adds a start and end log entry as Info and tracks how long it takes until disposed.
/// </summary>
/// <param name="loggerType"></param>
/// <param name="startMessage"></param>
/// <param name="completeMessage"></param>
/// <returns></returns>
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
/// <summary>
/// Adds a start and end log entry as Debug and tracks how long it takes until disposed.
/// </summary>
/// <typeparam name="T"></typeparam>
/// <param name="startMessage"></param>
/// <param name="completeMessage"></param>
/// <returns></returns>
public static DisposableTimer DebugDuration<T>(Func<string> startMessage, Func<string> completeMessage)
{
return DebugDuration(typeof(T), startMessage, completeMessage);
}
#region DebugDuration
/// <summary>
/// Adds a start and end log entry as Debug and tracks how long it takes until disposed.
/// </summary>
/// <typeparam name="T"></typeparam>
/// <param name="startMessage"></param>
/// <param name="completeMessage"></param>
/// <returns></returns>
public static DisposableTimer DebugDuration<T>(string startMessage, string completeMessage)
{
return DebugDuration(typeof(T), startMessage, completeMessage);
}
/// <summary>
/// Adds a start and end log entry as Debug and tracks how long it takes until disposed.
/// </summary>
/// <param name="loggerType"></param>
/// <param name="startMessage"></param>
/// <param name="completeMessage"></param>
/// <returns></returns>
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)"));
}
/// <summary>
/// Adds a start and end log entry as Debug and tracks how long it takes until disposed.
/// </summary>
/// <typeparam name="T"></typeparam>
/// <param name="startMessage"></param>
/// <param name="completeMessage"></param>
/// <returns></returns>
public static DisposableTimer DebugDuration<T>(Func<string> startMessage, Func<string> completeMessage)
{
return DebugDuration(typeof(T), startMessage, completeMessage);
}
/// <summary>
/// Adds a start and end log entry as Debug and tracks how long it takes until disposed.
/// </summary>
/// <param name="loggerType"></param>
/// <param name="startMessage"></param>
/// <param name="completeMessage"></param>
/// <returns></returns>
public static DisposableTimer DebugDuration(Type loggerType, Func<string> startMessage, Func<string> completeMessage)
{
LogHelper.Debug(loggerType, startMessage);
return new DisposableTimer(x => LogHelper.Debug(loggerType, () => completeMessage() + " (took " + x + "ms)"));
}
/// <summary>
/// Adds a start and end log entry as Debug and tracks how long it takes until disposed.
/// </summary>
/// <param name="loggerType"></param>
/// <param name="startMessage"></param>
/// <param name="completeMessage"></param>
/// <returns></returns>
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)"));
}
/// <summary>
/// Adds a start and end log entry as Debug and tracks how long it takes until disposed.
/// </summary>
/// <param name="loggerType"></param>
/// <param name="startMessage"></param>
/// <param name="completeMessage"></param>
/// <returns></returns>
public static DisposableTimer DebugDuration(Type loggerType, Func<string> startMessage, Func<string> completeMessage)
{
var msg = startMessage();
LogHelper.Debug(loggerType, msg);
return new DisposableTimer(loggerType, msg, x => LogHelper.Debug(loggerType, () => completeMessage() + " (took " + x + "ms)"));
}
#endregion
/// <summary>
/// Handles the disposal of resources. Derived from abstract class <see cref="DisposableObject"/> which handles common required locking logic.
/// </summary>
protected override void DisposeResources()
{
_profilerStep.DisposeIfDisposable();
_callback.Invoke(Stopwatch.ElapsedMilliseconds);
}
}

2
src/Umbraco.Core/ObjectResolution/ManyObjectsResolverBase.cs
View File

@@ -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

2
src/Umbraco.Core/ObjectResolution/ResolverBase.cs
View File

@@ -13,7 +13,7 @@ namespace Umbraco.Core.ObjectResolution
//add itself to the internal collection
ResolverCollection.Add(this, resetAction);
}
}
/// <summary>

11
src/Umbraco.Core/ObjectResolution/SingleObjectResolverBase.cs
View File

@@ -69,6 +69,12 @@ namespace Umbraco.Core.ObjectResolution
#endregion
/// <summary>
/// Gets or sets a value indicating whether the resolver can resolve objects before resolution is frozen.
/// </summary>
/// <remarks>This is false by default and is used for some special internal resolvers.</remarks>
internal bool CanResolveBeforeFrozen { get; set; }
/// <summary>
/// Gets a value indicating whether the resolved object instance can be null.
/// </summary>
@@ -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)

5
src/Umbraco.Core/Profiling/IProfiler.cs
View File

@@ -7,7 +7,6 @@ namespace Umbraco.Core.Profiling
/// </summary>
internal interface IProfiler
{
/// <summary>
/// Render the UI to display the profiler
/// </summary>
@@ -18,7 +17,7 @@ namespace Umbraco.Core.Profiling
string Render();
/// <summary>
/// Profile a step
/// Profile an operation
/// </summary>
/// <param name="name"></param>
/// <returns></returns>
@@ -26,7 +25,7 @@ namespace Umbraco.Core.Profiling
/// Use the 'using(' syntax
/// </remarks>
IDisposable Step(string name);
/// <summary>
/// Start the profiler
/// </summary>

18
src/Umbraco.Core/Profiling/ProfilerExtensions.cs
View File

@@ -13,7 +13,23 @@ namespace Umbraco.Core.Profiling
/// <returns></returns>
internal static IDisposable Step<T>(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);
}
/// <summary>
/// Writes out a step prefixed with the type
/// </summary>
/// <param name="profiler"></param>
/// <param name="objectType"></param>
/// <param name="name"></param>
/// <returns></returns>
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));
}
}
}

2
src/Umbraco.Core/Profiling/ProfilerResolver.cs
View File

@@ -33,5 +33,7 @@ namespace Umbraco.Core.Profiling
{
get { return Value; }
}
}
}

4
src/Umbraco.Tests/TypeFinderTests.cs
View File

@@ -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()
{

14
src/Umbraco.Web/WebBootManager.cs
View File

@@ -99,6 +99,17 @@ namespace Umbraco.Web
UmbracoContext.EnsureContext(new HttpContextWrapper(UmbracoApplication.Context), ApplicationContext);
}
/// <summary>
/// Ensure the current profiler is the web profiler
/// </summary>
protected override void InitializeProfilerResolver()
{
base.InitializeProfilerResolver();
//Set the profiler to be the web profiler
ProfilerResolver.Current.SetProfiler(new WebProfiler());
}
/// <summary>
/// Adds custom types to the ApplicationEventsResolver
/// </summary>
@@ -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));