Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Reporting CLS and LCP in a lab environment using Playwright is flakey / unreliable #180

Closed
tnolet opened this issue Sep 22, 2021 · 22 comments · Fixed by #297
Closed

Reporting CLS and LCP in a lab environment using Playwright is flakey / unreliable #180

tnolet opened this issue Sep 22, 2021 · 22 comments · Fixed by #297

Comments

@tnolet
Copy link

tnolet commented Sep 22, 2021

Hi,

we are bumping into an issue where we want to gather some web vitals using this library in a lab environment. We are using Playwright for this and injecting the web-vitals code into the browser context. Injecting and instrumenting works fine, but we are getting intermittent issues with some metrics not reporting.

Specifically:

  • LCP seems to not be reported unless we force some interaction. A simple click on the body normally does the trick.
  • CLS seems to come and go.

Conversely, FCP and TTFB are pretty reliable.

My question is: is this expected, or are we missing something? Could this be some race condition we can avoid?

Here is an reproducable example. The web-vitals UMD module is inlined. The only external dependency is Playwright

const { chromium } = require("playwright")

// UMD module copy-pasted from the NPM version of https://github.com/GoogleChrome/web-vitals
const WEB_VITALS_SCRIPT = `!function(e,t){"object"==typeof exports&&"undefined"!=typeof module?t(exports):"function"==typeof define&&define.amd?define(["exports"],t):t((e="undefined"!=typeof globalThis?globalThis:e||self).webVitals={})}(this,(function(e){"use strict";var t,n,i,a,r=function(e,t){return{name:e,value:void 0===t?-1:t,delta:0,entries:[],id:"v1-".concat(Date.now(),"-").concat(Math.floor(8999999999999*Math.random())+1e12)}},o=function(e,t){try{if(PerformanceObserver.supportedEntryTypes.includes(e)){var n=new PerformanceObserver((function(e){return e.getEntries().map(t)}));return n.observe({type:e,buffered:!0}),n}}catch(e){}},c=function(e,t){var n=function n(i){"pagehide"!==i.type&&"hidden"!==document.visibilityState||(e(i),t&&(removeEventListener("visibilitychange",n,!0),removeEventListener("pagehide",n,!0)))};addEventListener("visibilitychange",n,!0),addEventListener("pagehide",n,!0)},u=function(e){addEventListener("pageshow",(function(t){t.persisted&&e(t)}),!0)},f="function"==typeof WeakSet?new WeakSet:new Set,s=function(e,t,n){var i;return function(){t.value>=0&&(n||f.has(t)||"hidden"===document.visibilityState)&&(t.delta=t.value-(i||0),(t.delta||void 0===i)&&(i=t.value,e(t)))}},d=-1,p=function(){return"hidden"===document.visibilityState?0:1/0},m=function(){c((function(e){var t=e.timeStamp;d=t}),!0)},v=function(){return d<0&&(d=p(),m(),u((function(){setTimeout((function(){d=p(),m()}),0)}))),{get timeStamp(){return d}}},l={passive:!0,capture:!0},h=new Date,y=function(e,a){t||(t=a,n=e,i=new Date,E(removeEventListener),g())},g=function(){if(n>=0&&n<i-h){var e={entryType:"first-input",name:t.type,target:t.target,cancelable:t.cancelable,startTime:t.timeStamp,processingStart:t.timeStamp+n};a.forEach((function(t){t(e)})),a=[]}},S=function(e){if(e.cancelable){var t=(e.timeStamp>1e12?new Date:performance.now())-e.timeStamp;"pointerdown"==e.type?function(e,t){var n=function(){y(e,t),a()},i=function(){a()},a=function(){removeEventListener("pointerup",n,l),removeEventListener("pointercancel",i,l)};addEventListener("pointerup",n,l),addEventListener("pointercancel",i,l)}(t,e):y(t,e)}},E=function(e){["mousedown","keydown","touchstart","pointerdown"].forEach((function(t){return e(t,S,l)}))};e.getCLS=function(e,t){var n,i=r("CLS",0),a=function(e){e.hadRecentInput||(i.value+=e.value,i.entries.push(e),n())},f=o("layout-shift",a);f&&(n=s(e,i,t),c((function(){f.takeRecords().map(a),n()})),u((function(){i=r("CLS",0),n=s(e,i,t)})))},e.getFCP=function(e,t){var n,i=v(),a=r("FCP"),c=o("paint",(function(e){"first-contentful-paint"===e.name&&(c&&c.disconnect(),e.startTime<i.timeStamp&&(a.value=e.startTime,a.entries.push(e),f.add(a),n()))}));c&&(n=s(e,a,t),u((function(i){a=r("FCP"),n=s(e,a,t),requestAnimationFrame((function(){requestAnimationFrame((function(){a.value=performance.now()-i.timeStamp,f.add(a),n()}))}))})))},e.getFID=function(e,i){var d,p=v(),m=r("FID"),l=function(e){e.startTime<p.timeStamp&&(m.value=e.processingStart-e.startTime,m.entries.push(e),f.add(m),d())},h=o("first-input",l);d=s(e,m,i),h&&c((function(){h.takeRecords().map(l),h.disconnect()}),!0),h&&u((function(){var o;m=r("FID"),d=s(e,m,i),a=[],n=-1,t=null,E(addEventListener),o=l,a.push(o),g()}))},e.getLCP=function(e,t){var n,i=v(),a=r("LCP"),d=function(e){var t=e.startTime;t<i.timeStamp&&(a.value=t,a.entries.push(e)),n()},p=o("largest-contentful-paint",d);if(p){n=s(e,a,t);var m=function(){f.has(a)||(p.takeRecords().map(d),p.disconnect(),f.add(a),n())};["keydown","click"].forEach((function(e){addEventListener(e,m,{once:!0,capture:!0})})),c(m,!0),u((function(i){a=r("LCP"),n=s(e,a,t),requestAnimationFrame((function(){requestAnimationFrame((function(){a.value=performance.now()-i.timeStamp,f.add(a),n()}))}))}))}},e.getTTFB=function(e){var t,n=r("TTFB");t=function(){try{var t=performance.getEntriesByType("navigation")[0]||function(){var e=performance.timing,t={entryType:"navigation",startTime:0};for(var n in e)"navigationStart"!==n&&"toJSON"!==n&&(t[n]=Math.max(e[n]-e.navigationStart,0));return t}();n.value=n.delta=t.responseStart,n.entries=[t],e(n)}catch(e){}},"complete"===document.readyState?setTimeout(t,0):addEventListener("pageshow",t)},Object.defineProperty(e,"__esModule",{value:!0})}));`

