diff --git a/src/MiniProfiler.Providers.SqlServer/SqlServerStorage.cs b/src/MiniProfiler.Providers.SqlServer/SqlServerStorage.cs index c0a289db4..4be3d912d 100644 --- a/src/MiniProfiler.Providers.SqlServer/SqlServerStorage.cs +++ b/src/MiniProfiler.Providers.SqlServer/SqlServerStorage.cs @@ -85,15 +85,17 @@ public override void Save(MiniProfiler profiler) } SaveTimings(timings, conn); - if (profiler.ClientTimings != null && profiler.ClientTimings.Timings != null && profiler.ClientTimings.Timings.Any()) + + var clientTimings = profiler.ClientTimings?.Timings; + if (clientTimings != null && clientTimings.Any()) { // set the profilerId (isn't needed unless we are storing it) - profiler.ClientTimings.Timings.ForEach(x => + foreach(var x in clientTimings) { x.MiniProfilerId = profiler.Id; x.Id = Guid.NewGuid(); - }); - SaveClientTimings(profiler.ClientTimings.Timings, conn); + } + SaveClientTimings(clientTimings, conn); } } } @@ -139,7 +141,7 @@ INSERT INTO MiniProfilerTimings } } - private void SaveClientTimings(List timings, DbConnection conn) + private void SaveClientTimings(IReadOnlyList timings, DbConnection conn) { const string sql = @" INSERT INTO MiniProfilerClientTimings diff --git a/src/MiniProfiler.Providers.SqlServerCe/SqlServerCeStorage.cs b/src/MiniProfiler.Providers.SqlServerCe/SqlServerCeStorage.cs index c6d81d51f..18d9fb6e0 100644 --- a/src/MiniProfiler.Providers.SqlServerCe/SqlServerCeStorage.cs +++ b/src/MiniProfiler.Providers.SqlServerCe/SqlServerCeStorage.cs @@ -86,15 +86,16 @@ public override void Save(MiniProfiler profiler) } SaveTimings(timings, conn); - if (profiler.ClientTimings != null && profiler.ClientTimings.Timings != null && profiler.ClientTimings.Timings.Any()) + var clientTimings = profiler.ClientTimings?.Timings; + if (clientTimings != null && clientTimings.Any()) { // set the profilerId (isn't needed unless we are storing it) - profiler.ClientTimings.Timings.ForEach(x => + foreach (var x in clientTimings) { x.MiniProfilerId = profiler.Id; x.Id = Guid.NewGuid(); - }); - SaveClientTimings(profiler.ClientTimings.Timings, conn); + } + SaveClientTimings(clientTimings, conn); } } } @@ -140,7 +141,7 @@ INSERT INTO MiniProfilerTimings } } - private void SaveClientTimings(List timings, DbConnection conn) + private void SaveClientTimings(IReadOnlyList timings, DbConnection conn) { const string sql = @" INSERT INTO MiniProfilerClientTimings diff --git a/src/MiniProfiler.Shared/ClientTimings.cs b/src/MiniProfiler.Shared/ClientTimings.cs index c9a9ebc34..9c378be5d 100644 --- a/src/MiniProfiler.Shared/ClientTimings.cs +++ b/src/MiniProfiler.Shared/ClientTimings.cs @@ -14,12 +14,26 @@ public class ClientTimings { private const string TimingPrefix = "clientPerformance[timing]["; private const string ProbesPrefix = "clientProbes["; + private readonly object _lockObject = new object(); + private List _timings; /// /// Gets or sets the list of client side timings /// [DataMember(Order = 2)] - public List Timings { get; set; } + public List Timings + { + get + { + lock(_lockObject) + return _timings == null ? null : new List(_timings); + } + set + { + lock (_lockObject) + _timings = value == null ? null : new List(value); + } + } /// /// Gets or sets the redirect count. diff --git a/src/MiniProfiler.Shared/Helpers/Net45/AsyncLocal.cs b/src/MiniProfiler.Shared/Helpers/Net45/AsyncLocal.cs new file mode 100644 index 000000000..91298ba54 --- /dev/null +++ b/src/MiniProfiler.Shared/Helpers/Net45/AsyncLocal.cs @@ -0,0 +1,78 @@ +#if NET45 +using System; +using System.Collections.Generic; +using System.Linq; +using System.Runtime.CompilerServices; +using System.Runtime.Remoting.Messaging; +using System.Runtime.Serialization; + +namespace StackExchange.Profiling.Helpers.Net45 +{ + /// + /// Implements interface similar to AsyncLocal which is not available until .Net 4.6. + /// + /// The implementation is inspired by Ambient Context Logic from here: + /// https://github.com/mehdime/DbContextScope/blob/master/Mehdime.Entity/Implementations/DbContextScope.cs + /// Unlike DbContextScope's implementation this implementation doesn't support serialization/deserialization + /// ths not allowing to cross app domain barrier. + /// + internal class AsyncLocal + where T : class + { + public AsyncLocal() + { + } + + public AsyncLocal( + T obj + ) + { + Value = obj; + } + + /// + /// Gets or Sets the value. + /// + public T Value + { + get + { + return (CallContext.LogicalGetData(_id) as ObjectRef)?.Ref; + } + + set + { + CallContext.LogicalSetData(_id, new ObjectRef { Ref = value }); + } + } + + /// + /// Identifies this instance of in CallContext. + /// + private readonly string _id = Guid.NewGuid().ToString(); + + [Serializable] + private class ObjectRef : MarshalByRefObject, ISerializable + { + // The special constructor is used to deserialize values. + public ObjectRef() + { + } + + // The special constructor is used to deserialize values. + public ObjectRef( + SerializationInfo info, + StreamingContext context + ) + { + } + + public void GetObjectData(SerializationInfo info, StreamingContext context) + { + } + + public T Ref { get; set; } + } + } +} +#endif diff --git a/src/MiniProfiler.Shared/MiniProfiler.Shared.csproj b/src/MiniProfiler.Shared/MiniProfiler.Shared.csproj index 682deb012..e1faca5d4 100644 --- a/src/MiniProfiler.Shared/MiniProfiler.Shared.csproj +++ b/src/MiniProfiler.Shared/MiniProfiler.Shared.csproj @@ -1,4 +1,4 @@ - + net45;netstandard1.5 MiniProfiler.Shared @@ -22,6 +22,7 @@ + diff --git a/src/MiniProfiler.Shared/MiniProfiler.cs b/src/MiniProfiler.Shared/MiniProfiler.cs index d817cdb11..1a30927b7 100644 --- a/src/MiniProfiler.Shared/MiniProfiler.cs +++ b/src/MiniProfiler.Shared/MiniProfiler.cs @@ -135,10 +135,9 @@ public Timing Root { var timing = timings.Pop(); - if (timing.HasChildren) + var children = timing.Children; + if (children?.Count > 0) { - var children = timing.Children; - for (int i = children.Count - 1; i >= 0; i--) { children[i].ParentTiming = timing; @@ -189,7 +188,19 @@ public Timing Root /// /// Gets or sets points to the currently executing Timing. /// - public Timing Head { get; set; } + public Timing Head + { + get + { + Settings.EnsureProfilerProvider(); + return Settings.ProfilerProvider.CurrentHead; + } + set + { + Settings.EnsureProfilerProvider(); + Settings.ProfilerProvider.CurrentHead = value; + } + } /// /// Gets the ticks since this MiniProfiler was started. @@ -329,9 +340,9 @@ public IEnumerable GetTimingHierarchy() yield return timing; - if (timing.HasChildren) + var children = timing.Children; + if (children?.Count > 0) { - var children = timing.Children; for (int i = children.Count - 1; i >= 0; i--) timings.Push(children[i]); } } diff --git a/src/MiniProfiler.Shared/ProfileProviders/BaseProfilerProvider.cs b/src/MiniProfiler.Shared/ProfileProviders/BaseProfilerProvider.cs index e429cff90..e6a9cb555 100644 --- a/src/MiniProfiler.Shared/ProfileProviders/BaseProfilerProvider.cs +++ b/src/MiniProfiler.Shared/ProfileProviders/BaseProfilerProvider.cs @@ -28,6 +28,11 @@ public abstract class BaseProfilerProvider : IProfilerProvider /// public abstract MiniProfiler GetCurrentProfiler(); + /// + /// GEts or sets the current head timing. This is used by . + /// + public abstract Timing CurrentHead { get; set; } + /// /// Sets to be active (read to start profiling) /// This should be called once a new MiniProfiler has been created. diff --git a/src/MiniProfiler.Shared/ProfileProviders/DefaultProfilerProvider.cs b/src/MiniProfiler.Shared/ProfileProviders/DefaultProfilerProvider.cs index ec9663dea..b58aac928 100644 --- a/src/MiniProfiler.Shared/ProfileProviders/DefaultProfilerProvider.cs +++ b/src/MiniProfiler.Shared/ProfileProviders/DefaultProfilerProvider.cs @@ -1,7 +1,8 @@ #if NET45 using System; using System.Runtime.Remoting.Messaging; -using System.Web; +using System.Web; +using StackExchange.Profiling.Helpers.Net45; #else using System.Threading; #endif @@ -13,43 +14,23 @@ namespace StackExchange.Profiling /// public class DefaultProfilerProvider : BaseProfilerProvider { -#if NET45 - const string ContextKey = ":miniprofiler:"; + private readonly AsyncLocal _profiler = new AsyncLocal(); + private readonly AsyncLocal _currentTiming = new AsyncLocal(); private MiniProfiler Profiler { - get - { - if (HttpContext.Current != null) - { - return HttpContext.Current?.Items[ContextKey] as MiniProfiler; - } - else - { - return CallContext.LogicalGetData(ContextKey) as MiniProfiler; - } - } - set - { - if (HttpContext.Current != null) - { - HttpContext.Current.Items[ContextKey] = value; - } - else - { - CallContext.LogicalSetData(ContextKey, value); - } - } + get { return _profiler.Value; } + set { _profiler.Value = value; } } -#else - private AsyncLocal _profiler = new AsyncLocal(); - private MiniProfiler Profiler + /// + /// Current head timing. + /// + public override Timing CurrentHead { - get { return _profiler.Value; } - set { _profiler.Value = value; } + get { return _currentTiming.Value; } + set { _currentTiming.Value = value; } } -#endif /// /// The name says it all. diff --git a/src/MiniProfiler.Shared/ProfileProviders/IProfilerProvider.cs b/src/MiniProfiler.Shared/ProfileProviders/IProfilerProvider.cs index 5100efa75..91d477ced 100644 --- a/src/MiniProfiler.Shared/ProfileProviders/IProfilerProvider.cs +++ b/src/MiniProfiler.Shared/ProfileProviders/IProfilerProvider.cs @@ -30,5 +30,10 @@ public interface IProfilerProvider /// Returns the current MiniProfiler. This is used by . /// MiniProfiler GetCurrentProfiler(); + + /// + /// Current head . Used by + /// + Timing CurrentHead { get; set; } } } diff --git a/src/MiniProfiler.Shared/ProfileProviders/SingletonProfilerProvider.cs b/src/MiniProfiler.Shared/ProfileProviders/SingletonProfilerProvider.cs index 7ac30b2ed..bede37e6d 100644 --- a/src/MiniProfiler.Shared/ProfileProviders/SingletonProfilerProvider.cs +++ b/src/MiniProfiler.Shared/ProfileProviders/SingletonProfilerProvider.cs @@ -9,12 +9,22 @@ namespace StackExchange.Profiling public class SingletonProfilerProvider : IProfilerProvider { private MiniProfiler _profiler; + private Timing _timing; /// /// The name says it all /// public MiniProfiler GetCurrentProfiler() => _profiler; + /// + /// Current head timing. + /// + public Timing CurrentHead + { + get { return _timing; } + set { _timing = value; } + } + /// /// Starts a new profiling session. /// diff --git a/src/MiniProfiler.Shared/Storage/DatabaseStorageBase.cs b/src/MiniProfiler.Shared/Storage/DatabaseStorageBase.cs index 44e85eeda..a9eba7714 100644 --- a/src/MiniProfiler.Shared/Storage/DatabaseStorageBase.cs +++ b/src/MiniProfiler.Shared/Storage/DatabaseStorageBase.cs @@ -132,9 +132,13 @@ private void PopulateChildTimings(Timing parent, ILookup timingsLo protected void FlattenTimings(Timing timing, List timingsCollection) { timingsCollection.Add(timing); - if (timing.HasChildren) + var children = timing.Children; + if (children?.Count > 0) { - timing.Children.ForEach(x => FlattenTimings(x, timingsCollection)); + foreach (var child in children) + { + FlattenTimings(child, timingsCollection); + } } } } diff --git a/src/MiniProfiler.Shared/Timing.cs b/src/MiniProfiler.Shared/Timing.cs index e3aa9839f..4eb634c0e 100644 --- a/src/MiniProfiler.Shared/Timing.cs +++ b/src/MiniProfiler.Shared/Timing.cs @@ -3,6 +3,7 @@ using System.Linq; using System.Runtime.Serialization; using StackExchange.Profiling.Helpers; +using System.Collections.Immutable; #if NET45 using System.Web.Script.Serialization; #endif @@ -77,28 +78,76 @@ public Timing(MiniProfiler profiler, Timing parent, string name, decimal? minSav /// Gets or sets All sub-steps that occur within this Timing step. Add new children through /// [DataMember(Order = 5)] - public List Children { get; set; } + public List Children + { + get + { + lock(_lockObject) + { + return _children == null ? null : new List(_children); + } + } + set + { + lock(_lockObject) + { + _children = value == null ? null : new List(value); + } + } + } /// /// lists keyed by their type, e.g. "sql", "memcache", "redis", "http". /// [DataMember(Order = 6)] - public Dictionary> CustomTimings { get; set; } + public Dictionary> CustomTimings + { + get + { + lock(_lockObject) + { + return _customTimings?.ToDictionary(p => p.Key, p => new List(p.Value)); + } + } + set + { + lock(_lockObject) + { + _customTimings = value?.ToDictionary(p => p.Key, p => new List(p.Value)); + } + } + } /// /// JSON representing the Custom Timings associated with this timing. /// public string CustomTimingsJson { - get { return CustomTimings?.ToJson(); } - set { CustomTimings = value.FromJson>>(); } + get + { + lock (_lockObject) + { + return _customTimings?.ToJson(); + } + } + set + { + lock (_lockObject) + { + _customTimings = value.FromJson>>(); + } + } } - + /// /// Returns true when there exists any objects in this . /// public bool HasCustomTimings { - get { return CustomTimings != null && CustomTimings.Any(pair => pair.Value != null && pair.Value.Any()); } + get + { + lock(_lockObject) + return _customTimings != null && _customTimings.Any(pair => pair.Value != null && pair.Value.Any()); + } } /// @@ -132,9 +181,12 @@ public decimal DurationWithoutChildrenMilliseconds if (HasChildren) { - foreach (var child in Children) + lock (_lockObject) { - result -= child.DurationMilliseconds.GetValueOrDefault(); + foreach (var child in _children) + { + result -= child.DurationMilliseconds.GetValueOrDefault(); + } } } @@ -157,7 +209,16 @@ public decimal DurationWithoutChildrenMilliseconds #if NET45 [ScriptIgnore] #endif - public bool HasChildren => Children?.Count > 0; + public bool HasChildren + { + get + { + lock (_lockObject) + { + return _children?.Count > 0; + } + } + } /// /// Gets a value indicating whether this Timing is the first one created in a MiniProfiler session. @@ -253,19 +314,26 @@ public void Stop() /// public void AddChild(Timing timing) { - if (Children == null) - Children = new List(); - - Children.Add(timing); - if(timing.Profiler == null) - timing.Profiler = Profiler; - timing.ParentTiming = this; - timing.ParentTimingId = Id; - if (Profiler != null) - timing.MiniProfilerId = Profiler.Id; + lock (_lockObject) + { + if (_children == null) + _children = new List(); + + _children.Add(timing); + if (timing.Profiler == null) + timing.Profiler = Profiler; + timing.ParentTiming = this; + timing.ParentTimingId = Id; + if (Profiler != null) + timing.MiniProfilerId = Profiler.Id; + } } - internal void RemoveChild(Timing timing) => Children?.Remove(timing); + internal void RemoveChild(Timing timing) + { + lock (_lockObject) + _children?.Remove(timing); + } /// /// Adds to this step's dictionary of @@ -281,10 +349,15 @@ public void AddCustomTiming(string category, CustomTiming customTiming) internal void RemoveCustomTiming(string category, CustomTiming customTiming) { - GetCustomTimingList(category).Remove(customTiming); + lock (_lockObject) + { + GetCustomTimingList(category).Remove(customTiming); + } } private readonly object _lockObject = new object(); + private List _children; + private Dictionary> _customTimings; /// /// Returns the list keyed to the , creating any collections when null. @@ -292,20 +365,15 @@ internal void RemoveCustomTiming(string category, CustomTiming customTiming) /// The kind of custom timings, e.g. "sql", "redis", "memcache" private List GetCustomTimingList(string category) { - lock (_lockObject) - { - if (CustomTimings == null) - CustomTimings = new Dictionary>(); - } + // is invoked with _lockObject acquired + if (_customTimings == null) + _customTimings = new Dictionary>(); List result; - lock (CustomTimings) + if (!_customTimings.TryGetValue(category, out result)) { - if (!CustomTimings.TryGetValue(category, out result)) - { - result = new List(); - CustomTimings[category] = result; - } + result = new List(); + _customTimings[category] = result; } return result; } diff --git a/src/MiniProfiler/MiniProfilerWebExtensions.cs b/src/MiniProfiler/MiniProfilerWebExtensions.cs index 58c3812fb..f9141b63e 100644 --- a/src/MiniProfiler/MiniProfilerWebExtensions.cs +++ b/src/MiniProfiler/MiniProfilerWebExtensions.cs @@ -76,9 +76,10 @@ private static string RenderImpl(MiniProfiler profiler, bool htmlEncode) text.AppendFormat("{2} {0} = {1:###,##0.##}ms", name, timing.DurationMilliseconds, new string('>', timing.Depth)); - if (timing.HasCustomTimings) + var customTimingsMap = timing.CustomTimings; + if (customTimingsMap?.Count > 0) { - foreach (var pair in timing.CustomTimings) + foreach (var pair in customTimingsMap) { var type = pair.Key; var customTimings = pair.Value; @@ -92,10 +93,10 @@ private static string RenderImpl(MiniProfiler profiler, bool htmlEncode) } text.AppendLine(); - - if (timing.HasChildren) + + var children = timing.Children; + if (children?.Count > 0) { - var children = timing.Children; for (var i = children.Count - 1; i >= 0; i--) timings.Push(children[i]); } } diff --git a/src/MiniProfiler/ProfileProviders/WebRequestProfilerProvider.cs b/src/MiniProfiler/ProfileProviders/WebRequestProfilerProvider.cs index 143595877..0f3ffbdc1 100644 --- a/src/MiniProfiler/ProfileProviders/WebRequestProfilerProvider.cs +++ b/src/MiniProfiler/ProfileProviders/WebRequestProfilerProvider.cs @@ -150,7 +150,23 @@ private static void EnsureName(MiniProfiler profiler, HttpRequest request) /// public override MiniProfiler GetCurrentProfiler() => Current; + /// + /// Current head timing. + /// + public override Timing CurrentHead + { + get { return HttpContext.Current?.Items[CacheKeyHead] as Timing; } + set + { + var context = HttpContext.Current; + if (context == null) return; + + context.Items[CacheKeyHead] = value; + } + } + private const string CacheKey = ":mini-profiler:"; + private const string CacheKeyHead = ":mini-profiler-head:"; /// /// Gets the currently running MiniProfiler for the current HttpContext; null if no MiniProfiler was ed. diff --git a/tests/MiniProfiler.Tests/App.config b/tests/MiniProfiler.Tests/App.config index fb7108c1f..be5823d26 100644 --- a/tests/MiniProfiler.Tests/App.config +++ b/tests/MiniProfiler.Tests/App.config @@ -34,4 +34,7 @@ + + + \ No newline at end of file diff --git a/tests/MiniProfiler.Tests/BaseTest.cs b/tests/MiniProfiler.Tests/BaseTest.cs index f068996ed..8c86733b0 100644 --- a/tests/MiniProfiler.Tests/BaseTest.cs +++ b/tests/MiniProfiler.Tests/BaseTest.cs @@ -173,7 +173,7 @@ protected void AssertPublicPropertiesAreEqual(T t1, T t2) // we'll handle any collections elsewhere var props = from p in typeof(T).GetProperties(BindingFlags.Public | BindingFlags.Instance) where p.IsDefined(typeof(System.Runtime.Serialization.DataMemberAttribute), false) - && !p.PropertyType.GetInterfaces().Any(i => i.Equals(typeof(IDictionary)) || i.Equals(typeof(IList))) + && !p.PropertyType.GetInterfaces().Any(i => i.Equals(typeof(IEnumerable))) select p; foreach (var p in props) diff --git a/tests/MiniProfiler.Tests/MiniProfilerTest.cs b/tests/MiniProfiler.Tests/MiniProfilerTest.cs index adf57841d..75c07cca2 100644 --- a/tests/MiniProfiler.Tests/MiniProfilerTest.cs +++ b/tests/MiniProfiler.Tests/MiniProfilerTest.cs @@ -1,4 +1,7 @@ using System; +using System.Linq; +using System.Threading; +using System.Threading.Tasks; using Xunit; namespace StackExchange.Profiling.Tests @@ -32,6 +35,102 @@ public void Simple() } } + [Fact] + public void WhenUsingAsyncProvider_SimpleCaseWorking() + { + MiniProfiler.Settings.ProfilerProvider = new DefaultProfilerProvider(); + using (GetRequest()) + { + MiniProfiler.Start(); + IncrementStopwatch(); // 1 ms + MiniProfiler.Stop(); + + var c = MiniProfiler.Current; + + Assert.NotNull(c); + Assert.Equal(StepTimeMilliseconds, c.DurationMilliseconds); + + Assert.NotNull(c.Root); + Assert.False(c.Root.HasChildren); + } + } + + [Theory] + [InlineData(true)] + [InlineData(false)] + public async Task Current_WhenAsyncMethodReturns_IsCarried( + bool configureAwait + ) + { + MiniProfiler.Settings.ProfilerProvider = new DefaultProfilerProvider(); + using (GetRequest()) + { + MiniProfiler.Start(); + + var c = MiniProfiler.Current; + await Task.Delay(TimeSpan.FromMilliseconds(1)).ConfigureAwait(configureAwait); + + Assert.NotNull(MiniProfiler.Current); + Assert.Equal(c, MiniProfiler.Current); + } + } + + [Theory] + [InlineData(true)] + [InlineData(false)] + public async Task Head_WhenAsyncMethodReturns_IsCarried( + bool configureAwait + ) + { + MiniProfiler.Settings.ProfilerProvider = new DefaultProfilerProvider(); + using (GetRequest()) + { + MiniProfiler.Start(); + var sut = MiniProfiler.Current; + var head = sut.Head; + + await Task.Delay(TimeSpan.FromMilliseconds(1)).ConfigureAwait(configureAwait); + + Assert.NotNull(sut.Head); + Assert.Equal(head, sut.Head); + } + } + + [Fact] + public void Head_WhenMultipleTasksSpawned_EachSetsItsOwnHead() + { + MiniProfiler.Settings.ProfilerProvider = new DefaultProfilerProvider(); + var allTasks = new SemaphoreSlim(0, 1); + var completed = new TaskCompletionSource(); + using (GetRequest("http://localhost/Test.aspx", startAndStopProfiler: false)) + { + MiniProfiler.Start(); + var sut = MiniProfiler.Current; + var head = sut.Head; + + Task.Run(() => { + Assert.Equal(head, sut.Head); + using (sut.Step("test1")) + { + allTasks.Release(); + completed.Task.Wait(); + } + }); + allTasks.Wait(); + Task.Run(() => { + using (sut.Step("test2")) + { + allTasks.Release(); + completed.Task.Wait(); + } + }); + allTasks.Wait(); + + Assert.NotNull(sut.Head); + Assert.Equal(head, sut.Head); + completed.SetResult(0); + } + } [Fact] public void StepIf_Basic() { diff --git a/tests/MiniProfiler.Tests/Storage/SqlServerStorageTest.cs b/tests/MiniProfiler.Tests/Storage/SqlServerStorageTest.cs index 364de31b4..4531ce825 100644 --- a/tests/MiniProfiler.Tests/Storage/SqlServerStorageTest.cs +++ b/tests/MiniProfiler.Tests/Storage/SqlServerStorageTest.cs @@ -16,6 +16,7 @@ public class SqlServerStorageTest : BaseTest, IClassFixture fixture) { + MiniProfiler.Settings.ProfilerProvider = new WebRequestProfilerProvider(); _conn = fixture.Conn; }