Open Bug 1054947 Opened 7 years ago Updated 2 months ago

"It looks like you haven't started Firefox in a while" message despite running Firefox daily

Categories

(Firefox :: General, defect, P3)

Product:
Firefox
Component:
General
Type:
defect

Tracking

()

Milestone:
Firefox 56

People

(Reporter: djst, Unassigned)

References

Details

Attachments

(1 file)

Bug 1054947 - Fix misjudging user who always uses and never closes Firefox as one that hasn't used Firefox for a long time
59 bytes, text/x-review-board-request
Details 
I'm getting the message to Reset Firefox on my Firefox beta (32.0) despite running Firefox daily for a living. 

Did we regress here? I saw bug 896276 but it's an old one.
Summary: "It looks like you haven't started Firefox in a while" message despite → "It looks like you haven't started Firefox in a while" message despite running Firefox daily
Matt, can you help figure out what's going on here?
Blocks: 498181
Flags: needinfo?(MattN+bmo)
David, do you have any special Firefox launcher or profile setup (e.g. on a network share)?

Can you also provide the result of Services.appinfo.replacedLockTime from the Browser Console[1]?

[1] https://developer.mozilla.org/en-US/docs/Tools/Browser_Console
Flags: needinfo?(MattN+bmo) → needinfo?(djst)
Thanks, I confused it with the Web Console. Here are the results:

Services.appinfo.replacedLockTime
1409037992000
It happened again today, I got that info bar at the bottom complaining about Firefox... starting... slowly again. 

Not sure if this is related, but Firefox *is* acting slowly too, but not during startup. I frequently suffer from "Not responding" lockups of the entire browser and just recently had to Force Quit it. I do have iMacros running, if that's relevant. 

Services.appinfo.replacedLockTime
1409754389000
This morning I got it again. 

"It looks like you haven't started Firefox in a while. Do you want to clean it up for a fresh, like-new experience? And by the way, welcome back!"

Again, my browser is running constantly. It recently crashed, maybe that's related?

Services.appinfo.replacedLockTime
1325376057000
Matt, are there any other steps I need to take here? Don't want this bug to be forgotten as it could potentially affect many more than just myself.
Flags: needinfo?(MattN+bmo)
Flags: qe-verify?
MattN, I keep getting this bug from time to time. I have a hard time imagining that I would be the only user that is affected by it. 

Could you explain what Firefox does to determine that I haven't started it in a while? Is there a particular file it checks? Would love to understand this better. My sense is, it should be fairly easy to determine that I have indeed started Firefox recently - my profile is literally filled with files with recent modification dates.
From nsProfileLock::Lock https://dxr.mozilla.org/mozilla-central/source/profile/dirserviceprovider/nsProfileLock.cpp#432 it looks like the mtime of the ".parentlock" (on OS X) file in the profile is used.
Component: Untriaged → General
My fiancée hit this.

STR:

* Install Firefox (at the time, 37 Beta on OS X 10.8, but I doubt it matters).
* Use it for two straight months without restarting the machine or relaunching Firefox.
(In reply to Richard Newman [:rnewman] from comment #11)
> * Use it for two straight months without restarting the machine or
> relaunching Firefox.

Yeah, that's a known limitation of the current approach.

David, do you also leave the same Firefox session running for 60 days or more?
Flags: needinfo?(MattN+bmo) → needinfo?(djst)
See Also: → 1091619
This is also a duplicate of bug 1011978. And yes, I do leave the same Firefox session running for 60 days or more.
MattN: yes, that's fairly likely that I've sometimes left Firefox and the machine running for 2 months. That is, without rebooting (but putting it on standby). I didn't know that was a limitation, that would certainly explain this. Why aren't we looking at when history was most recently updated instead?
Flags: needinfo?(djst)
(In reply to David Tenser [:djst] from comment #14)
> MattN: yes, that's fairly likely that I've sometimes left Firefox and the
> machine running for 2 months. That is, without rebooting (but putting it on
> standby). I didn't know that was a limitation, that would certainly explain
> this. Why aren't we looking at when history was most recently updated
> instead?

Because you can run Firefox without saving history (permanent private browsing mode).
(In reply to Friedrich Volkmann from comment #13)
> This is also a duplicate of bug 1011978. And yes, I do leave the same
> Firefox session running for 60 days or more.

This isn't quite a duplicate - you're seeing this on every new window, and this bug is about this happening after you restart 60 days past the last restart.

I wonder if in order to fix this, we could touch the lockfile on shutdown. Don't know if that's a really dumb idea. Matt?
Flags: needinfo?(MattN+bmo)
(In reply to :Gijs Kruitbosch from comment #16)
> I wonder if in order to fix this, we could touch the lockfile on shutdown.

But you'd still get the message if Firefox or the system crashes or otherwise goes down uncleanly after a long period of continuous operation. The date probably needs to be updated periodically while Firefox is running (such as once per day or per week or so).
Blocks: 1351616
Whiteboard: [photon-onboarding]
Priority: -- → P1
Target Milestone: --- → Firefox 56
Assignee: nobody → fliu
Status: NEW → ASSIGNED
Flags: qe-verify? → qe-verify+
QA Contact: jwilliams
Comment on attachment 8871336 [details]
Bug 1054947 - Fix misjudging user who always uses and never closes Firefox as one that hasn't used Firefox for a long time

https://reviewboard.mozilla.org/r/142806/#review146560

::: browser/components/nsBrowserGlue.js:902
(Diff revision 1)
> +      profilesIni.append("profiles.ini");
> +      if (!profilesIni.exists()) {
> +        profilesIni = profileDir.parent.parent;
> +        profilesIni.append("profiles.ini");
> +        if (!profilesIni.exists()) {
> +          throw "Failed to find profiles.ini";

Basically this case shouldn't happen however in case of any unexpected thing, still a try-catch still be added here so as to make sure the start-up process couls proceed. Should we report this error here using, say, telemetry service if really happened?
Comment on attachment 8871336 [details]
Bug 1054947 - Fix misjudging user who always uses and never closes Firefox as one that hasn't used Firefox for a long time

Hi Matt,

This patch switches to using the last modified time of the profiles.ini file to check the last Firefox-used time.

Thanks
Attachment #8871336 - Flags: review?(MattN+bmo)
Comment on attachment 8871336 [details]
Bug 1054947 - Fix misjudging user who always uses and never closes Firefox as one that hasn't used Firefox for a long time

https://reviewboard.mozilla.org/r/142808/#review148212

::: browser/components/nsBrowserGlue.js:892
(Diff revision 1)
> +      // The profiles.ini could be located in the parent or the parent of prarent folder of profile dir,
> +      // depending on different OS platform.
> +      let profileService = Cc["@mozilla.org/toolkit/profile-service;1"].getService(Components.interfaces.nsIToolkitProfileService);
> +      let profileDir = profileService.selectedProfile.rootDir;
> +      profilesIni = profileDir.parent;
> +      profilesIni.append("profiles.ini");
> +      if (!profilesIni.exists()) {
> +        profilesIni = profileDir.parent.parent;
> +        profilesIni.append("profiles.ini");
> +        if (!profilesIni.exists()) {
> +          throw "Failed to find profiles.ini";
> +        }
> +      }

I think if you use `UAppData` you avoid this problem:
```js
Services.dirsvc.get("UAppData", Ci.nsIFile)
```

::: browser/components/nsBrowserGlue.js:912
(Diff revision 1)
> +  _profilesIniTouchTimer: null,
> +
> +  _touchProfilesIniScheduled: false,
> +
> +  _scheduleTouchProfilesIni() {
> +    if (!this._touchProfilesIniScheduled) {
> +      // For every 24 hours, we touch the profiles.ini's `lastModifiedTime`.
> +      // In this way, for users who don't close Firefox for months,
> +      // we will still be able to know their last-used time.
> +      const NEXT_TOUCH_PROFILES_INI_24_HR = 1000 * 60 * 60 * 24;
> +      this._touchProfilesIniScheduled = true;
> +
> +      if (!this._profilesIniTouchTimer) {
> +        this._profilesIniTouchTimer = Cc["@mozilla.org/timer;1"].createInstance(Ci.nsITimer);
> +      }
> +      this._profilesIniTouchTimer.init(() => {
> +        this._touchProfilesIniScheduled = false;
> +        let profilesIni = this._getProfilesIni();
> +        if (profilesIni) {
> +          profilesIni.lastModifiedTime = Date.now();
> +          this._scheduleTouchProfilesIni();
> +        }
> +      }, NEXT_TOUCH_PROFILES_INI_24_HR, Ci.nsITimer.TYPE_ONE_SHOT);

I have to think about the overall approach a bit more but in the meantime I think it could be simplified a bit using DeferredTask.jsm
Attachment #8871336 - Flags: review?(MattN+bmo)
Comment on attachment 8871336 [details]
Bug 1054947 - Fix misjudging user who always uses and never closes Firefox as one that hasn't used Firefox for a long time

https://reviewboard.mozilla.org/r/142808/#review148212

> I think if you use `UAppData` you avoid this problem:
> ```js
> Services.dirsvc.get("UAppData", Ci.nsIFile)
> ```

Thanks for reminding this, updated.

> I have to think about the overall approach a bit more but in the meantime I think it could be simplified a bit using DeferredTask.jsm

Thanks for reminding. Switched to DeferredTask.
Comment on attachment 8871336 [details]
Bug 1054947 - Fix misjudging user who always uses and never closes Firefox as one that hasn't used Firefox for a long time

Hi Matt,

About the overall approach, one consideration is about the windows stub installer. If the current user hasn't used FF for over 60 days, the stub installer will present a dialog with checkbox saying the profile auto-refresh will be done. And do auto-refresh if user doesn't opt-out.

One possible reason using the profiles.ini is that the stub installer could simply check one file's lastModifiedTime, then present that dialog, then execute `$ firefox --reset-profile` to do auto-refresh when launching Firefox.

Thanks.
Attachment #8871336 - Flags: review?(MattN+bmo)
Blocks: 1369255
Comment on attachment 8871336 [details]
Bug 1054947 - Fix misjudging user who always uses and never closes Firefox as one that hasn't used Firefox for a long time

https://reviewboard.mozilla.org/r/142808/#review149638

I have lots of comments but it's not too bad.

::: browser/components/nsBrowserGlue.js:898
(Diff revision 3)
> +  },
> +
> +  _touchProfilesIniTask: null,
> +
> +  _scheduleTouchProfilesIni() {
> +    if (!this._touchProfilesIniTask) {

Nit: Do an early return if it's truthy instead to avoid nesting/indentation.

::: browser/components/nsBrowserGlue.js:899
(Diff revision 3)
> +
> +  _touchProfilesIniTask: null,
> +
> +  _scheduleTouchProfilesIni() {
> +    if (!this._touchProfilesIniTask) {
> +      let { DeferredTask } = Cu.import("resource://gre/modules/DeferredTask.jsm", {});

Might as put this in the lazy module getter array at the top of the file (alphabetically)

::: browser/components/nsBrowserGlue.js:902
(Diff revision 3)
> +      // we will still be able to know their last-used time.
> +      const NEXT_TOUCH_PROFILES_INI_24_HR = 1000 * 60 * 60 * 24;

Move this adjacent to `OFFER_PROFILE_RESET_INTERVAL_MS` and then pass the timestamp as an argument to `_scheduleTouchProfilesIni`. Then write a mochitest-browser-chrome calling `_scheduleTouchProfilesIni` with a low number and ensure that the timestamp gets updated. This will ensure that the time gets flushed on every OS.

::: browser/components/nsBrowserGlue.js:903
(Diff revision 3)
> +    if (!this._touchProfilesIniTask) {
> +      let { DeferredTask } = Cu.import("resource://gre/modules/DeferredTask.jsm", {});
> +      // For every 24 hours, we touch the profiles.ini's `lastModifiedTime`.
> +      // In this way, for users who don't close Firefox for months,
> +      // we will still be able to know their last-used time.
> +      const NEXT_TOUCH_PROFILES_INI_24_HR = 1000 * 60 * 60 * 24;

Nit: Use a `_MS` suffix

Nit: reverse the order of the operands

::: browser/components/nsBrowserGlue.js:904
(Diff revision 3)
> +      let { DeferredTask } = Cu.import("resource://gre/modules/DeferredTask.jsm", {});
> +      // For every 24 hours, we touch the profiles.ini's `lastModifiedTime`.
> +      // In this way, for users who don't close Firefox for months,
> +      // we will still be able to know their last-used time.
> +      const NEXT_TOUCH_PROFILES_INI_24_HR = 1000 * 60 * 60 * 24;
> +      this._touchProfilesIniTask = new DeferredTask(() => {

Nit: Give the task function a name so it can be found in stack traces

::: browser/components/nsBrowserGlue.js:905
(Diff revision 3)
> +        let profilesIni = this._getProfilesIni();
> +        profilesIni.lastModifiedTime = Date.now();

I think we should put the I/O in a requestIdleCallback

::: browser/components/nsBrowserGlue.js:906
(Diff revision 3)
> +      // In this way, for users who don't close Firefox for months,
> +      // we will still be able to know their last-used time.
> +      const NEXT_TOUCH_PROFILES_INI_24_HR = 1000 * 60 * 60 * 24;
> +      this._touchProfilesIniTask = new DeferredTask(() => {
> +        let profilesIni = this._getProfilesIni();
> +        profilesIni.lastModifiedTime = Date.now();

The I/O should also be done off the main thread with `OS.File.setDates` same as the other place where it's done. If it's more than 2 lines then make it a helper here to be called

::: browser/components/nsBrowserGlue.js:907
(Diff revision 3)
> +        try {
> +          this._touchProfilesIniTask.arm();
> +        } catch (e) {

Since you never finalize, I would remove the try…catch to improve readability by reducing complexity

::: browser/components/nsBrowserGlue.js:977
(Diff revision 3)
> +    // the backward compatibilty. Before Bug 1054947, only using `replacedLockTime` and not touching profilesIni's `lastModifiedTime`.
> +    // Hence, `lastModifiedTime` could be much older than the 60-days threshold.
> +    // In this case we would misjudge lots of daily active users as inactive users if only consider `lastModifiedTime`.
> +    // So here would take the newer time as the last-used time.
> +    let profilesIni = this._getProfilesIni();
> +    let lastUse =  Math.max(profilesIni.lastModifiedTime, Services.appinfo.replacedLockTime);

Accessing the lastModifiedTime should be done async with OS.File https://developer.mozilla.org/en-US/docs/Mozilla/JavaScript_code_modules/OSFile.jsm/OS.File.Info#Cross-platform_Attributes_2 and I think all of this logic should go in a requestIdleCallback while you're touching it.
Attachment #8871336 - Flags: review?(MattN+bmo)
Comment on attachment 8871336 [details]
Bug 1054947 - Fix misjudging user who always uses and never closes Firefox as one that hasn't used Firefox for a long time

https://reviewboard.mozilla.org/r/142808/#review149638

> Move this adjacent to `OFFER_PROFILE_RESET_INTERVAL_MS` and then pass the timestamp as an argument to `_scheduleTouchProfilesIni`. Then write a mochitest-browser-chrome calling `_scheduleTouchProfilesIni` with a low number and ensure that the timestamp gets updated. This will ensure that the time gets flushed on every OS.

Updated and a one test - browser_browserGlue_schedule_touch_profiles_ini.js is added, thanks
Comment on attachment 8871336 [details]
Bug 1054947 - Fix misjudging user who always uses and never closes Firefox as one that hasn't used Firefox for a long time

https://reviewboard.mozilla.org/r/142808/#review149638

> Nit: Do an early return if it's truthy instead to avoid nesting/indentation.

OK, np, thanks

> Might as put this in the lazy module getter array at the top of the file (alphabetically)

Thanks, moved to the lazy module getter array,

> Nit: Use a `_MS` suffix
> 
> Nit: reverse the order of the operands

Thanks, updated

> Nit: Give the task function a name so it can be found in stack traces

Thanks, udpated

> I think we should put the I/O in a requestIdleCallback

Thanks updated

> The I/O should also be done off the main thread with `OS.File.setDates` same as the other place where it's done. If it's more than 2 lines then make it a helper here to be called

Thanks updated.

> Since you never finalize, I would remove the try…catch to improve readability by reducing complexity

OK, thanks

> Accessing the lastModifiedTime should be done async with OS.File https://developer.mozilla.org/en-US/docs/Mozilla/JavaScript_code_modules/OSFile.jsm/OS.File.Info#Cross-platform_Attributes_2 and I think all of this logic should go in a requestIdleCallback while you're touching it.

Thanks. Now using OS.File.setDates and requestIdleCallback.
Comment on attachment 8871336 [details]
Bug 1054947 - Fix misjudging user who always uses and never closes Firefox as one that hasn't used Firefox for a long time

Hi Matt,

Please see the updated patch. 
I added the test as a mochitest because in xpcshell test 
 - calling `BrowserGlue._getProfilesIni` would fail (because `Service.dirsvc.get` would fail, not yet ready) and
 - getting `nsIToolkitProfileService` would fail.

The test results are here:
- I selected randomly across Linux, Linux64, OS X, Windows different test builds to re-trigger 10x more runs. And no failure was found.
https://treeherder.mozilla.org/#/jobs?repo=try&revision=1f1565f594fe67abb78e6c7ec631635c481cc904

- This try tested all mochitests and xpcshell tests. The result looks good overall. There is one xpcshell failure on test_crash_service.js on OS X. I can reproduce the same failure without our patch on my MAC so I believe that has nothing to do with us.
https://treeherder.mozilla.org/#/jobs?repo=try&revision=0ebd4de6b7375abeaf554cb3047b60dac0b047c9

- Talos: https://treeherder.mozilla.org/perf.html#/compare?originalProject=try&originalRevision=b55372e35e3b907c1296ec453755d9132bf2fbea&newProject=try&newRevision=0c7552f0641ff6660262d6baecf3e79ae96ec89d&framework=1&showOnlyImportant=0

Thanks
Attachment #8871336 - Flags: review?(MattN+bmo)
Attachment #8871336 - Flags: review?(MattN+bmo)
Attachment #8871336 - Flags: review?(MattN+bmo)
Comment on attachment 8871336 [details]
Bug 1054947 - Fix misjudging user who always uses and never closes Firefox as one that hasn't used Firefox for a long time

https://reviewboard.mozilla.org/r/142808/#review155370

::: browser/components/nsBrowserGlue.js:898
(Diff revision 4)
> +  _scheduleTouchProfilesIni(ms) {
> +    if (this._touchProfilesIniDeferredTask) {
> +      return;
> +    }

Can you add a JSDoc comment to describe the purpose of this method since it may not be clear to future reader what it's all about or why we want to touch the ini timestamp.

::: browser/components/nsBrowserGlue.js:913
(Diff revision 4)
> +      let win = RecentWindow.getMostRecentBrowserWindow();
> +      win.requestIdleCallback(touchProfilesIniOnIdle);

Now that bug 1353206 was resolved you can use:  
```js
Services.tm.mainThread.idleDispatch(touchProfilesIniOnIdle)
```

::: browser/components/nsBrowserGlue.js:916
(Diff revision 4)
> +    this._touchProfilesIniDeferredTask = new DeferredTask(touchProfilesIniTask, ms);
> +    this._touchProfilesIniDeferredTask.arm();

Thinking about it more… we should probably be using the idle-daily observer notification instead of doing our own timer.

::: browser/components/nsBrowserGlue.js:971
(Diff revision 4)
> -    let lastUse = Services.appinfo.replacedLockTime;
> +    // For every 24 hours, we touch the profiles.ini's `lastModifiedTime`.
> +    // In this way, for users who don't close Firefox for months,
> +    // we will still be able to know their last-used time.

"Every 24 hours touch the profiles.ini `lastModifiedTime` so that a user who keeps the browser running for many weeks is tracked as having used it."

::: browser/components/nsBrowserGlue.js:974
(Diff revision 4)
>      // Offer to reset a user's profile if it hasn't been used for 60 days.
>      const OFFER_PROFILE_RESET_INTERVAL_MS = 60 * 24 * 60 * 60 * 1000;
> -    let lastUse = Services.appinfo.replacedLockTime;
> +    // For every 24 hours, we touch the profiles.ini's `lastModifiedTime`.
> +    // In this way, for users who don't close Firefox for months,
> +    // we will still be able to know their last-used time.
> +    const NEXT_TOUCH_PROFILES_INI_MS = 24 * 60 * 60 * 1000;

Nit: For consistency:

PROFILES_INI_TOUCH_INTERVAL_MS

::: browser/components/nsBrowserGlue.js:1008
(Diff revision 4)
>          if (removalSuccessful && uninstalledValue == "True") {
>            this._resetProfileNotification("uninstall");
>          }
>        }
>      }
> +    if (profilesIni.exists()) {

This patch is calling `profilesIni.exists()` 3 times during startup which I believe does disk I/O each time. Please try to reduce this to 1 time. Perhaps you can make `_getProfilesIni` a lazy getter that returns null if the file doesn't exist.

::: browser/components/nsBrowserGlue.js:1009
(Diff revision 4)
> +      let touchProfilesIniOnFirstWindowLoaded = () => {
> +        OS.File.setDates(profilesIni.path);
> +        this._scheduleTouchProfilesIni(NEXT_TOUCH_PROFILES_INI_MS);
> +      };
> +      let win = RecentWindow.getMostRecentBrowserWindow();
> +      win.requestIdleCallback(touchProfilesIniOnFirstWindowLoaded);

This should be calling a helper which is used both for the initial call and for scheduled ones to avoid having the code diverge by mistake.

::: browser/components/tests/browser/browser.ini:3
(Diff revision 4)
>  [browser_bug538331.js]
>  skip-if = !updater
>  reason = test depends on update channel
>  [browser_contentpermissionprompt.js]
> +[browser_browserGlue_schedule_touch_profiles_ini.js]

Nit: keep these alphabetical

::: browser/components/tests/browser/browser_browserGlue_schedule_touch_profiles_ini.js:20
(Diff revision 4)
> +    let profileService = Components.classes["@mozilla.org/toolkit/profile-service;1"]
> +                                   .getService(Components.interfaces.nsIToolkitProfileService);

Please use `Cc` and `Ci` which should already be defined
Attachment #8871336 - Flags: review?(MattN+bmo)
Descope this bug from Photon because now switching to Firefox version as the condition to do stub-installer auto refresh.
See the meeting notes [1].
[1] https://docs.google.com/document/d/17E14gz-ulyR8KFtwwuHPx7vGV7dDDfktN7pFRR1-2-A/edit
No longer blocks: 1369255, 1351616
Priority: P1 → P3
Whiteboard: [photon-onboarding]
Duplicate of this bug: 1391758
Flags: needinfo?(MattN+bmo)
See Also: → 1552469
Assignee: fischer.json → nobody
Status: ASSIGNED → NEW
OS: macOS → All
QA Contact: jwilliams
Hardware: x86 → All
Version: 32 Branch → Trunk
Duplicate of this bug: 1091619
Duplicate of this bug: 1560334
See Also: → 1290500
You need to log in before you can comment on or make changes to this bug.