Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Test failed: System.IO.Tests.File_Create_Tests.FileSystemWatcher_File_Create_EnablingDisablingNotAffectRaisingEvent #32955

Open
Tracked by #64596
VincentBu opened this issue Feb 28, 2020 · 25 comments

Comments

@VincentBu
Copy link
Contributor

VincentBu commented Feb 28, 2020

Job:
runtime-libraries outerloop 20200227.1

Related tests:
System.IO.Tests.File_Create_Tests.FileSystemWatcher_File_Create_EnablingDisablingNotAffectRaisingEvent

Error message:
Assert.False() Failure\nExpected: False\nActual: True

@Dotnet-GitSync-Bot Dotnet-GitSync-Bot added area-System.IO untriaged New issue has not been triaged by the area owner labels Feb 28, 2020
@danmoseley
Copy link
Member

@VincentBu thanks for opening test issues. Could you please include the full output, including callstack if any? In this case, it's

 at System.IO.Tests.File_Create_Tests.<FileSystemWatcher_File_Create_EnablingDisablingNotAffectRaisingEvent>b__1_0() in /_/src/libraries/System.IO.FileSystem.Watcher/tests/FileSystemWatcher.File.Create.cs:line 61
   at System.IO.Tests.FileSystemWatcherTest.ExecuteWithRetry(Action action, Int32 maxAttempts) in /_/src/libraries/System.IO.FileSystem.Watcher/tests/Utility/FileSystemWatcherTest.cs:line 243
   at System.IO.Tests.File_Create_Tests.FileSystemWatcher_File_Create_EnablingDisablingNotAffectRaisingEvent() in /_/src/libraries/System.IO.FileSystem.Watcher/tests/FileSystemWatcher.File.Create.cs:line 34

Let me know if you can't find it in the UI.

@JeremyKuhne JeremyKuhne removed the untriaged New issue has not been triaged by the area owner label Mar 5, 2020
@JeremyKuhne JeremyKuhne added this to the 5.0 milestone Mar 5, 2020
@v-haren
Copy link

v-haren commented Apr 26, 2020

failed again in job: runtime-libraries outerloop 20200425.4

failed test: System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther

Error message

Assert.False() Failure
Expected: False
Actual: True


Stack trace
   at System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther() in /_/src/libraries/System.IO.FileSystem.Watcher/tests/FileSystemWatcher.MultipleWatchers.cs:line 317

@josalem
Copy link
Contributor

josalem commented May 5, 2020

Similar failure here: https://dev.azure.com/dnceng/public/_build/results?buildId=632273&view=logs&j=499826eb-b71f-5fb9-e963-df1d0bd97bcc&t=592f02e1-36e2-5ce1-c6c7-5351786e61b6

failed test: System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther

Output:

  Discovering: System.IO.FileSystem.Watcher.Tests (method display = ClassAndMethod, method display options = None)
  Discovered:  System.IO.FileSystem.Watcher.Tests (found 19 of 183 test cases)
  Starting:    System.IO.FileSystem.Watcher.Tests (parallel test collections = on, max threads = 4)
    System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther [FAIL]
      Assert.False() Failure
      Expected: False
      Actual:   True
      Stack Trace:
        /_/src/libraries/System.IO.FileSystem.Watcher/tests/FileSystemWatcher.MultipleWatchers.cs(317,0): at System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther()
  Finished:    System.IO.FileSystem.Watcher.Tests
=== TEST EXECUTION SUMMARY ===
   System.IO.FileSystem.Watcher.Tests  Total: 35, Errors: 0, Failed: 1, Skipped: 0, Time: 61.506s

@v-haren
Copy link

v-haren commented Jun 1, 2020

failed again in job: runtime-libraries outerloop 20200531.3

Error message

Assert.False() Failure
Expected: False
Actual: True


Stack trace
   at System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther() in /_/src/libraries/System.IO.FileSystem.Watcher/tests/FileSystemWatcher.MultipleWatchers.cs:line 317

@carlossanlop carlossanlop modified the milestones: 5.0.0, 6.0.0 Jun 23, 2020
@v-haren
Copy link

v-haren commented Jul 9, 2020

failed again in job: runtime-libraries outerloop 20200708.3

failed test: System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther

Error message

Assert.False() Failure
Expected: False
Actual: True


Stack trace
   at System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther() in /_/src/libraries/System.IO.FileSystem.Watcher/tests/FileSystemWatcher.MultipleWatchers.cs:line 317

@v-haren
Copy link

v-haren commented Aug 4, 2020

also failed in job: runtime-libraries outerloop 20200803.2

failed test: System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther

Error message

Assert.False() Failure
Expected: False
Actual:   True


Stack trace
   at System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther() in /_/src/libraries/System.IO.FileSystem.Watcher/tests/FileSystemWatcher.MultipleWatchers.cs:line 316

@v-haren
Copy link

v-haren commented Aug 28, 2020

failed again in job: runtime-libraries outerloop 20200827.1

failed test:
System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther

Configurations:
net5.0-OSX-Release-x64-CoreCLR_release-OSX.1014.Amd64.Open

Error message

Assert.False() Failure
Expected: False
Actual:   True


Stack trace
   at System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther() in /_/src/libraries/System.IO.FileSystem.Watcher/tests/FileSystemWatcher.MultipleWatchers.cs:line 316

@v-haren
Copy link

v-haren commented Sep 15, 2020

failed again in job: runtime-libraries-coreclr outerloop 20200914.3

failed test: System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther

net5.0-OSX-Release-x64-CoreCLR_release-OSX.1014.Amd64.Open

Error message

Assert.False() Failure
Expected: False
Actual:   True


Stack trace
   at System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther() in /_/src/libraries/System.IO.FileSystem.Watcher/tests/FileSystemWatcher.MultipleWatchers.cs:line 316

@v-haren
Copy link

v-haren commented Oct 14, 2020

failed again in job: runtime-libraries-coreclr outerloop 20201013.2

failed test: System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther

net6.0-OSX-Release-x64-CoreCLR_release-OSX.1014.Amd64.Open

Error message

Assert.False() Failure
Expected: False
Actual:   True


Stack trace
   at System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther() in /_/src/libraries/System.IO.FileSystem.Watcher/tests/FileSystemWatcher.MultipleWatchers.cs:line 316

@VincentBu
Copy link
Contributor Author

Failed again in run runtime-libraries-coreclr outerloop 20210124.2

Failed tests:

net6.0-OSX-Release-x64-CoreCLR_release-OSX.1014.Amd64.Open
        - System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther

Error message:

Assert.False() Failure
Expected: False
Actual:   True

stack trace:
   at System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther() in /_/src/libraries/System.IO.FileSystem.Watcher/tests/FileSystemWatcher.MultipleWatchers.cs:line 316

@VincentBu
Copy link
Contributor Author

Failed again in runtime-libraries-coreclr outerloop 20210131.2

Failed tests:

net6.0-OSX-Release-x64-CoreCLR_release-OSX.1014.Amd64.Open
    - System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther

Error message:

Assert.False() Failure
Expected: False
Actual:   True

stack trace:
   at System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther() in /_/src/libraries/System.IO.FileSystem.Watcher/tests/FileSystemWatcher.MultipleWatchers.cs:line 316

@VincentBu
Copy link
Contributor Author

Failed again in runtime-libraries-coreclr outerloop 20210225.4

Failed test:

net6.0-OSX-Release-x64-CoreCLR_release-OSX.1014.Amd64.Open
 
-System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther

Error message:

Assert.False() Failure
Expected: False
Actual:   True


Stack trace
   at System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther() in /_/src/libraries/System.IO.FileSystem.Watcher/tests/FileSystemWatcher.MultipleWatchers.cs:line 316

@VincentBu
Copy link
Contributor Author

Failed again in runtime-libraries-coreclr outerloop 20210322.2

Failed test:

net6.0-OSX-Release-x64-CoreCLR_release-OSX.1014.Amd64.Open
 -System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther

Error message:

Assert.False() Failure
Expected: False
Actual:   True


Stack trace
   at System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther() in /_/src/libraries/System.IO.FileSystem.Watcher/tests/FileSystemWatcher.MultipleWatchers.cs:line 316

@VincentBu
Copy link
Contributor Author

Failed again in runtime-libraries-coreclr outerloop 20210505.3

Failed test:

net6.0-OSX-Release-x64-CoreCLR_release-OSX.1014.Amd64.Open
 -System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther

Error message:

Assert.False() Failure
Expected: False
Actual:   True


Stack trace
   at System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther() in /_/src/libraries/System.IO.FileSystem.Watcher/tests/FileSystemWatcher.MultipleWatchers.cs:line 316

@danmoseley
Copy link
Member

danmoseley commented May 6, 2021

Happened 56 times, although I think data is cut off at some point earlier than March.

TestResults
| join kind=inner WorkItems on WorkItemId
| join kind=inner Jobs on JobId
| where Finished >= datetime(2020-1-1 0:00:00)
| where Method == "FileSystemWatcher_File_Create_EnablingDisablingNotAffectRaisingEvent" or Method == "FileSystemWatcher_File_Delet_NotAffectEachOther"
| where Result == "Fail"
| project Method, Message, QueueAlias, Queued
| summarize count() by Method, QueueAlias, bin(Queued, 5d)
Method QueueAlias Queued count_
FileSystemWatcher_File_Delet_NotAffectEachOther osx.1014.amd64.open 2021-03-07 00:00:00.0000000 2
FileSystemWatcher_File_Delet_NotAffectEachOther osx.1014.amd64.open 2021-03-12 00:00:00.0000000 5
FileSystemWatcher_File_Delet_NotAffectEachOther osx.1014.amd64.open 2021-03-17 00:00:00.0000000 3
FileSystemWatcher_File_Create_EnablingDisablingNotAffectRaisingEvent osx.1014.amd64.open 2021-03-17 00:00:00.0000000 1
FileSystemWatcher_File_Delet_NotAffectEachOther osx.1014.amd64.open 2021-03-22 00:00:00.0000000 3
FileSystemWatcher_File_Create_EnablingDisablingNotAffectRaisingEvent osx.1014.amd64.open 2021-03-22 00:00:00.0000000 3
FileSystemWatcher_File_Delet_NotAffectEachOther osx.1014.amd64.open 2021-03-27 00:00:00.0000000 6
FileSystemWatcher_File_Delet_NotAffectEachOther osx.1014.amd64.open 2021-04-01 00:00:00.0000000 4
FileSystemWatcher_File_Delet_NotAffectEachOther osx.1014.amd64.open 2021-04-06 00:00:00.0000000 4
FileSystemWatcher_File_Create_EnablingDisablingNotAffectRaisingEvent osx.1014.amd64.open 2021-04-06 00:00:00.0000000 2
FileSystemWatcher_File_Create_EnablingDisablingNotAffectRaisingEvent osx.1013.amd64.open 2021-04-06 00:00:00.0000000 1
FileSystemWatcher_File_Delet_NotAffectEachOther osx.1014.amd64.open 2021-04-11 00:00:00.0000000 3
FileSystemWatcher_File_Delet_NotAffectEachOther osx.1014.amd64.open 2021-04-16 00:00:00.0000000 2
FileSystemWatcher_File_Create_EnablingDisablingNotAffectRaisingEvent osx.1014.amd64.open 2021-04-16 00:00:00.0000000 1
FileSystemWatcher_File_Delet_NotAffectEachOther osx.1014.amd64.open 2021-04-21 00:00:00.0000000 6
FileSystemWatcher_File_Delet_NotAffectEachOther osx.1014.amd64.open 2021-04-26 00:00:00.0000000 2
FileSystemWatcher_File_Delet_NotAffectEachOther osx.1014.amd64.open 2021-05-01 00:00:00.0000000 6
FileSystemWatcher_File_Create_EnablingDisablingNotAffectRaisingEvent osx.1014.amd64.open 2021-05-01 00:00:00.0000000 1
FileSystemWatcher_File_Delet_NotAffectEachOther osx.1013.amd64.open 2021-05-01 00:00:00.0000000 1

@danmoseley
Copy link
Member

danmoseley commented May 6, 2021

For FileSystemWatcher_File_Create_EnablingDisablingNotAffectRaisingEvent, the rarer one, I think the line number is off. It has to be here:

Assert.False(autoResetEvent.WaitOne(SubsequentExpectedWait));

Here we are subscribing to events for a file , creating the file, and apparently the event handler is getting called more than once.

For FileSystemWatcher_File_Delet_NotAffectEachOther it is here

Assert.False(autoResetEvent1.WaitOne(WaitForUnexpectedEventTimeout));

We delete a file, wait for several delete watchers to all signal, create it again, set watcher 1 to stop watching, delete it, and we see watcher 1 fire nevertheless within ~250ms.
One possibility here is that like the first case, we're getting two events (this time for the delete) and the second event is arriving in a race with disabling the watcher.

@danmoseley
Copy link
Member