async function run () {

  const browser = await chromium.launch()
  context = await browser.newContext()

  // START specific instrumentation code

  await context.addInitScript(WEB_VITALS_SCRIPT)

  await context.addInitScript(() => {
    // Wait for the init script to be fully loaded
    // https://github.com/GoogleChrome/web-vitals/issues/38
    window.addEventListener('DOMContentLoaded', () => {
      webVitals.getTTFB(metric => { console.trace(JSON.stringify({ name: metric.name, value: metric.value, blob: metric })) })
      webVitals.getFCP(metric => { console.trace(JSON.stringify({ name: metric.name, value: metric.value, blob: metric })) })
      webVitals.getLCP(metric => { console.trace(JSON.stringify({ name: metric.name, value: metric.value, blob: metric })) })
      webVitals.getCLS(metric => { console.trace(JSON.stringify({ name: metric.name, value: metric.value, blob: metric })) })
    })
  })

  const page = await context.newPage()
  page.on('console', async msg => {
    if (msg.type() === 'trace') {
      console.log(msg.text())
    }
  });

  // STOP specific instrumentation code

  await page.goto("https://checklyhq.com")
  // Doing a 'page.click()' on the body triggers the LCP metric to be reported much more reliably
  // await page.click('body')

  await browser.close()
}

run()

The typical output from this code looks like:

/usr/local/bin/node /Users/timnolet/WebstormProjects/playwright-scratch/web-vitals/web-vitals-inline.js

{"name":"FCP","value":846.6000000238419}
{"name":"TTFB","value":396}

Process finished with exit code 0
@philipwalton
Copy link
Member

This is expected, see this explanation in the README.

CLS is measured through the lifespan of the page, so it's impossible to know the final CLS value until the page is unloaded. For more context on why LCP is reported after user interactions, see: When is largest contentful paint reported.

My suggestion is to initiate page unload, and that should trigger reporting of all the metrics.

@tnolet
Copy link
Author

tnolet commented Sep 22, 2021

@philipwalton thanks for pointing me in the right direction. If I extend the above example with the code beneath it seems to help a lot. The beforeUnload flag needs to be there apparently. The extra 100 millisecond sleep also. Removing either reverts to the CLS and LCP missing. I think we are hitting the intersection between how Playwright loads/unloads and how the metrics are collected.

...
await page.goto("https://checklyhq.com")
await page.close({ runBeforeUnload: true })
await page.waitForTimeout(100)
await browser.close()

output:

{"name":"FCP","value":931.6999999880791}
{"name":"TTFB","value":588.7999999523163}
{"name":"LCP","value":1094.299}
{"name":"CLS","value":0}

@philipwalton
Copy link
Member

beforeUnload is probably too early (which explains why the timeout helps there). The web-vitals code uses a combination of pagehide and visibilitychange (whichever comes first) to detect backgrounding or unloading and report all metrics.

FYI, if you're curious, you can read more here about why we use pagehide and visibilitychange instead of beforeunload or unload.

@AndreyMelnichenko
Copy link

@tnolet Hi,
could you share your final solution for get check WEB_VITALS report on page?

@tnolet
Copy link
Author

tnolet commented Dec 10, 2021

@AndreyMelnichenko this is quite a bit of code, now part of our private code base. In essence, most Playwright or Puppeteer sessions are too quick. Maybe @danielpaulus could chime in here, as he coded most of our solution.

@SuperOleg39
Copy link

SuperOleg39 commented Dec 5, 2022

beforeUnload is probably too early (which explains why the timeout helps there). The web-vitals code uses a combination of pagehide and visibilitychange (whichever comes first) to detect backgrounding or unloading and report all metrics.

@philipwalton, Hello!

Looks like pagehide and visibilitychange have different order - whatwg/html#3957

And, if we send beacon in pagehide callback, and user just closed page after session, CLS will never be sended, visibilitychange will be fired after sendBeacon

So, what is the recommended and crossbrowser way to collect all metrics, when page just was closed?

@SuperOleg39
Copy link

As I understand right, and with visibilitychange application event handler can be fired before web-vitals event handler, and we will have the same problem

@philipwalton
Copy link
Member

And, if we send beacon in pagehide callback, and user just closed page after session, CLS will never be sended, visibilitychange will be fired after sendBeacon

You should be reporting data when the callback is invoked, not separately from when the callback is invoked.

If you want to just report yourself and not depend on the web-vitals callback timing, then you can set reportAllChanges to true so your code gets notified of any CLS updates immediately as it's happening rather than waiting until pagehide/visibilitychange.

@SuperOleg39
Copy link

You should be reporting data when the callback is invoked, not separately from when the callback is invoked.

Our approach is close to this reciepe with batching - https://github.com/GoogleChrome/web-vitals#batch-multiple-reports-together, it will be work together only with reportAllChanges?

And is there any disadvantages if we will use reportAllChanges for CLS?

@GoogleChrome GoogleChrome deleted a comment Dec 5, 2022
@GoogleChrome GoogleChrome deleted a comment Dec 5, 2022
@philipwalton
Copy link
Member

Our approach is close to this reciepe with batching - https://github.com/GoogleChrome/web-vitals#batch-multiple-reports-together, it will be work together only with reportAllChanges?

And is there any disadvantages if we will use reportAllChanges for CLS?

That approach will work fine with reportAllChanges. That's the approach I use on my website as well.

@SuperOleg39
Copy link

That approach will work fine with reportAllChanges. That's the approach I use on my website as well.

Thanks a lot for the answer, and of course for the great library)

@SuperOleg39
Copy link

SuperOleg39 commented Dec 7, 2022

That approach will work fine with reportAllChanges. That's the approach I use on my website as well.

Maybe found a one problem - with reportAllChanges , sometimes onCLS callback is never called.
Looks like there is some pattern, when FCP is slow and -1 here - https://github.com/GoogleChrome/web-vitals/blob/main/src/onCLS.ts#L65

And the problem is that after, CLS never called.

@philipwalton
Copy link
Member

Maybe found a one problem - with reportAllChanges , sometimes onCLS callback is never called.

Note that CLS should not be reported if FCP hasn't been reported (including when pages are opened in a background tab), so this is working as intended.

I don't think the behavior here is different between when reportAllChanges is true vs. when it's false, but let me know if it is (ideally with steps to repo).

@SuperOleg39
Copy link

SuperOleg39 commented Dec 7, 2022

I don't think the behavior here is different between when reportAllChanges is true vs. when it's false, but let me know if it is (ideally with steps to repo).

With reportAllChanges: true CLS callback not called even after page visibility hidden, I think only here is difference.

If it is wrong behaviour, can try to make a reproduction repo)

@SuperOleg39
Copy link

For me it is wrong, because no chance to measure CLS, if CLS called before FCP for some reasons

@SuperOleg39
Copy link

Found, it was because I also add reportAllChanges: true to onFCP callback, so maybe it is expected behaviour

@philipwalton
Copy link
Member

I'm trying to repro this cannot. Can you confirm that you're running the latest version (3.1.0)?

@SuperOleg39
Copy link

Yes, 3.1.0 version.

It was hard to investigate, problem is not in onFCP reportAllChanges parameter)

Steps to reproduce:

  1. Create layout shift as fast as possible
  2. Lazy load web-vitals library and add callbacks

First CLS will be calculated before FCP, this code will be called and nothing reported because FCP is -1

After, this code will be called and CLS value is larger than -1 already, so again no report

Here is reproduction: https://codesandbox.io/s/cranky-snyder-6lvs5f?file=/src/routes/index.tsx

@SuperOleg39
Copy link

SuperOleg39 commented Dec 8, 2022

Снимок экрана 2022-12-08 в 12 51 05

Is this change will be correct? Or we need to check reportAllChanges here?

@SuperOleg39
Copy link

Снимок экрана 2022-12-08 в 12 59 19

Test both cases, definitely need to check reportAllChanges

@philipwalton
Copy link
Member

Thanks for the repro! I was also able to repro this on my own test pages using your instructions. Looks like the missing test case was waiting until after paint and the first shift to invoke the onCLS() function.

I've been experimenting with a fix and can hopefully publish it in the next few days.

@SuperOleg39
Copy link

Thanks a lot!)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants