Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[WASM] dynamically compiled method with infinite loop renders the runtime non-functional #98855

Closed
JakeYallop opened this issue Feb 23, 2024 · 9 comments · Fixed by #99032
Closed
Labels
arch-wasm WebAssembly architecture area-Codegen-Interpreter-mono os-browser Browser variant of arch-wasm
Milestone

Comments

@JakeYallop
Copy link
Contributor

JakeYallop commented Feb 23, 2024

Description

Attempting to execute a dynamically compiled method that contains an infinite loop

while (true) { }

Results in the runtime becoming non functional. There is an error that appears in the browser console. Any subsequent requests to the runtime fail with the same error.

Error: [MONO] /__w/1/s/src/mono/mono/eglib/gmem.c:123 <disabled>
    at ht (logging.ts:95:18)
    at Ul (logging.ts:119:27)
    at wasm_trace_logger (00a88aba:0x1e7f43)
    at eglib_log_adapter (00a88aba:0x3aa8a)
    at monoeg_g_logv_nofree (00a88aba:0x37657)
    at monoeg_g_log (00a88aba:0x3771a)
    at g_log_disabled (00a88aba:0x3774d)
    at monoeg_malloc (00a88aba:0x3745a)
    at mono_mempool_new (00a88aba:0x91bd9)
    at mono_interp_transform_method (00a88aba:0x27fe2)
Full stack trace
Error: [MONO] /__w/1/s/src/mono/mono/eglib/gmem.c:123 <disabled>
    at ht (logging.ts:95:18)
    at Ul (logging.ts:119:27)
    at wasm_trace_logger (00a88aba:0x1e7f43)
    at eglib_log_adapter (00a88aba:0x3aa8a)
    at monoeg_g_logv_nofree (00a88aba:0x37657)
    at monoeg_g_log (00a88aba:0x3771a)
    at g_log_disabled (00a88aba:0x3774d)
    at monoeg_malloc (00a88aba:0x3745a)
    at mono_mempool_new (00a88aba:0x91bd9)
    at mono_interp_transform_method (00a88aba:0x27fe2)
Ul @ logging.ts:119
$func8039 @ 00a88aba:0x1e7f43
$func761 @ 00a88aba:0x3aa8a
$func682 @ 00a88aba:0x37657
$func684 @ 00a88aba:0x3771a
$func685 @ 00a88aba:0x3774d
$func672 @ 00a88aba:0x3745a
$func2011 @ 00a88aba:0x91bd9
$func286 @ 00a88aba:0x27fe2
$func111 @ 00a88aba:0x149b4
$func110 @ 00a88aba:0x1472e
$func179 @ 00a88aba:0x177c1
$func200 @ 00a88aba:0x17fb2
$func7998 @ 00a88aba:0x1e3557
$mono_wasm_execute_timer @ 00a88aba:0xdd6b1
e.<computed> @ cwraps.ts:338
mono_wasm_schedule_timer_tick @ scheduling.ts:75
callUserCallback @ dotnet.native.js:8
(anonymous) @ dotnet.native.js:8

Reproduction Steps

The issue can be seen here:

https://infinite-loop-dynamic.wasmsharp.pages.dev/

On my machine, it consistently takes ~5 seconds after clicking "Run Code", before the error in the console appears.

Expected behavior

The runtime hangs.

Interestingly, this is exactly what happens for a non-dynamically compiled method that includes a while (true) { } loop. https://infinite-loop-precompiled.wasmsharp.pages.dev/ has a loop inserted into the run method:

https://github.com/JakeYallop/WasmSharp/blob/infinite-loop-in-run/packages/core/src/Services/CodeSession.cs#L149

Clicking the "Run Code" button ends up with the runtime hanging, with no errors after a a while.

Actual behavior

An error occurs.

Taking a memory snapshot in DevTools after the error shows ~2GB of memory requested:
image

However, the actual allocated size of objects says that its much smaller:
image

It does not really make much sense to me.

A memory issue might make some sense given that the error stack trace contains /__w/1/s/src/mono/mono/eglib/gmem.c:123.

Regression?

No response

Known Workarounds

No response

Configuration

