EventLog tests failing on Windows 11 and Windows Server 2022

[wfurt]

https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-58570-merge-82d3210ae65b4c7bab/System.Diagnostics.EventLog.Tests/1/console.22fc633f.log?sv=2019-07-07&se=2021-09-28T19%3A09%3A59Z&sr=c&sp=rl&sig=c9WGUmQHt%2FIcFz23yiVBOPIXos7SuYjCtPHDRupOcxA%3D

C:\h\w\B1F40A27\w\A62108FB\e>"C:\h\w\B1F40A27\p\dotnet.exe" exec --runtimeconfig System.Diagnostics.EventLog.Tests.runtimeconfig.json --depsfile System.Diagnostics.EventLog.Tests.deps.json xunit.console.dll System.Diagnostics.EventLog.Tests.dll -xml testResults.xml -nologo -nocolor -notrait category=IgnoreForCI -notrait category=OuterLoop -notrait category=failing  
  Discovering: System.Diagnostics.EventLog.Tests (method display = ClassAndMethod, method display options = None)
  Discovered:  System.Diagnostics.EventLog.Tests (found 90 of 122 test cases)
  Starting:    System.Diagnostics.EventLog.Tests (parallel test collections = on, max threads = 2)
    System.Diagnostics.Tests.EventLogConfigurationTests.SetProperties_SaveChanges_NotAdmin_Throws [SKIP]
      Condition(s) not met: "NotElevatedAndSupportsEventLogs"
    System.Diagnostics.Tests.EventLogRecordTests.ExceptionOnce [FAIL]
      System.Diagnostics.Eventing.Reader.EventLogException : The system cannot find message text for message number 0x%1 in the message file for %2.
      Stack Trace:
        /_/src/libraries/System.Diagnostics.EventLog/src/System/Diagnostics/Reader/EventLogException.cs(46,0): at System.Diagnostics.Eventing.Reader.EventLogException.Throw(Int32 errorCode)
        /_/src/libraries/System.Diagnostics.EventLog/src/System/Diagnostics/Reader/NativeWrapper.cs(916,0): at System.Diagnostics.Eventing.Reader.NativeWrapper.EvtFormatMessageRenderName(EventLogHandle pmHandle, EventLogHandle eventHandle, EvtFormatMessageFlags flag)
        /_/src/libraries/System.Diagnostics.EventLog/src/System/Diagnostics/Reader/ProviderMetadataCachedInformation.cs(239,0): at System.Diagnostics.Eventing.Reader.ProviderMetadataCachedInformation.GetTaskDisplayName(String ProviderName, EventLogHandle eventHandle)
        /_/src/libraries/System.Diagnostics.EventLog/src/System/Diagnostics/Reader/EventLogRecord.cs(353,0): at System.Diagnostics.Eventing.Reader.EventLogRecord.get_TaskDisplayName()
        /_/src/libraries/System.Diagnostics.EventLog/tests/System/Diagnostics/Reader/EventLogRecordTests.cs(104,0): at System.Diagnostics.Tests.EventLogRecordTests.<>c__DisplayClass4_1.<ExceptionOnce>b__2()
        /_/src/libraries/System.Diagnostics.EventLog/tests/System/Diagnostics/Reader/EventLogRecordTests.cs(116,0): at System.Diagnostics.Tests.EventLogRecordTests.ThrowsMaxOnce[T](Action action)
        /_/src/libraries/System.Diagnostics.EventLog/tests/System/Diagnostics/Reader/EventLogRecordTests.cs(104,0): at System.Diagnostics.Tests.EventLogRecordTests.ExceptionOnce()
    System.Diagnostics.Tests.ProviderMetadataTests.ProviderNameTests(noProviderName: True) [FAIL]
      System.Diagnostics.Eventing.Reader.EventLogNotFoundException : The system cannot find the file specified.
      Stack Trace:
        /_/src/libraries/System.Diagnostics.EventLog/src/System/Diagnostics/Reader/EventLogException.cs(25,0): at System.Diagnostics.Eventing.Reader.EventLogException.Throw(Int32 errorCode)
        /_/src/libraries/System.Diagnostics.EventLog/src/System/Diagnostics/Reader/NativeWrapper.cs(144,0): at System.Diagnostics.Eventing.Reader.NativeWrapper.EvtOpenEventMetadataEnum(EventLogHandle ProviderMetadata, Int32 flags)
        /_/src/libraries/System.Diagnostics.EventLog/src/System/Diagnostics/Reader/ProviderMetadata.cs(495,0): at System.Diagnostics.Eventing.Reader.ProviderMetadata.get_Events()
        /_/src/libraries/System.Diagnostics.EventLog/tests/System/Diagnostics/Reader/ProviderMetadataTests.cs(40,0): at System.Diagnostics.Tests.ProviderMetadataTests.ProviderNameTests(Boolean noProviderName)
    System.Diagnostics.Tests.ProviderMetadataTests.ProviderNameTests(noProviderName: False) [FAIL]
      System.Diagnostics.Eventing.Reader.EventLogNotFoundException : The system cannot find the file specified.
      Stack Trace:
        /_/src/libraries/System.Diagnostics.EventLog/src/System/Diagnostics/Reader/EventLogException.cs(25,0): at System.Diagnostics.Eventing.Reader.EventLogException.Throw(Int32 errorCode)
        /_/src/libraries/System.Diagnostics.EventLog/src/System/Diagnostics/Reader/NativeWrapper.cs(144,0): at System.Diagnostics.Eventing.Reader.NativeWrapper.EvtOpenEventMetadataEnum(EventLogHandle ProviderMetadata, Int32 flags)
        /_/src/libraries/System.Diagnostics.EventLog/src/System/Diagnostics/Reader/ProviderMetadata.cs(495,0): at System.Diagnostics.Eventing.Reader.ProviderMetadata.get_Events()
        /_/src/libraries/System.Diagnostics.EventLog/tests/System/Diagnostics/Reader/ProviderMetadataTests.cs(40,0): at System.Diagnostics.Tests.ProviderMetadataTests.ProviderNameTests(Boolean noProviderName)
  Finished:    System.Diagnostics.EventLog.Tests
