Test failure: tracing_eventsource._eventpipeandetw_eventpipeandetw_eventpipeandetw_/_eventpipeandetw_eventpipeandetw_eventpipeandetw_cmd

Opened on behalf of @Sunny-pu

The test tracing_eventsource._eventpipeandetw_eventpipeandetw_eventpipeandetw_/_eventpipeandetw_eventpipeandetw_eventpipeandetw_cmd has failed.

Unhandled Exception: System.InvalidOperationException: TdhEnumerateProviders failed.\r
   at Microsoft.Diagnostics.Tracing.Session.TraceEventSession.get_ProviderNameToGuid()\r
   at Microsoft.Diagnostics.Tracing.Session.TraceEventProviders.GetProviderGuidByName(String name)\r
   at Microsoft.Diagnostics.Tracing.Session.TraceEventSession.EnableProvider(String providerName, TraceEventLevel providerLevel, UInt64 matchAnyKeywords, TraceEventProviderOptions options)\r
   at Tracing.Tests.EventPipeAndEtw.EnableETW(EventSource eventSource, EventKeywords keywords, String outputFile) in E:\\A\\_work\\138\\s\\tests\\src\\tracing\\eventsource\\eventpipeandetw\\EventPipeAndEtw.cs:line 113\r
   at Tracing.Tests.EventPipeAndEtw.RoundOne(String[] args) in E:\\A\\_work\\138\\s\\tests\\src\\tracing\\eventsource\\eventpipeandetw\\EventPipeAndEtw.cs:line 144\r
   at Tracing.Tests.EventPipeAndEtw.Main(String[] args) in E:\\A\\_work\\138\\s\\tests\\src\\tracing\\eventsource\\eventpipeandetw\\EventPipeAndEtw.cs:line 287


Return code:      1
Raw output file:      C:\\work\\f2125dcf-0985-4d70-b7d0-00824a6edc84\\Work\\c8415983-ece0-46e7-b42d-256fbc794b63\\Unzip\\Reports\\tracing.eventsource\\eventpipeandetw\\eventpipeandetw\\eventpipeandetw.output.txt
Raw output:
BEGIN EXECUTION\r
        1 file(s) copied.\r
\" C:\\work\\f2125dcf-0985-4d70-b7d0-00824a6edc84\\Payload\\crossgen.exe\" /Platform_Assemblies_Paths C:\\work\\f2125dcf-0985-4d70-b7d0-00824a6edc84\\Payload;C:\\work\\f2125dcf-0985-4d70-b7d0-00824a6edc84\\Work\\c8415983-ece0-46e7-b42d-256fbc794b63\\Unzip\\eventpipeandetw\\eventpipeandetw\\IL;C:\\work\\f2125dcf-0985-4d70-b7d0-00824a6edc84\\Work\\c8415983-ece0-46e7-b42d-256fbc794b63\\Unzip\\eventpipeandetw\\eventpipeandetw /in eventpipeandetw.org /out eventpipeandetw.exe\r
Microsoft (R) CoreCLR Native Image Generator - Version 4.5.30319.0\r
Copyright (c) Microsoft Corporation.  All rights reserved.\r
\r
Native image eventpipeandetw.exe generated successfully.\r
 \"C:\\work\\f2125dcf-0985-4d70-b7d0-00824a6edc84\\Payload\\corerun.exe\" eventpipeandetw.exe \r
\tStart: Enable EventPipe.\r
\tEnd: Enable EventPipe.
\r
\tStart: Enable ETW.\r
Expected: 100\r
Actual: -532462766\r
END EXECUTION - FAILED\r
FAILED\r
Test Harness Exitcode is : 1\r

To run the test:
> set CORE_ROOT=C:\\work\\f2125dcf-0985-4d70-b7d0-00824a6edc84\\Payload
> C:\\work\\f2125dcf-0985-4d70-b7d0-00824a6edc84\\Work\\c8415983-ece0-46e7-b42d-256fbc794b63\\Unzip\\eventpipeandetw\\eventpipeandetw\\eventpipeandetw.cmd
\r
Expected: True\r
Actual:   False

    Stack Trace:

Build : 3.0 - 20180806.01 (Ready-To-Run Tests)
Failing configurations:

• Windows.10.Nano.Amd64
  • x64

Details: https://mc.dot.net/#/product/netcore/30/source/official~2Fcoreclr~2Fmaster~2F/type/test~2Ffunctional~2Fr2r~2Fcli~2F/build/20180806.01/workItem/tracing.eventsource.XUnitWrapper/analysis/xunit/tracing_eventsource._eventpipeandetw_eventpipeandetw_eventpipeandetw_~2F_eventpipeandetw_eventpipeandetw_eventpipeandetw_cmd

[BruceForstall]

@brianrob

[brianrob]

@vancem, do you know what would cause this? Note, that this is on Nanoserver.

It looks like this is the code that's failing in TraceEvent: https://github.com/Microsoft/perfview/blob/375203fb2ee2aae6f1b34154669558aca2492050/src/TraceEvent/TraceEventSession.cs#L1297

[benaadams]

Windows.10.Amd64.Open-x64-Checked-no_tiered_compilation

Unhandled Exception: System.Exception: Values for 'EventPipeEvent2Count' are not equal! Left='0' Right='1'
   at Tracing.Tests.Common.Assert.Equal[T](String name, T left, T right)
   at Tracing.Tests.EventPipeAndEtw.RoundOne(String[] args)
   at Tracing.Tests.EventPipeAndEtw.Main(String[] args)


Return code:      1
Raw output file:      C:\\dotnetbuild\\work\\86f559f3-d582-43c4-b980-20ef3be71c26\\Work\\62e94f6d-dad6-4c5a-8d01-6810f06ad109\\Exec\\Reports\\tracing.eventsource\\eventpipeandetw\\eventpipeandetw\\eventpipeandetw.output.txt
Raw output:
BEGIN EXECUTION
 \"C:\\dotnetbuild\\work\\86f559f3-d582-43c4-b980-20ef3be71c26\\Payload\\corerun.exe\" eventpipeandetw.exe 
\tStart: Enable EventPipe.
\tEnd: Enable EventPipe.

\tStart: Enable ETW.
\tEnd: Enable ETW.

\tStart: Write events.
\tEnd: Writing events.

\tStart: Disable ETW.
\tEnd: Disable ETW.

\tStart: Write events.
\tEnd: Writing events.

\tStart: Disable EventPipe.
\tEnd: Disable EventPipe.

\tStart: Processing events from EventPipe file.

\tEventPipe Results:
\t\tEvent1Count: 2
\t\tEvent2Count: 0
\t\tEvent3Count: 2


\tEnd: Processing events from EventPipe file.

\tStart: Processing events from ETW file.

\tETW Results:
\t\tEvent1Count: 0
\t\tEvent2Count: 0
\t\tEvent3Count: 0


Expected: 100
Actual: -532462766
END EXECUTION - FAILED
FAILED
Test Harness Exitcode is : 1

To run the test:
> set CORE_ROOT=C:\\dotnetbuild\\work\\86f559f3-d582-43c4-b980-20ef3be71c26\\Payload
> C:\\dotnetbuild\\work\\86f559f3-d582-43c4-b980-20ef3be71c26\\Work\\62e94f6d-dad6-4c5a-8d01-6810f06ad109\\Exec\\eventpipeandetw\\eventpipeandetw\\eventpipeandetw.cmd

Expected: True
Actual:   False

https://mc.dot.net/#/user/coreclr-pulls/pr~2Fdotnet~2Fcoreclr~2Frefs~2Fpull~2F22187~2Fmerge/test~2Ffunctional~2Fcli~2Fpri0/20190202.716/workItem/tracing.eventsource/analysis/xunit/tracing_eventsource._eventpipeandetw_eventpipeandetw_eventpipeandetw_~2F_eventpipeandetw_eventpipeandetw_eventpipeandetw_cmd

[BruceForstall]

@brianrob who "owns" this test now?

[vancem]

I believe @jorive owns this now.

[brianrob]

Yes, @jorive and/or @noahfalk.

[vancem]

@jorive - This is actually an issue with the TraceEvent library. It seems we are running on Windows Nano AMD64, and the TdhEnumerateProviders is probably not supported there, which is causing the issue.

Do we know if this works on any other Window Nano configuration?

It turns out that the return value of this API is not actually needed for what the test is doing (it is looking up name->GUID mappings, but the test needs EventSources, which never use the OS mappings (but it checks the OS first). I can make this simply give up in this case. I am making a version of TraceEvent that does this.

It will be TraceEvent 2.0.36, you will need to upgrade to that.

[benaadams]

Test failed on Windows.10.Amd64.Open-x64 also though differently https://github.com/dotnet/coreclr/issues/19302#issuecomment-460021040

[benaadams]

Again in different PR dotnet/coreclr#22397; fails on coreclr-ci

Test Pri0 Windows_NT x64 checked Job
Agent: a0000PB
Windows.10.Amd64.Open-x64-Checked-no_tiered_compilation

https://mc.dot.net/#/user/coreclr-pulls/pr~2Fdotnet~2Fcoreclr~2Frefs~2Fpull~2F22397~2Fmerge/test~2Ffunctional~2Fcli~2Fpri0/20190204.715/workItem/tracing.eventsource/analysis/xunit/tracing_eventsource._eventpipeandetw_eventpipeandetw_eventpipeandetw_~2F_eventpipeandetw_eventpipeandetw_eventpipeandetw_cmd

Error as above

Unhandled Exception: System.Exception: Values for 'EventPipeEvent2Count' are not equal! Left='0' Right='1'
   at Tracing.Tests.Common.Assert.Equal[T](String name, T left, T right)
   at Tracing.Tests.EventPipeAndEtw.RoundOne(String[] args)
   at Tracing.Tests.EventPipeAndEtw.Main(String[] args)

[vancem]

Note that the failures @benaadams just listed are definitely a different issue (I suspect they are also non-deterministic). I am assuming that this failure IS deterministic (can anyone comment on that?)

@jorive - I have uploaded version 2.0.36 to nuget.org that has the fix. Try that.

We should also look into the failures that @benaadams has pointed out.

[RussKeldorph]

Another example: https://mc.dot.net/#/user/coreclr-ci/pr~2Fdotnet~2Fcoreclr~2Frefs~2Fpull~2F22860~2Fmerge/test~2Ffunctional~2Fcli~2F/20190226.756/workItem/tracing.eventsource/analysis/xunit/tracing_eventsource._eventpipeandetw_eventpipeandetw_eventpipeandetw_~2F_eventpipeandetw_eventpipeandetw_eventpipeandetw_cmd

@vancem @jorive @noahfalk This test is regularly causing both official build and PRs to spuriously fail. Could we disable the test against this issue and investigate as time allows?

[vancem]

@RussKeldorph Can you comment on the frequency of this causing grief?

@jorive can you disable the test until you hav time to look at the issue?

@RussKeldorph Note that what Jose will do is instrument the code and run it alot in a loop, but if that does not reproduce the problem he is likely to need to enable the test again (so he can get more information from his instrumentation).

[jorive]

@vancem OK, will do.

[jorive]

@vancem I'll try your new package 2.0.36 first.