Skip to content
This repository was archived by the owner on Jul 5, 2020. It is now read-only.

Fix 503 WCF test that sometimes fails because of intermediate request #908

Merged
lmolkova merged 2 commits into from
May 9, 2018
Merged

Fix 503 WCF test that sometimes fails because of intermediate request #908

Show file tree
Hide file tree
Changes from 1 commit
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
855a37a
Fix 503 WCF test that sometimes fails because of intermediate request
May 4, 2018
34a8597
Merge branch 'develop' into lmolova/fixFlackyWebFuns
May 8, 2018
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
10 changes: 7 additions & 3 deletions Src/Web/Web.Net45.Tests/AspNetDiagnosticTelemetryModuleTest.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -114,11 +114,15 @@ public void GrandChildTelemetryIsReportedProperlyBetweenBeginEndRequestWhenActiv
client.TrackTrace(trace);

this.aspNetDiagnosticsSource.ReportRestoredActivity(restoredActivity);
Assert.AreEqual(2, this.sendItems.Count);
var requestRestoredTelemetry = (RequestTelemetry)this.sendItems.SingleOrDefault(i => i is RequestTelemetry);
Assert.AreEqual(1, this.sendItems.Count);

restoredActivity.Stop();
this.aspNetDiagnosticsSource.StopLostActivity(activity);

Assert.AreEqual(3, this.sendItems.Count);
var requestRestoredTelemetry = (RequestTelemetry)this.sendItems[1];
Assert.IsNotNull(requestRestoredTelemetry);

this.aspNetDiagnosticsSource.StopActivity();
Assert.AreEqual(3, this.sendItems.Count);

var requestTelemetry = (RequestTelemetry)this.sendItems[2];
Expand Down
4 changes: 2 additions & 2 deletions Src/Web/Web.Shared.Net.Tests/RequestTrackingTelemetryModuleTest.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -429,8 +429,8 @@ public void TrackIntermediateRequestSetsProperties()
var restoredActivity = new Activity("dummy").SetParentId(originalRequest.Id).Start();

module.TrackIntermediateRequest(context, restoredActivity);

Assert.Equal(1, this.sentTelemetry.Count);
module.OnEndRequest(context);
Assert.Equal(2, this.sentTelemetry.Count);
Assert.True(this.sentTelemetry.TryDequeue(out RequestTelemetry intermediateRequest));

Assert.Equal(originalRequest.Id, intermediateRequest.Context.Operation.ParentId);
Expand Down
12 changes: 9 additions & 3 deletions Src/Web/Web.Shared.Net/RequestTrackingTelemetryModule.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -19,13 +19,14 @@
/// </summary>
public class RequestTrackingTelemetryModule : ITelemetryModule
{
private const string IntermediateRequestHttpContextKey = "IntermediateRequest";
private readonly IList<string> handlersToFilter = new List<string>();
private TelemetryClient telemetryClient;
private TelemetryConfiguration telemetryConfiguration;
private bool initializationErrorReported;
private bool correlationHeadersEnabled = true;
private ChildRequestTrackingSuppressionModule childRequestTrackingSuppressionModule = null;

/// <summary>
/// Gets or sets a value indicating whether child request suppression is enabled or disabled.
/// True by default.
Expand Down Expand Up @@ -211,6 +212,12 @@ public void OnEndRequest(HttpContext context)

if (this.childRequestTrackingSuppressionModule?.OnEndRequest_ShouldLog(context) ?? true)
{
var intermediateRequest = (RequestTelemetry)context.Items[IntermediateRequestHttpContextKey];
if (intermediateRequest != null)
Copy link
Copy Markdown
Member

@Dmitry-Matveev Dmitry-Matveev May 7, 2018

Choose a reason for hiding this comment

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

Is there a guarantee that internal request will reach this OnEndRequest handler faster all the time?
I remember that with TransferRequestHandler we didn't have such a guarantee as per @MS-TimothyMothra.
Without that, the tests may still fail very rarely but customers with high load of requests would sometimes see both reported vs. one reported.

Copy link
Copy Markdown
Author

@lmolkova lmolkova May 7, 2018

Choose a reason for hiding this comment

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

yes, it is guaranteed by TelemteryCorrelation package - it first fires event that there was 'intermediate activity' and right after that would report that request was ended.

This change only reduces noise in the reporting and tests only helped to notice this noise

{
this.telemetryClient.TrackRequest(intermediateRequest);
}

this.telemetryClient.TrackRequest(requestTelemetry);
}
else
Expand Down Expand Up @@ -338,8 +345,7 @@ internal void TrackIntermediateRequest(HttpContext context, Activity activity)
intermediateRequest.Context.Operation.ParentId = activity.ParentId;
intermediateRequest.ResponseCode = null;
intermediateRequest.Properties.Add("AI internal", "Execute request handler step");

this.telemetryClient.TrackRequest(intermediateRequest);
context.Items[IntermediateRequestHttpContextKey] = intermediateRequest;
}

/// <summary>
Expand Down