In the second case, it is assuming that events are deterministically not received after EnableRaisingEvents = false is set on a watcher. However, this is not synchronous: it just sets a CancellationToken. (Why isn't this failing on Linux?)

In the first case, we are flipping EnableRaisingEvents back and forth, and I am guessing that this may lead to a situation where we effectively have two identical watchers.

@danmoseley
Copy link
Member

It's not obvious how to fix this - I think it's reasonable to say that we do not guarantee that events won't arrive for a little longer after you disable raising events - and in practice for whatever reason this shows up only on Mac.

so FileSystemWatcher_File_Delet_NotAffectEachOther should be disabled for Mac, or refactor the disable raising events out.

The FileSystemWatcher_File_Create_EnablingDisablingNotAffectRaisingEvent needs a little more analysis.

@VincentBu
Copy link
Contributor Author

Failed again in runtime-libraries-coreclr outerloop 20210517.4

Failed test:

net6.0-OSX-Release-x64-CoreCLR_release-OSX.1013.Amd64.Open

- System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther

Error message:

Assert.False() Failure
Expected: False
Actual:   True


Stack trace
   at System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther() in /_/src/libraries/System.IO.FileSystem.Watcher/tests/FileSystemWatcher.MultipleWatchers.cs:line 316

@VincentBu
Copy link
Contributor Author

Failed again in runtime-libraries-coreclr outerloop 20210609.3

Failed test:

net6.0-OSX-Release-x64-CoreCLR_release-OSX.1014.Amd64.Open

- System.IO.Tests.File_Create_Tests.FileSystemWatcher_File_Create_EnablingDisablingNotAffectRaisingEvent

Error message:

Assert.False() Failure
Expected: False
Actual:   True


Stack trace
   at System.IO.Tests.File_Create_Tests.<FileSystemWatcher_File_Create_EnablingDisablingNotAffectRaisingEvent>b__1_0() in /_/src/libraries/System.IO.FileSystem.Watcher/tests/FileSystemWatcher.File.Create.cs:line 61
   at System.IO.Tests.FileSystemWatcherTest.ExecuteWithRetry(Action action, Int32 maxAttempts) in /_/src/libraries/System.IO.FileSystem.Watcher/tests/Utility/FileSystemWatcherTest.cs:line 241
   at System.IO.Tests.File_Create_Tests.FileSystemWatcher_File_Create_EnablingDisablingNotAffectRaisingEvent() in /_/src/libraries/System.IO.FileSystem.Watcher/tests/FileSystemWatcher.File.Create.cs:line 34

@adamsitnik adamsitnik modified the milestones: 6.0.0, 7.0.0 Jul 22, 2021
@VincentBu
Copy link
Contributor Author

Failed again in: runtime-libraries-coreclr outerloop 20210819.6

Failed test:

net6.0-OSX-Release-x64-CoreCLR_release-OSX.1014.Amd64.Open

- System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther

Error message:

Assert.False() Failure
Expected: False
Actual:   True


Stack trace
   at System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther() in /_/src/libraries/System.IO.FileSystem.Watcher/tests/FileSystemWatcher.MultipleWatchers.cs:line 316

@VincentBu
Copy link
Contributor Author

Failed again in: runtime-libraries-coreclr outerloop 20210927.4
Failed test

net7.0-OSX-Release-x64-CoreCLR_release-OSX.1014.Amd64.Open

- System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther

Error message:

Assert.False() Failure
Expected: False
Actual:   True


Stack trace
   at System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther() in /_/src/libraries/System.IO.FileSystem.Watcher/tests/FileSystemWatcher.MultipleWatchers.cs:line 316

@VincentBu
Copy link
Contributor Author

VincentBu commented Oct 11, 2021

Failed again in: runtime-libraries-coreclr outerloop 20211010.4

Failed test:

net7.0-OSX-Release-x64-CoreCLR_release-OSX.1014.Amd64.Open

- System.IO.Tests.File_Create_Tests.FileSystemWatcher_File_Create_EnablingDisablingNotAffectRaisingEvent
- System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther

Error message:

Assert.False() Failure
Expected: False
Actual:   True


Stack trace
   at System.IO.Tests.File_Create_Tests.<FileSystemWatcher_File_Create_EnablingDisablingNotAffectRaisingEvent>b__1_0() in /_/src/libraries/System.IO.FileSystem.Watcher/tests/FileSystemWatcher.File.Create.cs:line 63
   at System.IO.Tests.FileSystemWatcherTest.ExecuteWithRetry(Action action, Int32 maxAttempts) in /_/src/libraries/System.IO.FileSystem.Watcher/tests/Utility/FileSystemWatcherTest.cs:line 242
   at System.IO.Tests.File_Create_Tests.FileSystemWatcher_File_Create_EnablingDisablingNotAffectRaisingEvent() in /_/src/libraries/System.IO.FileSystem.Watcher/tests/FileSystemWatcher.File.Create.cs:line 34

@VincentBu
Copy link
Contributor Author

Failed again in: runtime-libraries-coreclr outerloop 20220123.3

Failed test:

net7.0-OSX-Release-x64-CoreCLR_release-OSX.1014.Amd64.Open

- System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther

Error message:

Assert.False() Failure
Expected: False
Actual:   True


Stack trace
   at System.IO.Tests.FileSystemWatcher_Multiple_Test.FileSystemWatcher_File_Delet_NotAffectEachOther() in /_/src/libraries/System.IO.FileSystem.Watcher/tests/FileSystemWatcher.MultipleWatchers.cs:line 316

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

No branches or pull requests

10 participants