Corefxlab: Intermittent test failure in System.IO.FileSystem.Watcher.Polling.Test

[krwq]

19:03:57   Discovering: System.Text.Formatting.Tests
19:03:57   Discovered:  System.Collections.Tests
19:03:57   Discovered:  System.IO.FileSystem.Watcher.Polling.Tests
19:03:57   Discovered:  System.Text.Formatting.Tests
19:03:57   Starting:    System.Collections.Tests
19:03:58   Starting:    System.IO.FileSystem.Watcher.Polling.Tests
19:03:58   Starting:    System.Text.Formatting.Tests
19:03:58   InvariantFormatStructClr : Elapsed 722ms
19:03:59   
19:03:59   Unhandled Exception: System.ObjectDisposedException: Cannot access a disposed object.
19:03:59      at System.Threading.TimerQueueTimer.Change(UInt32 dueTime, UInt32 period)
19:03:59      at System.IO.FileSystem.PollingWatcher.TimerHandler(Object context)
19:03:59      at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
19:03:59      at System.Threading.TimerQueueTimer.CallCallback()
19:03:59      at System.Threading.TimerQueueTimer.Fire()
19:03:59      at System.Threading.TimerQueue.FireNextTimers()
19:03:59   InvariantFormatIntHexClr : Elapsed 668ms
19:04:00 d:\j\workspace\dotnet_corefxlab\Debug_prtest\packages\Microsoft.DotNet.BuildTools.1.0.25-prerelease-00107\lib\tests.targets(129,5): warning MSB3073: The command "CoreRun.exe xunit.console.netcore.exe System.IO.FileSystem.Watcher.Polling.Tests.dll  -xml testResults.xml -notrait category=nonwindowstests  -notrait category=OuterLoop -notrait category=failing " exited with code -532462766. [d:\j\workspace\dotnet_corefxlab\Debug_prtest\src\System.IO.FileSystem.Watcher.Polling\tests\System.IO.FileSystem.Watcher.Polling.Tests.csproj]
19:04:00 d:\j\workspace\dotnet_corefxlab\Debug_prtest\packages\Microsoft.DotNet.BuildTools.1.0.25-prerelease-00107\lib\tests.targets(136,5): error : One or more tests failed while running tests from 'System.IO.FileSystem.Watcher.Polling.Tests' please check log for details! [d:\j\workspace\dotnet_corefxlab\Debug_prtest\src\System.IO.FileSystem.Watcher.Polling\tests\System.IO.FileSystem.Watcher.Polling.Tests.csproj]

http://dotnet-ci.cloudapp.net/job/dotnet_corefxlab/job/Debug_prtest/34/console

[MisinformedDNA]

The three current tests rely on Thread.Sleep and, thus, race conditions.

[MisinformedDNA]

Working on this now.

[ahsonkhan]

