-
Notifications
You must be signed in to change notification settings - Fork 67
Track dependency instrumented with HttpDesktop DiagnosticSource in Response event (#509) #516
Conversation
DependencyTelemetry remoteDependencyTelemetryActual, Uri url, string kind, bool? success, double valueMin, string statusCode) | ||
{ | ||
Assert.AreEqual("GET " + url.AbsolutePath, remoteDependencyTelemetryActual.Name, true, "Resource name in the sent telemetry is wrong"); | ||
string expectedVersion = SdkVersionHelper.GetExpectedSdkVersion(typeof(DependencyTrackingTelemetryModule), prefix: "rddfd:"); | ||
ValidateTelemetryPacket(remoteDependencyTelemetryActual, url, kind, success, valueMin, statusCode, expectedVersion); | ||
} | ||
}*/ |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Just delete unneeded code.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
nice catch!
forgot to remove it
internal ObjectInstanceBasedOperationHolder TelemetryTable; | ||
|
||
internal DesktopDiagnosticSourceHttpProcessing(TelemetryConfiguration configuration, ObjectInstanceBasedOperationHolder telemetryTupleHolder, bool setCorrelationHeaders, ICollection<string> correlationDomainExclusionList, string appIdEndpoint) | ||
: base(configuration, SdkVersionUtils.GetSdkVersion("rdd" + RddSource.FrameworkAndDiagnostic + ":"), null, setCorrelationHeaders, correlationDomainExclusionList, appIdEndpoint) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Please check with Sergey if "rdd" should be some other prefix code for uniqueness or not.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
it was already there (RddSource.FrameworkAndDiagnostic
) for this source
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
From this PR, it looks like DiagnosticSource and Framework cannot be active at the same time. So RddSource.FrameworkAndDiagnostic does not make sense here as it was originally intended to tell us dependency was collected by both Framework and Diagnostic source.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Minor changes/questions.
Dan Taylor suggestion is to have a flag that would let users choose what they want to sacrifice :) |
using (var reader = new StreamReader(response.GetResponseStream())) | ||
{ | ||
reader.ReadToEnd(); | ||
} |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Please retain the test for 'GetResponse() but no subsequent stream read' to test that we wont collect dependencies in that case, and having a test with comments will be easier for future reference.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
done
[TestMethod] | ||
public void RddTestHttpProcessingFrameworkUpdateTelemetryName() | ||
{ | ||
var stopwatch = Stopwatch.StartNew(); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
start stopwatch right before this line 'this.httpProcessingFramework.OnRequestSend(request); Don't want to include the time taken (its too small but still!) for WebRequest.Create.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
same for all other tests in this class.
@dnduffy How important is to get this 2.4.0-beta2 for you to refer in aspnet core? This change is non-trivial, and dont want to include this in beta2 without routine manual tests. Can this wait for 2.4 stable release ? @lmolkova - Will need to review this in detail+ check functional tests before merging this in. |
@cijothomas This is for Web SDK, it is quite important for the //build scenarios and stable 2.4.0. |
Update on the issue with not-tracked calls: they will be tracked if the response is closed/disposed properly. HttpWebRequest request = WebRequest.CreateHttp("http://localhost:3000");
using (HttpWebResponse response = (HttpWebResponse)request.GetResponse())
{
Console.WriteLine(response.StatusCode);
} If app does not dispose WebRequests properly, it could experience a lot of other issues: e.g. reach connection limit. So I do not consider this is a critical problem anymore even for WebRequests |
Hey guys, please merge it to develop if possible. |
this.sendItems = new List<ITelemetry>(); | ||
this.configuration.TelemetryChannel = new StubTelemetryChannel { OnSend = item => this.sendItems.Add(item) }; | ||
this.configuration.InstrumentationKey = Guid.NewGuid().ToString(); | ||
this.httpProcessingFramework = new DesktopDiagnosticSourceHttpProcessing(this.configuration, new ObjectInstanceBasedOperationHolder(), /*setCorrelationHeaders*/ true, new List<string>(), RandomAppIdEndpoint); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
httpProcessingFramework - this name is misleading. Please change to reflect the new class name.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This is not changed. DesktopDiagnosticSourceHttpProcessingTests is not testing HttpProcessingFramework, but the variable name is telling otherwise. (its difficult to read code with consuing names :( )
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Some comments left. Most importantly - can you add/modify Functional tests for the changes? There are a bunch of Functional tests already for dependency collector , please make use of that to validate things end to end.
need to discuss about the version prefix. RddSource.FrameworkAndDiagnostic does not seem logical here, rddd maybe okay, but DependencyCollector in Core already uses that, so we need to distinguish that as well. |
@@ -221,9 +221,23 @@ protected virtual void Dispose(bool disposing) | |||
/// </summary> | |||
private void InitializeForFrameworkEventSource() | |||
{ | |||
#if NET45 |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
What is the difference between #if NET 45 here and #if !NET40 below. Are we dealing with .net framework < 40?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
you are right, there is no difference
Core and Desktop will never be active at the same time, but it could be useful to distinguish them anyway. What about 'rdddd' (for rdd desktop diagnostics)? However it seems too similar to 'rddd' used in core. |
There are several difficult aspects of adding/changing functional tests
I would prefer another solution described in #494, so we can have local mocked server and track dependencies done to it. It requires a bit of investment to set up localhost. There are other questions where those tests should live: in unit-tests projects or in functional tests. I would argue to keep them as unit tests. |
/// </summary> | ||
internal sealed class DesktopDiagnosticSourceHttpProcessing : HttpProcessing | ||
{ | ||
internal ObjectInstanceBasedOperationHolder TelemetryTable; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Why make this internal? For tests? Should we make this a private field and expose an internal property instead? It's best practice to have fields private only - properties give more fine grained control on exposing what you want to expose to the outside world - for example may be you only want to give get permissions not set.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
copy/paste issue
/// Validates that OnRequestSend and OnResponseReceive sends valid telemetry. | ||
/// </summary> | ||
[TestMethod] | ||
public void RddTestHttpProcessingFrameworkUpdateTelemetryName() |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
can you modify all the test names to reflect what they are testing? HttpProcessing vs DesktopDiagnosticsSourceHttpProcessing?
Update: redirect issue is fixed in DiagnosticSource |
b237375
to
84bd166
Compare
@@ -221,9 +221,21 @@ protected virtual void Dispose(bool disposing) | |||
/// </summary> | |||
private void InitializeForFrameworkEventSource() |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This name does not hold true anymore as we are not only initializing frameworkeventsource but initializing DiagnosticSource as well.
/// <summary> | ||
/// Concrete class with all processing logic to generate RDD data from the callbacks received from HttpDesktopDiagnosticSourceListener. | ||
/// </summary> | ||
internal sealed class DesktopDiagnosticSourceHttpProcessing : HttpProcessing |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Won't this receive callbacks for failure cases? I only see logic to handle successfull dependencies.. (FrameworkEventSource, profiler had logic for failed calls)
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Could you please show me where FrameworkEventSource reports failure cases?
I don't see it here here
And in case of HTTP failure means exception because of e.g. DNS or network issue or cancellation.
@@ -53,7 +53,7 @@ public void OnNext(KeyValuePair<string, object> value) | |||
case "System.Net.Http.Request": | |||
{ | |||
var request = (HttpWebRequest)this.requestFetcherRequestEvent.Fetch(value.Value); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
We need to add DependencyCollectorEventSource.Log.Callback received type of logging here.
@@ -249,8 +249,7 @@ internal object OnBegin(object thisObj, bool skipIfNotNew) | |||
/// <param name="exception">The exception object if any.</param> | |||
/// <param name="thisObj">This object.</param> | |||
/// <param name="returnValue">Return value of the function if any.</param> | |||
/// <param name="endTracking">Whether this method should end the tracking or not.</param> | |||
internal void OnEnd(object exception, object thisObj, object returnValue, bool endTracking) | |||
internal void OnEnd(object exception, object thisObj, object returnValue) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
HttpProcessing class should not log about callbacks. Do that in the corresponding listeners.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Callbacks were not introduced in this PR, moving them goes far beyond this pull request,. This PR a critical issue fix and I doubt we should do more refactoring here
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I added callback logs into the listener and created an issue to consistently change profiler/httpprocessing logs #537
FrameworkHttpProcessing frameworkHttpProcessing = new FrameworkHttpProcessing(this.telemetryConfiguration, DependencyTableStore.Instance.WebRequestCacheHolder, this.SetComponentCorrelationHttpHeaders, this.ExcludeComponentCorrelationHttpHeadersOnDomains, this.EffectiveProfileQueryEndpoint); | ||
this.httpDesktopDiagnosticSourceListener = new HttpDesktopDiagnosticSourceListener(frameworkHttpProcessing); | ||
#if NET45 | ||
DesktopDiagnosticSourceHttpProcessing desktopHttpProcessing = new DesktopDiagnosticSourceHttpProcessing( |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
we are now enabling both diagnostic source and framework event source. where is the logic to prevent double collection or only one will be active at a time?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
it's here
In runtime, we do not know what happens first: initialization of Http Desktop DiagnosticSource or initialization of the DependencyTrackingTelemetryModule, so we keep listening to both, but ignoring the EventSource if DiagnosticSource is active.
DiagnosticSource Response event (#509)
e29dc2a
to
4f7d151
Compare
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Please check all the comments. There are lot.
@@ -47,6 +47,11 @@ public class DependencyTrackingTelemetryModule : ITelemetryModule, IDisposable | |||
public bool DisableRuntimeInstrumentation { get; set; } | |||
|
|||
/// <summary> | |||
/// Gets or sets a value indicating whether to disable runtime instrumentation. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
minor: incorrect comment.
this.ExcludeComponentCorrelationHttpHeadersOnDomains, | ||
this.EffectiveProfileQueryEndpoint); | ||
this.httpDesktopDiagnosticSourceListener = new HttpDesktopDiagnosticSourceListener(desktopHttpProcessing); | ||
} |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
please add a log here saying DesktopDiagnosticSource was not enabled as it was not enabled in config. Helps in debugging customer issues later.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Let's add log that is WAS actually activated.
using System.Net; | ||
|
||
/// <summary> | ||
/// Diagnostic listener implementation that listens for Http DiagnosticSource to see all outgoing HTTP dependency requests. | ||
/// </summary> | ||
internal class HttpDesktopDiagnosticSourceListener : IObserver<KeyValuePair<string, object>>, IDisposable | ||
{ | ||
private readonly FrameworkHttpProcessing httpProcessingFramework; | ||
private readonly DesktopDiagnosticSourceHttpProcessing httpDesktopProcessingFramework; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
minor - rename variable to reflect the class name. (Framework at the end will be confusing_)
if (DependencyTableStore.Instance.IsDesktopHttpDiagnosticSourceActivated) | ||
{ | ||
// request is handled by Desktop DiagnosticSource Listener | ||
DependencyCollectorEventSource.Log.TrackingAnExistingTelemetryItemVerbose(); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
please use a different log message here. TrackingAnExistingTelemetryItemVerbose() is used for a different purpose (it existed before diagnostic source). Log something like "I am not tracking this, as DesktopDiagnosticSource is already enabled"
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I've already done that in the next PR #538, there was a special event added there
@@ -48,6 +48,7 @@ public void OnNext(DiagnosticListener value) | |||
if (value.Name == "System.Net.Http.Desktop") | |||
{ | |||
this.sourceSubscription = value.Subscribe(this.parent, (Predicate<string>)null); | |||
DependencyTableStore.Instance.IsDesktopHttpDiagnosticSourceActivated = true; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Does it need to set this back to false on Dispose?
DependencyCollectorEventSource.Log.ProfilerFailedToAttachError(exp.ToInvariantString()); | ||
} | ||
} | ||
else | ||
{ | ||
// if config is set to disable runtime instrumentation then default to framework event source | ||
this.InitializeForFrameworkEventSource(); | ||
this.InitializeForDiagnosticAndFrameworkEventSource(); | ||
DependencyCollectorEventSource.Log.RemoteDependencyModuleVerbose("Runtime instrumentation is set to disabled. Initialize with framework event source instead."); | ||
} | ||
} | ||
else | ||
{ | ||
// if profiler is not attached then default to framework event source |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
minor - change comment to indicate eventsouce and/or diagnostic listene.
@@ -165,7 +165,7 @@ internal static void AddTupleForWebDependencies(WebRequest webRequest, Dependenc | |||
|
|||
Tuple<DependencyTelemetry, bool> telemetryTuple = null; | |||
|
|||
if (DependencyTableStore.Instance.IsProfilerActivated || PretendProfilerIsAttached) | |||
if (DependencyTableStore.Instance.IsDesktopHttpDiagnosticSourceActivated || DependencyTableStore.Instance.IsProfilerActivated || PretendProfilerIsAttached) | |||
{ |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This does not look right. This means that, even when Profiler is not installed, tuple will be looked up in SQLRequestConditionalHolder - this is incorrect, as without Profiler SQL Dependencies should be stored in SqlRequestCacheHolder.
(More concerning here is - did any functional tests for sql fail? if not there is a test gap)
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
nothing has failed. may be there is a gap
@@ -198,7 +198,7 @@ internal static void AddTupleForSqlDependencies(SqlCommand sqlRequest, Dependenc | |||
} | |||
|
|||
var telemetryTuple = new Tuple<DependencyTelemetry, bool>(telemetry, isCustomCreated); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
same comment as above related to SQL without profiler.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
removed this check for SQL deps, IsDesktopHttpDiagnosticSourceActivated is only for http
@@ -48,6 +48,7 @@ public void OnNext(DiagnosticListener value) | |||
if (value.Name == "System.Net.Http.Desktop") | |||
{ | |||
this.sourceSubscription = value.Subscribe(this.parent, (Predicate<string>)null); | |||
DependencyTableStore.Instance.IsDesktopHttpDiagnosticSourceActivated = true; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
We are counting on HttpDesktopDiagnosticSourceSubscriber OnNext() to set IsDesktopHttpDiagnosticSourceActivated = true. We definitely need unit test to check this.
Also, is there a guarantee that OnNext will be called before any callbacks to Framework event source?? If not, the IsDesktopHttpDiagnosticSourceActivated will be False, and FrameworkEventSource will start collecting dependencies, which might be later collected by DiagnosticSource. (this may be artificial scenario, but i'd like to know if thats even possible)
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Added checks in DependencyTrackingTelemetryModuleTestNet46.
There is no guarantee that subscription will happen before module initialization. It must happen before the first HTTP outgoing call or will never happen at all.
So if there is a HTTP call, in EventSource we will know for sure if diag source is activated or not
var request = (HttpWebRequest)this.requestFetcherRequestEvent.Fetch(value.Value); | ||
this.httpProcessingFramework.OnRequestSend(request); | ||
DependencyCollectorEventSource.Log.BeginCallbackCalled(request.GetHashCode(), value.Key); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Please use a different log message. I understand there is a task opened for fixing the calls backs, but having a new callback log message for 3-4 switch cases in DiagnosticSourceListener should be very easy fix.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Why it is important? I pass name of the callback in the parameter
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
ok callback name should be sufficient for now.
db87b9b
to
e973cdd
Compare
See #509 for the details.
Please note:
Before this fix, all dependencies are reported, but none of the dependencies instrumented with DiagnosticSource have proper Target with appId.
After this fix
E.g.
Will never be tracked... Application that does not dispose WebRequests may run short on the available connections, so in most cases uses will dispose them.
Will be tracked.
This problem does not affect requests done with HttpClient as responses are disposed.
Considering that some dependencies may not be collected and it does not look fixable, please decide whether this fix should be taken at all.
Otherwise, just keep current implementation (and sacrifice AppId for all dependencies).