Skip to content

Commit de36d20

Browse files
author
Liudmila Molkova
authored
Detect broken Activity stack and gracefully end the loop (#23)
Fix endless loop in case some activity in the stack is stopped in the child context
1 parent 402f92c commit de36d20

4 files changed

Lines changed: 131 additions & 18 deletions

File tree

‎src/Microsoft.AspNet.TelemetryCorrelation/ActivityHelper.cs‎

Lines changed: 65 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -36,6 +36,7 @@ internal static class ActivityHelper
3636
/// </summary>
3737
public const string ActivityKey = "__AspnetActivity__";
3838

39+
private const int MaxActivityStackSize = 128;
3940
private static readonly DiagnosticListener AspNetListener = new DiagnosticListener(AspNetListenerName);
4041

4142
/// <summary>
@@ -66,14 +67,52 @@ public static Activity RestoreCurrentActivity(Activity root)
6667
return childActivity;
6768
}
6869

70+
/// <summary>
71+
/// Stops the activity and notifies listeners about it.
72+
/// </summary>
73+
/// <param name="activity">Activity to stop.</param>
74+
/// <param name="context">Current HttpContext.</param>
75+
/// <returns>True if activity was found in the stack, false otherwise.</returns>
6976
public static bool StopAspNetActivity(Activity activity, HttpContext context)
7077
{
71-
if (activity != null && Activity.Current != null)
78+
var currentActivity = Activity.Current;
79+
if (activity != null && currentActivity != null)
7280
{
7381
// silently stop all child activities before activity
74-
while (Activity.Current != activity && Activity.Current != null)
82+
int iteration = 0;
83+
while (currentActivity != activity)
7584
{
76-
Activity.Current.Stop();
85+
currentActivity.Stop();
86+
var newCurrentActivity = Activity.Current;
87+
88+
if (newCurrentActivity == null)
89+
{
90+
break;
91+
}
92+
93+
// there could be a case when request or any child activity is stopped
94+
// from the child execution context. In this case, Activity is present in the Current Stack,
95+
// but is finished, i.e. stopping it has no effect on the Current.
96+
if (newCurrentActivity == currentActivity)
97+
{
98+
// We could not reach our 'activity' in the stack and have to report 'lost activity'
99+
// if child activity is broken, we can still stop the root one that we own to clean up
100+
// all resources
101+
AspNetTelemetryCorrelationEventSource.Log.FinishedActivityIsDetected(currentActivity.Id, currentActivity.OperationName);
102+
activity.Stop();
103+
return false;
104+
}
105+
106+
// We also protect from endless loop with the MaxActivityStackSize
107+
// in case it would ever be possible to have cycles in the Activity stack.
108+
if (iteration++ == MaxActivityStackSize)
109+
{
110+
AspNetTelemetryCorrelationEventSource.Log.ActivityStackIsTooDeep(currentActivity.Id, currentActivity.OperationName);
111+
activity.Stop();
112+
return false;
113+
}
114+
115+
currentActivity = newCurrentActivity;
77116
}
78117

79118
// if activity is in the stack, stop it with Stop event
@@ -89,6 +128,11 @@ public static bool StopAspNetActivity(Activity activity, HttpContext context)
89128
return false;
90129
}
91130

131+
/// <summary>
132+
/// Notifies listeners that activity was ended and lost during execution.
133+
/// </summary>
134+
/// <param name="activity">Activity to notify about.</param>
135+
/// <param name="context">Current HttpContext.</param>
92136
public static void StopLostActivity(Activity activity, HttpContext context)
93137
{
94138
if (activity != null)
@@ -99,6 +143,11 @@ public static void StopLostActivity(Activity activity, HttpContext context)
99143
}
100144
}
101145

146+
/// <summary>
147+
/// Creates root (first level) activity that describes incoming request.
148+
/// </summary>
149+
/// <param name="context">Current HttpContext.</param>
150+
/// <returns>New root activity.</returns>
102151
public static Activity CreateRootActivity(HttpContext context)
103152
{
104153
if (AspNetListener.IsEnabled() && AspNetListener.IsEnabled(AspNetActivityName))
@@ -117,6 +166,19 @@ public static Activity CreateRootActivity(HttpContext context)
117166
return null;
118167
}
119168

169+
/// <summary>
170+
/// This should be called after the Activity starts and only for root activity of a request.
171+
/// </summary>
172+
/// <param name="context">Context to save context to.</param>
173+
/// <param name="activity">Activity to save.</param>
174+
internal static void SaveCurrentActivity(HttpContext context, Activity activity)
175+
{
176+
Debug.Assert(context != null);
177+
Debug.Assert(activity != null);
178+
179+
context.Items[ActivityKey] = activity;
180+
}
181+
120182
private static bool StartAspNetActivity(Activity activity)
121183
{
122184
if (AspNetListener.IsEnabled(AspNetActivityName, activity, new { }))
@@ -136,19 +198,6 @@ private static bool StartAspNetActivity(Activity activity)
136198
return false;
137199
}
138200

