1001816 - Add To Search Bar: Custom search engines are lost on restart

Status: RESOLVED INVALID

(Firefox :: Search, defect)

Description

[Gian-Carlo Pascutto [:gcp]]

Current Nightly. Session restore "show my windows and tabs from last time" enabled.

1) Add search engines via either:
* Visit bugzilla, click add Bugzilla@mozilla
* Manage search engines->add more search engines
* http://mycroftproject.com/search-engines.html?name=google
2) Restart Firefox

Expected result: Search engines stay.
Actual result: Newly added search engines disappear.

This is a profile that has recently been reset, so it should be fairly "clean".

Comment 1

[castor]

I am also facing the same issue. I am on Firefox Beta channel and have sync set up on three systems. The profile is recently created and sync is working fine on all the three systems. However, my custom search engine that I installed from https://addons.mozilla.org/en-US/firefox/addon/google-ssl-243978/ is lost sometimes. I can't pinpoint exactly when its happening, but my suspicion is that If i restart my system its happening.

Comment 2

[Gian-Carlo Pascutto [:gcp]]

This is the contents of the profile/searchplugins dir, as you can see all engines that were installed are there, they just aren't picked up for some reason.

Could it be related to the .undefined extension? DuckDuckGo seems to work.

30/04/2014  10:12    <DIR>          .
30/04/2014  10:12    <DIR>          ..
30/04/2014  10:07             2.051 bugzillamozilla.undefined-0ucv.undefined
24/04/2014  17:22             2.051 bugzillamozilla.undefined-jp8m.undefined
27/04/2014  11:38             2.051 bugzillamozilla.undefined-ovgb.undefined
24/04/2014  11:35             2.051 bugzillamozilla.undefined.undefined
24/04/2014  08:39             1.937 duckduckgo.xml
27/04/2014  11:38             2.235 google-belgi-ssl.undefined-ekrv.undefined
24/04/2014  17:29             2.235 google-belgi-ssl.undefined.undefined
30/04/2014  10:12             2.508 google-belgi.undefined.undefined
24/04/2014  11:09             1.334 google-benl.undefined-jdyr.undefined
24/04/2014  08:40             1.334 google-benl.undefined.undefined
28/04/2014  16:46             8.276 google-ssl.undefined.undefined
27/04/2014  11:39             1.611 mozilla-dxr.undefined.undefined
24/04/2014  11:09             1.603 mozilla-mxr.undefined-16bi.undefined
24/04/2014  08:40             1.603 mozilla-mxr.undefined.undefined
              14 File(s)         32.880 bytes

Comment 3

[Matthew N. [:MattN]]

There are multiple bugs with the same summary so we may want to dupe this but I haven't compared the quality of the reports.

Can you provide output from the browser console after startup when you have the pref browser.search.log set to true (maybe browser.search.update.log too)?

Comment 4

[castor]

I don't know if I got this right, but here is my browser console.

TypeError: aUrl is undefined urlbarBindings.xml:650
Could not read chrome manifest 'file:///W:/Program%20Files/Mozilla%20Firefox/chrome.manifest'.
WARN addons.xpi: Ignoring missing add-on in W:\Program Files\AVAST Software\Avast\WebRep\FF XPIProvider.jsm:7339
Bootstrapped manifest not allowed to use 'component' directive. chrome.manifest:1
Bootstrapped manifest not allowed to use 'contract' directive. chrome.manifest:2
Bootstrapped manifest not allowed to use 'category' directive. chrome.manifest:3
Bootstrapped manifest not allowed to use 'resource' directive. chrome.manifest:6
Could not read chrome manifest 'file:///W:/Program%20Files/Mozilla%20Firefox/browser/extensions/%7B972ce4c6-7e08-4474-a285-3208198ce6fd%7D/chrome.manifest'.
While creating services from category 'profile-after-change', could not create service for entry 'Disk Space Watcher Service', contract ID '@mozilla.org/toolkit/disk-space-watcher;1'
Warning: unrecognized command line flag -jsconsol
 nsBrowserContentHandler.js:792
Selector expected.  Ruleset ignored due to bad selector. lastpass.css:15
Error in parsing value for 'background'.  Declaration dropped. lastpass.css:17
Unknown property '-moz-border-radius'.  Declaration dropped. lastpass.css:17
SearchService.init
metadata init: starting
metadata init: complete
_asyncInit start
_asyncLoadEngines: start
Expected end of value but found 'solid'.  Error in parsing value for 'border-width'.  Declaration dropped. button.css:16
Unknown property 'user-select'.  Declaration dropped. panel.css:232
Unknown property 'user-select'.  Declaration dropped. panel.css:506
Error in parsing value for 'background'.  Declaration dropped. panel.css:543
Error in parsing value for 'background'.  Declaration dropped. panel.css:544
Error in parsing value for 'background'.  Declaration dropped. panel.css:545
Expected 'none' or URL but found 'progid'.  Error in parsing value for 'filter'.  Declaration dropped. panel.css:547
Error in parsing value for 'background'.  Declaration dropped. panel.css:552
Error in parsing value for 'background'.  Declaration dropped. panel.css:553
Error in parsing value for 'background'.  Declaration dropped. panel.css:554
Expected 'none' or URL but found 'progid'.  Error in parsing value for 'filter'.  Declaration dropped. panel.css:556
Error in parsing value for 'background'.  Declaration dropped. panel.css:561
Error in parsing value for 'background'.  Declaration dropped. panel.css:562
Error in parsing value for 'background'.  Declaration dropped. panel.css:563
Error in parsing value for 'background'.  Declaration dropped. panel.css:564
Expected 'none' or URL but found 'progid'.  Error in parsing value for 'filter'.  Declaration dropped. panel.css:566
Expected 'none' or URL but found 'alpha('.  Error in parsing value for 'filter'.  Declaration dropped. bootstrap.css:10
Expected 'none' or URL but found 'alpha('.  Error in parsing value for 'filter'.  Declaration dropped. bootstrap.css:14
Unknown property '-moz-border-radius'.  Declaration dropped. bootstrap.css:40
not well-formed messages.json:1
_asyncLoadEngines: loading from cache directories
_loadEnginesFromCache: Loading from cache. 7 engines to load.
_addEngineToStore: Adding engine: "Amazon.com"
_addEngineToStore: Adding engine: "Bing"
_addEngineToStore: Adding engine: "eBay"
_addEngineToStore: Adding engine: "Google"
_addEngineToStore: Adding engine: "Twitter"
_addEngineToStore: Adding engine: "Wikipedia (en)"
_addEngineToStore: Adding engine: "Yahoo"
_asyncLoadEngines: done
_buildSortedEngineList: building list
_buildSortedEngineList: using db for order
_asyncInit: Completed _asyncInit
Key event not available on some keyboard layouts: key="h" modifiers="control alt" browser.xul
Key event not available on some keyboard layouts: key="x" modifiers="accel,alt" browser.xul
Key event not available on some keyboard layouts: key="g" modifiers="alt control" browser.xul
TypeError: aUrl is undefined urlbarBindings.xml:650
POST https://lastpass.com/login_check.php [HTTP/1.1 200 OK 2403ms]
POST http://evsecure-ocsp.thawte.com/ [HTTP/1.1 200 OK 1810ms]
POST http://evsecure-ocsp.thawte.com/ [HTTP/1.1 200 OK 1498ms]
GET https://token.services.mozilla.com/1.0/sync/1.5 [HTTP/1.1 200 OK 3104ms]
GET https://bay168.mail.live.com/default.aspx [HTTP/1.1 200 OK 5008ms]
Direct3D 9 DeviceManager Initialized Successfully.
Driver: igdumdx32.dll
Description: Mobile Intel(R) 965 Express Chipset Family
Version: 8.14.10.1930
POST http://ocsp.digicert.com/ [HTTP/1.1 200 OK 265ms]
POST http://ocsp.digicert.com/ [HTTP/1.1 200 OK 266ms]
POST http://sb.symcd.com/ [HTTP/1.1 200 OK 1170ms]
POST http://sb.symcd.com/ [HTTP/1.1 200 OK 1232ms]
GET https://sync-10-us-west-2.sync.services.mozilla.com/1.5/81994/info/collections [HTTP/1.1 200 OK 1326ms]
POST http://ocsp.digicert.com/ [HTTP/1.1 200 OK 296ms]
POST http://ocsp.digicert.com/ [HTTP/1.1 200 OK 265ms]
GET https://sync-10-us-west-2.sync.services.mozilla.com/1.5/81994/storage/meta/global [HTTP/1.1 200 OK 343ms]
GET https://sync-10-us-west-2.sync.services.mozilla.com/1.5/81994/info/collections [HTTP/1.1 200 OK 344ms]
GET https://sync-10-us-west-2.sync.services.mozilla.com/1.5/81994/storage/crypto/keys [HTTP/1.1 200 OK 359ms]
GET https://sync-10-us-west-2.sync.services.mozilla.com/1.5/81994/info/collections [HTTP/1.1 200 OK 343ms]
GET https://sync-10-us-west-2.sync.services.mozilla.com/1.5/81994/storage/meta/global [HTTP/1.1 200 OK 359ms]
GET https://sync-10-us-west-2.sync.services.mozilla.com/1.5/81994/storage/clients [HTTP/1.1 200 OK 344ms]
POST https://sync-10-us-west-2.sync.services.mozilla.com/1.5/81994/storage/clients [HTTP/1.1 200 OK 359ms]
1398905694765	Services.HealthReport.HealthReporter	WARN	Saved state file does not exist.

1398905694765	Services.HealthReport.HealthReporter	WARN	No prefs data found.

SearchService.init
POST https://sync-10-us-west-2.sync.services.mozilla.com/1.5/81994/storage/forms [HTTP/1.1 200 OK 358ms]
POST https://sync-10-us-west-2.sync.services.mozilla.com/1.5/81994/storage/history [HTTP/1.1 200 OK 1404ms]
A promise chain failed to handle a rejection.

Date: Thu May 01 2014 06:24:44 GMT+0530 (India Standard Time)
Full Message: 
Full Stack: JS frame :: resource://gre/components/nsLivemarkService.js :: LS_getLivemark/< :: line 405
JS frame :: resource://gre/components/nsLivemarkService.js :: ETAT_handleCompletion :: line 144
native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0 nsLivemarkService.js:405
A promise chain failed to handle a rejection.

Date: Thu May 01 2014 06:24:46 GMT+0530 (India Standard Time)
Full Message: 
Full Stack: JS frame :: resource://gre/components/nsLivemarkService.js :: LS_getLivemark/< :: line 405
native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0 nsLivemarkService.js:405



~~~~~~~~~~~~~~~~~~~~~~~
Also my searchplugins folder shows 2 files.
google-ssl.undefined
google-ssl.undefined-l2au.undefined.


And they are missing from my search engines.

Comment 5

[Matthew N. [:MattN]]

(In reply to castor from comment #4)
> I don't know if I got this right, but here is my browser console.

This looks right. In the future, please attachment logs as attachments on the bug instead of inline in a comment.

> ~~~~~~~~~~~~~~~~~~~~~~~
> Also my searchplugins folder shows 2 files.
> google-ssl.undefined
> google-ssl.undefined-l2au.undefined.


The "undefined" as the suffix here and in comment 2 seems like it may be related. Can you attach search-metadata.json from your profile folder? You can access it from about:support by clicking the button on the "profile folder" row.

Comment 6

[castor]

Attachment: search-metadata.json

Attaching search-metadata.json from my profile folder.

Comment 7

[Matthew N. [:MattN]]

(In reply to castor from comment #6)
> Attaching search-metadata.json from my profile folder.

Thanks. This file is looking for "google-ssl.undefined.undefined" in the searchplugins folder but you have "google-ssl.undefined" (one less ".undefined") which is why it doesn't get loaded. I'll try take a look at where the undefined comes from.

Comment 8

[castor]

My apologies.... Copy/Paste error

The folder contains
google-ssl.undefined.undefined
google-ssl.undefined-l2au.undefined

Comment 9

[Matthew N. [:MattN]]

Could you also attach search.json?

Comment 10

[castor]

Attachment: search.json

Adding search.json

Comment 11

[Matthew N. [:MattN]]

I suspect the reason why the search plugins aren't loading is because none of the ones in the profile's searchplugins directory have an .xml extension and you are both running on Windows so the winPattern[1] is taking effect and considering the directory as "empty" for the purpose of search plugins.

I still have no idea where the "undefined"s are coming from though. I may need one of you to invalidate the cache with logging on in order to see the output. I'll first try to read through the code some more.

[1] https://mxr.mozilla.org/mozilla-central/source/toolkit/components/search/nsSearchService.js?rev=45cde2fa5cb2#3135

Comment 12

[Matthew N. [:MattN]]

It seems like we're going to have to do a migration to fix the undefined suffix for users who are already affected. This may involve removing winPattern from [1] above which seems reasonable to avoid the platform inconsistency.

Comment 13

[castor]

I don't know what anything of it means obviously, but if you need some testing or need some files from my profile, I'm here.

Comment 14

[Matthew N. [:MattN]]

Knowing how/where the search plugins were installed may help.

Comment 15

[castor]

(In reply to Matthew N. [:MattN] (behind on reviews) from comment #14)
> Knowing how/where the search plugins were installed may help.

If you are talking about technical stuff, I am not a developer and can't understand any of it.
But if you want to know from where I installed the search engine, I downloaded it from 
https://addons.mozilla.org/en-US/firefox/addon/google-ssl-243978/

I used Firefox Sync and it was installed on my other two computers.

Comment 16

[Matthew N. [:MattN]]

I see that _asyncLoadEnginesFromDir and _loadEnginesFromDir have always (in HG history anyways) validated  that the plugin's extension is XML (or SRC in the past) so these files wouldn't have been loaded before either. This makes

(In reply to castor from comment #15)
> (In reply to Matthew N. [:MattN] (behind on reviews) from comment #14)
> > Knowing how/where the search plugins were installed may help.
> But if you want to know from where I installed the search engine, I
> downloaded it from 
> https://addons.mozilla.org/en-US/firefox/addon/google-ssl-243978/

That's what I wanted to know :) Do you know when you installed it? Could you also reply with the creation and modification times of the 2 search plugin files from comment 8?

> I used Firefox Sync and it was installed on my other two computers.

Search plugins aren't synchronized (bug 444284) so I think you probably installed this manually unless you used some extension for this.

Comment 17

[castor]

I am now at work and don't have access to my home machine. I am having the same problem on my work computer too. Here are the timestamps for the files in searchplugins folder.

google-ssl.undefined.undefined
Date created: 4/29/2014 8:42 AM
Date Modified: 4/29/2014 8:42 AM

google-ssl.undefined-5i1c.undefined
Date created: 4/29/2014 5:42 PM
Date Modified:  4/29/2014 5:42 PM

Any may be you are right, I may have installed the search plugins manually on all the computers. I don't actually remember much about them.

I will be at work for the next 5-6 hours and I can provide you with any information (files) that you may need  to figure out and solve the problem. As I said earlier, I am having the same issue on this computer.

Comment 18

[Matthew N. [:MattN]]

If either of you can reproduce new searchplugins being created with "undefined" in their file name, it would be good to attach logs (see comment 3) from when the engine is added. If you can reproduce that then we can also send custom builds with additional logging as I can't reproduce this on Windows 7 with Nightly.

Comment 19

[castor]

(In reply to Matthew N. [:MattN] (behind on reviews) from comment #18)
> If either of you can reproduce new searchplugins being created with
> "undefined" in their file name, it would be good to attach logs (see comment
> 3) from when the engine is added. If you can reproduce that then we can also
> send custom builds with additional logging as I can't reproduce this on
> Windows 7 with Nightly.

Any idea how I can reproduce? Shall i delete the files manually from searchplugins folder and add it again?

Comment 20

[Matthew N. [:MattN]]

Add a different search engine from addons.mozilla.org or http://mycroftproject.com/dlstats.html

Comment 21

[castor]

(In reply to Matthew N. [:MattN] (behind on reviews) from comment #20)
> Add a different search engine from addons.mozilla.org or
> http://mycroftproject.com/dlstats.html

Unfortunately, I am not able to reproduce the problem. I added two search engines from addons.mozilla.org (duckduckgo and Google SSL Search). Both created .xml files in searchplugins folder and they are retained on browser restart and system restart. Everything so far is working as expected. I don't know how I can reproduce the problem again.

Comment 22

[Matthew N. [:MattN]]

OK, thanks for trying. It seems like there was a bug in the past that caused "undefined" in the filename and I suspect everything worked fine until the cache got invalidated e.g. with the version bump that just happened.

We should probably figure out the cause by finding the regression window for when the "undefined" got added to the search plugin filenames. Requesting regressionwindow-wanted for this.

Comment 23

[Gian-Carlo Pascutto [:gcp]]

Attachment: searchlog.txt

Comment 24

[Gian-Carlo Pascutto [:gcp]]

Attachment: search.json.friends.zip

This reproduced again this morning on current Nightly, the problem certainly isn't gone.

Comment 25

[Gian-Carlo Pascutto [:gcp]]

Attachment: searchlog_adding_again.txt

Log after adding the new engines (once again).

Checking the profile, the new engines have the .undefined.undefined extension.

Comment 26

[Gian-Carlo Pascutto [:gcp]]

Attachment: search_json_after_adding_again.zip

JSON after adding the engines again.

Comment 27

[Gian-Carlo Pascutto [:gcp]]

Attachment: searchlog_afteradd_restart.txt

Browser log after a restart where the problem *doesn't* reproduce and the engines are still visible.

Comment 28

[Gian-Carlo Pascutto [:gcp]]

For what it's worth, I can reproduce the engines being saved as .undefined.undefind on Firefox 29 beta 9 as well.

Comment 29

[Gian-Carlo Pascutto [:gcp]]

The .undefined.undefined reproduces as far back as Firefox 24, at least.

Comment 30

[Gian-Carlo Pascutto [:gcp]]

On the other hand, on my laptop, which is also running currently Nightly, adding a new search engine causes it to correctly get the .xml extension.

So it looks like there is a bug that can cause the profile to get in a kind of corrupted state where saving new engines is no longer possible. I think you'll have to trace where the .undefined.undefined comes from.

Comment 31

[Gian-Carlo Pascutto [:gcp]]

Matthew, can you put up a patch or build with the extra logging you need?

Comment 32

[Gian-Carlo Pascutto [:gcp]]

After spending a day debugging this: it's caused by an addon. Finding out which one.

Comment 33

[Gian-Carlo Pascutto [:gcp]]

In my case it's "Add to Search Bar 2.2".

Comment 34

[castor]

(In reply to Gian-Carlo Pascutto [:gcp] from comment #33)
> In my case it's "Add to Search Bar 2.2".

Yes, I have used Add to Search Bar too. I guess in my case, the search plugins started working again since I disabled "Add to Search Bar" a while ago.

Comment 35

[Gian-Carlo Pascutto [:gcp]]

I've uploaded a fixed version of the add-on here: https://dl.dropboxusercontent.com/u/32496746/add-to-searchbox%40maltekraus.de.22fix.xpi

The add-on is replacing some internal Firefox functions and referencing other Firefox internals when doing so. It broke when this bug changed some of them: https://bugzilla.mozilla.org/show_bug.cgi?id=862143 Note comment 8.

The reason for the replacement is that it claims the built-in Firefox version is buggy...would've been better to just report that bug, I'd think!

I might try to make a fixed version that no longer messes with Firefox internals and if needed fix the claimed bug, but not today.

Comment 36

[Matthew N. [:MattN]]

(In reply to Gian-Carlo Pascutto [:gcp] from comment #35)
> The add-on is replacing some internal Firefox functions and referencing
> other Firefox internals when doing so. It broke when this bug changed some
> of them: https://bugzilla.mozilla.org/show_bug.cgi?id=862143 Note comment 8.

Thanks for figuring this out.

It sounds like we should mark it incompatible with version 24 and higher on AMO for now. Do you think the problem it causes is worth disabling for 112,000 users? Are there remaining benefits of the extension even when this bug is encountered? I'm trying to figure out the cost/benefit ratio.

> The reason for the replacement is that it claims the built-in Firefox
> version is buggy...would've been better to just report that bug, I'd think!
> 
> I might try to make a fixed version that no longer messes with Firefox
> internals and if needed fix the claimed bug, but not today.

Do you mean you will upstream the changes by contacting the author? (now CC'd)

Malte, are you aware of this bug and are you planning on fixing it?

Comment 37

[Gian-Carlo Pascutto [:gcp]]

>It sounds like we should mark it incompatible with version 24 and higher on AMO for now. Do you think the problem it causes is worth disabling for 112,000 users?

I'm not sure - I've used it for a long time without problems even since version 24. Given that as far as I can see the failure has been there for a while, I'd have to guess a recent change on our side (search engine mechanics or how and when we update them) exposed the bug or made it happen more often.

So it's possible this is now broken for everyone, but it's also possible the majority of people are using it without problems. I don't know. That said, the reviews on AMO seem to indicate the problem is common on Firefox updates: https://addons.mozilla.org/en-US/firefox/addon/add-to-search-bar/

Given that we know how to fix it, I'd rather try to get an update out rather than block it.

>Are there remaining benefits of the extension even when this bug is encountered?

There's no benefit to the add-on if the bug triggers as regularly as it does now and in fact it's pretty annoying.

>Do you mean you will upstream the changes by contacting the author? (now CC'd)

I mailed him indicating what needs to be fixed.

If there is no reply, and the license allows it, I would consider uploading the fixed version on a.m.o myself.

Comment 38

[Malte Kraus]

I just uploaded a version with your fix to AMO. Thanks for that.

I'll check in the next days if I can make the disappeared engines reappear (without creating duplicates for people who recreated the search engines). I'll also check if that monkey-patching is still necessary 8 years after I added it.

Comment 39

[Gian-Carlo Pascutto [:gcp]]

Awesome, thanks. If you find that CreateUnique is still buggy, please file a bug (you can CC me) and we'll try to get it fixed.