Closed Bug 1264535 (gdoc_pd3_ubuntu(61%)) Opened 8 years ago Closed 6 years ago

[perf][google suite][google docs] 61.03%(7867ms) slower than Chrome when scrolling a file with 3 pages by page down key

Categories

(Core :: General, defect, P3)

Product:
Core
Component:
General
Version:
45 Branch
Platform:
x86_64
Linux
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE
Project Flags:
Performance Impact ?
Tracking Flags:
Tracking Status
platform-rel --- -

People

(Reporter: askeing, Unassigned)

References

(Blocks 2 open bugs)

Details

(Keywords: perf, Whiteboard: [platform-rel-Google][platform-rel-GoogleSuite][platform-rel-GoogleDocs])

User Story

You can find all test scripts on github link:
https://github.com/mozilla-twqa/hasal

And you can also find the running script name in comments
for example: 
test scripts: test_chrome_gdoc_create_txt_1
then you can specify the test script name on suite.txt and run it

Attachments

(3 files, 2 obsolete files)

test_firefox_gdoc_pd3_1462438694.har
8.04 MB, text/plain
Details
release50_buildconfig.png
22.94 KB, image/png
Details
nightly53_buildconfig.png
24.05 KB, image/png
Details
Summary: [Perf][google docs] Scroll a file with 3 pages by page down key → [Perf][google docs] 61.03%(7867ms) slower than Chrome when scrolling a file with 3 pages by page down key
Summary: [Perf][google docs] 61.03%(7867ms) slower than Chrome when scrolling a file with 3 pages by page down key → [Perf][google docs] Scroll a file with 3 pages by page down key
Summary: [Perf][google docs] Scroll a file with 3 pages by page down key → [Perf][google docs] 61.03%(7867ms) slower than Chrome when scrolling a file with 3 pages by page down key
# Test Case
STR
1. Launch the browser with blank page
2. input the google doc url with 3 page content 
3. press page down 3 times
4. close the browser

# Hardware
OS: Ubuntu 14.04 LTS 64-bit
CPU: i7-3770 3.4GMhz
Memory: 16GB Ram
Hard Drive: 1TB SATA HDD
Graphics: GK107 [GeForce GT 640]/ GF108 [GeForce GT 440/630]

# Browsers
Firefox version: 45.0.2
Chrome version: 50.0.2661.75

