From b14fe925934b89c0e8fea0ae32db38c5e245af67 Mon Sep 17 00:00:00 2001 From: Calvin Nix Date: Wed, 31 Jan 2024 11:34:41 -0500 Subject: [PATCH 01/18] BAAS-28253: Add optional tick tracking at the function level --- compiler.go | 2 ++ runtime.go | 15 +++++++++++++++ vm.go | 25 +++++++++++++++++++++++++ 3 files changed, 42 insertions(+) diff --git a/compiler.go b/compiler.go index 2c6d354a..35a46a0b 100644 --- a/compiler.go +++ b/compiler.go @@ -71,6 +71,8 @@ type Program struct { funcName unistring.String src *file.File srcMap []srcMapItem + + metricName string } type compiler struct { diff --git a/runtime.go b/runtime.go index 67d69791..bced0cbd 100644 --- a/runtime.go +++ b/runtime.go @@ -204,12 +204,19 @@ type Runtime struct { limiter *rate.Limiter limiterTicksLeft int ticks uint64 + + disableTickMetrics bool + tickMetrics map[string]uint64 } func (self *Runtime) Ticks() uint64 { return self.ticks } +func (self *Runtime) GetTickMetrics() map[string]uint64 { + return self.tickMetrics +} + // SetStackTraceLimit sets an upper limit to the number of stack frames that // goja will use when formatting an error's stack trace. By default, the limit // is 10. This is consistent with V8 and SpiderMonkey. @@ -3229,3 +3236,11 @@ func (r *Runtime) getPrototypeFromCtor(newTarget, defCtor, defProto *Object) *Ob } return defProto } + +func (self *Runtime) DisableFunctionTickTracking() { + self.disableTickMetrics = true +} + +func (self *Runtime) EnableFunctionTickTracking() { + self.disableTickMetrics = false +} diff --git a/vm.go b/vm.go index 9f186ce9..1c50a640 100644 --- a/vm.go +++ b/vm.go @@ -582,9 +582,31 @@ func (vm *vm) init() { vm.maxCallStackSize = math.MaxInt32 } +func (vm *vm) trackMetrics(prg *Program) { + if prg == nil { + return + } + + if vm.r.tickMetrics == nil { + vm.r.tickMetrics = make(map[string]uint64) + } + + // todo this might help out performance + if prg.metricName == "" { + prg.metricName = string(prg.funcName) + if prg.src != nil { + prg.metricName = prg.src.Name() + "_" + prg.metricName + } + } + + vm.r.tickMetrics[prg.metricName]++ +} + func (vm *vm) run() { vm.halt = false interrupted := false + tickMetricsEnabled := !vm.r.disableTickMetrics + for !vm.halt { // NOTE: we should try to avoid making expensive operations within this // loop since it gets called millions of times per second. @@ -648,6 +670,9 @@ func (vm *vm) run() { atomic.StoreUint32(&vm.interrupted, 0) }() } else { + if tickMetricsEnabled { + vm.trackMetrics(vm.prg) + } vm.prg.code[vm.pc].exec(vm) } } From 5a636fac7872f31eacda4fd9228c61b5ac7b8057 Mon Sep 17 00:00:00 2001 From: Calvin Nix Date: Wed, 31 Jan 2024 14:13:28 -0500 Subject: [PATCH 02/18] improve variable name --- runtime.go | 8 ++++---- vm.go | 6 +++--- 2 files changed, 7 insertions(+), 7 deletions(-) diff --git a/runtime.go b/runtime.go index bced0cbd..b0c043de 100644 --- a/runtime.go +++ b/runtime.go @@ -205,16 +205,16 @@ type Runtime struct { limiterTicksLeft int ticks uint64 - disableTickMetrics bool - tickMetrics map[string]uint64 + disableTickMetrics bool + functionTickMetrics map[string]uint64 } func (self *Runtime) Ticks() uint64 { return self.ticks } -func (self *Runtime) GetTickMetrics() map[string]uint64 { - return self.tickMetrics +func (self *Runtime) GetFunctionTickMetrics() map[string]uint64 { + return self.functionTickMetrics } // SetStackTraceLimit sets an upper limit to the number of stack frames that diff --git a/vm.go b/vm.go index 1c50a640..7d2d45d9 100644 --- a/vm.go +++ b/vm.go @@ -587,8 +587,8 @@ func (vm *vm) trackMetrics(prg *Program) { return } - if vm.r.tickMetrics == nil { - vm.r.tickMetrics = make(map[string]uint64) + if vm.r.functionTickMetrics == nil { + vm.r.functionTickMetrics = make(map[string]uint64) } // todo this might help out performance @@ -599,7 +599,7 @@ func (vm *vm) trackMetrics(prg *Program) { } } - vm.r.tickMetrics[prg.metricName]++ + vm.r.functionTickMetrics[prg.metricName]++ } func (vm *vm) run() { From ebff8e50a6dafb9701fe35b1cdf4ca3218086770 Mon Sep 17 00:00:00 2001 From: Calvin Nix Date: Wed, 31 Jan 2024 16:41:07 -0500 Subject: [PATCH 03/18] improve performance by sampling 10% of ticks, a better approach might follow --- vm.go | 37 +++++++++++++++---------------------- 1 file changed, 15 insertions(+), 22 deletions(-) diff --git a/vm.go b/vm.go index 7d2d45d9..2b17291a 100644 --- a/vm.go +++ b/vm.go @@ -582,26 +582,6 @@ func (vm *vm) init() { vm.maxCallStackSize = math.MaxInt32 } -func (vm *vm) trackMetrics(prg *Program) { - if prg == nil { - return - } - - if vm.r.functionTickMetrics == nil { - vm.r.functionTickMetrics = make(map[string]uint64) - } - - // todo this might help out performance - if prg.metricName == "" { - prg.metricName = string(prg.funcName) - if prg.src != nil { - prg.metricName = prg.src.Name() + "_" + prg.metricName - } - } - - vm.r.functionTickMetrics[prg.metricName]++ -} - func (vm *vm) run() { vm.halt = false interrupted := false @@ -670,8 +650,21 @@ func (vm *vm) run() { atomic.StoreUint32(&vm.interrupted, 0) }() } else { - if tickMetricsEnabled { - vm.trackMetrics(vm.prg) + if tickMetricsEnabled && vm.r.ticks%10 == 0 { + if vm.prg != nil { + if vm.r.functionTickMetrics == nil { + vm.r.functionTickMetrics = make(map[string]uint64) + } + + if vm.prg.metricName == "" { + vm.prg.metricName = string(vm.prg.funcName) + if vm.prg.src != nil { + vm.prg.metricName = vm.prg.src.Name() + "_" + vm.prg.metricName + } + } + + vm.r.functionTickMetrics[vm.prg.metricName]++ + } } vm.prg.code[vm.pc].exec(vm) } From d9a1535a0bcf002ba1638b0e1e2ae1bc0aa8fa15 Mon Sep 17 00:00:00 2001 From: Calvin Nix Date: Wed, 31 Jan 2024 18:29:46 -0500 Subject: [PATCH 04/18] optimize function tick tracking --- compiler_test.go | 2 +- func.go | 6 ++--- runtime.go | 6 ++--- vm.go | 57 ++++++++++++++++++++++++++++-------------------- 4 files changed, 40 insertions(+), 31 deletions(-) diff --git a/compiler_test.go b/compiler_test.go index 2d6e9535..1db4f0a1 100644 --- a/compiler_test.go +++ b/compiler_test.go @@ -156,7 +156,7 @@ func testLibX() *Program { func (r *Runtime) testPrg(p *Program, expectedResult Value, t *testing.T) { vm := r.vm - vm.prg = p + vm.setPrg(p) vm.pc = 0 vm.prg.dumpCode(t.Logf) vm.result = _undefined diff --git a/func.go b/func.go index d1f7083b..154e9e50 100644 --- a/func.go +++ b/func.go @@ -227,7 +227,7 @@ func (f *classFuncObject) _initFields(instance *Object) { if f.initFields != nil { vm := f.val.runtime.vm vm.pushCtx() - vm.prg = f.initFields + vm.setPrg(f.initFields) vm.stash = f.stash vm.privEnv = f.privEnv vm.newTarget = nil @@ -319,7 +319,7 @@ func (f *baseJsFuncObject) _call(ctx context.Context, args []Value, newTarget, t vm.pushCtx() } vm.args = len(args) - vm.prg = f.prg + vm.setPrg(f.prg) vm.stash = f.stash vm.privEnv = f.privEnv vm.newTarget = newTarget @@ -433,7 +433,7 @@ func (f *nativeFuncObject) Call(call FunctionCall) Value { func (f *nativeFuncObject) vmCall(vm *vm, n int) { if f.f != nil { vm.pushCtx() - vm.prg = nil + vm.setPrg(nil) vm.sb = vm.sp - n // so that [sb-1] points to the callee ret := f.f(FunctionCall{ Arguments: vm.stack[vm.sp-n : vm.sp], diff --git a/runtime.go b/runtime.go index b0c043de..18dfc77c 100644 --- a/runtime.go +++ b/runtime.go @@ -978,7 +978,7 @@ func (r *Runtime) common_eval(name, src string, direct, strict bool) Value { panic(err) } - vm.prg = p + vm.setPrg(p) vm.pc = 0 vm.args = 0 vm.result = _undefined @@ -1520,7 +1520,7 @@ func (r *Runtime) RunProgram(p *Program) (result Value, err error) { vm.stash = &r.global.stash vm.sb = vm.sp - 1 } - vm.prg = p + vm.setPrg(p) vm.pc = 0 vm.result = _undefined ex := vm.runTry(r.vm.ctx) @@ -1535,7 +1535,7 @@ func (r *Runtime) RunProgram(p *Program) (result Value, err error) { vm.clearStack() } else { vm.stack = nil - vm.prg = nil + vm.setPrg(nil) vm.setFuncName("") r.leave() } diff --git a/vm.go b/vm.go index 2b17291a..75c3f506 100644 --- a/vm.go +++ b/vm.go @@ -306,12 +306,37 @@ type vm struct { interrupted uint32 interruptVal interface{} interruptLock sync.Mutex + + lastFunctionTicks uint64 } type instruction interface { exec(*vm) } +func (vm *vm) setPrg(prg *Program) { + if !vm.r.disableTickMetrics { + currentTicks := vm.r.Ticks() + if vm.prg != nil { + if vm.r.functionTickMetrics == nil { + vm.r.functionTickMetrics = make(map[string]uint64) + } + + // todo this optimization might not be needed + if vm.prg.metricName == "" { + vm.prg.metricName = string(vm.prg.funcName) + if vm.prg.src != nil { + vm.prg.metricName = vm.prg.src.Name() + "_" + vm.prg.metricName + } + } + + vm.r.functionTickMetrics[vm.prg.metricName] += currentTicks - vm.lastFunctionTicks + } + vm.lastFunctionTicks = currentTicks + } + vm.prg = prg +} + func (vm *vm) getFuncName() unistring.String { vm.funcNameLock.RLock() s := vm.funcName @@ -585,7 +610,6 @@ func (vm *vm) init() { func (vm *vm) run() { vm.halt = false interrupted := false - tickMetricsEnabled := !vm.r.disableTickMetrics for !vm.halt { // NOTE: we should try to avoid making expensive operations within this @@ -650,22 +674,6 @@ func (vm *vm) run() { atomic.StoreUint32(&vm.interrupted, 0) }() } else { - if tickMetricsEnabled && vm.r.ticks%10 == 0 { - if vm.prg != nil { - if vm.r.functionTickMetrics == nil { - vm.r.functionTickMetrics = make(map[string]uint64) - } - - if vm.prg.metricName == "" { - vm.prg.metricName = string(vm.prg.funcName) - if vm.prg.src != nil { - vm.prg.metricName = vm.prg.src.Name() + "_" + vm.prg.metricName - } - } - - vm.r.functionTickMetrics[vm.prg.metricName]++ - } - } vm.prg.code[vm.pc].exec(vm) } } @@ -884,8 +892,9 @@ func (vm *vm) pushCtx() { } func (vm *vm) restoreCtx(ctx *vmContext) { - vm.prg, vm.stash, vm.privEnv, vm.newTarget, vm.result, vm.pc, vm.sb, vm.args = - ctx.prg, ctx.stash, ctx.privEnv, ctx.newTarget, ctx.result, ctx.pc, ctx.sb, ctx.args + vm.stash, vm.privEnv, vm.newTarget, vm.result, vm.pc, vm.sb, vm.args = + ctx.stash, ctx.privEnv, ctx.newTarget, ctx.result, ctx.pc, ctx.sb, ctx.args + vm.setPrg(ctx.prg) vm.ctx = ctx.ctx vm.setFuncName(ctx.funcName) @@ -3412,7 +3421,7 @@ func (numargs call) exec(vm *vm) { vm.pc++ vm.pushCtx() vm.args = n - vm.prg = f.prg + vm.setPrg(f.prg) vm.stash = f.stash vm.privEnv = f.privEnv vm.pc = 0 @@ -3422,7 +3431,7 @@ func (numargs call) exec(vm *vm) { vm.pc++ vm.pushCtx() vm.args = n - vm.prg = f.prg + vm.setPrg(f.prg) vm.stash = f.stash vm.privEnv = f.privEnv vm.pc = 0 @@ -3432,7 +3441,7 @@ func (numargs call) exec(vm *vm) { vm.pc++ vm.pushCtx() vm.args = n - vm.prg = f.prg + vm.setPrg(f.prg) vm.stash = f.stash vm.privEnv = f.privEnv vm.pc = 0 @@ -3447,7 +3456,7 @@ func (numargs call) exec(vm *vm) { vm._nativeCall(&f.nativeFuncObject, n) case *proxyObject: vm.pushCtx() - vm.prg = nil + vm.setPrg(nil) vm.setFuncName("proxy") ret := f.apply(FunctionCall{ctx: vm.ctx, This: vm.stack[vm.sp-n-2], Arguments: vm.stack[vm.sp-n : vm.sp]}) if ret == nil { @@ -3467,7 +3476,7 @@ func (numargs call) exec(vm *vm) { func (vm *vm) _nativeCall(f *nativeFuncObject, n int) { if f.f != nil { vm.pushCtx() - vm.prg = nil + vm.setPrg(nil) vm.setFuncName(nilSafe(f.getStr("name", nil)).string()) ret := f.f(FunctionCall{ ctx: vm.ctx, From aae390afc020192634ae95a9a92e3f183b0510f7 Mon Sep 17 00:00:00 2001 From: Calvin Nix Date: Wed, 31 Jan 2024 18:37:19 -0500 Subject: [PATCH 05/18] undo map key optimization --- compiler.go | 2 -- vm.go | 12 ++---------- 2 files changed, 2 insertions(+), 12 deletions(-) diff --git a/compiler.go b/compiler.go index 35a46a0b..2c6d354a 100644 --- a/compiler.go +++ b/compiler.go @@ -71,8 +71,6 @@ type Program struct { funcName unistring.String src *file.File srcMap []srcMapItem - - metricName string } type compiler struct { diff --git a/vm.go b/vm.go index 75c3f506..b643c691 100644 --- a/vm.go +++ b/vm.go @@ -321,16 +321,8 @@ func (vm *vm) setPrg(prg *Program) { if vm.r.functionTickMetrics == nil { vm.r.functionTickMetrics = make(map[string]uint64) } - - // todo this optimization might not be needed - if vm.prg.metricName == "" { - vm.prg.metricName = string(vm.prg.funcName) - if vm.prg.src != nil { - vm.prg.metricName = vm.prg.src.Name() + "_" + vm.prg.metricName - } - } - - vm.r.functionTickMetrics[vm.prg.metricName] += currentTicks - vm.lastFunctionTicks + functionName := vm.prg.src.Name() + "_" + string(vm.prg.funcName) + vm.r.functionTickMetrics[functionName] += currentTicks - vm.lastFunctionTicks } vm.lastFunctionTicks = currentTicks } From cb34f3200f20401afeb030c643729ef9237a358d Mon Sep 17 00:00:00 2001 From: Calvin Nix Date: Wed, 31 Jan 2024 18:41:33 -0500 Subject: [PATCH 06/18] clean up code --- runtime.go | 4 ---- vm.go | 1 - 2 files changed, 5 deletions(-) diff --git a/runtime.go b/runtime.go index 18dfc77c..769a568e 100644 --- a/runtime.go +++ b/runtime.go @@ -3240,7 +3240,3 @@ func (r *Runtime) getPrototypeFromCtor(newTarget, defCtor, defProto *Object) *Ob func (self *Runtime) DisableFunctionTickTracking() { self.disableTickMetrics = true } - -func (self *Runtime) EnableFunctionTickTracking() { - self.disableTickMetrics = false -} diff --git a/vm.go b/vm.go index b643c691..b2f4d9b3 100644 --- a/vm.go +++ b/vm.go @@ -602,7 +602,6 @@ func (vm *vm) init() { func (vm *vm) run() { vm.halt = false interrupted := false - for !vm.halt { // NOTE: we should try to avoid making expensive operations within this // loop since it gets called millions of times per second. From 5f523153ae335f509ad739b005f100a79f5cbebf Mon Sep 17 00:00:00 2001 From: Calvin Nix Date: Wed, 31 Jan 2024 20:06:49 -0500 Subject: [PATCH 07/18] add nil check --- vm.go | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) diff --git a/vm.go b/vm.go index b2f4d9b3..bb920b91 100644 --- a/vm.go +++ b/vm.go @@ -321,8 +321,11 @@ func (vm *vm) setPrg(prg *Program) { if vm.r.functionTickMetrics == nil { vm.r.functionTickMetrics = make(map[string]uint64) } - functionName := vm.prg.src.Name() + "_" + string(vm.prg.funcName) - vm.r.functionTickMetrics[functionName] += currentTicks - vm.lastFunctionTicks + function := string(vm.prg.funcName) + if vm.prg.src != nil { + function = vm.prg.src.Name() + "_" + function + } + vm.r.functionTickMetrics[function] += currentTicks - vm.lastFunctionTicks } vm.lastFunctionTicks = currentTicks } From 6dcfbe8351ce4e84d278d87082500a4f12400373 Mon Sep 17 00:00:00 2001 From: Calvin Nix Date: Wed, 31 Jan 2024 20:09:57 -0500 Subject: [PATCH 08/18] rename variable for clarity --- runtime.go | 6 +++--- vm.go | 2 +- 2 files changed, 4 insertions(+), 4 deletions(-) diff --git a/runtime.go b/runtime.go index 769a568e..22c514d3 100644 --- a/runtime.go +++ b/runtime.go @@ -205,8 +205,8 @@ type Runtime struct { limiterTicksLeft int ticks uint64 - disableTickMetrics bool - functionTickMetrics map[string]uint64 + functionTickTrackingDisabled bool + functionTickMetrics map[string]uint64 } func (self *Runtime) Ticks() uint64 { @@ -3238,5 +3238,5 @@ func (r *Runtime) getPrototypeFromCtor(newTarget, defCtor, defProto *Object) *Ob } func (self *Runtime) DisableFunctionTickTracking() { - self.disableTickMetrics = true + self.functionTickTrackingDisabled = true } diff --git a/vm.go b/vm.go index bb920b91..815d6d41 100644 --- a/vm.go +++ b/vm.go @@ -315,7 +315,7 @@ type instruction interface { } func (vm *vm) setPrg(prg *Program) { - if !vm.r.disableTickMetrics { + if !vm.r.functionTickTrackingDisabled { currentTicks := vm.r.Ticks() if vm.prg != nil { if vm.r.functionTickMetrics == nil { From 3a14fee6743a86e40f546b53dbc4bcaad2763cc9 Mon Sep 17 00:00:00 2001 From: Calvin Nix Date: Thu, 1 Feb 2024 14:35:05 -0500 Subject: [PATCH 09/18] default function tick tracking to false, add comments --- runtime.go | 11 ++++++++--- vm.go | 2 +- 2 files changed, 9 insertions(+), 4 deletions(-) diff --git a/runtime.go b/runtime.go index 22c514d3..45867fe8 100644 --- a/runtime.go +++ b/runtime.go @@ -205,14 +205,15 @@ type Runtime struct { limiterTicksLeft int ticks uint64 - functionTickTrackingDisabled bool - functionTickMetrics map[string]uint64 + functionTickTrackingEnabled bool + functionTickMetrics map[string]uint64 } func (self *Runtime) Ticks() uint64 { return self.ticks } +// GetFunctionTickMetrics returns a map of ticks used per function. This function is not thread-safe. func (self *Runtime) GetFunctionTickMetrics() map[string]uint64 { return self.functionTickMetrics } @@ -3237,6 +3238,10 @@ func (r *Runtime) getPrototypeFromCtor(newTarget, defCtor, defProto *Object) *Ob return defProto } +func (self *Runtime) EnableFunctionTickTracking() { + self.functionTickTrackingEnabled = true +} + func (self *Runtime) DisableFunctionTickTracking() { - self.functionTickTrackingDisabled = true + self.functionTickTrackingEnabled = false } diff --git a/vm.go b/vm.go index 815d6d41..9bae13d6 100644 --- a/vm.go +++ b/vm.go @@ -315,7 +315,7 @@ type instruction interface { } func (vm *vm) setPrg(prg *Program) { - if !vm.r.functionTickTrackingDisabled { + if vm.r.functionTickTrackingEnabled { currentTicks := vm.r.Ticks() if vm.prg != nil { if vm.r.functionTickMetrics == nil { From 7e6ac5fa1b3082a83fb83e97f4a31319118a6164 Mon Sep 17 00:00:00 2001 From: Calvin Nix Date: Thu, 1 Feb 2024 14:54:51 -0500 Subject: [PATCH 10/18] improve comment --- runtime.go | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/runtime.go b/runtime.go index 45867fe8..185c5819 100644 --- a/runtime.go +++ b/runtime.go @@ -213,7 +213,8 @@ func (self *Runtime) Ticks() uint64 { return self.ticks } -// GetFunctionTickMetrics returns a map of ticks used per function. This function is not thread-safe. +// GetFunctionTickMetrics returns a map of ticks used per function. +// This function is not thread-safe and should only be called at the end of the function execution. func (self *Runtime) GetFunctionTickMetrics() map[string]uint64 { return self.functionTickMetrics } From a4e34daccc349250389d77b5115643c1a8772e0a Mon Sep 17 00:00:00 2001 From: Calvin Nix Date: Fri, 2 Feb 2024 10:12:52 -0500 Subject: [PATCH 11/18] replace setPrg pattern to avoid diverging from goja as much --- compiler_test.go | 3 ++- func.go | 9 ++++++--- runtime.go | 9 ++++++--- vm.go | 25 +++++++++++++++---------- 4 files changed, 29 insertions(+), 17 deletions(-) diff --git a/compiler_test.go b/compiler_test.go index 1db4f0a1..b09cd6ac 100644 --- a/compiler_test.go +++ b/compiler_test.go @@ -156,7 +156,8 @@ func testLibX() *Program { func (r *Runtime) testPrg(p *Program, expectedResult Value, t *testing.T) { vm := r.vm - vm.setPrg(p) + vm.profileTicks() + vm.prg = p vm.pc = 0 vm.prg.dumpCode(t.Logf) vm.result = _undefined diff --git a/func.go b/func.go index 154e9e50..08f55662 100644 --- a/func.go +++ b/func.go @@ -227,7 +227,8 @@ func (f *classFuncObject) _initFields(instance *Object) { if f.initFields != nil { vm := f.val.runtime.vm vm.pushCtx() - vm.setPrg(f.initFields) + vm.profileTicks() + vm.prg = f.initFields vm.stash = f.stash vm.privEnv = f.privEnv vm.newTarget = nil @@ -319,7 +320,8 @@ func (f *baseJsFuncObject) _call(ctx context.Context, args []Value, newTarget, t vm.pushCtx() } vm.args = len(args) - vm.setPrg(f.prg) + vm.profileTicks() + vm.prg = f.prg vm.stash = f.stash vm.privEnv = f.privEnv vm.newTarget = newTarget @@ -433,7 +435,8 @@ func (f *nativeFuncObject) Call(call FunctionCall) Value { func (f *nativeFuncObject) vmCall(vm *vm, n int) { if f.f != nil { vm.pushCtx() - vm.setPrg(nil) + vm.profileTicks() + vm.prg = nil vm.sb = vm.sp - n // so that [sb-1] points to the callee ret := f.f(FunctionCall{ Arguments: vm.stack[vm.sp-n : vm.sp], diff --git a/runtime.go b/runtime.go index 185c5819..81188ddb 100644 --- a/runtime.go +++ b/runtime.go @@ -980,7 +980,8 @@ func (r *Runtime) common_eval(name, src string, direct, strict bool) Value { panic(err) } - vm.setPrg(p) + vm.profileTicks() + vm.prg = p vm.pc = 0 vm.args = 0 vm.result = _undefined @@ -1522,7 +1523,8 @@ func (r *Runtime) RunProgram(p *Program) (result Value, err error) { vm.stash = &r.global.stash vm.sb = vm.sp - 1 } - vm.setPrg(p) + vm.profileTicks() + vm.prg = p vm.pc = 0 vm.result = _undefined ex := vm.runTry(r.vm.ctx) @@ -1537,7 +1539,8 @@ func (r *Runtime) RunProgram(p *Program) (result Value, err error) { vm.clearStack() } else { vm.stack = nil - vm.setPrg(nil) + vm.profileTicks() + vm.prg = nil vm.setFuncName("") r.leave() } diff --git a/vm.go b/vm.go index 9bae13d6..36ffa9a9 100644 --- a/vm.go +++ b/vm.go @@ -314,7 +314,8 @@ type instruction interface { exec(*vm) } -func (vm *vm) setPrg(prg *Program) { +// profileTicks tracks the ticks for the current Program, this should be called prior to updating the program (i.e. vm.prg = p) +func (vm *vm) profileTicks() { if vm.r.functionTickTrackingEnabled { currentTicks := vm.r.Ticks() if vm.prg != nil { @@ -329,7 +330,6 @@ func (vm *vm) setPrg(prg *Program) { } vm.lastFunctionTicks = currentTicks } - vm.prg = prg } func (vm *vm) getFuncName() unistring.String { @@ -886,9 +886,9 @@ func (vm *vm) pushCtx() { } func (vm *vm) restoreCtx(ctx *vmContext) { - vm.stash, vm.privEnv, vm.newTarget, vm.result, vm.pc, vm.sb, vm.args = - ctx.stash, ctx.privEnv, ctx.newTarget, ctx.result, ctx.pc, ctx.sb, ctx.args - vm.setPrg(ctx.prg) + vm.profileTicks() + vm.prg, vm.stash, vm.privEnv, vm.newTarget, vm.result, vm.pc, vm.sb, vm.args = + ctx.prg, ctx.stash, ctx.privEnv, ctx.newTarget, ctx.result, ctx.pc, ctx.sb, ctx.args vm.ctx = ctx.ctx vm.setFuncName(ctx.funcName) @@ -3415,7 +3415,8 @@ func (numargs call) exec(vm *vm) { vm.pc++ vm.pushCtx() vm.args = n - vm.setPrg(f.prg) + vm.profileTicks() + vm.prg = f.prg vm.stash = f.stash vm.privEnv = f.privEnv vm.pc = 0 @@ -3425,7 +3426,8 @@ func (numargs call) exec(vm *vm) { vm.pc++ vm.pushCtx() vm.args = n - vm.setPrg(f.prg) + vm.profileTicks() + vm.prg = f.prg vm.stash = f.stash vm.privEnv = f.privEnv vm.pc = 0 @@ -3435,7 +3437,8 @@ func (numargs call) exec(vm *vm) { vm.pc++ vm.pushCtx() vm.args = n - vm.setPrg(f.prg) + vm.profileTicks() + vm.prg = f.prg vm.stash = f.stash vm.privEnv = f.privEnv vm.pc = 0 @@ -3450,7 +3453,8 @@ func (numargs call) exec(vm *vm) { vm._nativeCall(&f.nativeFuncObject, n) case *proxyObject: vm.pushCtx() - vm.setPrg(nil) + vm.profileTicks() + vm.prg = nil vm.setFuncName("proxy") ret := f.apply(FunctionCall{ctx: vm.ctx, This: vm.stack[vm.sp-n-2], Arguments: vm.stack[vm.sp-n : vm.sp]}) if ret == nil { @@ -3470,7 +3474,8 @@ func (numargs call) exec(vm *vm) { func (vm *vm) _nativeCall(f *nativeFuncObject, n int) { if f.f != nil { vm.pushCtx() - vm.setPrg(nil) + vm.profileTicks() + vm.prg = nil vm.setFuncName(nilSafe(f.getStr("name", nil)).string()) ret := f.f(FunctionCall{ ctx: vm.ctx, From 608e64191a96de2d7af679a75c17ac3cc0823e2a Mon Sep 17 00:00:00 2001 From: Calvin Nix Date: Fri, 2 Feb 2024 10:27:26 -0500 Subject: [PATCH 12/18] Adhere to best practices, simplify profileTicks --- runtime.go | 12 ++++++++---- vm.go | 5 +---- 2 files changed, 9 insertions(+), 8 deletions(-) diff --git a/runtime.go b/runtime.go index 81188ddb..32469af9 100644 --- a/runtime.go +++ b/runtime.go @@ -206,17 +206,17 @@ type Runtime struct { ticks uint64 functionTickTrackingEnabled bool - functionTickMetrics map[string]uint64 + tickMetrics map[string]uint64 } func (self *Runtime) Ticks() uint64 { return self.ticks } -// GetFunctionTickMetrics returns a map of ticks used per function. +// TickMetrics returns a map of ticks used per function. // This function is not thread-safe and should only be called at the end of the function execution. -func (self *Runtime) GetFunctionTickMetrics() map[string]uint64 { - return self.functionTickMetrics +func (self *Runtime) TickMetrics() map[string]uint64 { + return self.tickMetrics } // SetStackTraceLimit sets an upper limit to the number of stack frames that @@ -498,6 +498,10 @@ func (r *Runtime) init() { } r.vm.init() + if r.functionTickTrackingEnabled { + r.tickMetrics = make(map[string]uint64) + } + r.SetRateLimiter(rate.NewLimiter(rate.Inf, maxInt)) } diff --git a/vm.go b/vm.go index 36ffa9a9..b76ce846 100644 --- a/vm.go +++ b/vm.go @@ -319,14 +319,11 @@ func (vm *vm) profileTicks() { if vm.r.functionTickTrackingEnabled { currentTicks := vm.r.Ticks() if vm.prg != nil { - if vm.r.functionTickMetrics == nil { - vm.r.functionTickMetrics = make(map[string]uint64) - } function := string(vm.prg.funcName) if vm.prg.src != nil { function = vm.prg.src.Name() + "_" + function } - vm.r.functionTickMetrics[function] += currentTicks - vm.lastFunctionTicks + vm.r.tickMetrics[function] += currentTicks - vm.lastFunctionTicks } vm.lastFunctionTicks = currentTicks } From 6f9d567e3c2383ee39d2d65aa83e4ec97f3231db Mon Sep 17 00:00:00 2001 From: Calvin Nix Date: Fri, 2 Feb 2024 11:00:12 -0500 Subject: [PATCH 13/18] add tests for tick tracking --- runtime.go | 4 +-- vm_test.go | 94 ++++++++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 95 insertions(+), 3 deletions(-) diff --git a/runtime.go b/runtime.go index 32469af9..0580cecc 100644 --- a/runtime.go +++ b/runtime.go @@ -498,9 +498,7 @@ func (r *Runtime) init() { } r.vm.init() - if r.functionTickTrackingEnabled { - r.tickMetrics = make(map[string]uint64) - } + r.tickMetrics = make(map[string]uint64) r.SetRateLimiter(rate.NewLimiter(rate.Inf, maxInt)) } diff --git a/vm_test.go b/vm_test.go index c34a5892..f8e41015 100644 --- a/vm_test.go +++ b/vm_test.go @@ -594,3 +594,97 @@ func TestStashMemUsage(t *testing.T) { }) } } + +func TestTickTracking(t *testing.T) { + tests := []struct { + name string + script string + functionTickTrackingEnabled bool + expectedTickMetrics map[string]uint64 + }{ + { + name: "should track looping function ticks when tick tracking is enabled", + script: ` + function f() { + for (var i = 0; i < 100; i++) { + } + } + f() + `, + functionTickTrackingEnabled: true, + expectedTickMetrics: map[string]uint64{"test.js_": 6, "test.js_f": 809}, + }, + { + name: "should track larger looping function ticks when tick tracking is enabled", + script: ` + function f() { + for (var i = 0; i < 1000; i++) { + } + } + f() + `, + functionTickTrackingEnabled: true, + expectedTickMetrics: map[string]uint64{"test.js_": 6, "test.js_f": 8009}, + }, + { + name: "should track fib function ticks when tick tracking is enabled", + script: ` + function fib(n) { + if (n < 2) return n; + return fib(n - 2) + fib(n - 1); + } + fib(35); + `, + functionTickTrackingEnabled: true, + expectedTickMetrics: map[string]uint64{"test.js_": 7, "test.js_fib": 358328431}, + }, + { + name: "should not track function ticks when tick tracking is disabled", + script: ` + function f() { + for (var i = 0; i < 100; i++) { + } + } + f() + `, + functionTickTrackingEnabled: false, + expectedTickMetrics: map[string]uint64{}, + }, + } + + for _, tc := range tests { + t.Run(tc.name, func(t *testing.T) { + vm := New() + if tc.functionTickTrackingEnabled { + vm.EnableFunctionTickTracking() + } + + prg := MustCompile("test.js", tc.script, false) + _, err := vm.RunProgram(prg) + if err != nil { + t.Fatal(err) + } + + actualTickMetrics := vm.TickMetrics() + if !isEqual(actualTickMetrics, tc.expectedTickMetrics) { + t.Fatalf("Unexpected tickMetrics. Actual: %v Expected: %v", actualTickMetrics, tc.expectedTickMetrics) + } + }) + } +} + +func isEqual(map1, map2 map[string]uint64) bool { + if map1 == nil && map2 == nil { + return true + } + if len(map1) != len(map2) { + return false + } + for key, valueMap1 := range map1 { + valueMap2, ok := map2[key] + if !ok || valueMap1 != valueMap2 { + return false + } + } + return true +} From c47f60779981d363f0d3fed97ce2100d4f491fcb Mon Sep 17 00:00:00 2001 From: Calvin Nix Date: Fri, 2 Feb 2024 11:06:54 -0500 Subject: [PATCH 14/18] use reflect to check map equality --- vm_test.go | 19 ++----------------- 1 file changed, 2 insertions(+), 17 deletions(-) diff --git a/vm_test.go b/vm_test.go index f8e41015..df3daf85 100644 --- a/vm_test.go +++ b/vm_test.go @@ -2,6 +2,7 @@ package goja import ( "math" + "reflect" "testing" "github.com/dop251/goja/parser" @@ -666,25 +667,9 @@ func TestTickTracking(t *testing.T) { } actualTickMetrics := vm.TickMetrics() - if !isEqual(actualTickMetrics, tc.expectedTickMetrics) { + if !reflect.DeepEqual(actualTickMetrics, tc.expectedTickMetrics) { t.Fatalf("Unexpected tickMetrics. Actual: %v Expected: %v", actualTickMetrics, tc.expectedTickMetrics) } }) } } - -func isEqual(map1, map2 map[string]uint64) bool { - if map1 == nil && map2 == nil { - return true - } - if len(map1) != len(map2) { - return false - } - for key, valueMap1 := range map1 { - valueMap2, ok := map2[key] - if !ok || valueMap1 != valueMap2 { - return false - } - } - return true -} From f02d9b02d643a8841f379adca921bb9a434c182a Mon Sep 17 00:00:00 2001 From: Calvin Nix Date: Fri, 2 Feb 2024 13:40:57 -0500 Subject: [PATCH 15/18] update tests and update variable names/location --- compiler_test.go | 1 - func.go | 3 --- runtime.go | 26 ++++++++++++-------------- vm.go | 27 ++++++++++++--------------- vm_test.go | 24 +++++++++++++++--------- 5 files changed, 39 insertions(+), 42 deletions(-) diff --git a/compiler_test.go b/compiler_test.go index b09cd6ac..2d6e9535 100644 --- a/compiler_test.go +++ b/compiler_test.go @@ -156,7 +156,6 @@ func testLibX() *Program { func (r *Runtime) testPrg(p *Program, expectedResult Value, t *testing.T) { vm := r.vm - vm.profileTicks() vm.prg = p vm.pc = 0 vm.prg.dumpCode(t.Logf) diff --git a/func.go b/func.go index 08f55662..d1f7083b 100644 --- a/func.go +++ b/func.go @@ -227,7 +227,6 @@ func (f *classFuncObject) _initFields(instance *Object) { if f.initFields != nil { vm := f.val.runtime.vm vm.pushCtx() - vm.profileTicks() vm.prg = f.initFields vm.stash = f.stash vm.privEnv = f.privEnv @@ -320,7 +319,6 @@ func (f *baseJsFuncObject) _call(ctx context.Context, args []Value, newTarget, t vm.pushCtx() } vm.args = len(args) - vm.profileTicks() vm.prg = f.prg vm.stash = f.stash vm.privEnv = f.privEnv @@ -435,7 +433,6 @@ func (f *nativeFuncObject) Call(call FunctionCall) Value { func (f *nativeFuncObject) vmCall(vm *vm, n int) { if f.f != nil { vm.pushCtx() - vm.profileTicks() vm.prg = nil vm.sb = vm.sp - n // so that [sb-1] points to the callee ret := f.f(FunctionCall{ diff --git a/runtime.go b/runtime.go index 0580cecc..922d5a65 100644 --- a/runtime.go +++ b/runtime.go @@ -205,20 +205,14 @@ type Runtime struct { limiterTicksLeft int ticks uint64 - functionTickTrackingEnabled bool - tickMetrics map[string]uint64 + tickMetricTrackingEnabled bool + tickMetrics map[string]uint64 } func (self *Runtime) Ticks() uint64 { return self.ticks } -// TickMetrics returns a map of ticks used per function. -// This function is not thread-safe and should only be called at the end of the function execution. -func (self *Runtime) TickMetrics() map[string]uint64 { - return self.tickMetrics -} - // SetStackTraceLimit sets an upper limit to the number of stack frames that // goja will use when formatting an error's stack trace. By default, the limit // is 10. This is consistent with V8 and SpiderMonkey. @@ -982,7 +976,6 @@ func (r *Runtime) common_eval(name, src string, direct, strict bool) Value { panic(err) } - vm.profileTicks() vm.prg = p vm.pc = 0 vm.args = 0 @@ -1525,7 +1518,6 @@ func (r *Runtime) RunProgram(p *Program) (result Value, err error) { vm.stash = &r.global.stash vm.sb = vm.sp - 1 } - vm.profileTicks() vm.prg = p vm.pc = 0 vm.result = _undefined @@ -3244,10 +3236,16 @@ func (r *Runtime) getPrototypeFromCtor(newTarget, defCtor, defProto *Object) *Ob return defProto } -func (self *Runtime) EnableFunctionTickTracking() { - self.functionTickTrackingEnabled = true +func (self *Runtime) EnableTickMetricTracking() { + self.tickMetricTrackingEnabled = true } -func (self *Runtime) DisableFunctionTickTracking() { - self.functionTickTrackingEnabled = false +func (self *Runtime) DisableTickMetricTracking() { + self.tickMetricTrackingEnabled = false +} + +// TickMetrics returns a map of ticks used per function. +// This function is not thread-safe and should only be called at the end of the function execution. +func (self *Runtime) TickMetrics() map[string]uint64 { + return self.tickMetrics } diff --git a/vm.go b/vm.go index b76ce846..63555106 100644 --- a/vm.go +++ b/vm.go @@ -314,19 +314,20 @@ type instruction interface { exec(*vm) } -// profileTicks tracks the ticks for the current Program, this should be called prior to updating the program (i.e. vm.prg = p) +// profileTicks tracks the ticks for the current Program func (vm *vm) profileTicks() { - if vm.r.functionTickTrackingEnabled { - currentTicks := vm.r.Ticks() - if vm.prg != nil { - function := string(vm.prg.funcName) - if vm.prg.src != nil { - function = vm.prg.src.Name() + "_" + function - } - vm.r.tickMetrics[function] += currentTicks - vm.lastFunctionTicks + if !vm.r.tickMetricTrackingEnabled { + return + } + currentTicks := vm.r.Ticks() + if vm.prg != nil { + function := string(vm.prg.funcName) + if vm.prg.src != nil { + function = vm.prg.src.Name() + "." + function } - vm.lastFunctionTicks = currentTicks + vm.r.tickMetrics[function] += currentTicks - vm.lastFunctionTicks } + vm.lastFunctionTicks = currentTicks } func (vm *vm) getFuncName() unistring.String { @@ -874,6 +875,7 @@ func (vm *vm) saveCtx(ctx *vmContext) { } func (vm *vm) pushCtx() { + vm.profileTicks() if len(vm.callStack) > vm.maxCallStackSize { panic(rangeError("Maximum call stack size exceeded")) } @@ -3412,7 +3414,6 @@ func (numargs call) exec(vm *vm) { vm.pc++ vm.pushCtx() vm.args = n - vm.profileTicks() vm.prg = f.prg vm.stash = f.stash vm.privEnv = f.privEnv @@ -3423,7 +3424,6 @@ func (numargs call) exec(vm *vm) { vm.pc++ vm.pushCtx() vm.args = n - vm.profileTicks() vm.prg = f.prg vm.stash = f.stash vm.privEnv = f.privEnv @@ -3434,7 +3434,6 @@ func (numargs call) exec(vm *vm) { vm.pc++ vm.pushCtx() vm.args = n - vm.profileTicks() vm.prg = f.prg vm.stash = f.stash vm.privEnv = f.privEnv @@ -3450,7 +3449,6 @@ func (numargs call) exec(vm *vm) { vm._nativeCall(&f.nativeFuncObject, n) case *proxyObject: vm.pushCtx() - vm.profileTicks() vm.prg = nil vm.setFuncName("proxy") ret := f.apply(FunctionCall{ctx: vm.ctx, This: vm.stack[vm.sp-n-2], Arguments: vm.stack[vm.sp-n : vm.sp]}) @@ -3471,7 +3469,6 @@ func (numargs call) exec(vm *vm) { func (vm *vm) _nativeCall(f *nativeFuncObject, n int) { if f.f != nil { vm.pushCtx() - vm.profileTicks() vm.prg = nil vm.setFuncName(nilSafe(f.getStr("name", nil)).string()) ret := f.f(FunctionCall{ diff --git a/vm_test.go b/vm_test.go index df3daf85..5baa03bc 100644 --- a/vm_test.go +++ b/vm_test.go @@ -2,7 +2,6 @@ package goja import ( "math" - "reflect" "testing" "github.com/dop251/goja/parser" @@ -601,7 +600,7 @@ func TestTickTracking(t *testing.T) { name string script string functionTickTrackingEnabled bool - expectedTickMetrics map[string]uint64 + expectedTickMetricsKeys []string }{ { name: "should track looping function ticks when tick tracking is enabled", @@ -613,7 +612,7 @@ func TestTickTracking(t *testing.T) { f() `, functionTickTrackingEnabled: true, - expectedTickMetrics: map[string]uint64{"test.js_": 6, "test.js_f": 809}, + expectedTickMetricsKeys: []string{"test.js.", "test.js.f"}, }, { name: "should track larger looping function ticks when tick tracking is enabled", @@ -625,7 +624,7 @@ func TestTickTracking(t *testing.T) { f() `, functionTickTrackingEnabled: true, - expectedTickMetrics: map[string]uint64{"test.js_": 6, "test.js_f": 8009}, + expectedTickMetricsKeys: []string{"test.js.", "test.js.f"}, }, { name: "should track fib function ticks when tick tracking is enabled", @@ -637,7 +636,7 @@ func TestTickTracking(t *testing.T) { fib(35); `, functionTickTrackingEnabled: true, - expectedTickMetrics: map[string]uint64{"test.js_": 7, "test.js_fib": 358328431}, + expectedTickMetricsKeys: []string{"test.js.", "test.js.fib"}, }, { name: "should not track function ticks when tick tracking is disabled", @@ -649,7 +648,7 @@ func TestTickTracking(t *testing.T) { f() `, functionTickTrackingEnabled: false, - expectedTickMetrics: map[string]uint64{}, + expectedTickMetricsKeys: []string{}, }, } @@ -657,7 +656,7 @@ func TestTickTracking(t *testing.T) { t.Run(tc.name, func(t *testing.T) { vm := New() if tc.functionTickTrackingEnabled { - vm.EnableFunctionTickTracking() + vm.EnableTickMetricTracking() } prg := MustCompile("test.js", tc.script, false) @@ -667,8 +666,15 @@ func TestTickTracking(t *testing.T) { } actualTickMetrics := vm.TickMetrics() - if !reflect.DeepEqual(actualTickMetrics, tc.expectedTickMetrics) { - t.Fatalf("Unexpected tickMetrics. Actual: %v Expected: %v", actualTickMetrics, tc.expectedTickMetrics) + + if len(actualTickMetrics) != len(tc.expectedTickMetricsKeys) { + t.Fatalf("Unexpected tickMetrics length: Actual: %v Expected length: %v", actualTickMetrics, len(tc.expectedTickMetricsKeys)) + } + + for _, key := range tc.expectedTickMetricsKeys { + if actualTickMetrics[key] <= 0 { + t.Fatalf("Unexpected tickMetrics for key: %v. Expected a positive tick value but received: %v", key, actualTickMetrics[key]) + } } }) } From 0ff846243966275dda5ea3edde9d1d036af458d1 Mon Sep 17 00:00:00 2001 From: Calvin Nix Date: Fri, 2 Feb 2024 13:54:51 -0500 Subject: [PATCH 16/18] add additional test scenarios --- vm_test.go | 68 +++++++++++++++++++++++++++++++++++++++++++----------- 1 file changed, 55 insertions(+), 13 deletions(-) diff --git a/vm_test.go b/vm_test.go index 5baa03bc..c0d159e8 100644 --- a/vm_test.go +++ b/vm_test.go @@ -597,10 +597,10 @@ func TestStashMemUsage(t *testing.T) { func TestTickTracking(t *testing.T) { tests := []struct { - name string - script string - functionTickTrackingEnabled bool - expectedTickMetricsKeys []string + name string + script string + tickMetricTrackingEnabled bool + expectedTickMetricsKeys []string }{ { name: "should track looping function ticks when tick tracking is enabled", @@ -611,8 +611,8 @@ func TestTickTracking(t *testing.T) { } f() `, - functionTickTrackingEnabled: true, - expectedTickMetricsKeys: []string{"test.js.", "test.js.f"}, + tickMetricTrackingEnabled: true, + expectedTickMetricsKeys: []string{"test.js.", "test.js.f"}, }, { name: "should track larger looping function ticks when tick tracking is enabled", @@ -623,8 +623,8 @@ func TestTickTracking(t *testing.T) { } f() `, - functionTickTrackingEnabled: true, - expectedTickMetricsKeys: []string{"test.js.", "test.js.f"}, + tickMetricTrackingEnabled: true, + expectedTickMetricsKeys: []string{"test.js.", "test.js.f"}, }, { name: "should track fib function ticks when tick tracking is enabled", @@ -635,8 +635,8 @@ func TestTickTracking(t *testing.T) { } fib(35); `, - functionTickTrackingEnabled: true, - expectedTickMetricsKeys: []string{"test.js.", "test.js.fib"}, + tickMetricTrackingEnabled: true, + expectedTickMetricsKeys: []string{"test.js.", "test.js.fib"}, }, { name: "should not track function ticks when tick tracking is disabled", @@ -647,15 +647,57 @@ func TestTickTracking(t *testing.T) { } f() `, - functionTickTrackingEnabled: false, - expectedTickMetricsKeys: []string{}, + tickMetricTrackingEnabled: false, + expectedTickMetricsKeys: []string{}, + }, + { + name: "should track ticks from a class method", + script: ` + class Car { + constructor(brand) { + this.brand = brand; + } + + drive() {} + honk() {} + } + const car = new Car("Tesla") + car.drive() + car.honk() + `, + tickMetricTrackingEnabled: true, + expectedTickMetricsKeys: []string{"test.js.", "test.js.drive", "test.js.honk"}, + }, + { + name: "should track ticks from nested functions", + script: ` + function outerFunction() { + function firstNestedFunction() { + function secondNestedFunction() { + function thirdNestedFunction() {} + thirdNestedFunction(); + } + secondNestedFunction(); + } + firstNestedFunction(); + } + outerFunction(); + `, + tickMetricTrackingEnabled: true, + expectedTickMetricsKeys: []string{ + "test.js.", + "test.js.outerFunction", + "test.js.firstNestedFunction", + "test.js.secondNestedFunction", + "test.js.thirdNestedFunction", + }, }, } for _, tc := range tests { t.Run(tc.name, func(t *testing.T) { vm := New() - if tc.functionTickTrackingEnabled { + if tc.tickMetricTrackingEnabled { vm.EnableTickMetricTracking() } From c0ed032e8e1f77668546c67ec9aacbde8149caeb Mon Sep 17 00:00:00 2001 From: Calvin Nix Date: Mon, 5 Feb 2024 10:25:43 -0500 Subject: [PATCH 17/18] update tick metric key formatting and add docs --- runtime.go | 4 ++++ vm.go | 2 +- vm_test.go | 18 +++++++++--------- 3 files changed, 14 insertions(+), 10 deletions(-) diff --git a/runtime.go b/runtime.go index 922d5a65..bdf9825d 100644 --- a/runtime.go +++ b/runtime.go @@ -3236,10 +3236,14 @@ func (r *Runtime) getPrototypeFromCtor(newTarget, defCtor, defProto *Object) *Ob return defProto } +// EnableTickMetricTracking sets tickMetricTrackingEnabled to true. tickMetricTrackingEnabled is checked during every +// profileTick call so this would effectively enable tick tracking immediately. func (self *Runtime) EnableTickMetricTracking() { self.tickMetricTrackingEnabled = true } +// DisableTickMetricTracking sets tickMetricTrackingEnabled to false. tickMetricTrackingEnabled is checked during every +// profileTick call so this would effectively disable tick tracking immediately. func (self *Runtime) DisableTickMetricTracking() { self.tickMetricTrackingEnabled = false } diff --git a/vm.go b/vm.go index 63555106..cc974c78 100644 --- a/vm.go +++ b/vm.go @@ -323,7 +323,7 @@ func (vm *vm) profileTicks() { if vm.prg != nil { function := string(vm.prg.funcName) if vm.prg.src != nil { - function = vm.prg.src.Name() + "." + function + function = vm.prg.src.Name() + "::" + function } vm.r.tickMetrics[function] += currentTicks - vm.lastFunctionTicks } diff --git a/vm_test.go b/vm_test.go index c0d159e8..9f2f2ba8 100644 --- a/vm_test.go +++ b/vm_test.go @@ -612,7 +612,7 @@ func TestTickTracking(t *testing.T) { f() `, tickMetricTrackingEnabled: true, - expectedTickMetricsKeys: []string{"test.js.", "test.js.f"}, + expectedTickMetricsKeys: []string{"test.js::", "test.js::f"}, }, { name: "should track larger looping function ticks when tick tracking is enabled", @@ -624,7 +624,7 @@ func TestTickTracking(t *testing.T) { f() `, tickMetricTrackingEnabled: true, - expectedTickMetricsKeys: []string{"test.js.", "test.js.f"}, + expectedTickMetricsKeys: []string{"test.js::", "test.js::f"}, }, { name: "should track fib function ticks when tick tracking is enabled", @@ -636,7 +636,7 @@ func TestTickTracking(t *testing.T) { fib(35); `, tickMetricTrackingEnabled: true, - expectedTickMetricsKeys: []string{"test.js.", "test.js.fib"}, + expectedTickMetricsKeys: []string{"test.js::", "test.js::fib"}, }, { name: "should not track function ticks when tick tracking is disabled", @@ -666,7 +666,7 @@ func TestTickTracking(t *testing.T) { car.honk() `, tickMetricTrackingEnabled: true, - expectedTickMetricsKeys: []string{"test.js.", "test.js.drive", "test.js.honk"}, + expectedTickMetricsKeys: []string{"test.js::", "test.js::drive", "test.js::honk"}, }, { name: "should track ticks from nested functions", @@ -685,11 +685,11 @@ func TestTickTracking(t *testing.T) { `, tickMetricTrackingEnabled: true, expectedTickMetricsKeys: []string{ - "test.js.", - "test.js.outerFunction", - "test.js.firstNestedFunction", - "test.js.secondNestedFunction", - "test.js.thirdNestedFunction", + "test.js::", + "test.js::outerFunction", + "test.js::firstNestedFunction", + "test.js::secondNestedFunction", + "test.js::thirdNestedFunction", }, }, } From 4fe0248d900378dcaecb891467896ae48cfe3e84 Mon Sep 17 00:00:00 2001 From: Calvin Nix Date: Mon, 12 Feb 2024 15:50:19 -0500 Subject: [PATCH 18/18] add error test scenario and more docs --- runtime.go | 4 ++++ vm_test.go | 16 ++++++++++++++++ 2 files changed, 20 insertions(+) diff --git a/runtime.go b/runtime.go index bdf9825d..a8a3ecc9 100644 --- a/runtime.go +++ b/runtime.go @@ -492,6 +492,10 @@ func (r *Runtime) init() { } r.vm.init() + // Initializing tickMetrics by default to avoid complexities when trying to enable tick tracking with + // vm.EnableFunctionTickTracking(). The problem here is we need to have the vm object in order to enable tick tracking, + // but we check whether tick tracking is enabled when we create the vm object. + // It is simpler, and not costly, to just have this map always initialized. r.tickMetrics = make(map[string]uint64) r.SetRateLimiter(rate.NewLimiter(rate.Inf, maxInt)) diff --git a/vm_test.go b/vm_test.go index 9f2f2ba8..28025b6d 100644 --- a/vm_test.go +++ b/vm_test.go @@ -692,6 +692,22 @@ func TestTickTracking(t *testing.T) { "test.js::thirdNestedFunction", }, }, + { + name: "should track ticks even when a function throws an error", + script: ` + function explode() { + throw new Error("boom"); + } + try { + explode() + } catch (err) {} + `, + tickMetricTrackingEnabled: true, + expectedTickMetricsKeys: []string{ + "test.js::", + "test.js::explode", + }, + }, } for _, tc := range tests {