Skip to content
This repository has been archived by the owner on Oct 12, 2022. It is now read-only.

The parameters to the Event method do not match the parameters to the WriteEvent method - error #97

Closed
norek opened this issue Mar 8, 2017 · 19 comments · Fixed by #98
Closed

Comments

@norek
Copy link

norek commented Mar 8, 2017

Hi, I cant see all requests on azure dashboard. When i attached debuger to service i discovered this message in Output Window:

The parameters to the Event method do not match the parameters to the WriteEvent method. This may cause the event to be displayed incorrectly.

Case study:

  • Every request have the same parameters
  • One request per 2 seconds
  • Only maybe 1 of 10 request is sended to azure correctly, other have error described above.
    I have newest version of SDK. .NET 4.0.
@SergeyKanzhelev
Copy link
Contributor

Which SDK do you use? Can you share list of NuGets with versions. What type is your application?

@norek
Copy link
Author

norek commented Mar 9, 2017

Sure, Its classic WCF hosten by Windows Service
ai_cfg.txt
cfg.txt
packages.txt

@tomasr
Copy link
Contributor

tomasr commented Mar 9, 2017

I've been going over the WCF ETW provider and can't seem to find a scenario that would trigger this error, nor have I been able to reproduce it so far. It could possibly come from any other EventSource class on the process, though.

Also, from looking at the EventSource code, seems like this message would get logged to the output trace, but it shouldn't actually cause the code to fail...

Besides compiling for .NET 4.0, are you running this on a machine that only has .net 4.0, or does it have a newer version?

@tomasr
Copy link
Contributor

tomasr commented Mar 9, 2017

Update: Found the issue. PR with fix coming up. It should only be coming up when a telemetry module failed, so there's definitely an exception that we're trying to log and failing.

@tomasr
Copy link
Contributor

tomasr commented Mar 9, 2017

@norek Once you test the new version with the fix, can you let us know if a) it fully fixes the issue for you, and b) what exception is being recorded in the ETW events that's causing request tracking to fail in your case? Sounds like there's an underlying issue and I'd like to get to the bottom of it ASAP 😄

@norek
Copy link
Author

norek commented Mar 10, 2017

hi, thanks for quick fix.
a) Yes, previous error was fixed but i have other:

Application Insights Telemetry: {"name":"Microsoft.ApplicationInsights.xxxx.Message","time":"2017-03-10T06:33:41.6195116Z","iKey":"xxxx","tags":{"ai.location.ip":"127.0.0.1","ai.operation.name":"testRequest","ai.cloud.roleInstance":"xxx","ai.operation.parentId":"jzfZQchVJBs=","ai.internal.sdkVersion":"dotnet:2.2.0-54035","ai.operation.id":"jzfZQchVJBs=","ai.operation.syntheticSource":"SDKTelemetry"},"data":{"baseType":"MessageData","baseData":{"ver":2,"message":"AI (Internal): WCF Telemetry Module RequestTrackingTelemetryModule failed stage OnEndRequest with exception: test.exe"}}}
WCF Telemetry Module RequestTrackingTelemetryModule failed stage OnEndRequest with exception: test.exe
b) Can you describe simplest way to grab those exceptions?

@tomasr
Copy link
Contributor

tomasr commented Mar 10, 2017

@norek: Thanks. I actually managed to code yet another bug into my EventSource that's causing the message you mentioned to be missing the trace. I'm currently looking at adding some tests to this, as I should've done in the first place!

In the meantime, since it seems you can repro this in the debugger, could you try this? Disable the 'Just my Code" option so that the output window contains all the errors, and then reproduce the problem in the debugger, and then send me a copy of the log? (tomasr @ microsoft). That should tell us at least what exception was triggered....

@norek
Copy link
Author

norek commented Mar 13, 2017

Hi, i investigate problem deeper, i clone you project and attach in debug mode. I find two issues.
a) I got ObjectDisposedException On method HasIncomingMessageProperty in class WCfOperationContext. I dont know why, i was debuging some time and i dont get any sollution.
b) After exception from a) i got an exception causeing this exceptionfailed stage OnEndRequest with exception. RequestTrackingTelemetryModule method OnEndRequest: you are inserting "Protocol" dictionary value to properties, this is causeing ArgumentException. Below my fix:

if (telemetry.Properties.ContainsKey("Protocol"))
{
     telemetry.Properties["Protocol"] = telemetry.Url.Scheme;
}
else {
     telemetry.Properties.Add("Protocol", telemetry.Url.Scheme);
}

After this fix , all request are tracked perfectly. Look at this, it is good solution? I should write some tests to it. What about this DisposedException?

@tomasr
Copy link
Contributor

