"PixieBrix could not run on page" error when opening sidebar

[twschiller]

Steps to reproduce

• Tested on 1.7.4-beta.3
• Video: https://www.loom.com/share/53868abef57a47e2a3cca79620602631
• Activate "LinkedIn organization demo bricks" brick from Pixies team
• Visit https://www.linkedin.com/company/tesla-motors/
• Toggle the sidebar

Expected Result

• Hacker News search results show in the sidebar panel

Actual Result

• Sidebar shows no panels
• After 2-3 seconds, PixieBrix opens up a new tab with "PixieBrix could not run on page" error

Related Conversations

• Also impacting playground sidebars for some @MMirandi : https://pixiebrix.slack.com/archives/C03RA8CFW8L/p1661008724190219

[fregante]

I was able to reproduce this once by reinstalling PB:

1. The sidebar’s own __getTabData call is being retried multiple times
2. This means that the content script’s PING_SIDEBAR call is temporarily ignored by the sidebar because it doesn't yet know its own tabId

Step 1 is kinda crazy because any runtime context should be able to respond to that call immediately and the background page is presumably ready to answer at all times, the message should not fail even if the background page is "processing".

I'll try to find out why this is happening.

[fregante]

Reproducibility

The general issue somewhat reproducible because this is simply a timeout issue due to the lengthy insertion sequence:

1. Page load
2. Content script load
3. Sidebar load

This has to happen within 4s from the user click, as defined by the timeout in the browser action handler.

To reproduce it:

1. Refresh LinkedIn
2. Immediately click the browser action
3. With some luck, it will take long enough to fail

[fregante]

I might have found one of the many reasons the sidebar loads slowly: off-site fonts.

Wow.

Look at the timestamps of the contentscript retries and error and then compare it to the first log by the sidebar. The JS was run 9 whole seconds after the timeout.

This is highly variable and depends on a third party, this is why it's hard to reproduce it.

I have a couple of PRs in the pipeline to address sidebar speed.

[twschiller]

This is highly variable and depends on a third party, this is why it's hard to reproduce it.

Yes, and will also depend on 1) if the user is new (are the fonts in cache), and 2) if Chrome decides to go grab it anyway

You can likely turn on network throttling to more reliable reproduction

[twschiller]

@fregante I cut a build 1.7.5-beta.4 with the following:

• #4078: Instant sidebar loading via browserAction #4099
• #4058: Fix content script race condition with messenger #4076
• #4021: Replace confusing "error modal in option page" UI with a plain alert #4080
• #4021: Stop opening the options page when the sidebar fails to open #4079

I'm still getting the original issue when I first activate the "LinkedIn organization demo bricks" blueprint (even when waiting for the content script to load). After I reload the extension background page the problem goes away

Update: not able to reproduce the problem reliably. But it's worrisome for the playground flow for new users. I guess this could be Google font related...

Screenshot from the console

[fregante]

In case of extreme font loading delays, the sidebar context would not receive any messages nor print any logs. It doesn't look like it's the case in the screenshot.

Those warnings suggest that the sidebar context is receiving messages while the context is waiting for a __getTabData response (or rather, it failed).

Do you see what happens to that __getTabData? Is it being received by the background page?

I've been thinking about other ways to get the current tabId but there's nothing, they only suggest a ping to the runtime.

Side note: we should probably add a "context invalidated" notification in the sidebar and options page so we catch any such issues.

[twschiller]

Moving to 1.7.X to keep an eye on this, as the main regression/bug has been addressed

[twschiller]

Bringing back to 1.7.5. Is still a significant issue.

Reloading the background page solves the problem, so appears to be a problem with the background messenger getting into a bad state?

[fregante]

If it happens, could you post the full logs of the sidebar and background?

The only state we have I think is the "target name" and only in the requester. The background always knows its name without race conditions.

I'll try to replicate this again today. I haven't seen it since.

Reloading the background page solves the problem

I think "reloading the background page" means nearly reloading the whole extension since it will cause to reinject the content scripts, among others. if I remember correctly.

[fregante]

Personal notes:

How to reproduce it

I can replicate it by reinstalling the extension, like:

1. Install
2. Open blueprints
3. Activate "LinkedIn organization demo bricks"
4. Visit https://www.linkedin.com/company/tesla-motors/ in a new tab
5. Toggle sidebar

__getTabData is being retried:

but the background page is successfully responding to every message, so I need to find out why it's not being handled:

The options page also receives the message but does not handle it at all for some reason, perhaps it did not register the handler on the very first load? It does on successive loads.

Possible cause

I probably found the issue. This PR actually made it worse because we're not registering any handlers in the options but now the options page is specifically responding with an error:

• Retry if registerMethods hasn't been called yet webext-messenger#77

It feels like the runtime.sendMessage broadcast is actually a broadcast rather than a sequential message until one is found. This would explain why the background page is responding, but its value is lost: the options page is responding first.