System.Diagnostics.Tests.EventLogWriteEntryTests.WriteEvent failing with System.ComponentModel.Win32Exception

[ahsonkhan]

From dotnet/corefx#41845
https://dev.azure.com/dnceng/public/_build/results?buildId=395966

Failing on netfx-Windows_NT-Release-x86-Windows.10.Amd64.Client19H1.Open

System.Diagnostics.Tests.EventLogWriteEntryTests.WriteEvent(SourceFlag: True)
System.Diagnostics.Tests.EventLogWriteEntryTests.WriteEvent(SourceFlag: False)

System.ComponentModel.Win32Exception : A device attached to the system is not functioning

https://helix.dot.net/api/2019-06-17/jobs/84405ce3-2c71-4840-8ff8-d714579059b2/workitems/System.Diagnostics.EventLog.Tests/console

    System.Diagnostics.Tests.EventLogConfigurationTests.SetProperties_SaveChanges_NotAdmin_Throws [SKIP]
      Condition(s) not met: "NotElevatedAndSupportsEventLogs"
    System.Diagnostics.Tests.EventLogWriteEntryTests.WriteEvent(SourceFlag: False) [FAIL]
      System.AggregateException : One or more errors occurred.
      ---- System.ComponentModel.Win32Exception : A device attached to the system is not functioning
      ---- System.ComponentModel.Win32Exception : A device attached to the system is not functioning
      ---- System.ComponentModel.Win32Exception : A device attached to the system is not functioning
      ---- System.ComponentModel.Win32Exception : A device attached to the system is not functioning
      ---- System.ComponentModel.Win32Exception : A device attached to the system is not functioning
      ---- System.ComponentModel.Win32Exception : A device attached to the system is not functioning
      ---- System.ComponentModel.Win32Exception : A device attached to the system is not functioning
      ---- System.ComponentModel.Win32Exception : A device attached to the system is not functioning
      ---- System.ComponentModel.Win32Exception : A device attached to the system is not functioning
      ---- System.ComponentModel.Win32Exception : A device attached to the system is not functioning
      Stack Trace:
        /_/src/Common/tests/CoreFx.Private.TestUtilities/System/RetryHelper.cs(45,0): at System.RetryHelper.Execute(Action test, Int32 maxAttempts, Func`2 backoffFunc)
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(35,0): at System.Diagnostics.Tests.Helpers.Retry[T](Func`1 func)
        /_/src/System.Diagnostics.EventLog/tests/EventLogTests/EventLogWriteEntryTests.cs(328,0): at System.Diagnostics.Tests.EventLogWriteEntryTests.WriteEvent(Boolean SourceFlag)
        ----- Inner Stack Trace dotnet/corefx#1 (System.ComponentModel.Win32Exception) -----
           at System.Diagnostics.EventLogInternal.Clear()
           at System.Diagnostics.EventLog.Delete(String logName, String machineName)
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(23,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass6_0.<Retry>b__0()
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(32,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass7_0`1.<Retry>b__0()
        /_/src/Common/tests/CoreFx.Private.TestUtilities/System/RetryHelper.cs(37,0): at System.RetryHelper.Execute(Action test, Int32 maxAttempts, Func`2 backoffFunc)
        ----- Inner Stack Trace dotnet/corefx#2 (System.ComponentModel.Win32Exception) -----
           at System.Diagnostics.EventLogInternal.Clear()
           at System.Diagnostics.EventLog.Delete(String logName, String machineName)
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(23,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass6_0.<Retry>b__0()
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(32,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass7_0`1.<Retry>b__0()
        /_/src/Common/tests/CoreFx.Private.TestUtilities/System/RetryHelper.cs(37,0): at System.RetryHelper.Execute(Action test, Int32 maxAttempts, Func`2 backoffFunc)
        ----- Inner Stack Trace dotnet/corefx#3 (System.ComponentModel.Win32Exception) -----
           at System.Diagnostics.EventLogInternal.Clear()
           at System.Diagnostics.EventLog.Delete(String logName, String machineName)
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(23,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass6_0.<Retry>b__0()
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(32,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass7_0`1.<Retry>b__0()
        /_/src/Common/tests/CoreFx.Private.TestUtilities/System/RetryHelper.cs(37,0): at System.RetryHelper.Execute(Action test, Int32 maxAttempts, Func`2 backoffFunc)
        ----- Inner Stack Trace dotnet/corefx#4 (System.ComponentModel.Win32Exception) -----
           at System.Diagnostics.EventLogInternal.Clear()
           at System.Diagnostics.EventLog.Delete(String logName, String machineName)
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(23,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass6_0.<Retry>b__0()
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(32,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass7_0`1.<Retry>b__0()
        /_/src/Common/tests/CoreFx.Private.TestUtilities/System/RetryHelper.cs(37,0): at System.RetryHelper.Execute(Action test, Int32 maxAttempts, Func`2 backoffFunc)
        ----- Inner Stack Trace dotnet/corefx#5 (System.ComponentModel.Win32Exception) -----
           at System.Diagnostics.EventLogInternal.Clear()
           at System.Diagnostics.EventLog.Delete(String logName, String machineName)
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(23,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass6_0.<Retry>b__0()
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(32,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass7_0`1.<Retry>b__0()
        /_/src/Common/tests/CoreFx.Private.TestUtilities/System/RetryHelper.cs(37,0): at System.RetryHelper.Execute(Action test, Int32 maxAttempts, Func`2 backoffFunc)
        ----- Inner Stack Trace dotnet/corefx#6 (System.ComponentModel.Win32Exception) -----
           at System.Diagnostics.EventLogInternal.Clear()
           at System.Diagnostics.EventLog.Delete(String logName, String machineName)
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(23,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass6_0.<Retry>b__0()
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(32,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass7_0`1.<Retry>b__0()
        /_/src/Common/tests/CoreFx.Private.TestUtilities/System/RetryHelper.cs(37,0): at System.RetryHelper.Execute(Action test, Int32 maxAttempts, Func`2 backoffFunc)
        ----- Inner Stack Trace dotnet/corefx#7 (System.ComponentModel.Win32Exception) -----
           at System.Diagnostics.EventLogInternal.Clear()
           at System.Diagnostics.EventLog.Delete(String logName, String machineName)
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(23,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass6_0.<Retry>b__0()
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(32,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass7_0`1.<Retry>b__0()
        /_/src/Common/tests/CoreFx.Private.TestUtilities/System/RetryHelper.cs(37,0): at System.RetryHelper.Execute(Action test, Int32 maxAttempts, Func`2 backoffFunc)
        ----- Inner Stack Trace dotnet/corefx#8 (System.ComponentModel.Win32Exception) -----
           at System.Diagnostics.EventLogInternal.Clear()
           at System.Diagnostics.EventLog.Delete(String logName, String machineName)
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(23,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass6_0.<Retry>b__0()
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(32,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass7_0`1.<Retry>b__0()
        /_/src/Common/tests/CoreFx.Private.TestUtilities/System/RetryHelper.cs(37,0): at System.RetryHelper.Execute(Action test, Int32 maxAttempts, Func`2 backoffFunc)
        ----- Inner Stack Trace dotnet/corefx#9 (System.ComponentModel.Win32Exception) -----
           at System.Diagnostics.EventLogInternal.Clear()
           at System.Diagnostics.EventLog.Delete(String logName, String machineName)
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(23,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass6_0.<Retry>b__0()
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(32,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass7_0`1.<Retry>b__0()
        /_/src/Common/tests/CoreFx.Private.TestUtilities/System/RetryHelper.cs(37,0): at System.RetryHelper.Execute(Action test, Int32 maxAttempts, Func`2 backoffFunc)
        ----- Inner Stack Trace dotnet/corefx#10 (System.ComponentModel.Win32Exception) -----
           at System.Diagnostics.EventLogInternal.Clear()
           at System.Diagnostics.EventLog.Delete(String logName, String machineName)
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(23,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass6_0.<Retry>b__0()
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(32,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass7_0`1.<Retry>b__0()
        /_/src/Common/tests/CoreFx.Private.TestUtilities/System/RetryHelper.cs(37,0): at System.RetryHelper.Execute(Action test, Int32 maxAttempts, Func`2 backoffFunc)
    System.Diagnostics.Tests.EventLogWriteEntryTests.WriteEvent(SourceFlag: True) [FAIL]
      System.AggregateException : One or more errors occurred.
      ---- System.ComponentModel.Win32Exception : A device attached to the system is not functioning
      ---- System.ComponentModel.Win32Exception : A device attached to the system is not functioning
      ---- System.ComponentModel.Win32Exception : A device attached to the system is not functioning
      ---- System.ComponentModel.Win32Exception : A device attached to the system is not functioning
      ---- System.ComponentModel.Win32Exception : A device attached to the system is not functioning
      ---- System.ComponentModel.Win32Exception : A device attached to the system is not functioning
      ---- System.ComponentModel.Win32Exception : A device attached to the system is not functioning
      ---- System.ComponentModel.Win32Exception : A device attached to the system is not functioning
      ---- System.ComponentModel.Win32Exception : A device attached to the system is not functioning
      ---- System.ComponentModel.Win32Exception : A device attached to the system is not functioning
      Stack Trace:
        /_/src/Common/tests/CoreFx.Private.TestUtilities/System/RetryHelper.cs(45,0): at System.RetryHelper.Execute(Action test, Int32 maxAttempts, Func`2 backoffFunc)
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(35,0): at System.Diagnostics.Tests.Helpers.Retry[T](Func`1 func)
        /_/src/System.Diagnostics.EventLog/tests/EventLogTests/EventLogWriteEntryTests.cs(328,0): at System.Diagnostics.Tests.EventLogWriteEntryTests.WriteEvent(Boolean SourceFlag)
        ----- Inner Stack Trace dotnet/corefx#1 (System.ComponentModel.Win32Exception) -----
           at System.Diagnostics.EventLogInternal.Clear()
           at System.Diagnostics.EventLog.Delete(String logName, String machineName)
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(23,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass6_0.<Retry>b__0()
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(32,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass7_0`1.<Retry>b__0()
        /_/src/Common/tests/CoreFx.Private.TestUtilities/System/RetryHelper.cs(37,0): at System.RetryHelper.Execute(Action test, Int32 maxAttempts, Func`2 backoffFunc)
        ----- Inner Stack Trace dotnet/corefx#2 (System.ComponentModel.Win32Exception) -----
           at System.Diagnostics.EventLogInternal.Clear()
           at System.Diagnostics.EventLog.Delete(String logName, String machineName)
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(23,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass6_0.<Retry>b__0()
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(32,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass7_0`1.<Retry>b__0()
        /_/src/Common/tests/CoreFx.Private.TestUtilities/System/RetryHelper.cs(37,0): at System.RetryHelper.Execute(Action test, Int32 maxAttempts, Func`2 backoffFunc)
        ----- Inner Stack Trace dotnet/corefx#3 (System.ComponentModel.Win32Exception) -----
           at System.Diagnostics.EventLogInternal.Clear()
           at System.Diagnostics.EventLog.Delete(String logName, String machineName)
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(23,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass6_0.<Retry>b__0()
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(32,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass7_0`1.<Retry>b__0()
        /_/src/Common/tests/CoreFx.Private.TestUtilities/System/RetryHelper.cs(37,0): at System.RetryHelper.Execute(Action test, Int32 maxAttempts, Func`2 backoffFunc)
        ----- Inner Stack Trace dotnet/corefx#4 (System.ComponentModel.Win32Exception) -----
           at System.Diagnostics.EventLogInternal.Clear()
           at System.Diagnostics.EventLog.Delete(String logName, String machineName)
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(23,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass6_0.<Retry>b__0()
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(32,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass7_0`1.<Retry>b__0()
        /_/src/Common/tests/CoreFx.Private.TestUtilities/System/RetryHelper.cs(37,0): at System.RetryHelper.Execute(Action test, Int32 maxAttempts, Func`2 backoffFunc)
        ----- Inner Stack Trace dotnet/corefx#5 (System.ComponentModel.Win32Exception) -----
           at System.Diagnostics.EventLogInternal.Clear()
           at System.Diagnostics.EventLog.Delete(String logName, String machineName)
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(23,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass6_0.<Retry>b__0()
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(32,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass7_0`1.<Retry>b__0()
        /_/src/Common/tests/CoreFx.Private.TestUtilities/System/RetryHelper.cs(37,0): at System.RetryHelper.Execute(Action test, Int32 maxAttempts, Func`2 backoffFunc)
        ----- Inner Stack Trace dotnet/corefx#6 (System.ComponentModel.Win32Exception) -----
           at System.Diagnostics.EventLogInternal.Clear()
           at System.Diagnostics.EventLog.Delete(String logName, String machineName)
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(23,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass6_0.<Retry>b__0()
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(32,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass7_0`1.<Retry>b__0()
        /_/src/Common/tests/CoreFx.Private.TestUtilities/System/RetryHelper.cs(37,0): at System.RetryHelper.Execute(Action test, Int32 maxAttempts, Func`2 backoffFunc)
        ----- Inner Stack Trace dotnet/corefx#7 (System.ComponentModel.Win32Exception) -----
           at System.Diagnostics.EventLogInternal.Clear()
           at System.Diagnostics.EventLog.Delete(String logName, String machineName)
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(23,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass6_0.<Retry>b__0()
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(32,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass7_0`1.<Retry>b__0()
        /_/src/Common/tests/CoreFx.Private.TestUtilities/System/RetryHelper.cs(37,0): at System.RetryHelper.Execute(Action test, Int32 maxAttempts, Func`2 backoffFunc)
        ----- Inner Stack Trace dotnet/corefx#8 (System.ComponentModel.Win32Exception) -----
           at System.Diagnostics.EventLogInternal.Clear()
           at System.Diagnostics.EventLog.Delete(String logName, String machineName)
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(23,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass6_0.<Retry>b__0()
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(32,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass7_0`1.<Retry>b__0()
        /_/src/Common/tests/CoreFx.Private.TestUtilities/System/RetryHelper.cs(37,0): at System.RetryHelper.Execute(Action test, Int32 maxAttempts, Func`2 backoffFunc)
        ----- Inner Stack Trace dotnet/corefx#9 (System.ComponentModel.Win32Exception) -----
           at System.Diagnostics.EventLogInternal.Clear()
           at System.Diagnostics.EventLog.Delete(String logName, String machineName)
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(23,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass6_0.<Retry>b__0()
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(32,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass7_0`1.<Retry>b__0()
        /_/src/Common/tests/CoreFx.Private.TestUtilities/System/RetryHelper.cs(37,0): at System.RetryHelper.Execute(Action test, Int32 maxAttempts, Func`2 backoffFunc)
        ----- Inner Stack Trace dotnet/corefx#10 (System.ComponentModel.Win32Exception) -----
           at System.Diagnostics.EventLogInternal.Clear()
           at System.Diagnostics.EventLog.Delete(String logName, String machineName)
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(23,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass6_0.<Retry>b__0()
        /_/src/System.Diagnostics.EventLog/tests/Helpers.cs(32,0): at System.Diagnostics.Tests.Helpers.<>c__DisplayClass7_0`1.<Retry>b__0()
        /_/src/Common/tests/CoreFx.Private.TestUtilities/System/RetryHelper.cs(37,0): at System.RetryHelper.Execute(Action test, Int32 maxAttempts, Func`2 backoffFunc)
  Finished:    System.Diagnostics.EventLog.Tests
=== TEST EXECUTION SUMMARY ===
   System.Diagnostics.EventLog.Tests  Total: 138, Errors: 0, Failed: 2, Skipped: 1, Time: 63.162s
----- end Mon 10/21/2019 20:59:06.57 ----- exit code 1 ----------------------------------------------------------

cc @wtgodbe

Looks similar to https://github.com/dotnet/corefx/issues/41150

[danmoseley]

https://github.com/dotnet/corefx/issues/41150 is not .NET Framework, so it's not .NET Framework specific unfortunately. Might be worth increasing the retries even further - exponential backoff style.

[danmoseley]

Looks like it already retries 10 times, at intervals of 300ms, totaling 3 seconds . I also see we already disable all parallelization in the entire test library.

Since there is no other option, I will increase the retries further. There is a function used in other tests called WaitForEventLog that is even more patient, it will wait potentially minutes.

[danmoseley]

Hmm. Also intersting, of 138 tests, many or most of which use the event log, only 1 test failed, and in both its permutations.

Also the failure is on EventLog.Delete(log) not the step being tested (writing to the log), which apparently succeeded in both cases, possibly after hidden retries. Delete is calling ClearEventLog which is returning ERROR_GEN_FAILURE.