search

microsoft / ApplicationInsights-dotnet

ApplicationInsights-dotnet
MIT License
566 stars 285 forks source link

Exceptions lost due to Bad request #2320

Closed Bubleguy closed 1 year ago

Bubleguy commented 3 years ago

Nuget packages:

Runtime:

Hosting Environment:

I have N-Layers WS and I use NInject for dependancy injection. When Excpetion is thrown at first layer (called ApplicationService) everything is fine. But if exceptions occurs in the below layers(service, business, repository, ...) the exceptions cannot reach AppInsightPortal. I activated debugging in Appinsight an i got the following log.

Microsoft.ApplicationInsights.Extensibility.TraceSource Warning: 71 : TransmissionDataLossError. Telemetry items are being lost here as the response code is not in the whitelisted set of retriable codes.TransmissionId: 9jZTekTqAaM=. Status Code: 400.

Since exceptions throw by lower layers are a bit bigger i checked the constraints but i am under the 32 768 size so it should work fine.

Here the telemetry that is working : { "name": "AppExceptions", "time": "2021-06-28T15:06:40.2734458Z", "seq": "760", "iKey": "XXXXX-XXXXX-XXXXX-XXXXX-XXXXX", "tags": { "ai.application.ver": "local", "ai.cloud.role": "XXXXX XXXXX", "ai.cloud.roleInstance": "XXXXX-XXXXX-XXXXX.XXXXX.XXXXX", "ai.operation.id": "8c47410647f1b74a9815683df6931f34", "ai.operation.parentId": "4b5e00c9c488b54b", "ai.operation.name": "GET /XXXXX.svc/GetContextAbonnement", "ai.location.ip": "::1", "ai.internal.sdkVersion": "nlog:2.14.0-17971" }, "data": { "baseType": "ExceptionData", "baseData": { "ver": 2, "exceptions": [{ "id": 7583353, "outerId": 0, "typeName": "System.Exception", "message": "System.Exception: Exception throw at top layer by hand", "hasFullStack": true, "parsedStack": [{ "level": 0, "method": "XXXXX.XXXXX.XXXXX.XXXXX.XXXXX.GetContextAbonnement", "assembly": "XXXXX.XXXXX.XXXXX, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null", "fileName": "C:\\XXXXX\\XXXXX\\XXXXX\\XXXXX\\XXXXX\\XXXXX.XXXXX.XXXXX\\XXXXX\\XXXXX\\XXXXX.cs", "line": 294 }, { "level": 1, "method": "SyncInvokeGetContextAbonnement", "assembly": "System.ServiceModel, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089", "line": 0 }, { "level": 2, "method": "System.ServiceModel.Dispatcher.SyncMethodInvoker.Invoke", "assembly": "System.ServiceModel, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089", "line": 0 }, { "level": 3, "method": "XXXXX.XXXXX.XXXXX.AuthorizingOperationInvoker.Invoke", "assembly": "XXXXX.XXXXX.XXXXX, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null", "fileName": "C:\\XXXXX\\XXXXX\\XXXXX\\XXXXX\\XXXXX\\XXXXX.XXXXX.XXXXX\\Technique\\AOP\\AuthorizingOperationBehavior.cs", "line": 180 }, { "level": 4, "method": "XXXXX.XXXXX.XXXXX.ErrorHandlingOperationInvoker.Invoke", "assembly": "XXXXX.XXXXX.XXXXX, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null", "fileName": "C:\\XXXXX\\XXXXX\\XXXXX\\XXXXX\\XXXXX\\XXXXX.XXXXX.XXXXX\\Technique\\AOP\\ErrorHandlingOperationBehavior.cs", "line": 86 }] }], "severityLevel": "Error", "properties": { "layer": "WebServices", "LoggerName": "TraceLogger", "ClientName": "XXXXX", "methodName": "GetContextAbonnement", "Environnement": "localhost", "UserName": "XXXXX", "className": "XXXXX", "DeveloperMode": "true", "Message": "Exception throw at top layer by hand", "UserId": "XXXXX", "_MS.ProcessedByMetricExtractors": "(Name:'Exceptions', Ver:'1.1')" } } } }

Here the telemetry that fails: { "name": "AppExceptions", "time": "2021-06-28T15:00:22.8664458Z", "seq": "742", "iKey": "XXXXX-XXXXX-XXXXX-XXXXX-XXXXX", "tags": { "ai.application.ver": "local", "ai.cloud.role": "XXXXX XXXXX", "ai.cloud.roleInstance": "XXXXX-XXXXX-XXXXX.XXXXX.XXXXX", "ai.operation.id": "bdcd9188bf60ad4483e264106dbcca52", "ai.operation.parentId": "b17749f3ecf15742", "ai.operation.name": "GET /XXXXX.svc/GetInformationsTechnique", "ai.location.ip": "::1", "ai.internal.sdkVersion": "nlog:2.14.0-17971" }, "data": { "baseType": "ExceptionData", "baseData": { "ver": 2, "exceptions": [{ "id": 24390049, "outerId": 0, "typeName": "System.Exception", "message": "System.Exception: Exception thrown in below layer by hand", "hasFullStack": true, "parsedStack": [{ "level": 0, "method": "XXXXX.XXXXX.XXXXX.XXXXX.AbonnementRepository.GetDateResiliationPredecesseur", "assembly": "XXXXX.XXXXX.XXXXX.XXXXX, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null", "line": 0 }, { "level": 1, "assembly": "Ninject.Extensions.Interception, Version=3.2.0.0, Culture=neutral, PublicKeyToken=c7192dc5380945e7", "line": 0 }, { "level": 2, "method": "Ninject.Extensions.Interception.Injection.Dynamic.DynamicMethodInjector.Invoke", "assembly": "Ninject.Extensions.Interception, Version=3.2.0.0, Culture=neutral, PublicKeyToken=c7192dc5380945e7", "line": 0 }, { "level": 3, "method": "Ninject.Extensions.Interception.Invocation.Invocation.CallTargetMethod", "assembly": "Ninject.Extensions.Interception, Version=3.2.0.0, Culture=neutral, PublicKeyToken=c7192dc5380945e7", "line": 0 }, { "level": 4, "method": "Ninject.Extensions.Interception.Invocation.InvocationBase.Proceed", "assembly": "Ninject.Extensions.Interception, Version=3.2.0.0, Culture=neutral, PublicKeyToken=c7192dc5380945e7", "line": 0 }, { "level": 5, "method": "XXXXX.XXXXX.IoC.Ninject.Modules.LoggingInterceptor.Intercept", "assembly": "XXXXX.XXXXX.IoC.Ninject.Modules, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null", "line": 0 }, { "level": 6, "method": "Ninject.Extensions.Interception.Invocation.InvocationBase.Proceed", "assembly": "Ninject.Extensions.Interception, Version=3.2.0.0, Culture=neutral, PublicKeyToken=c7192dc5380945e7", "line": 0 }, { "level": 7, "method": "Ninject.Extensions.Interception.Wrapper.DynamicProxyWrapper.Intercept", "assembly": "Ninject.Extensions.Interception.DynamicProxy, Version=3.2.0.0, Culture=neutral, PublicKeyToken=c7192dc5380945e7", "line": 0 }, { "level": 8, "method": "Castle.DynamicProxy.AbstractInvocation.Proceed", "assembly": "Castle.Core, Version=3.2.0.0, Culture=neutral, PublicKeyToken=407dd0808d44fbdc", "line": 0 }, { "level": 9, "method": "Castle.Proxies.IAbonnementRepositoryProxy.GetDateResiliationPredecesseur", "assembly": "DynamicProxyGenAssembly2, Version=0.0.0.0, Culture=neutral, PublicKeyToken=null", "line": 0 }, { "level": 10, "method": "XXXXX.XXXXX.Domain.Services.AbonnementService.RecupererInformationsTechnique", "assembly": "XXXXX.XXXXX.Domain.Services, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null", "line": 0 }, { "level": 11, "assembly": "Ninject.Extensions.Interception, Version=3.2.0.0, Culture=neutral, PublicKeyToken=c7192dc5380945e7", "line": 0 }, { "level": 12, "method": "Ninject.Extensions.Interception.Injection.Dynamic.DynamicMethodInjector.Invoke", "assembly": "Ninject.Extensions.Interception, Version=3.2.0.0, Culture=neutral, PublicKeyToken=c7192dc5380945e7", "line": 0 }, { "level": 13, "method": "Ninject.Extensions.Interception.Invocation.Invocation.CallTargetMethod", "assembly": "Ninject.Extensions.Interception, Version=3.2.0.0, Culture=neutral, PublicKeyToken=c7192dc5380945e7", "line": 0 }, { "level": 14, "method": "Ninject.Extensions.Interception.Invocation.InvocationBase.Proceed", "assembly": "Ninject.Extensions.Interception, Version=3.2.0.0, Culture=neutral, PublicKeyToken=c7192dc5380945e7", "line": 0 }, { "level": 15, "method": "XXXXX.XXXXX.IoC.Ninject.Modules.LoggingInterceptor.Intercept", "assembly": "XXXXX.XXXXX.IoC.Ninject.Modules, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null", "line": 0 }, { "level": 16, "method": "Ninject.Extensions.Interception.Invocation.InvocationBase.Proceed", "assembly": "Ninject.Extensions.Interception, Version=3.2.0.0, Culture=neutral, PublicKeyToken=c7192dc5380945e7", "line": 0 }, { "level": 17, "method": "Ninject.Extensions.Interception.Wrapper.DynamicProxyWrapper.Intercept", "assembly": "Ninject.Extensions.Interception.DynamicProxy, Version=3.2.0.0, Culture=neutral, PublicKeyToken=c7192dc5380945e7", "line": 0 }, { "level": 18, "method": "Castle.DynamicProxy.AbstractInvocation.Proceed", "assembly": "Castle.Core, Version=3.2.0.0, Culture=neutral, PublicKeyToken=407dd0808d44fbdc", "line": 0 }, { "level": 19, "method": "Castle.Proxies.IAbonnementServiceProxy.RecupererInformationsTechnique", "assembly": "DynamicProxyGenAssembly2, Version=0.0.0.0, Culture=neutral, PublicKeyToken=null", "line": 0 }, { "level": 20, "method": "XXXXX.XXXXX.XXXXX.XXXXX.XXXXX.GetInformationsTechnique", "assembly": "XXXXX.XXXXX.XXXXX, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null", "fileName": "C:\\XXXXX\\XXXXX\\XXXXX\\XXXXX\\XXXXX\\XXXXX.XXXXX.XXXXX\\XXXXX\\XXXXX\\XXXXX.cs", "line": 654 }, { "level": 21, "method": "SyncInvokeGetInformationsTechnique", "assembly": "System.ServiceModel, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089", "line": 0 }, { "level": 22, "method": "System.ServiceModel.Dispatcher.SyncMethodInvoker.Invoke", "assembly": "System.ServiceModel, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089", "line": 0 }, { "level": 23, "method": "XXXXX.XXXXX.XXXXX.AuthorizingOperationInvoker.Invoke", "assembly": "XXXXX.XXXXX.XXXXX, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null", "fileName": "C:\\XXXXX\\XXXXX\\XXXXX\\XXXXX\\XXXXX\\XXXXX.XXXXX.XXXXX\\Technique\\AOP\\AuthorizingOperationBehavior.cs", "line": 180 }, { "level": 24, "method": "XXXXX.XXXXX.XXXXX.ErrorHandlingOperationInvoker.Invoke", "assembly": "XXXXX.XXXXX.XXXXX, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null", "fileName": "C:\\XXXXX\\XXXXX\\XXXXX\\XXXXX\\XXXXX\\XXXXX.XXXXX.XXXXX\\Technique\\AOP\\ErrorHandlingOperationBehavior.cs", "line": 86 }] }], "severityLevel": "Error", "properties": { "layer": "WebServices", "LoggerName": "TraceLogger", "ClientName": "XXXXX", "methodName": "GetInformationsTechnique", "Environnement": "localhost", "UserName": "XXXXX", "className": "XXXXX", "DeveloperMode": "true", "Message": "Exception thrown in below layer by hand", "UserId": "XXXXX", "_MS.ProcessedByMetricExtractors": "(Name:'Exceptions', Ver:'1.1')" } } } }

