TestVUIntegrationMetrics is broken, make it into an integration test

[na--]

This test:

k6/js/runner_test.go

Lines 824 to 885 in 4e4e5b1

	func TestVUIntegrationMetrics(t *testing.T) {
	t.Parallel()
	r1, err := getSimpleRunner(t, "/script.js", `
	var group = require("k6").group;
	var Trend = require("k6/metrics").Trend;
	var myMetric = new Trend("my_metric");
	exports.default = function() { myMetric.add(5); }
	`)
	require.NoError(t, err)
	registry := metrics.NewRegistry()
	builtinMetrics := metrics.RegisterBuiltinMetrics(registry)
	r2, err := NewFromArchive(
	&lib.TestPreInitState{
	Logger: testutils.NewLogger(t),
	BuiltinMetrics: builtinMetrics,
	Registry: registry,
	}, r1.MakeArchive())
	require.NoError(t, err)
	testdata := map[string]*Runner{"Source": r1, "Archive": r2}
	for name, r := range testdata {
	r := r
	t.Run(name, func(t *testing.T) {
	t.Parallel()
	samples := make(chan metrics.SampleContainer, 100)
	defer close(samples)
	vu, err := r.newVU(1, 1, samples)
	require.NoError(t, err)
	ctx, cancel := context.WithCancel(context.Background())
	defer cancel()
	activeVU := vu.Activate(&lib.VUActivationParams{RunContext: ctx})
	err = activeVU.RunOnce()
	require.NoError(t, err)
	sampleCount := 0
	for i, sampleC := range metrics.GetBufferedSamples(samples) {
	for j, s := range sampleC.GetSamples() {
	sampleCount++
	switch i + j {
	case 0:
	assert.Equal(t, 5.0, s.Value)
	assert.Equal(t, "my_metric", s.Metric.Name)
	assert.Equal(t, metrics.Trend, s.Metric.Type)
	case 1:
	assert.Equal(t, 0.0, s.Value)
	assert.Equal(t, builtinMetrics.DataSent, s.Metric, "`data_sent` sample is before `data_received` and `iteration_duration`")
	case 2:
	assert.Equal(t, 0.0, s.Value)
	assert.Equal(t, builtinMetrics.DataReceived, s.Metric, "`data_received` sample is after `data_received`")
	case 3:
	assert.Equal(t, builtinMetrics.IterationDuration, s.Metric, "`iteration-duration` sample is after `data_received`")
	case 4:
	assert.Equal(t, builtinMetrics.Iterations, s.Metric, "`iterations` sample is after `iteration_duration`")
	assert.Equal(t, float64(1), s.Value)
	}
	}
	}
	assert.Equal(t, sampleCount, 5)
	})
	}
	}

Has been quite flaky recently, with failures like this:

