Skip to content

concurrency problem #1 #3

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
alexsku wants to merge 1 commit into
base: v4
Choose a base branch
from
Open

concurrency problem #1 #3

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
30 changes: 30 additions & 0 deletions samples/Samples.Mvc5/Controllers/HomeController.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,8 @@
using Samples.Mvc5.EfModelFirst;
using Samples.Mvc5.EFCodeFirst;
using Samples.Mvc5.Helpers;
using System.Threading.Tasks;
using System.Collections.Generic;

namespace Samples.Mvc5.Controllers
{
Expand Down Expand Up @@ -131,6 +133,34 @@ public ActionResult About()
/// <returns>The <see cref="ActionResult"/>.</returns>
public ActionResult ResultsAuthorization() => View();

public async Task<ActionResult> CallAsync()
{
var profiler = MiniProfiler.Current;
var service = new FooService();
using (profiler.Step("action"))
{
var head = profiler.Head;
var tasks = new List<Task>();
for (int i = 0; i < 10; i++)
{
tasks.Add(service.FooAsync(head));
}
await Task.WhenAll(tasks);
return Content("All good");
}
}

class FooService
{
public async Task FooAsync(Timing head)
{
using (new Timing(MiniProfiler.Current, head, "foo async", minSaveMs: 100000))
Copy link
Owner Author

@alexsku alexsku Dec 23, 2016

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

if i use profiler.Step for this it would make all foo async timing to be a long tree with each timing having one child only, this is because Timing replaced the head with itself, so creating 1000 timings in parallel would make them all children of each other. My test is a bit more artificial than i would have liked - i explicitly pass the correct head to each timing

Copy link
Owner Author

@alexsku alexsku Dec 23, 2016

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Also high minSaveMs is important since it triggers the children to be removed from the parent node, if their timing exceeds minSaveMs or minSaveMs is not set they would not be removed and the issue will not get triggered - this is another artificial piece about this test.

{
await Task.Delay(100).ConfigureAwait(false);
}
}
}

/// <summary>
/// fetch the route hits.
/// </summary>
Expand Down
1 change: 1 addition & 0 deletions samples/Samples.Mvc5/Views/Home/Index.cshtml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -65,6 +65,7 @@
<li><a href="/Home/MassiveNesting2">Massive Nesting 2</a></li>
<li><a href="/Home/ParameterizedSqlWithEnums">Parameterized SQL with Enums</a></li>
<li><a href="/Home/MinSaveMs">Test Min Save Ms</a></li>
<li><a href="/Home/CallAsync">Async call + Concurrency</a></li>
</ul>
</div>
</div>
Expand Down
47 changes: 38 additions & 9 deletions src/MiniProfiler.Shared/Timing.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,8 @@
using System.Linq;
using System.Runtime.Serialization;
using StackExchange.Profiling.Helpers;
using System.Threading;
using System.Threading.Tasks;
#if NET45
using System.Web.Script.Serialization;
#endif
Expand All @@ -22,6 +24,9 @@ public class Timing : IDisposable
private readonly decimal? _minSaveMs;
private readonly bool _includeChildrenWithMinSave;

// used for concurrent access detection
private int _threadsAccessing = 0;

/// <summary>
/// Initialises a new instance of the <see cref="Timing"/> class.
/// Obsolete - used for serialization.
Expand Down Expand Up @@ -253,19 +258,43 @@ public void Stop()
/// </remarks>
public void AddChild(Timing timing)
{
if (Children == null)
if (Interlocked.Increment(ref _threadsAccessing) > 1)
throw new Exception("Concurrent access");

try
{
if (Children == null)
Children = new List<Timing>();

Children.Add(timing);
if(timing.Profiler == null)
timing.Profiler = Profiler;
timing.ParentTiming = this;
timing.ParentTimingId = Id;
if (Profiler != null)
timing.MiniProfilerId = Profiler.Id;
Children.Add(timing);
if(timing.Profiler == null)
timing.Profiler = Profiler;
timing.ParentTiming = this;
timing.ParentTimingId = Id;
if (Profiler != null)
timing.MiniProfilerId = Profiler.Id;
}
finally
{
Interlocked.Decrement(ref _threadsAccessing);
}
}

internal void RemoveChild(Timing timing) => Children?.Remove(timing);
internal void RemoveChild(Timing timing)
{
if (Interlocked.Increment(ref _threadsAccessing) > 1)
throw new Exception("Concurrent access");

Task.Delay(10).Wait();
Copy link
Owner Author

@alexsku alexsku Dec 23, 2016

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

i think this delay is helping to trigger the concurrency since the timing spend much longer doing RemoveChild

try
{
Children?.Remove(timing);
}
finally
{
Interlocked.Decrement(ref _threadsAccessing);
}
}

/// <summary>
/// Adds <paramref name="customTiming"/> to this <see cref="Timing"/> step's dictionary of
Expand Down