Failure in baseservices\threading\mutex\misc\waitone2

[adityamandaleeka]

Saw this on this job.

MESSAGE:

Return code: 1
Raw output file: D:\j\workspace\x64_release_w---0575cb46\bin\tests\Windows_NT.x64.Releaseeports\baseservices\threading\mutex\misc\waitone2\waitone2.output.txt
Raw output:
BEGIN EXECUTION
 "D:\j\workspace\x64_release_w---0575cb46\tests\..\bin\tests\Windows_NT.x64.Release\Tests\Core_Root\corerun.exe" waitone2.exe 
Beginning test case MutexWaitOne2 at 7/21/2016 9:07:52 AM
Random seed: 20010415; set environment variable CORECLR_SEED to this value to repro

[Positive]
Beginning scenario: PosTest1: Wait Infinite
Beginning scenario: PosTest2: Wait some finite time
ERROR!!!-003: Unexpected exception: System.Exception: Object synchronization method was called from an unsynchronized block of code.
 at System.Threading.Mutex.ReleaseMutex()
 at MutexWaitOne2.PosTest2() in D:\j\workspace\x64_release_w---0575cb46\tests\src\baseservices\threading\mutex\misc\WaitOne2.cs:line 127
 at System.Threading.Mutex.ReleaseMutex()
 at MutexWaitOne2.PosTest2() in D:\j\workspace\x64_release_w---0575cb46\tests\src\baseservices\threading\mutex\misc\WaitOne2.cs:line 127
Beginning scenario: PosTest3: Wait some finite time will quit for timeout
Beginning scenario: PosTest4: Wait some finite time will quit for timeout when another thread is in nondefault managed context
Beginning scenario: PosTest5: Wait some finite time will quit for timeout when another thread is in nondefault managed context
Beginning scenario: PosTest6: Wait infinite time when another thread is in nondefault managed context
Beginning scenario: PosTest7: Wait infinite time when another thread is in nondefault managed context
[Negative]
Beginning scenario: NegTest1: AbandonedMutexException should be thrown if a thread exited without releasing a mutex
Beginning scenario: NegTest2: ObjectDisposedException should be thrown if current instance has already been disposed
Beginning scenario: NegTest3: Check ArgumentOutOfRangeException will be thrown if millisecondsTimeout is a negative number other than -1

Ending test case at 7/21/2016 9:08:25 AM
FAIL
Expected: 100
Actual: 0
END EXECUTION - FAILED
FAILED
Test Harness Exitcode is : 1

To run the test:
> set CORE_ROOT=D:\j\workspace\x64_release_w---0575cb46\bin\tests\Windows_NT.x64.Release\Tests\Core_Root
> D:\j\workspace\x64_release_w---0575cb46\bin\tests\Windows_NT.x64.Release\baseservices\threading\mutex\misc\waitone2\waitone2.cmd

Expected: True
Actual: False
+++++++++++++++++++
STACK TRACE:
at baseservices._threading_mutex_misc_waitone2_waitone2_._threading_mutex_misc_waitone2_waitone2_cmd() in D:\j\workspace\x64_release_w---0575cb46\bin\tests\Windows_NT.x64.Release\TestWrappers\baseservices\baseservices.XUnitWrapper.cs:line 27222

[janvorli]

Occured again:
https://ci.dot.net/job/dotnet_coreclr/job/master/job/x64_release_windows_nt_pri1_prtest/1719/testReport/junit/baseservices/_threading_mutex_misc_waitone2_waitone2_/_threading_mutex_misc_waitone2_waitone2_cmd/

[janvorli]

@kouvel could you please take a look at what could be causing the issue?

[ruben-ayrapetyan]

Maybe, this is related: https://ci.dot.net/job/dotnet_coreclr/job/master/job/x64_release_windows_nt_pri1_prtest/8242/testReport/junit/baseservices_threading/_mutex_misc_waitone2_waitone2_/_mutex_misc_waitone2_waitone2_cmd/

[RussKeldorph]

