983988 - bookmarkbackups .json files not being generated often enough on some systems where idle is "bogus"

Status: VERIFIED FIXED

(Firefox :: Bookmarks & History, defect)

Description

[Spencer Selander [greenknight]]

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

Steps to reproduce:

1. Create a new profile.
2. Launch Nightly with the new profile.
3. Bookmark a Web page.
4. Leave Nightly open and idle for more than 10 minutes.
5. Press Ctrl + Shift + B t pen Library, go to Import and Backup > Restore to view list of backups.


Actual results:

No bookmark backups listed, prompted to browse for them.


Expected results:

Should have been a backup created during idle.

Comment 1

[Spencer Selander [greenknight]]

First noticed in my regular Nightly profile that bookmark backups that previously occurred daily had been erratic after 2-20, up to 5 days between backups. Most recent backup was 3-12, couldn't trigger creation of another by idling, even when all add-ons disabled. Tried repeatedly with both my regular Nightly profile and clean test profile, backups are not created.

Comment 2

[Marco Bonardo [:mak]]

when you idle, do you completely leave your pc unattended or do you just move to other software?

May you please run this code in the browser console, leave the computer idle for 12 minutes, then post the results?

let idle = Components.classes["@mozilla.org/widget/idleservice;1"].getService(Components.interfaces.nsIIdleService); [1,2,3,5,7,10].forEach(aTimeMin => { idle.addIdleObserver((undefined, aTopic) => { console.log(aTopic); if (aTopic == "idle") console.log(aTimeMin + " <= " + Math.round(idle.idleTime / 60000)) }, aTimeMin * 60) })

Comment 3

[Spencer Selander [greenknight]]

(In reply to Marco Bonardo [:mak] from comment #2)
> when you idle, do you completely leave your pc unattended or do you just
> move to other software?
> 
> May you please run this code in the browser console, leave the computer idle
> for 12 minutes, then post the results?
> 
> let idle =
> Components.classes["@mozilla.org/widget/idleservice;1"].
> getService(Components.interfaces.nsIIdleService);
> [1,2,3,5,7,10].forEach(aTimeMin => { idle.addIdleObserver((undefined,
> aTopic) => { console.log(aTopic); if (aTopic == "idle") console.log(aTimeMin
> + " <= " + Math.round(idle.idleTime / 60000)) }, aTimeMin * 60) })

I left the computer alone, totally idle.

The browser console has no javascript interpreter, just the display pane (when did that happen?), so where do I run that code? The web console?

Comment 4

[Spencer Selander [greenknight]]

Just installed Nightly on my Win7 laptop, tried the STR - backup was created.

Comment 5

[Spencer Selander [greenknight]]

Tried entering that code in the web console, got "TypeError: Components.classes is undefined". Let it idle for 12 min. anyway, nothing happened.

Comment 6

[Spencer Selander [greenknight]]

Did a clean reinstall of Nightly (uninstalled, deleted install folder, cleaned file system and registry, defragged, installed fresh download). Backups were then created in both original and test profiles. Will check again in 24 hrs, but looking like this may have just been bustage in my installation.

Comment 7

[Marco Bonardo [:mak]]

(In reply to Spencer Selander [greenknight] from comment #3)
> The browser console has no javascript interpreter, just the display pane
> (when did that happen?), so where do I run that code? The web console?

This is strange, the browser console always had the eval text field, I can use it... the above code can only run in the browser console.

Comment 8

[Spencer Selander [greenknight]]

Well, it's not fixed. Can't trigger another backup with either profile on this computer, or on the lsptop. It's always produced at least one backup every 5 days, this fits that pattern - the latest one was 5 days after the previous one. On the laptop, got one backup on a new install, 24hrs later it won't produce another.

I don't know what's up with the browser console, it's the same on the laptop's new install of Nightly. In Aurora the text field is present, not in Nightly.

Comment 9

[Marco Bonardo [:mak]]

maybe you must toggle devtools.chrome.enabled (didn't try, I just know I have it enabled)

Comment 10

[Spencer Selander [greenknight]]

(In reply to Marco Bonardo [:mak] from comment #9)
> maybe you must toggle devtools.chrome.enabled (didn't try, I just know I
> have it enabled)

Tried that, works.Then I found an MDN page that says the command line interpreter is disabled by default starting with Fx 30, dunno how I missed that before. Ran that code, this was displayed:


undefined
"idle"
"1 <= 1"
"idle"
"2 <= 2"
"active"
"idle"
"1 <= 1"
"idle"
"2 <= 2"
"idle"
"3 <= 3"
"active"

---------
Got it running on the Win 7 laptop right now. It shows "active" if I so much as move the mouse slightly.

Comment 11

[Jim Jeffery not reading bug-mail 1/2/11]

Not related, but when I looked to see if I was getting backups I find a strange filename:

bookmarks-2014-04-02_841_wv7IiDn0JMeya13Zskxfqw==.json

I've been getting those random letters/numbers it seems since 3/24...

Comment 12

[Spencer Selander [greenknight]]

Left the laptop running that code completely undisturbed for a prolonged period, well past the point where it went to sleep. It eventually did produce a backup. The browser console output:

undefined
"idle"
"1 <= 1"
"idle"
"2 <= 2"
"idle"
"3 <= 3"
"idle"
"5 <= 5"
"idle"
"7 <= 7"
"active"
"idle"
"1 <= 1"
"active"
"idle"
"1 <= 1"
"idle"
"2 <= 2"
"active"
"idle"
"2 <= 2"
"idle"
"1 <= 2"
"idle"
"3 <= 3"
"idle"
"5 <= 5"
"active"
"idle"
"1 <= 1"
"active"
"idle"
"1 <= 1"
"idle"
"2 <= 2"
"idle"
"3 <= 3"
"idle"
"5 <= 5"
"idle"
"7 <= 7"
"active"
"idle"
"1 <= 1"
"idle"
"2 <= 2"
"active"
"idle"
"1 <= 1"
"idle"
"2 <= 2"
"idle"
"3 <= 3"
"idle"
"5 <= 5"
"idle"
"7 <= 7"
"active"
"idle"
"1 <= 1"
"idle"
"2 <= 2"
"idle"
"3 <= 3"
"idle"
"5 <= 5"
"active"
"idle"
"1 <= 1"
"idle"
"2 <= 2"
"idle"
"3 <= 3"
"active"
"idle"
"1 <= 1"
"idle"
"2 <= 2"
"active"
"idle"
"10 <= 12"
"idle"
"7 <= 12"
"idle"
"5 <= 12"
"idle"
"3 <= 12"
"idle"
"2 <= 12"
"idle"
"1 <= 12"
"active"
[ABE WAN] Trying to detect WAN IP...
[ABE WAN] Detected WAN IP 97.120.215.88
TypeError: mutating the [[Prototype]] of an object will cause your code to run very slowly; instead create the object with the correct initial [[Prototype]] value using Object.create

Comment 13

[Adam Porter]

I have also noticed this behavior, and the date after which it seemed to start happening is nearly the same: 2014-02-19.  Although, there is also a gap from 2013-12-12 to 2014-02-19.  Here is a directory listing:

$ ll bookmarkbackups
total 51M
-rw------- 1 me me 5.4M Nov 26 18:32 bookmarks-2013-11-26_20347.json
-rw------- 1 me me 5.4M Nov 28 00:09 bookmarks-2013-11-28_20353.json
-rw------- 1 me me 5.4M Nov 29 01:38 bookmarks-2013-11-29_20361.json
-rw------- 1 me me 5.4M Nov 30 05:16 bookmarks-2013-11-30_20366.json
-rw------- 1 me me 5.4M Dec  2 02:10 bookmarks-2013-12-02_20375.json
-rw------- 1 me me 5.4M Dec  3 09:04 bookmarks-2013-12-03_20379.json
-rw------- 1 me me 5.4M Dec  4 03:40 bookmarks-2013-12-04_20379.json
-rw------- 1 me me 5.4M Dec  9 00:54 bookmarks-2013-12-09_20392.json
-rw------- 1 me me 5.4M Dec 12 05:44 bookmarks-2013-12-12_20429.json
-rw------- 1 me me 2.6M Feb 19 20:50 bookmarks-2014-02-19_10026.json

Also, the Restore submenu in the Places dialog is empty except for "Restore...".

Currently on Fx 27, but since the reporter is on Fx 30, I thought it was worth adding this comment.  I'm on Ubuntu 13.10 Saucy.

Comment 14

[Spencer Selander [greenknight]]

I also see this on Aurora after 2-25. Still happening on both computers in Nightly and in Aurora.

Comment 15

[Marco Bonardo [:mak]]

FX27 is completely different story, that code was very bogus and 30 should make things better.

Spencer's issue is that looks like something is "disturbing" idle of his browser, either an external app, an add-on or a website. We should figure that out since not touching the mouse/keyboard should definitely be detected as idle by the idle service.
To workaround that we have code in place that checks if the newest backup is 5 days old, then we try every 5 minutes instead of 10, and then you may expect at least a backup every about 5 days in the worst case. This can probably be reduced a bit, though would be much better to first figure what causes us going back from idle to active when nothing is touched.

Comment 16

[Spencer Selander [greenknight]]

Whatever it is, it's not affecting Fx 28 - it still generates daily backups. We can eliminate add-ons, since the bug is present in a clean profile with no add-ons.

I have the same security programs on both computers, maybe it's an interaction with one of them. I'll try disabling one at a time and testing it.

Comment 17

[Adam Porter]

> FX27 is completely different story, that code was very bogus and 30 should make things better.

Indeed, I had had Firefox held in apt on v27 due to an extension incompatibility.  It was finally updated, so I updated to Fx 28 and now the JSON backups are being created again.

Comment 18

[Marco Bonardo [:mak]]

(In reply to Spencer Selander [greenknight] from comment #16)
> Whatever it is, it's not affecting Fx 28 - it still generates daily backups.
> We can eliminate add-ons, since the bug is present in a clean profile with
> no add-ons.

That's not strange, in FX28 if we were unable to find a good idle time we were just forcing a backup on shutdown, making shutdown much slower though. We stopped doing that, cause the benefits of faster shutdowns are tangible to most users.  We still need to find the "perfect" compromise to have backups created often enough without having to force them. I think that we may reduce the maximum number of days without a backup to 3, now that we don't store duplicate backups.

Let me confirm this bug to touch those numbers, it should be a trivial patch, like changing this const. http://mxr.mozilla.org/mozilla-central/source/browser/components/nsBrowserGlue.js#111

Indeed if you wish to work on that patch, just let me know, I'd be happy to mentor this.

Comment 19

[Marco Bonardo [:mak]]

yes, telemetry for Nightly and Aurora confirms we should reduce the times a little bit.
I'd say 8 minutes idle and 3 days without a backup sounds like a good compromise.

Comment 20

[Spencer Selander [greenknight]]

(In reply to Marco Bonardo [:mak] from comment #19)
> yes, telemetry for Nightly and Aurora confirms we should reduce the times a
> little bit.
> I'd say 8 minutes idle and 3 days without a backup sounds like a good
> compromise.

I hope that does the job. There have been a couple times it went 7 days between backups since I checked previously, which is disturbing if the max is supposed to be 5 days.

As for me helping with the patch, my coding skills are minimal. You don't want me touching the code, I'll stick to testing.

Comment 21

[Marco Bonardo [:mak]]

(In reply to Spencer Selander [greenknight] from comment #20)
> which is disturbing if the max
> is supposed to be 5 days.

it's not the maximum, it's the time after which we try to be more aggressive with the idle time.

Comment 22

[Althaf Hameez [:ahameez]]

Attachment: bug983988_update_idle_time.diff

Comment 23

[Marco Bonardo [:mak]]

Comment on attachment 8429890 [details] [diff] [review]
bug983988_update_idle_time.diff

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

https://tbpl.mozilla.org/?tree=Try&rev=29e6bd8547f3

Comment 24

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/integration/fx-team/rev/0f272c2ce847

Comment 25

[Marco Bonardo [:mak]]

I think we should try to backport this, it's late for 30, but we should be in time for 31.

Comment 26

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/0f272c2ce847

Comment 27

[Marco Bonardo [:mak]]

Comment on attachment 8429890 [details] [diff] [review]
bug983988_update_idle_time.diff

[Approval Request Comment]
Bug caused by (feature/regressing bug #): bookmarks backups rewrite
User impact if declined: telemetry tells us some users are not getting recent enough backups of their bookmarks
Testing completed (on m-c, etc.): m-c
Risk to taking this patch (and alternatives if risky): very low, just changing consts
String or IDL/UUID changes made by this patch: none

Comment 28

[Lawrence Mandel [:lmandel] (use needinfo)]

Comment on attachment 8429890 [details] [diff] [review]
bug983988_update_idle_time.diff

Aurora approval granted.

Comment 29

[Lawrence Mandel [:lmandel] (use needinfo)]

I'm -aurora for tracking as I don't think this issue is severe enough to warrant tracking. (As I understand it, backups are happening but the delay between backups is longer than expected.) However, I have approved this patch for Aurora uplift.

Comment 30

[Marco Bonardo [:mak]]

Thanks!
https://hg.mozilla.org/releases/mozilla-aurora/rev/c62a11a932a1

Comment 31

[Spencer Selander [greenknight]]

Seems to do the job - I tried to trigger a backup in Aurora, and succeeded. Nice!

Not my first bug, by the way. Just the first in a while.