Re-opening the issue as we are still getting intermittent failures on Windows (https://github.com/dotnet/corefxlab/pull/2306):
https://ci.dot.net/job/dotnet_corefxlab/job/master/job/windows_nt_debug_prtest/1925/console

-4b678204\scripts\..\tests\System.IO.FileSystem.Watcher.Polling.Tests\System.IO.FileSystem.Watcher.Polling.Tests.csproj...
08:55:52 Test run for D:\j\workspace\windows_nt_de---4b678204\tests\System.IO.FileSystem.Watcher.Polling.Tests\bin\Debug\netcoreapp2.1\System.IO.FileSystem.Watcher.Polling.Tests.dll(.NETCoreApp,Version=v2.1)
08:55:52 Microsoft (R) Test Execution Command Line Tool Version 15.7.0
08:55:52 Copyright (c) Microsoft Corporation.  All rights reserved.
08:55:52 
08:55:52 Starting test execution, please wait...
08:56:05 The active test run was aborted. Reason: Unhandled Exception: System.ObjectDisposedException: Cannot access a disposed object.
08:56:05    at System.Threading.TimerQueueTimer.Change(UInt32 dueTime, UInt32 period)
08:56:05    at System.IO.PollingFileSystemWatcher.TimerHandler(Object context) in D:\j\workspace\windows_nt_de---4b678204\src\System.IO.FileSystem.Watcher.Polling\System\IO\PollingFileSystemWatcher.cs:line 207
08:56:05    at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
08:56:05 --- End of stack trace from previous location where exception was thrown ---
08:56:05    at System.Threading.TimerQueueTimer.CallCallback()
08:56:05    at System.Threading.TimerQueueTimer.Fire()
08:56:05    at System.Threading.TimerQueue.FireNextTimers()

[ahsonkhan]

From @KrzysztofCwalina (https://github.com/dotnet/corefxlab/issues/2343):

Got the following exception when running CI build, yet I did not touch any code in the polling watcher library:

08:40:24 Starting test execution, please wait...
08:40:26 The active test run was aborted. Reason: Unhandled Exception: System.ObjectDisposedException: Cannot access a disposed object.
08:40:26 at System.Threading.TimerQueueTimer.Change(UInt32 dueTime, UInt32 period)
08:40:26 at System.IO.PollingFileSystemWatcher.TimerHandler(Object context) in /mnt/j/workspace/dotnet_corefxlab/master/ubuntu16.04_release_prtest/src/System.IO.FileSystem.Watcher.Polling/System/IO/PollingFileSystemWatcher.cs:line 208
08:40:26 at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
08:40:26 --- End of stack trace from previous location where exception was thrown ---
08:40:26 at System.Threading.TimerQueueTimer.CallCallback()
08:40:26 at System.Threading.TimerQueueTimer.Fire()
08:40:26 at System.Threading.ThreadPoolWorkQueue.Dispatch()

[ahsonkhan]

Failed again here: https://github.com/dotnet/corefxlab/pull/2529

https://ci.dot.net/job/dotnet_corefxlab/job/master/job/ubuntu16.04_debug_prtest/2574/
https://ci.dot.net/job/dotnet_corefxlab/job/master/job/ubuntu16.04_debug_prtest/2574/consoleFull#-8536224876a086b3e-df04-41d2-bc4d-43e8f9406d07

15:37:38 Building and running tests for project tests/System.IO.FileSystem.Watcher.Polling.Tests/System.IO.FileSystem.Watcher.Polling.Tests.csproj...
15:37:39 Test run for /mnt/j/workspace/dotnet_corefxlab/master/ubuntu16.04_debug_prtest/tests/System.IO.FileSystem.Watcher.Polling.Tests/bin/Debug/netcoreapp2.1/System.IO.FileSystem.Watcher.Polling.Tests.dll(.NETCoreApp,Version=v2.1)
15:37:39 Microsoft (R) Test Execution Command Line Tool Version 15.9.0-preview-20180807-05
15:37:39 Copyright (c) Microsoft Corporation.  All rights reserved.
15:37:39 
15:37:39 Starting test execution, please wait...
15:37:41 The active test run was aborted. Reason: Unhandled Exception: System.ObjectDisposedException: Cannot access a disposed object.
15:37:41    at System.Threading.TimerQueueTimer.Change(UInt32 dueTime, UInt32 period)
15:37:41    at System.IO.PollingFileSystemWatcher.TimerHandler(Object context) in /mnt/j/workspace/dotnet_corefxlab/master/ubuntu16.04_debug_prtest/src/System.IO.FileSystem.Watcher.Polling/System/IO/PollingFileSystemWatcher.cs:line 208
15:37:41    at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
15:37:41 --- End of stack trace from previous location where exception was thrown ---
15:37:41    at System.Threading.TimerQueueTimer.CallCallback()
15:37:41    at System.Threading.TimerQueueTimer.Fire()
15:37:41    at System.Threading.TimerQueue.FireNextTimers()
15:37:41 
15:37:41 
15:37:41 Test Run Aborted.
15:37:41 Some tests failed in project tests/System.IO.FileSystem.Watcher.Polling.Tests/System.IO.FileSystem.Watcher.Polling.Tests.csproj

[joshfree]

Moving this to the 3.0 milestone as the issue popped up again

[ahsonkhan]

On OSX:
https://ci.dot.net/job/dotnet_corefxlab/job/master/job/osx10.12_debug_prtest/2630/consoleFull#-8536224876a086b3e-df04-41d2-bc4d-43e8f9406d07

[ahsonkhan]

Disabling the test for now. Failed again for Windows and OSX in https://github.com/dotnet/corefxlab/pull/2603

https://ci.dot.net/job/dotnet_corefxlab/job/master/job/osx10.12_release_prtest/2844/console

https://ci.dot.net/job/dotnet_corefxlab/job/master/job/windows_nt_debug_prtest/2778/console

22:56:32 Building and running tests for project D:\j\workspace\windows_nt_de---4b678204\scripts\..\tests\System.IO.FileSystem.Watcher.Polling.Tests\System.IO.FileSystem.Watcher.Polling.Tests.csproj...
22:56:32 Test run for D:\j\workspace\windows_nt_de---4b678204\tests\System.IO.FileSystem.Watcher.Polling.Tests\bin\Debug\netcoreapp2.1\System.IO.FileSystem.Watcher.Polling.Tests.dll(.NETCoreApp,Version=v2.1)
22:56:33 Microsoft (R) Test Execution Command Line Tool Version 15.9.0
22:56:33 Copyright (c) Microsoft Corporation.  All rights reserved.
22:56:33 
22:56:33 Starting test execution, please wait...
22:56:40 The active test run was aborted. Reason: Unhandled Exception: System.ObjectDisposedException: Cannot access a disposed object.
22:56:40    at System.Threading.TimerQueueTimer.Change(UInt32 dueTime, UInt32 period)
22:56:40    at System.IO.PollingFileSystemWatcher.TimerHandler(Object context) in D:\j\workspace\windows_nt_de---4b678204\src\System.IO.FileSystem.Watcher.Polling\System\IO\PollingFileSystemWatcher.cs:line 208
22:56:40    at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
22:56:40 --- End of stack trace from previous location where exception was thrown ---
22:56:40    at System.Threading.TimerQueueTimer.CallCallback()
22:56:40    at System.Threading.TimerQueueTimer.Fire()
22:56:40    at System.Threading.TimerQueue.FireNextTimers()
22:56:40 
22:56:41 
22:56:41 Test Run Aborted.
22:56:41 D:\j\workspace\windows_nt_de---4b678204\scripts\build.ps1 : Some tests failed 
22:56:41 in project D:\j\workspace\windows_nt_de---4b678204\scripts\..\tests\System.IO.F
22:56:41 ileSystem.Watcher.Polling.Tests\System.IO.FileSystem.Watcher.Polling.Tests.cspr
22:56:41 oj
22:56:41 At line:1 char:1
22:56:41 + D:\j\workspace\windows_nt_de---4b678204\scripts\build.ps1 Debug
22:56:41 + ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
22:56:41     + CategoryInfo          : NotSpecified: (:) [Write-Error], WriteErrorExcep 
22:56:41    tion
22:56:41     + FullyQualifiedErrorId : Microsoft.PowerShell.Commands.WriteErrorExceptio 
22:56:41    n,build.ps1
22:56:41  

[krwq]

@ahsonkhan is it possible that the fix just needs a port to 2.1? from the paths it seems that's what you're using

[ahsonkhan]

What do you mean a port to 2.1? What type/APIs would we be porting?

[krwq]

@ahsonkhan I meant those changes were merged into master/3.0 but you seem to be using 2.1:
https://github.com/dotnet/corefxlab/pull/2253
https://github.com/dotnet/corefxlab/pull/2258
or is this library an OOB package?

It might make sense to check if the IL has the fixes which were done there

[ahsonkhan]

I meant those changes were merged into master/3.0

Which changes are you referring to?

Also, the library targets netcoreapp2.1, so I should be able to test/run on that: https://github.com/dotnet/corefxlab/blob/b43a07bbe24f4072deb555cff9ce5d3aec237948/src/System.IO.FileSystem.Watcher.Polling/System.IO.FileSystem.Watcher.Polling.csproj#L5

All corefxlab libraries are "OOB" effectively.

[krwq]

@ahsonkhan ahh nvm, I thought those were corefx PRs

[JosefBackovsky]

Hello. I have issue with The active test run was aborted on dotnet core 3 preview 5.

The active test run was aborted. Reason: Unhandled Exception: System.ObjectDisposedException: Cannot access a disposed object.
   at System.Reactive.Concurrency.EventLoopScheduler.Schedule[TState](TState state, TimeSpan dueTime, Func`3 action)
   at System.Reactive.Concurrency.Scheduler.<>c__DisplayClass49_0`1.<InvokeRec1>b__1(TState state2)
   at System.Reactive.ScheduledObserver1.Run(Object state, Action1 recurse)
   at System.Reactive.Concurrency.Scheduler.InvokeRec1[TState](IScheduler scheduler, Pair`2 pair)
   at System.Reactive.Concurrency.EventLoopScheduler.Run()
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
--- End of stack trace from previous location where exception was thrown ---
   at System.Threading.ThreadHelper.ThreadStart()

It happens in 50% of cases in middle of test run.

Running in Azure DevOPS on azure hosted agent in docker conatiner based on mcr.microsoft.com/dotnet/core/sdk:3.0.100-preview5

Thanks and regards,
Josef