2022-12-05T12:08:57.8321834Z time="2022-12-05T12:08:18Z" level=warning msg="Request Failed" error="Get \"http://httpbin.local:41655/html\": lookup httpbin.local: Temporary failure in name resolution"
2022-12-05T12:08:57.8322437Z time="2022-12-05T12:08:18Z" level=info msg=1 source=console
2022-12-05T12:08:57.8323053Z time="2022-12-05T12:08:19Z" level=warning msg="There were unknown fields in the options exported in the script" error="json: unknown field \"myOption\""
2022-12-05T12:08:57.8323733Z time="2022-12-05T12:08:21Z" level=warning msg="There were unknown fields in the options exported in the script" error="json: unknown field \"someField\""
2022-12-05T12:08:57.8325351Z time="2022-12-05T12:08:21Z" level=warning msg="Couldn't load source map for file:///script.js" error="The moduleSpecifier \"file:///test.min.js.map\" couldn't be found on local disk. Make sure that you've specified the right path to the file. If you're running k6 using the Docker image make sure you have mounted the local directory (-v /local/path/:/inside/docker/path) containing your script and modules so that they're accessible by k6 from inside of the container, see https://k6.io/docs/using-k6/modules#using-local-modules-with-docker."
2022-12-05T12:08:57.8327422Z time="2022-12-05T12:08:21Z" level=warning msg="Couldn't load source map for file:///script.js" error="The moduleSpecifier \"file:///test.min.js.map\" couldn't be found on local disk. Make sure that you've specified the right path to the file. If you're running k6 using the Docker image make sure you have mounted the local directory (-v /local/path/:/inside/docker/path) containing your script and modules so that they're accessible by k6 from inside of the container, see https://k6.io/docs/using-k6/modules#using-local-modules-with-docker."
2022-12-05T12:08:57.8329105Z time="2022-12-05T12:08:21Z" level=warning msg="The moduleSpecifier \"buffer\" has no scheme but we will try to resolve it as remote module. This will be deprecated in the future and all remote modules will need to explicitly use \"https\" as scheme."
2022-12-05T12:08:57.8330144Z time="2022-12-05T12:08:21Z" level=warning msg="The moduleSpecifier \"buffer\" has no scheme but we will try to resolve it as remote module. This will be deprecated in the future and all remote modules will need to explicitly use \"https\" as scheme."
2022-12-05T12:08:57.8330804Z time="2022-12-05T12:08:31Z" level=info msg="{\"text\":\"nativeObject\"}" source=console
2022-12-05T12:08:57.8331241Z time="2022-12-05T12:08:32Z" level=info msg=yes source=console
2022-12-05T12:08:57.8331615Z time="2022-12-05T12:08:32Z" level=info msg=yes source=console
2022-12-05T12:08:57.8332000Z time="2022-12-05T12:08:32Z" level=info msg=yes source=console
2022-12-05T12:08:57.8332384Z time="2022-12-05T12:08:32Z" level=info msg=yes source=console
2022-12-05T12:08:57.8332965Z time="2022-12-05T12:08:33Z" level=warning msg="Request Failed" error="Get \"http://127.0.0.1:1\": dial tcp 127.0.0.1:1: connect: connection refused"
2022-12-05T12:08:57.8333657Z time="2022-12-05T12:08:33Z" level=warning msg="Request Failed" error="Get \"http://127.0.0.1:1\": dial tcp 127.0.0.1:1: connect: connection refused"
2022-12-05T12:08:57.8334122Z --- FAIL: TestVUIntegrationMetrics (0.00s)
2022-12-05T12:08:57.8334581Z     --- FAIL: TestVUIntegrationMetrics/Source (0.01s)
2022-12-05T12:08:57.8335251Z         runner_test.go:870: 
2022-12-05T12:08:57.8335818Z             	Error Trace:	/home/runner/work/k6/k6/js/runner_test.go:870
2022-12-05T12:08:57.8336210Z             	Error:      	Not equal: 
2022-12-05T12:08:57.8339382Z             	            	expected: &metrics.Metric{registry:(*metrics.Registry)(0xc002a5a630), Name:"data_sent", Type:0, Contains:2, Tainted:null.Bool{NullBool:sql.NullBool{Bool:false, Valid:false}}, Thresholds:metrics.Thresholds{Thresholds:[]*metrics.Threshold(nil), Abort:false, sinked:map[string]float64(nil)}, Submetrics:[]*metrics.Submetric(nil), Sub:(*metrics.Submetric)(nil), Sink:(*metrics.CounterSink)(0xc000ea2740), Observed:false}
2022-12-05T12:08:57.8343420Z             	            	actual  : &metrics.Metric{registry:(*metrics.Registry)(0xc000cee840), Name:"data_sent", Type:0, Contains:2, Tainted:null.Bool{NullBool:sql.NullBool{Bool:false, Valid:false}}, Thresholds:metrics.Thresholds{Thresholds:[]*metrics.Threshold(nil), Abort:false, sinked:map[string]float64(nil)}, Submetrics:[]*metrics.Submetric(nil), Sub:(*metrics.Submetric)(nil), Sink:(*metrics.CounterSink)(0xc002412ce0), Observed:false}
2022-12-05T12:08:57.8344179Z             	            	
2022-12-05T12:08:57.8344528Z             	            	Diff:
2022-12-05T12:08:57.8344968Z             	Test:       	TestVUIntegrationMetrics/Source
2022-12-05T12:08:57.8345931Z             	Messages:   	`data_sent` sample is before `data_received` and `iteration_duration`
2022-12-05T12:08:57.8346474Z time="2022-12-05T12:08:34Z" level=info msg=1 source=console
2022-12-05T12:08:57.8347384Z time="2022-12-05T12:08:35Z" level=warning msg="The moduleSpecifier \"buffer\" has no scheme but we will try to resolve it as remote module. This will be deprecated in the future and all remote modules will need to explicitly use \"https\" as scheme."
2022-12-05T12:08:57.8348498Z time="2022-12-05T12:08:35Z" level=warning msg="The moduleSpecifier \"buffer\" has no scheme but we will try to resolve it as remote module. This will be deprecated in the future and all remote modules will need to explicitly use \"https\" as scheme."
2022-12-05T12:08:57.8349223Z time="2022-12-05T12:08:40Z" level=info msg="{\"text\":\"test1\"}" source=console
2022-12-05T12:08:57.8349744Z time="2022-12-05T12:08:40Z" level=info msg="{\"text\":\"test3\"}" source=console
2022-12-05T12:08:57.8350239Z time="2022-12-05T12:08:40Z" level=info msg="{\"text\":\"test2\"}" source=console
2022-12-05T12:08:57.8350775Z 2022/12/05 12:08:44 http: TLS handshake error from [::1]:35952: tls: no cipher suite supported by both client and server
2022-12-05T12:08:57.8351401Z 2022/12/05 12:08:44 http: TLS handshake error from [::1]:36000: tls: no cipher suite supported by both client and server
2022-12-05T12:08:57.8351871Z 2022/12/05 12:08:44 http: TLS handshake error from [::1]:36012: EOF
2022-12-05T12:08:57.8352265Z 2022/12/05 12:08:44 http: TLS handshake error from [::1]:36022: EOF
2022-12-05T12:08:57.8352709Z 2022/12/05 12:08:44 http: TLS handshake error from [::1]:36830: remote error: tls: bad certificate
2022-12-05T12:08:57.8353198Z 2022/12/05 12:08:45 http: TLS handshake error from [::1]:36834: remote error: tls: bad certificate
2022-12-05T12:08:57.8353664Z 2022/12/05 12:08:45 http: TLS handshake error from [::1]:36844: remote error: tls: bad certificate
2022-12-05T12:08:57.8354134Z 2022/12/05 12:08:45 http: TLS handshake error from [::1]:36862: remote error: tls: bad certificate
2022-12-05T12:08:57.8354466Z FAIL
2022-12-05T12:08:57.8354698Z FAIL	go.k6.io/k6/js	51.415s

Looking at how it validates things and how ancient it is, it is a good candidate for moving it away from the js/ package and either making it an integration test or changing an already existing integration test to test the same things. Just for fun, I did some archeology, and the test has existed for more than 5 years roughly in its current form, so it's time for it to retire 😅

[na--]

hmm actually, this test is probably not just flaky, it seems like it's buggy 😕 notice the different metric registry addresses here:

expected: &metrics.Metric{registry:(*metrics.Registry)(0xc002a5a630), Name:"data_sent", Type:0, Contains:2, Tainted:null.Bool{NullBool:sql.NullBool{Bool:false, Valid:false}}, Thresholds:metrics.Thresholds{Thresholds:[]*metrics.Threshold(nil), Abort:false, sinked:map[string]float64(nil)}, Submetrics:[]*metrics.Submetric(nil), Sub:(*metrics.Submetric)(nil), Sink:(*metrics.CounterSink)(0xc000ea2740), Observed:false}
actual  : &metrics.Metric{registry:(*metrics.Registry)(0xc000cee840), Name:"data_sent", Type:0, Contains:2, Tainted:null.Bool{NullBool:sql.NullBool{Bool:false, Valid:false}}, Thresholds:metrics.Thresholds{Thresholds:[]*metrics.Threshold(nil), Abort:false, sinked:map[string]float64(nil)}, Submetrics:[]*metrics.Submetric(nil), Sub:(*metrics.Submetric)(nil), Sink:(*metrics.CounterSink)(0xc002412ce0), Observed:false}

This shouldn't happen after #2594, all of the metric.Sample values should use the same metric.Registry, to have the same atlas root node and be comparable. At this point I am actually confused how this test even worked at all, given the extra metrics.NewRegistry() call... 😅

An integration test would be a good place for its replacement, especially since we don't have any integration tests that do k6 archive and then run the archive afterwards.

[mstoykov]

I have fixed the thing that is reported here in #3012 . But IMO the underlying reason why Equals returns false in this case is still not fixed and I don't know what it is or where it comes from.

Hopefully after the linked fix it will actually present itself 🤞

[olegbespalov]

For the record. After an internal discussion, we decided to clean a milestone since the issue was jumping between milestones without completion.

Once we determine which milestone it lands, we set the right one.