139-
/// <summary>
140-
/// This should be called after the Activity starts and only for root activity of a request.
141-
/// </summary>
142-
/// <param name="context">Context to save context to.</param>
143-
/// <param name="activity">Activity to save.</param>
144-
private static void SaveCurrentActivity(HttpContext context, Activity activity)
145-
{
146-
Debug.Assert(context != null);
147-
Debug.Assert(activity != null);
148-
149-
context.Items[ActivityKey] = activity;
150-
}
151-
152201
private static void RemoveCurrentActivity(HttpContext context)
153202
{
154203
Debug.Assert(context != null);

‎src/Microsoft.AspNet.TelemetryCorrelation/AspNetTelemetryCorrelationEventSource.cs‎

Lines changed: 13 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -35,7 +35,7 @@ public void ActivityStopped(string id, bool lost = false)
3535
WriteEvent(3, id, lost);
3636
}
3737

38-
[Event(4, Message = "Failed to parse header '{0}', value: '{1}'", Level = EventLevel.Error)]
38+
[Event(4, Message = "Failed to parse header '{0}', value: '{1}'", Level = EventLevel.Informational)]
3939
public void HeaderParsingError(string headerName, string headerValue)
4040
{
4141
WriteEvent(4, headerName, headerValue);
@@ -46,6 +46,18 @@ public void ActvityExtractionError(string reason)
4646
{
4747
WriteEvent(5, reason);
4848
}
49+
50+
[Event(6, Message = "Finished Activity is detected on the stack, Id: '{0}', Name: '{1}'", Level = EventLevel.Error)]
51+
public void FinishedActivityIsDetected(string id, string name)
52+
{
53+
WriteEvent(6, id, name);
54+
}
55+
56+
[Event(7, Message = "Activity stack is too deep, Current Id: '{0}', Name: '{1}'", Level = EventLevel.Error)]
57+
public void ActivityStackIsTooDeep(string id, string name)
58+
{
59+
WriteEvent(7, id, name);
60+
}
4961
}
5062
}
5163
#pragma warning restore SA1600 // Elements must be documented

‎src/Microsoft.AspNet.TelemetryCorrelation/Microsoft.AspNet.TelemetryCorrelation.csproj‎

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -68,7 +68,9 @@
6868
</ItemGroup>
6969
<ItemGroup>
7070
<None Include="Microsoft.AspNet.TelemetryCorrelation.ruleset" />
71-
<None Include="packages.config" />
71+
<None Include="packages.config">
72+
<SubType>Designer</SubType>
73+
</None>
7274
</ItemGroup>
7375
<ItemGroup>
7476
<Analyzer Include="..\..\packages\StyleCop.Analyzers.1.0.0\analyzers\dotnet\cs\Newtonsoft.Json.dll" />

‎test/Microsoft.AspNet.TelemetryCorrelation.Tests/ActivityHelperTest.cs‎

Lines changed: 50 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -126,6 +126,56 @@ public void Can_Stop_Child_Activity_With_All_Children()
126126
Assert.Equal(rootActivity, Activity.Current);
127127
Assert.Null(context.Items[ActivityHelper.ActivityKey]);
128128
}
129+
130+
[Fact]
131+
public async Task Can_Stop_Root_Activity_If_It_Is_Broken()
132+
{
133+
var context = HttpContextHelper.GetFakeHttpContext();
134+
var root = new Activity("root").Start();
135+
ActivityHelper.SaveCurrentActivity(context, root);
136+
137+
new Activity("child").Start();
138+
139+
for (int i = 0; i < 2; i++)
140+
{
141+
await Task.Run(() =>
142+
{
143+
// when we enter this method, Current is 'child' activity
144+
Activity.Current.Stop();
145+
// here Current is 'parent', but only in this execution context
146+
});
147+
}
148+
149+
// when we return back here, in the 'parent' execution context
150+
// Current is still 'child' activity - changes in child context (inside Task.Run)
151+
// do not affect 'parent' context in which Task.Run is called.
152+
// But 'child' Activity is stopped, thus consequent calls to Stop will
153+
// not update Current
154+
Assert.False(ActivityHelper.StopAspNetActivity(root, context));
155+
Assert.NotNull(context.Items[ActivityHelper.ActivityKey]);
156+
Assert.Null(Activity.Current);
157+
}
158+
159+
[Fact]
160+
public void Stop_Root_Activity_With_129_Nesting_Depth()
161+
{
162+
var context = HttpContextHelper.GetFakeHttpContext();
163+
var root = new Activity("root").Start();
164+
ActivityHelper.SaveCurrentActivity(context, root);
165+
166+
for (int i = 0; i < 129; i++)
167+
{
168+
new Activity("child" + i).Start();
169+
}
170+
171+
// we do not allow more than 128 nested activities here
172+
// only to protect from hypothetical cycles in Activity stack
173+
Assert.False(ActivityHelper.StopAspNetActivity(root, context));
174+
175+
Assert.NotNull(context.Items[ActivityHelper.ActivityKey]);
176+
Assert.Null(Activity.Current);
177+
}
178+
129179
#endregion
130180

131181
#region CreateRootActivity tests

0 commit comments

Comments
 (0)