[wasm][debugger] Random test failure due to a possible race in startup
Failure:
[xUnit.net 00:39:52.49] DebuggerTests.HotReloadTests.DebugHotReloadMethodUnchanged [FAIL]
Failed DebuggerTests.HotReloadTests.DebugHotReloadMethodUnchanged [10 ms]
Error Message:
: Expected Ok result but got [Result: IsOk: False, IsErr: True, Value: , Error: {
"result": {
"type": "object",
"subtype": "error",
"className": "TypeError",
"description": "TypeError: Cannot read properties of undefined (reading 'BINDING')\n at invoke_static_method (http://localhost:9400/debugger-driver.html:25:65)\n at <anonymous>:1:35007\n at mono_wasm_runtime_ready (http://localhost:9400/dotnet.js:3:6539)\n at sc (http://localhost:9400/dotnet.js:3:106750)\n at async Qa (http://localhost:9400/dotnet.js:3:104967)",
"objectId": "-8087959768314858508.1.9"
},
"exceptionDetails": {
"exceptionId": 1,
"text": "Uncaught",
"lineNumber": 24,
"columnNumber": 64,
"scriptId": "3",
"stackTrace": {
"callFrames": [
{
"functionName": "invoke_static_method",
"scriptId": "3",
"url": "http://localhost:9400/debugger-driver.html",
"lineNumber": 24,
"columnNumber": 64
},
{
"functionName": "",
"scriptId": "60",
"url": "",
"lineNumber": 0,
"columnNumber": 35006
},
{
"functionName": "mono_wasm_runtime_ready",
"scriptId": "6",
"url": "http://localhost:9400/dotnet.js",
"lineNumber": 2,
"columnNumber": 6538
},
{
"functionName": "sc",
"scriptId": "6",
"url": "http://localhost:9400/dotnet.js",
"lineNumber": 2,
"columnNumber": 106749
}
]
},
"exception": {
"type": "object",
"subtype": "error",
"className": "TypeError",
"description": "TypeError: Cannot read properties of undefined (reading 'BINDING')\n at invoke_static_method (http://localhost:9400/debugger-driver.html:25:65)\n at <anonymous>:1:35007\n at mono_wasm_runtime_ready (http://localhost:9400/dotnet.js:3:6539)\n at sc (http://localhost:9400/dotnet.js:3:106750)\n at async Qa (http://localhost:9400/dotnet.js:3:104967)",
"objectId": "-8087959768314858508.1.10"
}
}
} ]
Expected: True
Actual: False
Stack Trace:
at DebuggerTests.TestExtensions.AssertOk(Result res, String prefix) in /_/src/mono/wasm/debugger/DebuggerTestSuite/TestExtensions.cs:line 12
at DebuggerTests.DebuggerTestBase.LoadAssemblyAndTestHotReload(String asm_file, String pdb_file, String asm_file_hot_reload, String class_name, String method_name) in /_/src/mono/wasm/debugger/DebuggerTestSuite/DebuggerTestBase.cs:line 1444
at DebuggerTests.HotReloadTests.DebugHotReloadMethodUnchanged() in /_/src/mono/wasm/debugger/DebuggerTestSuite/HotReloadTests.cs:line 39
--- End of stack trace from previous location ---
I think this is because https://github.com/dotnet/runtime/blob/e43e31527db9f1a2dde3095a1651279b272c8c09/src/mono/wasm/debugger/tests/debugger-test/debugger-main.js#L24 .. in ..
https://github.com/dotnet/runtime/blob/e43e31527db9f1a2dde3095a1651279b272c8c09/src/mono/wasm/debugger/tests/debugger-test/debugger-main.js#L9-L25
.. can run after the test starts running which is once Mono.runtimeReady is received from the proxy.
IIUC, mono_wasm_runtime_ready() gets called before createDotnetRuntime returns, which would create a race, because in response to the Mono.runtimeReady message, the test would start to execute, and can call invoke_static_method which would access the as-yet-uninitialized App.runtime.
I might have this wrong, in which case please do explain what I got wrong :)
cc @pavelsavara @thaystg
Tagging subscribers to 'arch-wasm': @lewing See info in area-owners.md if you want to be subscribed.
Issue Details
Failure:
[xUnit.net 00:39:52.49] DebuggerTests.HotReloadTests.DebugHotReloadMethodUnchanged [FAIL]
Failed DebuggerTests.HotReloadTests.DebugHotReloadMethodUnchanged [10 ms]
Error Message:
: Expected Ok result but got [Result: IsOk: False, IsErr: True, Value: , Error: {
"result": {
"type": "object",
"subtype": "error",
"className": "TypeError",
"description": "TypeError: Cannot read properties of undefined (reading 'BINDING')\n at invoke_static_method (http://localhost:9400/debugger-driver.html:25:65)\n at <anonymous>:1:35007\n at mono_wasm_runtime_ready (http://localhost:9400/dotnet.js:3:6539)\n at sc (http://localhost:9400/dotnet.js:3:106750)\n at async Qa (http://localhost:9400/dotnet.js:3:104967)",
"objectId": "-8087959768314858508.1.9"
},
"exceptionDetails": {
"exceptionId": 1,
"text": "Uncaught",
"lineNumber": 24,
"columnNumber": 64,
"scriptId": "3",
"stackTrace": {
"callFrames": [
{
"functionName": "invoke_static_method",
"scriptId": "3",
"url": "http://localhost:9400/debugger-driver.html",
"lineNumber": 24,
"columnNumber": 64
},
{
"functionName": "",
"scriptId": "60",
"url": "",
"lineNumber": 0,
"columnNumber": 35006
},
{
"functionName": "mono_wasm_runtime_ready",
"scriptId": "6",
"url": "http://localhost:9400/dotnet.js",
"lineNumber": 2,
"columnNumber": 6538
},
{
"functionName": "sc",
"scriptId": "6",
"url": "http://localhost:9400/dotnet.js",
"lineNumber": 2,
"columnNumber": 106749
}
]
},
"exception": {
"type": "object",
"subtype": "error",
"className": "TypeError",
"description": "TypeError: Cannot read properties of undefined (reading 'BINDING')\n at invoke_static_method (http://localhost:9400/debugger-driver.html:25:65)\n at <anonymous>:1:35007\n at mono_wasm_runtime_ready (http://localhost:9400/dotnet.js:3:6539)\n at sc (http://localhost:9400/dotnet.js:3:106750)\n at async Qa (http://localhost:9400/dotnet.js:3:104967)",
"objectId": "-8087959768314858508.1.10"
}
}
} ]
Expected: True
Actual: False
Stack Trace:
at DebuggerTests.TestExtensions.AssertOk(Result res, String prefix) in /_/src/mono/wasm/debugger/DebuggerTestSuite/TestExtensions.cs:line 12
at DebuggerTests.DebuggerTestBase.LoadAssemblyAndTestHotReload(String asm_file, String pdb_file, String asm_file_hot_reload, String class_name, String method_name) in /_/src/mono/wasm/debugger/DebuggerTestSuite/DebuggerTestBase.cs:line 1444
at DebuggerTests.HotReloadTests.DebugHotReloadMethodUnchanged() in /_/src/mono/wasm/debugger/DebuggerTestSuite/HotReloadTests.cs:line 39
--- End of stack trace from previous location ---
I think this is because https://github.com/dotnet/runtime/blob/e43e31527db9f1a2dde3095a1651279b272c8c09/src/mono/wasm/debugger/tests/debugger-test/debugger-main.js#L24 .. in ..
https://github.com/dotnet/runtime/blob/e43e31527db9f1a2dde3095a1651279b272c8c09/src/mono/wasm/debugger/tests/debugger-test/debugger-main.js#L9-L25
.. can run after the test starts running which is once Mono.runtimeReady is received from the proxy.
IIUC, mono_wasm_runtime_ready() gets called before createDotnetRuntime returns, which would create a race, because in response to the Mono.runtimeReady message, the test would start to execute, and can call invoke_static_method which would access the as-yet-uninitialized App.runtime.
I might have this wrong, in which case please do explain what I got wrong :)
cc @pavelsavara @thaystg
| Author: | radical |
|---|---|
| Assignees: | - |
| Labels: |
|
| Milestone: | 7.0.0 |
Tagging subscribers to this area: @thaystg See info in area-owners.md if you want to be subscribed.
Issue Details
Failure:
[xUnit.net 00:39:52.49] DebuggerTests.HotReloadTests.DebugHotReloadMethodUnchanged [FAIL]
Failed DebuggerTests.HotReloadTests.DebugHotReloadMethodUnchanged [10 ms]
Error Message:
: Expected Ok result but got [Result: IsOk: False, IsErr: True, Value: , Error: {
"result": {
"type": "object",
"subtype": "error",
"className": "TypeError",
"description": "TypeError: Cannot read properties of undefined (reading 'BINDING')\n at invoke_static_method (http://localhost:9400/debugger-driver.html:25:65)\n at <anonymous>:1:35007\n at mono_wasm_runtime_ready (http://localhost:9400/dotnet.js:3:6539)\n at sc (http://localhost:9400/dotnet.js:3:106750)\n at async Qa (http://localhost:9400/dotnet.js:3:104967)",
"objectId": "-8087959768314858508.1.9"
},
"exceptionDetails": {
"exceptionId": 1,
"text": "Uncaught",
"lineNumber": 24,
"columnNumber": 64,
"scriptId": "3",
"stackTrace": {
"callFrames": [
{
"functionName": "invoke_static_method",
"scriptId": "3",
"url": "http://localhost:9400/debugger-driver.html",
"lineNumber": 24,
"columnNumber": 64
},
{
"functionName": "",
"scriptId": "60",
"url": "",
"lineNumber": 0,
"columnNumber": 35006
},
{
"functionName": "mono_wasm_runtime_ready",
"scriptId": "6",
"url": "http://localhost:9400/dotnet.js",
"lineNumber": 2,
"columnNumber": 6538
},
{
"functionName": "sc",
"scriptId": "6",
"url": "http://localhost:9400/dotnet.js",
"lineNumber": 2,
"columnNumber": 106749
}
]
},
"exception": {
"type": "object",
"subtype": "error",
"className": "TypeError",
"description": "TypeError: Cannot read properties of undefined (reading 'BINDING')\n at invoke_static_method (http://localhost:9400/debugger-driver.html:25:65)\n at <anonymous>:1:35007\n at mono_wasm_runtime_ready (http://localhost:9400/dotnet.js:3:6539)\n at sc (http://localhost:9400/dotnet.js:3:106750)\n at async Qa (http://localhost:9400/dotnet.js:3:104967)",
"objectId": "-8087959768314858508.1.10"
}
}
} ]
Expected: True
Actual: False
Stack Trace:
at DebuggerTests.TestExtensions.AssertOk(Result res, String prefix) in /_/src/mono/wasm/debugger/DebuggerTestSuite/TestExtensions.cs:line 12
at DebuggerTests.DebuggerTestBase.LoadAssemblyAndTestHotReload(String asm_file, String pdb_file, String asm_file_hot_reload, String class_name, String method_name) in /_/src/mono/wasm/debugger/DebuggerTestSuite/DebuggerTestBase.cs:line 1444
at DebuggerTests.HotReloadTests.DebugHotReloadMethodUnchanged() in /_/src/mono/wasm/debugger/DebuggerTestSuite/HotReloadTests.cs:line 39
--- End of stack trace from previous location ---
I think this is because https://github.com/dotnet/runtime/blob/e43e31527db9f1a2dde3095a1651279b272c8c09/src/mono/wasm/debugger/tests/debugger-test/debugger-main.js#L24 .. in ..
https://github.com/dotnet/runtime/blob/e43e31527db9f1a2dde3095a1651279b272c8c09/src/mono/wasm/debugger/tests/debugger-test/debugger-main.js#L9-L25
.. can run after the test starts running which is once Mono.runtimeReady is received from the proxy.
IIUC, mono_wasm_runtime_ready() gets called before createDotnetRuntime returns, which would create a race, because in response to the Mono.runtimeReady message, the test would start to execute, and can call invoke_static_method which would access the as-yet-uninitialized App.runtime.
I might have this wrong, in which case please do explain what I got wrong :)
cc @pavelsavara @thaystg
| Author: | radical |
|---|---|
| Assignees: | - |
| Labels: |
|
| Milestone: | 7.0.0 |
I was able to artificially reproduce this by calling moving App.runtime = runtime; App.init(); to run after a timeout.
we are synchronizing 2 processes here.
- The normal unix dotnet+debug-proxy +xunit
- the wasm app running inside
mono_wasm_runtime_readyis the synchronization helper necessary to make the process 1) wait
@radical said "mono_wasm_runtime_ready indicates that the runtime is ready, but not that the app is ready.. "
and we need both. I will think about some consistent fix.
Moving App.runtime = runtime into callback is possible, but I'm not sure yet if the best thing.
Having an event/message that indicates "app is ready", and having "app is ready" as formal thing would be helpful.
As a workaround, I can add a special message for this in debugger-main.js's App.init, and make the tests wait for that. or even just add a tiny delay after we get runtime ready.
The mono_wasm_runtime_ready is currently called by runtime in non-blazor startup sequence
https://github.com/dotnet/runtime/blob/0c5ca95fec9b6e2cc5e757ad36d0b094f81a59a6/src/mono/wasm/runtime/startup.ts#L297
And blazor calls it here https://github.com/dotnet/aspnetcore/blob/55616fa5b272d6d957d20059a681a68901807486/src/Components/Web.JS/src/Platform/Mono/MonoPlatform.ts#L483
Both environments don't have applications ready at that point. Only the runtime is mostly ready.
cc @maraf