Closed Bug 983571 Opened 6 years ago Closed 6 years ago

browser.bookmarks.autoExportHTML = true no longer works on 29.0a2 as of 03-13-2014

Categories

(Firefox :: Bookmarks & History, defect)

29 Branch
defect
Not set

Tracking

()

VERIFIED FIXED
Firefox 31
Tracking Status
firefox28 --- unaffected
firefox29 + verified
firefox30 + fixed
firefox31 --- fixed

People

(Reporter: the1edmeister, Assigned: mak)

References

(Blocks 1 open bug)

Details

(Keywords: regression, Whiteboard: p=3 s=it-31c-30a-29b.1 [qa-])

Attachments

(2 files, 2 obsolete files)

User Agent: Mozilla/5.0 (Windows NT 5.1; rv:27.0) Gecko/20100101 Firefox/27.0 (Beta/Release)
Build ID: 20140212131424

Steps to reproduce:

browser.bookmarks.autoExportHTML = true - no longer works - Aurora 29.0a2 as of 03-13-2014 version


Actual results:

bookmarks.html file isn't being created


Expected results:

bookmarks.html file should be created upon exiting Firefox.
could you please try to do a manual export to html from the Library and tell me if that one works?
Component: Untriaged → Bookmarks & History
Keywords: regression
Status: UNCONFIRMED → NEW
Ever confirmed: true
fwiw, this is very likely fixed in Nightly, so may be Aurora only
I just tried it in Nightly, didn't work there either.
Regression window(m-i)
Good:
https://hg.mozilla.org/integration/mozilla-inbound/rev/3a10c4605795
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:30.0) Gecko/20100101 Firefox/30.0 ID:20140207094102
Bad:
https://hg.mozilla.org/integration/mozilla-inbound/rev/9fb9effa74a6
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:30.0) Gecko/20100101 Firefox/30.0 ID:20140207094802
Pushlog:
http://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=3a10c4605795&tochange=9fb9effa74a6

Regressed by: 
	af5cdb31f131	Marco Bonardo — Bug 824433 - Bookmarks backup takes a long time to write out on shutdown. r=mano
Looks like the AsyncShutdown call may not work as expected in this case, before we were manually spinning the events loop and that was working fine.
Assignee: nobody → mak77
OS: Windows XP → All
Hardware: x86 → All
Just checked with clean profile, no auto backup of bookmarks at all, not even .json. Imported bookmarks, restarted again, still nothing.
json happens only on idle.
How long does it need to idle? I'll test that.
10 minutes, though if there is no backup or the last backup is old it will try in 5... btw, that's easier to check, just see in Library / import and backup / Restore menu, there should be the list of the latest automatic backups.
Let it idle for 12 minutes to be sure - no backups.
idle detection is not perfect (there is a bug there), so you should do multiple tests. As I said, please, check in the Library if you have backups for the last week or so.
also, if you can export a json backup from the Library Import and Backup / Backup menuitem, there is no issue, otherwise there may be a problem with your database, but that would be a separate bug.
The idle test I did before was with a clean profile I created on 2-26 to test something else, hadn't been used since. Hadn't been run long enough to make backups.

In my regular Nightly profile, used daily, there are daily .json backups up to 2-20. After that, they were generated erratically, at intervals up to 5 days, last one on 3-12. Tried adding a bookmark, letting it idle, closing and reopening, no new backup.

I'm usually answering email on my laptop while Nightly is running on my desktop, so it often sits idle. I normally get backups every day.
it may be an add-on or a complex webapp interacting with idle (See bug 973591 for example). It would be very nice to figure the reason in your case, may be a case we are not aware of. May you try disabling add-ons? Do you have some complex weabbps usually open that may be listening to idle times to do specific work?
I'm looking at telemetry daily, may decide to reduce idle time even further if I see a good number of clients on old backups.
Also, we create backups at no less than 24 hours, so if you have a backup for yesterday created at evening, one for today won't be created during morning or afternoon.
That said, this bug is about bookmarks.html, so you should probably file a bug apart for backups, and we can have the discussion there.
Failure is consistent in repeated tests, even with all add-ons disabled, and in clean test profile.

Filed Bug 983988
there's no relation between the 2 bugs.
See Also: 983988
ok, basically the issue is that we are using a profileBeforeChange blocker for this, unfortunately Sqlite.jsm (that we are using to make the html file) as well as Places, are both shutting down at profile-before-change. So we end up trying to use them too late, since the shutdown order is not predictable.

The funny thing is that the code inside the blocker function was throwing a "Phase profile-before-change has already begun, it is too late to register completion conditions.", this made me think we were adding the blocker too late, instead it was Sqlite.jsm trying to add a new blocker later...

Before using AsyncShutdown this was working cause we were spinning at profile-change-teardown, so we were sure to not run too late.

Summing up:
1. We need a profileChangeTeardown blocker
2. the "Phase has already begun" error should also print the name of the blocker we were trying to add, to avoid confusing its consumers.
3. Likely Sqlite.jsm should shutdown later (profile-before-change2) to allow its consumers to do shutdown work at profile-before-change. I will file a separate bug for this though, since it's not needed here and this fix should likely be uplifted.
Attached patch patch v1 (obsolete) — Splinter Review
when reviewing this, please keep in mind this bug is tracked for Beta, so the patch will be uplifted to it.
Attachment #8393737 - Flags: review?(dteller)
Flags: in-testsuite?
Comment on attachment 8393737 [details] [diff] [review]
patch v1

ugh, I forgot to update the error in AsyncShutdown
Attachment #8393737 - Attachment is obsolete: true
Attachment #8393737 - Flags: review?(dteller)
Attached patch patch v2 (obsolete) — Splinter Review
Attachment #8393740 - Flags: review?(dteller)
PS: I filed bug 985655 for Sqlite.jsm shutdown
Comment on attachment 8393740 [details] [diff] [review]
patch v2

Review of attachment 8393740 [details] [diff] [review]:
-----------------------------------------------------------------

Code looks good, but I'm not convinced by the test.

::: browser/components/nsBrowserGlue.js
@@ +1073,5 @@
> +          try {
> +            yield BookmarkHTMLUtils.exportToFile(BookmarkHTMLUtils.defaultPath);
> +          } catch(ex) {
> +            // At this point there's no UI, so just dump.
> +            dump("ERROR: Unable to export bookmarks.html " + ex + "\n");

It would be nice to print the stack if there is one.

@@ +1076,5 @@
> +            // At this point there's no UI, so just dump.
> +            dump("ERROR: Unable to export bookmarks.html " + ex + "\n");
> +          }
> +        }));
> +    }

Just to be sure: the only thing you did (besides regrouping related pieces of code) is changing the phase to profileChangeTeardown, isn't it?

::: browser/components/places/tests/unit/test_browserGlue_bookmarkshtml.js
@@ +28,5 @@
> +
> +  Services.obs.addObserver(function observer() {
> +    Services.obs.removeObserver(observer, "profile-before-change");
> +    check_bookmarks_html();
> +  }, "profile-before-change", false);

profile-before-change is sent only if do_get_profile() has been called. I don't think that this is the case here.
Attachment #8393740 - Flags: review?(dteller) → feedback+
(In reply to David Rajchenbach Teller [:Yoric] (please use "needinfo?") from comment #23)
> Just to be sure: the only thing you did (besides regrouping related pieces
> of code) is changing the phase to profileChangeTeardown, isn't it?

yes, but I cannot do that at places-shutdown cause it happens at teardown as well. So I just moved that to initPlaces.

> ::: browser/components/places/tests/unit/test_browserGlue_bookmarkshtml.js
> @@ +28,5 @@
> > +
> > +  Services.obs.addObserver(function observer() {
> > +    Services.obs.removeObserver(observer, "profile-before-change");
> > +    check_bookmarks_html();
> > +  }, "profile-before-change", false);
> 
> profile-before-change is sent only if do_get_profile() has been called. I
> don't think that this is the case here.

Places doesn't make sense without a profile, thus any Places test runs only with a profile. all xpcshell tests in Places include head_common.js that always invokes do_get_profile() (I actually wrote the code that notifies profile notifications in xpcshell iirc)
Could you document this, in that case? I couldn't find where do_get_profile() gets called.
I'm running FX 29.0b1 and I'm getting the.html file created in my profile folder, but it's either corrupt or it's making a blank one. The file size is much smaller than when I manually export to .html. Opening the file in the browser shows a blank page.
(In reply to David Rajchenbach Teller [:Yoric] (please use "needinfo?") from comment #25)
> Could you document this, in that case? I couldn't find where
> do_get_profile() gets called.

where should I document it? I don't think there's a good point where I can document all Places xpcshell-tests use head_common.js... And surely I'm not going to add such documentation to each test :)
(In reply to L.A.R. Grizzly from comment #26)
> I'm running FX 29.0b1 and I'm getting the.html file created in my profile
> folder, but it's either corrupt or it's making a blank one. The file size is
> much smaller than when I manually export to .html. Opening the file in the
> browser shows a blank page.

the code that exports "manually" or "automatically" is exactly the same, I suspect the html you get created is actually not, it's just an old one that keeps stayin there? There's no way the current code may export to html automatically, that's the primary reason this bug exists.
Oh, right, I had missed the loadSubScript to head_common.js. Weirdish, but ok.
Hi Marco, Gavin told me this bug had to be added to the current iteration.  Can you provide a point estimate.  Thanks.
Status: NEW → ASSIGNED
Flags: needinfo?(mak77)
Whiteboard: p=0 s=it-31c-30a-29b.1
I think it's an easy:3. Thanks.
Flags: needinfo?(mak77) → needinfo?(mmucci)
Thanks Marco.  All updated.
Flags: needinfo?(mmucci)
Whiteboard: p=0 s=it-31c-30a-29b.1 → p=3 s=it-31c-30a-29b.1
Hi Anthony, can you review if this bug should be [qa+] or [qa-] for verification.
Flags: needinfo?(anthony.s.hughes)
Attached patch patch v3Splinter Review
I think I replied to all of the comments, this is identical as before apart printing the stack.

As I said I don't think it's worth to add a comment about do_get_profile and yes, the only change is basically moving this stuff to profile-change-teardown
Attachment #8393740 - Attachment is obsolete: true
Attachment #8395189 - Flags: review?(dteller)
I wrongly pushed this cause it was in my queue, and backed out cause of missing review.
https://hg.mozilla.org/integration/fx-team/rev/0469cf95fbfe
https://hg.mozilla.org/integration/fx-team/rev/f8ac41a79fc0
Comment on attachment 8395189 [details] [diff] [review]
patch v3

Review of attachment 8395189 [details] [diff] [review]:
-----------------------------------------------------------------

::: browser/components/nsBrowserGlue.js
@@ +1074,5 @@
> +            yield BookmarkHTMLUtils.exportToFile(BookmarkHTMLUtils.defaultPath);
> +          } catch(ex) {
> +            // At this point there's no UI, so just dump.
> +            dump("ERROR: Unable to export bookmarks.html " + ex + "\n"
> +                                                           + ex.stack + "\n");

If you just return 
|BookmarkHTMLUtils.exportToFile(BookmarkHTMLUtils.defaultPath)|, AsyncShutdown will report the error automatically with the following message:

"A completion condition encountered an error" +
                " while we were spinning the event loop." +
                " Condition: " + name +
                " Phase: " + topic +
                " State: " + safeGetState(state);

Your call.

::: toolkit/modules/AsyncShutdown.jsm
@@ +285,5 @@
>    addBlocker: function(condition) {
>      if (!this._conditions) {
>        throw new Error("Phase " + this._topic +
> +                      " has already begun, it is too late to register '" +
> +                      condition.name + "' completion condition.");

"it is too late to register completion condition '" + condition.name + "'."
Attachment #8395189 - Flags: review?(dteller) → review+
with comments addressed:
https://hg.mozilla.org/integration/fx-team/rev/f162ae54353d

Regarding QA, I think it would be worth to do manual testing that bookmarks.html is properly exported if the browser.bookmarks.autoExportHTML pref is set to true.
Even if we have a test, shutdown conditions are always particular.
Flags: in-testsuite? → in-testsuite+
Target Milestone: --- → Firefox 31
https://hg.mozilla.org/mozilla-central/rev/f162ae54353d
Status: ASSIGNED → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Comment on attachment 8395189 [details] [diff] [review]
patch v3

[Approval Request Comment]
Bug caused by (feature/regressing bug #): bug 824433
User impact if declined: bookmarks.html is not created anymore for users who enabled it
Testing completed (on m-c, etc.): m-c
Risk to taking this patch (and alternatives if risky): low
String or IDL/UUID changes made by this patch: none
Attachment #8395189 - Flags: approval-mozilla-beta?
Attachment #8395189 - Flags: approval-mozilla-aurora?
Attachment #8395189 - Flags: approval-mozilla-beta?
Attachment #8395189 - Flags: approval-mozilla-beta+
Attachment #8395189 - Flags: approval-mozilla-aurora?
Attachment #8395189 - Flags: approval-mozilla-aurora+
backed out from Beta due to xpcshell failure, looks like Beta is missing some fix related to OS.File or AsyncShutdown

https://hg.mozilla.org/releases/mozilla-beta/rev/1009928465c9

04:55:46     INFO -  [4301] WARNING: NS_ENSURE_TRUE(aFile) failed: file /builds/slave/m-beta-osx64-d-000000000000000/build/netwerk/base/src/nsFileStreams.cpp, line 304
04:55:46     INFO -  WARNING: A completion condition encountered an error while we were spinning the event loop. Condition: Places: export bookmarks.html Phase: profile-change-teardown
04:55:46     INFO -  WARNING: [Exception... "Component returned failure code: 0x8000ffff (NS_ERROR_UNEXPECTED) [nsIFileOutputStream.init]"  nsresult: "0x8000ffff (NS_ERROR_UNEXPECTED)"  location: "JS frame :: resource://gre/modules/BookmarkHTMLUtils.jsm :: doExportToFile :: line 913"  data: no]
04:55:46  WARNING -  TEST-UNEXPECTED-FAIL | /builds/slave/talos-slave/test/build/tests/xpcshell/tests/browser/components/places/tests/unit/head_bookmarks.js -> file:///builds/slave/talos-slave/test/build/tests/xpcshell/tests/toolkit/components/places/tests/head_common.js | false == true - See following stack:
or more likely, it's missing bug 968177, so BookmarkHTMLUtils.defaultPath doesn't exist!
Attached patch beta patchSplinter Review
basically the same patch, but without using BookmarkHTMLUtil.defaultPath, I'm rather using the old nsIFile code that was already there.
Not going to further as for review or approval cause the patch is the same and the "new" code is the old one that is already in beta.
qa- as per in-testsuite coverage. Please needinfo me if you think this needs more thorough verification.
Flags: needinfo?(anthony.s.hughes)
Whiteboard: p=3 s=it-31c-30a-29b.1 → p=3 s=it-31c-30a-29b.1 [qa-]
Status: RESOLVED → VERIFIED
No longer blocks: fxdesktopbacklog
Flags: firefox-backlog+
This bug is fixed in FX 29.0b4 on my system.
(In reply to L.A.R. Grizzly from comment #46)
> This bug is fixed in FX 29.0b4 on my system.

Thanks for following up.
You need to log in before you can comment on or make changes to this bug.