Concurrent map writes when incrementing a property from setup()'s return

[SaberStrat]

I'm getting a race condition when I'm using a "global counter" by incrementing an object property in the VU code that I pass from setup().
I realize that such a construct was prone to a race condition. But I wanted a global counter so that I could iterate through test data that I needed to be unique for every VU. I know one can use a construct by defining a variable from (__VU,__ITER), but a global counter was something I knew from JMeter, so I wanted to use that. Now it bit me :).

script.js

import {sleep} from 'k6';

export let options = {
	vus: 20,
	duration: "300s"
};

export function setup(){
	return {globalIter: 0};
}

export default function(data){
	data.globalIter++;
	console.log(`global iterator: ${data.globalIter}`);
	sleep(1);
}

Run:

$ k6 run script.js &> racecondition.txt

racecondition.txt:

          /\      |‾‾|  /‾‾/  /‾/   
     /\  /  \     |  |_/  /  / /   
    /  \/    \    |      |  /  ‾‾\  
   /          \   |  |‾\  \ | (_) | 
  / __________ \  |__|  \__\ \___/ .io

    init [----------------------------------------------------------] runner
    init [----------------------------------------------------------] options
    init [----------------------------------------------------------] executor
    init [----------------------------------------------------------]   engine
    init [----------------------------------------------------------]   collector
    init [----------------------------------------------------------]   server
  execution: local
     output: -
     script: /home/user/script.js

    duration: 5m0s, iterations: -
         vus: 20,   max: 20

    init [----------------------------------------------------------] starting
time="2018-07-06T09:27:01+02:00" level=info msg="global iterator: 1"
time="2018-07-06T09:27:01+02:00" level=info msg="global iterator: 3"
time="2018-07-06T09:27:01+02:00" level=info msg="global iterator: 3"
time="2018-07-06T09:27:01+02:00" level=info msg="global iterator: 5"
time="2018-07-06T09:27:01+02:00" level=info msg="global iterator: 7"
time="2018-07-06T09:27:01+02:00" level=info msg="global iterator: 7"
time="2018-07-06T09:27:01+02:00" level=info msg="global iterator: 8"
time="2018-07-06T09:27:01+02:00" level=info msg="global iterator: 9"
time="2018-07-06T09:27:01+02:00" level=info msg="global iterator: 4"
time="2018-07-06T09:27:01+02:00" level=info msg="global iterator: 1"
time="2018-07-06T09:27:01+02:00" level=info msg="global iterator: 10"
.
.
.
time="2018-07-06T09:27:58+02:00" level=info msg="global iterator: 1137"
time="2018-07-06T09:27:58+02:00" level=info msg="global iterator: 1138"
time="2018-07-06T09:27:58+02:00" level=info msg="global iterator: 1139"
fatal error: concurrent map writes

goroutine 87 [running]:
runtime.throw(0xd423f9, 0x15)
	/usr/local/Cellar/go/1.9.3/libexec/src/runtime/panic.go:605 +0x95 fp=0xc4235b5820 sp=0xc4235b5800 pc=0x42ba95
runtime.mapassign_faststr(0xc24fa0, 0xc4246bccf0, 0xc4209b8cc1, 0xa, 0x473)
	/usr/local/Cellar/go/1.9.3/libexec/src/runtime/hashmap_fast.go:861 +0x4da fp=0xc4235b58a0 sp=0xc4235b5820 pc=0x40d09a
github.com/loadimpact/k6/vendor/github.com/dop251/goja.(*objectGoMapSimple).putStr(0xc423e491d0, 0xc4209b8cc1, 0xa, 0x1298be0, 0xc421387aa0, 0x1)
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/vendor/github.com/dop251/goja/object_gomap.go:76 +0x8f fp=0xc4235b5900 sp=0xc4235b58a0 pc=0x826cbf
github.com/loadimpact/k6/vendor/github.com/dop251/goja.setPropStrict.exec(0xc4209b8cc1, 0xa, 0xc4227a7d40)
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/vendor/github.com/dop251/goja/vm.go:1060 +0xe7 fp=0xc4235b5958 sp=0xc4235b5900 pc=0x851e87
github.com/loadimpact/k6/vendor/github.com/dop251/goja.(*setPropStrict).exec(0xc4217d83f0, 0xc4227a7d40)
	<autogenerated>:1 +0x4f fp=0xc4235b5980 sp=0xc4235b5958 pc=0x8784cf
github.com/loadimpact/k6/vendor/github.com/dop251/goja.(*vm).run(0xc4227a7d40)
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/vendor/github.com/dop251/goja/vm.go:288 +0x51 fp=0xc4235b59c0 sp=0xc4235b5980 pc=0x84cd81
github.com/loadimpact/k6/vendor/github.com/dop251/goja.(*funcObject).Call(0xc423fabc80, 0x1298d20, 0x14493a0, 0xc42135c970, 0x1, 0x1, 0x7fdd1f439290, 0xc420020600)
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/vendor/github.com/dop251/goja/func.go:130 +0x3c8 fp=0xc4235b5a80 sp=0xc4235b59c0 pc=0x81fe88
github.com/loadimpact/k6/vendor/github.com/dop251/goja.(*funcObject).Call-fm(0x1298d20, 0x14493a0, 0xc42135c970, 0x1, 0x1, 0x42a369, 0xc42251e0a0)
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/vendor/github.com/dop251/goja/builtin_function.go:120 +0x51 fp=0xc4235b5ad0 sp=0xc4235b5a80 pc=0x8699c1
github.com/loadimpact/k6/vendor/github.com/dop251/goja.AssertFunction.func1.2()
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/vendor/github.com/dop251/goja/runtime.go:1412 +0xb6 fp=0xc4235b5b48 sp=0xc4235b5ad0 pc=0x861896
github.com/loadimpact/k6/vendor/github.com/dop251/goja.(*vm).try(0xc4227a7d40, 0xc4235b5c00, 0x0)
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/vendor/github.com/dop251/goja/vm.go:370 +0x119 fp=0xc4235b5bd8 sp=0xc4235b5b48 pc=0x84d409
github.com/loadimpact/k6/vendor/github.com/dop251/goja.AssertFunction.func1(0x1298d20, 0x14493a0, 0xc42135c970, 0x1, 0x1, 0x0, 0x0, 0x0, 0x0)
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/vendor/github.com/dop251/goja/runtime.go:1411 +0x12e fp=0xc4235b5c50 sp=0xc4235b5bd8 pc=0x861a0e
github.com/loadimpact/k6/js.(*VU).runFn(0xc421fa3680, 0x1292340, 0xc4245d7b00, 0xc4232cbdc0, 0xc42135c970, 0x1, 0x1, 0xc425503d38, 0xc42001a538, 0xc42552dd40, ...)
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/js/runner.go:372 +0x38c fp=0xc4235b5d80 sp=0xc4235b5c50 pc=0xb2605c
github.com/loadimpact/k6/js.(*VU).RunOnce(0xc421fa3680, 0x1292340, 0xc4245d7b00, 0x0, 0x1, 0x1, 0x0, 0x0)
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/js/runner.go:336 +0x1ab fp=0xc4235b5e20 sp=0xc4235b5d80 pc=0xb25aab
github.com/loadimpact/k6/core/local.(*vuHandle).run(0xc424150440, 0xc420074af0, 0xc42001a540, 0xc42001a4e0)
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/core/local/local.go:74 +0x1cc fp=0xc4235b5f90 sp=0xc4235b5e20 pc=0xb3e94c
github.com/loadimpact/k6/core/local.(*Executor).scale.func1(0xc424150440, 0xc421903d40, 0xc42001a540, 0xc42001a4e0)
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/core/local/local.go:360 +0x4d fp=0xc4235b5fc0 sp=0xc4235b5f90 pc=0xb4245d
runtime.goexit()
	/usr/local/Cellar/go/1.9.3/libexec/src/runtime/asm_amd64.s:2337 +0x1 fp=0xc4235b5fc8 sp=0xc4235b5fc0 pc=0x45a3a1
created by github.com/loadimpact/k6/core/local.(*Executor).scale
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/core/local/local.go:359 +0x35f

goroutine 1 [select]:
github.com/loadimpact/k6/cmd.glob..func11(0x141f1e0, 0xc42319e4b0, 0x1, 0x1, 0x0, 0x0)
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/cmd/run.go:341 +0x25c4
github.com/loadimpact/k6/vendor/github.com/spf13/cobra.(*Command).execute(0x141f1e0, 0xc42319e480, 0x1, 0x1, 0x141f1e0, 0xc42319e480)
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/vendor/github.com/spf13/cobra/command.go:698 +0x47a
github.com/loadimpact/k6/vendor/github.com/spf13/cobra.(*Command).ExecuteC(0x141efc0, 0x52, 0xc422a68180, 0xc420790750)
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/vendor/github.com/spf13/cobra/command.go:783 +0x30e
github.com/loadimpact/k6/vendor/github.com/spf13/cobra.(*Command).Execute(0x141efc0, 0x4046a4, 0xc42001a0b8)
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/vendor/github.com/spf13/cobra/command.go:736 +0x2b
github.com/loadimpact/k6/cmd.Execute()
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/cmd/root.go:84 +0x31
main.main()
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/main.go:28 +0x20

goroutine 5 [syscall]:
os/signal.signal_recv(0x0)
	/usr/local/Cellar/go/1.9.3/libexec/src/runtime/sigqueue.go:131 +0xa6
os/signal.loop()
	/usr/local/Cellar/go/1.9.3/libexec/src/os/signal/signal_unix.go:22 +0x22
created by os/signal.init.0
	/usr/local/Cellar/go/1.9.3/libexec/src/os/signal/signal_unix.go:28 +0x41

goroutine 18 [select]:
github.com/loadimpact/k6/core.(*Engine).runMetricsEmission(0xc42389b680, 0x1292340, 0xc423d72040)
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/core/engine.go:253 +0x126
github.com/loadimpact/k6/core.(*Engine).Run.func2(0xc42389b680, 0x1292340, 0xc423d72040, 0xc421154040)
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/core/engine.go:160 +0x43
created by github.com/loadimpact/k6/core.(*Engine).Run
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/core/engine.go:159 +0x7eb

goroutine 11 [IO wait]:
internal/poll.runtime_pollWait(0x7fdd1f81ef70, 0x72, 0xffffffffffffffff)
	/usr/local/Cellar/go/1.9.3/libexec/src/runtime/netpoll.go:173 +0x57
internal/poll.(*pollDesc).wait(0xc424564518, 0x72, 0xc4252eab00, 0x0, 0x0)
	/usr/local/Cellar/go/1.9.3/libexec/src/internal/poll/fd_poll_runtime.go:85 +0xae
internal/poll.(*pollDesc).waitRead(0xc424564518, 0xffffffffffffff00, 0x0, 0x0)
	/usr/local/Cellar/go/1.9.3/libexec/src/internal/poll/fd_poll_runtime.go:90 +0x3d
internal/poll.(*FD).Accept(0xc424564500, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
	/usr/local/Cellar/go/1.9.3/libexec/src/internal/poll/fd_unix.go:335 +0x1e2
net.(*netFD).accept(0xc424564500, 0x7fdd1f87a6c8, 0x0, 0xd68e30)
	/usr/local/Cellar/go/1.9.3/libexec/src/net/fd_unix.go:238 +0x42
net.(*TCPListener).accept(0xc42000c0a8, 0xc4252ead98, 0x4111b8, 0x30)
	/usr/local/Cellar/go/1.9.3/libexec/src/net/tcpsock_posix.go:136 +0x2e
net.(*TCPListener).AcceptTCP(0xc42000c0a8, 0xc423dfa960, 0xc423dfa960, 0xc19e20)
	/usr/local/Cellar/go/1.9.3/libexec/src/net/tcpsock.go:234 +0x49
net/http.tcpKeepAliveListener.Accept(0xc42000c0a8, 0xc4200140d0, 0xc19e20, 0x1414530, 0xcf9120)
	/usr/local/Cellar/go/1.9.3/libexec/src/net/http/server.go:3120 +0x2f
net/http.(*Server).Serve(0xc4245140d0, 0x1291d80, 0xc42000c0a8, 0x0, 0x0)
	/usr/local/Cellar/go/1.9.3/libexec/src/net/http/server.go:2695 +0x1b2
net/http.(*Server).ListenAndServe(0xc4245140d0, 0xc4245140d0, 0xc4224b8a40)
	/usr/local/Cellar/go/1.9.3/libexec/src/net/http/server.go:2636 +0xa9
net/http.ListenAndServe(0xd3d0f7, 0xe, 0x1287600, 0xc423dfa120, 0xc420046180, 0xd37fbd)
	/usr/local/Cellar/go/1.9.3/libexec/src/net/http/server.go:2882 +0x7f
github.com/loadimpact/k6/api.ListenAndServe(0xd3d0f7, 0xe, 0xc42389b680, 0x8, 0xd35ccc)
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/api/server.go:51 +0x219
github.com/loadimpact/k6/cmd.glob..func11.2(0xc42389b680)
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/cmd/run.go:206 +0x47
created by github.com/loadimpact/k6/cmd.glob..func11
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/cmd/run.go:205 +0x1284

goroutine 12 [runnable]:
github.com/loadimpact/k6/core.(*Engine).Run(0xc42389b680, 0x1292340, 0xc423d35dc0, 0x0, 0x0)
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/core/engine.go:217 +0xb10
github.com/loadimpact/k6/cmd.glob..func11.3(0xc420509560, 0xc42389b680, 0x1292340, 0xc423d35dc0)
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/cmd/run.go:261 +0x3f
created by github.com/loadimpact/k6/cmd.glob..func11
	/Users/robin/Projects/go/src/github.com/loadimpact/k6/cmd/run.go:261 +0x2310

goroutine 13 [select, locked to thread]:
runtime.gopark(0xd68d20, 0x0, 0xd3616a, 0x6, 0x18, 0x1)
	/usr/local/Cellar/go/1.9.3/libexec/src/runtime/proc.go:287 +0x12c
runtime.selectgo(0xc4252eef50, 0xc420509620)
	/usr/local/Cellar/go/1.9.3/libexec/src/runtime/select.go:395 +0x1149
runtime.ensureSigM.func1()
	/usr/local/Cellar/go/1.9.3/libexec/src/runtime/signal_unix.go:511 +0x220
runtime.goexit()
	/usr/local/Cellar/go/1.9.3/libexec/src/runtime/asm_amd64.s:2337 +0x1
.
.
.

[na--]

As you've mentioned, you shouldn't use the setup data in this way. The setup data is in no way intended or suitable for synchronization or even cross-VU modification. The different VUs have their own separate JS runtimes and the only reason that this sort-of works is that we currently don't do a deep copy of the setup data for each VU and a quirk in the way go manages objects... But even then it wouldn't have worked in a distributed cluster/cloud execution scenario...

This issue, #684 and #558, make me reevaluate how we handle the setup data... I think that we should either make the setup data totally read-only (which I'm not sure is actually possible with goja) or we should do something like this:

• make it explicitly clear in the documentation that only the data from whatever setup() returns is preserved and that this data is then copied to each VU runtime before it starts; any changes in that data would be local to the VU and wouldn't propagate to other VUs or the teardown() function
• actually implement that, with deep copying, proper sanitization, etc.
• check (with many unit tests) for these things, especially how things like maps, slices, objects like http.Response and such are handled...

Regarding a global counter, it would be quite difficult and costly in terms of synchronization overhead to do in a distributed execution setting. Building a unique ID from __VU and __ITER (and instance id in the future) is the suggested solution, though making it sequential can be a challenge...

[SaberStrat]

I figured this would fail at most when running in a future distributed mode (which I look forward to). I only tried it because it wasn't explicitly recommended against in the docs, and worked with fewer VUs.

So maybe the documentation should at least contain a warning. If possible, a read-only state would probably be the best 'immediate' fix, as a deep copy would increase the memory foot print.

And as for my use case of a global counter for unique test data, a stream API (#592) is what I extremely look forward to, too. I haven't tried using third party modules for external data sources yet (e.g. Redis), but figure the performance impact on the test run might be noticible.

The downside of a 'unique' ID from __VU and __ITER is that one needs to manually pre-slice the test data on a per-VU basis, which is not so elegant.

[na--]

This was fixed by #799