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

Heads Up on Changes to INP Measurement When Interfered with JS Modal Dialogs #492

Open
zuoaoyuan opened this issue Jun 6, 2024 · 9 comments · May be fixed by #528
Open

Heads Up on Changes to INP Measurement When Interfered with JS Modal Dialogs #492

zuoaoyuan opened this issue Jun 6, 2024 · 9 comments · May be fixed by #528

Comments

@zuoaoyuan
Copy link

With landing of EventTimingFallbackToModalDialogStart, event timing now will treat JS modal dialog showing time as an alternative end point of INP or event duration measurement.

It has following impact on WebVitals.js v4:

  • Events will have a short duration (when interfered with JS modal dialogs), which is good
  • The Event Timing processing is still large (this is a weirdness in event timing itself)

So now we can have a situation like:
INP: 100ms, input delay: 20ms, processing: 10000ms, presentationDelay: 0ms
This doesn't break web-vitals.js which is good, and it's also technically the truth:)

However, that huge event timing processing is also used to get a LoAF attribution, and it can be something that users will find surprising if it comes from field data, and we might want to signal it somehow.
(Loaf ::Script will have a pauseDuration for dialogs, which could be one strategy to mitigate this)

@mmocny
Copy link
Member

mmocny commented Jun 7, 2024

Steps to reproduce:

  • Open a page (e.g. the INP Demo page)
  • Using JS console:
    • Add an event handler that fires an alert, with less priority than the registered events on the page already:
    document.documentElement.addEventListener('click', () => alert("hi"));
    • Add web-vitals.js v4 + attribution logging:
      const { onLCP, onINP, onCLS } = await import('https://unpkg.com/web-vitals/attribution?module');
      onINP((metric) => {
        console.log('web-vitals.js', metric.value, metric);
      }, { reportAllChanges: true });
  • Then interact with the page.

This results in the following:

  • First, you see a small jank which comes from the INP demo page itself (setInterval, pointerdown/up blocking events etc)
  • Then you see an alert popup, after that delay

The reported INP will show something like (specific numbers will vary):

{
    "name": "INP",
    "value": 376,
    "rating": "needs-improvement",
    "delta": 104,
    "entries": [
        {
            "name": "pointerdown",
            "entryType": "event",
            "startTime": 13763.100000023842,
            "duration": 376,
            "navigationId": "204030c4-b7ac-4c2c-a31d-5d15ef400627",
            "interactionId": 7303,
            "processingStart": 13820,
            "processingEnd": 13935.100000023842,
            "cancelable": true
        }
    ],
    "id": "v4-1717772209807-2007043867067",
    "navigationType": "back-forward",
    "attribution": {
        "interactionTarget": "#textarea",
        "interactionTargetElement": {},
        "interactionType": "pointer",
        "interactionTime": 13763.100000023842,
        "nextPaintTime": 16142.899999976158,
        "processedEventEntries": [
            {
                "name": "pointerdown",
                "entryType": "event",
                "startTime": 13763.100000023842,
                "duration": 376,
                "navigationId": "204030c4-b7ac-4c2c-a31d-5d15ef400627",
                "interactionId": 7303,
                "processingStart": 13820,
                "processingEnd": 13935.100000023842,
                "cancelable": true
            },
            {
                "name": "mousedown",
                "entryType": "event",
                "startTime": 13763.100000023842,
                "duration": 376,
                "navigationId": "204030c4-b7ac-4c2c-a31d-5d15ef400627",
                "interactionId": 0,
                "processingStart": 13935.100000023842,
                "processingEnd": 13935.100000023842,
                "cancelable": true
            },
            {
                "name": "pointerup",
                "entryType": "event",
                "startTime": 13769.199999928474,
                "duration": 368,
                "navigationId": "204030c4-b7ac-4c2c-a31d-5d15ef400627",
                "interactionId": 7303,
                "processingStart": 13936.299999952316,
                "processingEnd": 14136.299999952316,
                "cancelable": true
            },
            {
                "name": "mouseup",
                "entryType": "event",
                "startTime": 13769.199999928474,
                "duration": 368,
                "navigationId": "204030c4-b7ac-4c2c-a31d-5d15ef400627",
                "interactionId": 0,
                "processingStart": 14136.299999952316,
                "processingEnd": 14136.299999952316,
                "cancelable": true
            },
            {
                "name": "click",
                "entryType": "event",
                "startTime": 13769.199999928474,
                "duration": 368,
                "navigationId": "204030c4-b7ac-4c2c-a31d-5d15ef400627",
                "interactionId": 7303,
                "processingStart": 14136.299999952316,
                "processingEnd": 16142,
                "cancelable": true
            }
        ],
        "longAnimationFrameEntries": [
            {
                "name": "long-animation-frame",
                "entryType": "long-animation-frame",
                "startTime": 13745.899999976158,
                "duration": 2397,
                "navigationId": "204030c4-b7ac-4c2c-a31d-5d15ef400627",
                "renderStart": 16142.100000023842,
                "styleAndLayoutStart": 16142.299999952316,
                "firstUIEventTimestamp": 13763.100000023842,
                "blockingDuration": 2289,
                "scripts": [
                    {
                        "name": "script",
                        "entryType": "script",
                        "startTime": 13754.100000023842,
                        "duration": 65,
                        "navigationId": "204030c4-b7ac-4c2c-a31d-5d15ef400627",
                        "invoker": "TimerHandler:setTimeout",
                        "invokerType": "user-callback",
                        "windowAttribution": "self",
                        "executionStart": 13754.100000023842,
                        "forcedStyleAndLayoutDuration": 0,
                        "pauseDuration": 0,
                        "sourceURL": "https://inp-demo.glitch.me/main.js",
                        "sourceFunctionName": "periodicBlock",
                        "sourceCharPosition": 1410
                    },
                    {
                        "name": "script",
                        "entryType": "script",
                        "startTime": 13820,
                        "duration": 114,
                        "navigationId": "204030c4-b7ac-4c2c-a31d-5d15ef400627",
                        "invoker": "DOMWindow.onpointerdown",
                        "invokerType": "event-listener",
                        "windowAttribution": "self",
                        "executionStart": 13820,
                        "forcedStyleAndLayoutDuration": 0,
                        "pauseDuration": 0,
                        "sourceURL": "https://inp-demo.glitch.me/main.js",
                        "sourceFunctionName": "",
                        "sourceCharPosition": 4059
                    },
                    {
                        "name": "script",
                        "entryType": "script",
                        "startTime": 13936.299999952316,
                        "duration": 200,
                        "navigationId": "204030c4-b7ac-4c2c-a31d-5d15ef400627",
                        "invoker": "DOMWindow.onpointerup",
                        "invokerType": "event-listener",
                        "windowAttribution": "self",
                        "executionStart": 13936.299999952316,
                        "forcedStyleAndLayoutDuration": 0,
                        "pauseDuration": 0,
                        "sourceURL": "https://inp-demo.glitch.me/main.js",
                        "sourceFunctionName": "",
                        "sourceCharPosition": 4059
                    },
                    {
                        "name": "script",
                        "entryType": "script",
                        "startTime": 14136.699999928474,
                        "duration": 2005,
                        "navigationId": "204030c4-b7ac-4c2c-a31d-5d15ef400627",
                        "invoker": "HTML.onclick",
                        "invokerType": "event-listener",
                        "windowAttribution": "self",
                        "executionStart": 14136.699999928474,
                        "forcedStyleAndLayoutDuration": 0,
                        "pauseDuration": 0,
                        "sourceURL": "",
                        "sourceFunctionName": "",
                        "sourceCharPosition": -1
                    }
                ]
            }
        ],
        "inputDelay": 56.89999997615814,
        "processingDuration": 2322,
        "presentationDelay": 0.8999999761581421,
        "loadState": "complete"
    }
}