dotnet workload --info
Workload version: 8.0.200-manifests.5638171e
 [wasm-tools]
   Installation Source: SDK 8.0.200-preview.23624, VS 17.9.34518.117
   Manifest Version:    8.0.2/8.0.100
   Manifest Path:       C:\Program Files\dotnet\sdk-manifests\8.0.100\microsoft.net.workload.mono.toolchain.current\8.0.2\WorkloadManifest.json
   Install Type:              Msi

Full dotnet --info output

.NET SDK:
 Version:           8.0.200-preview.23624.5
 Commit:            8065b9770c
 Workload version:  8.0.200-manifests.5638171e

Runtime Environment:
 OS Name:     Windows
 OS Version:  10.0.22621
 OS Platform: Windows
 RID:         win-x64
 Base Path:   C:\Program Files\dotnet\sdk\8.0.200-preview.23624.5\

.NET workloads installed:
 Workload version: 8.0.200-manifests.5638171e
 [wasm-tools]
   Installation Source: SDK 8.0.200-preview.23624, VS 17.9.34518.117
   Manifest Version:    8.0.2/8.0.100
   Manifest Path:       C:\Program Files\dotnet\sdk-manifests\8.0.100\microsoft.net.workload.mono.toolchain.current\8.0.2\WorkloadManifest.json
   Install Type:              Msi

 [maui-windows]
   Installation Source: VS 17.9.34518.117
   Manifest Version:    8.0.6/8.0.100
   Manifest Path:       C:\Program Files\dotnet\sdk-manifests\8.0.100\microsoft.net.sdk.maui\8.0.6\WorkloadManifest.json
   Install Type:              Msi

 [maccatalyst]
   Installation Source: VS 17.9.34518.117
   Manifest Version:    17.2.8022/8.0.100
   Manifest Path:       C:\Program Files\dotnet\sdk-manifests\8.0.100\microsoft.net.sdk.maccatalyst\17.2.8022\WorkloadManifest.json
   Install Type:              Msi

 [android]
   Installation Source: VS 17.9.34518.117
   Manifest Version:    34.0.79/8.0.100
   Manifest Path:       C:\Program Files\dotnet\sdk-manifests\8.0.100\microsoft.net.sdk.android\34.0.79\WorkloadManifest.json
   Install Type:              Msi

 [ios]
   Installation Source: VS 17.9.34518.117
   Manifest Version:    17.2.8022/8.0.100
   Manifest Path:       C:\Program Files\dotnet\sdk-manifests\8.0.100\microsoft.net.sdk.ios\17.2.8022\WorkloadManifest.json
   Install Type:              Msi


Host:
  Version:      8.0.2
  Architecture: x64
  Commit:       1381d5ebd2

.NET SDKs installed:
  8.0.102 [C:\Program Files\dotnet\sdk]
  8.0.200-preview.23624.5 [C:\Program Files\dotnet\sdk]

.NET runtimes installed:
  Microsoft.AspNetCore.App 6.0.25 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 7.0.14 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 8.0.0 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 8.0.2 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.NETCore.App 6.0.25 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 7.0.14 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 8.0.0 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 8.0.2 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.WindowsDesktop.App 6.0.25 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 7.0.14 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 8.0.0 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 8.0.2 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]

Other architectures found:
  x86   [C:\Program Files (x86)\dotnet]
    registered at [HKLM\SOFTWARE\dotnet\Setup\InstalledVersions\x86\InstallLocation]

Environment variables:
  Not set

global.json file:
  Not found

Learn more:
  https://aka.ms/dotnet/info

Download .NET:
  https://aka.ms/dotnet/download

Other information

The runtime is running from inside a web worker.

@ghost ghost added the untriaged New issue has not been triaged by the area owner label Feb 23, 2024
@dotnet-issue-labeler dotnet-issue-labeler bot added the needs-area-label An area label is needed to ensure this gets routed to the appropriate area owners label Feb 23, 2024
@JakeYallop
Copy link
Contributor Author

As an aside - using the "Allocation instrumentation on timeline" option doesn't really show anything either (start recording -> reproduce bug -> stop recording):
image

If recording a memory snapshot yourself, make sure to select the web worker, as that is what the runtime is executing inside of:
image

@lewing
Copy link
Member

lewing commented Feb 23, 2024

cc @kg

@lewing lewing added os-browser Browser variant of arch-wasm area-Codegen-Interpreter-mono labels Feb 23, 2024
@ghost
Copy link

ghost commented Feb 23, 2024

Tagging subscribers to this area: @BrzVlad, @kotlarmilos
See info in area-owners.md if you want to be subscribed.

