From c585b5053fd8c4bed3632666313eb4dfa00368c8 Mon Sep 17 00:00:00 2001 From: Dan Mosedale Date: Mon, 7 Aug 2017 14:05:31 -0700 Subject: [PATCH 1/2] fix(telemetry): closes #3105, dont overwrite existing hero element time --- .../components/TopSites/TopSites.jsx | 25 +++++++----- .../content-src/components/TopSites.test.jsx | 38 +++++++++++++------ 2 files changed, 42 insertions(+), 21 deletions(-) diff --git a/system-addon/content-src/components/TopSites/TopSites.jsx b/system-addon/content-src/components/TopSites/TopSites.jsx index 4cded2bdbe..6365d3b536 100644 --- a/system-addon/content-src/components/TopSites/TopSites.jsx +++ b/system-addon/content-src/components/TopSites/TopSites.jsx @@ -105,7 +105,7 @@ class TopSitesPerfTimer extends React.Component { this.perfSvc = this.props.perfSvc || perfSvc; this._sendPaintedEvent = this._sendPaintedEvent.bind(this); - this._timestampSent = false; + this._timestampHandled = false; } componentDidMount() { @@ -131,11 +131,6 @@ class TopSitesPerfTimer extends React.Component { } _maybeSendPaintedEvent() { - // If we've already saved a timestamp for this session, don't do so again. - if (this._timestampSent) { - return; - } - // We don't want this to ever happen, but sometimes it does. And when it // does (typically on the first newtab at startup time calling // componentDidMount), the paint(s) we care about will be later (eg @@ -145,6 +140,19 @@ class TopSitesPerfTimer extends React.Component { return; } + // If we've already handled a timestamp, don't do it again + if (this._timestampHandled) { + return; + } + + // And if we haven't, we're doing so now, so remember that. + // Even if something goes wrong in the callback, we can't + // try again, as we'd be sending back the wrong data, and we + // have to do it here, so that other calls to this method + // while waiting for the next frame won't also try to handle + // handle it. + this._timestampHandled = true; + this._onNextFrame(this._sendPaintedEvent); } @@ -162,11 +170,10 @@ class TopSitesPerfTimer extends React.Component { } catch (ex) { // If this failed, it's likely because the `privacy.resistFingerprinting` // pref is true. We should at least not blow up, and should continue - // to set this._timestampSent to avoid going through this again. + // to set this._timestampHandled to avoid going through this again. } - - this._timestampSent = true; } + render() { return (); } diff --git a/system-addon/test/unit/content-src/components/TopSites.test.jsx b/system-addon/test/unit/content-src/components/TopSites.test.jsx index 6d17853d67..03ade2d899 100644 --- a/system-addon/test/unit/content-src/components/TopSites.test.jsx +++ b/system-addon/test/unit/content-src/components/TopSites.test.jsx @@ -81,16 +81,40 @@ describe("", () => { assert.notCalled(stub); }); - it("should not call _onNextFrame if this._timestampSent is true", () => { + + it("should not call _onNextFrame if this._timestampHandled is true", () => { const wrapper = shallow(); const instance = wrapper.instance(); const stub = sandbox.stub(instance, "_onNextFrame"); - instance._timestampSent = true; + instance._timestampHandled = true; instance._maybeSendPaintedEvent(); assert.notCalled(stub); }); + + it("should set this._timestampHandled=true when called with Topsites.initialized === true", () => { + const wrapper = shallow(); + const instance = wrapper.instance(); + sandbox.stub(instance, "_onNextFrame"); + instance._timestampHandled = false; + + instance._maybeSendPaintedEvent(); + + assert.isTrue(instance._timestampHandled); + }); + it("should not set this._timestampHandled=true when called with Topsites.initialized === false", () => { + let props = {}; + Object.assign(props, DEFAULT_PROPS, {TopSites: {initialized: false}}); + const wrapper = shallow(); + const instance = wrapper.instance(); + sandbox.stub(instance, "_onNextFrame"); + instance._timestampHandled = false; + + instance._maybeSendPaintedEvent(); + + assert.isFalse(instance._timestampHandled); + }); }); describe("#_onNextFrame", () => { @@ -120,16 +144,6 @@ describe("", () => { assert.calledWithExactly(perfSvc.mark, "topsites_first_painted_ts"); }); - it("should set this._timestamp_sent to true", () => { - const wrapper = shallow(); - const instance = wrapper.instance(); - assert.isFalse(instance._timestampSent); - - wrapper.instance()._sendPaintedEvent(); - - assert.isTrue(instance._timestampSent); - }); - it("should send a SAVE_SESSION_PERF_DATA message with the result of perfSvc.getMostRecentAbsMarkStartByName two frames after mount", () => { sandbox.stub(perfSvc, "getMostRecentAbsMarkStartByName") .withArgs("topsites_first_painted_ts").returns(777); From 1817be97afcf43614846eef08ba179daec888a40 Mon Sep 17 00:00:00 2001 From: Dan Mosedale Date: Mon, 7 Aug 2017 15:06:17 -0700 Subject: [PATCH 2/2] fix(telemetry): make paint timings more precise --- .../components/TopSites/TopSites.jsx | 18 ++++++----- .../content-src/components/TopSites.test.jsx | 30 +++++++++---------- 2 files changed, 25 insertions(+), 23 deletions(-) diff --git a/system-addon/content-src/components/TopSites/TopSites.jsx b/system-addon/content-src/components/TopSites/TopSites.jsx index 6365d3b536..9460bce9de 100644 --- a/system-addon/content-src/components/TopSites/TopSites.jsx +++ b/system-addon/content-src/components/TopSites/TopSites.jsx @@ -117,17 +117,21 @@ class TopSitesPerfTimer extends React.Component { } /** - * Call the given callback when the subsequent animation frame - * (not the upcoming one) paints. + * Call the given callback after the upcoming frame paints. We're using + * a Promise rather than a setTimeout or double rFA, as Promise resolution + * is faster, as of this writing (Firefox 57 Nightly) - see #3105 for + * details. * * @param {Function} callback * * @returns void */ - _onNextFrame(callback) { - requestAnimationFrame(() => { - requestAnimationFrame(callback); - }); + _afterFramePaint(callback) { + new Promise(resolve => requestAnimationFrame(resolve)) + .then(callback).catch(reason => { + // eslint-disable-next-line no-console + console.warn("_afterFramePaint Promise rejected, reason:", reason); + }); } _maybeSendPaintedEvent() { @@ -153,7 +157,7 @@ class TopSitesPerfTimer extends React.Component { // handle it. this._timestampHandled = true; - this._onNextFrame(this._sendPaintedEvent); + this._afterFramePaint(this._sendPaintedEvent); } _sendPaintedEvent() { diff --git a/system-addon/test/unit/content-src/components/TopSites.test.jsx b/system-addon/test/unit/content-src/components/TopSites.test.jsx index 03ade2d899..22cddb465d 100644 --- a/system-addon/test/unit/content-src/components/TopSites.test.jsx +++ b/system-addon/test/unit/content-src/components/TopSites.test.jsx @@ -61,31 +61,31 @@ describe("", () => { }); describe("#_maybeSendPaintedEvent", () => { - it("should call _onNextFrame if props.TopSites.initialized is true", () => { + it("should call _afterFramePaint if props.TopSites.initialized is true", () => { const wrapper = shallow(); const instance = wrapper.instance(); - const stub = sandbox.stub(instance, "_onNextFrame"); + const stub = sandbox.stub(instance, "_afterFramePaint"); instance._maybeSendPaintedEvent(); assert.calledOnce(stub); assert.calledWithExactly(stub, instance._sendPaintedEvent); }); - it("should not call _onNextFrame if props.TopSites.initialized is false", () => { + it("should not call _afterFramePaint if props.TopSites.initialized is false", () => { sandbox.stub(DEFAULT_PROPS.TopSites, "initialized").value(false); const wrapper = shallow(); const instance = wrapper.instance(); - const stub = sandbox.stub(instance, "_onNextFrame"); + const stub = sandbox.stub(instance, "_afterFramePaint"); instance._maybeSendPaintedEvent(); assert.notCalled(stub); }); - it("should not call _onNextFrame if this._timestampHandled is true", () => { + it("should not call _afterFramePaint if this._timestampHandled is true", () => { const wrapper = shallow(); const instance = wrapper.instance(); - const stub = sandbox.stub(instance, "_onNextFrame"); + const stub = sandbox.stub(instance, "_afterFramePaint"); instance._timestampHandled = true; instance._maybeSendPaintedEvent(); @@ -96,7 +96,7 @@ describe("", () => { it("should set this._timestampHandled=true when called with Topsites.initialized === true", () => { const wrapper = shallow(); const instance = wrapper.instance(); - sandbox.stub(instance, "_onNextFrame"); + sandbox.stub(instance, "_afterFramePaint"); instance._timestampHandled = false; instance._maybeSendPaintedEvent(); @@ -108,7 +108,7 @@ describe("", () => { Object.assign(props, DEFAULT_PROPS, {TopSites: {initialized: false}}); const wrapper = shallow(); const instance = wrapper.instance(); - sandbox.stub(instance, "_onNextFrame"); + sandbox.stub(instance, "_afterFramePaint"); instance._timestampHandled = false; instance._maybeSendPaintedEvent(); @@ -117,19 +117,17 @@ describe("", () => { }); }); - describe("#_onNextFrame", () => { - it("should call callback one frame after the current one", () => { - const callback = sandbox.spy(); + describe("#_afterFramePaint", () => { + it("should call callback after the requestAnimationFrame callback returns", done => { + this.callback = () => done(); + sandbox.spy(this, "callback"); const wrapper = shallow(); - const instance = wrapper.instance(); - instance._onNextFrame(callback); - mockRaf.step({count: 1}); - assert.notCalled(callback); + instance._afterFramePaint(this.callback); + assert.notCalled(this.callback); mockRaf.step({count: 1}); - assert.calledOnce(callback); }); });