Perhaps another with slightly different output.

  BEGIN EXECUTION
         "D:\j\workspace\x64_release_w---8be20721\tests\..\bin\tests\Windows_NT.x64.Release\Tests\Core_Root\corerun.exe" waitone2.exe 
        Beginning test case MutexWaitOne2 at 7/12/2017 1:24:46 AM
        Random seed: 20010415; set environment variable CORECLR_SEED to this value to repro
        
        [Positive]
        Beginning scenario: PosTest1: Wait Infinite
        Beginning scenario: PosTest2: Wait some finite time
        Beginning scenario: PosTest3: Wait some finite time will quit for timeout
        Beginning scenario: PosTest4: Wait some finite time will quit for timeout when another thread is in nondefault managed context
        Beginning scenario: PosTest5: Wait some finite time will quit for timeout when another thread is in nondefault managed context
        Beginning scenario: PosTest6: Wait infinite time when another thread is in nondefault managed context
        Beginning scenario: PosTest7: Wait infinite time when another thread is in nondefault managed context
        [Negative]
        Beginning scenario: NegTest1: AbandonedMutexException should be thrown if a thread exited without releasing a mutex
        Beginning scenario: NegTest2: ObjectDisposedException should be thrown if current instance has already been disposed
        ERROR!!!-103: ObjectDisposedException is not thrown if current instance has already been disposed
        Beginning scenario: NegTest3: Check ArgumentOutOfRangeException will be thrown if millisecondsTimeout is a negative number other than -1
        
        Ending test case at 7/12/2017 1:25:17 AM
        FAIL
        Expected: 100
        Actual: 0
        END EXECUTION - FAILED
        FAILED
        Test Harness Exitcode is : 1

[mikedn]

And another one: https://ci.dot.net/job/dotnet_coreclr/job/master/job/x64_release_windows_nt_pri1_prtest/11525/testReport/junit/baseservices_threading/_mutex_misc_waitone2_waitone2_/_mutex_misc_waitone2_waitone2_cmd/

MESSAGE:
\n\nReturn code: 1\nRaw output file: D:\\j\\workspace\\x64_release_w---0575cb46\\bin\\tests\\Windows_NT.x64.Release\\Reports\\baseservices.threading\\mutex\\misc\\waitone2\\waitone2.output.txt\nRaw output:\nBEGIN EXECUTION\r\n \"D:\\j\\workspace\\x64_release_w---0575cb46\\tests\\..\\bin\\tests\\Windows_NT.x64.Release\\Tests\\Core_Root\\corerun.exe\" waitone2.exe \r\nBeginning test case MutexWaitOne2 at 10/7/2017 11:12:13 AM\r\nRandom seed: 20010415; set environment variable CORECLR_SEED to this value to repro\r\n\r\n[Positive]\r\nBeginning scenario: PosTest1: Wait Infinite\r\nBeginning scenario: PosTest2: Wait some finite time\r\nBeginning scenario: PosTest3: Wait some finite time will quit for timeout\r\nBeginning scenario: PosTest4: Wait some finite time will quit for timeout when another thread is in nondefault managed context\r\nBeginning scenario: PosTest5: Wait some finite time will quit for timeout when another thread is in nondefault managed context\r\nBeginning scenario: PosTest6: Wait infinite time when another thread is in nondefault managed context\r\nBeginning scenario: PosTest7: Wait infinite time when another thread is in nondefault managed context\r\n[Negative]\r\nBeginning scenario: NegTest1: AbandonedMutexException should be thrown if a thread exited without releasing a mutex\r\nBeginning scenario: NegTest2: ObjectDisposedException should be thrown if current instance has already been disposed\r\nERROR!!!-103: ObjectDisposedException is not thrown if current instance has already been disposed\r\nBeginning scenario: NegTest3: Check ArgumentOutOfRangeException will be thrown if millisecondsTimeout is a negative number other than -1\r\n\r\nEnding test case at 10/7/2017 11:12:44 AM\r\nFAIL\r\nExpected: 100\r\nActual: 0\r\nEND EXECUTION - FAILED\r\nFAILED\r\nTest Harness Exitcode is : 1\r\n\nTo run the test:\n> set CORE_ROOT=D:\\j\\workspace\\x64_release_w---0575cb46\\bin\\tests\\Windows_NT.x64.Release\\Tests\\Core_Root\n> D:\\j\\workspace\\x64_release_w---0575cb46\\bin\\tests\\Windows_NT.x64.Release\\baseservices\\threading\\mutex\\misc\\waitone2\\waitone2.cmd\n\r\nExpected: True\r\nActual: False
+++++++++++++++++++
STACK TRACE:
at baseservices_threading._mutex_misc_waitone2_waitone2_._mutex_misc_waitone2_waitone2_cmd() in D:\j\workspace\x64_release_w---0575cb46\bin\tests\Windows_NT.x64.Release\TestWrappers\baseservices.threading\baseservices.threading.XUnitWrapper.cs:line 17607

