1251347 - 100% reproducible AsyncShutdown crash: "SessionFile: Finish writing Session Restore data"

Status: RESOLVED FIXED

(Firefox :: General, defect)

Description

[Alice0775 White]

[Tracking Requested - why for this release]:

This bug was filed from the Socorro interface and is 
report
bp-41acefac-0abd-411d-86cc-28ade2160225 
bp-661199d0-9782-45d3-8918-1c4ba2160225 
bp-8feb28ba-052f-4943-ad9e-7ec8c2160225

=============================================================

[Tracking Requested - why for this release]: Crash

Reproducible: 100% with clean profile

Steps to reproduce: 
1. Open about:preferences#privacy
2. Choose "Never remember history" and then restart
3. Open about:preferences#privacy
4. Choose "Remember history" and then restart

Actual Results:
Browser crashes after fora while.

Expected Results:
Browser should be restarted.

Comment 1

[Alice0775 White]

Regression window:
https://hg.mozilla.org/integration/fx-team/pushloghtml?fromchange=d2522fbd0f6328c7c2b54975636d951924ec7372&tochange=d0badf8b22b00ea52616c93eea6cbb9143545ace

Regressed by: Bug 1243549

Comment 2

[David Teller [:Yoric] - still alive but not very active]

That's 99% sure a problem in my code.

Alice, does this reproduce both with a short run of Firefox (≤1 minute) and a long run (≥2 minutes)?

Comment 3

[Alice0775 White]

(In reply to David Rajchenbach-Teller [:Yoric] (please use "needinfo") from comment #2)
> That's 99% sure a problem in my code.
> 
> Alice, does this reproduce both with a short run of Firefox (≤1 minute) and
> a long run (≥2 minutes)?

Seems both.

Comment 4

[David Teller [:Yoric] - still alive but not very active]

As with many bugs we have noticed recently around sanitization, the real bug is probably pretty old, but was probably made visible by fixing the calling code.

Comment 5

[David Teller [:Yoric] - still alive but not very active]

AsyncShutdown signature



{
  "phase": "profile-before-change",
  "conditions": [
    {
      "name": "SessionFile: Finish writing Session Restore data",
      "state": {
        "options": {
          "isFinalWrite": true,
          "performShutdownCleanup": false
        },
        "hasEverSucceeded": false
      },
      "filename": "resource:\/\/app\/modules\/sessionstore\/SessionFile.jsm",
      "lineNumber": 315,
      "stack": [
        "resource:\/\/app\/modules\/sessionstore\/SessionFile.jsm:SessionFileInternal.write:315",
        "resource:\/\/app\/modules\/sessionstore\/SessionFile.jsm:this.SessionFile.write:76",
        "resource:\/\/app\/modules\/sessionstore\/SessionSaver.jsm:SessionSaverInternal._writeState:257",
        "resource:\/\/app\/modules\/sessionstore\/SessionSaver.jsm:SessionSaverInternal._saveState:228",
        "resource:\/\/app\/modules\/sessionstore\/SessionSaver.jsm:SessionSaverInternal.run:125",
        "resource:\/\/app\/modules\/sessionstore\/SessionSaver.jsm:this.SessionSaver<.run:76",
        "resource:\/\/\/modules\/sessionstore\/SessionStore.jsm:ssi_uninit:620",
        "resource:\/\/\/modules\/sessionstore\/SessionStore.jsm:ssi_onQuitApplication:1527",
        "resource:\/\/\/modules\/sessionstore\/SessionStore.jsm:ssi_observe:648"
      ]
    }
  ]
}

Comment 6

[David Teller [:Yoric] - still alive but not very active]

The combination of `isFinalWrite` true and `hasEverSucceeded` false is a bit worrying. This seems to indicate that we have never succeeded writing the session file to disk, until shutdown.

Comment 7

[David Teller [:Yoric] - still alive but not very active]

Ok, I believe that I understand the issue.

If we start Firefox with "Forget History", I suspect that we don't initialize Session Restore. Switching to "Remember History" makes us attempt to place a final write to Session Restore, but since Session Restore is not initialized, this fails. Until Bug 1243549, we didn't pay attention to that and errors went unnoticed. Bug 1243549 fixed that and revealed the error.

If my hypothesis proves true, I should be able to fix this in time for uplift to 45.

Comment 8

[David Teller [:Yoric] - still alive but not very active]

Attachment: MozReview Request: Bug 1251347 - Refining SessionFile Shutdown hang details;r?self

Review commit: https://reviewboard.mozilla.org/r/36815/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/36815/

Comment 9

[David Teller [:Yoric] - still alive but not very active]

Attachment: MozReview Request: Bug 1251347 - Making sure that SessionFile.write initializes its workers;r?mconley

Bug 1243549 fixed a race condition during SessionFile startup which
could cause calls to SessionFile.write to send messages to the worker
before it was initialized. The fix consisted in waiting until
initialization was complete before proceeding.

As it turns out, there are cases in which we send messages to the
worker without ever attempting to initialize it, so this wait ends up
causing a hang/shutdown.

This patch fixes the issue by making sure that any message sent to the
worker first initializes the worker if it hasn't been initialized
yet. Since initializing the worker requires us reading the session
store files to find out which one is valid, well, we do exactly that.

Review commit: https://reviewboard.mozilla.org/r/36817/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/36817/

Comment 10

[Sylvestre Ledru [:Sylvestre]]

OK, we are going to start the build of 45 rc 1 next monday evening (paris tz), we need the patch to be in m-r or m-b by that time.

Comment 11

[Mike Conley (:mconley) (:⚙️)]

Comment on attachment 8724025 [details]
MozReview Request: Bug 1251347 - Making sure that SessionFile.write initializes its workers;r?mconley

https://reviewboard.mozilla.org/r/36817/#review33419

This looks good to me. Do we have a contingency in case this results in other problems? We should definitely make sure relman is keeping their eye on this one, and maybe have a back-out strategy for bug 1243549 in place in the event that this goes sideways?

Comment 12

[Marco Bonardo [:mak]]

(In reply to Mike Conley (:mconley) - Needinfo me! from comment #11)
> have a back-out strategy for bug 1243549 in place in
> the event that this goes sideways?

fwiw, the sanitize part of bug 1243549 has already been backed out, as well as bug 1089695 that caused bug 1243549. I didn't backout the session restore part cause it looked like a fix on itself. But it should be possible to just backout that from beta.
Aurora is a different story, we are trying to actually fix the problems there, so no backout strategy so far.

Comment 13

[David Teller [:Yoric] - still alive but not very active]

Comment on attachment 8724023 [details]
MozReview Request: Bug 1251347 - Refining SessionFile Shutdown hang details;r?self

https://reviewboard.mozilla.org/r/36815/#review33431

Trivial testing change, self-reviewing. This part doesn't need uplift.

Comment 14

[quality+bugzilla]

I was going to create a bug due to the following error in the browser console:

Could not write session state file  TypeError: this.Paths is null
Stack trace:
Agent.write@resource:///modules/sessionstore/SessionWorker.js:161:9
worker.dispatch@resource:///modules/sessionstore/SessionWorker.js:21:24
anonymous/AbstractWorker.prototype.handleMessage@resource://gre/modules/workers/PromiseWorker.js:122:16
@resource:///modules/sessionstore/SessionWorker.js:30:41
 Agent.write@resource:///modules/sessionstore/SessionWorker.js:161:9
worker.dispatch@resource:///modules/sessionstore/SessionWorker.js:21:24
anonymous/AbstractWorker.prototype.handleMessage@resource://gre/modules/workers/PromiseWorker.js:122:16
@resource:///modules/sessionstore/SessionWorker.js:30:41

Is this caused by this bug, or is it a different issue?

Comment 15

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

Tracking since this is a current reproducible crash. 
Please request uplift to aurora and beta when you're ready, this would be great to fix !

Comment 16

[David Teller [:Yoric] - still alive but not very active]

(In reply to quality+bugzilla from comment #14)
> I was going to create a bug due to the following error in the browser
> console:
> 
> Could not write session state file  TypeError: this.Paths is null
> Stack trace:
> Agent.write@resource:///modules/sessionstore/SessionWorker.js:161:9
> worker.dispatch@resource:///modules/sessionstore/SessionWorker.js:21:24
> anonymous/AbstractWorker.prototype.handleMessage@resource://gre/modules/
> workers/PromiseWorker.js:122:16
> @resource:///modules/sessionstore/SessionWorker.js:30:41
>  Agent.write@resource:///modules/sessionstore/SessionWorker.js:161:9
> worker.dispatch@resource:///modules/sessionstore/SessionWorker.js:21:24
> anonymous/AbstractWorker.prototype.handleMessage@resource://gre/modules/
> workers/PromiseWorker.js:122:16
> @resource:///modules/sessionstore/SessionWorker.js:30:41
> 
> Is this caused by this bug, or is it a different issue?

Different issue, but I believe that this patch fixes it, too.

Comment 17

[Pulsebot]

https://hg.mozilla.org/integration/mozilla-inbound/rev/cc6dd36ae908
https://hg.mozilla.org/integration/mozilla-inbound/rev/bc6e8eb75949

Comment 18

[quality+bugzilla]

(In reply to David Rajchenbach-Teller [:Yoric] (please use "needinfo") from comment #16)
> (In reply to quality+bugzilla from comment #14)
> > I was going to create a bug due to the following error in the browser
> > console:
> > 
> > Could not write session state file  TypeError: this.Paths is null
> > Stack trace:
> > Agent.write@resource:///modules/sessionstore/SessionWorker.js:161:9
> > worker.dispatch@resource:///modules/sessionstore/SessionWorker.js:21:24
> > anonymous/AbstractWorker.prototype.handleMessage@resource://gre/modules/
> > workers/PromiseWorker.js:122:16
> > @resource:///modules/sessionstore/SessionWorker.js:30:41
> >  Agent.write@resource:///modules/sessionstore/SessionWorker.js:161:9
> > worker.dispatch@resource:///modules/sessionstore/SessionWorker.js:21:24
> > anonymous/AbstractWorker.prototype.handleMessage@resource://gre/modules/
> > workers/PromiseWorker.js:122:16
> > @resource:///modules/sessionstore/SessionWorker.js:30:41
> > 
> > Is this caused by this bug, or is it a different issue?
> 
> Different issue, but I believe that this patch fixes it, too.

Thanks so much.  Can both issues be lumped into this bug, or do they need to get separate bugs for testing or other purposes?

Comment 19

[David Teller [:Yoric] - still alive but not very active]

I'd be more comfortable with another bug, blocked by this one.

Comment 20

[Sylvestre Ledru [:Sylvestre]]

David, could you fill an uplift request to Aurora and beta? Merci

Comment 21

[David Teller [:Yoric] - still alive but not very active]

Comment on attachment 8724025 [details]
MozReview Request: Bug 1251347 - Making sure that SessionFile.write initializes its workers;r?mconley

Approval Request Comment
[Feature/regressing bug #]: Bug 1243549, but original bug is much, much, much older.
[User impact if declined]: User cannot switch from "Never remember history" to "Remember history" without crashing Firefox. This patch probably also fixes some Session Restore dataloss issues.
[Describe test coverage new/current, TreeHerder]: Just landed. Green on TreeHerder.
[Risks and why]: If we mess up Session Restore, we should realize this very out quickly on Nightly. If so, mak has a backout plan.
[String/UUID change made/needed]: 0

Comment 22

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/cc6dd36ae908
https://hg.mozilla.org/mozilla-central/rev/bc6e8eb75949

Comment 23

[Sylvestre Ledru [:Sylvestre]]

Comment on attachment 8724025 [details]
MozReview Request: Bug 1251347 - Making sure that SessionFile.write initializes its workers;r?mconley

Fix a crash, taking it. Should be in 45 rc1

Comment 24

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/ae9f8a99c11e

Comment 25

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/releases/mozilla-beta/rev/5cd15f382c0c

Comment 27

[Saheda Reza [:Antora]]

Reproduced this successfully according to 47.0a1 (2016-2-23) 

Verified is done by Latest Beta, Nightly, Developer Edition:

Beta--Build ID(20160301003640),Mozilla/5.0 (Windows NT 6.3; rv:45.0) Gecko/20100101 Firefox/45.0

Developer Edition--Build ID(20160302004006),Mozilla/5.0 (Windows NT 6.3; rv:46.0) Gecko/20100101 Firefox/46.0

Nightly--Build ID(20160302030209),Mozilla/5.0 (Windows NT 6.3; rv:47.0) Gecko/20100101 Firefox/47.0
 	

Tested OS-Windows8.1 32bit

Comment 28

[Mayur Patil]

[bugday-20160323]

Status: RESOLVED,FIXED -> VERIFIED

Comments:
Test Successful

Component: 
Name			Firefox
Version			46.0b9
Build ID		20160322075646
Update Channel          beta
User Agent		Mozilla/5.0 (Windows NT 6.1; WOW64; rv:46.0) Gecko/20100101 Firefox/46.0
OS			Windows 7 SP1 x86_64

Expected Results: 
Yes

Actual Results: 
As expected