[wasm][mt] Guard more places for blocking wait on JS interop threads by radekdoulik · Pull Request #98508 · dotnet/runtime

radekdoulik · 2024-02-15T17:42:51Z

Extend the tests as well

radekdoulik · 2024-02-15T18:26:31Z

/azp run runtime-wasm

azure-pipelines · 2024-02-15T18:26:50Z

Azure Pipelines successfully started running 1 pipeline(s).

ghost · 2024-02-15T20:06:19Z

Tagging subscribers to 'arch-wasm': @lewing
See info in area-owners.md if you want to be subscribed.

Issue Details

Extend the tests as well

Author:	radekdoulik
Assignees:	radekdoulik
Labels:	`arch-wasm`, `area-System.Runtime.InteropServices.JavaScript`
Milestone:	-

pavelsavara · 2024-02-16T11:45:21Z

Log
Build: https://dev.azure.com/dnceng-public/public/_build/results?buildId=568149

[18:32:33] info: [FAIL] System.Runtime.InteropServices.JavaScript.Tests.WebWorkerTest.ThreadingTimer(executor: Main)
[18:32:33] info: System.PlatformNotSupportedException : Blocking wait is not supported on the JS interop threads.
[18:32:33] info: at System.Threading.Thread.AssureBlockingPossible()
[18:32:33] info: at System.Threading.LowLevelMonitor.AcquireCore()
[18:32:33] info: at System.Threading.LowLevelMonitor.Acquire()
[18:32:33] info: at System.Threading.WaitSubsystem.ThreadWaitInfo.TrySignalToSatisfyWait(WaitedListNode , Boolean )
[18:32:33] info: at System.Threading.WaitSubsystem.WaitableObject.SignalAutoResetEvent()
[18:32:33] info: at System.Threading.WaitSubsystem.WaitableObject.SignalEvent(LockHolder& )
[18:32:33] info: at System.Threading.WaitSubsystem.SetEvent(WaitableObject )
[18:32:33] info: at System.Threading.WaitSubsystem.SetEvent(IntPtr )
[18:32:33] info: at System.Threading.EventWaitHandle.Set()
[18:32:33] info: at System.Threading.TimerQueue.SetTimerPortable(UInt32 )
[18:32:33] info: at System.Threading.TimerQueue.SetTimer(UInt32 )
[18:32:33] info: at System.Threading.TimerQueue.EnsureTimerFiresBy(UInt32 )
[18:32:33] info: at System.Threading.TimerQueue.UpdateTimer(TimerQueueTimer , UInt32 , UInt32 )
[18:32:33] info: at System.Threading.TimerQueueTimer.Change(UInt32 , UInt32 )
[18:32:33] info: at System.Threading.TimerQueueTimer..ctor(TimerCallback , Object , UInt32 , UInt32 , Boolean )
[18:32:33] info: at System.Threading.Timer.TimerSetup(TimerCallback , Object , UInt32 , UInt32 , Boolean )
[18:32:33] info: at System.Threading.Timer..ctor(TimerCallback , Object , Int32 , Int32 , Boolean )
[18:32:33] info: at System.Threading.Timer..ctor(TimerCallback , Object , Int32 , Int32 )
[18:32:33] info: at System.Runtime.InteropServices.JavaScript.Tests.WebWorkerTest.<>c__DisplayClass11_0.<<ThreadingTimer>b__0>d.MoveNext()
[18:32:33] info: --- End of stack trace from previous location ---
[18:32:33] info: at System.Runtime.InteropServices.JavaScript.Tests.Executor.<>c__DisplayClass16_0.<<RunOnTargetAsync>b__0>d.MoveNext()
[18:32:33] info: --- End of stack trace from previous location ---
[18:32:33] info: at System.Runtime.InteropServices.JavaScript.Tests.WebWorkerTest.ThreadingTimer(Executor executor)
[18:32:33] info: --- End of stack trace from previous location ---

radekdoulik · 2024-02-16T12:51:01Z

With #91317 in place, we get asserts from xharness.

@maraf @pavelsavara I think we will need to make xharness to not block on main thread or find a way how to do forced blocking waits in xharness.

fail: [0x000f36a0--UI- 12:53:06.846] MONO_WASM: Blocking wait is not supported on the JS interop threads.
at System.Threading.Thread.AssureBlockingPossible() in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/Thread.cs:line 683
at System.Threading.LowLevelMonitor.AcquireCore() in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/LowLevelMonitor.Unix.cs:line 35
at System.Threading.LowLevelMonitor.Acquire() in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/LowLevelMonitor.cs:line 78
at System.Threading.WaitSubsystem.ThreadWaitInfo.Wait(Int32 , Boolean , Boolean , LockHolder& ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/WaitSubsystem.ThreadWaitInfo.Unix.cs:line 299
at System.Threading.WaitSubsystem.WaitableObject.Wait_Locked(ThreadWaitInfo , Int32 , Boolean , Boolean , LockHolder& ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/WaitSubsystem.WaitableObject.Unix.cs:line 368
at System.Threading.WaitSubsystem.WaitableObject.Wait(ThreadWaitInfo , Int32 , Boolean , Boolean ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/WaitSubsystem.WaitableObject.Unix.cs:line 320
at System.Threading.WaitSubsystem.Wait(WaitableObject , Int32 , Boolean , Boolean ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/WaitSubsystem.Unix.cs:line 339
at System.Threading.WaitSubsystem.Wait(IntPtr , Int32 , Boolean ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/WaitSubsystem.Unix.cs:line 327
at System.Threading.WaitHandle.WaitOneCore(IntPtr , Int32 , Boolean ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/WaitHandle.Unix.cs:line 11
at System.Threading.WaitHandle.WaitOneNoCheck(Int32 , Boolean , Object , WaitHandleWaitSourceMap ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/WaitHandle.cs:line 179
at System.Threading.WaitHandle.WaitOne() in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/WaitHandle.cs:line 504
at Microsoft.DotNet.XHarness.TestRunners.Xunit.XUnitTestRunner.Run(Assembly , String )
at Microsoft.DotNet.XHarness.TestRunners.Xunit.XUnitTestRunner.Run(IEnumerable`1 )
at Microsoft.DotNet.XHarness.TestRunners.Common.ApplicationEntryPoint.InternalRunAsync(LogWriter )
at Microsoft.DotNet.XHarness.TestRunners.Common.ApplicationEntryPoint.InternalRunAsync(ApplicationOptions , TextWriter , TextWriter )
at Microsoft.DotNet.XHarness.TestRunners.Common.WasmApplicationEntryPointBase.RunAsync()
at Microsoft.DotNet.XHarness.TestRunners.Xunit.WasmApplicationEntryPoint.Run()
at WasmTestRunner.Main(String[] args) in /Users/rodo/git/threads-runtime/src/libraries/Common/tests/WasmTestRunner/WasmTestRunner.cs:line 101

pavelsavara · 2024-02-16T13:49:10Z

@maraf @pavelsavara I think we will need to make xharness to not block on main thread or find a way how to do forced blocking waits in xharness.

We have _XUnitBackgroundExec which executes the test on ThreadPool. I thought this is enabled now for all MT unit tests.

maraf · 2024-02-16T14:34:35Z

@maraf @pavelsavara I think we will need to make xharness to not block on main thread or find a way how to do forced blocking waits in xharness.
We have _XUnitBackgroundExec which executes the test on ThreadPool. I thought this is enabled now for all MT unit tests.

Yes, by default MT tests start in background https://github.com/dotnet/runtime/blob/main/eng/testing/tests.browser.targets#L90

@radekdoulik~~Based on the line number in the log (WasmTestRunner.cs:line 101), it seems you are not using the latest WasmTestRunner~~ Sorry, my bad. The background exec was aparently turned off for that run

radekdoulik · 2024-02-16T15:38:26Z

@maraf @pavelsavara I think we will need to make xharness to not block on main thread or find a way how to do forced blocking waits in xharness.
We have _XUnitBackgroundExec which executes the test on ThreadPool. I thought this is enabled now for all MT unit tests.
Yes, by default MT tests start in background https://github.com/dotnet/runtime/blob/main/eng/testing/tests.browser.targets#L90
@radekdoulik~~Based on the line number in the log (WasmTestRunner.cs:line 101), it seems you are not using the latest WasmTestRunner~~ Sorry, my bad. The background exec was aparently turned off for that run

I see, I guess this wasn't working locally because I was setting WasmTestAppArgs="-method ..."

radekdoulik · 2024-02-16T18:54:15Z

/azp run runtime-wasm

azure-pipelines · 2024-02-16T18:54:25Z

Azure Pipelines successfully started running 1 pipeline(s).

pavelsavara · 2024-02-17T11:09:59Z

 await executor.Execute(async () =>
 {
- await Task.Delay(10, cts.Token).ContinueWith(_ =>
+ await ForceBlockingWaitAsync(async () =>


I don't agree that making Task.Delay forbidden operation on UI thread is a way forward.
I think we have to find a way that it never calls blocking .Wait
Here you are just hiding the problem from the unit test, rigth ?

And the same for Timer, there is no theoretical reason why this needs to block.
Except maybe for creating new child thread. If that's the reason, we should add ForceBlockingWaitAsync into new Thread() code.

I don't agree that making Task.Delay forbidden operation on UI thread is a way forward. I think we have to find a way that it never calls blocking .Wait
Here you are just hiding the problem from the unit test, rigth ?
Yes, here I am forcing it to not break the current ManagedDelay_ContinueWith test.
The Task.Delay eventually ends calling System.Threading.LowLevelMonitor.AcquireCore(), which calls to native pthread_mutex_lock - that is a blocking call.
The Timer calls LowLevelMonitor.AcquireCore as well.
Details:
info: System.PlatformNotSupportedException : Blocking wait is not supported on the JS interop threads. info: at System.Threading.Thread.AssureBlockingPossible() in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/Thread.cs:line 683 info: at System.Threading.LowLevelMonitor.AcquireCore() in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/LowLevelMonitor.Unix.cs:line 35 info: at System.Threading.LowLevelMonitor.Acquire() in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/LowLevelMonitor.cs:line 78 info: at System.Threading.WaitSubsystem.ThreadWaitInfo.TrySignalToSatisfyWait(WaitedListNode , Boolean ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/WaitSubsystem.ThreadWaitInfo.Unix.cs:line 448 info: at System.Threading.WaitSubsystem.WaitableObject.SignalAutoResetEvent() in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/WaitSubsystem.WaitableObject.Unix.cs:line 709 info: at System.Threading.WaitSubsystem.WaitableObject.SignalEvent(LockHolder& ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/WaitSubsystem.WaitableObject.Unix.cs:line 658 info: at System.Threading.WaitSubsystem.SetEvent(WaitableObject ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/WaitSubsystem.Unix.cs:line 254 info: at System.Threading.WaitSubsystem.SetEvent(IntPtr ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/WaitSubsystem.Unix.cs:line 244 info: at System.Threading.EventWaitHandle.Set() in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/EventWaitHandle.Unix.cs:line 48 info: at System.Threading.TimerQueue.SetTimerPortable(UInt32 ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/TimerQueue.Portable.cs:line 66 info: at System.Threading.TimerQueue.SetTimer(UInt32 ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/TimerQueue.Unix.cs:line 16 info: at System.Threading.TimerQueue.EnsureTimerFiresBy(UInt32 ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/Timer.cs:line 138 info: at System.Threading.TimerQueue.UpdateTimer(TimerQueueTimer , UInt32 , UInt32 ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/Timer.cs:line 368 info: at System.Threading.TimerQueueTimer.Change(UInt32 , UInt32 ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/Timer.cs:line 561 info: at System.Threading.TimerQueueTimer..ctor(TimerCallback , Object , UInt32 , UInt32 , Boolean ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/Timer.cs:line 516 info: at System.Threading.Tasks.Task.DelayPromise..ctor(UInt32 , TimeProvider ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Task.cs:line 5704 info: at System.Threading.Tasks.Task.DelayPromiseWithCancellation..ctor(UInt32 , TimeProvider , CancellationToken ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Task.cs:line 5749 info: at System.Threading.Tasks.Task.Delay(UInt32 , TimeProvider , CancellationToken ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Task.cs:line 5668 info: at System.Threading.Tasks.Task.Delay(Int32 millisecondsDelay, CancellationToken cancellationToken) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Task.cs:line 5664 info: at System.Runtime.InteropServices.JavaScript.Tests.WebWorkerTest.<>c__DisplayClass15_0.<<ManagedDelay_ContinueWith>b__0>d.MoveNext() in /Users/rodo/git/threads-runtime/src/libraries/System.Runtime.InteropServices.JavaScript/tests/System.Runtime.InteropServices.JavaScript.UnitTests/System/Runtime/InteropServices/JavaScript/WebWorkerTest.cs:line 442
info: [FAIL] System.Runtime.InteropServices.JavaScript.Tests.WebWorkerTest.ThreadingTimer(executor: Main) info: System.PlatformNotSupportedException : Blocking wait is not supported on the JS interop threads. info: at System.Threading.Thread.AssureBlockingPossible() in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/Thread.cs:line 683 info: at System.Threading.LowLevelMonitor.AcquireCore() in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/LowLevelMonitor.Unix.cs:line 35 info: at System.Threading.LowLevelMonitor.Acquire() in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/LowLevelMonitor.cs:line 78 info: at System.Threading.WaitSubsystem.ThreadWaitInfo.TrySignalToSatisfyWait(WaitedListNode , Boolean ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/WaitSubsystem.ThreadWaitInfo.Unix.cs:line 448 info: at System.Threading.WaitSubsystem.WaitableObject.SignalAutoResetEvent() in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/WaitSubsystem.WaitableObject.Unix.cs:line 709 info: at System.Threading.WaitSubsystem.WaitableObject.SignalEvent(LockHolder& ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/WaitSubsystem.WaitableObject.Unix.cs:line 658 info: at System.Threading.WaitSubsystem.SetEvent(WaitableObject ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/WaitSubsystem.Unix.cs:line 254 info: at System.Threading.WaitSubsystem.SetEvent(IntPtr ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/WaitSubsystem.Unix.cs:line 244 info: at System.Threading.EventWaitHandle.Set() in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/EventWaitHandle.Unix.cs:line 48 info: at System.Threading.TimerQueue.SetTimerPortable(UInt32 ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/TimerQueue.Portable.cs:line 66 info: at System.Threading.TimerQueue.SetTimer(UInt32 ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/TimerQueue.Unix.cs:line 16 info: at System.Threading.TimerQueue.EnsureTimerFiresBy(UInt32 ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/Timer.cs:line 138 info: at System.Threading.TimerQueue.UpdateTimer(TimerQueueTimer , UInt32 , UInt32 ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/Timer.cs:line 368 info: at System.Threading.TimerQueueTimer.Change(UInt32 , UInt32 ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/Timer.cs:line 561 info: at System.Threading.TimerQueueTimer..ctor(TimerCallback , Object , UInt32 , UInt32 , Boolean ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/Timer.cs:line 516 info: at System.Threading.Timer.TimerSetup(TimerCallback , Object , UInt32 , UInt32 , Boolean ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/Timer.cs:line 905 info: at System.Threading.Timer..ctor(TimerCallback , Object , Int32 , Int32 , Boolean ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/Timer.cs:line 845 info: at System.Threading.Timer..ctor(TimerCallback , Object , Int32 , Int32 ) in /Users/rodo/git/threads-runtime/src/libraries/System.Private.CoreLib/src/System/Threading/Timer.cs:line 832 info: at System.Runtime.InteropServices.JavaScript.Tests.WebWorkerTest.<>c__DisplayClass11_0.<<ThreadingTimer>b__0>d.MoveNext() in /Users/rodo/git/threads-runtime/src/libraries/System.Runtime.InteropServices.JavaScript/tests/System.Runtime.InteropServices.JavaScript.UnitTests/System/Runtime/InteropServices/JavaScript/WebWorkerTest.cs:line 371

pavelsavara · 2024-02-22T10:13:39Z

+ {
+ throw;
+ }
+ /* ignore the local one */


@mkhamoyan Radek improved it here.

Thanks, will update in my PR.

I don't agree anymore

…re-blocking-wait-detection-and-tests

pavelsavara · 2024-03-15T19:09:47Z

Closing in favor of #99833

[wasm][mt] Guard more places for blocking wait on JS interop threads
9cf90be
Extend the tests as well

radekdoulik requested review from lewing and pavelsavara as code owners February 15, 2024 17:42

ghost added the area-System.Runtime.InteropServices.JavaScript label Feb 15, 2024

ghost assigned radekdoulik Feb 15, 2024

pavelsavara reviewed Feb 15, 2024
View reviewed changes

Comment thread...eropServices.JavaScript.UnitTests/System/Runtime/InteropServices/JavaScript/WebWorkerTest.cs
Comment thread...Services.JavaScript.UnitTests/System/Runtime/InteropServices/JavaScript/WebWorkerTestBase.cs Outdated

pavelsavara added the arch-wasm WebAssembly architecture label Feb 15, 2024

Feedback
468bea0

build-analysisBot mentioned this pull request Feb 16, 2024
Unhandled exception. System.Exception: Profilee returned exit code 139 instead of expected exit code 100 #98500
Closed

Feedback
aca8dd5

pavelsavara previously approved these changes Feb 16, 2024
View reviewed changes

Fix existing tests
157b487

build-analysisBot mentioned this pull request Feb 16, 2024
[8.0] Failing to build native components #94823
Closed

pavelsavara reviewed Feb 17, 2024
View reviewed changes

pavelsavara reviewed Feb 22, 2024
View reviewed changes

pavelsavara self-requested a review February 22, 2024 10:14

pavelsavara mentioned this pull request Feb 22, 2024
[browser][MT] Log ManagedThreadId and NativeThreadId for known test failures #98291
Merged

Merge remote-tracking branch 'remotes/origin/main' into pr-wasm-mt-mo…
bc688a3
…re-blocking-wait-detection-and-tests

This was referenced Feb 27, 2024
Tracking issue for CI build timeouts #76454
Closed
"We stopped hearing from agent Azure Pipelines 32. Verify the agent machine is running and has a healthy network connection" dotnet/dnceng#1886
Open
[browser][MT] Unhandled JS error #97546
Closed

pavelsavara closed this Mar 15, 2024

github-actionsBot locked and limited conversation to collaborators Apr 15, 2024

Uh oh!

Conversation

radekdoulik commented Feb 15, 2024

Uh oh!

radekdoulik commented Feb 15, 2024

Uh oh!

azure-pipelinesBot commented Feb 15, 2024

Uh oh!

Uh oh!

Uh oh!

ghost commented Feb 15, 2024

Uh oh!

pavelsavara commented Feb 16, 2024

Uh oh!

radekdoulik commented Feb 16, 2024• edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

pavelsavara commented Feb 16, 2024

Uh oh!

maraf commented Feb 16, 2024• edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

radekdoulik commented Feb 16, 2024

Uh oh!

radekdoulik commented Feb 16, 2024

Uh oh!

azure-pipelinesBot commented Feb 16, 2024

Uh oh!

pavelsavaraFeb 17, 2024

Choose a reason for hiding this comment

Uh oh!

pavelsavaraFeb 17, 2024• edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

radekdoulikFeb 27, 2024

Choose a reason for hiding this comment

Uh oh!

pavelsavaraFeb 22, 2024

Choose a reason for hiding this comment

Uh oh!

mkhamoyanFeb 22, 2024

Choose a reason for hiding this comment

Uh oh!

pavelsavara commented Mar 15, 2024

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

radekdoulik commented Feb 16, 2024•
edited
Loading

maraf commented Feb 16, 2024•
edited
Loading

pavelsavaraFeb 17, 2024•
edited
Loading