[4creators]

And next one: https://ci.dot.net/job/dotnet_coreclr/job/master/job/jitstress/job/x86_checked_windows_nt_jitx86hwintrinsicnosimd_prtest/314/

03:22:01       baseservices_threading._mutex_misc_waitone2_waitone2_._mutex_misc_waitone2_waitone2_cmd [FAIL]
03:22:01         
03:22:01   
03:22:01   Return code:      1
03:22:01   Raw output file:      D:\j\workspace\x86_checked_w---0c50c361\bin\tests\Windows_NT.x86.Checked\Reports\baseservices.threading\mutex\misc\waitone2\waitone2.output.txt
03:22:01   Raw output:
03:22:01   BEGIN EXECUTION
03:22:01          "D:\j\workspace\x86_checked_w---0c50c361\bin\tests\Windows_NT.x86.Checked\Tests\Core_Root\corerun.exe" waitone2.exe 
03:22:01         Beginning test case MutexWaitOne2 at 9/12/2018 3:21:27 AM
03:22:01         Random seed: 20010415; set environment variable CORECLR_SEED to this value to repro
03:22:01         
03:22:01         [Positive]
03:22:01         Beginning scenario: PosTest1: Wait Infinite
03:22:01         Beginning scenario: PosTest2: Wait some finite time
03:22:01         Beginning scenario: PosTest3: Wait some finite time will quit for timeout
03:22:01         ERROR!!!-004: WaitOne returns true when wait time out
03:22:01         Beginning scenario: PosTest4: Wait some finite time will quit for timeout when another thread is in nondefault managed context
03:22:01         Beginning scenario: PosTest5: Wait some finite time will quit for timeout when another thread is in nondefault managed context
03:22:01         Beginning scenario: PosTest6: Wait infinite time when another thread is in nondefault managed context
03:22:01         Beginning scenario: PosTest7: Wait infinite time when another thread is in nondefault managed context
03:22:01         [Negative]
03:22:01         Beginning scenario: NegTest1: AbandonedMutexException should be thrown if a thread exited without releasing a mutex
03:22:01         Beginning scenario: NegTest2: ObjectDisposedException should be thrown if current instance has already been disposed
03:22:01         Beginning scenario: NegTest3: Check ArgumentOutOfRangeException will be thrown if millisecondsTimeout is a negative number other than -1
03:22:01         
03:22:01         Ending test case at 9/12/2018 3:21:59 AM
03:22:01         FAIL
03:22:01         Expected: 100
03:22:01         Actual: 0
03:22:01         END EXECUTION - FAILED
03:22:01         FAILED
03:22:01         Test Harness Exitcode is : 1
03:22:01         
03:22:01   To run the test:
03:22:01   > set CORE_ROOT=D:\j\workspace\x86_checked_w---0c50c361\bin\tests\Windows_NT.x86.Checked\Tests\Core_Root
03:22:01   > D:\j\workspace\x86_checked_w---0c50c361\bin\tests\Windows_NT.x86.Checked\baseservices\threading\mutex\misc\waitone2\waitone2.cmd
03:22:01   
03:22:01         Expected: True
03:22:01         Actual:   False
03:22:01         Stack Trace:
03:22:01           D:\j\workspace\x86_checked_w---0c50c361\bin\tests\Windows_NT.x86.Checked\TestWrappers\baseservices.threading\baseservices.threading.XUnitWrapper.cs(17679,0): at baseservices_threading._mutex_misc_waitone2_waitone2_._mutex_misc_waitone2_waitone2_cmd()

[BruceForstall]

Another failure in waitone2, this time Linux arm64 R2R JitStress1:

https://ci.dot.net/job/dotnet_coreclr/job/master/view/arm/job/jitstress/job/arm_cross_checked_ubuntu_r2r_jitstress1_tst/41/consoleFull

16:59:55 
      baseservices_threading._mutex_misc_waitone2_waitone2_._mutex_misc_waitone2_waitone2_sh [FAIL]
