From 91a287c7f1fa416e16b4bb6ecaef47c2bf8818d2 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ivan=20Miri=C4=87?= Date: Fri, 16 Dec 2022 12:40:11 +0100 Subject: [PATCH] Rewrite event loop tests as integration tests This also removes the duplication of the xk6-timers module, and uses it directly now that it's an experimental built-in module. Although, shouldn't these be xk6-timers tests rather than event loop ones? We have plenty of tests that indirectly test the event loop, and we could always add much simpler ones that don't involve the timers module. See https://github.com/grafana/k6/issues/2459 --- .../eventloop/eventloop_test.go | 219 ------------------ .../testmodules/events/events.go | 157 ------------- .../testmodules/events/events.js | 49 ---- .../testmodules/events/events_test.go | 43 ---- cmd/tests/eventloop_test.go | 132 +++++++++++ 5 files changed, 132 insertions(+), 468 deletions(-) delete mode 100644 cmd/integration_tests/eventloop/eventloop_test.go delete mode 100644 cmd/integration_tests/testmodules/events/events.go delete mode 100644 cmd/integration_tests/testmodules/events/events.js delete mode 100644 cmd/integration_tests/testmodules/events/events_test.go create mode 100644 cmd/tests/eventloop_test.go diff --git a/cmd/integration_tests/eventloop/eventloop_test.go b/cmd/integration_tests/eventloop/eventloop_test.go deleted file mode 100644 index 9e8e554b68c6..000000000000 --- a/cmd/integration_tests/eventloop/eventloop_test.go +++ /dev/null @@ -1,219 +0,0 @@ -package tests - -import ( - "context" - "io/ioutil" - "net/url" - "testing" - "time" - - "github.com/sirupsen/logrus" - "github.com/stretchr/testify/require" - "go.k6.io/k6/cmd/integration_tests/testmodules/events" - "go.k6.io/k6/core/local" - "go.k6.io/k6/js" - "go.k6.io/k6/js/modules" - "go.k6.io/k6/lib" - "go.k6.io/k6/lib/executor" - "go.k6.io/k6/lib/testutils" - "go.k6.io/k6/lib/types" - "go.k6.io/k6/loader" - "go.k6.io/k6/metrics" - "gopkg.in/guregu/null.v3" -) - -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() - piState := &lib.TestPreInitState{ - Logger: logger, - Registry: registry, - BuiltinMetrics: metrics.RegisterBuiltinMetrics(registry), - } - - script = []byte("import {setTimeout} from 'k6/x/events';\n" + string(script)) - runner, err := js.New(piState, &loader.SourceData{URL: &url.URL{Path: "/script.js"}, Data: script}, nil) - require.NoError(t, err) - - ctx, cancel := context.WithCancel(context.Background()) - defer cancel() - newOpts, err := executor.DeriveScenariosFromShortcuts(lib.Options{ - MetricSamplesBufferSize: null.NewInt(200, false), - TeardownTimeout: types.NullDurationFrom(time.Second), - SetupTimeout: types.NullDurationFrom(time.Second), - }.Apply(runner.GetOptions()), nil) - require.NoError(t, err) - require.Empty(t, newOpts.Validate()) - require.NoError(t, runner.SetOptions(newOpts)) - - testState := &lib.TestRunState{ - TestPreInitState: piState, - Options: newOpts, - Runner: runner, - RunTags: piState.Registry.RootTagSet().WithTagsFromMap(newOpts.RunTags), - } - - execScheduler, err := local.NewExecutionScheduler(testState) - require.NoError(t, err) - - samples := make(chan metrics.SampleContainer, newOpts.MetricSamplesBufferSize.Int64) - go func() { - for { - select { - case <-samples: - case <-ctx.Done(): - return - } - } - }() - - require.NoError(t, execScheduler.Init(ctx, samples)) - - errCh := make(chan error, 1) - go func() { errCh <- execScheduler.Run(ctx, ctx, samples) }() - - select { - case err := <-errCh: - testHandle(ctx, runner, err, logHook) - case <-time.After(10 * time.Second): - t.Fatal("timed out") - } -} - -func init() { - modules.Register("k6/x/events", events.New()) -} - -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{ - "setTimeout 1 was stopped because the VU iteration was interrupted", - "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{ - "setTimeout 1 was stopped because the VU iteration was interrupted", - "just error\n\tat /script.js:13:4(15)\n", "1", - }, msgs) - }) -} diff --git a/cmd/integration_tests/testmodules/events/events.go b/cmd/integration_tests/testmodules/events/events.go deleted file mode 100644 index e34c087c083f..000000000000 --- a/cmd/integration_tests/testmodules/events/events.go +++ /dev/null @@ -1,157 +0,0 @@ -// Package events implements setInterval, setTimeout and co. Not to be used, mostly for testing purposes -package events - -import ( - "sync" - "sync/atomic" - "time" - - "github.com/dop251/goja" - "go.k6.io/k6/js/modules" -) - -// RootModule is the global module instance that will create module -// instances for each VU. -type RootModule struct{} - -// Events represents an instance of the events module. -type Events struct { - vu modules.VU - - timerStopCounter uint32 - timerStopsLock sync.Mutex - timerStops map[uint32]chan struct{} -} - -var ( - _ modules.Module = &RootModule{} - _ modules.Instance = &Events{} -) - -// New returns a pointer to a new RootModule instance. -func New() *RootModule { - return &RootModule{} -} - -// NewModuleInstance implements the modules.Module interface to return -// a new instance for each VU. -func (*RootModule) NewModuleInstance(vu modules.VU) modules.Instance { - return &Events{ - vu: vu, - timerStops: make(map[uint32]chan struct{}), - } -} - -// Exports returns the exports of the k6 module. -func (e *Events) Exports() modules.Exports { - return modules.Exports{ - Named: map[string]interface{}{ - "setTimeout": e.setTimeout, - "clearTimeout": e.clearTimeout, - "setInterval": e.setInterval, - "clearInterval": e.clearInterval, - }, - } -} - -func noop() error { return nil } - -func (e *Events) getTimerStopCh() (uint32, chan struct{}) { - id := atomic.AddUint32(&e.timerStopCounter, 1) - ch := make(chan struct{}) - e.timerStopsLock.Lock() - e.timerStops[id] = ch - e.timerStopsLock.Unlock() - return id, ch -} - -func (e *Events) stopTimerCh(id uint32) bool { //nolint:unparam - e.timerStopsLock.Lock() - defer e.timerStopsLock.Unlock() - ch, ok := e.timerStops[id] - if !ok { - return false - } - delete(e.timerStops, id) - close(ch) - return true -} - -func (e *Events) call(callback goja.Callable, args []goja.Value) error { - // TODO: investigate, not sure GlobalObject() is always the correct value for `this`? - _, err := callback(e.vu.Runtime().GlobalObject(), args...) - return err -} - -func (e *Events) setTimeout(callback goja.Callable, delay float64, args ...goja.Value) uint32 { - runOnLoop := e.vu.RegisterCallback() - id, stopCh := e.getTimerStopCh() - - if delay < 0 { - delay = 0 - } - - go func() { - timer := time.NewTimer(time.Duration(delay * float64(time.Millisecond))) - defer func() { - e.stopTimerCh(id) - if !timer.Stop() { - <-timer.C - } - }() - - select { - case <-timer.C: - runOnLoop(func() error { - return e.call(callback, args) - }) - case <-stopCh: - runOnLoop(noop) - case <-e.vu.Context().Done(): - e.vu.State().Logger.Warnf("setTimeout %d was stopped because the VU iteration was interrupted", id) - runOnLoop(noop) - } - }() - - return id -} - -func (e *Events) clearTimeout(id uint32) { - e.stopTimerCh(id) -} - -func (e *Events) setInterval(callback goja.Callable, delay float64, args ...goja.Value) uint32 { - runOnLoop := e.vu.RegisterCallback() - id, stopCh := e.getTimerStopCh() - - go func() { - ticker := time.NewTicker(time.Duration(delay * float64(time.Millisecond))) - defer func() { - e.stopTimerCh(id) - ticker.Stop() - }() - - for { - select { - case <-ticker.C: - runOnLoop(func() error { - runOnLoop = e.vu.RegisterCallback() - return e.call(callback, args) - }) - case <-stopCh: - runOnLoop(noop) - return - case <-e.vu.Context().Done(): - e.vu.State().Logger.Warnf("setInterval %d was stopped because the VU iteration was interrupted", id) - runOnLoop(noop) - return - } - } - }() - - return id -} - -func (e *Events) clearInterval(id uint32) { - e.stopTimerCh(id) -} diff --git a/cmd/integration_tests/testmodules/events/events.js b/cmd/integration_tests/testmodules/events/events.js deleted file mode 100644 index 7e5c98fd6e60..000000000000 --- a/cmd/integration_tests/testmodules/events/events.js +++ /dev/null @@ -1,49 +0,0 @@ -import exec from 'k6/execution'; -import { setTimeout, clearTimeout, setInterval, clearInterval } from 'k6/events' - - -export let options = { - scenarios: { - 'foo': { - executor: 'constant-vus', - vus: 1, - duration: '3.8s', - gracefulStop: '0s', - } - } -}; - -function debug(arg) { - let t = String((new Date()) - exec.scenario.startTime).padStart(6, ' ') - console.log(`[${t}ms, iter=${exec.scenario.iterationInTest}] ${arg}`); -} - -export default function () { - debug('default start'); - - let tickCount = 1; - let f0 = (arg) => { - debug(`${arg} ${tickCount++}`); - } - let t0 = setInterval(f0, 500, 'tick') - - let f1 = (arg) => { - debug(arg); - clearInterval(t0); - } - let t1 = setTimeout(f1, 2000, 'third'); - - let t2 = setTimeout(debug, 1500, 'never happening'); - - let f3 = (arg) => { - debug(arg); - clearTimeout(t2); - setTimeout(debug, 600, 'second'); - } - let t3 = setTimeout(f3, 1000, 'first'); - - debug('default end'); - if (exec.scenario.iterationInTest == 1) { - debug(`expected last iter, the interval ID is ${t0}, we also expect timer ${t1} to be interrupted`) - } -} diff --git a/cmd/integration_tests/testmodules/events/events_test.go b/cmd/integration_tests/testmodules/events/events_test.go deleted file mode 100644 index bdcb57cbf3d9..000000000000 --- a/cmd/integration_tests/testmodules/events/events_test.go +++ /dev/null @@ -1,43 +0,0 @@ -package events - -import ( - "context" - "testing" - - "github.com/dop251/goja" - "github.com/stretchr/testify/require" - "go.k6.io/k6/js/common" - "go.k6.io/k6/js/eventloop" - "go.k6.io/k6/js/modulestest" -) - -func TestSetTimeout(t *testing.T) { - t.Parallel() - rt := goja.New() - vu := &modulestest.VU{ - RuntimeField: rt, - InitEnvField: &common.InitEnvironment{}, - CtxField: context.Background(), - StateField: nil, - } - - m, ok := New().NewModuleInstance(vu).(*Events) - require.True(t, ok) - var log []string - require.NoError(t, rt.Set("events", m.Exports().Named)) - require.NoError(t, rt.Set("print", func(s string) { log = append(log, s) })) - loop := eventloop.New(vu) - vu.RegisterCallbackField = loop.RegisterCallback - - err := loop.Start(func() error { - _, err := vu.Runtime().RunString(` - events.setTimeout(()=> { - print("in setTimeout") - }) - print("outside setTimeout") - `) - return err - }) - require.NoError(t, err) - require.Equal(t, []string{"outside setTimeout", "in setTimeout"}, log) -} diff --git a/cmd/tests/eventloop_test.go b/cmd/tests/eventloop_test.go new file mode 100644 index 000000000000..09d0bde2e7eb --- /dev/null +++ b/cmd/tests/eventloop_test.go @@ -0,0 +1,132 @@ +package tests + +import ( + "bytes" + "testing" + + "github.com/stretchr/testify/require" + "go.k6.io/k6/cmd" + "go.k6.io/k6/cmd/state" +) + +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(logLines []string) { + 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", + }, logLines) + }) +} + +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(logLines []string) { + require.Equal(t, []string{ + "setTimeout 1 was stopped because the VU iteration was interrupted", + "second", + }, logLines) + }) +} + +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(logLines []string) { + require.Equal(t, []string{ + "setTimeout 1 was stopped because the VU iteration was interrupted", + "just error\n\tat file:///-:13:4(15)\n", "1", + }, logLines) + }) +} + +func eventLoopTest(t *testing.T, script []byte, testHandle func(logLines []string)) { + ts := state.NewGlobalTestState(t) + ts.CmdArgs = []string{"k6", "--quiet", "run", "-"} + ts.Stdin = bytes.NewBuffer( + append([]byte("import { setTimeout } from 'k6/experimental/timers';\n"), script...), + ) + + cmd.Execute(ts.GlobalState) + + testHandle(ts.LoggerHook.Lines()) +}