rare Panic during initialization of VUs

[mstoykov]

Brief summary

Under very specific situations initialization of a VU can panic.

This requires that getting an export includes calling a function as is the case when the internal babel transpiles

export * from "./a.js"
to

"use strict";

Object.defineProperty(exports, "__esModule", {
  value: true
});
var _a = require("a.js");
Object.keys(_a).forEach(function (key) {
  if (key === "default" || key === "__esModule") return;
  if (key in exports && exports[key] === _a[key]) return;
  Object.defineProperty(exports, key, {
    enumerable: true,
    get: function get() {
      return _a[key];
    }
  });
});

(you can see it in the playground here)

And the run context was cancelled between the k6 running the init context

k6/js/bundle.go

Lines 320 to 334 in bbfe357

	err = common.RunWithPanicCatching(logger, rt, func() error {
	return init.moduleVUImpl.eventLoop.Start(func() error {
	f, errRun := rt.RunProgram(b.Program)
	if errRun != nil {
	return errRun
	}
	if call, ok := goja.AssertFunction(f); ok {
	if _, errRun = call(pgm.exports, pgm.module, pgm.exports); errRun != nil {
	return errRun
	}
	return nil
	}
	panic("Somehow a commonjs main module is not wrapped in a function")
	})
	})

and getting the exports in

k6/js/bundle.go

Line 234 in bbfe357

fn, _ := goja.AssertFunction(exports.Get(k))

This in practice means that the interrupt from

k6/js/bundle.go

Line 314 in bbfe357

rt.Interrupt(init.moduleVUImpl.ctx.Err())

needs to run before

k6/js/bundle.go

Line 335 in bbfe357

close(initDone)

but after goja has stopped running the above code.

This is ... Extremely hard to do which is why this is low prio.

Also this is only a problem after #2800 as before this the context was not cancelled.

This will also not be a problem if/when we do not use babel unless someone writes this code.

And finally as this happens mostly at the beginning of the test and the window is really small in the real world it is very unlikely. The case it was noticed is with unplanned VUs for arrival rate but even there I needed to use sleep to reproduce it.

k6 version

v0.43.0 (not released), commit: bbfe357

OS

all

Docker version and image (if applicable)

No response

Steps to reproduce the problem

1. add a sleep and a log before

   k6/js/bundle.go

   Line 335 in bbfe357

   close(initDone)

2. Have a script that uses export *
3. have a script with scenarios which uses unplanned VUs
4. run the script and ^C after you see teh logged line a couple of times

export * from "./a.js"
export const options  = {
  scenarios: {
    test: {
      executor: "ramping-arrival-rate",
      exec: "a",
      preallocatedVUs: 1,
      maxVUs: 1000,
      stages :[
        { duration: "100s", target: 10000000,},
      ],
    }
  }
}

and a.js being

import { sleep } from "k6"
export function a() { sleep(1) }

Expected behaviour

No panic

Actual behaviour

goroutine 124 [running]:
github.com/dop251/goja.(*vm).handleThrow(0xc000eccc60, {0x15483c0, 0xc000700cc0})
        github.com/dop251/[email protected]/vm.go:730 +0x3b8
github.com/dop251/goja.(*vm).runTryInner.func1()
        github.com/dop251/[email protected]/vm.go:772 +0x45
panic({0x15483c0, 0xc000700cc0})
        runtime/panic.go:884 +0x212
github.com/dop251/goja.(*vm).run(0xc000eccc60)
        github.com/dop251/[email protected]/vm.go:577 +0x133
github.com/dop251/goja.(*vm).runTryInner(0xc000eccc60?)
        github.com/dop251/[email protected]/vm.go:776 +0x70
github.com/dop251/goja.(*baseJsFuncObject).__call(0xc000f380c0, {0x0?, 0x0, 0x40f43f?}, {0x0?, 0x0}, {0x1971458?, 0xc0004c4e10?})
        github.com/dop251/[email protected]/func.go:378 +0x665
github.com/dop251/goja.(*baseJsFuncObject)._call(...)
        github.com/dop251/[email protected]/func.go:394
github.com/dop251/goja.(*baseJsFuncObject).call(0x10?, {{0x1971458, 0xc0004c4e10}, {0x0, 0x0, 0x0}}, {0x0?, 0x0?})
        github.com/dop251/[email protected]/func.go:402 +0x7a
github.com/dop251/goja.(*baseJsFuncObject).Call(0x14a7160?, {{0x1971458, 0xc0004c4e10}, {0x0, 0x0, 0x0}})
        github.com/dop251/[email protected]/func.go:334 +0x45
github.com/dop251/goja.(*valueProperty).get(0x1459260?, {0x1971458, 0xc0004c4e10})
        github.com/dop251/[email protected]/value.go:516 +0xbb
github.com/dop251/goja.(*baseObject).getStr(0xc000cdb420, {0xc001617474, 0x1}, {0x0?, 0x0})
        github.com/dop251/[email protected]/object.go:363 +0x125
github.com/dop251/goja.(*Object).Get(0xc0004c4e10, {0xc001617474?, 0xc000f596f0?})
        github.com/dop251/[email protected]/value.go:796 +0x52
go.k6.io/k6/js.(*Bundle).Instantiate(0xc0027642c0, {0x19634a8?, 0xc0018e51a0}, 0xc0001c42f0?)
        go.k6.io/k6/js/bundle.go:236 +0x61c
go.k6.io/k6/js.(*Runner).newVU(0xc000eba0c0, {0x19634a8?, 0xc0018e51a0?}, 0x3, 0x3, 0xc0027836e0)
        go.k6.io/k6/js/runner.go:129 +0x65
go.k6.io/k6/js.(*Runner).NewVU(0x6fc23ac00?, {0x19634a8?, 0xc0018e51a0?}, 0x24155a8?, 0x1?, 0x1?)
        go.k6.io/k6/js/runner.go:117 +0x25
go.k6.io/k6/execution.(*Scheduler).initVU(0xc000eac3f0, {0x19634a8, 0xc0018e51a0}, 0x40890a?, {0x1975610, 0xc000eac380})
        go.k6.io/k6/execution/scheduler.go:130 +0xa5
go.k6.io/k6/execution.(*Scheduler).initVUsAndExecutors.func2({0x19634a8?, 0xc0018e51a0?}, 0x435cadd1521bd?)
        go.k6.io/k6/execution/scheduler.go:305 +0x3e
go.k6.io/k6/lib.(*ExecutionState).InitializeNewVU(0xc002677e00, {0x19634a8?, 0xc0018e51a0?}, 0x6fc23ac00?)
        go.k6.io/k6/lib/execution.go:527 +0x3e
go.k6.io/k6/lib.(*ExecutionState).GetUnplannedVU(0xc002677e00, {0x19634a8, 0xc0018e51a0}, 0x40ec1e?)
        go.k6.io/k6/lib/execution.go:518 +0x105
go.k6.io/k6/lib/executor.RampingArrivalRate.Run.func6()
        go.k6.io/k6/lib/executor/ramping_arrival_rate.go:412 +0x131
created by go.k6.io/k6/lib/executor.RampingArrivalRate.Run
        go.k6.io/k6/lib/executor/ramping_arrival_rate.go:407 +0xe8c