Skip to content
This repository has been archived by the owner on Jan 30, 2025. It is now read-only.

Go panic: cannot create frame session #125

Closed
imiric opened this issue Nov 18, 2021 · 5 comments · Fixed by #129
Closed

Go panic: cannot create frame session #125

imiric opened this issue Nov 18, 2021 · 5 comments · Fixed by #129
Assignees
Labels
bug Something isn't working next Might be eligible for the next planning (not guaranteed!)

Comments

@imiric
Copy link
Contributor

imiric commented Nov 18, 2021

We've been noticing this error recently from Tom's updated script:

ERRO[0014] unable to evaluate expression: Cannot find context with specified id (-32000)
running at reflect.methodValueCall (native)
default at file:///home/ivan/Projects/grafana/xk6-browser/examples/49-vistaprint-20211115.js:76:26(9)
        at go.k6.io/k6/js/common.Bind.func1 (native)
        at clickBusinessCards (file:///home/ivan/Projects/grafana/xk6-browser/examples/49-vistaprint-20211115.js:73:17(17))
        at file:///home/ivan/Projects/grafana/xk6-browser/examples/49-vistaprint-20211115.js:18:21(8)  executor=per-vu-iterations scenario=default source=stacktrace
WARN[0014]                                               category=cdp error="error fetching response body: context canceled" method=GET url="https://www.vistaprint.ca/visage/latest/v5/all/library/styles/components/core.ef3572a618c168760ba19432b84f7447.css"
panic: cannot create frame session: unable to add script to evaluate for isolated world: context canceled
running (00m13.4s), 1/1 VUs, 0 complete and 0 interrupted iterations
goroutine 52 [running]:--------------------------] 1 VUs  00m13.4s/10m0s  0/1 iters, 1 per VU
go.k6.io/k6/js/common.Throw(0x11203c0, {0x1585ca0, 0xc003298aa0})
        go.k6.io/[email protected]/js/common/util.go:36 +0x55
github.com/grafana/xk6-browser/common.k6Throw({0x15a57a8, 0xc0037d43c0}, {0x1328705, 0x1f}, {0xc002b49f30, 0x1, 0x1})
        github.com/grafana/[email protected]/common/helpers.go:338 +0x1ae
github.com/grafana/xk6-browser/common.(*FrameSession).onAttachedToTarget(0xc003292280, 0xc003288400)
        github.com/grafana/[email protected]/common/frame_session.go:653 +0x1d4
github.com/grafana/xk6-browser/common.(*FrcaameSession).initEvents.func1()
        github.com/grafana/[email protected]/common/frame_session.go:217 +0x2f2
created by github.com/grafana/xk6-browser/common.(*FrameSession).initEvents
        github.com/grafana/[email protected]/common/frame_session.go:180 +0xe7

The first Cannot find context with specified id is the same error from #49, but now it pretty much happens constantly. So yay, it can be reproduced 😄

The second cannot create frame session panic is because the context was canceled. We're not sure if this is a regression or if a site change has exposed it. Regardless, it shouldn't happen.

@imiric imiric added bug Something isn't working next Might be eligible for the next planning (not guaranteed!) labels Nov 18, 2021
@inancgumus inancgumus self-assigned this Nov 19, 2021
@inancgumus
Copy link
Member

inancgumus commented Nov 19, 2021

I couldn't find the root cause of this after dealing with hundreds of print statements and debugging trials.

@inancgumus
Copy link
Member

inancgumus commented Nov 22, 2021

Findings:

  1. I finally determined that the context canceled error happens when we sleep in a script.
  2. My experiments showed that the error happens when the browser is closed before we finish.

I have a draft PR for this (not ready for review), working on it.

I added a lot of logging statements to diagnose the root cause. And they are super helpful.

@inancgumus
Copy link
Member

inancgumus commented Nov 23, 2021

Today's findings:

  • Proper logging: After adding a lot of log statements in this PR, I can determine where and when the error occurs but still don't know the root cause.

  • Go test: I wrote a new test in an experimental branch for validating the issue from the Go side. The weird thing is that the test passes!

  • Finding: Headless mode: The issue doesn't occur in the headless mode.

  • Finding: Don't Sleep: The issue doesn't occur if we don't sleep in the test code. I determined this yesterday as well, however, it should be the correct behavior for test scripts the follow which is "never sleep"! Note that Playwright also recommends the same.

  • Finding: SlowMo: I also determined that SlowMo breaks the script and results in the same error. So the problem may lie there. So I used a 50ms slow motion in the test below. It's because the websocket connection somehow drops (above 150ms), so I added a websocket keepaliver, but it didn't work, then I removed it.

  • Finding: Use waitForSelector: So the test script works when it doesn't ever sleep but uses waitForSelector instead:

import launcher from 'k6/x/browser';

export default function() {
  let browser = launcher.launch('chromium', {
    debug: false,
    devtools: false,
    headless: false,
    slowMo: '50ms', // 500ms breaks it
    timeout: '30s',
  });
  let context = browser.newContext({ });
  let page = context.newPage();

  page.goto('https://vistaprint.ca', { waitUntil: 'domcontentloaded' });

  page.waitForSelector("//span[text()='Business Cards']");
  let elem = page.$("//span[text()='Business Cards']");
  elem.click();
  
  page.waitForSelector("//a[text()='Browse designs']");
  elem = page.$("//a[text()='Browse designs']");
  elem.click();  

  page.waitForSelector("li.design-tile");
  let elems = page.$$("li.design-tile");
  page.waitForSelector("li.design-tile");
}

I also wrote a Playwright script that never uses sleep and works flawlessly. Of course, it uses promises, unfortunately, which we don't have.

const { test } = require('@playwright/test');

test('basic test', async ({ page }) => {
  await page.goto('https://vistaprint.ca', { waitUntil: 'domcontentloaded' });
  console.log("Current Page:", await page.title())

  let elem = await page.$("//span[text()='Business Cards']");
  await elem.click();
  console.log("Current Page:", await page.title())
  
  elem = await page.$("//a[text()='Browse designs']");
  await elem.click();
  console.log("Current Page:", await page.title())
  
  let elems = await page.$$("li.design-tile");
  console.log(`Found ${elems.length} design options.`);
})

@robingustafsson @imiric

@inancgumus
Copy link
Member

inancgumus commented Nov 30, 2021

I believe I solved the error (see this):
panic: cannot create frame session: unable to add script to evaluate for isolated world: context canceled.

Now, I'm trying to add a proper test to validate it without using vista.

PS: I changed the name of the PR because we no longer witness context-canceled errors (I checked this with Tom's script).

inancgumus added a commit that referenced this issue Dec 1, 2021
There were missing locks for execution contexts. This fix adds a
lock-based management for locks and uses an internal goroutine
to track whether an execution context is ready to use.

For now, it uses an infinite for loop with sleep. This is not
effective. So it should be fixed with something better.

There are some TODOs in the code that should be investigated.
Also the tests are missing from this commit. So they should
be added as well.

Fixes #125
@inancgumus inancgumus changed the title Go panic: cannot create frame session (context canceled) Go panic: cannot create frame session Dec 1, 2021
@inancgumus
Copy link
Member

Playwright cannot run this script and randomly fails as well 🤷

@tom-miseur can you provide us a script to reproduce the issue?

We need a script that:

  • Works with Playwright (that doesn't fail randomly)
  • Doesn't work with xk6-browser
  • Doesn't use any external websites

So we can locally reproduce the problem and fix it if there is one.

@inancgumus inancgumus added the blocked We need further action from something/someone to be able to work on the issue label Dec 6, 2021
@inancgumus inancgumus removed their assignment Dec 6, 2021
inancgumus added a commit that referenced this issue Dec 8, 2021
The error was:
panic: interface conversion: interface {} is nil, not
*common.ElementHandle

The cause of the error was trying to assert a nil result
in Frame.document to *ElementHandle. Of course, this is
probably the surface error. There may be other causes
for it, or maybe not.

It was hard to test Frame, so I used an abstraction called
FrameExecutionContext. There are a lot of problems are
happening with execution contexts. See: #125 and #49, for
example. So, it's better to make them testable, starting
here.

Fixes #53
@inancgumus inancgumus self-assigned this Dec 10, 2021
inancgumus added a commit that referenced this issue Dec 20, 2021
There were missing locks for execution contexts. This fix adds a
lock-based management for locks and uses an internal goroutine
to track whether an execution context is ready to use.

For now, it uses an infinite for loop with sleep. This is not
effective. So it should be fixed with something better.

There are some TODOs in the code that should be investigated.
Also the tests are missing from this commit. So they should
be added as well.

Fixes #125
@inancgumus inancgumus removed the blocked We need further action from something/someone to be able to work on the issue label Dec 24, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
bug Something isn't working next Might be eligible for the next planning (not guaranteed!)
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants