Closed Bug 1460607 Opened 6 years ago Closed 6 years ago

Tree Style Tabs addon broken in Nightly 20180510100205

Categories

(WebExtensions :: General, defect)

Product:
WebExtensions
Component:
General
Version:
62 Branch
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(firefox62 fixed)

Status:
RESOLVED FIXED
Tracking Flags:
Tracking Status
firefox62 --- fixed

People

(Reporter: mitchell, Unassigned)

References

Details

(Keywords: regression) 

User Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:62.0) Gecko/20100101 Firefox/62.0
Build ID: 20180510100205

Steps to reproduce:

Existing installation of TST (webextension, of course) version stopped working in the current and previous nightly builds.


Actual results:

Only a grey sidebar with a loading spinner is visible. Addon acts like JS crashed early in loading. Does not respond to clicking its button (should toggle sidebar) or F1 (same). Preference page does not populate.

Here is the console output when debugging the addon:

https://pastebin.mozilla.org/9085100


Expected results:

Should work.
Reproduced on a new profile. Installing the addon works fine, but after restart it fails.

Weirdly, loading back into my usual profile, and TST works again. I guess the error is somewhat inconsistent?
I can Reproduce the problem after restart to update Nightly from About Nightly.

Error in Browser Console:

Error: Invalid sidebar broadcaster specified: treestyletab_piro_sakura_ne_jp-sidebar-action browser-sidebar.js:423:
Status: UNCONFIRMED → NEW
status-firefox62: --- → affected
Component: Untriaged → WebExtensions: General
Ever confirmed: true
Product: Firefox → Toolkit
Version: 61 Branch → Trunk
Version: Trunk → 62 Branch
(In reply to Alice0775 White from comment #2)
 
> Error in Browser Console:
> 
> Error: Invalid sidebar broadcaster specified:
> treestyletab_piro_sakura_ne_jp-sidebar-action browser-sidebar.js:423:

the error message is unrelated to this bug.
STR
1. install Tree Style Tab from https://addons.mozilla.org/en-US/firefox/addon/tree-style-tab/
2. Open Developer toolbar (Shift+F2)
3. Type 'restart'(without quotation) and keypress [enter] in Developer toolbar
4. Repeat step 3 several times(at least 3 times)

Regression window:
https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=b17ded2f29626043dbf28bd4cd76c7bdcf91a40c&tochange=7201982e0481cbc237a21756ef88827c4dcfb2c8

Regressed by: Bug 1457224
Blocks: 1457224
Keywords: regression
I suspect this is a variant of bug 1369841.  That bug talks about content scripts, but I suspect this is the same issue with messaging between the sidebar page and the background page.
Depends on: 1369841
I couldn't reproduce this problem on my environment: Nightly 62.0a1 (build id: 20180517100441) on Windows, with TST 2.4.21.

Basically TST's sidebar and background page are designed to work even if sidebar is loaded earlier than background page. They both scripts send ping-like message to each other and wait until both scripts successfully receive response. So I think that the initialization failure told at the initial comment might be caused by different reason.
In that case, this bug should be tracked in the TST issue tracker.  Piro, if you can isolate this to a specific issue with a webextension API, then we can pick it up from there.
There are some similar issues exist at TST's issue tracker:

The TST sidebar keeps reloading · Issue #1818 · piroor/treestyletab
https://github.com/piroor/treestyletab/issues/1818

Sidebar does not display, only animated blob · Issue #1812 · piroor/treestyletab
https://github.com/piroor/treestyletab/issues/1812
I can still reproduce the problem at every Nightly(20180517100441) start up with new profile +TST2.4.21 installed.
(In reply to Andrew Swan [:aswan] from comment #7)
> In that case, this bug should be tracked in the TST issue tracker.  Piro, if
> you can isolate this to a specific issue with a webextension API, then we
> can pick it up from there.

Let's move to TE::Addons for now.
status-firefox62: affected → fix-optional
Component: WebExtensions: General → Add-ons
Flags: needinfo?(aswan)
Product: Toolkit → Tech Evangelism
Version: 62 Branch → Firefox 62
I use TST and the problem appeared to be fixed in the last couple of days. Mitchell, can you confirm?
Flags: needinfo?(mitchell)
I can still reproduce the problem on Win10 Nightly62.0a1x64(20180523100147) with only installed TST 2.4.21
(In reply to Mike Taylor [:miketaylr] (62 Regression Engineering Owner) from comment #10)
> Let's move to TE::Addons for now.

works for me
Flags: needinfo?(aswan)
(oops, that ni? was unintentional)
No, this happened again today for me.
Flags: needinfo?(mitchell)
I've found an exception of the story:

(In reply to YUKI "Piro" Hiroshi from comment #6)
> Basically TST's sidebar and background page are designed to work even if
> sidebar is loaded earlier than background page. They both scripts send
> ping-like message to each other and wait until both scripts successfully
> receive response.

On the other hand, the addon contains a library to share configurations between namespaces via local storage, and its initialization process will fail if any script which cannot access to `storage.local` is loaded before background page is loaded. So I've done a change to wait initialization of content scripts until background page is loaded. A development build containing the change is available:
https://piro.sakura.ne.jp/xul/xpi/nightly/treestyletab-we.xpi
Does it solve the problem or not?
I can still reproduce the issue with the dev build of tst 2.4.21.6854.
(In reply to Alice0775 White from comment #17)
> I can still reproduce the issue with the dev build of tst 2.4.21.6854.

Could you cooperate to research what happens when the "infinite loading" happens? Steps to research: 

 1. Start addon debugger and attach debugger to the page "/sidebar/sidebar.html".
    Instructions:
      https://github.com/piroor/treestyletab/wiki/How-to-inspect-tree-of-tabs#how-to-inspect-the-sidebar
 2. Choose "Console" tab in the remote debugger.
 3. Focus to the command line at the bottom of the debugger window, and run `gMetricsData.toString()`.

The last step reports a details of the initialization process successfully. If the sidebar is correctly loaded, the log will be:

```
total 2600 msec for 57 tabs
0: Loaded
632: init start
247: browser.tabs.query, configs.$loaded
570: applyStyle, waitUntilBackgroundIsReady and retrieveAllContextualIdentities
1: getEffectiveWindowCache start
12: (async) calculateDefaultSizes
5: (async) initializing contextual identities
2: (async) tabContextMenu.init
289: (async) getting kWINDOW_STATE_SCROLL_POSITION
396: getEffectiveWindowCache get {"cache":false}
6: getEffectiveWindowCache fail
402: (async) read cached sidebar contents
392: (async) getting registered addons and scroll lock state
153: rebuildAll (from scratch)
471: inheritTreeStructure: kCOMMAND_PULL_TREE_STRUCTURE
1: applyTreeStructureToTabs: start
0: applyTreeStructureToTabs: preparation
27: applyTreeStructureToTabs: attach/detach
11: applyTreeStructureToTabs: collapse/expand
1: inheritTreeStructure: applyTreeStructureToTabs
509: (async) inheritTreeStructure
0: start to listen events
49: apply configs
1117: (async) main
1103: (async) parallel initialization tasks
5: applying scroll position
30: init end
```

On the other hand, on such "infinite loading" cases, some parts will be missing and the result will become short. So it helps me knowing what process failed on the case.
Flags: needinfo?(alice0775)
While ping-pong was displayed on the side bar of TST, I executed these command according to comment#18.
The debugger console display the followings.

gMetricsData.toString()
"total 33 msec for 0 tabs
1: Loaded
32: init start"
Flags: needinfo?(alice0775)
(In reply to Alice0775 White from comment #19)
> While ping-pong was displayed on the side bar of TST, I executed these
> command according to comment#18.
> The debugger console display the followings.
> 
> gMetricsData.toString()
> "total 33 msec for 0 tabs
> 1: Loaded
> 32: init start"

Thanks a lot! The log says that initialization process is failed on very early step: that is completely unexpected for me. Could you collect very detailed logs with a special debug build again? Here instructions:
https://github.com/piroor/treestyletab/issues/1735#issuecomment-392735500
(Because the debug log will become very long, please post debug log to the GitHub issue instead of here.)
(In reply to YUKI "Piro" Hiroshi from comment #20)
> (In reply to Alice0775 White from comment #19)
> > While ping-pong was displayed on the side bar of TST, I executed these
> > command according to comment#18.
> > The debugger console display the followings.
> > 
> > gMetricsData.toString()
> > "total 33 msec for 0 tabs
> > 1: Loaded
> > 32: init start"
> 
> Thanks a lot! The log says that initialization process is failed on very
> early step: that is completely unexpected for me. Could you collect very
> detailed logs with a special debug build again? Here instructions:
> https://github.com/piroor/treestyletab/issues/1735#issuecomment-392735500
> (Because the debug log will become very long, please post debug log to the
> GitHub issue instead of here.)


The instruction(https://github.com/piroor/treestyletab/wiki/How-to-inspect-tree-of-tabs#how-to-collect-debug-logs-of-tst) say

> How to collect debug logs of TST?

> 1. Go to TST's configurations and turn the checkbox "Development" => "Debug mode" on.
> 2. Start remote debugger for TST.
> 3. Choose the "Console" tab.
> 4. Click the dustbox icon to clear old logs.
> 5. Run steps to reproduce the problem you met.

Since it is necessary to restart the browser in order to reproduce the problem.
How can I get the debug log from startup of browser?
With cooperation of Alice0775 and more people, I realized that there was a recursive "await" triggered by browser.runtime.sendMessage(). I've introduced some changes to avoid such a recursion, and now it looks working as expected.
https://github.com/piroor/treestyletab/issues/1735#issuecomment-392849039
I can no longer reproduce with TST ver.2.4.23

@mitchell, 
Could you please test with latest TST?
Flags: needinfo?(mitchell)
I've just tried 10 restarts or so with no reproduction. I guess this can be closed as fixed.

I'm very sorry I wasn't able to help with debugging, I've been away for a week. Thanks for the help, piroor!
Flags: needinfo?(mitchell)
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
FYI, I can still reproduce the problem in Always Private Browsing Mode. 
But this is a different cause (See https://bugzilla.mozilla.org/show_bug.cgi?id=1465537#c19 )
Component: Add-ons → General
Product: Tech Evangelism → WebExtensions
Version: Firefox 62 → 62 Branch
You need to log in before you can comment on or make changes to this bug.