Skip to content
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.

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

Missing external calls in WCF Service. #551

Closed
vuqtran88 opened this issue May 7, 2021 · 0 comments · Fixed by #610
Closed

Missing external calls in WCF Service. #551

vuqtran88 opened this issue May 7, 2021 · 0 comments · Fixed by #610
Assignees
Labels
bug Something isn't working

Comments

@vuqtran88
Copy link
Contributor

vuqtran88 commented May 7, 2021

Description
It is reported that external calls made by HttpClient inside a WCF IIS Hosted service endpoint are not tracked by the agent. I am able to repro the behavior by calling the the HttpClient multiple times in async/await fashion in side a test WCF service hosted in IIS (ASP compatible mode enabled).

    [ServiceBehavior(AddressFilterMode = AddressFilterMode.Any)]
    public class Service1 : IService1
    {
		public async Task<string> MakeSomeExternalCall()
		{
            var httpClient = new HttpClient();

            var a = await httpClient.GetAsync("https://google.com");

            var b = await httpClient.GetAsync("https://bing.com");

            var c = await httpClient.GetAsync("https://yahoo.com");

            return $"{a.IsSuccessStatusCode} + {b.IsSuccessStatusCode} + {c.IsSuccessStatusCode}";
		}
	}

While investigating the issue, I notice the following messages in the agent log:

2021-05-07 20:51:05,238 NewRelic FINEST: [pid: 13500, tid: 15] Trx 8043d0d7e18ed004: Attempting to execute NewRelic.Providers.Wrapper.Wcf3.MethodInvokerWrapper found from InstrumentedMethodInfo: Method: System.ServiceModel.Dispatcher.TaskMethodInvoker, System.ServiceModel, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089:InvokeAsync(System.Object,System.Object[]), RequestedWrapperName: NewRelic.Agent.Core.Tracer.Factories.DefaultTracerFactory, IsAsync: True, RequestedMetricName: , RequestedTransactionNamePriority: , StartWebTransaction: False
2021-05-07 20:51:05,255 NewRelic FINEST: [pid: 13500, tid: 15] Trx 8043d0d7e18ed004: Setting transaction name to TransactionName{"IsWeb":true,"Category":"WCF","Name":"WcfService1.IService1.MakeSomeExternalCall","UnprefixedName":"WCF/WcfService1.IService1.MakeSomeExternalCall"} (priority 6, FrameworkHigh) from TransactionName{"IsWeb":true,"Category":"ASP","Name":"ServiceHttpHandler","UnprefixedName":"ASP/ServiceHttpHandler"} (priority 3, Handler)
2021-05-07 20:51:05,264 NewRelic FINEST: [pid: 13500, tid: 15] Trx 8043d0d7e18ed004: Segment start {Id=9,ParentId=6,Name=WcfService1.IService1.MakeSomeExternalCall,IsLeaf=False,Combinable=False,MethodCallData=System.ServiceModel.Dispatcher.TaskMethodInvoker.InvokeAsync}
2021-05-07 20:51:05,319 NewRelic  DEBUG: [pid: 13500, tid: 15] Wrapper "NewRelic.Providers.Wrapper.HttpClient.SendAsync" will be used for instrumented method "System.Net.Http.HttpClient.SendAsync"
2021-05-07 20:51:05,322 NewRelic FINEST: [pid: 13500, tid: 15] Trx 8043d0d7e18ed004: Retrieved from NewRelic.Providers.Storage.HttpContext.HttpContextStorage`1[NewRelic.Agent.Core.Transactions.IInternalTransaction]
2021-05-07 20:51:05,324 NewRelic FINEST: [pid: 13500, tid: 15] Trx 8043d0d7e18ed004: Attempting to execute NewRelic.Providers.Wrapper.HttpClient.SendAsync found from InstrumentedMethodInfo: Method: System.Net.Http.HttpClient, System.Net.Http, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a:SendAsync(System.Net.Http.HttpRequestMessage,System.Net.Http.HttpCompletionOption,System.Threading.CancellationToken), RequestedWrapperName: NewRelic.Agent.Core.Tracer.Factories.DefaultTracerFactory, IsAsync: False, RequestedMetricName: , RequestedTransactionNamePriority: , StartWebTransaction: False
2021-05-07 20:51:05,332 NewRelic FINEST: [pid: 13500, tid: 15] Trx 8043d0d7e18ed004: Segment start {Id=10,ParentId=9,Name=DotNet/System.Net.Http.HttpClient/SendAsync,IsLeaf=False,Combinable=False,MethodCallData=System.Net.Http.HttpClient.SendAsync}
.....
.....
.....
.....
2021-05-07 20:51:06,080 NewRelic FINEST: [pid: 13500, tid: 16] Trx Noop: Attempting to execute NewRelic.Providers.Wrapper.HttpClient.SendAsync found from InstrumentedMethodInfo: Method: System.Net.Http.HttpClient, System.Net.Http, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a:SendAsync(System.Net.Http.HttpRequestMessage,System.Net.Http.HttpCompletionOption,System.Threading.CancellationToken), RequestedWrapperName: NewRelic.Agent.Core.Tracer.Factories.DefaultTracerFactory, IsAsync: False, RequestedMetricName: , RequestedTransactionNamePriority: , StartWebTransaction: False
2021-05-07 20:51:06,084 NewRelic FINEST: [pid: 13500, tid: 16] Trx Noop: No transaction, skipping method System.Net.Http.HttpClient.SendAsync(System.Net.Http.HttpRequestMessage,System.Net.Http.HttpCompletionOption,System.Threading.CancellationToken)

The log messages indicate that the first external call was successfully tracked because it was executed on the same thread as the caller (tid: 15). However, the agent failed to track the second external call because it was executed on a different thread (tid: 16)--> no transaction found.

The agent seems to make the assumption that async calls executed in async/await fashion executed on same thread as the caller, but this prove to be inaccurate.

Expected Behavior
External calls made with HttpClient should be tracked by the agent.

Steps to Reproduce
Repro app included.
WcfService1.zip

Your Environment
WCF service hosted in IIS, Asp compatibility mode enabled.

@vuqtran88 vuqtran88 added the bug Something isn't working label May 7, 2021
@JcolemanNR JcolemanNR assigned JcolemanNR and vuqtran88 and unassigned JcolemanNR May 10, 2021
@angelatan2 angelatan2 added this to the FY22Q1 Bug Smash - Cicada milestone Jun 4, 2021
@vuqtran88 vuqtran88 linked a pull request Jun 18, 2021 that will close this issue
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants