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

[WIP] Add InterruptedIterations metric #1769

Closed
wants to merge 10 commits into from
13 changes: 10 additions & 3 deletions api/v1/status_routes_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -103,10 +103,17 @@ func TestPatchStatus(t *testing.T) {
require.NoError(t, err)
engine, err := core.NewEngine(execScheduler, options, logger)
require.NoError(t, err)
ctx, cancel := context.WithTimeout(context.Background(), 2*time.Second)
defer cancel()
run, _, err := engine.Init(ctx, ctx)
globalCtx, globalCancel := context.WithTimeout(context.Background(), 2*time.Second)
runCtx, runCancel := context.WithCancel(globalCtx)
run, waitFn, err := engine.Init(globalCtx, runCtx)
require.NoError(t, err)
defer func() {
runCancel()
// Wait for metrics processing to finish
time.Sleep(100 * time.Millisecond)
globalCancel()
waitFn()
}()

go func() { _ = run() }()
// wait for the executor to initialize to avoid a potential data race below
Expand Down
8 changes: 8 additions & 0 deletions core/engine.go
Original file line number Diff line number Diff line change
Expand Up @@ -288,6 +288,14 @@ func (e *Engine) processMetrics(globalCtx context.Context, processMetricsAfterRu
if !e.NoThresholds {
e.processThresholds()
}
if iim, ok := e.Metrics[metrics.InterruptedIterations.Name]; ok {
Copy link
Contributor Author

Choose a reason for hiding this comment

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

This map lookup is racy according to the current TestSentReceivedMetrics failure. So I guess we'll need to rethink or abandon this hack...

Copy link
Contributor

Choose a reason for hiding this comment

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

I am pretty sure this breaks any output as you are only emitting the 1 to them ...

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I guess it depends on how this metric is agreggated. If their system allows it they could factor it in with the iterations metric and get a percentage that way, which is kind of what we're doing here for the summary.

It makes no sense to me to emit the 0 value of this metric considering it's equivalent to iterations, and it would add a considerable amount of output data and affect the performance. A 5s/5VU test with an empty default and no sleep does 2115298 iterations on my machine and generates a 1.5 GB JSON file when emitting the 0 value. The same test without it manages to do 3203002 iterations and generate a 1.9 GB JSON file, but this is because it's doing ~50% more iterations.

Considering we already have complaints about outputting too much data and interest in #1321, I think we should rather work on #1321 before we consider adding another default metric.

Though we should probably rethink duplicating iterations...

How about instead of a new metric, we simply reused iterations and added an interrupted: "<cause>" tag to it? If the tag is omitted it's a complete iteration and if it's set then it was interrupted with the specific cause. WYT?

Copy link
Contributor

Choose a reason for hiding this comment

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

I agree with prioritizing #1321, but that will actually probably require quite the refactoring, IMO even for an MVP.
The reusage of the iterations was discussed (I think) and we decided against it based on the fact the primary usage for this will be to check that a percentage of the iterations aren't actually interrupted, which with the current thresholds isn't possible if the metric isn't rate... so :(.

I think that maybe we should just make another PR with the changes that are in this PR (the test fixes and the lib.Exception) and merge that to both have them and make this PR easier to rebase and then work on #1321 so we can merge this then.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

The reusage of the iterations was discussed (I think) and we decided against it based on the fact the primary usage for this will be to check that a percentage of the iterations aren't actually interrupted, which with the current thresholds isn't possible if the metric isn't rate

Then maybe that should be a feature? I'll see what I can do.

if sink, ok := iim.Sink.(*stats.RateSink); ok {
// HACK: This is done to avoid emitting a 0 value for this
// metric on each iteration but still get a correct
// calculation in the summary.
sink.Total += int64(e.executionState.GetFullIterationCount())
}
}
processMetricsAfterRun <- struct{}{}

case sc := <-e.Samples:
Expand Down
24 changes: 15 additions & 9 deletions core/engine_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -88,6 +88,8 @@ func newTestEngine( //nolint:golint
if runCancel != nil {
runCancel()
}
// Wait for metrics processing to finish
time.Sleep(100 * time.Millisecond)
globalCancel()
waitFn()
}
Expand Down Expand Up @@ -791,21 +793,24 @@ func TestMetricsEmission(t *testing.T) {
}

testCases := []struct {
method string
minIterDuration string
defaultBody string
expCount, expIters float64
method string
minIterDuration string
defaultBody string
expCount, expIters, expInterrupted float64
}{
// Since emission of Iterations happens before the minIterationDuration
// sleep is done, we expect to receive metrics for all executions of
// the `default` function, despite of the lower overall duration setting.
{"minIterationDuration", `"300ms"`, "testCounter.add(1);", 16.0, 16.0},
{"minIterationDuration", `"300ms"`, "testCounter.add(1);", 16.0, 16.0, 4.0},
// With the manual sleep method and no minIterationDuration, the last
// `default` execution will be cutoff by the duration setting, so only
// 3 sets of metrics are expected.
{"sleepBeforeCounterAdd", "null", "sleep(0.3); testCounter.add(1); ", 12.0, 12.0},
// The counter should be sent, but the last iteration will be incomplete
{"sleepAfterCounterAdd", "null", "testCounter.add(1); sleep(0.3); ", 16.0, 12.0},
{"sleepBeforeCounterAdd", "null", "sleep(0.3); testCounter.add(1); ", 12.0, 12.0, 4.0},
// The counter should be sent, but the last iteration will be incomplete.
{"sleepAfterCounterAdd", "null", "testCounter.add(1); sleep(0.3); ", 16.0, 12.0, 4.0},
// All iterations should fail, but only 12 will be counted as complete.
{"fail", "null", "sleep(0.3); fail('test'); ", 0, 12.0, 16.0},
{"throw", "null", "sleep(0.3); throw 'test'; ", 0, 12.0, 16.0},
}

for _, tc := range testCases {
Expand All @@ -817,7 +822,7 @@ func TestMetricsEmission(t *testing.T) {
runner, err := js.New(
testutils.NewLogger(t),
&loader.SourceData{URL: &url.URL{Path: "/script.js"}, Data: []byte(fmt.Sprintf(`
import { sleep } from "k6";
import { fail, sleep } from "k6";
import { Counter } from "k6/metrics";

let testCounter = new Counter("testcounter");
Expand Down Expand Up @@ -860,6 +865,7 @@ func TestMetricsEmission(t *testing.T) {

assert.Equal(t, tc.expIters, getMetricSum(collector, metrics.Iterations.Name))
assert.Equal(t, tc.expCount, getMetricSum(collector, "testcounter"))
assert.Equal(t, tc.expInterrupted, getMetricSum(collector, metrics.InterruptedIterations.Name))
})
}
}
Expand Down
36 changes: 18 additions & 18 deletions js/common/bridge_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -348,7 +348,7 @@ func TestBind(t *testing.T) {
}},
{"Error", bridgeTestErrorType{}, func(t *testing.T, obj interface{}, rt *goja.Runtime) {
_, err := RunString(rt, `obj.error()`)
assert.Contains(t, err.Error(), "GoError: error")
assert.Contains(t, err.Error(), "error")
Copy link
Contributor

Choose a reason for hiding this comment

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

I think this can be moved to another PR that we can merge today and make this ... more focused ;)

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Sure, will do.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

See #1775.

}},
{"JSValue", bridgeTestJSValueType{}, func(t *testing.T, obj interface{}, rt *goja.Runtime) {
v, err := RunString(rt, `obj.func(1234)`)
Expand All @@ -358,7 +358,7 @@ func TestBind(t *testing.T) {
}},
{"JSValueError", bridgeTestJSValueErrorType{}, func(t *testing.T, obj interface{}, rt *goja.Runtime) {
_, err := RunString(rt, `obj.func()`)
assert.Contains(t, err.Error(), "GoError: missing argument")
assert.Contains(t, err.Error(), "missing argument")

t.Run("Valid", func(t *testing.T) {
v, err := RunString(rt, `obj.func(1234)`)
Expand All @@ -369,7 +369,7 @@ func TestBind(t *testing.T) {
}},
{"JSValueContext", bridgeTestJSValueContextType{}, func(t *testing.T, obj interface{}, rt *goja.Runtime) {
_, err := RunString(rt, `obj.func()`)
assert.Contains(t, err.Error(), "GoError: func() can only be called from within default()")
assert.Contains(t, err.Error(), "func() can only be called from within default()")

t.Run("Context", func(t *testing.T) {
*ctxPtr = context.Background()
Expand All @@ -383,14 +383,14 @@ func TestBind(t *testing.T) {
}},
{"JSValueContextError", bridgeTestJSValueContextErrorType{}, func(t *testing.T, obj interface{}, rt *goja.Runtime) {
_, err := RunString(rt, `obj.func()`)
assert.Contains(t, err.Error(), "GoError: func() can only be called from within default()")
assert.Contains(t, err.Error(), "func() can only be called from within default()")

t.Run("Context", func(t *testing.T) {
*ctxPtr = context.Background()
defer func() { *ctxPtr = nil }()

_, err := RunString(rt, `obj.func()`)
assert.Contains(t, err.Error(), "GoError: missing argument")
assert.Contains(t, err.Error(), "missing argument")

t.Run("Valid", func(t *testing.T) {
v, err := RunString(rt, `obj.func(1234)`)
Expand All @@ -408,7 +408,7 @@ func TestBind(t *testing.T) {
}},
{"NativeFunctionError", bridgeTestNativeFunctionErrorType{}, func(t *testing.T, obj interface{}, rt *goja.Runtime) {
_, err := RunString(rt, `obj.func()`)
assert.Contains(t, err.Error(), "GoError: missing argument")
assert.Contains(t, err.Error(), "missing argument")

t.Run("Valid", func(t *testing.T) {
v, err := RunString(rt, `obj.func(1234)`)
Expand All @@ -419,7 +419,7 @@ func TestBind(t *testing.T) {
}},
{"NativeFunctionContext", bridgeTestNativeFunctionContextType{}, func(t *testing.T, obj interface{}, rt *goja.Runtime) {
_, err := RunString(rt, `obj.func()`)
assert.Contains(t, err.Error(), "GoError: func() can only be called from within default()")
assert.Contains(t, err.Error(), "func() can only be called from within default()")

t.Run("Context", func(t *testing.T) {
*ctxPtr = context.Background()
Expand All @@ -433,14 +433,14 @@ func TestBind(t *testing.T) {
}},
{"NativeFunctionContextError", bridgeTestNativeFunctionContextErrorType{}, func(t *testing.T, obj interface{}, rt *goja.Runtime) {
_, err := RunString(rt, `obj.func()`)
assert.Contains(t, err.Error(), "GoError: func() can only be called from within default()")
assert.Contains(t, err.Error(), "func() can only be called from within default()")

t.Run("Context", func(t *testing.T) {
*ctxPtr = context.Background()
defer func() { *ctxPtr = nil }()

_, err := RunString(rt, `obj.func()`)
assert.Contains(t, err.Error(), "GoError: missing argument")
assert.Contains(t, err.Error(), "missing argument")

t.Run("Valid", func(t *testing.T) {
v, err := RunString(rt, `obj.func(1234)`)
Expand All @@ -464,7 +464,7 @@ func TestBind(t *testing.T) {

t.Run("Negative", func(t *testing.T) {
_, err := RunString(rt, `obj.addWithError(0, -1)`)
assert.Contains(t, err.Error(), "GoError: answer is negative")
assert.Contains(t, err.Error(), "answer is negative")
})
}},
{"AddWithError", bridgeTestAddWithErrorType{}, func(t *testing.T, obj interface{}, rt *goja.Runtime) {
Expand All @@ -475,12 +475,12 @@ func TestBind(t *testing.T) {

t.Run("Negative", func(t *testing.T) {
_, err := RunString(rt, `obj.addWithError(0, -1)`)
assert.Contains(t, err.Error(), "GoError: answer is negative")
assert.Contains(t, err.Error(), "answer is negative")
})
}},
{"Context", bridgeTestContextType{}, func(t *testing.T, obj interface{}, rt *goja.Runtime) {
_, err := RunString(rt, `obj.context()`)
assert.Contains(t, err.Error(), "GoError: context() can only be called from within default()")
assert.Contains(t, err.Error(), "context() can only be called from within default()")

t.Run("Valid", func(t *testing.T) {
*ctxPtr = context.Background()
Expand All @@ -492,7 +492,7 @@ func TestBind(t *testing.T) {
}},
{"ContextAdd", bridgeTestContextAddType{}, func(t *testing.T, obj interface{}, rt *goja.Runtime) {
_, err := RunString(rt, `obj.contextAdd(1, 2)`)
assert.Contains(t, err.Error(), "GoError: contextAdd() can only be called from within default()")
assert.Contains(t, err.Error(), "contextAdd() can only be called from within default()")

t.Run("Valid", func(t *testing.T) {
*ctxPtr = context.Background()
Expand All @@ -506,7 +506,7 @@ func TestBind(t *testing.T) {
}},
{"ContextAddWithError", bridgeTestContextAddWithErrorType{}, func(t *testing.T, obj interface{}, rt *goja.Runtime) {
_, err := RunString(rt, `obj.contextAddWithError(1, 2)`)
assert.Contains(t, err.Error(), "GoError: contextAddWithError() can only be called from within default()")
assert.Contains(t, err.Error(), "contextAddWithError() can only be called from within default()")

t.Run("Valid", func(t *testing.T) {
*ctxPtr = context.Background()
Expand All @@ -519,7 +519,7 @@ func TestBind(t *testing.T) {

t.Run("Negative", func(t *testing.T) {
_, err := RunString(rt, `obj.contextAddWithError(0, -1)`)
assert.Contains(t, err.Error(), "GoError: answer is negative")
assert.Contains(t, err.Error(), "answer is negative")
})
})
}},
Expand All @@ -529,7 +529,7 @@ func TestBind(t *testing.T) {
case bridgeTestContextInjectType:
assert.EqualError(t, err, "TypeError: Object has no member 'contextInject' at <eval>:1:18(3)")
case *bridgeTestContextInjectType:
assert.Contains(t, err.Error(), "GoError: contextInject() can only be called from within default()")
assert.Contains(t, err.Error(), "contextInject() can only be called from within default()")
assert.Equal(t, nil, impl.ctx)

t.Run("Valid", func(t *testing.T) {
Expand Down Expand Up @@ -588,7 +588,7 @@ func TestBind(t *testing.T) {
}},
{"SumWithContext", bridgeTestSumWithContextType{}, func(t *testing.T, obj interface{}, rt *goja.Runtime) {
_, err := RunString(rt, `obj.sumWithContext(1, 2)`)
assert.Contains(t, err.Error(), "GoError: sumWithContext() can only be called from within default()")
assert.Contains(t, err.Error(), "sumWithContext() can only be called from within default()")

t.Run("Valid", func(t *testing.T) {
*ctxPtr = context.Background()
Expand Down Expand Up @@ -626,7 +626,7 @@ func TestBind(t *testing.T) {
}},
{"SumWithContextAndError", bridgeTestSumWithContextAndErrorType{}, func(t *testing.T, obj interface{}, rt *goja.Runtime) {
_, err := RunString(rt, `obj.sumWithContextAndError(1, 2)`)
assert.Contains(t, err.Error(), "GoError: sumWithContextAndError() can only be called from within default()")
assert.Contains(t, err.Error(), "sumWithContextAndError() can only be called from within default()")

t.Run("Valid", func(t *testing.T) {
*ctxPtr = context.Background()
Expand Down
2 changes: 1 addition & 1 deletion js/common/util.go
Original file line number Diff line number Diff line change
Expand Up @@ -34,5 +34,5 @@ func Throw(rt *goja.Runtime, err error) {
if e, ok := err.(*goja.Exception); ok {
panic(e)
}
panic(rt.NewGoError(err))
panic(rt.ToValue(err))
}
4 changes: 2 additions & 2 deletions js/common/util_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -33,12 +33,12 @@ func TestThrow(t *testing.T) {
fn1, ok := goja.AssertFunction(rt.ToValue(func() { Throw(rt, errors.New("aaaa")) }))
if assert.True(t, ok, "fn1 is invalid") {
_, err := fn1(goja.Undefined())
assert.EqualError(t, err, "GoError: aaaa")
assert.EqualError(t, err, "aaaa")

fn2, ok := goja.AssertFunction(rt.ToValue(func() { Throw(rt, err) }))
if assert.True(t, ok, "fn1 is invalid") {
_, err := fn2(goja.Undefined())
assert.EqualError(t, err, "GoError: aaaa")
assert.EqualError(t, err, "aaaa")
}
}
}
6 changes: 3 additions & 3 deletions js/initcontext_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -52,7 +52,7 @@ func TestInitContextRequire(t *testing.T) {
t.Run("Modules", func(t *testing.T) {
t.Run("Nonexistent", func(t *testing.T) {
_, err := getSimpleBundle(t, "/script.js", `import "k6/NONEXISTENT";`)
assert.Contains(t, err.Error(), "GoError: unknown module: k6/NONEXISTENT")
assert.Contains(t, err.Error(), "unknown module: k6/NONEXISTENT")
})

t.Run("k6", func(t *testing.T) {
Expand Down Expand Up @@ -317,15 +317,15 @@ func TestInitContextOpen(t *testing.T) {
t.Run("Nonexistent", func(t *testing.T) {
path := filepath.FromSlash("/nonexistent.txt")
_, err := getSimpleBundle(t, "/script.js", `open("/nonexistent.txt"); export default function() {}`)
assert.Contains(t, err.Error(), fmt.Sprintf("GoError: open %s: file does not exist", path))
assert.Contains(t, err.Error(), fmt.Sprintf("open %s: file does not exist", path))
})

t.Run("Directory", func(t *testing.T) {
path := filepath.FromSlash("/some/dir")
fs := afero.NewMemMapFs()
assert.NoError(t, fs.MkdirAll(path, 0o755))
_, err := getSimpleBundle(t, "/script.js", `open("/some/dir"); export default function() {}`, fs)
assert.Contains(t, err.Error(), fmt.Sprintf("GoError: open() can't be used with directories, path: %q", path))
assert.Contains(t, err.Error(), fmt.Sprintf("open() can't be used with directories, path: %q", path))
})
}

Expand Down
6 changes: 3 additions & 3 deletions js/modules/k6/crypto/crypto_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -316,7 +316,7 @@ func TestOutputEncoding(t *testing.T) {
hasher.update("hello world");
hasher.digest("someInvalidEncoding");
`)
assert.Contains(t, err.Error(), "GoError: Invalid output encoding: someInvalidEncoding")
assert.Contains(t, err.Error(), "Invalid output encoding: someInvalidEncoding")
})
}

Expand Down Expand Up @@ -395,7 +395,7 @@ func TestHMac(t *testing.T) {
throw new Error("Hex encoding mismatch: " + resultHex);
}`)

assert.Contains(t, err.Error(), "GoError: Invalid algorithm: "+algorithm)
assert.Contains(t, err.Error(), "Invalid algorithm: "+algorithm)
})

t.Run(algorithm+" wrapper: invalid", func(t *testing.T) {
Expand All @@ -405,7 +405,7 @@ func TestHMac(t *testing.T) {
throw new Error("Hex encoding mismatch: " + resultHex);
}`)

assert.Contains(t, err.Error(), "GoError: Invalid algorithm: "+algorithm)
assert.Contains(t, err.Error(), "Invalid algorithm: "+algorithm)
})
}
}
Expand Down
4 changes: 2 additions & 2 deletions js/modules/k6/crypto/x509/x509_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -150,7 +150,7 @@ func TestParse(t *testing.T) {
_, err := common.RunString(rt, `
x509.parse("bad-certificate");`)
assert.Contains(
t, err.Error(), "GoError: failed to decode certificate PEM file")
t, err.Error(), "failed to decode certificate PEM file")
})

