Debug blocking js function which delays mojo call

49 views
Skip to first unread message

Yuchen Liu

unread,
Oct 25, 2022, 5:50:51 PM10/25/22
to Chromium-dev, Frank Liberato
Hi,

I'm debugging a delay mojo call from browser to renderer on Cast for ATV, when the user pressed the home button on the remote control to background the app.

The mojo call SetPageLifecycleState is to deliver the visibility change signal from Activity to the media pipeline so that the media pipeline can pause the playback.

However I found the call may take > 2s from browser process to renderer process. I tried to capture the trace from about:inspect?tracing. It shows some v8.callFunction can take 600ms to 1.8s to finish. It blocks the renderer main thread and delays the mojo function.

image.png

Are there any suggestions on how I should find which js function blocks the thread?

Thanks.
Yuchen

Yuchen Liu

unread,
Oct 25, 2022, 6:00:32 PM10/25/22
to Chromium-dev, Frank Liberato
The highlighted range is 2.121s. The first v8.callFunction shown in the capture takes around 679ms to finish. The bars without any name on the left are also v8.callFunction, they take more than 3.5s to finish. The red vertical line is the time for the mojo call in browser process.

Fredrik Söderquist

unread,
Oct 26, 2022, 4:56:54 AM10/26/22
to yuc...@chromium.org, Chromium-dev, Frank Liberato
I can't see that you could get that information from any of the visible tracepoints, but the "first" v8.callFunction looks like it's run as part of a timer (setTimeout/setInterval; TimerBase::run). It might be possible to see what triggered it since it should have flow data associated with it. Looks like that script may access a "parkable" resource ("Park...") - which may be one source of the low amount of CPU time (vs. wall time) used. Looks like this task itself was delayed by an even longer JS task (the label isn't visible, but the nested MinorGC and colors seem to point in that direction at least).

The "second" v8.callFunction would be in response to the mentioned Mojo call, and is thus likely a 'visibilitychange' event handler (+ following microtasks likely triggered by it).

Not what you asked for, but I hope it helps forward progress,


/fs


Thanks.
Yuchen

--
--
Chromium Developers mailing list: chromi...@chromium.org
View archives, change email options, or unsubscribe:
http://groups.google.com/a/chromium.org/group/chromium-dev
---
You received this message because you are subscribed to the Google Groups "Chromium-dev" group.
To unsubscribe from this group and stop receiving emails from it, send an email to chromium-dev...@chromium.org.
To view this discussion on the web visit https://groups.google.com/a/chromium.org/d/msgid/chromium-dev/CAJv%3DBG%2BwRa00HBi2w0j4tDNbT9u80ApxHRuoyDYaoOe46XdBLQ%40mail.gmail.com.

Yuchen Liu

unread,
Oct 26, 2022, 2:26:46 PM10/26/22
to Fredrik Söderquist, Chromium-dev, Frank Liberato
Hi Fredrik, thanks for the info.

What is a "parkable" resource?

And the js task without a label (which triggers the MinorGC) is a v8.callFunction as well, it takes 3.5s to finish :(.

image.png

The second v8.callFunction is not the mojo call. The mojo call is the block after that, which ends at the right edge of the highlighted region.

Yuchen Liu

unread,
Oct 26, 2022, 8:35:25 PM10/26/22
to Fredrik Söderquist, Chromium-dev, Frank Liberato
The 3.5s blocking function is called from WebFrameWidgetImpl::FocusChanged. We're using m92, which only has  View()->SetPageFocus from that function. Is there a corresponding JS event listener for this?

Fredrik Söderquist

unread,
Oct 27, 2022, 4:23:22 AM10/27/22
to Yuchen Liu, Chromium-dev, Frank Liberato
On Thu, Oct 27, 2022 at 2:33 AM Yuchen Liu <yuc...@chromium.org> wrote:
The 3.5s blocking function is called from WebFrameWidgetImpl::FocusChanged. We're using m92, which only has  View()->SetPageFocus from that function. Is there a corresponding JS event listener for this?

'focus' and 'blur' are likely the main candidates there (but also others, like 'focusin' / 'focusout', maybe - but unlikely - with DOM prefix). The CPU/walltime ratio here is pretty bad as well it seems (indicating some form of blocking/waiting).


/fs
Reply all
Reply to author
Forward
0 new messages