The value of 376 here represent the time it took to show the dialog-- which in this case did have observable UX delays. It does not include the time the dialog was opened.

However, the attribution data represents the entirely of the animation frame, including other events and the total time the js dialog was opened.

In particular, "processingDuration": 2322 is somewhat inconsistent with overall value of the metric, at first glance. (the last LoAF Script entry should have a "pauseDuration": value which is not 0, but seems not working on Canary for me...


In my opinion the attribution is FINE but there probably should be some obvious clue about WHY the numbers are the way they are. Maybe if the LoAF "pauseDuration" worked and the sum of all pauseDuration was split out from "processingDuration" (subtracted from and reported distinctly) this would be good enough?

@rviscomi
Copy link
Member

rviscomi commented Aug 5, 2024

To make testing this a bit easier, I've forked the INP demo to include a few buttons for triggering different dialogs and upgraded it to the latest attribution build: https://inp-demo-dialog.glitch.me/

image

@rviscomi
Copy link
Member

rviscomi commented Aug 6, 2024

Filed w3c/long-animation-frames#17 to track the 0ms pauseDuration bug

@tunetheweb
Copy link
Member

@mmocny / @zuoaoyuan this looks weird:

            {
                "name": "click",
                "entryType": "event",
                "startTime": 13769.199999928474,
                "duration": 368,
                "navigationId": "204030c4-b7ac-4c2c-a31d-5d15ef400627",
                "interactionId": 7303,
                "processingStart": 14136.299999952316,
                "processingEnd": 16142,
                "cancelable": true
            }

The processingEnd is > duration + startTime.

I guess that's technically correct since we're capping the duration but why not also cap processingEnd? Is the thought that people might still want to measure the full duration?

I guess web-vitals could similarly cap the processingDuration but it seems to me it's accurately reporting that based on the event timing details.

@mmocny
Copy link
Member

mmocny commented Aug 30, 2024

why not also cap processingEnd?

Because the event is not done processing yet, and we thought that it would be best (i.e. for LoAF attribution with scripts) to leave the value accurate and "honest". Also, duration is capped because for INP we thought it made more sense-- but developers using Event Timing for other reasons might have different preferences.

I think we should expose MORE data to make this less confusing, such as making it obvious that the duration is based on an alternative fallback time, and to also still expose the presentation time alongside. We've started to do this in tracing but need to make a spec proposal to change public entry interface.

@mmocny
Copy link
Member

mmocny commented Aug 30, 2024

One more note: when you have multiple events in one frame, the "fallback time" will be in the middle of exactly one of those events. For the other events, the fallback time can be before processingStart or after processingEnd.

The only reliable way to know if we're using a fallback time (at least today) I think is to compare with LoAF data and see if the end time of the event disagrees with the end time of the animation frame.

@tunetheweb
Copy link
Member

Hmmm... so I guess from an INP point of view the duration has finished processing. So we could cap processingDuration (there precedence for this in #527 for example).

Would still look weird for LoAF-based bucketing, but guess we can deal with that, when we decide how that looks.

@mmocny
Copy link
Member

mmocny commented Aug 30, 2024

the duration has finished processing

I would say:

  • The interaction has finished (there was visual feedback)
  • The event has not finished processing

I think capping processingDuration for the interaction as used for INP breakdowns for example, I think makes sense to me.

@tunetheweb
Copy link
Member

That's why I said "from an INP point of view" 😁

OK will raise a PR similar to #527

@tunetheweb tunetheweb linked a pull request Aug 30, 2024 that will close this issue
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