The short answer is that, unfortunately, you currently can’t… This problem will be partially solved by Improve execution information in scripts · Issue #1320 · grafana/k6 · GitHub, parts of which we hope to release in the upcoming k6 v0.32.0 (ETA May 3rd). However, depending on your use case and requirements, even that might be enough.
The root of the issue is that the __VU
global constant is very restricted. It represents the unique global sequential number for the current virtual user. However, since v0.27.0, k6 initializes VUs in parallel, 1 VU for every CPU core on your machine. So, if you have 4 CPU cores on your machine, 4 VUs will be concurrently initialized, and if VU #3 is initialized a millisecond faster than VU #1, your pool of workers (i.e. VUs) will be [VU3, VU1, VU2, VU4, ...]
.
Moreover, when you have multiple scenarios, k6 reuses VUs between non-overlapping scenarios, to reduce resource usage. Some scenarios may also allocate new VUs mid-test. And, most importantly, the duration of every script iteration varies, so even if VUs were perfectly ordered by __VU
at the start, after a few script iterations the order will completely disintegrate.
So, yeah, __VU
cannot be relied on to be sequential, and we’ll solve some of these issues in Improve execution information in scripts · Issue #1320 · grafana/k6 · GitHub by introducing new APIs that would be able to return the sequential VU and iteration number in a single scenario. Depending on your use case, that might or might not be enough.
Here’s a modified version of your example script that demonstrates these issues:
import { sleep } from 'k6';
export let options = {
stages: [
{ duration: '30s', target: 10 }
],
};
console.log(`Init phase of VU ${__VU}`);
sleep(3);
export default function printVuser() {
console.log(`Running VU: ${__VU} ITER: ${__ITER}`);
sleep(35);
}
console.log(`Init phase of VU ${__VU} done`);
I’ve made the VU initialization take 3 seconds with sleep(3)
, to make the init concurrency apparent. And the sleep(35)
makes it so that a single script iteration is longer than the whole script duration, so every VU is going to execute only a single iteration for the whole script. If I run this script on my 4-core machine, I’d get a log like this:
INFO[0003] Init phase of VU 1 source=console
INFO[0003] Init phase of VU 3 source=console
INFO[0003] Init phase of VU 4 source=console
INFO[0003] Init phase of VU 2 source=console
INFO[0006] Init phase of VU 1 done source=console
INFO[0006] Init phase of VU 4 done source=console
INFO[0006] Init phase of VU 3 done source=console
INFO[0006] Init phase of VU 2 done source=console
INFO[0006] Init phase of VU 5 source=console
INFO[0006] Init phase of VU 6 source=console
INFO[0006] Init phase of VU 7 source=console
INFO[0006] Init phase of VU 8 source=console
INFO[0009] Init phase of VU 8 done source=console
INFO[0009] Init phase of VU 7 done source=console
INFO[0009] Init phase of VU 5 done source=console
INFO[0009] Init phase of VU 6 done source=console
INFO[0009] Init phase of VU 9 source=console
INFO[0009] Init phase of VU 10 source=console
INFO[0012] Init phase of VU 9 done source=console
INFO[0012] Init phase of VU 10 done source=console
INFO[0012] Init phase of VU 0 source=console
INFO[0015] Init phase of VU 0 done source=console
INFO[0015] Running VU: 1 ITER: 0 source=console
INFO[0018] Running VU: 4 ITER: 0 source=console
INFO[0022] Running VU: 3 ITER: 0 source=console
INFO[0025] Running VU: 2 ITER: 0 source=console
INFO[0028] Running VU: 8 ITER: 0 source=console
INFO[0032] Running VU: 7 ITER: 0 source=console
INFO[0035] Running VU: 5 ITER: 0 source=console
INFO[0038] Running VU: 6 ITER: 0 source=console
INFO[0042] Running VU: 10 ITER: 0 source=console
INFO[0075] Init phase of VU 0 source=console
INFO[0078] Init phase of VU 0 done source=console
Ignoring the Init phase of VU 0
logs (that’s for setup()
and teardown()
), the timestamp between the INFO[]
brackets makes it apparent that VU initialization happens 4 VUs at a time, and because of the concurrency, VUs may be initialized out of order.
If you pin k6 to use only a single CPU core, by running GOMAXPROCS=1 k6 run script.js
, you’d get what you expected, albeit with a great performance penalty:
INFO[0003] Init phase of VU 1 source=console
INFO[0006] Init phase of VU 1 done source=console
INFO[0006] Init phase of VU 2 source=console
INFO[0009] Init phase of VU 2 done source=console
INFO[0009] Init phase of VU 3 source=console
INFO[0012] Init phase of VU 3 done source=console
INFO[0012] Init phase of VU 4 source=console
INFO[0015] Init phase of VU 4 done source=console
INFO[0015] Init phase of VU 5 source=console
INFO[0018] Init phase of VU 5 done source=console
INFO[0018] Init phase of VU 6 source=console
INFO[0021] Init phase of VU 6 done source=console
INFO[0021] Init phase of VU 7 source=console
INFO[0024] Init phase of VU 7 done source=console
INFO[0024] Init phase of VU 8 source=console
INFO[0027] Init phase of VU 8 done source=console
INFO[0027] Init phase of VU 9 source=console
INFO[0030] Init phase of VU 9 done source=console
INFO[0030] Init phase of VU 10 source=console
INFO[0033] Init phase of VU 10 done source=console
INFO[0033] Init phase of VU 0 source=console
INFO[0036] Init phase of VU 0 done source=console
INFO[0036] Running VU: 1 ITER: 0 source=console
INFO[0039] Running VU: 2 ITER: 0 source=console
INFO[0043] Running VU: 3 ITER: 0 source=console
INFO[0046] Running VU: 4 ITER: 0 source=console
INFO[0049] Running VU: 5 ITER: 0 source=console
INFO[0053] Running VU: 6 ITER: 0 source=console
INFO[0056] Running VU: 7 ITER: 0 source=console
INFO[0059] Running VU: 8 ITER: 0 source=console
INFO[0063] Running VU: 9 ITER: 0 source=console
INFO[0096] Init phase of VU 0 source=console
INFO[0099] Init phase of VU 0 done source=console