search

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

[wasm] `DebuggerTests.MiscTests.DebuggerTests.MiscTests.TestDebugUsingMultiThreadedRuntime` failing #89909

Open radical opened 1 year ago

radical commented 1 year ago

Build Information

Build: https://dev.azure.com/dnceng-public/cbb18261-c48f-4abb-8651-8cdcb5474649/_build/results?buildId=361663 Build error leg or test failing: DebuggerTests.MiscTests.DebuggerTests.MiscTests.TestDebugUsingMultiThreadedRuntime Pull request: https://github.com/dotnet/runtime/pull/89890

Error Message

Fill the error message using step by step known issues guidance.

{
  "ErrorMessage": "",
  "ErrorPattern": "at Newtonsoft.Json.Linq.JArray.get_Item|GetValues: .*memory access out of bounds",
  "BuildRetry": false,
  "ExcludeConsoleLog": false
}

Known issue validation

Build: :mag_right: Result validation: :warning: Provided build not found. Provide a valid build in the "Build: :mag_right:" line. Validation performed at: 8/23/2023 4:28:55 AM UTC

Report

Summary

24-Hour Hit Count 7-Day Hit Count 1-Month Count
0 0 0
ghost commented 1 year ago

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

Issue Details
## Build Information Build: https://dev.azure.com/dnceng-public/cbb18261-c48f-4abb-8651-8cdcb5474649/_build/results?buildId=361663 Build error leg or test failing: DebuggerTests.MiscTests.DebuggerTests.MiscTests.TestDebugUsingMultiThreadedRuntime Pull request: https://github.com/dotnet/runtime/pull/89890 ## Error Message Fill the error message using [step by step known issues guidance](https://github.com/dotnet/arcade/blob/main/Documentation/Projects/Build%20Analysis/KnownIssues.md#how-to-fill-out-a-known-issue-error-section). ```json { "ErrorMessage": "", "ErrorPattern": "at Newtonsoft.Json.Linq.JArray.get_Item", "BuildRetry": false, "ExcludeConsoleLog": false } ```
Author: radical
Assignees: -
Labels: `arch-wasm`, `blocking-clean-ci`, `untriaged`, `area-Debugger-mono`, `Known Build Error`, `needs-area-label`
Milestone: -
pavelsavara commented 1 year ago

RuntimeError: memory access out of bounds Log

[xUnit.net 00:03:07.85]     DebuggerTests.MiscTests.TestDebugUsingMultiThreadedRuntime [FAIL]
  Failed DebuggerTests.MiscTests.TestDebugUsingMultiThreadedRuntime [312 ms]
  Error Message:
   [Runtime.getProperties returned False instead of True, for {
  "objectId": "dotnet:scope:1"
}, with Result: [Result: IsOk: False, IsErr: True, Value: , Error: {
  "message": "RuntimeGetProperties: Failed to get properties for dotnet:scope:1: 
System.Exception: Error resolving scope properties SendDebuggerAgentCommand failed for GetValues: [Result: IsOk: False, IsErr: True, Value: , Error: {\n  \"result\": {\n    \"type\": \"object\",\n    \"subtype\": \"error\",\n    
\"className\": \"RuntimeError\",\n    \"description\": \"RuntimeError: memory access out of bounds\\n    at http://localhost:9400/_framework/dotnet.native.wasm:wasm-function[2794]:0xca9f8\\n    at http://localhost:9400/_framework/dotnet.native.wasm:wasm-function[2793]:0xca9bf\\n    at http://localhost:9400/_framework/dotnet.native.wasm:wasm-function[1725]:0x7dd2c\\n    at http://localhost:9400/_framework/dotnet.native.wasm:wasm-function[1798]:0x87339\\n    at http://localhost:9400/_framework/dotnet.native.wasm:wasm-function[1666]:0x7a8c8\\n    at Module._mono_wasm_send_dbg_command [as mono_wasm_send_dbg_command] (http://localhost:9400/_framework/dotnet.native.js:8:152890)\\n    at Object.Yt [as mono_wasm_send_dbg_command] (http://localhost:9400/_framework/dotnet.runtime.js:3:23153)\\n    at <anonymous>:1:30\\n    at mono_wasm_fire_debugger_agent_message_with_data_to_pause (http://localhost:9400/_framework/dotnet.runtime.js:3:22379)\\n    at mono_wasm_fire_debugger_agent_message_with_data (http://localhost:9400/_framework/dotnet.runtime.js:3:22450)\",\n    \"objectId\": \"-4071294141316437108.1.72\"\n  },\n  \"exceptionDetails\": {\n    \"exceptionId\": 3,\n    \"text\": \"Uncaught\",\n    \"lineNumber\": 0,\n    \"columnNumber\": 829944,\n    \"scriptId\": \"5\",\n    \"stackTrace\": {\n      \"callFrames\": [\n        {\n          \"functionName\": \"$func2794\",\n          \"scriptId\": \"5\",\n          \"url\": \"http://localhost:9400/_framework/dotnet.native.wasm\",\n          \"lineNumber\": 0,\n          \"columnNumber\": 829944\n        },\n        {\n          \"functionName\": \"$func2793\",\n          \"scriptId\": \"5\",\n          \"url\": \"http://localhost:9400/_framework/dotnet.native.wasm\",\n          \"lineNumber\": 0,\n          \"columnNumber\": 829887\n        },\n        {\n          \"functionName\": \"$func1725\",\n          \"scriptId\": \"5\",\n          \"url\": \"http://localhost:9400/_framework/dotnet.native.wasm\",\n          \"lineNumber\": 0,\n          \"columnNumber\": 515372\n        },\n        {\n          \"functionName\": \"$func1798\",\n          \"scriptId\": \"5\",\n          \"url\": \"http://localhost:9400/_framework/dotnet.native.wasm\",\n          \"lineNumber\": 0,\n          \"columnNumber\": 553785\n        },\n        {\n          \"functionName\": \"$mono_wasm_send_dbg_command\",\n          \"scriptId\": \"5\",\n          \"url\": \"http://localhost:9400/_framework/dotnet.native.wasm\",\n          \"lineNumber\": 0,\n          \"columnNumber\": 501960\n        },\n        {\n          \"functionName\": \"Module._mono_wasm_send_dbg_command\",\n          \"scriptId\": \"7\",\n          \"url\": \"http://localhost:9400/_framework/dotnet.native.js\",\n          \"lineNumber\": 7,\n          \"columnNumber\": 152889\n        },\n        {\n          \"functionName\": \"Yt\",\n          \"scriptId\": \"8\",\n          \"url\": \"http://localhost:9400/_framework/dotnet.runtime.js\",\n          \"lineNumber\": 2,\n          \"columnNumber\": 23152\n        },\n        {\n          \"functionName\": \"\",\n          \"scriptId\": \"50\",\n          \"url\": \"\",\n          \"lineNumber\": 0,\n          \"columnNumber\": 29\n        },\n        {\n          \"functionName\": \"mono_wasm_fire_debugger_agent_message_with_data_to_pause\",\n          \"scriptId\": \"8\",\n          \"url\": \"http://localhost:9400/_framework/dotnet.runtime.js\",\n          \"lineNumber\": 2,\n          \"columnNumber\": 22378\n        },\n        {\n          \"functionName\": \"mono_wasm_fire_debugger_agent_message_with_data\",\n          \"scriptId\": \"8\",\n          \"url\": \"http://localhost:9400/_framework/dotnet.runtime.js\",\n          \"lineNumber\": 2,\n          \"columnNumber\": 22449\n        },\n        {\n          \"functionName\": \"$func1672\",\n          \"scriptId\": \"5\",\n          \"url\": \"http://localhost:9400/_framework/dotnet.native.wasm\",\n          \"lineNumber\": 0,\n          \"columnNumber\": 502446\n        },\n        {\n          \"functionName\": \"$func1844\",\n          \"scriptId\": \"5\",\n          \"url\": \"http://localhost:9400/_framework/dotnet.native.wasm\",\n          \"lineNumber\": 0,\n          \"columnNumber\": 577867\n        },\n        {\n          \"functionName\": \"$func1784\",\n          \"scriptId\": \"5\",\n          \"url\": \"http://localhost:9400/_framework/dotnet.native.wasm\",\n          \"lineNumber\": 0,\n          \"columnNumber\": 535782\n        },\n        {\n          \"functionName\": \"$func1783\",\n          \"scriptId\": \"5\",\n          \"url\": \"http://localhost:9400/_framework/dotnet.native.wasm\",\n          \"lineNumber\": 0,\n          \"columnNumber\": 534251\n        },\n        {\n          \"functionName\": \"$func1707\",\n          \"scriptId\": \"5\",\n          \"url\": \"http://localhost:9400/_framework/dotnet.native.wasm\",\n          \"lineNumber\": 0,\n          \"columnNumber\": 512879\n        },\n        {\n          \"functionName\": \"$func1669\",\n          \"scriptId\": \"5\",\n          \"url\": \"http://localhost:9400/_framework/dotnet.native.wasm\",\n          \"lineNumber\": 0,\n          \"columnNumber\": 502064\n        },\n        {\n          \"functionName\": \"$func266\",\n          \"scriptId\": \"5\",\n          \"url\": \"http://localhost:9400/_framework/dotnet.native.wasm\",\n          \"lineNumber\": 0,\n          \"columnNumber\": 153264\n        },\n        {\n          \"functionName\": \"$func263\",\n          \"scriptId\": \"5\",\n          \"url\": \"http://localhost:9400/_framework/dotnet.native.wasm\",\n          \"lineNumber\": 0,\n          \"columnNumber\": 142811\n        },\n        {\n          \"functionName\": \"$func299\",\n          \"scriptId\": \"5\",\n          \"url\": \"http://localhost:9400/_framework/dotnet.native.wasm\",\n          \"lineNumber\": 0,\n          \"columnNumber\": 158999\n        },\n        {\n          \"functionName\": \"$func3564\",\n          \"scriptId\": \"5\",\n          \"url\": \"http://localhost:9400/_framework/dotnet.native.wasm\",\n          \"lineNumber\": 0,\n          \"columnNumber\": 1026155\n        },\n        {\n          \"functionName\": \"$func2835\",\n          \"scriptId\": \"5\",\n          \"url\": \"http://localhost:9400/_framework/dotnet.native.wasm\",\n          \"lineNumber\": 0,\n          \"columnNumber\": 838445\n        },\n        {\n          \"functionName\": \"$func2834\",\n          \"scriptId\": \"5\",\n          \"url\": \"http://localhost:9400/_framework/dotnet.native.wasm\",\n          \"lineNumber\": 0,\n          \"columnNumber\": 838333\n        },\n        {\n          \"functionName\": \"$func2988\",\n          \"scriptId\": \"5\",\n          \"url\": \"http://localhost:9400/_framework/dotnet.native.wasm\",\n          \"lineNumber\": 0,\n          \"columnNumber\": 868995\n        },\n        {\n          \"functionName\": \"invokeEntryPoint\",\n          \"scriptId\": \"7\",\n          \"url\": \"http://localhost:9400/_framework/dotnet.native.js\",\n          \"lineNumber\": 7,\n          \"columnNumber\": 68740\n        },\n        {\n          \"functionName\": \"handleMessage\",\n          \"scriptId\": \"4\",\n          \"url\": \"http://localhost:9400/_framework/dotnet.native.worker.js\",\n          \"lineNumber\": 0,\n          \"columnNumber\": 2305\n        }\n      ],\n      \"parentId\": {\n        \"id\": \"34\",\n        \"debuggerId\": \"-4468978960161569201.7625199215478716467\"\n      }\n    },\n    \"exception\": {\n      \"type\": \"object\",\n      \"subtype\": \"error\",\n      \"className\": \"RuntimeError\",\n      \"description\": \"RuntimeError: memory access out of bounds\\n    at http://localhost:9400/_framework/dotnet.native.wasm:wasm-function[2794]:0xca9f8\\n    at http://localhost:9400/_framework/dotnet.native.wasm:wasm-function[2793]:0xca9bf\\n    at http://localhost:9400/_framework/dotnet.native.wasm:wasm-function[1725]:0x7dd2c\\n    at http://localhost:9400/_framework/dotnet.native.wasm:wasm-function[1798]:0x87339\\n    at http://localhost:9400/_framework/dotnet.native.wasm:wasm-function[1666]:0x7a8c8\\n    at Module._mono_wasm_send_dbg_command [as mono_wasm_send_dbg_command] (http://localhost:9400/_framework/dotnet.native.js:8:152890)\\n    at Object.Yt [as mono_wasm_send_dbg_command] (http://localhost:9400/_framework/dotnet.runtime.js:3:23153)\\n    at <anonymous>:1:30\\n    at mono_wasm_fire_debugger_agent_message_with_data_to_pause (http://localhost:9400/_framework/dotnet.runtime.js:3:22379)\\n    at mono_wasm_fire_debugger_agent_message_with_data (http://localhost:9400/_framework/dotnet.runtime.js:3:22450)\",\n      \"objectId\": \"-4071294141316437108.1.73\"\n    }\n  }\n} ]\n   at Microsoft.WebAssembly.Diagnostics.MonoProxy.GetScopeProperties(SessionId msg_id, Int32 scopeId, CancellationToken token) in /_/src/mono/wasm/debugger/BrowserDebugProxy/MonoProxy.cs:line 1533\n   at Microsoft.WebAssembly.Diagnostics.MonoProxy.RuntimeGetObjectMembers(SessionId id, DotnetObjectId objectId, JToken args, CancellationToken token, Boolean sortByAccessLevel) in /_/src/mono/wasm/debugger/BrowserDebugProxy/MonoProxy.cs:line 840"
} ]]

Expected: True
Actual:   False
  Stack Trace:
     at DebuggerTests.DebuggerTestBase.AssertEqual(Object expected, Object actual, String label) in /_/src/mono/wasm/debugger/DebuggerTestSuite/DebuggerTestBase.cs:line 1299
   at DebuggerTests.DebuggerTestBase.GetProperties(String id, JToken fn_args, Nullable`1 own_properties, Nullable`1 accessors_only, Boolean expect_ok) in /_/src/mono/wasm/debugger/DebuggerTestSuite/DebuggerTestBase.cs:line 1056
   at DebuggerTests.MiscTests.TestDebugUsingMultiThreadedRuntime() in /_/src/mono/wasm/debugger/DebuggerTestSuite/MiscTests.cs:line 1182
--- End of stack trace from previous location ---
  Standard Output Messages:
pavelsavara commented 1 year ago

Here the debugger test is calling into runtime via legacy JS interop method (probably on main thread) but it's not having correct GC transition barrier.

@kg @lambdageek is my analysis right ?

In which case that should be separate issue.

Log

 {
          "functionName": "$mono_wasm_invoke_method_ref",
          "scriptId": "10",
          "url": "http://localhost:9400/_framework/dotnet.native.wasm",
          "lineNumber": 0,
          "columnNumber": 80961
        },
        {
          "functionName": "Module._mono_wasm_invoke_method_ref",
          "scriptId": "9",
          "url": "http://localhost:9400/_framework/dotnet.native.js",
          "lineNumber": 7,
          "columnNumber": 143113
        },

...snip

console.error: Error: [MONO] /__w/1/s/src/mono/mono/utils/mono-threads-state-machine.c:807 <disabled>
   at It (http://localhost:9400/_framework/dotnet.runtime.js:3:13374)
lambdageek commented 1 year ago

Yea I think you're right @pavelsavara

thaystg commented 1 year ago

I will work on it today.

pavelsavara commented 7 months ago

So, legacy interop is gone now and with it the assumed GC boundary problems of it. I see new issue

Log Build

[xUnit.net 00:01:56.08]     DebuggerTests.MiscTests.TestDebugUsingMultiThreadedRuntime(_attempt: 5) [FAIL]
  Failed DebuggerTests.MiscTests.TestDebugUsingMultiThreadedRuntime(_attempt: 5) [57 s]
  Error Message:
   System.Threading.Tasks.TaskCanceledException : Test timed out (elapsed time: 60.0038633)
  Stack Trace:
     at DebuggerTests.DebuggerTestBase.WaitFor(String what) in /_/src/mono/browser/debugger/DebuggerTestSuite/DebuggerTestBase.cs:line 284
   at DebuggerTests.DebuggerTestBase.SendCommandAndCheck(JObject args, String method, String script_loc, Int32 line, Int32 column, String function_name, Func`2 wait_for_event_fn, Func`2 locals_fn, String waitForEvent) in /_/src/mono/browser/debugger/DebuggerTestSuite/DebuggerTestBase.cs:line 688
   at DebuggerTests.DebuggerTestBase.StepAndCheck(StepKind kind, String script_loc, Int32 line, Int32 column, String function_name, Func`2 wait_for_event_fn, Func`2 locals_fn, Int32 times) in /_/src/mono/browser/debugger/DebuggerTestSuite/DebuggerTestBase.cs:line 640
   at DebuggerTests.MiscTests.TestDebugUsingMultiThreadedRuntime(Int32 _attempt) in /_/src/mono/browser/debugger/DebuggerTestSuite/MiscTests.cs:line 1197
--- End of stack trace from previous location ---
  Standard Output Messages:
 | [2024-01-20T18:22:17] DebuggerTests.TestHarnessProxy Debug: [testId: 17] TestHarnessStartup done
 | [2024-01-20T18:22:17] DebuggerTests.TestHarnessProxy Debug: TestHarnessStartup: closing for 17
 | [2024-01-20T18:22:17] DebuggerTests.TestHarnessProxy Information: [testId: 18] New test request for test id 18
 | [2024-01-20T18:22:17] DebuggerTests.TestHarnessProxy Debug: [18] Starting /root/helix/work/correlation/chrome-linux/chrome with --no-sandbox --headless --disable-gpu --lang=en-US --incognito --remote-debugging-port=0 about:blank
 | [2024-01-20T18:22:18] DebuggerTests.TestHarnessProxy Debug: [testId: 18] browser-stderr [0120/182218.036167:WARNING:bluez_dbus_manager.cc(248)] Floss manager not present, cannot set Floss enable/disable.
 | [2024-01-20T18:22:18] DebuggerTests.TestHarnessProxy Debug: [testId: 18] browser-stderr 
 | [2024-01-20T18:22:18] DebuggerTests.TestHarnessProxy Debug: [testId: 18] browser-stderr DevTools listening on ws://127.0.0.1:40115/devtools/browser/a898adbb-349f-4b12-a7a3-647dbb6aa6c1
 | [2024-01-20T18:22:18] DebuggerTests.TestHarnessProxy Debug: [testId: 18] browser-stderr [0120/182218.070658:WARNING:sandbox_linux.cc(400)] InitializeSandbox() called with multiple threads in process gpu-process.
 | [2024-01-20T18:22:18] DebuggerTests.TestHarnessProxy Information: [testId: 18] launching proxy for ws://127.0.0.1:40115/devtools/page/26163E33E5C64B436AAB53A4A40666EB
 | [2024-01-20T18:22:18] Inspector-18 Information: waiting for the runtime to be ready
 | [2024-01-20T18:22:20] Inspector-18 Information: runtime ready, TEST TIME
 | [2024-01-20T18:22:20] Inspector-18 Information: console.log: Thread:3 - y
 | [2024-01-20T18:22:20] Inspector-18 Information: console.log: Thread:5 - y
 | [2024-01-20T18:22:20] Inspector-18 Information: console.log: Thread:4 - y

[xUnit.net 00:02:03.80]     DebuggerTests.MiscTests.InspectTaskAtLocals [SKIP]

It look like deadlock.

jeffschwMSFT commented 6 months ago

removing blocking-clean-ci as it has not failed in 30 days

24-Hour Hit Count 7-Day Hit Count 1-Month Count
0 0 0
lewing commented 4 months ago

leaving open since these may still be running in servicing but these tests are disabled in main