Data race during panic and running code on event loop

[ankur22]

Brief summary

A data race can occur frequently in CI when running browser integration tests such as when running TestPageEvaluateMapping, TestGetByNullHandling, or TestPageOnResponse.

k6 version

NA

OS

NA

Docker version and image (if applicable)

No response

Steps to reproduce the problem

This can occur when:

1. the context is closed for whatever reason;
2. chrome is sends a targetAttach event back to k6;
3. k6 tries to to work with the event and fails, causing a panic;
4. At the same time while running TestPageEvaluateMapping, TestGetByNullHandling, or TestPageOnResponse a script is ran on the eventloop with RunAsync;
5. Both of these actions will try to work with non thread safe data structures (the stack) which causes the data race.

I was able to reproduce this with GOMAXPROCS=8 go test -race -run "TestPageEvaluateMapping|TestGetByNullHandling|TestPageOnResponse" -count=100 -failfast -p 8 -timeout 30m -v ./internal/js/modules/k6/browser/tests

It's worth noting that this will happen less often once we merge in #5526.

The reason for this issue is due to trying to work with the Sobek runtime off the "main" Sobek thread. We should only work with the Sobek runtime when running the "main" Sobek thread (when an API is called in the mapping layer) or working with the event loop. The browser module has improved significantly and reducing such failures, but we still have many such cases, e.g. #4203.

I took a look at where else we might be working with the Runtime outside the "main" Sobek thread, and it seems that it's only in Panicf. We should either refactor that to work with the event loop, or refactor it to not need the Runtime.

Expected behaviour

No data race

Actual behaviour

See stack trace for more details

==================
WARNING: DATA RACE
Read at 0x00c000795138 by goroutine 2118:
  github.com/grafana/sobek.(*errorObject).init()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/vendor/github.com/grafana/sobek/builtin_error.go:104 +0xcc
  github.com/grafana/sobek.(*Runtime).newErrorObject()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/vendor/github.com/grafana/sobek/builtin_error.go:118 +0x200
  github.com/grafana/sobek.(*Runtime).builtin_Error()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/vendor/github.com/grafana/sobek/builtin_error.go:123 +0x4c
  github.com/grafana/sobek.(*Runtime).builtin_Error-fm()
      <autogenerated>:1 +0x54
  github.com/grafana/sobek.(*Runtime).newNativeFuncConstructProto.(*Runtime).wrapNativeConstruct.func2()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/vendor/github.com/grafana/sobek/runtime.go:998 +0x84
  github.com/grafana/sobek.(*Runtime).builtin_new()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/vendor/github.com/grafana/sobek/runtime.go:913 +0x64
  github.com/grafana/sobek.(*Runtime).newError()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/vendor/github.com/grafana/sobek/runtime.go:480 +0x124
  github.com/grafana/sobek.(*Runtime).NewGoError()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/vendor/github.com/grafana/sobek/runtime.go:558 +0x68
  go.k6.io/k6/js/common.Throw()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/js/common/util.go:17 +0x7c
  go.k6.io/k6/internal/js/modules/k6/browser/k6ext.Panicf.func1()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/internal/js/modules/k6/browser/k6ext/panic.go:35 +0x3c
  go.k6.io/k6/internal/js/modules/k6/browser/k6ext.sharedPanic.deferwrap1()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/internal/js/modules/k6/browser/k6ext/panic.go:56 +0x64
  runtime.deferreturn()
      /usr/local/go/src/runtime/panic.go:589 +0x5c
  go.k6.io/k6/internal/js/modules/k6/browser/k6ext.Panicf()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/internal/js/modules/k6/browser/k6ext/panic.go:37 +0x84
  go.k6.io/k6/internal/js/modules/k6/browser/common.(*Browser).initEvents.func1()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/internal/js/modules/k6/browser/common/browser.go:242 +0x384

Previous write at 0x00c000795138 by goroutine 1814:
  github.com/grafana/sobek.(*vm).popCtx()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/vendor/github.com/grafana/sobek/vm.go:940 +0x5f0
  github.com/grafana/sobek.(*nativeFuncObject).vmCall()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/vendor/github.com/grafana/sobek/func.go:579 +0x600
  github.com/grafana/sobek.call.exec()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/vendor/github.com/grafana/sobek/vm.go:3732 +0xd4
  github.com/grafana/sobek.(*call).exec()
      <autogenerated>:1 +0x48
  github.com/grafana/sobek.(*vm).run()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/vendor/github.com/grafana/sobek/vm.go:642 +0x9c
  github.com/grafana/sobek.(*vm).runTryInner()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/vendor/github.com/grafana/sobek/vm.go:893 +0x78
  github.com/grafana/sobek.(*generator).step()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/vendor/github.com/grafana/sobek/func.go:770 +0x44
  github.com/grafana/sobek.(*asyncRunner).start()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/vendor/github.com/grafana/sobek/func.go:741 +0x190
  github.com/grafana/sobek.(*baseJsFuncObject).asyncVmCall()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/vendor/github.com/grafana/sobek/func.go:672 +0x11c
  github.com/grafana/sobek.(*asyncFuncObject).vmCall()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/vendor/github.com/grafana/sobek/func.go:678 +0x98
  github.com/grafana/sobek.call.exec()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/vendor/github.com/grafana/sobek/vm.go:3732 +0xd4
  github.com/grafana/sobek.(*call).exec()
      <autogenerated>:1 +0x48
  github.com/grafana/sobek.(*vm).run()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/vendor/github.com/grafana/sobek/vm.go:642 +0x9c
  github.com/grafana/sobek.(*vm).runTryInner()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/vendor/github.com/grafana/sobek/vm.go:893 +0x78
  github.com/grafana/sobek.(*vm).runTry()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/vendor/github.com/grafana/sobek/vm.go:879 +0x270
  github.com/grafana/sobek.(*Runtime).RunProgram()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/vendor/github.com/grafana/sobek/runtime.go:1481 +0x584
  github.com/grafana/sobek.(*Runtime).RunScript()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/vendor/github.com/grafana/sobek/runtime.go:1417 +0x8c
  github.com/grafana/sobek.(*Runtime).RunString()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/vendor/github.com/grafana/sobek/runtime.go:1406 +0x80
  go.k6.io/k6/js/modulestest.(*Runtime).RunOnEventLoop.func1()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/js/modulestest/runtime.go:112 +0x44
  go.k6.io/k6/internal/js/eventloop.(*EventLoop).Start()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/internal/js/eventloop/eventloop.go:179 +0x1dc
  go.k6.io/k6/js/modulestest.(*Runtime).RunOnEventLoop()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/js/modulestest/runtime.go:111 +0x1cc
  go.k6.io/k6/internal/js/modules/k6/browser/k6ext/k6test.(*VU).RunOnEventLoop()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/internal/js/modules/k6/browser/k6ext/k6test/vu.go:133 +0x90
  go.k6.io/k6/internal/js/modules/k6/browser/k6ext/k6test.(*VU).RunAsync()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/internal/js/modules/k6/browser/k6ext/k6test/vu.go:143 +0xb4
  go.k6.io/k6/internal/js/modules/k6/browser/k6ext/k6test.(*VU).RunPromise()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/internal/js/modules/k6/browser/k6ext/k6test/vu.go:151 +0x74
  go.k6.io/k6/internal/js/modules/k6/browser/tests.TestPageEvaluateMapping.func1()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/internal/js/modules/k6/browser/tests/page_test.go:243 +0x2a0
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:1934 +0x164
  testing.(*T).Run.gowrap1()
      /usr/local/go/src/testing/testing.go:1997 +0x3c

