Clearscript: Application crash

[ArgonAlex]

Firstly, it's amazing that you work on this as a side project. We've been using ClearScript for server side rendering React for several years now. Thank you!

Over the past few months, we have been seeing our application (w3wp) crash a few times a day due to ClearScript/V8. I would say it's very roughly 1 in a million requests.

It might not be a ton of information to go on, but we have a couple of stack traces retrieved from minidumps. Maybe there's something that can at least lead us in the right direction. The only exception we can see is a generic CLR ThreadAbortException.

Here's the relevant part of CLR stack trace:

[HelperMethodFrame: 000000ce863f9f28] 
.HostObjectHelpers.QueueNativeCallback(std.function*)
[InlinedCallFrame: 000000ce863fc148] 
[InlinedCallFrame: 000000ce863fc148] 
DomainBoundILStubClass.IL_STUB_PInvoke(IntPtr, V8Value*, V8DocumentInfo*, StdString*, Byte)
Microsoft.ClearScript.V8.V8ContextProxyImpl.Execute(Microsoft.ClearScript.DocumentInfo, System.String, Boolean)
Microsoft.ClearScript.V8.V8ScriptEngine+c__DisplayClass78_0.b__0()
Microsoft.ClearScript.ScriptEngine.ScriptInvokeInternal[[System.__Canon, mscorlib]](System.Func`1)
Microsoft.ClearScript.V8.V8ScriptEngine+c__DisplayClass83_1`1[[System.__Canon, mscorlib]].b__0()
[InlinedCallFrame: 000000ce863fc6d8] 
[InlinedCallFrame: 000000ce863fc6d8] 
DomainBoundILStubClass.IL_STUB_PInvoke(IntPtr, Void (Void*), Void*)
Microsoft.ClearScript.V8.V8ContextProxyImpl.InvokeWithLock(System.Action)
Microsoft.ClearScript.V8.V8ScriptEngine.ScriptInvoke[[System.__Canon, mscorlib]](System.Func`1)
JavaScriptEngineSwitcher.V8.V8JsEngine.InnerEvaluate(System.String, System.String)
JavaScriptEngineSwitcher.V8.V8JsEngine.InnerEvaluate[[System.__Canon, mscorlib]](System.String, System.String)

And the native stack trace:

KERNELBASE!RaiseException+0x69
clr!RaiseTheExceptionInternalOnly+0x2aa
clr!Thread::HandleThreadAbort+0x210e56
clr!HelperMethodFrame::PushSlowHelper+0x2c
clr!JIT_New+0xbd
0x00007fff`60cdb428
clr!UMThunkStub+0x6e
ClearScriptV8_64+0x1af8c
ClearScriptV8_64+0x18630
ClearScriptV8_64+0x17f0b
v8_x64!v8::internal::ItemParallelJob::Run+0x2ac
v8_x64!v8::internal::ScavengeJob::ScheduleIdleTaskIfNeeded+0xc80
v8_x64!v8::internal::Heap::CreateFillerObjectAt+0x32e5
v8_x64!v8::internal::Heap::CreateFillerObjectAt+0x6b8
v8_x64!v8::internal::Heap::CollectGarbage+0x4ba
v8_x64!v8::internal::Heap::ProtectUnprotectedMemoryChunks+0x4659
v8_x64!v8::internal::Heap::ProtectUnprotectedMemoryChunks+0x471e
v8_x64!v8::internal::Factory::NewFillerObject+0x5a
v8_x64!v8::internal::wasm::NativeModuleDeserializer::NativeModuleDeserializer+0x2f869
v8_x64!v8::internal::NativesCollection<0>::GetScriptsSource+0xa1106
0x0000033f`4977fa29
0x18
0x000000fd`80a7aee8
v8_x64!v8::internal::NativesCollection<0>::GetScriptsSource+0x84f60
0x0000033f`4977f7d1

Let me know if there is any additional information I can provide that might help.

[ClearScriptLib]

Hi @ArgonAlex,

Thank you for your kind words!

Unfortunately we don't have much to go on here. The CLR stack just indicates a crash during script execution, and the native stack points at something bad happening deep within V8's garbage collector, although a call back into ClearScript appears to be in progress. The latter stack is a bit more promising, but sadly its ClearScript frames aren't symbolized.

Nevertheless, the available symbols suggest the involvement of V8's task scheduling system, which has been problematic in the past.

Can you describe your ClearScript usage pattern? You mentioned that the crash happens approximately once per million requests, but what does each request look like, in terms of script execution? For example, do all requests hit the same long-lived V8ScriptEngine instance? Does each request run unique JavaScript code? Can you say anything about the API you're exposing to script code and the complexity of the script code itself? Any information could help.

Thanks!

[ArgonAlex]

I forgot to mention that we are running ClearScript version 5.5.6.

We use the JsPool library, so we load most of our code (a multi megabyte script containing React, libraries, our own React components, etc) into a pool of engines when the application starts. This exposes a global renderPage function within the Javascript engine that calls React's renderToString. Then during a request we retrieve an engine from the pool and essentially call
C# result = engine.Evaluate($"renderPage({data})")
where data is a ~100KB serialized JSON object unique to the request.

[ClearScriptLib]

@ArgonAlex,

Thanks for posting that information. We have a few suggestions.

First, make sure that JsPool is configured to retire old engines. V8 seems to have some slow memory leaks that could lead to crashes.

Second, we strongly recommend that you eliminate unnecessary JavaScript parsing. Doing so should improve efficiency, especially if your engines are recycled lazily. Eliminating per-request JavaScript parsing (and JIT compilation!) could also help reduce the occurrence of this crash.

Here's how you might do that. Expose a global renderPage wrapper that uses the JSON parser:

function renderPageFromJSON(json) { return renderPage(JSON.parse(json)); }

And then, in your application:

C# result = engine.CallFunction("renderPageFromJSON", data);

Finally, consider upgrading to ClearScript 5.6. It uses a significantly newer version of V8.

Cheers!

[ArgonAlex]

Interesting. I remember trying JSON.parse that way when first implementing server side rendering, and it was very slightly slower. And I just reconfirmed that to be the case with ClearScript 5.5.6. However, ClearScript 5.6 with V8 7.6 changes things, probably because there were specifically huge improvements to JSON.parse speed! How fortunate.

We're always on the lookout for ways to optimize performance (which often just amounts to updating ClearScript because V8 is constantly improving with almost every release). These changes bring a noticeable improvement in my testing. Thank you!

We'll have to see over the next few days whether it has any affect on the crashes too.

[ClearScriptLib]

@ArgonAlex, have you observed any change in the crash frequency?

[ArgonAlex]

We are seeing fewer crashes now! Although it's hard to say whether it was these changes, as some of the crashes were not related to ClearScript.

We do however have a new stack trace with a more useful exception:

ERROR_CODE: 0xc0000005 (Access violation) - The instruction at 0x%p referenced memory at 0x%p. The memory could not be %s.

 v8_x64!v8::internal::CanonicalHandleScope::Lookup+0x87
 v8_x64!v8::internal::Factory::NewRawOneByteString+0xd2
 v8_x64!v8::internal::Factory::NewStringFromTwoByte+0x159
 v8_x64!v8::internal::Factory::NewStringFromTwoByte+0x1c
 v8_x64!v8::String::NewFromTwoByte+0x12a
 ClearScriptV8_64+0xc2d0
 ClearScriptV8_64+0x25ff8
 0x00007ff8`1d708911
 0x00007ff8`1d70682b
 0x00007ff8`1d5fdab2
 0x00007ff8`1d5fda2d
 clr!UMThunkStub+0x6e
 ClearScriptV8_64+0x755d

This smells like an out of memory issue. Although, we manually get the TotalHeapSize from the heap statistics after each render, and they've never been close to the default HeapSizeLimit of 1448MB. I suppose it is possible for it to spike and hit the limit during the render though, and we'd never log it.

[ClearScriptLib]

Yes, that does look like an out-of-memory condition, which V8 handles by crashing the process. How often is it happening?

[ArgonAlex]

It's happening 1 in every few million requests now.

[ClearScriptLib]

Is the stack always the same?

Unfortunately, if this is an intermittent out-of-memory condition, and if there’s no reliable way to reproduce it, there’s really no action we can take to resolve it.

One thing you might try is adjusting the memory limits beyond the defaults.

[ArgonAlex]

I took a look at 3 different crashes from 3 different machines and they all had that exact same stack trace on the thread that caused the main access violation exception.

One of the crashes happened while CLR garbage collection was also happening. Another one of them had a bunch of threads with V8 engines doing what looks like garbage collection:

v8_x64!v8::internal::ConcurrentMarking::TotalMarkedBytes+6be
v8_x64!v8::internal::ConcurrentMarking::TotalMarkedBytes+1b98
v8_x64!v8::internal::ConcurrentMarking::TotalMarkedBytes+287b
v8_x64!v8::internal::ConcurrentMarking::Run+2743
ClearScriptV8_64+1e64a

Certainly seems like an out of memory condition, so I'm not sure what else you can do here. Thanks for you help and the ideas though!

[ClearScriptLib]

Do these crashes generate dump files, by any chance? If you have one, we'd love to take a look at it.

[ClearScriptLib]

Hi @ArgonAlex,

If you get a chance, please try ClearScript 6.0, which comes with a significantly newer V8 build and improved embedding code.

If the crashes persist, please send dump files for analysis.

Thanks!

[ClearScriptLib]

Please reopen this issue if you have additional comments or information.