tomasr commented Mar 13, 2017

@norek Thanks for the report. I've made a couple of changes to prevent this, though the interesting bit here is that this should only happen in two cases: Either we're trying to track the same request object twice (which shouldn't happen) or the user code added a Protocol property to the request already.

We certainly don't want to fail on the second case, but the first one is interesting, and have not figured out a way to repro it yet. I wonder if by any chance you might have the behavior registered twice? (once in config, and also the [ServiceTelemetry] attribute on your service class?

@norek
Copy link
Author

norek commented Mar 14, 2017

Hi, No i dont have any configuration in config file applied. I have only attribute [ServiceTelemetry] above my WCF class and [OperationTelemetery] above methods. But...My service is in SingleContextMode maybe this is causing the problem
[ServiceBehavior(InstanceContextMode = InstanceContextMode.Single, IncludeExceptionDetailInFaults = true)]?
Ill try change it to PerCall.

@tomasr
Copy link
Contributor

tomasr commented Mar 14, 2017

Can you try the latest version and see if that one works better for you? I think I've cleared out all the issues you ran into....

@norek
Copy link
Author

norek commented Mar 14, 2017

Yup, it looks like everything its working perfectly, THANKS!

@nhwilly
Copy link

nhwilly commented Jul 24, 2017

I'm getting the same error, but not on WCF. This is an ASP.NET Core app targeted at 4.61. I turned off Just My Code and got this:

The parameters to the Event method do not match the parameters to the WriteEvent method. This may cause the event to be displayed incorrectly.
Exception thrown: 'System.IO.FileLoadException' in mscorlib.dll
Exception thrown: 'System.IO.FileLoadException' in mscorlib.dll
Exception thrown: 'System.IO.FileLoadException' in mscorlib.dll
Exception thrown: 'System.IO.FileLoadException' in mscorlib.dll
Exception thrown: 'System.DllNotFoundException' in Microsoft.CodeAnalysis.dll
Application Insights Telemetry: {"name":"Microsoft.ApplicationInsights.Dev.1284fd502e674a4cbe07a4c19866931d.Request","time":"2017-07-24T16:00:04.2075101Z","iKey":"1284fd50-2e67-4a4c-be07-a4c19866931d","tags":{"ai.operation.id":"f7affe75-4964168000f3b01f","ai.application.ver":"1.0.0.0","ai.operation.name":"GET Home/Index","ai.location.ip":"::1","ai.user.id":"wZgLk","ai.internal.nodeName":"Solo","ai.internal.sdkVersion":"aspnet5f:2.1.1","ai.session.id":"yGwgh","ai.cloud.roleInstance":"Solo"},"data":{"baseType":"RequestData","baseData":{"ver":2,"id":"|f7affe75-4964168000f3b01f.","name":"GET Home/Index","duration":"00:00:05.0611466","success":true,"responseCode":"200","url":"https://localhost:44353/","properties":{"DeveloperMode":"true","httpMethod":"GET","AspNetCoreEnvironment":"Development"}}}}
Exception thrown: 'System.InvalidOperationException' in System.dll
Exception thrown: 'System.InvalidOperationException' in System.dll
Exception thrown: 'System.InvalidOperationException' in Microsoft.AI.PerfCounterCollector.dll
Exception thrown: 'System.InvalidOperationException' in Microsoft.AI.PerfCounterCollector.dll
Exception thrown: 'System.InvalidOperationException' in System.dll
Exception thrown: 'System.InvalidOperationException' in Microsoft.AI.PerfCounterCollector.dll
Exception thrown: 'System.InvalidOperationException' in Microsoft.AI.PerfCounterCollector.dll
Exception thrown: 'System.InvalidOperationException' in System.dll
Exception thrown: 'System.InvalidOperationException' in Microsoft.AI.PerfCounterCollector.dll
Exception thrown: 'System.InvalidOperationException' in Microsoft.AI.PerfCounterCollector.dll
Application Insights Telemetry: {"name":"Microsoft.ApplicationInsights.Dev.1284fd502e674a4cbe07a4c19866931d.Message","time":"2017-07-24T16:01:06.4888598Z","iKey":"1284fd50-2e67-4a4c-be07-a4c19866931d","tags":{"ai.application.ver":"1.0.0.0","ai.operation.syntheticSource":"SDKTelemetry","ai.cloud.roleInstance":"Solo","ai.internal.sdkVersion":"dotnet:2.4.0-32153"},"data":{"baseType":"MessageData","baseData":{"ver":2,"message":"AI: Error collecting 3 of the configured performance counters. Please check the configuration.\r\nCounter \\ASP.NET Applications(??APP_W3SVC_PROC??)\\Requests/Sec: Failed to perform the first read for performance counter. Please make sure it exists. Category: ASP.NET Applications, counter: Requests/Sec, instance TrustyMvcCore.exe\r\nCounter \\ASP.NET Applications(??APP_W3SVC_PROC??)\\Request Execution Time: Failed to perform the first read for performance counter. Please make sure it exists. Category: ASP.NET Applications, counter: Request Execution Time, instance TrustyMvcCore.exe\r\nCounter \\ASP.NET Applications(??APP_W3SVC_PROC??)\\Requests In Application Queue: Failed to perform the first read for performance counter. Please make sure it exists. Category: ASP.NET Applications, counter: Requests In Application Queue, instance TrustyMvcCore.exe","properties":{"DeveloperMode":"true","AspNetCoreEnvironment":"Development"}}}}

At first I thought it had to do with a custom telemetry logger that I wrote so I could swap out Application Insights if I needed to. But I took that out and now I don't reference any TelemetryClients anywhere in the app and I still get this error.

Am I missing something? Like a DLL? :) I just don't know what I'm supposed to have in there. I brought in all the Nuget packages if wanted. Do you want me to move this to another issue?