Goroutine 2118 (running) created at:
  go.k6.io/k6/internal/js/modules/k6/browser/common.(*Browser).initEvents()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/internal/js/modules/k6/browser/common/browser.go:219 +0x1dc
  go.k6.io/k6/internal/js/modules/k6/browser/common.(*Browser).connect()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/internal/js/modules/k6/browser/common/browser.go:169 +0x6b4
  go.k6.io/k6/internal/js/modules/k6/browser/common.NewBrowser()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/internal/js/modules/k6/browser/common/browser.go:98 +0x70
  go.k6.io/k6/internal/js/modules/k6/browser/chromium.(*BrowserType).launch()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/internal/js/modules/k6/browser/chromium/browser_type.go:218 +0x484
  go.k6.io/k6/internal/js/modules/k6/browser/chromium.(*BrowserType).Launch()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/internal/js/modules/k6/browser/chromium/browser_type.go:178 +0xec
  go.k6.io/k6/internal/js/modules/k6/browser/browser.newBrowserRegistry.func1()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/internal/js/modules/k6/browser/browser/registry.go:218 +0xac
  go.k6.io/k6/internal/js/modules/k6/browser/browser.(*browserRegistry).handleIterEvents()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/internal/js/modules/k6/browser/browser/registry.go:306 +0x3f8
  go.k6.io/k6/internal/js/modules/k6/browser/browser.newBrowserRegistry.gowrap2()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/internal/js/modules/k6/browser/browser/registry.go:248 +0x50

Goroutine 1814 (running) created at:
  testing.(*T).Run()
      /usr/local/go/src/testing/testing.go:1997 +0x6e0
  go.k6.io/k6/internal/js/modules/k6/browser/tests.TestPageEvaluateMapping()
      /Users/ankuragarwal/go/src/github.com/grafana/k6/internal/js/modules/k6/browser/tests/page_test.go:233 +0x268
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:1934 +0x164
  testing.(*T).Run.gowrap1()
      /usr/local/go/src/testing/testing.go:1997 +0x3c
==================

... stack trace redacted due to github char limitations.

panic: GoError: browser is attaching to target: canceled

goroutine 2161 [running]:
go.k6.io/k6/js/common.Throw(...)
        /Users/ankuragarwal/go/src/github.com/grafana/k6/js/common/util.go:17
go.k6.io/k6/internal/js/modules/k6/browser/k6ext.Panicf.func1(0xc0000d8c08, {0xc002c693e0, 0x1, 0x1})
        /Users/ankuragarwal/go/src/github.com/grafana/k6/internal/js/modules/k6/browser/k6ext/panic.go:35 +0x90
go.k6.io/k6/internal/js/modules/k6/browser/k6ext.sharedPanic({0x104918480, 0xc0002ca000}, 0xc0007dfe30, {0xc002c693e0, 0x1, 0x1})
        /Users/ankuragarwal/go/src/github.com/grafana/k6/internal/js/modules/k6/browser/k6ext/panic.go:76 +0x2b0
go.k6.io/k6/internal/js/modules/k6/browser/k6ext.Panicf({0x104918480, 0xc0002ca000}, {0x1042aa7d4, 0x22}, {0xc002c693e0, 0x1, 0x1})
        /Users/ankuragarwal/go/src/github.com/grafana/k6/internal/js/modules/k6/browser/k6ext/panic.go:37 +0x88
go.k6.io/k6/internal/js/modules/k6/browser/common.(*Browser).initEvents.func1()
        /Users/ankuragarwal/go/src/github.com/grafana/k6/internal/js/modules/k6/browser/common/browser.go:242 +0x388
created by go.k6.io/k6/internal/js/modules/k6/browser/common.(*Browser).initEvents in goroutine 1880
        /Users/ankuragarwal/go/src/github.com/grafana/k6/internal/js/modules/k6/browser/common/browser.go:219 +0x1e0
FAIL    go.k6.io/k6/internal/js/modules/k6/browser/tests        13.809s