I don't understand what is wrong. Any idea?

cijothomas commented 3 years ago

related/maybe-same : https://github.com/microsoft/ApplicationInsights-dotnet/issues/2284

Spikrit commented 3 years ago

We are having the same problem here. Also using App Insights + NLog.

It appears that Exceptions with a big StackTrace never reach Azure while manual Exceptions thrown from the same place but hence with lower stack traces are visible in the App Insights Logs, in Azure.

I've tried to debug App Insights and also have 4XX errors for no apparent reason...

I'm pretty sure it's not related to the 32k size limit. Bubleguy telemetry payload is 6.5k so... yeah...

cijothomas commented 3 years ago

You can collect troubleshooting logs, and confirm if the ingestion endpoint rejected any telemetry and see exact reason why it rejected. The related issue is due to the size limit. This will confirm if you are facing the same issue or not.

Spikrit commented 3 years ago

You can collect troubleshooting logs

Yeah, my bad, that's what I meant by "I've tried to debug App Insights"...

Anyway, I tried again and something must have changed on Azure side since the last time i checked because i get more information now. This is the message I get now :

Microsoft.ApplicationInsights.Extensibility.TraceSource Information: 67 : Backend has responded with 206 status code in 643ms. ProcessId=6796 DateTime=2021-07-20T16:31:07.6439943Z Microsoft.ApplicationInsights.Extensibility.TraceSource Verbose: 22 : TransmissionSent. TransmissionId: aKs7WHtzkAg=. Capacity: 0. ProcessId=6796 DateTime=2021-07-20T16:31:07.6499965Z Microsoft.ApplicationInsights.Extensibility.TraceSource Verbose: 70 : Raw response content from AI Backend for Transmission Id aKs7WHtzkAg= : {"itemsReceived":5,"itemsAccepted":4,"errors":[{"index":3,"statusCode":400,"message":"109: Field 'method' on type 'StackFrame' is required but missing or empty. Expected: string, Actual: undefined"}]}. ProcessId=6796 DateTime=2021-07-20T16:31:07.6529761Z Microsoft.ApplicationInsights.Extensibility.TraceSource Warning: 7 : Item was rejected by endpoint. Message: 109: Field 'method' on type 'StackFrame' is required but missing or empty. Expected: string, Actual: undefined ProcessId=6796 DateTime=2021-07-20T16:31:07.6549743Z Microsoft.ApplicationInsights.Extensibility.TraceSource Warning: 7 : Item was rejected by endpoint. Message: 109: Field 'method' on type 'StackFrame' is required but missing or empty. Expected: string, Actual: undefined ProcessId=6796 DateTime=2021-07-20T16:31:07.6579757Z Microsoft.ApplicationInsights.Extensibility.TraceSource Verbose: 3 : [msg=Log verbose];[msg=No Telemetry Items passed to Enqueue]

Which is weird because i don't see any "method" field in the StackFrame class : https://docs.microsoft.com/fr-fr/dotnet/api/system.diagnostics.stackframe?view=net-5.0 or https://docs.microsoft.com/en-us/dotnet/api/microsoft.applicationinsights.datacontracts.stackframe?view=azure-dotnet

I've tried to :

Same message again...

I found that this package "Microsoft.ApplicationInsights.DependencyCollector" uses System.Diagnostics.StackTrace for ".NETStandard 2.0" and "System.Diagnostics.DiagnosticSource" for .Net Framework 4.5.2+ (which is my case).

Tried updating "System.Diagnostics.DiagnosticSource" but nothing changed.

Out of luck, I even tried to update every package starting with "Microsoft.ApplicationInsights" to the last beta version ("2.18.0-beta3") but it doesn't seem to work.

There a few messages about this exact error ("message":"109: Field 'method' on type 'StackFrame' is required but missing or empty") on the Internet, but it's about Cordova : https://social.msdn.microsoft.com/Forums/sqlserver/en-US/a76e4e2f-1066-403a-a338-16055b91f3ab/failed-to-sent-telemetric-error-on-app-crashes-data?forum=ApplicationInsights https://stackoverflow.com/questions/51594138/failed-to-send-telemetry-in-ionic-cordova-mobile-app

...and i'm definitely NOT on Cordova. :/

cijothomas commented 2 years ago

related: https://github.com/microsoft/ApplicationInsights-dotnet/issues/2482

github-actions[bot] commented 1 year ago

This issue is stale because it has been open 300 days with no activity. Remove stale label or this will be closed in 7 days. Commenting will instruct the bot to automatically remove the label.