Open Bug 1381384 Opened 7 years ago Updated 2 years ago

Performance analysis on gmail_ail_compose_new_mail_via_keyboard

Categories

(Core :: General, defect, P2)

56 Branch
x86_64
Windows 10
defect

Tracking

()

Performance Impact low

People

(Reporter: myen, Unassigned)

References

(Blocks 1 open bug)

Details

(Keywords: perf, Whiteboard: [QRC][QRC_Analyzed])

STR:
0. Enable Keyboard Shortcuts in Settings.
1. Open GMail.
2. Press ""c"".
3. Wait for the new mail window to open.

Short Gecko Profile(cover only Input Lantency action):
https://perfht.ml/2tvKNcU
on Ref Device

Reports: https://tinyurl.com/knp6swp
Notes: https://docs.google.com/spreadsheets/d/1RgiyTm41Af-mC0lVkqiDT1sp9yKNkZ5cBoj7bApZWtY/edit?ts=596c1cbc#gid=256706414
Blocks: 1366681
Whiteboard: [QRC][QRC_Analyzed]
Blocks: Hasal_InputLatency
No longer blocks: 1366681
Whiteboard: [QRC][QRC_Analyzed] → [QRC][QRC_NeedAnalysis]
Dan, could you help to have the fist analysis? Thanks.
Assignee: nobody → dminor
Flags: needinfo?(dminor)
Looks like it's a problem in Windows. NtWaitForMultipleObjects takes 99.8 % of running time, 5117 ms. How do you think, may mozilla::ipc::MessagePump::Run cause this behaviour, or this is really a Windows' bug?
(In reply to Andrey Mukamolow from comment #2)
> Looks like it's a problem in Windows. NtWaitForMultipleObjects takes 99.8 %
> of running time, 5117 ms. How do you think, may
> mozilla::ipc::MessagePump::Run cause this behaviour, or this is really a
> Windows' bug?

I captured a profile in Linux [1] while opening the compose window and and in that case we're spending 83.6 % of our time in __poll() with NS_ProcessNextEvent in the call stack. The windows trace also has NS_ProcessNextEvent in the call stack, so this isn't a Windows bug.

I also captured a ~5 second profile with gmail do nothing at all, and in that case, we were spending 97.3% of our time in __poll(). To me, it looks like Firefox is essentially sitting idle, waiting for an event to process in both the case where I'm opening the compose window and when I'm doing nothing.

In my Linux profile [1], 11.1% of the time was spent on timers and a timeout handler to run this script [2]. I'm not sure if this is related to the bug as filed, since the timeout handler doesn't show up in original profile.

Out of curiosity, I tried the compose window in Chrome on my machine. It does feel slightly faster in Chrome than in Firefox, but I'm not sure there is anything actionable in the profiles captured. Maybe we're doing something inefficient with timers, I don't have the experience to say for certain.

[1] https://perfht.ml/2u1CPdq
[2] https://mail.google.com/_/scs/mail-static/_/js/k=gmail.main.en.YLDmfjBKkgk.O/m=pds,pdl,pdit,m_i,pdt,t,it/am=rcB5gPx-BDiYAcbSCYSZ__OXy-Fhz2_6Xw8gRwX8AP_m_p_AjwMAAAAAAAAAAAAAAAAAAABbFJ8/rt=h/d=1/rs=AHGWq9Aa5w8HzEqsWArDtE4m7MEfV2UAaQ
Flags: needinfo?(dminor)
Component: JavaScript Engine → General
Dan, do you need other profile on this? or we are good to close this case?
Flags: needinfo?(dminor)
(In reply to Bobby Chien [:bchien] from comment #4)
> Dan, do you need other profile on this? or we are good to close this case?

I think it is safe to close this. I don't think it is actionable.
Flags: needinfo?(dminor)
Cervantes, could you share the finds from bug 1381387?
Flags: needinfo?(cyu)
See Also: → 1381387
I captured a profile using the same metric as in bug 1381387. In the time span starting from native keyboard input event to when mozilla::dom::Element::focus() is called, there are several obvious time-consuming operations:

38 ms is spent in building display list and painting
22 ms is spent in mozilla::dom::CSS2PropertiesBinding::get_direction (turning on Stylo doesn't make this part better)
8 ms is spent in frame construction (nsCSSFrameConstructor::RecreateFramesForContent)
Flags: needinfo?(cyu)
(In reply to Bobby Chien [:bchien] from comment #6)
> Cervantes, could you share the finds from bug 1381387?

This bug behaves similarly as bug 1381387, but the time-consuming operations are more obvious in the profile in this bug.
I'm not the best person to work on this bug.
Assignee: dminor → nobody
tracking under QF.
Summary: gmail_ail_compose_new_mail_via_keyboard for QRC_NeedAnalysis → gmail_ail_compose_new_mail_via_keyboard
Whiteboard: [QRC][QRC_NeedAnalysis] → [qf][QRC][QRC_Analyzed]
After FF57 lets reprofile this and make it part of a concerted GC plan
Whiteboard: [qf][QRC][QRC_Analyzed] → [qf:p2][QRC][QRC_Analyzed]
Priority: -- → P2
Keywords: perf
Whiteboard: [qf:p2][QRC][QRC_Analyzed] → [qf:p3][QRC][QRC_Analyzed]
@MarkYen, would you mind reprofiling (and seeing whether we are still slow enough on the STR, comparable to the competition, to prompt this bug to be open)?

The QF triage team is guessing that things might have changed here (possibly fixed or possibly shifted pain-points in the profile), given the various QF improvements that have happened since this was originally filed.
Flags: needinfo?(myen)
Oops, looks like MarkYen is no longer active on Mozilla stuff (and his bugzilla account is disabled, so he probably wouldn't have seen the needinfo request).

I was going to punt to Bobby, but he seems inactive as well, based on bugzilla activity queries.

So, I captured a profile of the STR myself in latest linux Nightly: https://perfht.ml/2AIA6aB (<---this is zoomed to just the keypress & resulting code).  As you can see, we have a ~278ms long red "jank" bar there -- though we do start ticking the refresh driver partway through that red bar (about 180ms in) and complete a paint at ~191ms into the red bar, and we paint & tick the refresh driver pretty frequently after that. So we're *visually* responsive after ~191ms of jank, even if we're still not handling user events (per the red bar being present in the profile).

I compared to current Chrome Dev Edition, and it seems they're a bit better. They show 3 frames getting painted while servicing the keypress & its resulting events/timeouts:
 - Frame 1: 152.2ms
 - Frame 2: 52.2ms
 - Frame 3: 20.2ms

So they're spending ~225ms here, with a not-quite-as-long jank at the beginning (their 152.2ms vs. our ~191ms, between keypress & first paint getting completed).  So they're somewhat faster, though still a good deal of jank on the first frame.

So, this is still a valid bug (based on my unscientific 1-attempt-per-browser investigation), but it doesn't seem super severe.
Flags: needinfo?(myen)
Hi Daniel,

Sorry for late response. Yes, both Bobby and Mark Yen are no longer with us. 

Do you still need the new profiler data? If yes, please let me know, I'll generate a new one for latest nightly build on windows for you.

If you need any other assistance with this bug, please also let me know.

Regards
Summary: gmail_ail_compose_new_mail_via_keyboard → Performance analysis on gmail_ail_compose_new_mail_via_keyboard
Performance Impact: --- → P3
Whiteboard: [qf:p3][QRC][QRC_Analyzed] → [QRC][QRC_Analyzed]
Severity: normal → S3
You need to log in before you can comment on or make changes to this bug.