@nhwilly
Copy link

nhwilly commented Jul 24, 2017

I believe I may have found the problem. This was originally and ASP.NET MVC Core app that I retargeted to 4.61. As such, the call in program.cs to WebHostBuilder.UseApplicationInsights fails unless Application Insights for ASP.NET Core in installed.

So I ripped out the packages for the web and just left the ones for ASP.NET Core installed. Now I get this:
The parameters to the Event method do not match the parameters to the WriteEvent method. This may cause the event to be displayed incorrectly.

Event 1 was called with 2 argument(s) , but it is defined with 3 paramenter(s).
Exception thrown: 'System.IO.FileLoadException' in mscorlib.dll
Exception thrown: 'System.IO.FileLoadException' in mscorlib.dll
Exception thrown: 'System.IO.FileLoadException' in mscorlib.dll
Exception thrown: 'System.IO.FileLoadException' in mscorlib.dll
Exception thrown: 'System.DllNotFoundException' in Microsoft.CodeAnalysis.dll
Application Insights Telemetry: {"name":"Microsoft.ApplicationInsights.Dev.1284fd502e674a4cbe07a4c19866931d.Request","time":"2017-07-24T16:25:58.8515829Z","iKey":"1284fd50-2e67-4a4c-be07-a4c19866931d","tags":{"ai.operation.id":"239b9bf2-45b4d80a8f4dc213","ai.application.ver":"1.0.0.0","ai.operation.name":"GET Home/Index","ai.location.ip":"::1","ai.user.id":"wZgLk","ai.internal.nodeName":"Solo","ai.internal.sdkVersion":"aspnet5f:2.1.1","ai.session.id":"yGwgh","ai.cloud.roleInstance":"Solo"},"data":{"baseType":"RequestData","baseData":{"ver":2,"id":"|239b9bf2-45b4d80a8f4dc213.","name":"GET Home/Index","duration":"00:00:05.0727767","success":true,"responseCode":"200","url":"https://localhost:44353/","properties":{"DeveloperMode":"true","httpMethod":"GET","AspNetCoreEnvironment":"Development"}}}}

@nhwilly
Copy link

nhwilly commented Jul 24, 2017

And so, I retargeted every project in my solution (!) to netcoreapp1.1 and the "Event" errors went away, but I still get this:

