Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Treat go panics as an interrupt error #2453

Merged
merged 5 commits into from
Mar 29, 2022
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 .github/workflows/xk6-tests/xk6-js-test/jstest.go
Original file line number Diff line number Diff line change
Expand Up @@ -48,7 +48,7 @@ func (j *JSTest) Exports() modules.Exports {
func (j JSTest) Foo(arg float64) (bool, error) {
state := j.vu.State()
if state == nil {
return false, fmt.Errorf("the VU State is not avaialble in the init context")
return false, fmt.Errorf("the VU State is not available in the init context")
}

ctx := j.vu.Context()
Expand Down
100 changes: 100 additions & 0 deletions cmd/panic_integration_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,100 @@
package cmd

// TODO: convert this into the integration tests, once https://github.com/grafana/k6/issues/2459 will be done

import (
"path/filepath"
"testing"

"github.com/sirupsen/logrus"
"github.com/spf13/afero"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
"go.k6.io/k6/errext/exitcodes"
"go.k6.io/k6/js/modules"
"go.k6.io/k6/lib/testutils"
)

// alarmist is a mock module that do a panic
type alarmist struct {
vu modules.VU
}

var _ modules.Module = &alarmist{}

func (a *alarmist) NewModuleInstance(vu modules.VU) modules.Instance {
return &alarmist{
vu: vu,
}
}

func (a *alarmist) Exports() modules.Exports {
return modules.Exports{
Named: map[string]interface{}{
"panic": a.panic,
},
}
}

func (a *alarmist) panic(s string) {
panic(s)
}

func init() {
modules.Register("k6/x/alarmist", new(alarmist))
}

func TestRunScriptPanicsErrorsAndAbort(t *testing.T) {
t.Parallel()

testCases := []struct {
caseName, testScript, expectedLogMessage string
}{
{
caseName: "panic in the VU context",
testScript: `
import { panic } from 'k6/x/alarmist';
export default function() {
panic('hey');
console.log('lorem ipsum');
}
`,
expectedLogMessage: "a panic occurred during JS execution: hey",
},
{
caseName: "panic in the init context",
testScript: `
import { panic } from 'k6/x/alarmist';
panic('hey');
export default function() {
console.log('lorem ipsum');
}
`,
expectedLogMessage: "a panic occurred during JS execution: hey",
},
}

for _, tc := range testCases {
tc := tc
name := tc.caseName

t.Run(name, func(t *testing.T) {
t.Parallel()

testFilename := "script.js"
testState := newGlobalTestState(t)
require.NoError(t, afero.WriteFile(testState.fs, filepath.Join(testState.cwd, testFilename), []byte(tc.testScript), 0o644))
testState.args = []string{"k6", "run", testFilename}

testState.expectedExitCode = int(exitcodes.ScriptAborted)
newRootCommand(testState.globalState).execute()

logs := testState.loggerHook.Drain()

assert.True(t, testutils.LogContains(logs, logrus.ErrorLevel, tc.expectedLogMessage))
olegbespalov marked this conversation as resolved.
Show resolved Hide resolved
assert.False(t, testutils.LogContains(logs, logrus.InfoLevel, "lorem ipsum"))
})
}
}
11 changes: 7 additions & 4 deletions js/bundle.go
Original file line number Diff line number Diff line change
Expand Up @@ -299,7 +299,7 @@ func (b *Bundle) Instantiate(

// Instantiates the bundle into an existing runtime. Not public because it also messes with a bunch
// of other things, will potentially thrash data and makes a mess in it if the operation fails.
func (b *Bundle) instantiate(logger logrus.FieldLogger, rt *goja.Runtime, init *InitContext, vuID uint64) error {
func (b *Bundle) instantiate(logger logrus.FieldLogger, rt *goja.Runtime, init *InitContext, vuID uint64) (err error) {
rt.SetFieldNameMapper(common.FieldNameMapper{})
rt.SetRandSource(common.NewRandSource())

Expand Down Expand Up @@ -333,10 +333,13 @@ func (b *Bundle) instantiate(logger logrus.FieldLogger, rt *goja.Runtime, init *
init.moduleVUImpl.ctx = context.Background()
unbindInit := b.setInitGlobals(rt, init)
init.moduleVUImpl.eventLoop = eventloop.New(init.moduleVUImpl)
err := init.moduleVUImpl.eventLoop.Start(func() error {
_, err := rt.RunProgram(b.Program)
return err
err = common.RunWithPanicCatching(logger, rt, func() error {
return init.moduleVUImpl.eventLoop.Start(func() error {
_, errRun := rt.RunProgram(b.Program)
return errRun
})
})

if err != nil {
var exception *goja.Exception
if errors.As(err, &exception) {
Expand Down
24 changes: 24 additions & 0 deletions js/common/util.go
Original file line number Diff line number Diff line change
Expand Up @@ -24,8 +24,10 @@ import (
"bytes"
"fmt"
"io"
"runtime/debug"

"github.com/dop251/goja"
"github.com/sirupsen/logrus"
)

// Throw a JS error; avoids re-wrapping GoErrors.
Expand Down Expand Up @@ -79,3 +81,25 @@ func ToString(data interface{}) (string, error) {
return "", fmt.Errorf("invalid type %T, expected string, []byte or ArrayBuffer", data)
}
}

// RunWithPanicCatching catches panic and converts into an InterruptError error that should abort a script
func RunWithPanicCatching(logger logrus.FieldLogger, rt *goja.Runtime, fn func() error) (err error) {
defer func() {
if r := recover(); r != nil {
gojaStack := rt.CaptureCallStack(20, nil)

err = &InterruptError{Reason: fmt.Sprintf("a panic occurred during JS execution: %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)
}
logger.Error("panic: ", r, "\n", string(debug.Stack()), "\nGoja stack:\n", b.String())
}
}()

return fn()
}
2 changes: 1 addition & 1 deletion js/modules/k6/execution/execution_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -186,7 +186,7 @@ func TestVUTags(t *testing.T) {
})
}

func TestAbortTest(t *testing.T) { //nolint: tparallel
func TestAbortTest(t *testing.T) { //nolint:tparallel
Copy link
Contributor

Choose a reason for hiding this comment

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

nit: I kind of prefer to not have unrelated changes in unrelated files like that ;)

Copy link
Contributor Author

@olegbespalov olegbespalov Mar 25, 2022

Choose a reason for hiding this comment

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

It sounds like a personal preference 🤔 Let me try to provide my two cents on why I'm doing this and continue doing it.

It's a common/best practice to leave the place cleaner than before. For example, this is a comment for a machine (linter) comment, and it doesn't require space in between. The same things I usually do when spotting any grammar issues. Such changes itself is super-minor and don't deserve a separated PR, so that's why I prefer not postpone fixing.

Does that make sense? Will it help if I'll do this in a separate commit?

t.Parallel()

var (
Expand Down
26 changes: 5 additions & 21 deletions js/runner.go
Original file line number Diff line number Diff line change
Expand Up @@ -21,7 +21,6 @@
package js

import (
"bytes"
"context"
"crypto/tls"
"encoding/json"
Expand All @@ -32,7 +31,6 @@ import (
"net/http"
"net/http/cookiejar"
"os"
"runtime/debug"
"strconv"
"strings"
"sync"
Expand Down Expand Up @@ -794,25 +792,11 @@ func (u *VU) runFn(
if u.moduleVUImpl.eventLoop == nil {
u.moduleVUImpl.eventLoop = eventloop.New(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
err = common.RunWithPanicCatching(u.state.Logger, u.Runtime, func() error {
return u.moduleVUImpl.eventLoop.Start(func() (err error) {
v, err = fn(goja.Undefined(), args...) // Actually run the JS script
return err
})
})

select {
Expand Down
10 changes: 5 additions & 5 deletions js/runner_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -1941,7 +1941,7 @@ func TestVUPanic(t *testing.T) {
vu.(*ActiveVU).Console.logger = logger.WithField("source", "console")
err = vu.RunOnce()
require.Error(t, err)
assert.Contains(t, err.Error(), "a panic occurred in VU code but was caught: here we panic")
assert.Contains(t, err.Error(), "a panic occurred during JS execution: here we panic")
entries := hook.Drain()
require.Len(t, entries, 1)
assert.Equal(t, logrus.ErrorLevel, entries[0].Level)
Expand Down Expand Up @@ -2048,16 +2048,16 @@ func TestComplicatedFileImportsForGRPC(t *testing.T) {
fs := afero.NewMemMapFs()
protoFile, err := ioutil.ReadFile("../vendor/google.golang.org/grpc/test/grpc_testing/test.proto")
require.NoError(t, err)
require.NoError(t, afero.WriteFile(fs, "/path/to/service.proto", protoFile, 0644))
require.NoError(t, afero.WriteFile(fs, "/path/to/service.proto", protoFile, 0o644))
require.NoError(t, afero.WriteFile(fs, "/path/to/same-dir.proto", []byte(
`syntax = "proto3";package whatever;import "service.proto";`,
), 0644))
), 0o644))
require.NoError(t, afero.WriteFile(fs, "/path/subdir.proto", []byte(
`syntax = "proto3";package whatever;import "to/service.proto";`,
), 0644))
), 0o644))
require.NoError(t, afero.WriteFile(fs, "/path/to/abs.proto", []byte(
`syntax = "proto3";package whatever;import "/path/to/service.proto";`,
), 0644))
), 0o644))

grpcTestCase := func(expInitErr, expVUErr bool, cwd, loadCode string) multiFileTestCase {
script := tb.Replacer.Replace(fmt.Sprintf(`
Expand Down