Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

The "complex" test fails on the very first step (page.goto) #542

Closed
ankur22 opened this issue Sep 21, 2022 · 6 comments
Closed

The "complex" test fails on the very first step (page.goto) #542

ankur22 opened this issue Sep 21, 2022 · 6 comments
Labels
bug Something isn't working

Comments

@ankur22
Copy link
Collaborator

ankur22 commented Sep 21, 2022

Commit tested against: 8b52a02 (pre-v0.6.0).
Test script: "complex" test.

The "complex" test does not work against the version of xk6-browser mentioned above. It navigates to the site, but seems to fail to get passed the waitUntil: 'networkidle' stage of the page.goto action.

In a randomly chosen tagged version of xk6-browser (v0.4.0) it is able to consistently get through most of the "complex" test, so well passed the page.goto initial step.
@ankur22 ankur22 added the bug Something isn't working label Sep 21, 2022
@inancgumus
Copy link
Member

inancgumus commented Sep 21, 2022 •
edited
Loading

There is regression somewhere, and git bisect can help even though the complex test script is somewhat flaky. Weirdly, we cannot even pass the page.goto stage with the script. I vote to make this a high priority after dealing with the current high-priority issues.

PS: The script was working after fixing #169. Even though that's an old PR, it possibly can give us clues about where to look next.

@mstoykov
Copy link
Contributor

removing the debug: false fixed it for me

mstoykov added a commit that referenced this issue Oct 11, 2022
@mstoykov
Fix what seems like an obvious logical error
08f4aad 
Updates #542
@mstoykov mstoykov mentioned this issue Oct 11, 2022
Merged
@mstoykov
Copy link
Contributor

removing the debug: false fixed it for me

This is no longer true with the latest version - I first hit what I fixed in #579 and then I get

go.k6.io/k6/js/common.Throw(0x1394a00?, {0x18b3ca0?, 0xc0012c0120?})
        go.k6.io/[email protected]/js/common/util.go:20 +0x55
github.com/grafana/xk6-browser/k6ext.Panic({0x18c2b68, 0xc002384e40}, {0x1600224, 0x27}, {0xc003491df8, 0x2, 0x2})
        github.com/grafana/[email protected]/k6ext/panic.go:51 +0x2d7
github.com/grafana/xk6-browser/common.(*FrameSession).onFrameNavigated(0xc001973c30, 0xc000af66c0, 0x20?)
        github.com/grafana/[email protected]/common/frame_session.go:650 +0x2e9
github.com/grafana/xk6-browser/common.(*FrameSession).initEvents.func1()
        github.com/grafana/[email protected]/common/frame_session.go:257 +0x694
created by github.com/grafana/xk6-browser/common.(*FrameSession).initEvents
        github.com/grafana/[email protected]/common/frame_session.go:228 +0x1ab

Which seems like a case where we should log or return an error, but instead we panic. But no obvious logical error as in #579

mstoykov added a commit that referenced this issue Oct 11, 2022
@mstoykov
Fix what seems like an obvious logical error
1114144 
Updates #542
@ankur22
Copy link
Collaborator Author

ankur22 commented Oct 11, 2022 •
edited
Loading

Interesting! I didn't come across this when I was running this locally. Instead I was facing the issue where waitUntil: 'networkidle' wasn't being handled correctly. The reason for that is the event fires (lifecycle event with networkIdle) before the FrameManager registers to the event loop. I'm currently looking to fix it in #578.

@mstoykov mstoykov mentioned this issue Oct 13, 2022
Merged
@mstoykov
Copy link
Contributor

mstoykov commented Oct 13, 2022 •
edited
Loading

With the latest main and also with the commit from before the goto async support I get the following race

==================
WARNING: DATA RACE, 1/1 VUs, 0 complete and 0 interrupted iterations
Write at 0x00c002d32870 by goroutine 80:---------] 1 VUs  00m05.0s/10m0s  0/1 iters, 1 per VU
  runtime.mapdelete_faststr()
      runtime/map_faststr.go:301 +0x0
  github.com/grafana/xk6-browser/common.(*FrameManager).requestFinished()
      github.com/grafana/[email protected]/common/frame_manager.go:485 +0x1e9
  github.com/grafana/xk6-browser/common.(*NetworkManager).onLoadingFinished()
      github.com/grafana/[email protected]/common/network_manager.go:409 +0x664
  github.com/grafana/xk6-browser/common.(*NetworkManager).handleEvents()
      github.com/grafana/[email protected]/common/network_manager.go:352 +0x1ce
  github.com/grafana/xk6-browser/common.(*NetworkManager).initEvents.func1()
      github.com/grafana/[email protected]/common/network_manager.go:333 +0x3e

Previous write at 0x00c002d32870 by goroutine 1780:
  runtime.mapdelete_faststr()
      runtime/map_faststr.go:301 +0x0
  github.com/grafana/xk6-browser/common.(*FrameManager).requestFinished()
      github.com/grafana/[email protected]/common/frame_manager.go:485 +0x1e9
  github.com/grafana/xk6-browser/common.(*NetworkManager).onLoadingFinished()
      github.com/grafana/[email protected]/common/network_manager.go:409 +0x664
  github.com/grafana/xk6-browser/common.(*NetworkManager).handleEvents()
      github.com/grafana/[email protected]/common/network_manager.go:352 +0x1ce
  github.com/grafana/xk6-browser/common.(*NetworkManager).initEvents.func1()
      github.com/grafana/[email protected]/common/network_manager.go:333 +0x3e

Goroutine 80 (running) created at:
  github.com/grafana/xk6-browser/common.(*NetworkManager).initEvents()
      github.com/grafana/[email protected]/common/network_manager.go:332 +0x34e
  github.com/grafana/xk6-browser/common.NewNetworkManager()
      github.com/grafana/[email protected]/common/network_manager.go:107 +0x57d
  github.com/grafana/xk6-browser/common.NewFrameSession()
      github.com/grafana/[email protected]/common/frame_session.go:120 +0x73a
  github.com/grafana/xk6-browser/common.NewPage()
      github.com/grafana/[email protected]/common/page.go:139 +0xc18
  github.com/grafana/xk6-browser/common.(*Browser).onAttachedToTarget()
      github.com/grafana/[email protected]/common/browser.go:294 +0xadb
  github.com/grafana/xk6-browser/common.(*Browser).initEvents.func1()
      github.com/grafana/[email protected]/common/browser.go:195 +0x424

Goroutine 1780 (running) created at:
  github.com/grafana/xk6-browser/common.(*NetworkManager).initEvents()
      github.com/grafana/[email protected]/common/network_manager.go:332 +0x34e
  github.com/grafana/xk6-browser/common.NewNetworkManager()
      github.com/grafana/[email protected]/common/network_manager.go:107 +0x57d
  github.com/grafana/xk6-browser/common.NewFrameSession()
      github.com/grafana/[email protected]/common/frame_session.go:120 +0x73a
  github.com/grafana/xk6-browser/common.(*FrameSession).attachIFrameToTarget()
      github.com/grafana/[email protected]/common/frame_session.go:843 +0x266
  github.com/grafana/xk6-browser/common.(*FrameSession).onAttachedToTarget()
      github.com/grafana/[email protected]/common/frame_session.go:776 +0x476
  github.com/grafana/xk6-browser/common.(*FrameSession).initEvents.func1()
      github.com/grafana/[email protected]/common/frame_session.go:279 +0x608
==================

Which might be goto related

but the thing that kills the test for me is

panic: handling frameNavigated event to "https://fledge-usa.creativecdn.com/fledge-igmembership?ntk=KEkVm9eNgoZkFBlB_Mqexdx7hBrOVavM6XVKiQwxMH1Oc3uyi6pc6SjOxbUjfWRqlzT2sUrnzGM9FjSwkllzNA": we either navigate top level or have old version of the navigated frame
running (00m05.3s), 1/1 VUs, 0 complete and 0 interrupted iterations
goroutine 2424 [running]:------------------------] 1 VUs  00m05.3s/10m0s  0/1 iters, 1 per VU
go.k6.io/k6/js/common.Throw(0xfd?, {0x233ae00?, 0xc0017eab00})
        go.k6.io/[email protected]/js/common/util.go:20 +0x79
github.com/grafana/xk6-browser/k6ext.Panic({0x2349f48, 0xc002d32120}, {0x1fd43a0, 0x27}, {0xc0032b7d58, 0x2, 0x2})
        github.com/grafana/[email protected]/k6ext/panic.go:51 +0x418
github.com/grafana/xk6-browser/common.(*FrameSession).onFrameNavigated(0xc000cfe6e0, 0xc002245d40, 0x20?)
        github.com/grafana/[email protected]/common/frame_session.go:652 +0x4ba
github.com/grafana/xk6-browser/common.(*FrameSession).initEvents.func1()
        github.com/grafana/[email protected]/common/frame_session.go:257 +0x918
created by github.com/grafana/xk6-browser/common.(*FrameSession).initEvents
        github.com/grafana/[email protected]/common/frame_session.go:228 +0x33f

which seems to be one more case of k6ext.Panic being used not on the event loop which leads to a panic and stopping of xk6-browser instead to an exception :(

edit: If I just make it not panic but log the error, I do get a lot further in the test and IMO either dies because of races with loading and finding elements or because the site under test has changed ... not certain

@inancgumus inancgumus added this to the v0.7.0 milestone Nov 9, 2022
@inancgumus inancgumus removed this from the v0.7.0 milestone Feb 7, 2023
@inancgumus
Copy link
Member

It is not failing on the very first step :yay:

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@mstoykov @inancgumus @ankur22