Ryan VanderMeulen [:RyanVM] Reporter
	Description • 9 years ago

It's not immediately clear what broke this, but it's something from the last few days (my mid-week simulation push wasn't hitting this). I'll try to bisect it down.

https://treeherder.mozilla.org/logviewer.html#?job_id=6018968&repo=try

15:39:56 INFO - Assertion failure: !aOther.IsNull() (Cannot compute with aOther null value), at ../../../dist/include/mozilla/TimeStamp.h:510
15:39:56 INFO - #01: mozilla::RecordShutdownEndTimeStamp() [xpcom/ds/TimeStamp.h:510]
15:39:56 INFO - #02: XRE_main [toolkit/xre/nsAppRunner.cpp:4500]
15:39:56 INFO - #03: do_main [browser/app/nsBrowserApp.cpp:294]
15:39:56 INFO - #04: main [browser/app/nsBrowserApp.cpp:669]
15:39:56 INFO - TEST-INFO | Main app process: killed by out-of-range signal, number 117
15:39:56 INFO - 617 INFO checking window state
15:39:56 INFO - 618 INFO TEST-START | Shutdown
15:39:56 INFO - 619 INFO Browser Chrome Test Summary
15:39:56 INFO - 620 INFO Passed: 12842
15:39:56 INFO - 621 INFO Failed: 0
15:39:56 INFO - 622 INFO Todo: 0
15:39:56 INFO - 623 INFO *** End BrowserChrome Test Results ***
15:39:56 WARNING - TEST-UNEXPECTED-FAIL | toolkit/mozapps/extensions/test/browser/test-window/browser_updateid.js | application terminated with exit code -11

	Ryan VanderMeulen [:RyanVM] Reporter
	Comment 1 • 9 years ago

Initial regression range based on my last green simulation push:
https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=cc0950b7a369&tochange=44e454b5e93b

	Ryan VanderMeulen [:RyanVM] Reporter
	Comment 2 • 9 years ago

Down to https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=a88935c80ba5&tochange=8a1bac74ed80

	Ryan VanderMeulen [:RyanVM] Reporter
	Comment 3 • 9 years ago

More fun with Telemetry shutdown it appears.
https://hg.mozilla.org/integration/fx-team/pushloghtml?fromchange=01482cdccd72&tochange=386d8cc19d8d

I'll narrow it down to the specific cset.

	Ryan VanderMeulen [:RyanVM] Reporter
	Comment 4 • 9 years ago

First bad rev:
https://hg.mozilla.org/integration/fx-team/rev/135c75e6fa1e

Regression from bug 1134279.

	Ryan VanderMeulen [:RyanVM] Reporter
	Comment 5 • 9 years ago

Note that rev 2aa9f4d0385d didn't build by itself, so I don't know which of the two csets was responsible. For future reference, situations like these are why the practice of ensuring that every cset pushed is independently buildable/testable is strongly encouraged :)

	Alessio Placitelli [:Dexter] Assignee
	Comment 6 • 9 years ago

This patch removes a double TelemetrySession initialisation in the browser_bug557956.js test, which was causing the weird shutdown behaviour in browser_updateid.js.

Try push with trunk as beta:

https://treeherder.mozilla.org/#/jobs?repo=try&revision=06ad4850cc78

Try push with vanilla trunk:

https://treeherder.mozilla.org/#/jobs?repo=try&revision=b5aacd4f7f69

	Georg Fritzsche [:gfritzsche]
	Comment 7 • 9 years ago

Comment on attachment 8586718 [details] [diff] [review]
bug1148763.patch

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

::: toolkit/mozapps/extensions/test/browser/browser_bug557956.js
@@ -198,5 @@
>    Services.telemetry.canRecordExtended = true;
>    registerCleanupFunction(function () {
>      Services.telemetry.canRecordExtended = oldCanRecord;
>    });
> -  TelemetrySession.setup().then(run_next_test);

Whats the actual problem here?
Maybe we should just bail out early out of TelemetrySession.setupChromeProcess() on this._initStarted too?

	Alessio Placitelli [:Dexter] Assignee
	Comment 8 • 9 years ago

(In reply to Georg Fritzsche [:gfritzsche] from comment #7)
> Whats the actual problem here?

Forcing canRecordExtended to true makes |GetShutdownTimeFileName| get called and set |gRecordedShutdownTimeFileName|, which guards |RecordShutdownEndTimeStamp|. After the test runs, we correctly restore canRecordExtended to the old value (false).

When shutting down the browser, RecordShutdownStartTimeStamp [1] is not recording the timestamp due to Telemetry being disabled. RecordShutdownEndTimeStamp [1] still gets called, as |gRecordedShutdownTimeFileName| is set.

> Maybe we should just bail out early out of
> TelemetrySession.setupChromeProcess() on this._initStarted too?

I can add that, but his really only happens in Mochitests and I think we shouldn't be initializing TelemetrySession in that test to begin with.

[1] - https://hg.mozilla.org/mozilla-central/annotate/18a8ea7c2c62/toolkit/components/telemetry/Telemetry.cpp#l3558
[2] - https://hg.mozilla.org/mozilla-central/annotate/18a8ea7c2c62/toolkit/components/telemetry/Telemetry.cpp#l3568
[3] - https://hg.mozilla.org/mozilla-central/annotate/18a8ea7c2c62/toolkit/components/telemetry/Telemetry.cpp#l1773

	Georg Fritzsche [:gfritzsche]
	Comment 9 • 9 years ago

(In reply to Alessio Placitelli [:Dexter] from comment #8)
> (In reply to Georg Fritzsche [:gfritzsche] from comment #7)
> > Whats the actual problem here?
> 
> Forcing canRecordExtended to true makes |GetShutdownTimeFileName| get called
> and set |gRecordedShutdownTimeFileName|, which guards
> |RecordShutdownEndTimeStamp|. After the test runs, we correctly restore
> canRecordExtended to the old value (false).
> 
> When shutting down the browser, RecordShutdownStartTimeStamp [1] is not
> recording the timestamp due to Telemetry being disabled.
> RecordShutdownEndTimeStamp [1] still gets called, as
> |gRecordedShutdownTimeFileName| is set.

This sounds potentially broken then, can you file a phase 4 follow-up on that?
Apparently this is hard to trace down and we should consider if we can fix it or make it a clearer failure etc.

> > Maybe we should just bail out early out of
> > TelemetrySession.setupChromeProcess() on this._initStarted too?
> 
> I can add that, but his really only happens in Mochitests and I think we
> shouldn't be initializing TelemetrySession in that test to begin with.

Yes and yes. This bug just points to that issue and we should fix it.
We don't have any safe-guards against calling TelemetrySession.setup() twice though, so we should fix that just like the this._initialized guard.

If the test works fine with those parts removed then that's good.
Is this test still fine if it is run alone, i.e. when the delayed TelemetrySession init didn't finish yet?

	Alessio Placitelli [:Dexter] Assignee
	Comment 10 • 9 years ago

(In reply to Georg Fritzsche [:gfritzsche] from comment #9)
> (In reply to Alessio Placitelli [:Dexter] from comment #8)
> > (In reply to Georg Fritzsche [:gfritzsche] from comment #7)
> > > Whats the actual problem here?
> > 
> > Forcing canRecordExtended to true makes |GetShutdownTimeFileName| get called
> > and set |gRecordedShutdownTimeFileName|, which guards
> > |RecordShutdownEndTimeStamp|. After the test runs, we correctly restore
> > canRecordExtended to the old value (false).
> > 
> > When shutting down the browser, RecordShutdownStartTimeStamp [1] is not
> > recording the timestamp due to Telemetry being disabled.
> > RecordShutdownEndTimeStamp [1] still gets called, as
> > |gRecordedShutdownTimeFileName| is set.
> 
> This sounds potentially broken then, can you file a phase 4 follow-up on
> that?
> Apparently this is hard to trace down and we should consider if we can fix
> it or make it a clearer failure etc.

Filed bug 1149980 for that.

> > > Maybe we should just bail out early out of
> > > TelemetrySession.setupChromeProcess() on this._initStarted too?
> > 
> > I can add that, but his really only happens in Mochitests and I think we
> > shouldn't be initializing TelemetrySession in that test to begin with.
> 
> Yes and yes. This bug just points to that issue and we should fix it.
> We don't have any safe-guards against calling TelemetrySession.setup() twice
> though, so we should fix that just like the this._initialized guard.

As we discussed over IRC, that's not needed, as |.setup()| already bails out if |this._initialized| or there's an init task already running.

> If the test works fine with those parts removed then that's good.
> Is this test still fine if it is run alone, i.e. when the delayed
> TelemetrySession init didn't finish yet?

Yes, the test still works when run alone.

	Ryan VanderMeulen [:RyanVM] Reporter
	Comment 11 • 9 years ago

https://hg.mozilla.org/integration/fx-team/rev/2edd4fbfb7e1

	Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)
	Comment 12 • 9 years ago

https://hg.mozilla.org/mozilla-central/rev/2edd4fbfb7e1

	Ryan VanderMeulen [:RyanVM] Reporter
	Comment 13 • 9 years ago

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