Add instrumentation for measuring metrics related to visit by suchitadoshi1987 · Pull Request #276 · ember-fastboot/fastboot

suchitadoshi1987 · 2020-10-07T18:22:01Z

Added instrumentation to measure

time taken to complete the fastboot visit
time taken to complete the instance visit
time taken to retrieve the app instance from the queue

rwjblue

Looking good! Left a few inline comments/ideas...

rwjblue · 2020-10-07T20:23:18Z

src/ember-app.js

   *                                       only
   */
  async getNewApplicationInstance() {
+    const appInstanceRetrievalStartTime = Date.now();


I'd generally prefer to use something with higher precision. Mind swapping to performance.now() (docs here):

const { performance } = require('perf_hooks'); // ...snip... const start = performance.now();

+1 to performance.now(), not only higher precision, more importantly it's using a monotonic clock therefore it is not subject to system clock skew or adjustments https://www.w3.org/TR/hr-time-2/#sec-monotonic-clock

rwjblue · 2020-10-07T20:26:11Z

src/ember-app.js

-    return this.getAppInstanceInfo(app, queueObject.isItemPreBuilt);
+    return this.getAppInstanceInfo(app, {
+      isAppInstancePreBuilt: queueObject.isItemPreBuilt,
+      appInstanceRetrievalTime: Date.now() - appInstanceRetrievalStartTime,


I'd like to store the start and stops too. Also can we rename this to buildAppInstanceTiming?

Something like:

const start = performance.now(); const queueObject = this._sandboxApplicationInstanceQueue.dequeue(); const app = await queueObject.item; const stop = performance.now(); return this.getAppInstanceInfo(app, { isAppInstancePreBuilt: queueObject.isItemPreBuilt, buildAppInstanceTiming: { start, stop, duration: stop - start, } });

Rob,

Do we need all 3 of 'start', 'stop', and 'duration'?

I'd prefer either (1) 'start' and 'stop' or (2) 'start' and 'duration'. I prefer the latter option more. The reason I like it is because: (1) it's smaller (which isn't a huge deal) and (2) whenever I see all 3 I do the subtraction to make sure 'duration' = 'stop' - 'start' because I always ask myself, why would they provide all 3?

That being said, this is not such a strong opinion and if you are strongly opinionated, I'll defer.

Thanks,
Mark

My reasoning here is basically that "clock time duration" isn't enough information in all cases, but in many cases it is. For example, if we just provided duration it is actually quite difficult to map the results to see how many were interleaved/overlapping/whateverTheWordIs. In general, I feel like this is in a "why not" kinda scenario (where it costs us roughly nothing to do all three, and in fact we basically have to know all three anyways in order to provide a duration). That being said, I definitely do not feel strongly about providing all 3. I think start and duration is probably enough info (and addresses my primary issue).

Let's call it "dealers choice", to the PR author go the spoils 😝

lol okk.... i will unveil the suspense in my next commit ;)

FWIW PerformanceEntry defines startTime and duration

rwjblue · 2020-10-07T20:26:30Z

src/ember-app.js

    let shouldBuildApp = buildSandboxPerVisit || this._applicationInstance === undefined;

-    let { app, isSandboxPreBuilt } = shouldBuildApp
+    let { app, appAnalytics } = shouldBuildApp


Can we call this analytics instead of appAnalytics?

Also, can we unify these? Can we funnel both cases through a single function (e.g. buildAppInstance or even getNewApplicationInstance) so the rest of the code doesn't need to care about the two pathways?

do you mean

? await this.getNewApplicationInstance() : this.getAppInstanceInfo(this._applicationInstance);

should instead be

let { app, appAnalytics } = await this.getNewApplicationInstance(shouldBuildApp)

and the function would return the appropriate response

Yes, IMHO we should have only a single function that is responsible for understanding:

if we should build a new instance (based on shouldBuildApp)

if we should build a new instance when the queue is empty and a new application instance is requested

how to build the proper set of analytics output

agreed! 👍

rwjblue · 2020-10-07T20:29:47Z

src/ember-app.js

+    const instanceVisitStartTime = Date.now();
    await instance.visit(path, bootOptions);
+    result.analytics.instanceVisitTime = Date.now() - instanceVisitStartTime;


Similar to above, lets use a POJO to group multiple values:

const start = performance.now(); await instance.visit(path, bootOptions); const stop = performance.now(); result.analytics.instanceVisitTimings = { start, stop, duration: stop - start, };

rwjblue · 2020-10-07T20:30:30Z

src/ember-app.js


    try {
      await this._visit(path, fastbootInfo, bootOptions, result, buildSandboxPerVisit);
+      result.analytics.fastbootVisitTime = Date.now() - fastbootVisitStartTime;


Same as above

SergeAstapov · 2020-10-08T00:44:27Z

@suchitadoshi1987 @rwjblue have you considered to instrument result._finalize() and createShoebox() as well?

rwjblue · 2020-10-08T20:48:56Z

@suchitadoshi1987 @rwjblue have you considered to instrument result._finalize() and createShoebox() as well?

Ya, we definitely can (and should!) add that. We should probably make an enumerated list over in #107.

kratiahuja

I believe this also needs README updates as the public API of result.analytics is being changed: https://github.com/ember-fastboot/fastboot#result

kratiahuja · 2020-10-09T00:19:18Z

src/ember-app.js

-    return this.getAppInstanceInfo(app, queueObject.isItemPreBuilt);
+    return this.getAppInstanceInfo(app, {
+      isAppInstancePreBuilt: queueObject.isItemPreBuilt,
+      appInstanceRetrievalTime: Date.now() - appInstanceRetrievalStartTime,


Instead of doing this here, shouldn't these metrics come from the queueObject like isItemPreBuilt? It seems a bit of an odd API where we return whether the item was pre built or built on the fly but not the metrics of the time spent for that task. In other words, we are already getting what task was dequeued but not it's timing info.

If it isn't prebuilt, it can capture the time to create the sandbox. This way the generator function takes care of creation of the object, determining the state of reterival and metrics. If the intent is to get the time taken to built the sanbox then it should come from as part of the dequeue API IMO.

kratiahuja · 2020-10-09T00:21:15Z

src/ember-app.js


    try {
      await this._visit(path, fastbootInfo, bootOptions, result, buildSandboxPerVisit);
+      result.analytics.fastbootVisitTime = Date.now() - fastbootVisitStartTime;


I think visit end time is when finally block is called in order capture the entire time. Is there specific reason why we are not capturing the remaining time to build the result and shoebox?

Add instrumentation for measuring metrics related to visit

c3a0379

suchitadoshi1987 requested a review from rwjblue October 7, 2020 18:22

rwjblue reviewed Oct 7, 2020

View reviewed changes

kratiahuja requested changes Oct 9, 2020

View reviewed changes

Conversation

suchitadoshi1987 commented Oct 7, 2020

Uh oh!

rwjblue left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

SergeAstapov commented Oct 8, 2020

Uh oh!

rwjblue commented Oct 8, 2020

Uh oh!

kratiahuja left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

6 participants