Issue Details

Description

Attempting to execute a dynamically compiled method that contains an infinite loop

while (true) { }

Results in the runtime becoming non functional. There is an error that appears in the browser console. Any subsequent requests to the runtime fail with the same error.

Error: [MONO] /__w/1/s/src/mono/mono/eglib/gmem.c:123 <disabled>
    at ht (logging.ts:95:18)
    at Ul (logging.ts:119:27)
    at wasm_trace_logger (00a88aba:0x1e7f43)
    at eglib_log_adapter (00a88aba:0x3aa8a)
    at monoeg_g_logv_nofree (00a88aba:0x37657)
    at monoeg_g_log (00a88aba:0x3771a)
    at g_log_disabled (00a88aba:0x3774d)
    at monoeg_malloc (00a88aba:0x3745a)
    at mono_mempool_new (00a88aba:0x91bd9)
    at mono_interp_transform_method (00a88aba:0x27fe2)
Full stack trace
Error: [MONO] /__w/1/s/src/mono/mono/eglib/gmem.c:123 <disabled>
    at ht (logging.ts:95:18)
    at Ul (logging.ts:119:27)
    at wasm_trace_logger (00a88aba:0x1e7f43)
    at eglib_log_adapter (00a88aba:0x3aa8a)
    at monoeg_g_logv_nofree (00a88aba:0x37657)
    at monoeg_g_log (00a88aba:0x3771a)
    at g_log_disabled (00a88aba:0x3774d)
    at monoeg_malloc (00a88aba:0x3745a)
    at mono_mempool_new (00a88aba:0x91bd9)
    at mono_interp_transform_method (00a88aba:0x27fe2)
Ul @ logging.ts:119
$func8039 @ 00a88aba:0x1e7f43
$func761 @ 00a88aba:0x3aa8a
$func682 @ 00a88aba:0x37657
$func684 @ 00a88aba:0x3771a
$func685 @ 00a88aba:0x3774d
$func672 @ 00a88aba:0x3745a
$func2011 @ 00a88aba:0x91bd9
$func286 @ 00a88aba:0x27fe2
$func111 @ 00a88aba:0x149b4
$func110 @ 00a88aba:0x1472e
$func179 @ 00a88aba:0x177c1
$func200 @ 00a88aba:0x17fb2
$func7998 @ 00a88aba:0x1e3557
$mono_wasm_execute_timer @ 00a88aba:0xdd6b1
e.<computed> @ cwraps.ts:338
mono_wasm_schedule_timer_tick @ scheduling.ts:75
callUserCallback @ dotnet.native.js:8
(anonymous) @ dotnet.native.js:8

Reproduction Steps

The issue can be seen here:

https://infinite-loop-dynamic.wasmsharp.pages.dev/

On my machine, it consistently takes ~5 seconds after clicking "Run Code", before the error in the console appears.

Expected behavior

The runtime hangs.

Interestingly, this is exactly what happens for a non-dynamically compiled method that includes a while (true) { } loop. https://infinite-loop-precompiled.wasmsharp.pages.dev/ has a loop inserted into the run method:

https://github.com/JakeYallop/WasmSharp/blob/infinite-loop-in-run/packages/core/src/Services/CodeSession.cs#L149

Clicking the "Run Code" button ends up with the runtime hanging, with no errors after a a while.

Actual behavior

An error occurs.

Taking a memory snapshot in DevTools after the error shows ~2GB of memory requested:
image

However, the actual allocated size of objects says that its much smaller:
image

It does not really make much sense to me.

A memory issue might make some sense given that the error stack trace contains /__w/1/s/src/mono/mono/eglib/gmem.c:123.

Regression?

No response

Known Workarounds

No response

Configuration

dotnet workload --info
Workload version: 8.0.200-manifests.5638171e
 [wasm-tools]
   Installation Source: SDK 8.0.200-preview.23624, VS 17.9.34518.117
   Manifest Version:    8.0.2/8.0.100
   Manifest Path:       C:\Program Files\dotnet\sdk-manifests\8.0.100\microsoft.net.workload.mono.toolchain.current\8.0.2\WorkloadManifest.json
   Install Type:              Msi

Full dotnet --info output

.NET SDK:
 Version:           8.0.200-preview.23624.5
 Commit:            8065b9770c
 Workload version:  8.0.200-manifests.5638171e

