1270351 - "nsJSUtils::EvaluateString" spent more time between navigationStart and loadEventEnd

Status: RESOLVED INCOMPLETE

(Core :: General, defect)

Description

[Askeing Yen[:askeing][:fyen]]

+++ This bug was initially created as a clone of Bug #1267971 +++

# Test Case
Empty Google Docs Loading
https://docs.google.com/document/d/1YNxUZPc7xB4OtnxnRLMIKlagMzSOh3_uggp2WCz3aww/edit?pref=2&pli=1

# Browsers
Firefox version: 46.0
gecko-dev release branch
> gecko-dev$ git log -1
> commit a9d9c1d156223c31ae83f395a0004fbe5500ef3e
> Author: Nils Ohlmeier [:drno] <[e-mail]>
> Date:   Tue Apr 19 17:06:44 2016 -0700
>     Bug 1259842: allow RFC1918 pairing again r=mjf a=lizzard
>     MozReview-Commit-ID: 8fFPVwl4bd3
>     --HG--
>     extra : source : 2514d1549b0b2824906d893d8be19f931f0eb055

# Result
https://cleopatra.io/#report=6e0fa80692c5c24d334ce02eca15f33c186caaf8&filter=[{%22type%22%3A%22RangeSampleFilter%22,%22start%22%3A1386851,%22end%22%3A1390942}]&selection=0,1,319

From Gecko Profiling data, the Range [1386851, 1390943]:
 4091  100%  Startup::XRE_Main
 1109 27.1% ├─ nsInputStreamPump::OnInputStreamReady
 1000 24.4% │  ├─ nsInputStreamPump::OnStateStop
   82  2.0% │  ├─ nsInputStreamPump::OnStateTransfer
   27  0.7% │  └─ nsInputStreamPump::OnStateStart
  730 17.8% ├─ js::RunScript
  651 15.9% ├─ Timer::Fire
  629 15.4% ├─ nsHtml5TreeOpExecutor::RunFlushLoop
  569 13.9% │  ├─ nsJSUtils::EvaluateString
   43  1.1% │  ├─ EventDispatcher::Dispatch
            │  └─ ...so on
            └─ ...so on

Comment 3

[:Harald Kirschner :digitarald]

We need platform engineers to review the profile to have more details in this bug.

Comment 4

[(Away)]

Hi Askeing, I'm looking at [qf:investigate] issues, and I see many bugs titled "spent more time" which I'm having trouble understanding. Usually in English one would say "more ... than" to make a comparison to something else.

Are you saying that nsJSUtils::EvaluateString takes more time in this build than the previous build? Or that nsJSUtils::EvaluateString takes more time than some equivalent function in Chrome? Or that nsJSUtils::EvaluateString is generally too expensive for the amount of work that it's doing? Or something else?

Thanks!

Comment 5

[Askeing Yen[:askeing][:fyen]]

The "spent more time" means this component spent comparatively higher percentage (13.9%) than other components.

Comment 6

[Askeing Yen[:askeing][:fyen]]

Furthermore, please see the call stack below.

-----
  629 15.4% ├─ nsHtml5TreeOpExecutor::RunFlushLoop
  569 13.9% │  ├─ nsJSUtils::EvaluateString
   43  1.1% │  ├─ EventDispatcher::Dispatch
            │  └─ ...so on
------

"nsJSUtils::EvaluateString" is 13.9%, and others are (15.4 - 13.9 = 1.5%).
So, we think this component might be the entry point for tracking all the blocking bugs.


Shako, please correct me if I miss something.

Comment 7

[Shako Ho]

Hi bobby,

  Could you help me to clarify do we still need to leave these bugs "xxxx spent more time ..." open?

  All these bugs are opened based on the profiler data analysis from QA perspective, but according to the past few quarters, we realize engineers will follow the same way to analyze these profiler data.

Comment 8

[Bobby Chien]

Leave open here as it has been noted as [qf:investigate].

Comment 9

[(Away)]

(In reply to Bobby Chien [:bchien] from comment #8)
> Leave open here as it has been noted as [qf:investigate].

This seems like circular reasoning to me. It's not clear that these "spent more time" bugs should be [qf:investigate] at all.

(In reply to Askeing Yen[:askeing][:fyen] from comment #5)
> The "spent more time" means this component spent comparatively higher
> percentage (13.9%) than other components.

I don't think this style of bug is a productive route to fixing performance issues. It's useful to have bugs for high-level symptoms ("Page XYZ is slow"), and investigating those will lead to bugs for specific code issues ("Foo::Bar calls Baz in this bad way") but this sort of drilling-down-only-halfway is an incomplete investigation at best, and may be misleading at worst.