t.Run("ParseFailure", func(t *testing.T) {
Expand All @@ -160,7 +160,7 @@ func TestParse(t *testing.T) {
if assert.Error(t, err) {
assert.Contains(t,
err.Error(),
"GoError: failed to parse certificate",
"failed to parse certificate",
)
}
})
Expand Down
8 changes: 4 additions & 4 deletions js/modules/k6/http/response_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -198,13 +198,13 @@ func TestResponse(t *testing.T) {
t.Run("Invalid", func(t *testing.T) {
_, err := common.RunString(rt, sr(`http.request("GET", "HTTPBIN_URL/html").json();`))
//nolint:lll
assert.Contains(t, err.Error(), "GoError: cannot parse json due to an error at line 1, character 2 , error: invalid character '<' looking for beginning of value")
assert.Contains(t, err.Error(), "cannot parse json due to an error at line 1, character 2 , error: invalid character '<' looking for beginning of value")
})

t.Run("Invalid", func(t *testing.T) {
_, err := common.RunString(rt, sr(`http.request("GET", "HTTPBIN_URL/invalidjson").json();`))
//nolint:lll
assert.Contains(t, err.Error(), "GoError: cannot parse json due to an error at line 3, character 9 , error: invalid character 'e' in literal true (expecting 'r')")
assert.Contains(t, err.Error(), "cannot parse json due to an error at line 3, character 9 , error: invalid character 'e' in literal true (expecting 'r')")
})
})
t.Run("JsonSelector", func(t *testing.T) {
Expand Down Expand Up @@ -327,7 +327,7 @@ func TestResponse(t *testing.T) {
if (res.status != 200) { throw new Error("wrong status: " + res.status); }
res.submitForm({ formSelector: "#doesNotExist" })
`))
assert.Contains(t, err.Error(), sr("GoError: no form found for selector '#doesNotExist' in response 'HTTPBIN_URL/forms/post'"))
assert.Contains(t, err.Error(), sr("no form found for selector '#doesNotExist' in response 'HTTPBIN_URL/forms/post'"))
})

t.Run("withGetMethod", func(t *testing.T) {
Expand Down Expand Up @@ -378,7 +378,7 @@ func TestResponse(t *testing.T) {
if (res.status != 200) { throw new Error("wrong status: " + res.status); }
res = res.clickLink({ selector: 'a#doesNotExist' })
`))
assert.Contains(t, err.Error(), sr("GoError: no element found for selector 'a#doesNotExist' in response 'HTTPBIN_URL/links/10/0'"))
assert.Contains(t, err.Error(), sr("no element found for selector 'a#doesNotExist' in response 'HTTPBIN_URL/links/10/0'"))
})

t.Run("withRequestParams", func(t *testing.T) {
Expand Down
Loading