Stack traces for JS exceptions #821

lahma · 2020-12-19T09:02:18Z

I needed better errors while trying to figure out problems in class implementation branch so decided to separate these changes from there. Now the exceptions start to make more sense, at least from my viewpoint.

now always collecting stacks for exception purposes
the actual line of execution that caused the exception first, not just the containing function name and its location
format is more like in node/chromium, line:column, the reverse was making it really hard to read
have stack property on error, like browsers have, use more .NET like properties Message and StackTrace in JavaScriptException
hide implementation as internal
use struct for call stack elements for better performance
extracted RefStack<T> from ExecutionContextStack so call stack can use it and thus structs more efficiently
when limit recursion is not defined, don't collect costly dictionary traces of statistics
now also get/set methods in functions are observed and restricted by recursion limits

fixes #112
fixes #190
fixes #251
fixes #258
fixes #293
fixes #735

Now in REPL:

jint> var f = (x) => Array.prototype.sort.call(x); f(null);
Jint.Runtime.JavaScriptException: Array.prorotype.sort can only be applied on objects
    at call (x) repl:1:46
    at f () repl:1:16
    at repl:1:46
jint>

Performance

No noticeable performance difference after enabling always having traces, mostly seems like jitter.

Esprima.Benchmark.SunSpiderBenchmark

Diff	Method	FileName	Mean	Error	Gen 0	Gen 1	Gen 2	Allocated
Old	Run	3d-cube	569.3 ms	1.28 ms	12000.0000	1000.0000	0.0000	52.59 MB
New			551.1 ms (-3%)	3.16 ms	12000.0000 (0%)	1000.0000 (0%)	0.0000	52.59 MB (0%)
Old	Run	3d-morph	413.5 ms	0.89 ms	10000.0000	2000.0000	0.0000	62.09 MB
New			434.8 ms (+5%)	3.05 ms	10000.0000 (0%)	2000.0000 (0%)	0.0000	62.09 MB (0%)
Old	Run	3d-raytrace	406.1 ms	1.44 ms	23000.0000	3000.0000	0.0000	95.73 MB
New			413.0 ms (+2%)	0.32 ms	23000.0000 (0%)	3000.0000 (0%)	0.0000	95.74 MB (0%)
Old	Run	access-binary-trees	195.6 ms	0.29 ms	20000.0000	2000.0000	0.0000	83.01 MB
New			197.5 ms (+1%)	0.60 ms	20000.0000 (0%)	2000.0000 (0%)	0.0000	83.01 MB (0%)
Old	Run	access-fannkuch	1,363.2 ms	11.39 ms	9000.0000	0.0000	0.0000	37.95 MB
New			1,371.9 ms (+1%)	10.53 ms	9000.0000 (0%)	0.0000	0.0000	37.95 MB (0%)
Old	Run	access-nbody	496.3 ms	0.71 ms	15000.0000	0.0000	0.0000	62.82 MB
New			482.5 ms (-3%)	1.10 ms	15000.0000 (0%)	0.0000	0.0000	62.82 MB (0%)
Old	Run	access-nsieve	498.8 ms	1.31 ms	10000.0000	4000.0000	1000.0000	55.59 MB
New			503.7 ms (+1%)	1.18 ms	10000.0000 (0%)	4000.0000 (0%)	1000.0000 (0%)	55.59 MB (0%)
Old	Run	bitop(...)-byte [24]	365.0 ms	0.96 ms	18000.0000	0.0000	0.0000	75.18 MB
New			366.4 ms (0%)	1.04 ms	18000.0000 (0%)	0.0000	0.0000	75.18 MB (0%)
Old	Run	bitops-bits-in-byte	569.3 ms	3.51 ms	12000.0000	0.0000	0.0000	49.87 MB
New			569.3 ms (0%)	2.27 ms	12000.0000 (0%)	0.0000	0.0000	49.87 MB (0%)
Old	Run	bitops-bitwise-and	261.4 ms	0.67 ms	13000.0000	0.0000	0.0000	54.64 MB
New			262.3 ms (0%)	1.97 ms	13000.0000 (0%)	0.0000	0.0000	54.64 MB (0%)
Old	Run	bitops-nsieve-bits	512.2 ms	1.96 ms	16000.0000	1000.0000	0.0000	66.35 MB
New			496.7 ms (-3%)	1.62 ms	16000.0000 (0%)	1000.0000 (0%)	0.0000	66.35 MB (0%)
Old	Run	contr(...)rsive [21]	267.5 ms	0.68 ms	32000.0000	0.0000	0.0000	128.3 MB
New			274.0 ms (+2%)	0.62 ms	32000.0000 (0%)	1000.0000	0.0000	128.3 MB (0%)
Old	Run	crypto-aes	363.3 ms	1.31 ms	6000.0000	1000.0000	0.0000	26.93 MB
New			363.4 ms (0%)	1.10 ms	6000.0000 (0%)	1000.0000 (0%)	0.0000	26.9 MB (0%)
Old	Run	crypto-md5	234.0 ms	0.76 ms	24000.0000	1000.0000	0.0000	97.9 MB
New			236.4 ms (+1%)	0.65 ms	24000.0000 (0%)	1000.0000 (0%)	0.0000	97.9 MB (0%)
Old	Run	crypto-sha1	234.6 ms	0.57 ms	20000.0000	1000.0000	0.0000	84.71 MB
New			243.0 ms (+4%)	0.56 ms	20000.0000 (0%)	1000.0000 (0%)	0.0000	84.71 MB (0%)
Old	Run	date-format-tofte	283.9 ms	0.74 ms	18000.0000	1000.0000	0.0000	73.57 MB
New			283.1 ms (0%)	0.43 ms	18000.0000 (0%)	2000.0000 (+100%)	0.0000	73.7 MB (0%)
Old	Run	date-format-xparb	130.5 ms	0.50 ms	7000.0000	1000.0000	0.0000	30.69 MB
New			134.3 ms (+3%)	0.86 ms	7000.0000 (0%)	1000.0000 (0%)	0.0000	30.69 MB (0%)
Old	Run	math-cordic	825.2 ms	3.63 ms	30000.0000	0.0000	0.0000	122.65 MB
New			822.0 ms (0%)	2.24 ms	30000.0000 (0%)	0.0000	0.0000	122.65 MB (0%)
Old	Run	math-partial-sums	318.5 ms	1.15 ms	14000.0000	0.0000	0.0000	56.72 MB
New			309.4 ms (-3%)	1.45 ms	14000.0000 (0%)	0.0000	0.0000	56.72 MB (0%)
Old	Run	math-spectral-norm	282.7 ms	0.88 ms	17000.0000	0.0000	0.0000	69.55 MB
New			294.1 ms (+4%)	0.75 ms	17000.0000 (0%)	0.0000	0.0000	69.55 MB (0%)
Old	Run	regexp-dna	297.9 ms	0.55 ms	1000.0000	1000.0000	1000.0000	17.31 MB
New			291.8 ms (-2%)	2.87 ms	1000.0000 (0%)	1000.0000 (0%)	1000.0000 (0%)	17.3 MB (0%)
Old	Run	string-base64	241.6 ms	1.02 ms	2000.0000	0.0000	0.0000	11.39 MB
New			244.6 ms (+1%)	1.07 ms	2000.0000 (0%)	0.0000	0.0000	11.39 MB (0%)
Old	Run	string-fasta	476.9 ms	1.27 ms	40000.0000	0.0000	0.0000	160.74 MB
New			491.7 ms (+3%)	9.63 ms	40000.0000 (0%)	0.0000	0.0000	160.74 MB (0%)
Old	Run	string-tagcloud	171.9 ms	0.74 ms	10000.0000	1000.0000	0.0000	52.82 MB
New			176.1 ms (+2%)	0.83 ms	10000.0000 (0%)	1000.0000 (0%)	0.0000	52.82 MB (0%)
Old	Run	string-unpack-code	169.3 ms	0.41 ms	21000.0000	7000.0000	1000.0000	88.93 MB
New			171.2 ms (+1%)	0.40 ms	21000.0000 (0%)	7000.0000 (0%)	1000.0000 (0%)	88.93 MB (0%)
Old	Run	strin(...)input [21]	1,282.6 ms	22.74 ms	1227000.0000	1207000.0000	1207000.0000	6204.76 MB
New			1,298.8 ms (+1%)	22.08 ms	1227000.0000 (0%)	1208000.0000 (0%)	1208000.0000 (0%)	6204.37 MB (0%)

Jint.Benchmark.DromaeoBenchmark

Diff	Method	FileName	Mean	Error	Gen 0	Gen 1	Gen 2	Allocated
Old	Run	dromaeo-3d-cube	66.25 ms	0.096 ms	1500.0000	375.0000	0.0000	8596.92 KB
New			65.72 ms (-1%)	0.052 ms	1500.0000 (0%)	375.0000 (0%)	0.0000	8599.14 KB (0%)
Old	Run	dromaeo-core-eval	17.16 ms	0.065 ms	125.0000	0.0000	0.0000	518.59 KB
New			16.42 ms (-4%)	0.075 ms	125.0000 (0%)	31.2500	0.0000	518.59 KB (0%)
Old	Run	dromaeo-object-array	181.12 ms	0.583 ms	41000.0000	2000.0000	0.0000	174222.42 KB
New			179.30 ms (-1%)	0.507 ms	41000.0000 (0%)	2000.0000 (0%)	0.0000	174222.5 KB (0%)
Old	Run	droma(...)egexp [21]	667.84 ms	7.465 ms	41000.0000	22000.0000	14000.0000	373749.98 KB
New			690.62 ms (+3%)	13.560 ms	41000.0000 (0%)	22000.0000 (0%)	14000.0000 (0%)	371889.06 KB (0%)
Old	Run	droma(...)tring [21]	819.02 ms	51.287 ms	75000.0000	41000.0000	39000.0000	1344955.06 KB
New			826.51 ms (+1%)	53.336 ms	75000.0000 (0%)	41000.0000 (0%)	39000.0000 (0%)	1342252.64 KB (0%)
Old	Run	droma(...)ase64 [21]	155.25 ms	0.300 ms	1000.0000	0.0000	0.0000	7989.73 KB
New			168.67 ms (+9%)	0.683 ms	1000.0000 (0%)	0.0000	0.0000	7989.89 KB (0%)

Jint.Benchmark.EvaluationBenchmark

Diff	Method	N	Mean	Error	Gen 0	Gen 1	Gen 2	Allocated
Old	Jint	20	1.124 ms	0.0024 ms	177.7344	1.9531	0.0000	732.03 KB
New			1.125 ms (0%)	0.0013 ms	177.7344 (0%)	0.0000 (-100%)	0.0000	732.97 KB (0%)

… REPL

sebastienros

Looks great, love how the stack trace looks.
My comments are only for my personal understanding, and the PR is GTG.

sebastienros · 2020-12-28T15:40:52Z

Jint.Tests.Test262/Jint.Tests.Test262.csproj

@@ -1,6 +1,8 @@
 <Project Sdk="Microsoft.NET.Sdk">
  <PropertyGroup>
    <TargetFrameworks>net461;net5.0</TargetFrameworks>
+    <AssemblyOriginatorKeyFile>..\Jint\Jint.snk</AssemblyOriginatorKeyFile>
+    <SignAssembly>true</SignAssembly>


Feels like I asked the same question recently, but what's the reason?

Just to get access to internal methods, like Jint.Tests has

sebastienros · 2020-12-28T15:42:02Z

Jint/AssemblyInfoExtras.cs

@@ -1,4 +1,5 @@
 using System.Runtime.CompilerServices;

 [assembly: InternalsVisibleTo("Jint.Tests, PublicKey=0024000004800000940000000602000000240000525341310004000001000100bf2553c9f214cb21f1f64ed62cadad8fe4f2fa11322a5dfa1d650743145c6085aba05b145b29867af656e0bb9bfd32f5d0deb1668263a38233e7e8e5bad1a3c6edd3f2ec6c512668b4aa797283101444628650949641b4f7cb16707efba542bb754afe87ce956f3a5d43f450d14364eb9571cbf213d1061852fb9dd47a6c05c4")]
+[assembly: InternalsVisibleTo("Jint.Tests.Test262, PublicKey=0024000004800000940000000602000000240000525341310004000001000100bf2553c9f214cb21f1f64ed62cadad8fe4f2fa11322a5dfa1d650743145c6085aba05b145b29867af656e0bb9bfd32f5d0deb1668263a38233e7e8e5bad1a3c6edd3f2ec6c512668b4aa797283101444628650949641b4f7cb16707efba542bb754afe87ce956f3a5d43f450d14364eb9571cbf213d1061852fb9dd47a6c05c4")]


Ah, that's for the internal visible that you added the snk?

sebastienros · 2020-12-28T15:42:58Z

Jint/Collections/RefStack.cs

+    /// <summary>
+    /// Stack for struct types.
+    /// </summary>
+    internal sealed class RefStack<T> : IEnumerable<T> where T : struct


Tell me more about that!

Basically just optimized to return refs without copies (like structs usually get copied with generic .NET data structures). Faster and simpler for specific use case.

sebastienros · 2020-12-28T15:43:49Z

Jint/Pooling/StringBuilderPool.cs

@@ -9,7 +9,7 @@ namespace Jint.Pooling
    /// <summary>
    /// Pooling of StringBuilder instances.
    /// </summary>
-    internal sealed class StringBuilderPool
+    internal static class StringBuilderPool


Why not static anymore?

Actually now static instead of sealed, all methods are static and no instances of pool are required 😉

Configurable stack trace collection, report stack traces in tests and…

beeea6f

… REPL

lahma force-pushed the stack-trace-for-tests branch from 85afeb7 to beeea6f Compare December 19, 2020 09:11

lahma requested a review from sebastienros December 19, 2020 09:26

reuse RefStack for JintCallStack

e0cabae

lahma marked this pull request as draft December 20, 2020 21:00

lahma added 4 commits December 26, 2020 12:53

improve stack trace printing and make it follow node/chromium more

5c956ed

harmonize JavaScriptException to look more line a .NET exception

e1768ff

always collect stack traces

bf23e78

cleanup

9acbbf7

lahma force-pushed the stack-trace-for-tests branch from 7337c4a to 9acbbf7 Compare December 26, 2020 14:37

handle getter/setter

20df718

lahma changed the title ~~Configurable stack trace collection~~ Stack traces for JS exceptions Dec 27, 2020

lahma marked this pull request as ready for review December 27, 2020 15:40

lahma added 3 commits December 27, 2020 18:00

tweak coercible logic

47d7f2b

unify Call dispatch

d4d0d44

add a way for RavenDB to construct reflection property descriptors

939c23c

sebastienros approved these changes Dec 28, 2020

View reviewed changes

lahma merged commit de3739b into sebastienros:dev Dec 28, 2020

lahma deleted the stack-trace-for-tests branch December 28, 2020 16:19

sebastienros mentioned this pull request Feb 7, 2022

Support comparing BenchmarkDotNet results dotnet/crank#402

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Stack traces for JS exceptions #821

Stack traces for JS exceptions #821

lahma commented Dec 19, 2020 •

edited

sebastienros left a comment

sebastienros Dec 28, 2020

lahma Dec 28, 2020

sebastienros Dec 28, 2020

lahma Dec 28, 2020

sebastienros Dec 28, 2020

lahma Dec 28, 2020

sebastienros Dec 28, 2020

lahma Dec 28, 2020

Stack traces for JS exceptions #821

Stack traces for JS exceptions #821

Conversation

lahma commented Dec 19, 2020 • edited

Performance

Esprima.Benchmark.SunSpiderBenchmark

Jint.Benchmark.DromaeoBenchmark

Jint.Benchmark.EvaluationBenchmark

sebastienros left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

lahma commented Dec 19, 2020 •

edited