Runtime Environment:
 OS Name:     Windows
 OS Version:  10.0.22621
 OS Platform: Windows
 RID:         win-x64
 Base Path:   C:\Program Files\dotnet\sdk\8.0.200-preview.23624.5\

.NET workloads installed:
 Workload version: 8.0.200-manifests.5638171e
 [wasm-tools]
   Installation Source: SDK 8.0.200-preview.23624, VS 17.9.34518.117
   Manifest Version:    8.0.2/8.0.100
   Manifest Path:       C:\Program Files\dotnet\sdk-manifests\8.0.100\microsoft.net.workload.mono.toolchain.current\8.0.2\WorkloadManifest.json
   Install Type:              Msi

 [maui-windows]
   Installation Source: VS 17.9.34518.117
   Manifest Version:    8.0.6/8.0.100
   Manifest Path:       C:\Program Files\dotnet\sdk-manifests\8.0.100\microsoft.net.sdk.maui\8.0.6\WorkloadManifest.json
   Install Type:              Msi

 [maccatalyst]
   Installation Source: VS 17.9.34518.117
   Manifest Version:    17.2.8022/8.0.100
   Manifest Path:       C:\Program Files\dotnet\sdk-manifests\8.0.100\microsoft.net.sdk.maccatalyst\17.2.8022\WorkloadManifest.json
   Install Type:              Msi

 [android]
   Installation Source: VS 17.9.34518.117
   Manifest Version:    34.0.79/8.0.100
   Manifest Path:       C:\Program Files\dotnet\sdk-manifests\8.0.100\microsoft.net.sdk.android\34.0.79\WorkloadManifest.json
   Install Type:              Msi

 [ios]
   Installation Source: VS 17.9.34518.117
   Manifest Version:    17.2.8022/8.0.100
   Manifest Path:       C:\Program Files\dotnet\sdk-manifests\8.0.100\microsoft.net.sdk.ios\17.2.8022\WorkloadManifest.json
   Install Type:              Msi


Host:
  Version:      8.0.2
  Architecture: x64
  Commit:       1381d5ebd2

.NET SDKs installed:
  8.0.102 [C:\Program Files\dotnet\sdk]
  8.0.200-preview.23624.5 [C:\Program Files\dotnet\sdk]

.NET runtimes installed:
  Microsoft.AspNetCore.App 6.0.25 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 7.0.14 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 8.0.0 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 8.0.2 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.NETCore.App 6.0.25 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 7.0.14 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 8.0.0 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 8.0.2 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.WindowsDesktop.App 6.0.25 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 7.0.14 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 8.0.0 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 8.0.2 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]

Other architectures found:
  x86   [C:\Program Files (x86)\dotnet]
    registered at [HKLM\SOFTWARE\dotnet\Setup\InstalledVersions\x86\InstallLocation]

Environment variables:
  Not set

global.json file:
  Not found

Learn more:
  https://aka.ms/dotnet/info

Download .NET:
  https://aka.ms/dotnet/download

Other information

The runtime is running from inside a web worker.

Author: JakeYallop
Assignees: -
Labels:

untriaged, area-Codegen-Interpreter-mono, needs-area-label, os-browser

Milestone: -

@lewing lewing added the arch-wasm WebAssembly architecture label Feb 23, 2024
@vcsjones vcsjones removed the needs-area-label An area label is needed to ensure this gets routed to the appropriate area owners label Feb 26, 2024
@lewing lewing added this to the 9.0.0 milestone Feb 26, 2024
@ghost ghost removed the untriaged New issue has not been triaged by the area owner label Feb 26, 2024
@kg
Copy link
Member

kg commented Feb 27, 2024

Thanks for the report! What is the behavior you expect? An infinite loop isn't going to do anything useful regardless of whether this bug is present, so I assume this is a reduced version of a problem in application code where you have a long or infinite loop that does actual work, but isn't behaving correctly.

You also mention a web worker, which won't be present in the default configuration of the .NET runtime. Are you using a multithreaded build from source? Our default configuration is single-threaded.

From 'Interestingly, this is exactly what happens for a non-dynamically compiled method that includes a while (true) { } loop.' it sounds like loops are not behaving to your satisfaction in both scenarios, but this report is for dynamic compilation because it produces a unique error. Is that correct?

@kg
Copy link
Member

kg commented Feb 27, 2024

From looking at the stack trace and related code, it seems like this is a straightforward out-of-memory condition involving (but not necessarily caused by) the interpreter. As a basic check, are you certain you're not accidentally dynamically compiling a bunch of methods? The failed allocation in that stack is the creation of a memory pool, and we usually create one of those for each method transformed by the interpreter. So for that allocation to fail, we would have to start doing interpreter codegen after we've already allocated a ton of memory (likely the 2GB you see in that snapshot). Does your application usually allocate that much memory under normal circumstances? Each dynamically compiled method will use up memory for interpreter internals and potentially for jiterpreter traces as well, and most of that memory will be a part of the WASM heap, so it won't show up as individual allocations in chrome's devtools, it's one big block.

I did some local testing and was not able to reproduce this, but if you let me know more about how you're dynamically compiling this method (sample IL, etc) I can try to reproduce this here and investigate further.

@JakeYallop
Copy link
Contributor Author

JakeYallop commented Feb 27, 2024

I totally agree that an infinite loop is not going to do anything useful, I was just interested in what would actually happen, so in this case its not a reduction of a problem. I'm kind of okay if we just want to close this, but it does seem like odd behaviour, as I wouldn't expect an empty while loop to do anything other than hang.

As mentioned above, adding an empty while loop in my compiled code does exactly that - nothing at all, the runtime hangs as expected and memory usage does not grow.

Are you using a multithreaded build from source

I'm not using the multithreaded runtime - instead I'm just loading the runtime myself inside a web worker, https://github.com/JakeYallop/WasmSharp/blob/main/packages/core/src/worker.ts

I did some local testing and was not able to reproduce this

Did you try the link in the original issue, at least as a sense check it would good to know that its not just me 😄. https://infinite-loop-dynamic.wasmsharp.pages.dev/ - I know its not super useful in practice due to the difficulty in debugging.

Does your application usually allocate that much memory under normal circumstances?

No, it does not - its very obvious just from looking at Task Manager - as soon as I run the repro, the memory usage that my web browser is using explodes. Normal memory usage for the app is very low (it basically doesn't do much right now anyway)

but if you let me know more about how you're dynamically compiling this method

I'm actually compiling the code using Roslyn, then using Emit(), loading the resulting assembly and invoking its main method:

https://github.com/JakeYallop/WasmSharp/blob/main/packages/core/src/Services/CodeSession.cs#L152-L155

@kg
Copy link
Member

kg commented Feb 27, 2024

It does allocate 2GB and then fail for me when I load your webpage and click Run Code, yes.

I'm guessing this prefilled snippet from your sample is the repro case?

using System;
    using System.Reflection.Emit;
    //or remove the return to use the code below
    
    var method = new DynamicMethod("Test", typeof(void), Array.Empty<Type>());
    ILGenerator il = method.GetILGenerator(32);
    var loopTarget = il.DefineLabel();
    il.MarkLabel(loopTarget);
    il.Emit(OpCodes.Br_S, loopTarget);
    
    var MyMethod = method.CreateDelegate<InfiniteLoop>();
    
    MyMethod();
    
    delegate void InfiniteLoop();

If so, I'll do some testing with it later today. Alternately, you can provide the resulting assembly that Roslyn compiled, but this seems like a pretty straightforward snippet and is roughly what I had in mind.

@JakeYallop
Copy link
Contributor Author

Actually, it reproduces with just

while (true) { }

as code, no manual IL generation needed. Although I assume Emit() is doing this behind the scenes, I mostly wrote the IL fragment to make sure I knew exactly what was actually being run and that the while (true) { } loop was not being optimised or otherwise changed in some way.

@kg
Copy link
Member

kg commented Feb 27, 2024

Thanks, that is helpful. It doesn't reproduce in a local build of .NET 9, so it's possible we already fixed it with recent changes to the interpreter, but I'll dig in a little more. If you find ways to reproduce this against 8 with production code do let us know.

@ghost ghost added the in-pr There is an active PR which will close this issue when it is merged label Feb 28, 2024
@ghost ghost removed the in-pr There is an active PR which will close this issue when it is merged label Feb 28, 2024
@github-actions github-actions bot locked and limited conversation to collaborators Mar 30, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
arch-wasm WebAssembly architecture area-Codegen-Interpreter-mono os-browser Browser variant of arch-wasm
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants