grafana / xk6-browser

The browser module adds support for browser automation and end-to-end web testing via the Chrome Devtools Protocol to k6.
https://grafana.com/docs/k6/latest/javascript-api/k6-browser/
GNU Affero General Public License v3.0
344 stars 41 forks source link

element_handle.newAction function can wait indefinitely when context is cancelled #1437

Closed ankur22 closed 1 week ago

ankur22 commented 2 months ago

Brief summary

We've found another issue where the browser module seems to hang indefinitely. This time it is due to a goroutine not reading from the channel once the context is closed.

  1. helper func calls newPointerAction
  2. newPointerAction is then called. On result it tries to write to the resultCh.
  3. In the meantime the context has been closed and the goroutine that is supposed to read from the resultCh has shutdown.

This could be a reason for the browser module not shutting down, although i would have expected the goroutine to be cleaned up by the go runtime 🤔

stack trace of issue:

goroutine 0 gp=0x2ef51e0 m=0 mp=0x2ef6420 [idle]:
runtime.futex(0x2ef6560, 0x80, 0x0, 0x0, 0x0, 0x0)
    runtime/sys_linux_amd64.s:557 +0x21 fp=0x7ffc7c4c4b50 sp=0x7ffc7c4c4b48 pc=0x47ee21
runtime.futexsleep(0x7ffc7c4c4bc8?, 0x40f630?, 0x7ffc7c4c4bf8?)
    runtime/os_linux.go:69 +0x30 fp=0x7ffc7c4c4ba0 sp=0x7ffc7c4c4b50 pc=0x437dd0
runtime.notesleep(0x2ef6560)
    runtime/lock_futex.go:170 +0x87 fp=0x7ffc7c4c4bd8 sp=0x7ffc7c4c4ba0 pc=0x40f7c7
runtime.mPark(...)
    runtime/proc.go:1866
runtime.stopm()
    runtime/proc.go:2885 +0x8c fp=0x7ffc7c4c4c08 sp=0x7ffc7c4c4bd8 pc=0x4432ac
runtime.findRunnable()
    runtime/proc.go:3622 +0xd5c fp=0x7ffc7c4c4d80 sp=0x7ffc7c4c4c08 pc=0x444d1c
runtime.schedule()
    runtime/proc.go:3995 +0xb1 fp=0x7ffc7c4c4db8 sp=0x7ffc7c4c4d80 pc=0x445df1
runtime.goexit0(0xc000b396c0?)
    runtime/proc.go:4268 +0x18 fp=0x7ffc7c4c4dd0 sp=0x7ffc7c4c4db8 pc=0x446ad8
runtime.mcall()
    runtime/asm_amd64.s:459 +0x4e fp=0x7ffc7c4c4de8 sp=0x7ffc7c4c4dd0 pc=0x47b16e

goroutine 1 gp=0xc0000061c0 m=nil [select]:
runtime.gopark(0xc000d0ae50?, 0x2?, 0x10?, 0xa0?, 0xc000d0ae2c?)
    runtime/proc.go:424 +0xce fp=0xc000d0acd0 sp=0xc000d0acb0 pc=0x474bce
runtime.selectgo(0xc000d0ae50, 0xc000d0ae28, 0x18780c0?, 0x0, 0x2ef46c0?, 0x1)
    runtime/select.go:335 +0x7a5 fp=0xc000d0adf8 sp=0xc000d0acd0 pc=0x450865
go.k6.io/k6/event.(*System).Emit.func4({0x1f1fb18, 0xc02a7836c0})
    go.k6.io/k6/event/system.go:115 +0xc5 fp=0xc000d0ae90 sp=0xc000d0adf8 pc=0x619a45
go.k6.io/k6/cmd.(*cmdRun).run.func2.1()
    go.k6.io/k6/cmd/run.go:88 +0x64 fp=0xc000d0aef0 sp=0xc000d0ae90 pc=0x1785b04
go.k6.io/k6/cmd.(*cmdRun).run.func3()
    go.k6.io/k6/cmd/run.go:99 +0xc7 fp=0xc000d0af30 sp=0xc000d0aef0 pc=0x1785987
runtime.deferreturn()
    runtime/panic.go:605 +0x5e fp=0xc000d0afc0 sp=0xc000d0af30 pc=0x43a55e
go.k6.io/k6/cmd.(*cmdRun).run(0xc000311060, 0xc000299348, {0xc0003dac08, 0x1, 0x2f})
    go.k6.io/k6/cmd/run.go:434 +0x1738 fp=0xc000d0bc50 sp=0xc000d0afc0 pc=0x1783ad8
go.k6.io/k6/cmd.(*cmdRun).run-fm(0xc00040fb
... omitting 106543 bytes ...
ommon.NewSession.gowrap1()
    github.com/grafana/xk6-browser@v1.8.2/common/session.go:47 +0x25 fp=0xc01b6837e0 sp=0xc01b6837c8 pc=0x15933a5
runtime.goexit({})
    runtime/asm_amd64.s:1700 +0x1 fp=0xc01b6837e8 sp=0xc01b6837e0 pc=0x47d021
created by github.com/grafana/xk6-browser/common.NewSession in goroutine 211384515
    github.com/grafana/xk6-browser@v1.8.2/common/session.go:47 +0x367

goroutine 27770480 gp=0xc012a61180 m=nil [chan send, 63 minutes]:
runtime.gopark(0xc02ab11d78?, 0xc02ab11e58?, 0x1c?, 0x93?, 0x1f1fb18?)
    runtime/proc.go:424 +0xce fp=0xc08e335dc8 sp=0xc08e335da8 pc=0x474bce
runtime.chansend(0xc048ad87e0, 0xc08e335e98, 0x1, 0xc11f898de0?)
    runtime/chan.go:270 +0x38d fp=0xc08e335e38 sp=0xc08e335dc8 pc=0x40916d
runtime.chansend1(0x1f1fb18?, 0xc0bbee21c0?)
    runtime/chan.go:156 +0x17 fp=0xc08e335e68 sp=0xc08e335e38 pc=0x408dd7
github.com/grafana/xk6-browser/common.(*ElementHandle).newPointerAction.func2({0x1f1fb18?, 0xc0bbee21c0?}, 0xc048ad87e0, 0xc048ad88c0)
    github.com/grafana/xk6-browser@v1.8.2/common/element_handle.go:1651 +0x9c fp=0xc08e335eb8 sp=0xc08e335e68 pc=0x15388fc
github.com/grafana/xk6-browser/common.(*Frame).click.(*Frame).newPointerAction.func2({0x1f1fb18, 0xc0bbee21c0}, 0xc048ad87e0, 0xc048ad88c0)
    github.com/grafana/xk6-browser@v1.8.2/common/frame.go:2181 +0x116 fp=0xc08e335fb0 sp=0xc08e335eb8 pc=0x15446d6
github.com/grafana/xk6-browser/common.call.gowrap1()
    github.com/grafana/xk6-browser@v1.8.2/common/helpers.go:103 +0x30 fp=0xc08e335fe0 sp=0xc08e335fb0 pc=0x156b730
runtime.goexit({})
    runtime/asm_amd64.s:1700 +0x1 fp=0xc08e335fe8 sp=0xc08e335fe0 pc=0x47d021
created by github.com/grafana/xk6-browser/common.call in goroutine 27770479
    github.com/grafana/xk6-browser@v1.8.2/common/helpers.go:103 +0x14c

xk6-browser version

v1.8.2

OS

NA

Chrome version

NA

Docker version and image (if applicable)

No response

Steps to reproduce the problem

NA

Expected behaviour

The browser module shuts down and instead of it trying to write to the resultCh it exits when the context closes.

Actual behaviour

Waits for a goroutine to read off of resultCh.

### My tasks
- [ ] https://github.com/grafana/xk6-browser/pull/1438
- [x] Release notes