Chromedp: WaitReady/WaitVisible occasionally time out

[kjk]

Using latest chromedp as of 2018-01-14.

The relevant code snippet: https://gist.github.com/kjk/dcadf02391b949e8cdf79c1f5dfb503b

I navigate to a page and use WaitReady to wait for a simple selector (element id). Performance is very unpredictable:

googleSearchPage: Navigate() took 264.901601ms
googleSearchPage: WaitReady() took 567.942913ms
googleSearchPage: Nodes() took 1.022337106s
query: 'epub reader', 14 nodes.
googleSearchPage: Navigate() took 147.584583ms
googleSearchPage: WaitReady() took 10.718708228s
googleSearchPage: Nodes() took 315.006303ms
query: 'epub reader', 10 nodes.
googleSearchPage: Navigate() took 148.665099ms
googleSearchPage: WaitReady() took 10.783208824s
googleSearchPage: Nodes() took 417.417634ms
query: 'epub reader', 10 nodes.
googleSearchPage: Navigate() took 155.791276ms
googleSearchPage: WaitReady() took 712.509751ms
googleSearchPage: Nodes() took 269.002505ms
query: 'epub reader', 10 nodes.
googleSearch('epub reader', 4) took 25.523793214s

It varies between 0.5 sec to 10 sec.

I can tell visually that the results are available much faster.

Also, if I replace WaitReady with just time.Sleep(time.Second) I always get the right results.

That suggests that WatiReady gets stuck for a long time roughly 50% of the time.

The same happens with WaitVisible.

As a side note: I don't know what's the difference between WaitVisible and WaitReady. It would be good to add a note to docs about it.

[devarsh]

For some reason, i've noticed WaitVisible/WaitReady randomly waiting infinitely for the node to exist, even when the page is loaded and element is present, I don't know if i'm doing anything wrong, but this has been happening randomly and haven't been able to trace whats causing this issue.

[nsmith5]

That ~10 second timeout could have something to do with the TODO statement here. I'm not sure what is broken about the WaitFrame function that the TODO is mentioning, but I imagine it is the culprit.

Here is the implementation for reference:

func (h *TargetHandler) WaitFrame(ctxt context.Context, id cdp.FrameID) (*cdp.Frame, error) {
    // TODO: fix this
    timeout := time.After(10 * time.Second)

    for {
        select {
        default:
            var f *cdp.Frame
            var ok bool

            h.RLock()
            if id == cdp.EmptyFrameID {
                f, ok = h.cur, h.cur != nil
            } else {
                f, ok = h.frames[id]
            }
            h.RUnlock()

            if ok {
                return f, nil
            }

            time.Sleep(DefaultCheckDuration)

        case <-ctxt.Done():
            return nil, ctxt.Err()

        case <-timeout:
            return nil, fmt.Errorf("timeout waiting for frame `%s`", id)
        }
    }
}

[daved]

This is creating exceptionally poor behavior for one of my projects as well.

[newdayrising]

Is it possible to get an update? Better to have definitive checks rather than sleeping and hoping things load correctly.

[clanstyles]

Any updates on this?

[lived-tw]

Not sure if it is appropriate to say it here since this is for issue discussion. I found that this fork (github.com/mpppk/chromedp) had fixed the problem. Looks like the problem is due to async processing the events.

[mvdan]

Thanks all for the input. We use chromedp internally too, and have experienced this bug as well.

It appears that the problem is a race somewhere. For example, if one does a Click and then a WaitVisible for a node in the new page, you might get unlucky and you might wait for the node to be visible in the old frame. Of course, that may never happen, and the program can hit a timeout.

It's clear this needs to be fixed, even if it requires new API. For now it's unclear how we will fix it, though. We're designing v2 and we'll tackle this issue, so stay tuned.

[ckcks12]

Hello.

I figured out that

dom.ResolveNode().WithNodeID(ids[0]).Do(ctxt, h) // sel.go waitReady()

is working well.

Even if there's no such node in Frame.Nodes which is retrieved from h.cur (also from cdp.EmptyFrameID), ResolveNode() returns exactly what we are seeking.

I hope this may help you tho.

[mvdan]

Hi all,

Just as a quick update - the refactor branch is far from finished, but I believe this issue is already fixed there. In particular, the internal design has been rewritten so that events and commands are handled synchronously, and the wait functions no longer get stuck like they did before.

A nice result of that refactor is that there are less mutexes than before, and those internal timeouts and sleeps are now gone. As far as I can tell, go test is now stable, passes all tests, and consistently takes ~10s total on my laptop - much less than before.

We're far from finishing the v2 rewrite, but any feedback is appreciated. For example, if you'd like to see this fix ship in a beta release, you could help us out by testing the refactor branch and letting us know if you still encounter any bugs.

And, if you need some help getting started with the new API, see example_test.go. Just remember that this is a work in progress, and there probably will be more API-breaking changes as we move forward.

Thanks!

[mvdan]

The refactor branch has been merged into master, so I'm going to close this issue as fixed. We'll probably release an alpha soon. Until then, feel free to use a commit from master; all tests pass, and we're experimenting with it ourselves, so it should be pretty stable.

And of course, if you still encounter this issue or any other bugs, do let us know.