Negative timing on documentParsingTime

[jcarres-mdsol]

Description

documentParsingTime is always a big negative time.

Example of a navigation event:

In the above example the TTFB was 472, FCP 1807 and lcp 1977

Also I do not think numbers quite add up but I am just not understanding this well.

I would imagine FCP = TTFB + pageLoadTime but it is never quite that. Maybe my understanding is wong?
Also, does the navigation event has a time for LCP - FCP ? Or the point of providing those is to not need it to be in the navigation event?

Environment

• OS:
  Mac OS 14.1.1
• Browser:
  Firefox 125.0beta9

Faro 1.5.1
Web SDK, Web Tracing, React
Desktop

[codecapitano]

Hi @jcarres-mdsol

documentParsingTime is always a big negative time.

This should not happen.
Would you mind to provide a bit more context here to make debugging the issue easier?
E. g. does it happen for all browsers or a specific browser+version?

In the above example the TTFB was 472, FCP 1807 and lcp 1977
Also I do not think numbers quite add up but I am just not understanding this

That's correct.

The web vitals represents loading and rendering milestones and not all are in direct relation to the contents of a resource entry.
Take LCP as an example which is the time it takes to load and render the largest visible element on a page. The browser use as set of rules to define what element qualifies as the LCP element to calculate the time for.

The page load time is the time between the browser starts fetching a resource (fetchStart) and when the document and all sub-resources have finished loading (domComplete).

Between the largest contentful paint and the domComplete other things happen so you can not simply sum up the web vitals to get the page load time.

Also, does the navigation event has a time for LCP - FCP ? Or the point of providing those is to not need it to be in the navigation event?

No, navigation timings do not contain web-vitals.
Faro has a dedicated instrumentation to send web-vitals.
You need to do the calculation either in your o11y tool or you can use Faro's beforeSend hook to enrich beacons with custom data

Or the point of providing those is to not need it to be in the navigation event?

They are not related to the data the navigation entry.
It's a set of load and rendering performance milestones to judge the related UX of a web site or app.

Cheers,
Marco

[codecapitano]

Note:
Just double checked the negative parsing time.
Looks like there's something different with firefox dev edition/beta.

Tested with following browsers:

• Chrome 123.0.6312.123 - works ✅

• Firefox 124.0.2 - works ✅

• Safari - works ✅

• Firefox Dev Edition 125.0b9 - does not work ❌

[jcarres-mdsol]

Sorry, you got there faster than me.

I've tried in addition Firefox 125b9 and it works.

So ironically Firefox normal edition works but developer edition does not.

[codecapitano]

Hey @jcarres-mdsol thanks a lot that you also had a look.
It's always great to see people care and invest time to report issues or help with debugging.
Very appreciated!

Let's wait and see if it gets fixed. I double checked the MDN docs if there are changes which affect the APIs we are using but couldn't find anything.

Cheers,
Marco

[codecapitano]

@jcarres-mdsol may I ask from what tool you've taken the screenshot above?

[jcarres-mdsol]

Grafana/Loki
That's simply the result of searching for

{service="...."}  | json 

Then opening a faro.performance.navigation log message

[codecapitano]

Ah ok, I wondered why it looks so different to the original log format.

{app_id="..."} |~ "faro.performance.navigation" | logfmt

[codecapitano]

Here are the docs for the performance instrumentation.

https://grafana.com/docs/grafana-cloud/monitor-applications/frontend-observability/faro-web-sdk/performance-instrumentation/

[jcarres-mdsol]

Oh, interesting, you are saying our text format in the log is different.
Yeah, we are coming from a different vendor. This other vendor almost but not quite implemented opentelemetry, doing something very weird in their output. So we added a proxy that "fixes" their format to be normal otel before hitting our otel collector.
As this is an experiment, I just pointed faro instrumentation to the same collector, probably the "fixing" proxy is doing this.
As we substitute them out, we will drop the hack.

Faro is way better, I really appreciate your work here

[codecapitano]

Thank you so much @jcarres-mdsol 🙏

[codecapitano]

So we added a proxy that "fixes" their format to be normal otel before hitting our otel collector.

Faro uses it's own wire protocol (!) but we also provide a transport which transforms the Faro protocol to OTLP before sending it.
With the restriction that is does not create metrics.

But in case you use Grafana Cloud you don't need it.

[jcarres-mdsol]

yeah, we are using the OTLP version.
In my view telemetry pipelines should always use OTLP as protocol, this will make the community more vibrant.

[codecapitano]

@jcarres-mdsol did you still notice any problems or can we close the issue?

[jcarres-mdsol]

I think we can close yes.