16:59:55         
16:59:55         cmdLine:/ssd/j/workspace/dotnet_coreclr/master/jitstress/arm_cross_checked_ubuntu_r2r_jitstress1_tst/bin/tests/Linux.arm.Checked/baseservices/threading/mutex/misc/waitone2/waitone2.sh Timed Out
16:59:55         /n/nReturn code:      -100/nRaw output file:      /ssd/j/workspace/dotnet_coreclr/master/jitstress/arm_cross_checked_ubuntu_r2r_jitstress1_tst/bin/tests/Linux.arm.Checked/baseservices/threading/Reports/baseservices.threading/mutex/misc/waitone2/waitone2.output.txt/nRaw output:/nBEGIN EXECUTION
16:59:55         in takeLock
16:59:55         /ssd/j/workspace/dotnet_coreclr/master/jitstress/arm_cross_checked_ubuntu_r2r_jitstress1_tst/bin/tests/Linux.arm.Checked/Tests/Core_Root/crossgen /Platform_Assemblies_Paths /ssd/j/workspace/dotnet_coreclr/master/jitstress/arm_cross_checked_ubuntu_r2r_jitstress1_tst/bin/tests/Linux.arm.Checked/Tests/Core_Root:/ssd/j/workspace/dotnet_coreclr/master/jitstress/arm_cross_checked_ubuntu_r2r_jitstress1_tst/bin/tests/Linux.arm.Checked/baseservices/threading/mutex/misc/waitone2/IL:/ssd/j/workspace/dotnet_coreclr/master/jitstress/arm_cross_checked_ubuntu_r2r_jitstress1_tst/bin/tests/Linux.arm.Checked/baseservices/threading/mutex/misc/waitone2 /in waitone2.org /out waitone2.exe
16:59:55         Microsoft (R) CoreCLR Native Image Generator - Version 4.5.30319.0
16:59:55         Copyright (c) Microsoft Corporation.  All rights reserved.
16:59:55         
16:59:55         Native image waitone2.exe generated successfully.
16:59:55         in ReleaseLock
16:59:55         in takeLock
16:59:55         /ssd/j/workspace/dotnet_coreclr/master/jitstress/arm_cross_checked_ubuntu_r2r_jitstress1_tst/bin/tests/Linux.arm.Checked/Tests/Core_Root/corerun waitone2.exe
16:59:55         Beginning test case MutexWaitOne2 at 12/18/2018 12:44:58 AM
16:59:55         Random seed: 20010415; set environment variable CORECLR_SEED to this value to repro
16:59:55         
16:59:55         [Positive]
16:59:55         Beginning scenario: PosTest1: Wait Infinite
16:59:55         Beginning scenario: PosTest2: Wait some finite time
16:59:55         Beginning scenario: PosTest3: Wait some finite time will quit for timeout
16:59:55         Beginning scenario: PosTest4: Wait some finite time will quit for timeout when another thread is in nondefault managed context
16:59:55         Beginning scenario: PosTest5: Wait some finite time will quit for timeout when another thread is in nondefault managed context
16:59:55         Beginning scenario: PosTest6: Wait infinite time when another thread is in nondefault managed context
16:59:55         
16:59:55         cmdLine:/ssd/j/workspace/dotnet_coreclr/master/jitstress/arm_cross_checked_ubuntu_r2r_jitstress1_tst/bin/tests/Linux.arm.Checked/baseservices/threading/mutex/misc/waitone2/waitone2.sh Timed Out
16:59:55         Test Harness Exitcode is : -100
16:59:55         /nTo run the test:/n> set CORE_ROOT=/ssd/j/workspace/dotnet_coreclr/master/jitstress/arm_cross_checked_ubuntu_r2r_jitstress1_tst/bin/tests/Linux.arm.Checked/Tests/Core_Root/n> /ssd/j/workspace/dotnet_coreclr/master/jitstress/arm_cross_checked_ubuntu_r2r_jitstress1_tst/bin/tests/Linux.arm.Checked/baseservices/threading/mutex/misc/waitone2/waitone2.sh/n
16:59:55         Expected: True
16:59:55         Actual:   False
16:59:55         Stack Trace:
16:59:55           /mnt/j/workspace/dotnet_coreclr/master/arm_cross_checked_ubuntu/bin/tests/Linux.arm.Checked/TestWrappers/baseservices.threading/baseservices.threading.XUnitWrapper.cs(17259,0): at baseservices_threading._mutex_misc_waitone2_waitone2_._mutex_misc_waitone2_waitone2_sh()