# Result
Browser | Run time (median value) 
Firefox | 20755.5555555555 ms
Chrome  | 12888.8888888889 ms
Product: Firefox → Core
(In reply to Shako Ho from comment #1)
> # Test Case
> STR
> 1. Launch the browser with blank page
> 2. input the google doc url with 3 page content 
> 3. press page down 3 times
> 4. close the browser
> 
> # Hardware
> OS: Ubuntu 14.04 LTS 64-bit
> CPU: i7-3770 3.4GMhz
> Memory: 16GB Ram
> Hard Drive: 1TB SATA HDD
> Graphics: GK107 [GeForce GT 640]/ GF108 [GeForce GT 440/630]
> 
> # Browsers
> Firefox version: 45.0.2
> Chrome version: 50.0.2661.75
> 
> # Result
> Browser | Run time (median value) 
> Firefox | 20755.5555555555 ms
> Chrome  | 12888.8888888889 ms

test_firefox_gdoc_pd3.sikuli
test_chrome_gdoc_pd3.sikuli
Attachment #8749078 - Attachment is obsolete: true
Attachment #8749081 - Attachment is obsolete: true
Due to the profiler's buffer is not enough, run script again.

# Profiling Data:
https://cleopatra.io/#report=9cc2bcb2eaa3d81d9d70345b6365c3cd2298e0b2&filter=%5B%7B%22type%22%3A%22RangeSampleFilter%22,%22start%22%3A42807,%22end%22%3A68148%7D,%7B%22type%22%3A%22RangeSampleFilter%22,%22start%22%3A60977,%22end%22%3A67601%7D%5D&selection=0,1,11

# Performance Timing:
http://goo.gl/ZU2hu7
{
  "navigationStart": 1462438737913,
  "unloadEventStart": 0,
  "unloadEventEnd": 0,
  "redirectStart": 0,
  "redirectEnd": 0,
  "fetchStart": 1462438737919,
  "domainLookupStart": 1462438737919,
  "domainLookupEnd": 1462438737941,
  "connectStart": 1462438737941,
  "connectEnd": 1462438737941,
  "requestStart": 1462438738707,
  "responseStart": 1462438739126,
  "responseEnd": 1462438739126,
  "domLoading": 1462438739129,
  "domInteractive": 1462438740921,
  "domContentLoadedEventStart": 1462438741963,
  "domContentLoadedEventEnd": 1462438741964,
  "domComplete": 1462438749026,
  "loadEventStart": 1462438749026,
  "loadEventEnd": 1462438749034
}

# Adding perf mark (#3 #4 #5) into following test script:
https://github.com/Mozilla-TWQA/Hasal/blob/master/tests/test_firefox_gdoc_pd3.sikuli/test_firefox_gdoc_pd3.py
> sys.path.append(sys.argv[2])
> import browser
> import common
> import gdoc
> 
> 
> com = common.General()
> ff = browser.Firefox()
> gd = gdoc.gDoc()
> 
> ff.clickBar()
> ff.enterLink(sys.argv[3])
> 
> gd.wait_for_loaded()
> ff.profilerMark_3()
> 
> for i in range(3):
>     wait(0.5)
>     ff.profilerMark_4()
>     type(Key.PAGE_DOWN)
> 
> ff.profilerMark_5()
> sleep(2)
> gd.deFoucsContentWindow()
Depends on: 1270427
# Try to identify the time between "domLoading" to "loadEventEnd"

From Perf Timing json, the "domLoading" to "loadEventEnd" are 1216 ~ 11121 ms, diff is 9905 ms.
Switch to profiling data, we can only check the Add-on start/end mark.
The first "Start" to last "End" marks, timestamp are 43105 ~ 52958 ms, diff is 9853 ms.

From Gecko Profiling data, the Range [43041, 53108]:
 9939  100%  Startup::XRE_Main
 3217 32.4% ├─ Timer::Fire 
 2013 20.3% ├─ nsInputStreamPump::OnInputStreamReady
 1771 17.8% │  ├─ nsInputStreamPump::OnStateStop
> ref: bug 1267971
  157  1.6% │  ├─ nsInputStreamPump::OnStateTransfer
   85  0.9% │  └─ nsInputStreamPump::OnStateStart
 1482 14.9% ├─ nsRefreshDriver::Tick
> new: bug 1270427
  614  6.2% │  ├─ PresShell::Paint
  341  3.4% │  ├─ PresShell::Flush (Flush_Style)
  260  2.6% │  ├─ js::GCRuntime::collect
  183  1.8% │  ├─ PresShell::Flush (Flush_InterruptibleLayout)
            │  └─ ...so on
 1217 12.2% ├─ nsHtml5TreeOpExecutor::RunFlushLoop
 1050 10.6% │  ├─ nsJSUtils::EvaluateString
> ref: bug 1270351
  148  1.5% │  ├─ EventDispatcher::Dispatch
            │  └─ ...so on
            └─ ...so on
No longer depends on: 1270427
Depends on: 1270427, 1267971, 1270351
Depends on: 1270737
Depends on: 1270739
# Try to identify the time when clicking Page Down

From Gecko Profiling data, the Range [60950, 67564]:
 6613  100% Startup::XRE_Main
 4182 63.2% ├─ __pool
 1020 15.4% ├─ nsRefreshDriver::Tick
> new: bug 1270737
  730 11.0% │  ├─ PresShell::Paint
   74  1.1% │  ├─ js::GCRuntime::collect
   72  1.1% │  ├─ EventDispatcher::Dispatch
   62  0.9% │  ├─ PresShell::Flush (Flush_Style)
            │  └─ ...so on
  593  9.0% ├─ nsViewManager::Dispatch
  512  7.7% │  ├─ EventDispatcher::Dispatch
> new: bug 1270739

   39  0.6% │  ├─ nsLayoutUtils::GetFrameForPoint
            │  └─ ...so on
            └─ ...so on
Version: unspecified → 45 Branch
QA Contact: fyen
User Story: (updated)
Whiteboard: [platform-rel-Google][platform-rel-GoogleDocs]
platform-rel: --- → ?
Severity: normal → critical
Priority: -- → P1
Hi Bobby,

For Firefox Nightly, 13.24%(2783ms) slower than Chrome when scrolling a file with 3 pages by page down 

# Browsers
Firefox version: Nightly 50.0a1 (2016/06/28)
Chrome version: 50.0.2661.75

# Result
Browser  | Run time (median value) 
Firefox  | 23,800.00 ms
Chrome   | 21,016.67 ms

# Video
https://www.youtube.com/watch?v=_dHZXZuZKd8

# Profiler 
https://cleopatra.io/#report=23021c0b94cf0623430351b177e610d904bad00f

# Test Data
https://goo.gl/YSsvTg
platform-rel: ? → +
# Hardware
OS: Windows 7
CPU: i7-3770 3.4GMhz
Memory: 16GB Ram
Hard Drive: 1TB SATA HDD
Graphics: GK107 [GeForce GT 640]/ GF108 [GeForce GT 440/630]

# Browsers
Firefox version: 47
Chrome version: 50.0.2704.103

# Result
Browser | Run time (median value) 
Firefox | 21800 ms
Chrome  | 12989 ms

Comparing to the old 61.03% slower results, results in win7 shows a 67.83% slower.
Alias: gdoc_findr3
Alias: gdoc_findr3 → gdoc_create_txt_1
Alias: gdoc_create_txt_1 → gdoc_pd3
Alias: gdoc_pd3 → gdoc_pd3_ubuntu(61%)
(In reply to Walter Chen[:ypwalter][:wachen] from comment #13)
> Further testing details:
> https://docs.google.com/spreadsheets/d/1O6Y0coEzWg6YMhe6ecsB-
> 4Z6ABN_S18KIm87hPGjt2A/edit#gid=0

The attached seems to relate to Facebook rather than Google Docs?
Flags: needinfo?(wachen)
Sorry! I put the link in the wrong bug :P
It is indeed fb related profile.
Flags: needinfo?(wachen)
Whiteboard: [platform-rel-Google][platform-rel-GoogleDocs] → [platform-rel-Google][platform-rel-GoogleSuite][platform-rel-GoogleDocs]
The profile https://cleopatra.io/#report=9cc2bcb2eaa3d81d9d70345b6365c3cd2298e0b2 shows

  46% script
  38% paint

in between markers 3 and 5, not counting the time spent waiting.

Note that 14% of those samples are uncategorized, which means I should work on the script some more, but this seems good enough to go off of. Some of the uncategorized samples look kind of strange and suspicious, though; they include things like NS_DebugBreak and NS_ShutdownXPCOM that should not be happening in that time period, so I'm a little suspicious of the symbolication here.
Blocks: 1299643
Summary: [Perf][google docs] 61.03%(7867ms) slower than Chrome when scrolling a file with 3 pages by page down key → [perf][google suite][google docs] 61.03%(7867ms) slower than Chrome when scrolling a file with 3 pages by page down key
plat-rel tracked at meta/parent level
platform-rel: + → -
(In reply to Walter Chen[:ypwalter][:wachen] from comment #18)
> New Profiler Data can be downloaded from: (windows 7)
> https://drive.google.com/file/d/0BwkEhia_D6l_SHlYa05QbU9aMFE/view?usp=sharing

Unfortunately the profile file alone isn't very useful because cleopatra cannot symbolicate it without having access to the debug information that belongs to the build.  As a result, all native symbols in the profile show up as addresses in xul.pdb (see the profile in cleopatra: <https://cleopatra.io/#report=62f260d70826c419f77a59114927a1144a4c8adc>)

Can you please load the profile in cleopatra on the machine that produced the build and upload that to cleopatra so that we can see the symbolicated profile?  Thank you!
(In reply to :Ehsan Akhgari from comment #19)
> (In reply to Walter Chen[:ypwalter][:wachen] from comment #18)
> > New Profiler Data can be downloaded from: (windows 7)
> > https://drive.google.com/file/d/0BwkEhia_D6l_SHlYa05QbU9aMFE/view?usp=sharing
> 
> Unfortunately the profile file alone isn't very useful because cleopatra
> cannot symbolicate it without having access to the debug information that
> belongs to the build.  As a result, all native symbols in the profile show
> up as addresses in xul.pdb (see the profile in cleopatra:
> <https://cleopatra.io/#report=62f260d70826c419f77a59114927a1144a4c8adc>)
> 
> Can you please load the profile in cleopatra on the machine that produced
> the build and upload that to cleopatra so that we can see the symbolicated
> profile?  Thank you!

Please check the latest symbolicated profile and this is different with comment#18's one:
https://cleopatra.io/#report=c89e13f8227c3888e0c288d7b5b2b5bc5004bbc9
(In reply to Mike Lien[:mlien] from comment #20)
> (In reply to :Ehsan Akhgari from comment #19)
> > (In reply to Walter Chen[:ypwalter][:wachen] from comment #18)
> > > New Profiler Data can be downloaded from: (windows 7)
> > > https://drive.google.com/file/d/0BwkEhia_D6l_SHlYa05QbU9aMFE/view?usp=sharing
> > 
> > Unfortunately the profile file alone isn't very useful because cleopatra
> > cannot symbolicate it without having access to the debug information that
> > belongs to the build.  As a result, all native symbols in the profile show
> > up as addresses in xul.pdb (see the profile in cleopatra:
> > <https://cleopatra.io/#report=62f260d70826c419f77a59114927a1144a4c8adc>)
> > 
> > Can you please load the profile in cleopatra on the machine that produced
> > the build and upload that to cleopatra so that we can see the symbolicated
> > profile?  Thank you!
> 
> Please check the latest symbolicated profile and this is different with
> comment#18's one:
> https://cleopatra.io/#report=c89e13f8227c3888e0c288d7b5b2b5bc5004bbc9

Unfortunately this profile is missing the native stacks again.  :(

Can you please describe exactly how you obtained the build that you made this profile from?  Can you run the same build and go to about:buildconfig and post what you find there here?  Thanks!
Flags: needinfo?(mlien)
The simplest way to use the correct build is to download the latest Nightly and run the tests on that.  Nightly is build with --enable-profiling already.
This is auto-updated release build(50), and the build config as attachment shown.
I'll leave ni here and post nightly build's profiling data later.
Attachment is the build config of nightly 53 and the latest profiling data as below:
https://cleopatra.io/#report=939facc9ab8cfa9ce4e69d825a069e9551037322
Flags: needinfo?(mlien)
(In reply to Mike Lien[:mlien] from comment #23)
> Created attachment 8818771 [details]
> release50_buildconfig.png
> 
> This is auto-updated release build(50), and the build config as attachment
> shown.
PS:
The Windows release build operate in pseudo stack.

https://developer.mozilla.org/en-US/docs/Mozilla/Performance/Profiling_with_the_Built-in_Profiler#Availability


> I'll leave ni here and post nightly build's profiling data later.
Whiteboard: [platform-rel-Google][platform-rel-GoogleSuite][platform-rel-GoogleDocs] → [platform-rel-Google][platform-rel-GoogleSuite][platform-rel-GoogleDocs][qf:p3]
Whiteboard: [platform-rel-Google][platform-rel-GoogleSuite][platform-rel-GoogleDocs][qf:p3] → [qf:p3][platform-rel-Google][platform-rel-GoogleSuite][platform-rel-GoogleDocs]
Whiteboard: [qf:p3][platform-rel-Google][platform-rel-GoogleSuite][platform-rel-GoogleDocs] → [qf:p3][qf:investigate][platform-rel-Google][platform-rel-GoogleSuite][platform-rel-GoogleDocs]
Whiteboard: [qf:p3][qf:investigate][platform-rel-Google][platform-rel-GoogleSuite][platform-rel-GoogleDocs] → [qf:investigate][platform-rel-Google][platform-rel-GoogleSuite][platform-rel-GoogleDocs]
Keywords: perf
Moving to p3 because no activity for at least 24 weeks.
Priority: P1 → P3
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE
Performance Impact: --- → ?
Whiteboard: [qf:investigate][platform-rel-Google][platform-rel-GoogleSuite][platform-rel-GoogleDocs] → [platform-rel-Google][platform-rel-GoogleSuite][platform-rel-GoogleDocs]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: