Bugzilla

To make it easier to debug the issue, I have commented out the [rest of the test](https://searchfox.org/mozilla-central/rev/78f4bb0d4d2c95ad302d54d78c77a223fea6ccb2/browser/components/sessionstore/test/browser_491168.js#68-111) right away.

Observations so far:

- Right away after running this test for a few times, you might notice that sometimes it passes and sometimes it fails. In cases when it fails, the issue is that ` tabState.entries[0]` is undefined [here](https://searchfox.org/mozilla-central/rev/78f4bb0d4d2c95ad302d54d78c77a223fea6ccb2/browser/components/sessionstore/test/browser_491168.js#60). 
- I added some logging and see that the [expected `historychange` update](https://searchfox.org/mozilla-central/rev/78f4bb0d4d2c95ad302d54d78c77a223fea6ccb2/browser/components/sessionstore/TabStateCache.jsm#232) does indeed happen, but in cases when we have no `entries`, the update happens too late, after the test has finished, or at least after the assertion. That makes it seem that sometimes the `historychange` update takes too long. So this was my next question, why does it take longer sometimes? 
- I traced down code that initiates the correct `historychange` update, and it happens to be `requestTabStateFlush()` that gets called because of `await TabStateFlusher.flush(browser);` in the test. 
- So following the previous theory, how can it be that sometimes this update "takes longer" if we await for this promise? So it looks like the promise that we return from `TabStateFlusher.flush` is 
```
Promise.race([
      nativePromise.then(_ => requestPromise),
      request.cancelPromise,
    ]);
```
   - I decided to add debug prints to places where might either resolve `requestPromise` or `request.cancelPromise`, which was [in `resolve()`](https://searchfox.org/mozilla-central/rev/78f4bb0d4d2c95ad302d54d78c77a223fea6ccb2/browser/components/sessionstore/TabStateFlusher.jsm#199) and in [`resolveAll()`](https://searchfox.org/mozilla-central/rev/78f4bb0d4d2c95ad302d54d78c77a223fea6ccb2/browser/components/sessionstore/TabStateFlusher.jsm#235)


(still editing but saving the comment just in case)

To make it easier to debug the issue, I have commented out the [rest of the test](https://searchfox.org/mozilla-central/rev/78f4bb0d4d2c95ad302d54d78c77a223fea6ccb2/browser/components/sessionstore/test/browser_491168.js#68-111) right away.

Observations so far:

- Right away after running this test for a few times, you might notice that sometimes it passes and sometimes it fails. In cases when it fails, the issue is that ` tabState.entries[0]` is undefined [here](https://searchfox.org/mozilla-central/rev/78f4bb0d4d2c95ad302d54d78c77a223fea6ccb2/browser/components/sessionstore/test/browser_491168.js#60). 
- I added some logging and see that the [expected `historychange` update](https://searchfox.org/mozilla-central/rev/78f4bb0d4d2c95ad302d54d78c77a223fea6ccb2/browser/components/sessionstore/TabStateCache.jsm#232) does indeed happen, but in cases when we have no `entries`, the update happens too late, after the test has finished, or at least after the assertion. That makes it seem that sometimes the `historychange` update takes too long. So this was my next question, why does it take longer sometimes? 
- I traced down code that initiates the correct `historychange` update, and it happens to be `requestTabStateFlush()` that gets called because of `await TabStateFlusher.flush(browser);` in the test. 
- So following the previous theory, how can it be that sometimes this update "takes longer" if we await for this promise? So it looks like the promise that we return from `TabStateFlusher.flush` is 
```
Promise.race([
      nativePromise.then(_ => requestPromise),
      request.cancelPromise,
    ]);
```
   - I decided to add debug prints to places where might either resolve `requestPromise` or `request.cancelPromise`, which was in [`resolve()`](https://searchfox.org/mozilla-central/rev/78f4bb0d4d2c95ad302d54d78c77a223fea6ccb2/browser/components/sessionstore/TabStateFlusher.jsm#199) and in [`resolveAll()`](https://searchfox.org/mozilla-central/rev/78f4bb0d4d2c95ad302d54d78c77a223fea6ccb2/browser/components/sessionstore/TabStateFlusher.jsm#235). The latter is used used for "when the content process crashed or the final update message was seen". When the test failed the next time, I saw that `resolveAll` has been called first. It was called from `onFinalTabStateUpdateComplete` , which at some point was triggered by a call [here](https://searchfox.org/mozilla-central/rev/78f4bb0d4d2c95ad302d54d78c77a223fea6ccb2/browser/components/sessionstore/SessionStore.jsm#1014) within when message "browser-shutdown-tabstate-updated" was received. This message is sent from `WindowGlobalParent::NotifySessionStoreUpdatesComplete`, which was called by `nsFrameLoader::RequestFinalTabStateFlush` (but not invoked by JS code). When I printed out the bc, it was one belonging to the previous navigation, about:blank. I also checked if that bc's current window global was equal to `this` and it was not (`GetBrowsingContext()->GetCurrentWindowGlobal() == this`). Both of these things indicate that this is a session store update call that was corresponding to a previous navigation, and is not for the current navigation. The test passes if I add a change within `WindowGlobalParent::NotifySessionStoreUpdatesComplete`  to also check for `IsCurrentGlobal` [here](https://searchfox.org/mozilla-central/rev/78f4bb0d4d2c95ad302d54d78c77a223fea6ccb2/dom/ipc/WindowGlobalParent.cpp#1342). Going to see if try looks good for other tests as well.




(still editing but saving the comment just in case)

To make it easier to debug the issue, I have commented out the [rest of the test](https://searchfox.org/mozilla-central/rev/78f4bb0d4d2c95ad302d54d78c77a223fea6ccb2/browser/components/sessionstore/test/browser_491168.js#68-111) right away.

Observations so far:

- Right away after running this test for a few times, you might notice that sometimes it passes and sometimes it fails. In cases when it fails, the issue is that ` tabState.entries[0]` is undefined [here](https://searchfox.org/mozilla-central/rev/78f4bb0d4d2c95ad302d54d78c77a223fea6ccb2/browser/components/sessionstore/test/browser_491168.js#60). 
- I added some logging and see that the [expected `historychange` update](https://searchfox.org/mozilla-central/rev/78f4bb0d4d2c95ad302d54d78c77a223fea6ccb2/browser/components/sessionstore/TabStateCache.jsm#232) does indeed happen, but in cases when we have no `entries`, the update happens too late, after the test has finished, or at least after the assertion. That makes it seem that sometimes the `historychange` update takes too long. So this was my next question, why does it take longer sometimes? 
- I traced down code that initiates the correct `historychange` update, and it happens to be `requestTabStateFlush()` that gets called because of `await TabStateFlusher.flush(browser);` in the test. 
- So following the previous theory, how can it be that sometimes this update "takes longer" if we await for this promise? So it looks like the promise that we return from `TabStateFlusher.flush` is 
```
Promise.race([
      nativePromise.then(_ => requestPromise),
      request.cancelPromise,
    ]);
```
   - I decided to add debug prints to places where might either resolve `requestPromise` or `request.cancelPromise`, which was in [`resolve()`](https://searchfox.org/mozilla-central/rev/78f4bb0d4d2c95ad302d54d78c77a223fea6ccb2/browser/components/sessionstore/TabStateFlusher.jsm#199) and in [`resolveAll()`](https://searchfox.org/mozilla-central/rev/78f4bb0d4d2c95ad302d54d78c77a223fea6ccb2/browser/components/sessionstore/TabStateFlusher.jsm#235). The latter is used used for "when the content process crashed or the final update message was seen". When the test failed the next time, I saw that `resolveAll` has been called first. It was called from `onFinalTabStateUpdateComplete` , which at some point was triggered by a call [here](https://searchfox.org/mozilla-central/rev/78f4bb0d4d2c95ad302d54d78c77a223fea6ccb2/browser/components/sessionstore/SessionStore.jsm#1014) within when message "browser-shutdown-tabstate-updated" was received. This message is sent from `WindowGlobalParent::NotifySessionStoreUpdatesComplete`, which was called by `nsFrameLoader::RequestFinalTabStateFlush` (but not invoked by JS code). When I printed out the bc, it was one belonging to the previous navigation, about:blank. I also checked if that bc's current window global was equal to `this` and it was not (`GetBrowsingContext()->GetCurrentWindowGlobal() == this`). Both of these things indicate that this is a session store update call that was corresponding to a previous navigation, and is not for the current navigation. The test passes if I add a change within `WindowGlobalParent::NotifySessionStoreUpdatesComplete`  to also check for `IsCurrentGlobal` [here](https://searchfox.org/mozilla-central/rev/78f4bb0d4d2c95ad302d54d78c77a223fea6ccb2/dom/ipc/WindowGlobalParent.cpp#1342). Going to see if try looks good for other tests as well.