=== TEST EXECUTION SUMMARY ===
   System.Diagnostics.EventLog.Tests  Total: 106, Errors: 0, Failed: 3, Skipped: 1, Time: 40.801s

locally, I was able to reproduce only on failure on Insider Preview build.

[danmoseley]

We already added 2 new ones in #57804

Looks like we now need to add ERROR_MR_MID_NOT_FOUND

@dotnet/area-system-diagnostics-eventlog if this is consistent on Windows 11, it might be a 6.0 candidate.

[danmoseley]

Not sure what is special about these two tests..?

[wfurt]

I don't know either. This is not my area so I'm disabling the failing tests in #58570 so we can at least add the new test queue.

[danmoseley]

Sounds good. It sounds like you ran all our tests on Win11 not just networking (cc @jeffhandley ) -- appreciate you doing that. Seems we're largely in a good state.

[danmoseley]

I believe we just need someone to do a PR with ERROR_MR_MID_NOT_FOUND added next to these two lines: https://github.com/dotnet/runtime/search?q=ERROR_EVT_MESSAGE_NOT_FOUND

Presumably by someone with Windows 11 installed so they can verify and undisable the test.

[danmoseley]

@wfurt I don't have Windows 11. Do you have a few minutes to try the change above? I am happy to make the PR if it works on your machine.

[wfurt]

I'm not 100% what the value should be. I made the suggested change and I get

      System.Diagnostics.Tests.EventLogRecordTests.ExceptionOnce [FAIL]
        System.Diagnostics.Eventing.Reader.EventLogException : Invalid access to memory location
        Stack Trace:
             at System.Diagnostics.Eventing.Reader.EventLogException.Throw(Int32 errorCode)
             at System.Diagnostics.Eventing.Reader.NativeWrapper.EvtFormatMessageRenderName(EventLogHandle pmHandle, EventLogHandle eventHandle, EvtFormatMessageFlags flag)
             at System.Diagnostics.Eventing.Reader.ProviderMetadataCachedInformation.GetLevelDisplayName(String ProviderName, EventLogHandle eventHandle)
             at System.Diagnostics.Eventing.Reader.EventLogRecord.get_LevelDisplayName()
          C:\Users\test\github\wfurt-runtime\src\libraries\System.Diagnostics.EventLog\tests\System\Diagnostics\Reader\EventLogRecordTests.cs(102,0): at System.Diagnostics.Tests.EventLogRecordTests.<>c__DisplayClass4_1.<ExceptionOnce>b__0()
          C:\Users\test\github\wfurt-runtime\src\libraries\System.Diagnostics.EventLog\tests\System\Diagnostics\Reader\EventLogRecordTests.cs(116,0): at System.Diagnostics.Tests.EventLogRecordTests.ThrowsMaxOnce[T](Action action)
          C:\Users\test\github\wfurt-runtime\src\libraries\System.Diagnostics.EventLog\tests\System\Diagnostics\Reader\EventLogRecordTests.cs(102,0): at System.Diagnostics.Tests.EventLogRecordTests.ExceptionOnce()

I'd be happy to run more tests if you need me to @danmoseley

You can also create exact VM here.
With few clicks not as easy as old repro tool but still pretty slick.

[danmoseley]

Oh, too bad (and suggests Windows 11 bug). Well, this will need investigation. Since most of the tests are passing - it may not be to concerning right now.

[danmoseley]

BTW I created a new os-windows11 label that might help us keep track of issues specific to this OS

[Robo210]

IIRC, ERROR_MR_MID_NOT_FOUND is not an expected return code from EvtRender or EvtFormatMessage. There is a known issue in Windows Server 2022 where this error code could incorrectly be returned, but that has been fixed via Windows Update. I am not aware of any similar issues in Windows 11, so feel free to reach out to the ETW team within MS and we can investigate and track the issue further from the Windows side.

[mdh1418]

Hit the first exception System.Diagnostics.Tests.EventLogRecordTests.ExceptionOnce in an unrelated PR #64952 on lane Libraries Test Run release coreclr windows x86 Release
Build: https://dev.azure.com/dnceng/public/_build/results?buildId=1606293&view=logs&j=457f7e88-dfa2-5bd9-f871-fdf124c2477d&t=bfe52dfb-2099-5c7f-ee52-70a1d81c544e&s=96ac2280-8cb4-5df5-99de-dd2da759617d
Log: https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-64952-merge-bb663c35c087459bb8/System.Diagnostics.EventLog.Tests/1/console.6fde3b12.log?sv=2019-07-07&se=2022-03-03T01%3A58%3A49Z&sr=c&sp=rl&sig=8twS3bwRjJKf0aJthzMSrl8XnyO1gthfCqRNFarRKm0%3D

[elinor-fung]

Hit the System.Diagnostics.Tests.EventLogRecordTests.ExceptionOnce failure in another run on Windows Server 2022: https://dev.azure.com/dnceng/public/_build/results?buildId=1616198&view=ms.vss-test-web.build-test-results-tab&runId=44972004&resultId=123558&paneView=dotnet-dnceng.dnceng-build-release-tasks.helix-test-information-tab

System.Diagnostics.Tests.EventLogRecordTests.ExceptionOnce [FAIL]
  System.Diagnostics.Eventing.Reader.EventLogException : The system cannot find message text for message number 0x%1 in the message file for %2.
  Stack Trace:
    /_/src/libraries/System.Diagnostics.EventLog/src/System/Diagnostics/Reader/EventLogException.cs(46,0): at System.Diagnostics.Eventing.Reader.EventLogException.Throw(Int32 errorCode)
    /_/src/libraries/System.Diagnostics.EventLog/src/System/Diagnostics/Reader/NativeWrapper.cs(926,0): at System.Diagnostics.Eventing.Reader.NativeWrapper.EvtFormatMessageRenderName(EventLogHandle pmHandle, EventLogHandle eventHandle, EvtFormatMessageFlags flag)
    /_/src/libraries/System.Diagnostics.EventLog/src/System/Diagnostics/Reader/ProviderMetadataCachedInformation.cs(239,0): at System.Diagnostics.Eventing.Reader.ProviderMetadataCachedInformation.GetTaskDisplayName(String ProviderName, EventLogHandle eventHandle)
    /_/src/libraries/System.Diagnostics.EventLog/src/System/Diagnostics/Reader/EventLogRecord.cs(353,0): at System.Diagnostics.Eventing.Reader.EventLogRecord.get_TaskDisplayName()
    /_/src/libraries/System.Diagnostics.EventLog/tests/System/Diagnostics/Reader/EventLogRecordTests.cs(105,0): at System.Diagnostics.Tests.EventLogRecordTests.<>c__DisplayClass4_0.<ExceptionOnce>b__2()
    /_/src/libraries/System.Diagnostics.EventLog/tests/System/Diagnostics/Reader/EventLogRecordTests.cs(117,0): at System.Diagnostics.Tests.EventLogRecordTests.ThrowsMaxOnce[T](Action action)
    /_/src/libraries/System.Diagnostics.EventLog/tests/System/Diagnostics/Reader/EventLogRecordTests.cs(105,0): at System.Diagnostics.Tests.EventLogRecordTests.ExceptionOnce()

Console log

[elinor-fung]

The failure in System.Diagnostics.Tests.EventLogRecordTests.ExceptionOnce is being hit a decent amount on Windows Server 2022. Kusto data is showing 25 failures in the last 7 days.

@dotnet/area-system-diagnostics-eventlog I just realized that that test was disabled for Windows 11. Is there any more information on what was happening? Should we also disable for Windows Server 2022?

TestResults
| where Result == "Fail"
| where Type == "System.Diagnostics.Tests.EventLogRecordTests" and Method == "ExceptionOnce"
| where Message contains "The system cannot find message text"
| join kind=inner Jobs on JobId
| where Queued > ago(7d)
| project
  QueueName, Queued,
  Type, Method, Message,
  PhaseName = tostring(parse_json(Properties)["System.PhaseName"]),
  Pipeline = tostring(parse_json(Properties).DefinitionName),
  Source,
  Build = tostring(parse_json(Properties).BuildNumber)
| order by Queued desc

[danmoseley]

Disabled test, no evidence of major issue. moving to Future.