Skip to content
This repository has been archived by the owner on Oct 16, 2024. It is now read-only.

Don't block the event loop on context end and related fixes #9

Merged
merged 1 commit into from
Jan 12, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@ go 1.20
require (
github.com/dop251/goja v0.0.0-20231027120936-b396bb4c349d
github.com/mstoykov/k6-taskqueue-lib v0.1.0
github.com/sirupsen/logrus v1.9.3
github.com/stretchr/testify v1.8.4
go.k6.io/k6 v0.48.0
)
Expand All @@ -29,7 +30,6 @@ require (
github.com/onsi/gomega v1.20.2 // indirect
github.com/pmezard/go-difflib v1.0.0 // indirect
github.com/serenize/snaker v0.0.0-20201027110005-a7ad2135616e // indirect
github.com/sirupsen/logrus v1.9.3 // indirect
github.com/spf13/afero v1.1.2 // indirect
go.opentelemetry.io/otel v1.19.0 // indirect
go.opentelemetry.io/otel/exporters/otlp/otlptrace v1.19.0 // indirect
Expand Down
33 changes: 25 additions & 8 deletions timers/timers.go
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@ import (
"time"

"github.com/mstoykov/k6-taskqueue-lib/taskqueue"
"github.com/sirupsen/logrus"

"github.com/dop251/goja"
"go.k6.io/k6/js/modules"
Expand Down Expand Up @@ -212,10 +213,21 @@ func (e *Timers) closeTaskQueue() {
// so that we do not execute it twice
e.taskQueueCh = nil

// wait for this to happen so we don't need to hit the event loop again
// instead this just closes the queue
ch <- struct{}{}
<-ch
select {
case ch <- struct{}{}:
// wait for this to happen so we don't need to hit the event loop again
// instead this just closes the queue
<-ch
case <-e.vu.Context().Done(): // still shortcircuit if the context is done as we might block otherwise
}
Comment on lines +216 to +222
Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is the original fix

}

// logger is helper to get a logger either from the state or the initenv
func (e *Timers) logger() logrus.FieldLogger {
if state := e.vu.State(); state != nil {
return state.Logger
}
return e.vu.InitEnv().Logger
}

func (e *Timers) setupTaskQueueCloserOnIterationEnd() {
Expand All @@ -229,23 +241,28 @@ func (e *Timers) setupTaskQueueCloserOnIterationEnd() {
// lets report timers won't be executed and clean the fields for the next execution
// we need to do this on the event loop as we don't want to have a race
q.Queue(func() error {
logger := e.vu.State().Logger
logger := e.logger()
for _, timer := range e.queue.queue {
logger.Warnf("%s %d was stopped because the VU iteration was interrupted", timer.name, timer.id)
logger.Warnf("%s %d was stopped because the VU iteration was interrupted",
timer.name, timer.id)
}

// TODO: use `clear` when we only support go 1.21 and above
e.timers = make(map[uint64]time.Time)
e.queue.stopTimer()
e.queue = new(timerQueue)
e.taskQueue = nil
return nil
})
q.Close()
case <-ch:
e.timers = make(map[uint64]time.Time)
e.queue.stopTimer()
e.queue = new(timerQueue)
e.taskQueue = nil
q.Close()
close(ch)
}
e.queue.stopTimer()
q.Close()
}()
}

Expand Down
52 changes: 52 additions & 0 deletions timers/timers_test.go
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
package timers

import (
"context"
"testing"
"time"

Expand Down Expand Up @@ -138,3 +139,54 @@ func TestSetIntervalOrder(t *testing.T) {
log = log[:0]
}
}

func TestSetTimeoutContextCancel(t *testing.T) {
t.Parallel()
runtime := modulestest.NewRuntime(t)
err := runtime.SetupModuleSystem(map[string]any{"k6/x/timers": New()}, nil, nil)
require.NoError(t, err)

rt := runtime.VU.Runtime()
var log []string
interruptChannel := make(chan struct{})
require.NoError(t, rt.Set("print", func(s string) { log = append(log, s) }))
require.NoError(t, rt.Set("interrupt", func() {
select {
case interruptChannel <- struct{}{}:
default:
}
}))

_, err = rt.RunString(`globalThis.setTimeout = require("k6/x/timers").setTimeout;`)
require.NoError(t, err)

for i := 0; i < 2000; i++ {
ctx, cancel := context.WithCancel(context.Background())
runtime.CancelContext = cancel
runtime.VU.CtxField = ctx
runtime.VU.RuntimeField.ClearInterrupt()
const interruptMsg = "definitely an interrupt"
go func() {
<-interruptChannel
time.Sleep(time.Millisecond)
runtime.CancelContext()
runtime.VU.RuntimeField.Interrupt(interruptMsg)
}()
_, err = runtime.RunOnEventLoop(`
(async () => {
let poll = async (resolve, reject) => {
await (async () => 5);
setTimeout(poll, 1, resolve, reject);
interrupt();
}
setTimeout(async () => {
await new Promise(poll)
}, 0)
})()
`)
Comment on lines +176 to +186
Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Not certain which parts make more of a difference ... or less, but this is the smallest I got to actually reproduce the issue without needing the whole k6.

if err != nil {
require.ErrorContains(t, err, interruptMsg)
}
require.Empty(t, log)
}
}
Loading