Exception thrown: 'System.IO.FileNotFoundException' in System.Private.CoreLib.ni.dll
Exception thrown: 'System.IO.FileNotFoundException' in System.Private.CoreLib.ni.dll
Exception thrown: 'System.IO.FileNotFoundException' in System.Private.CoreLib.ni.dll
Exception thrown: 'System.IO.FileNotFoundException' in System.Private.CoreLib.ni.dll
Exception thrown: 'System.IO.FileNotFoundException' in System.Private.CoreLib.ni.dll
Exception thrown: 'System.IO.FileNotFoundException' in System.Private.CoreLib.ni.dll
Exception thrown: 'System.IO.FileNotFoundException' in System.Private.CoreLib.ni.dll
Exception thrown: 'System.IO.FileNotFoundException' in System.Private.CoreLib.ni.dll
Exception thrown: 'System.IO.FileNotFoundException' in System.Private.CoreLib.ni.dll
Application Insights Telemetry: {"name":"Microsoft.ApplicationInsights.1284fd502e674a4cbe07a4c19866931d.Request","time":"2017-07-24T17:09:04.9566364Z","iKey":"1284fd50-2e67-4a4c-be07-a4c19866931d","tags":{"ai.cloud.roleInstance":"Solo","ai.operation.id":"e16d91c3-44562a4bcb170ae7","ai.operation.name":"GET Home/Index","ai.application.ver":"1.0.0.0","ai.location.ip":"::1","ai.internal.sdkVersion":"aspnet5c:2.1.1","ai.user.id":"wZgLk","ai.session.id":"yGwgh","ai.internal.nodeName":"Solo"},"data":{"baseType":"RequestData","baseData":{"ver":2,"id":"|e16d91c3-44562a4bcb170ae7.","name":"GET Home/Index","duration":"00:00:04.7206294","success":true,"responseCode":"200","url":"https://localhost:44353/","properties":{"AspNetCoreEnvironment":"Development","httpMethod":"GET"}}}}
Application Insights Telemetry: {"name":"Microsoft.ApplicationInsights.1284fd502e674a4cbe07a4c19866931d.Event","time":"2017-07-24T17:09:22.5632855Z","iKey":"1284fd50-2e67-4a4c-be07-a4c19866931d","tags":{"ai.cloud.roleInstance":"Solo","ai.operation.id":"e16d91c4-44562a4bcb170ae7","ai.operation.name":"POST Invitations/Post","ai.application.ver":"1.0.0.0","ai.internal.sdkVersion":"dotnet:2.4.0-32153","ai.location.ip":"127.0.0.1","ai.user.id":"5f44ec85-d764-4dc3-98d9-7f6da30a93cb","ai.operation.parentId":"|e16d91c4-44562a4bcb170ae7.","ai.internal.nodeName":"Solo"},"data":{"baseType":"EventData","baseData":{"ver":2,"name":"Invitation created","properties":{"accountId":"35bcd58f-17cd-407b-b596-7dbcef8e4989","AspNetCoreEnvironment":"Development","appUserId":"5f44ec85-d764-4dc3-98d9-7f6da30a93cb","telemetryId":"34bf1e9e-d369-48bc-801b-22088aaea760"}}}}
Exception thrown: 'System.IO.FileNotFoundException' in System.Private.CoreLib.ni.dll

I hope these comments help someone, but I'm going to try to proceed with Just My Code enabled and hope someone responds to this. Thanks in advance.

@SergeyKanzhelev
Copy link
Contributor

Hi @nhwilly I think there is a mix of many issues:

The parameters to the Event method do not match the parameters to the WriteEvent method. This may cause the event to be displayed incorrectly.

Seem to be CLR problem explained here microsoft/ApplicationInsights-dotnet-server#608

Exception thrown: 'System.IO.FileNotFoundException' in System.Private.CoreLib.ni.dll

Is this only happens with Application Insights enabled? I doubt we use it in Application Insights so may be something with the code or configuration of your app.

Exception thrown: 'System.DllNotFoundException' in Microsoft.CodeAnalysis.dll

Same here...

Exception thrown: 'System.InvalidOperationException' in Microsoft.AI.PerfCounterCollector.dll

This error saying that some counters will not be collected while running locally. You can remove those from standard configuration to get rid of this message. However it is not harmful at all.

Let me know if it helps or you need more details.

@nhwilly
Copy link

nhwilly commented Jul 25, 2017

@SergeyKanzhelev Thanks for the quick response.

What kicked this off was me starting out with netcoreapp1.1, then discovering that I couldn't use my libraries for Azure Functions (since they don't do Core yet) and just punting and retargeting everything to net461. Sloppy, I know. And then the AI stuff started complaining. So today I decided I'd slog through it and figure it out.

Unfortunately, most of the documentation/posts regarding targeting multiple frameworks seem to reference the json project format, but eventually I did figure out how to target multiple frameworks. That's allowed me to get everything back working again, by targeting the AI Core package for the ASP.NET site and the AI Web package for Azure Functions. Ditto for my own libraries.

So, the good news is that the Event, PerfCounter... and CodeAnalysis... errors have all stopped. So those must have been related to the targeting issues.

I am still getting the 'System.IO.FileNotFoundException' in System.Private.CoreLib.ni.dll errors, just at startup and I can't isolate it to Application Insights, so I think I'll have to bother someone else. Thanks for all your help.

p.s. I am having some difficulty with AI in Azure Functions. Should I post that in this repo or on theirs?

@SergeyKanzhelev
Copy link
Contributor

@nhwilly I think this repo is the best for Azure Functions questions related to Application Insights https://github.com/Azure/azure-webjobs-sdk/issues

@nhwilly
Copy link

nhwilly commented Jul 25, 2017

Thanks.

According to their repo, stackoverflow id preferred. I posted it here: https://stackoverflow.com/questions/45292109/azure-functions-application-insights-custom-telemetry-eventsource-instance

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants