dotnet / runtime

.NET is a cross-platform runtime for cloud, mobile, desktop, and IoT apps.
https://docs.microsoft.com/dotnet/core/
MIT License
14.91k stars 4.63k forks source link

x86 Windows `System.IO.Tests.Directory_NotifyFilter_Tests.FileSystemWatcher_Directory_NotifyFilter_CreationTime` failure #105431

Open TIHan opened 1 month ago

TIHan commented 1 month ago

https://dev.azure.com/dnceng/internal/_build/results?buildId=2499379&view=ms.vss-test-web.build-test-results-tab&runId=53901219&resultId=113131&paneView=dotnet-dnceng.dnceng-build-release-tasks.helix-test-information-tab

Console log: 'System.IO.FileSystem.Watcher.Tests' from job d35b68c7-21fa-4be4-8a3a-f359ef09afaa workitem cc76a755-a668-4441-b0e0-39781d4d8d2d (windows.10.amd64.x86.rt) executed on machine a001ER5 running Windows-10-10.0.14393-SP0

C:\h\w\B5570A35\w\A739091D\e>set _NT_SYMBOL_PATH=C:\h\w\B5570A35\p;C:\h\w\B5570A35\p\PDB;C:\h\w\B5570A35\p\shared\Microsoft.NETCore.App\9.0.0 

C:\h\w\B5570A35\w\A739091D\e>C:\h\w\B5570A35\p\dotnet C:\h\w\B5570A35\p\sos\tools\net6.0\any\dotnet-sos.dll install --architecture x86 
Installing SOS to C:\Users\runner\.dotnet\sos
Creating installation directory...
Copying files from C:\h\w\B5570A35\p\sos\tools\net6.0\any\win-x86
Copying files from C:\h\w\B5570A35\p\sos\tools\net6.0\any\lib
Execute '.load C:\Users\runner\.dotnet\sos\sos.dll' to load SOS in your Windows debugger.
SOS install succeeded

C:\h\w\B5570A35\w\A739091D\e>set spmi_enable_collection=1 

C:\h\w\B5570A35\w\A739091D\e>set spmi_collect_dir=C:\h\w\B5570A35\w\A739091D\u\spmi_collect 

C:\h\w\B5570A35\w\A739091D\e>if not exist C:\h\w\B5570A35\w\A739091D\u\spmi_collect mkdir C:\h\w\B5570A35\w\A739091D\u\spmi_collect 

C:\h\w\B5570A35\w\A739091D\e>set spmi_core_root=C:\h\w\B5570A35\p\coreclr 

C:\h\w\B5570A35\w\A739091D\e>taskkill.exe /f /im corerun.exe 
ERROR: The process "corerun.exe" not found.

C:\h\w\B5570A35\w\A739091D\e>set __TestArchitecture=x86 

C:\h\w\B5570A35\w\A739091D\e>set __TestEnv=C:\h\w\B5570A35\p\SetStressModes_normal.cmd 

C:\h\w\B5570A35\w\A739091D\e>type C:\h\w\B5570A35\p\SetStressModes_normal.cmd 

C:\h\w\B5570A35\w\A739091D\e>call C:\h\w\B5570A35\p\SetStressModes_normal.cmd 

C:\h\w\B5570A35\w\A739091D\e>set DOTNET 
Environment variable DOTNET not defined

C:\h\w\B5570A35\w\A739091D\e>call RunTests.cmd --runtime-path C:\h\w\B5570A35\p 
SuperPMI collection enabled
SuperPMIShimLogPath=C:\h\w\B5570A35\w\A739091D\u\spmi_collect
SuperPMIShimPath=C:\h\w\B5570A35\p\coreclr\clrjit.dll
DOTNET_EnableExtraSuperPmiQueries=1
DOTNET_JitPath=C:\h\w\B5570A35\p\coreclr\superpmi-shim-collector.dll
========================= Begin custom configuration settings ==============================
set __IsXUnitLogCheckerSupported=1
========================== End custom configuration settings ===============================
----- start Sun 07/21/2024 19:02:23.38 ===============  To repro directly: =====================================================
pushd C:\h\w\B5570A35\w\A739091D\e\
"C:\h\w\B5570A35\p\dotnet.exe" exec --runtimeconfig System.IO.FileSystem.Watcher.Tests.runtimeconfig.json --depsfile System.IO.FileSystem.Watcher.Tests.deps.json xunit.console.dll System.IO.FileSystem.Watcher.Tests.dll -xml testResults.xml -nologo -nocolor -notrait category=IgnoreForCI -notrait category=OuterLoop -notrait category=failing 
popd
===========================================================================================================

C:\h\w\B5570A35\w\A739091D\e>"C:\h\w\B5570A35\p\dotnet.exe" exec --runtimeconfig System.IO.FileSystem.Watcher.Tests.runtimeconfig.json --depsfile System.IO.FileSystem.Watcher.Tests.deps.json xunit.console.dll System.IO.FileSystem.Watcher.Tests.dll -xml testResults.xml -nologo -nocolor -notrait category=IgnoreForCI -notrait category=OuterLoop -notrait category=failing  
  Discovering: System.IO.FileSystem.Watcher.Tests (method display = ClassAndMethod, method display options = None)
  Discovered:  System.IO.FileSystem.Watcher.Tests (found 149 of 209 test cases)
  Starting:    System.IO.FileSystem.Watcher.Tests (parallel test collections = on [2 threads], stop on fail = off)
RetryHelper: retrying FileSystemWatcher_ModifyFiltersConcurrentWithEvents 1th time of 3: got Created event did not occur as expected
    System.IO.Tests.Directory_NotifyFilter_Tests.FileSystemWatcher_Directory_NotifyFilter_CreationTime(filter: CreationTime) [FAIL]
      Changed event did not occur as expected
      Stack Trace:
        /_/src/libraries/System.IO.FileSystem.Watcher/tests/Utility/FileSystemWatcherTest.cs(317,0): at System.IO.Tests.FileSystemWatcherTest.ExecuteAndVerifyEvents(FileSystemWatcher watcher, WatcherChangeTypes expectedEvents, Action action, Boolean assertExpected, String[] expectedPaths, Int32 timeout)
        /_/src/libraries/System.IO.FileSystem.Watcher/tests/Utility/FileSystemWatcherTest.cs(198,0): at System.IO.Tests.FileSystemWatcherTest.ExpectEvent(FileSystemWatcher watcher, WatcherChangeTypes expectedEvents, Action action, Action cleanup, String[] expectedPaths, Int32 attempts, Int32 timeout)
        /_/src/libraries/System.IO.FileSystem.Watcher/tests/Utility/FileSystemWatcherTest.cs(168,0): at System.IO.Tests.FileSystemWatcherTest.ExpectEvent(FileSystemWatcher watcher, WatcherChangeTypes expectedEvents, Action action, Action cleanup, String expectedPath, Int32 attempts, Int32 timeout)
        /_/src/libraries/System.IO.FileSystem.Watcher/tests/FileSystemWatcher.Directory.NotifyFilter.cs(70,0): at System.IO.Tests.Directory_NotifyFilter_Tests.FileSystemWatcher_Directory_NotifyFilter_CreationTime(NotifyFilters filter)
           at InvokeStub_Directory_NotifyFilter_Tests.FileSystemWatcher_Directory_NotifyFilter_CreationTime(Object, Span`1)
           at System.Reflection.MethodBaseInvoker.InvokeWithOneArg(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture)
  Finished:    System.IO.FileSystem.Watcher.Tests
=== TEST EXECUTION SUMMARY ===
   System.IO.FileSystem.Watcher.Tests  Total: 272, Errors: 0, Failed: 1, Skipped: 0, Time: 17.231s
----- end Sun 07/21/2024 19:03:02.71 ----- exit code 1 ----------------------------------------------------------
2024-07-21T19:03:03.606Z    INFO    run.py  run(48) main    Beginning reading of test results.
2024-07-21T19:03:03.606Z    INFO    run.py  __init__(42)    read_results    Searching 'C:\h\w\B5570A35\w\A739091D\e' for test results files
2024-07-21T19:03:03.606Z    INFO    run.py  __init__(48)    read_results    Found results file C:\h\w\B5570A35\w\A739091D\e\testResults.xml with format xunit
2024-07-21T19:03:03.606Z    INFO    run.py  __init__(42)    read_results    Searching 'C:\h\w\B5570A35\w\A739091D\uploads' for test results files
2024-07-21T19:03:03.606Z    INFO    run.py  packing_test_reporter(30)   report_results  Packing 272 test reports to 'C:\h\w\B5570A35\w\A739091D\e\__test_report.json'
2024-07-21T19:03:03.622Z    INFO    run.py  packing_test_reporter(33)   report_results  Packed 71520 bytes

C:\h\w\B5570A35\w\A739091D\e>set spmi_core_root=C:\h\w\B5570A35\p\coreclr 

C:\h\w\B5570A35\w\A739091D\e>set spmi_collection_name=libraries_tests 

C:\h\w\B5570A35\w\A739091D\e>set spmi_collection_type=run 

C:\h\w\B5570A35\w\A739091D\e>set spmi_collection_mch_file_tag=windows.x86.Release 

C:\h\w\B5570A35\w\A739091D\e>set spmi_superpmi_py=C:\h\w\B5570A35\p\spmi_scripts\superpmi.py 

C:\h\w\B5570A35\w\A739091D\e>set spmi_upload_dir=C:\h\w\B5570A35\w\A739091D\uploads 

C:\h\w\B5570A35\w\A739091D\e>if not exist C:\h\w\B5570A35\w\A739091D\uploads mkdir C:\h\w\B5570A35\w\A739091D\uploads 

C:\h\w\B5570A35\w\A739091D\e>set spmi_output_base_name=libraries_tests.run.windows.x86.Release 

C:\h\w\B5570A35\w\A739091D\e>set spmi_finalmch=C:\h\w\B5570A35\w\A739091D\uploads\libraries_tests.run.windows.x86.Release.mch 

C:\h\w\B5570A35\w\A739091D\e>set spmi_log_file=C:\h\w\B5570A35\w\A739091D\uploads\libraries_tests.run.windows.x86.Release.log 

C:\h\w\B5570A35\w\A739091D\e>C:\python3\python.exe C:\h\w\B5570A35\p\spmi_scripts\superpmi.py collect -log_level DEBUG -core_root C:\h\w\B5570A35\p\coreclr --skip_cleanup --clean --ci --skip_collection_step --skip_toc_step -temp_dir C:\h\w\B5570A35\w\A739091D\u\spmi_collect -output_mch_path C:\h\w\B5570A35\w\A739091D\uploads\libraries_tests.run.windows.x86.Release.mch -log_file C:\h\w\B5570A35\w\A739091D\uploads\libraries_tests.run.windows.x86.Release.log 
[19:03:04] ================ Logging to C:\h\w\B5570A35\w\A739091D\uploads\libraries_tests.run.windows.x86.Release.log
[19:03:04] Using temp_dir C:\h\w\B5570A35\w\A739091D\u\spmi_collect
[19:03:04] SuperPMI collect
[19:03:04] ------------------------------------------------------------
[19:03:04] Start time: 19:03:04
[19:03:04] Using superpmi.exe from Core_Root: C:\h\w\B5570A35\p\coreclr\superpmi.exe
[19:03:04] Using mcs.exe from Core_Root: C:\h\w\B5570A35\p\coreclr\mcs.exe
[19:03:04] SuperPMI JIT Path: C:\h\w\B5570A35\p\coreclr\clrjit.dll
[19:03:04] Merging MC files
[19:03:04] Invoking: C:\h\w\B5570A35\p\coreclr\mcs.exe -merge C:\h\w\B5570A35\w\A739091D\u\spmi_collect\base.mch C:\h\w\B5570A35\w\A739091D\u\spmi_collect\*.mc -recursive -dedup -thin
[19:03:05] Merging files matching 'C:\h\w\B5570A35\w\A739091D\u\spmi_collect\*.mc' into 'C:\h\w\B5570A35\w\A739091D\u\spmi_collect\base.mch'
[19:03:05] Appending file 'C:\h\w\B5570A35\w\A739091D\u\spmi_collect\ C__h_w_B5570A35_p_dotnet_exe __exec_--runtimeconfig_System_IO_FileSystem_Watcher_Tests_runtimeconfig_json_--depsfile_System_IO_FileSystem_Watcher_Tests_deps4B8384B5.mc'
[19:03:05] Loaded 1000 at 5516 per second
[19:03:05] Loaded 2000 at 6894 per second
[19:03:05] Loaded 3000 at 8662 per second
[19:03:05] Loaded 4000 at 8241 per second
[19:03:05] Loaded 5000 at 5384 per second
[19:03:05] Loaded 5858, Saved 5275
[19:03:05] Read/Wrote 74 MB @ 87.95 MB/s.
[19:03:05] Cleaning MCH file
[19:03:05] Invoking: C:\h\w\B5570A35\p\coreclr\superpmi.exe -p -f C:\h\w\B5570A35\w\A739091D\u\spmi_collect\basefail.mcl C:\h\w\B5570A35\w\A739091D\u\spmi_collect\base.mch C:\h\w\B5570A35\p\coreclr\clrjit.dll
[19:03:16] Using child (C:\h\w\B5570A35\p\coreclr\superpmi.exe) with args ( C:\h\w\B5570A35\p\coreclr\clrjit.dll C:\h\w\B5570A35\w\A739091D\u\spmi_collect\base.mch)
[19:03:16]  failingMCList=C:\h\w\B5570A35\w\A739091D\u\spmi_collect\basefail.mcl
[19:03:16]  workerCount=2, skipCleanup=0.
[19:03:16] Loaded 5275  Jitted 5275  FailedCompile 0 Excluded 0 Missing 0
[19:03:16] Total time: 11718.923200ms
[19:03:17] Verifying MCH file
[19:03:17] Using superpmi.exe from Core_Root: C:\h\w\B5570A35\p\coreclr\superpmi.exe
[19:03:17] 
[19:03:17] Temp Location: C:\h\w\B5570A35\t\tmpttobz2kc
[19:03:17] 
[19:03:17] Running SuperPMI replay of C:\h\w\B5570A35\w\A739091D\uploads\libraries_tests.run.windows.x86.Release.mch
[19:03:17] Invoking: C:\h\w\B5570A35\p\coreclr\superpmi.exe -v ewi -p -f C:\h\w\B5570A35\t\tmpttobz2kc\libraries_tests.run.windows.x86.Release.mch_fail.mcl -details C:\h\w\B5570A35\t\tmpttobz2kc\libraries_tests.run.windows.x86.Release.mch_details.csv C:\h\w\B5570A35\p\coreclr\clrjit.dll C:\h\w\B5570A35\w\A739091D\uploads\libraries_tests.run.windows.x86.Release.mch
[19:03:27] Clean SuperPMI replay (5275 contexts processed)
[19:03:27] Replay summary:
[19:03:27]   All replays clean
[19:03:27] Process MCH files for CI
[19:03:27] Generated MCH file: C:\h\w\B5570A35\w\A739091D\uploads\libraries_tests.run.windows.x86.Release.mch
[19:03:27] Finish time: 19:03:27
[19:03:27] Elapsed time: 0:00:23.609265

C:\h\w\B5570A35\w\A739091D\e>taskkill.exe /f /im corerun.exe 
ERROR: The process "corerun.exe" not found.

C:\h\w\B5570A35\w\A739091D\e>C:\python3\python.exe C:\h\w\B5570A35\p\gen-debug-dump-docs.py -buildid 2499379 -workitem System.IO.FileSystem.Watcher.Tests -jobid d35b68c7-21fa-4be4-8a3a-f359ef09afaa -outdir C:\h\w\B5570A35\w\A739091D\uploads -templatedir C:\h\w\B5570A35\p -dumpdir C:\cores -productver 9.0.0 
gen-debug-dump-docs.py: Did not find dumps, skipping dump docs generation.

C:\h\w\B5570A35\w\A739091D\e>EXIT /b 0 
['System.IO.FileSystem.Watcher.Tests' END OF WORK ITEM LOG: Command exited with 0]
dotnet-policy-service[bot] commented 1 month ago

Tagging subscribers to this area: @dotnet/area-infrastructure-libraries See info in area-owners.md if you want to be subscribed.

dotnet-policy-service[bot] commented 1 month ago

Tagging subscribers to this area: @dotnet/area-system-io See info in area-owners.md if you want to be subscribed.

adamsitnik commented 1 month ago

I've sent https://github.com/dotnet/runtime/pull/105637 to disable it.