[BruceForstall]

Other waitone2 failures: https://github.com/dotnet/coreclr/issues/17632, https://github.com/dotnet/coreclr/issues/18047

[BruceForstall]

@kouvel Have you ever looked at this test to see what might be causing all these problems? I haven't seen it fail recently, but there are still 3 bugs open mentioning it.

[kouvel]

I had looked at the failure several times in the past and haven't found a cause yet, will have to look at it again

[BruceForstall]

Saw it fail again on Windows/x64:
https://ci.dot.net/job/dotnet_coreclr/job/master/view/x64/job/jitstress/job/x64_checked_windows_nt_jitstress2_jitstressregs0x1000/644/consoleFull

23:14:24       baseservices_threading._mutex_misc_waitone2_waitone2_._mutex_misc_waitone2_waitone2_cmd [FAIL]
23:14:24         
23:14:24   
23:14:24   Return code:      1
23:14:24   Raw output file:      D:\j\workspace\x64_checked_w---4f751dcb\bin\tests\Windows_NT.x64.Checked\Reports\baseservices.threading\mutex\misc\waitone2\waitone2.output.txt
23:14:24   Raw output:
23:14:24   BEGIN EXECUTION
23:14:24          "D:\j\workspace\x64_checked_w---4f751dcb\bin\tests\Windows_NT.x64.Checked\Tests\Core_Root\corerun.exe" waitone2.exe 
23:14:24         Beginning test case MutexWaitOne2 at 2/4/2019 11:12:38 PM
23:14:24         Random seed: 20010415; set environment variable CORECLR_SEED to this value to repro
23:14:24         
23:14:24         [Positive]
23:14:24         Beginning scenario: PosTest1: Wait Infinite
23:14:24         Beginning scenario: PosTest2: Wait some finite time
23:14:24         Beginning scenario: PosTest3: Wait some finite time will quit for timeout
23:14:24         ERROR!!!-004: WaitOne returns true when wait time out
23:14:24         Beginning scenario: PosTest4: Wait some finite time will quit for timeout when another thread is in nondefault managed context
23:14:24         Beginning scenario: PosTest5: Wait some finite time will quit for timeout when another thread is in nondefault managed context
23:14:24         Beginning scenario: PosTest6: Wait infinite time when another thread is in nondefault managed context
23:14:24         Beginning scenario: PosTest7: Wait infinite time when another thread is in nondefault managed context
23:14:24         [Negative]
23:14:24         Beginning scenario: NegTest1: AbandonedMutexException should be thrown if a thread exited without releasing a mutex
23:14:24         Beginning scenario: NegTest2: ObjectDisposedException should be thrown if current instance has already been disposed
23:14:24         Beginning scenario: NegTest3: Check ArgumentOutOfRangeException will be thrown if millisecondsTimeout is a negative number other than -1
23:14:24         
23:14:24         Ending test case at 2/4/2019 11:13:19 PM
23:14:24         FAIL
23:14:24         Expected: 100
23:14:24         Actual: 0
23:14:24         END EXECUTION - FAILED
23:14:24         FAILED
23:14:24         Test Harness Exitcode is : 1
23:14:24         
23:14:24   To run the test:
23:14:24   > set CORE_ROOT=D:\j\workspace\x64_checked_w---4f751dcb\bin\tests\Windows_NT.x64.Checked\Tests\Core_Root
23:14:24   > D:\j\workspace\x64_checked_w---4f751dcb\bin\tests\Windows_NT.x64.Checked\baseservices\threading\mutex\misc\waitone2\waitone2.cmd
23:14:24   
23:14:24         Expected: True
23:14:24         Actual:   False
23:14:24         Stack Trace:
23:14:24           D:\j\workspace\x64_checked_w---4f751dcb\bin\tests\Windows_NT.x64.Checked\TestWrappers\baseservices.threading\baseservices.threading.XUnitWrapper.cs(17679,0): at baseservices_threading._mutex_misc_waitone2_waitone2_._mutex_misc_waitone2_waitone2_cmd()

@kouvel This test has been noisy for so long, can we just disable it?

[BruceForstall]

Another failure with same log:
https://ci.dot.net/job/dotnet_coreclr/job/master/view/x64/job/jitstress/job/x64_checked_windows_nt_jitstressregs0x10/753/consoleFull