1267719 - Searchbar broken/empty on firstrun after upgrade to 46 - Services.search.currentEngine is null and more

Status: RESOLVED INCOMPLETE

(Firefox :: Search, defect, P3)

Description

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

[Tracking Requested - why for this release]:

Firefox 46.0 64 bit on Windows 8.1

After launching a profile with Firefox 46.0 for the first time, the search bar design is broken and the engines missing. Some errors from the console (no idea if some got already removed):

Timestamp: 26.04.2016 19:15:08
Error: TypeError: Services.search.currentEngine is null
Source File: resource://app/modules/BrowserUITelemetry.jsm
Line: 574

Timestamp: 26.04.2016 19:15:08
Error: engine is null
Source File: resource://app/modules/ContentSearch.jsm
Line: 489

Timestamp: 26.04.2016 19:15:08
Error: TypeError: this.defaultEngine is undefined
Source File: chrome://browser/content/contentSearchUI.js
Line: 616

Timestamp: 26.04.2016 19:15:13
Error: [Exception... "[JavaScript Error: "Services.search.defaultEngine is null" {file: "resource://app/modules/UITour.jsm" line: 1965}]'[JavaScript Error: "Services.search.defaultEngine is null" {file: "resource://app/modules/UITour.jsm" line: 1965}]' when calling method: [nsIBrowserSearchInitObserver::onInitComplete]"  nsresult: "0x80570021 (NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS)"  location: "JS frame :: resource://gre/components/nsSearchService.js :: onSuccess :: line 3750"  data: yes]
Source File: resource://gre/components/nsSearchService.js
Line: 3752

Timestamp: 26.04.2016 19:15:13
Error: Error: Invalid search engine
Source File: resource://gre/modules/SearchSuggestionController.jsm
Line: 126

Timestamp: 26.04.2016 19:15:13
Error: TypeError: currentEngine is null
Source File: chrome://browser/content/search/search.xml
Line: 1093

Timestamp: 26.04.2016 19:17:23
Error: TypeError: this.currentEngine.speculativeConnect is not a function
Source File: chrome://browser/content/search/search.xml
Line: 477

Reproduced with 2/2 profiles.

Comment 1

[Florian Quèze [:florian]]

Is this something you can reliably reproduce?

If you have access to an affected profile, could you please provide the values of these preferences:
browser.search.countryCode
browser.search.isUS
browser.search.region

And it would be very helpful if you could attach the search.json.mozlz4 file from the profile. Thanks!

Comment 2

[Florian Quèze [:florian]]

When you say it's "on firstrun", do you mean that it's working fine after a restart?

Comment 3

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Attachment: search.json.mozlz4

Yes, it works after a restart. I can also mail you such a profile (15 MB zipped).

Same values for the preferences in 45.0.2 and 46.
browser.search.countryCode DE
browser.search.isUS false
browser.search.region DE

The attached search.json.mozlz4 remains unchanged after the first run in Firefox 46.

I can't reproduce with a new profile and this might only happen after a profile got moved (I clone my test profiles, and this would also explain why it only happens on the first run).

Comment 4

[Mike Kaply [:mkaply]]

What language version of Firefox was this?

Comment 5

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

en-US. Language packs are installed, but not active.

Comment 6

[Mike Kaply [:mkaply]]

What was your default search engine set to?


I just tested a simply upgrade scenario through a German proxy and it worked for me.

Create new profile on Firefox 45 US.
Verified that search engine is Google.
Verified that region/language is DE.
Close browser.
Start Firefox 46 with the same profile.
Verified that Google is still the search engine and has the proper new codes.

Comment 7

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Default engine is Google. It doesn't reproduce with a new profile, see comment 3.

Comment 8

[Florian Quèze [:florian]]

(In reply to Sebastian H. [:aryx][:archaeopteryx] from comment #3)
> Created attachment 8745502 [details]
> search.json.mozlz4
> 
> Yes, it works after a restart. I can also mail you such a profile (15 MB
> zipped).

If you have a profile that can be installed on 45.0.2 to reproduce, I would be interested.

Comment 9

[Florian Quèze [:florian]]

Sebastian sent me a test profile, unfortunately I still can't reproduce. However, he gave me a debug log of the search service, which contains some interesting lines:

1461765880803   addons.xpi-utils        WARN    Disabling foreign installed add-
on [e-mail] in winreg-app-global
1461765880820   addons.xpi      WARN    Add-on [e-mail]
.org is missing bootstrap method uninstall
1461765880825   addons.xpi      WARN    Add-on [e-mail]
.org is missing bootstrap method install
1461765880831   addons.xpi      WARN    Add-on [e-mail]
.org is missing bootstrap method uninstall
1461765880836   addons.xpi      WARN    Add-on [e-mail]
.org is missing bootstrap method install
1461765880842   addons.xpi      WARN    Add-on [e-mail]
.org is missing bootstrap method uninstall
1461765880847   addons.xpi      WARN    Add-on [e-mail]
.org is missing bootstrap method install
*** Search: SearchService.init
*** Search: _asyncInit start
*** Search: _asyncLoadEngines: start
*** Search: _asyncFindJAREngines: looking for engines in JARs
*** Search: _asyncFindJAREngines: resource://search-plugins/ isn't registered
*** Search: _asyncLoadEngines: Absent or outdated cache. Loading engines from di
sk.
*** Search: _asyncLoadEngines: loading user-installed engines from the obsolete
cache
*** Search: _loadEnginesFromCache: Loading 8 engines from cache
*** Search: _loadEnginesFromCache: skipped 8 read-only engines.
*** Search: _buildCache: Could not write to cache file: cannot write without any
 engine.
*** Search: _buildSortedEngineList: building list
*** Search: _asyncInit: Completed _asyncInit


"_asyncFindJAREngines: resource://search-plugins/ isn't registered" is especially interesting.

When I try Sebastian's profile locally, I don't get the "missing bootstrap method" lines at startup, they appear only if I go in the add-on manager and click "Check for updates".

So I'm guessing add-on updates during startup are somehow messing with the registration of the "search-plugins" resource; maybe if language packs get enabled/disabled during updates?

The "Could not write to cache file: cannot write without any engine." error message is the safety net we added in bug 1255605 to prevent us from corrupting the profile. This is the reason why things work at the next restart.

Comment 10

[:shell escalante]

still trying troubleshooting - will raise priority once determine cause.  

florian suggested asking mossop who might know a lead for if something has changed in add-on updating call.  Put andy as back-up - in case Mossop is out of reach.

Comment 11

[Dave Townsend [:mossop]]

(In reply to :shell escalante from comment #10)
> still trying troubleshooting - will raise priority once determine cause.  
> 
> florian suggested asking mossop who might know a lead for if something has
> changed in add-on updating call.  Put andy as back-up - in case Mossop is
> out of reach.

Nothing has changed there in a while that I can think of.

Comment 12

[Mike Kaply [:mkaply]]

Is this the first time we've sent down a new visibleDefaultEngines list and had the search plugins reconstructed?

Comment 13

[Florian Quèze [:florian]]

(In reply to Mike Kaply [:mkaply] from comment #12)
> Is this the first time we've sent down a new visibleDefaultEngines list and
> had the search plugins reconstructed?

The "resource://search-plugins/ isn't registered" error doesn't seem related to the visibleDefaultEngines change.

Comment 14

[Florian Quèze [:florian]]

Adding debug logging to nsChromeRegistryChrome::ManifestResource shows that we are re-registering the search-plugins resource each time we update a language pack. I don't thinks we are ever un-registering it though, and in all cases it maps to chrome://browser/locale/searchplugins/, so this shouldn't be the actual problem.

However, the "resource://search-plugins/ isn't registered" message may be slightly misleading: the message is displayed whenever creating a channel for resource://search-plugins/list.txt fails, and the search-plugins resource not being registered is one reason for failing to create a channel, but most likely not the only reason.

Comment 15

[Florian Quèze [:florian]]

I tried to reproduce on Windows (where the add-on update wizard isn't behaving exactly like on Mac and Linux), but couldn't reproduce there either. I'm going to give up on this for now, unless I/we find new ideas.

Comment 16

[Liz Henry (:lizzard) (relman/hg->git project)]

I'll track this for now for 46, though no one has been able to reproduce the issue yet.

Comment 17

[Liz Henry (:lizzard) (relman/hg->git project)]

Florian, would it help to have QE try reproducing this too? Is anyone else still investigating?

Comment 18

[Florian Quèze [:florian]]

(In reply to Liz Henry (:lizzard) (needinfo? me) from comment #17)
> Florian, would it help to have QE try reproducing this too?

Yes. aryx can give them the test profile that he uses to reproduce.

> Is anyone else still investigating?

AFAIK, no.

Comment 19

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

So this call fails:
> http://mxr.mozilla.org/mozilla-release/source/toolkit/components/search/nsSearchService.js#3569
glandium shed some light on the situation:
> glandium: Aryx: are you sure there's not a race condition, where something is trying to use it before it's registered?
> Aryx: yes, but not yet on startup, and that only when i launch it the first time with 46 (i have a backup so i can reproduce)
> Aryx: yes, nsSearchService.js ends up calling it too early
> glandium: Aryx: when does nsSearchService.js call it?
> glandium: Aryx: if it's during component registration, you're essentially screwed
For progress, a stacktrace is needed.

Comment 20

[Florian Quèze [:florian]]

It would be nice to have a stack for the first call to Services.search.init (causing the "*** Search: SearchService.init" message in your debug log from comment 9).

Anybody knows if there's an easy way to know if we are done registering chrome files? Eg. a promise the async init code could wait for.

Comment 21

[Florian Quèze [:florian]]

Maybe something along the lines of:

let appStartup = Cc["@mozilla.org/toolkit/app-startup;1"]
                   .getService(Ci.nsIAppStartup);
if (appStartup.startingUp)
  /* wait for "final-ui-startup" notification */

I don't see any existing code using this pattern though.

Comment 22

[Florian Quèze [:florian]]

Attachment: Tentative patch

This delays the search service initialization until after the final-ui-startup notification, based on the idea I had in comment 21.

Comment 23

[Florian Quèze [:florian]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=97c9932ba341

Comment 24

[Florian Quèze [:florian]]

Sebastian, could you please try to reproduce with the try build fro comment 23 (http://archive.mozilla.org/pub/firefox/try-builds/[e-mail]-2627657a5b53abffd54220315362d2aed2af2236/try-win32/ ) and tell me if you can still reproduce the bug or if the patch fixes it?

Comment 25

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Hi Florian, the issue still reproduces with the provided Try build.

Comment 26

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Attachment: console log of try build

Comment 27

[Mike Connor [:mconnor]]

Florian, any update here?

Comment 28

[Florian Quèze [:florian]]

No, I've never been able to reproduce.

Comment 29

[Sylvestre Ledru [:Sylvestre]]

Moving to p3 because no activity for at least 1 year(s).
See https://github.com/mozilla/bug-handling/blob/master/policy/triage-bugzilla.md#how-do-you-triage for more information

Comment 30

[Sylvestre Ledru [:Sylvestre]]

Moving to p3 because no activity for at least 1 year(s).
See https://github.com/mozilla/bug-handling/blob/master/policy/triage-bugzilla.md#how-do-you-triage for more information

Comment 31

[Mike Kaply [:mkaply]]

With the switch of search engines out of language packs, this shouldn't be an issue anymore.

Since no one can recreate at this point, I'm going to mark incomplete.