From b0008174755b025670463583bb4b53575701a233 Mon Sep 17 00:00:00 2001 From: Mihail Stoykov Date: Thu, 28 Oct 2021 15:06:56 +0300 Subject: [PATCH] Add basic event loop with an API to be used by modules As well as cut down setTimeout implementation. A recent update to goja introduced support for ECMAScript Promise. The catch here is that Promise's then will only be called when goja exits executing js code and it has already been resolved. Also resolving and rejecting Promises needs to happen while no other js code is being executed as it will otherwise lead to a data race. This more or less necessitates adding an event loop. Additionally because a call to a k6 modules such as `k6/http` might make a promise to signal when an http request is made, but if (no changes were made) the iteration then finishes before the request completes, nothing would've stopped the start of a *new* iteration. That new iteration would then probably just again ask k6/http to make a new request with a Promise ... This might be a desirable behaviour for some cases but arguably will be very confusing so this commit also adds a way to RegisterCallback that will return a function to actually queue the callback on the event loop, but prevent the event loop from ending before the callback is queued and possible executed, once RegisterCallback is called. Additionally to that, some additional code was needed so there is an event loop for all special functions calls (setup, teardown, handleSummary, default) and the init context. This also adds handling of rejected promise which don't have a reject handler similar to what deno does. It also adds a per iteration context that gets canceled on the end of each iteration letting other code know that it needs to stop. This is particularly needed here as if an iteration gets aborted by a syntax error (or unhandled promise rejection), a new iteration will start right after that. But this means that any in-flight asynchronous operation (an http requests for example) will *not* get stopped. With a context that gets canceled every time module code can notice that and abort any operation. For this same reason the event loop needs wait to be *empty* before the iteration ends. This did lead to some ... not very nice code, but a whole package needs a big refactor which will likely happen once common.Bind and co gets removed. And finally, a basic setTimeout implementation was added. There is no way to currently cancel the setTimeout - no clearTimeout. This likely needs to be extended but this can definitely wait. Or we might decide to actually drop setTimeout altogether as it isn't particularly useful currently without any async APIs, it just makes testing the event loop functionality possible. fixes #882 --- core/local/eventloop_test.go | 181 ++++++++++++++++++++++++++++++++++ js/bundle.go | 7 +- js/doc.go | 5 + js/eventloop.go | 167 +++++++++++++++++++++++++++++++ js/eventloop_test.go | 118 ++++++++++++++++++++++ js/initcontext.go | 32 +++++- js/modules/modules.go | 14 +++ js/modulestest/modulestest.go | 6 ++ js/runner.go | 58 +++++++---- 9 files changed, 562 insertions(+), 26 deletions(-) create mode 100644 core/local/eventloop_test.go create mode 100644 js/doc.go create mode 100644 js/eventloop.go create mode 100644 js/eventloop_test.go diff --git a/core/local/eventloop_test.go b/core/local/eventloop_test.go new file mode 100644 index 00000000000..ef1bfaff7d8 --- /dev/null +++ b/core/local/eventloop_test.go @@ -0,0 +1,181 @@ +package local + +import ( + "context" + "io/ioutil" + "net/url" + "testing" + "time" + + "github.com/sirupsen/logrus" + "github.com/stretchr/testify/require" + "go.k6.io/k6/js" + "go.k6.io/k6/lib" + "go.k6.io/k6/lib/metrics" + "go.k6.io/k6/lib/testutils" + "go.k6.io/k6/lib/types" + "go.k6.io/k6/loader" +) + +func eventLoopTest(t *testing.T, script []byte, testHandle func(context.Context, lib.Runner, error, *testutils.SimpleLogrusHook)) { + logger := logrus.New() + logger.SetOutput(ioutil.Discard) + logHook := &testutils.SimpleLogrusHook{HookedLevels: []logrus.Level{logrus.InfoLevel, logrus.WarnLevel, logrus.ErrorLevel}} + logger.AddHook(logHook) + + registry := metrics.NewRegistry() + builtinMetrics := metrics.RegisterBuiltinMetrics(registry) + runner, err := js.New( + logger, + &loader.SourceData{ + URL: &url.URL{Path: "/script.js"}, + Data: script, + }, + nil, + lib.RuntimeOptions{}, + builtinMetrics, + registry, + ) + require.NoError(t, err) + + ctx, cancel, execScheduler, samples := newTestExecutionScheduler(t, runner, logger, + lib.Options{ + TeardownTimeout: types.NullDurationFrom(time.Second), + SetupTimeout: types.NullDurationFrom(time.Second), + }) + defer cancel() + + errCh := make(chan error, 1) + go func() { errCh <- execScheduler.Run(ctx, ctx, samples, builtinMetrics) }() + + select { + case err := <-errCh: + testHandle(ctx, runner, err, logHook) + case <-time.After(10 * time.Second): + t.Fatal("timed out") + } +} + +func TestEventLoop(t *testing.T) { + t.Parallel() + script := []byte(` + setTimeout(()=> {console.log("initcontext setTimeout")}, 200) + console.log("initcontext"); + export default function() { + setTimeout(()=> {console.log("default setTimeout")}, 200) + console.log("default"); + }; + export function setup() { + setTimeout(()=> {console.log("setup setTimeout")}, 200) + console.log("setup"); + }; + export function teardown() { + setTimeout(()=> {console.log("teardown setTimeout")}, 200) + console.log("teardown"); + }; + export function handleSummary() { + setTimeout(()=> {console.log("handleSummary setTimeout")}, 200) + console.log("handleSummary"); + }; +`) + eventLoopTest(t, script, func(ctx context.Context, runner lib.Runner, err error, logHook *testutils.SimpleLogrusHook) { + require.NoError(t, err) + _, err = runner.HandleSummary(ctx, &lib.Summary{RootGroup: &lib.Group{}}) + require.NoError(t, err) + entries := logHook.Drain() + msgs := make([]string, len(entries)) + for i, entry := range entries { + msgs[i] = entry.Message + } + require.Equal(t, []string{ + "initcontext", // first initialization + "initcontext setTimeout", + "initcontext", // for vu + "initcontext setTimeout", + "initcontext", // for setup + "initcontext setTimeout", + "setup", // setup + "setup setTimeout", + "default", // one iteration + "default setTimeout", + "initcontext", // for teardown + "initcontext setTimeout", + "teardown", // teardown + "teardown setTimeout", + "initcontext", // for handleSummary + "initcontext setTimeout", + "handleSummary", // handleSummary + "handleSummary setTimeout", + }, msgs) + }) +} + +func TestEventLoopCrossScenario(t *testing.T) { + t.Parallel() + script := []byte(` +import exec from "k6/execution" +export const options = { + scenarios: { + "first":{ + executor: "shared-iterations", + maxDuration: "1s", + iterations: 1, + vus: 1, + gracefulStop:"1s", + }, + "second": { + executor: "shared-iterations", + maxDuration: "1s", + iterations: 1, + vus: 1, + startTime: "3s", + } + } +} +export default function() { + let i = exec.scenario.name + setTimeout(()=> {console.log(i)}, 3000) +} +`) + + eventLoopTest(t, script, func(_ context.Context, _ lib.Runner, err error, logHook *testutils.SimpleLogrusHook) { + require.NoError(t, err) + entries := logHook.Drain() + msgs := make([]string, len(entries)) + for i, entry := range entries { + msgs[i] = entry.Message + } + require.Equal(t, []string{"second"}, msgs) + }) +} + +func TestEventLoopDoesntCrossIterations(t *testing.T) { + t.Parallel() + script := []byte(` +import { sleep } from "k6" +export const options = { + iterations: 2, + vus: 1, +} + +export default function() { + let i = __ITER; + setTimeout(()=> { console.log(i) }, 1000) + if (__ITER == 0) { + throw "just error" + } else { + sleep(1) + } +} +`) + + eventLoopTest(t, script, func(_ context.Context, _ lib.Runner, err error, logHook *testutils.SimpleLogrusHook) { + require.NoError(t, err) + entries := logHook.Drain() + msgs := make([]string, len(entries)) + for i, entry := range entries { + msgs[i] = entry.Message + } + require.Equal(t, []string{"just error\n\tat /script.js:12:4(13)\n\tat native\n", "1"}, msgs) + }) +} diff --git a/js/bundle.go b/js/bundle.go index dc6bac545fb..85fe604364e 100644 --- a/js/bundle.go +++ b/js/bundle.go @@ -335,7 +335,12 @@ func (b *Bundle) instantiate(logger logrus.FieldLogger, rt *goja.Runtime, init * "require": init.Require, "open": init.Open, }) - if _, err := rt.RunProgram(b.Program); err != nil { + init.moduleVUImpl.eventLoop = newEventLoop(init.moduleVUImpl) + err := init.moduleVUImpl.eventLoop.start(func() error { + _, err := rt.RunProgram(b.Program) + return err + }) + if err != nil { var exception *goja.Exception if errors.As(err, &exception) { err = &scriptException{inner: exception} diff --git a/js/doc.go b/js/doc.go new file mode 100644 index 00000000000..21915fca4c4 --- /dev/null +++ b/js/doc.go @@ -0,0 +1,5 @@ +/* +Package js is the JavaScript implementation of the lib.Runner and relative concepts for +executing concurrent-safe JavaScript code. +*/ +package js diff --git a/js/eventloop.go b/js/eventloop.go new file mode 100644 index 00000000000..b2abe635b93 --- /dev/null +++ b/js/eventloop.go @@ -0,0 +1,167 @@ +package js + +import ( + "fmt" + "sync" + "time" + + "github.com/dop251/goja" + "go.k6.io/k6/js/modules" +) + +// eventLoop implements an event loop with a cut-down setTimeout and +// handling of unhandled rejected promises. +// +// A specific thing about this event loop is that it will wait to return +// not only until the queue is empty but until nothing is registered that it will run in the future. +// This is in contrast with more common behaviours where it only returns on +// a specific event/action or when the loop is empty. +// This is required as in k6 iterations (for which event loop will be primary used) +// are supposed to be independent and any work started in them needs to finish, +// but also they need to end when all the instructions are done. +// Additionally because of this on any error while the event loop will exit it's +// required to wait on the event loop to be empty before the execution can continue. +type eventLoop struct { + lock sync.Mutex + queue []func() error + wakeupCh chan struct{} // TODO: maybe use sync.Cond ? + registeredCallbacks int + vu modules.VU + + // pendingPromiseRejections are rejected promises with no handler, + // if there is something in this map at an end of an event loop then it will exit with an error. + // It's similar to what Deno and Node do. + pendingPromiseRejections map[*goja.Promise]struct{} +} + +// newEventLoop returns a new event loop with a few helpers attached to it: +// - adding setTimeout javascript implementation +// - reporting (and aborting on) unhandled promise rejections +func newEventLoop(vu modules.VU) *eventLoop { + e := &eventLoop{ + wakeupCh: make(chan struct{}, 1), + pendingPromiseRejections: make(map[*goja.Promise]struct{}), + vu: vu, + } + vu.Runtime().SetPromiseRejectionTracker(e.promiseRejectionTracker) + e.addSetTimeout() + + return e +} + +func (e *eventLoop) wakeup() { + select { + case e.wakeupCh <- struct{}{}: + default: + } +} + +// registerCallback register that a callback will be invoked on the loop, preventing it from returning/finishing. +// The returned function, upon invocation, will queue its argument and wakeup the loop if needed. +// If the eventLoop has since stopped, it will not be executed. +// This function *must* be called from within running on the event loop, but its result can be called from anywhere. +func (e *eventLoop) registerCallback() func(func() error) { + e.lock.Lock() + e.registeredCallbacks++ + e.lock.Unlock() + + return func(f func() error) { + e.lock.Lock() + e.queue = append(e.queue, f) + e.registeredCallbacks-- + e.lock.Unlock() + e.wakeup() + } +} + +func (e *eventLoop) promiseRejectionTracker(p *goja.Promise, op goja.PromiseRejectionOperation) { + // No locking necessary here as the goja runtime will call this synchronously + // Read Notes on https://tc39.es/ecma262/#sec-host-promise-rejection-tracker + if op == goja.PromiseRejectionReject { + e.pendingPromiseRejections[p] = struct{}{} + } else { // goja.PromiseRejectionHandle so a promise that was previously rejected without handler now got one + delete(e.pendingPromiseRejections, p) + } +} + +func (e *eventLoop) popAll() (queue []func() error, awaiting bool) { + e.lock.Lock() + queue = e.queue + e.queue = make([]func() error, 0, len(queue)) + awaiting = e.registeredCallbacks != 0 + e.lock.Unlock() + return +} + +// start will run the event loop until it's empty and there are no uninvoked registered callbacks +// or a queued function returns an error. The provided firstCallback will be the first thing executed. +// After start returns the event loop can be reused as long as waitOnRegistered is called. +func (e *eventLoop) start(firstCallback func() error) error { + e.queue = []func() error{firstCallback} + for { + queue, awaiting := e.popAll() + + if len(queue) == 0 { + if !awaiting { + return nil + } + <-e.wakeupCh + continue + } + + for _, f := range queue { + if err := f(); err != nil { + return err + } + } + + // This will get a random unhandled rejection instead of the first one, for example. + // But that seems to be the case in other tools as well so it seems to not be that big of a problem. + for promise := range e.pendingPromiseRejections { + // TODO maybe throw the whole promise up and get make a better message outside of the event loop + value := promise.Result() + if o := value.ToObject(e.vu.Runtime()); o != nil { + stack := o.Get("stack") + if stack != nil { + value = stack + } + } + // this is the de facto wording in both firefox and deno at least + return fmt.Errorf("Uncaught (in promise) %s", value) //nolint:stylecheck + } + } +} + +// Wait on all registered callbacks so we know nothing is still doing work. +func (e *eventLoop) waitOnRegistered() { + for { + _, awaiting := e.popAll() + if !awaiting { + return + } + <-e.wakeupCh + } +} + +func (e *eventLoop) addSetTimeout() { + _ = e.vu.Runtime().Set("setTimeout", func(f goja.Callable, t float64) { + // TODO maybe really return something to use with `clearTimeout + // TODO support arguments ... maybe + runOnLoop := e.registerCallback() + go func() { + timer := time.NewTimer(time.Duration(t * float64(time.Millisecond))) + select { + case <-timer.C: + runOnLoop(func() error { + _, err := f(goja.Undefined()) + return err + }) + case <-e.vu.Context().Done(): + // TODO log something? + + timer.Stop() + runOnLoop(func() error { return nil }) + } + }() + }) +} diff --git a/js/eventloop_test.go b/js/eventloop_test.go new file mode 100644 index 00000000000..7fed52b58e5 --- /dev/null +++ b/js/eventloop_test.go @@ -0,0 +1,118 @@ +package js + +import ( + "errors" + "fmt" + "testing" + "time" + + "github.com/dop251/goja" + "github.com/stretchr/testify/require" + "go.k6.io/k6/js/modulestest" +) + +func TestBasicEventLoop(t *testing.T) { + t.Parallel() + loop := newEventLoop(&modulestest.VU{RuntimeField: goja.New()}) + var ran int + f := func() error { //nolint:unparam + ran++ + return nil + } + require.NoError(t, loop.start(f)) + require.Equal(t, 1, ran) + require.NoError(t, loop.start(f)) + require.Equal(t, 2, ran) + require.Error(t, loop.start(func() error { + _ = f() + loop.registerCallback()(f) + return errors.New("something") + })) + require.Equal(t, 3, ran) +} + +func TestEventLoopRegistered(t *testing.T) { + t.Parallel() + loop := newEventLoop(&modulestest.VU{RuntimeField: goja.New()}) + var ran int + f := func() error { + ran++ + r := loop.registerCallback() + go func() { + time.Sleep(time.Second) + r(func() error { + ran++ + return nil + }) + }() + return nil + } + start := time.Now() + require.NoError(t, loop.start(f)) + took := time.Since(start) + require.Equal(t, 2, ran) + require.Less(t, time.Second, took) + require.Greater(t, time.Second+time.Millisecond*100, took) +} + +func TestEventLoopWaitOnRegistered(t *testing.T) { + t.Parallel() + var ran int + loop := newEventLoop(&modulestest.VU{RuntimeField: goja.New()}) + f := func() error { + ran++ + r := loop.registerCallback() + go func() { + time.Sleep(time.Second) + r(func() error { + ran++ + return nil + }) + }() + return fmt.Errorf("expected") + } + start := time.Now() + require.Error(t, loop.start(f)) + took := time.Since(start) + loop.waitOnRegistered() + took2 := time.Since(start) + require.Equal(t, 1, ran) + require.Greater(t, time.Millisecond*50, took) + require.Less(t, time.Second, took2) + require.Greater(t, time.Second+time.Millisecond*100, took2) +} + +func TestEventLoopReuse(t *testing.T) { + t.Parallel() + sleepTime := time.Millisecond * 500 + loop := newEventLoop(&modulestest.VU{RuntimeField: goja.New()}) + f := func() error { + for i := 0; i < 100; i++ { + bad := i == 17 + r := loop.registerCallback() + + go func() { + if !bad { + time.Sleep(sleepTime) + } + r(func() error { + if bad { + return errors.New("something") + } + panic("this should never execute") + }) + }() + } + return fmt.Errorf("expected") + } + for i := 0; i < 3; i++ { + start := time.Now() + require.Error(t, loop.start(f)) + took := time.Since(start) + loop.waitOnRegistered() + took2 := time.Since(start) + require.Greater(t, time.Millisecond*50, took) + require.Less(t, sleepTime, took2) + require.Greater(t, sleepTime+time.Millisecond*100, took2) + } +} diff --git a/js/initcontext.go b/js/initcontext.go index 3eab0d553e7..9db4c16969d 100644 --- a/js/initcontext.go +++ b/js/initcontext.go @@ -150,10 +150,11 @@ func (i *InitContext) Require(arg string) goja.Value { } type moduleVUImpl struct { - ctxPtr *context.Context - initEnv *common.InitEnvironment - state *lib.State - runtime *goja.Runtime + ctxPtr *context.Context + initEnv *common.InitEnvironment + state *lib.State + runtime *goja.Runtime + eventLoop *eventLoop } func newModuleVUImpl() *moduleVUImpl { @@ -178,6 +179,29 @@ func (m *moduleVUImpl) Runtime() *goja.Runtime { return m.runtime } +func (m *moduleVUImpl) RegisterCallback() func(func() error) { + return m.eventLoop.registerCallback() +} + +/* This is here to illustrate how to use RegisterCallback to get a promise to work with the event loop +// TODO move this to a common function or remove before merging + +// MakeHandledPromise will create and promise and return it's resolve, reject methods as well wrapped in such a way that +// it will block the eventloop from exiting before they are called even if the promise isn't resolved by the time the +// current script ends executing +func (m *moduleVUImpl) MakeHandledPromise() (*goja.Promise, func(interface{}), func(interface{})) { + callback := m.eventLoop.registerCallback() + p, resolve, reject := m.runtime.NewPromise() + return p, func(i interface{}) { + // more stuff + callback(func() { resolve(i) }) + }, func(i interface{}) { + // more stuff + callback(func() { reject(i) }) + } +} +*/ + func toESModuleExports(exp modules.Exports) interface{} { if exp.Named == nil { return exp.Default diff --git a/js/modules/modules.go b/js/modules/modules.go index acff2edfa27..0cedc6705cb 100644 --- a/js/modules/modules.go +++ b/js/modules/modules.go @@ -114,6 +114,20 @@ type VU interface { // Runtime returns the goja.Runtime for the current VU Runtime() *goja.Runtime + + // RegisterCallback lets a module declare that it wants to run a function on the event loop *at a later point in time*. + // It needs to be called from within the event loop, so not in a goroutine spawned by a module. + // Its result can be called with a function that will be executed *on the event loop* - + // possibly letting you call RegisterCallback again. + // Calling the result can be done at any time. The event loop will block until that happens, (if it doesn't + // have something else to run) so in the event of an iteration end or abort (for example due to an exception), + // It is the module responsibility to monitor the context and abort on it being done. + // This still means that the returned function here *needs* to be called to signal that the module + // has aborted the operation and will not do anything more, not doing so will block k6. + RegisterCallback() func(func() error) + + // sealing field will help probably with pointing users that they just need to embed this in their Instance + // implementations } // Exports is representation of ESM exports of a module diff --git a/js/modulestest/modulestest.go b/js/modulestest/modulestest.go index cf3574d5cfa..03519a7cb60 100644 --- a/js/modulestest/modulestest.go +++ b/js/modulestest/modulestest.go @@ -58,3 +58,9 @@ func (m *VU) State() *lib.State { func (m *VU) Runtime() *goja.Runtime { return m.RuntimeField } + +// RegisterCallback is not really implemented +func (m *VU) RegisterCallback() func(f func() error) { + // TODO Implement + return nil +} diff --git a/js/runner.go b/js/runner.go index 6f509aa9911..0ce9f8d2fca 100644 --- a/js/runner.go +++ b/js/runner.go @@ -403,7 +403,7 @@ func (r *Runner) HandleSummary(ctx context.Context, summary *lib.Summary) (map[s vu.Runtime.ToValue(r.Bundle.RuntimeOptions.SummaryExport.String), vu.Runtime.ToValue(summaryDataForJS), } - rawResult, _, _, err := vu.runFn(ctx, false, handleSummaryWrapper, wrapperArgs...) + rawResult, _, _, err := vu.runFn(ctx, false, handleSummaryWrapper, nil, wrapperArgs...) // TODO: refactor the whole JS runner to avoid copy-pasting these complicated bits... // deadline is reached so we have timeouted but this might've not been registered correctly @@ -535,7 +535,7 @@ func (r *Runner) runPart(ctx context.Context, out chan<- stats.SampleContainer, } vu.state.Group = group - v, _, _, err := vu.runFn(ctx, false, fn, vu.Runtime.ToValue(arg)) + v, _, _, err := vu.runFn(ctx, false, fn, nil, vu.Runtime.ToValue(arg)) // deadline is reached so we have timeouted but this might've not been registered correctly if deadline, ok := ctx.Deadline(); ok && time.Now().After(deadline) { @@ -729,8 +729,11 @@ func (u *ActiveVU) RunOnce() error { panic(fmt.Errorf("error setting __ITER in goja runtime: %w", err)) } + ctx, cancel := context.WithCancel(u.RunContext) + defer cancel() + *u.moduleVUImpl.ctxPtr = ctx // Call the exported function. - _, isFullIteration, totalTime, err := u.runFn(u.RunContext, true, fn, u.setupData) + _, isFullIteration, totalTime, err := u.runFn(ctx, true, fn, cancel, u.setupData) if err != nil { var x *goja.InterruptedError if errors.As(err, &x) { @@ -756,8 +759,10 @@ func (u *ActiveVU) RunOnce() error { return err } +// if isDefault is true, cancel also needs to be provided and it should cancel the provided context +// TODO remove the need for the above through refactoring of this function and its callees func (u *VU) runFn( - ctx context.Context, isDefault bool, fn goja.Callable, args ...goja.Value, + ctx context.Context, isDefault bool, fn goja.Callable, cancel func(), args ...goja.Value, ) (v goja.Value, isFullIteration bool, t time.Duration, err error) { if !u.Runner.Bundle.Options.NoCookiesReset.ValueOrZero() { u.state.CookieJar, err = cookiejar.New(nil) @@ -771,24 +776,35 @@ func (u *VU) runFn( u.state.Tags.Set("iter", strconv.FormatInt(u.state.Iteration, 10)) } - defer func() { - if r := recover(); r != nil { - gojaStack := u.Runtime.CaptureCallStack(20, nil) - err = fmt.Errorf("a panic occurred in VU code but was caught: %s", r) - // TODO figure out how to use PanicLevel without panicing .. this might require changing - // the logger we use see - // https://github.com/sirupsen/logrus/issues/1028 - // https://github.com/sirupsen/logrus/issues/993 - b := new(bytes.Buffer) - for _, s := range gojaStack { - s.Write(b) - } - u.state.Logger.Log(logrus.ErrorLevel, "panic: ", r, "\n", string(debug.Stack()), "\nGoja stack:\n", b.String()) - } - }() - startTime := time.Now() - v, err = fn(goja.Undefined(), args...) // Actually run the JS script + + if u.moduleVUImpl.eventLoop == nil { + u.moduleVUImpl.eventLoop = newEventLoop(u.moduleVUImpl) + } + err = u.moduleVUImpl.eventLoop.start(func() (err error) { + // here the returned value purposefully shadows the external one as they can be different + defer func() { + if r := recover(); r != nil { + gojaStack := u.Runtime.CaptureCallStack(20, nil) + err = fmt.Errorf("a panic occurred in VU code but was caught: %s", r) + // TODO figure out how to use PanicLevel without panicing .. this might require changing + // the logger we use see + // https://github.com/sirupsen/logrus/issues/1028 + // https://github.com/sirupsen/logrus/issues/993 + b := new(bytes.Buffer) + for _, s := range gojaStack { + s.Write(b) + } + u.state.Logger.Log(logrus.ErrorLevel, "panic: ", r, "\n", string(debug.Stack()), "\nGoja stack:\n", b.String()) + } + }() + v, err = fn(goja.Undefined(), args...) // Actually run the JS script + return err + }) + if err != nil && isDefault { + cancel() + u.moduleVUImpl.eventLoop.waitOnRegistered() + } endTime := time.Now() var exception *goja.Exception if errors.As(err, &exception) {