Skip to content

Commit

Permalink
performance-impl: use performance.now() over Date.now() (#26512)
Browse files Browse the repository at this point in the history 
* performance-impl: use performance apis instead of Date.now()

* small self-nit

* missed a Date.now()

* fix strange test

* lint and delete incorrect comment

* prerenderComplete test should check for subtraction of docVisible time

* make it harder to think that perf.now can be stubbed with Date.now

* fix failing test.

* should not check ordering
  • Loading branch information
@samouri
samouri committed Feb 24, 2020
1 parent 1b24138 commit 3a7b315
Show file tree
Hide file tree
Showing 3 changed files with 44 additions and 30 deletions.
8 changes: 8 additions & 0 deletions extensions/amp-access/0.1/test/test-amp-access.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -37,6 +37,7 @@ describes.fakeWin(

beforeEach(() => {
win = env.win;
win.performance = {timeOrigin: 1};
ampdoc = env.ampdoc;
document = win.document;

Expand Down Expand Up @@ -271,6 +272,7 @@ describes.fakeWin(

beforeEach(() => {
win = env.win;
win.performance = {timeOrigin: 1};
ampdoc = env.ampdoc;
document = win.document;
clock = env.sandbox.useFakeTimers();
Expand Down Expand Up @@ -563,6 +565,7 @@ describes.fakeWin(

beforeEach(() => {
win = env.win;
win.performance = {timeOrigin: 1};
ampdoc = env.ampdoc;
document = win.document;

Expand Down Expand Up @@ -723,6 +726,7 @@ describes.fakeWin(

beforeEach(() => {
win = env.win;
win.performance = {timeOrigin: 1};
ampdoc = env.ampdoc;
document = win.document;
clock = env.sandbox.useFakeTimers();
Expand Down Expand Up @@ -1125,6 +1129,7 @@ describes.fakeWin(

beforeEach(() => {
win = env.win;
win.performance = {timeOrigin: 1};
ampdoc = env.ampdoc;
document = win.document;

Expand Down Expand Up @@ -1209,6 +1214,7 @@ describes.fakeWin(

beforeEach(() => {
win = env.win;
win.performance = {timeOrigin: 1};
ampdoc = env.ampdoc;
document = win.document;
clock = env.sandbox.useFakeTimers();
Expand Down Expand Up @@ -1623,6 +1629,7 @@ describes.fakeWin(

beforeEach(() => {
win = env.win;
win.performance = {timeOrigin: 1};
ampdoc = env.ampdoc;
document = win.document;

Expand Down Expand Up @@ -1751,6 +1758,7 @@ describes.fakeWin(

beforeEach(() => {
win = env.win;
win.performance = {timeOrigin: 1};
ampdoc = env.ampdoc;
document = win.document;
clock = env.sandbox.useFakeTimers();
Expand Down
46 changes: 19 additions & 27 deletions src/service/performance-impl.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -61,12 +61,13 @@ export class Performance {
/** @const {!Window} */
this.win = win;

/** @private @const {number} */
this.initTime_ = this.win.Date.now();

/** @const @private {!Array<TickEventDef>} */
this.events_ = [];

/** @const @private {number} */
this.timeOrigin_ =
win.performance.timeOrigin || win.performance.timing.navigationStart;

/** @private {?./ampdoc-impl.AmpDoc} */
this.ampdoc_ = null;

Expand Down Expand Up @@ -233,14 +234,10 @@ export class Performance {
return channelPromise
.then(() => {
// Tick the "messaging ready" signal.
this.tickDelta('msr', this.win.Date.now() - this.initTime_);
this.tickDelta('msr', this.win.performance.now());

// Tick timeOrigin so that epoch time can be calculated by consumers.
this.tickDelta(
'timeOrigin',
this.win.performance.timeOrigin ||
this.win.performance.timing.navigationStart
);
this.tickDelta('timeOrigin', this.timeOrigin_);

return this.maybeAddStoryExperimentId_();
})
Expand Down Expand Up @@ -464,7 +461,7 @@ export class Performance {
* method does nothing if it is available.
*/
tickLegacyFirstPaintTime_() {
// Detect deprecated first pain time API
// Detect deprecated first paint time API
// https://bugs.chromium.org/p/chromium/issues/detail?id=621512
// We'll use this until something better is available.
if (
Expand Down Expand Up @@ -504,12 +501,10 @@ export class Performance {
*/
measureUserPerceivedVisualCompletenessTime_() {
const didStartInPrerender = !this.ampdoc_.hasBeenVisible();
let docVisibleTime = didStartInPrerender ? -1 : this.initTime_;

// This will only be relevant if the ampdoc is in prerender mode.
// (hasn't been visible yet, ever at this point)
let docVisibleTime = -1;
this.ampdoc_.whenFirstVisible().then(() => {
docVisibleTime = this.win.Date.now();
docVisibleTime = this.win.performance.now();
// Mark this first visible instance in the browser timeline.
this.mark('visible');
});
Expand All @@ -518,7 +513,7 @@ export class Performance {
if (didStartInPrerender) {
const userPerceivedVisualCompletenesssTime =
docVisibleTime > -1
? this.win.Date.now() - docVisibleTime
? this.win.performance.now() - docVisibleTime
: // Prerender was complete before visibility.
0;
this.ampdoc_.whenFirstVisible().then(() => {
Expand All @@ -536,9 +531,7 @@ export class Performance {
// and we just need to tick `pc`. (it will give us the relative
// time since the viewer initialized the timer)
this.tick('pc');
// We don't have the actual csi timer's clock start time,
// so we just have to use `docVisibleTime`.
this.prerenderComplete_(this.win.Date.now() - docVisibleTime);
this.prerenderComplete_(this.win.performance.now() - docVisibleTime);
}
this.flush();
});
Expand Down Expand Up @@ -575,17 +568,16 @@ export class Performance {
*/
tick(label, opt_delta) {
const data = dict({'label': label});
let storedVal;
let delta;

// Absolute value case (not delta).
if (opt_delta == undefined) {
// Marking only makes sense for non-deltas.
this.mark(label);
const now = this.win.Date.now();
data['value'] = now;
storedVal = now - this.initTime_;
delta = this.win.performance.now();
data['value'] = this.timeOrigin_ + delta;
} else {
data['delta'] = storedVal = Math.max(opt_delta, 0);
data['delta'] = delta = Math.max(opt_delta, 0);
}

if (this.isMessagingReady_ && this.isPerformanceTrackingOn_) {
Expand All @@ -596,13 +588,13 @@ export class Performance {

switch (label) {
case 'fcp':
this.fcpDeferred_.resolve(storedVal);
this.fcpDeferred_.resolve(delta);
break;
case 'pc':
this.fvrDeferred_.resolve(storedVal);
this.fvrDeferred_.resolve(delta);
break;
case 'mbv':
this.mbvDeferred_.resolve(storedVal);
this.mbvDeferred_.resolve(delta);
break;
}
}
Expand Down Expand Up @@ -638,7 +630,7 @@ export class Performance {
* @param {string} label The variable name as it will be reported.
*/
tickSinceVisible(label) {
const now = this.win.Date.now();
const now = this.timeOrigin_ + this.win.performance.now();
const visibleTime = this.ampdoc_ ? this.ampdoc_.getFirstVisibleTime() : 0;
const v = visibleTime ? Math.max(now - visibleTime, 0) : 0;
this.tickDelta(label, v);
Expand Down
20 changes: 17 additions & 3 deletions test/unit/test-performance.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -39,6 +39,8 @@ describes.realWin('performance', {amp: true}, env => {
// set initial Date.now to 100, so that we can differentiate between time relative to epoch and relative to process start (value vs. delta).
now: timeOrigin,
});
Object.defineProperty(win.performance, 'timeOrigin', {value: timeOrigin}); // timeOrigin is read-only.
win.performance.now = clock.performance.now;
installPlatformService(env.win);
installPerformanceService(env.win);
perf = Services.performanceFor(env.win);
Expand Down Expand Up @@ -710,20 +712,30 @@ describes.realWin('performance', {amp: true}, env => {
perf.coreServicesAvailable();
});

it('should call prerenderComplete on viewer', () => {
it('should call prerenderComplete on viewer', async () => {
env.sandbox
.stub(viewer, 'getParam')
.withArgs('csi')
.returns('1');
env.sandbox.stub(viewer, 'isEmbedded').returns(true);
clock.tick(300);
clock.tick(100);
whenFirstVisibleResolve();
await whenFirstVisiblePromise.then(() => {
clock.tick(300);
});
whenViewportLayoutCompleteResolve();
return perf.whenViewportLayoutComplete_().then(() => {
expect(
viewerSendMessageStub.withArgs('prerenderComplete').firstCall
.args[1].value
).to.equal(300);
expect(getPerformanceMarks()).to.deep.equal(['dr', 'ol', 'pc']);
expect(getPerformanceMarks()).to.have.members([
'dr',
'ol',
'visible',
'ofv',
'pc',
]);
});
});

Expand Down Expand Up @@ -854,6 +866,8 @@ describes.realWin('PeformanceObserver metrics', {amp: true}, env => {
navigator: env.win.navigator,
performance: {
getEntriesByType: env.sandbox.stub(),
now: () => 100,
timeOrigin: 100,
},
};

Expand Down

0 comments on commit 3a7b315

Please sign in to comment.