Petruta Horea [:phorea], Desktop QA Reporter
	Description • 8 years ago

[Note]:
- Issue doesn't reproduce under Ubuntu 12.04 64-bit

[Affected versions]:
- latest Nightly 47.0a1 2016-02-15
- latest Aurora 46.0a2 2016-02-15

[Affected platforms]:
- Win 7 64-bit
- Mac OS X 10.9.5

[Steps to reproduce]:
1. Open a large PDF (eg http://cp.literature.agilent.com/litweb/pdf/5989-8139EN.pdf)
2. Scroll fast up and down using mouse wheel.
3. Scroll up and down using the trackpad (OSX)

[Expected result]:
- The scrolling is smooth, without any jerkiness or rendering issues.

[Actual result]:
- The pdf's dark background becomes visible.
The issue doesn't reproduce with APZ pref disabled.

[Regression range]:
- Last good revision: 8b1fc0961a076e35646d0
- First bad revision: 45273bbed8efaface6f5e
https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=8b1fc0961a076e3564
6d0472a81feefc0074558c&tochange=45273bbed8efaface6f5ec56d984cb9faf4fbb6a

I will investigate further the regression range as it seems that in some 45.0a1 Nightly the issue didn't reproduce with the pref set to true and the above range only points to APZ changes that are related to Fennec.
I'll follow up with the results.

	Kartikaya Gupta (email:kats@mozilla.staktrace.com)
	Comment 1 • 8 years ago

This looks like regular checkerboarding.

	Benjamin Smedberg
	Comment 2 • 8 years ago

Does that mean this is WONTFIX, or dependent on some other bug tree?

	Kartikaya Gupta (email:kats@mozilla.staktrace.com)
	Comment 3 • 8 years ago

Well we can try to improve the behaviour on this, although most likely improvements will be minimal. The first step though is profiling the page to see why the main thread is taking up time. I got a profile on a recent OS X nightly [1] and from a quick examination of the part where I was madly scrolling up and down on the page [2] it looks like a good chunk of time is spent in JS and cycle collection innards. So somebody knowledgeable in that code should probably take a look a this profile to see if there's anything obvious that stands out that could be improved. ni? to :mccr8 and :djvj for CC and Ion stuff respectively.

(Note that if you load the second link below, the "samples" tab will actually show the running time relative to the entire profile, not the selected sample range. Click anywhere on the graph labeled "content" to have it update - you should see __mprotect taking up 8.2% of the running time).

[1] https://cleopatra.io/#report=c3e93aa733509d6f648b8610f3d7f9e43757536e
[2] https://cleopatra.io/#report=c3e93aa733509d6f648b8610f3d7f9e43757536e&invertCallback=true&filter=[{%22type%22%3A%22RangeSampleFilter%22,%22start%22%3A449540,%22end%22%3A451367}]&selection=%22%28total%29%22,378

	Andrew McCreight [:mccr8]
	Comment 4 • 8 years ago

The nsCycleCollector::FreeSnowWhite() means that a lot of cycle collected objects with refcount 0 are being destroyed, without the involvement of the cycle collector. (The stacks under je_malloc_usable_size -> free may give an indication of what.)

	Kannan Vijayan [:djvj]
	Comment 5 • 8 years ago

Ok, so taking a closer look at this, the calls to |mprotect| are due to megamorphic |obj.prop = ...| assignment somewhere in this function:

https://github.com/mozilla/pdf.js/blob/e8db8255123dac16973004c24b529c598d24e781/src/display/text_layer.js#L60

I don't know which property assignment within that function is responsible for this, but there are a few candidate objects.

textdiv.dataset gets properties set on it in multiple places in that function (e.g. textdiv.dataset.fontName = geom.fontName).

Also, textdiv.style also gets properties set on it in multiple places (e.g. textdiv.style.left = left + 'px').

Also the line |textDiv.textContent = geom.str| sets a property on textdiv directly.

My intuition is that the culprit is probably textdiv.dataset or textdiv.style.  The assignment of properties on these objects is being complied as an inline cache, and the inline cache keeps generating new IC stubs, and generating new stubs requires that existing stub code be patched, and that forces heavy calls to mprotect to add and remove write perms from the code for modification.  One way to fix it is to profile the code in more detail and figure out where and why we keep generating new IC stubs, and fix that issue.

Alternatively, I know that there is work being done on using the Baseline IC scheme (which does not require code repatches when adding stubs) for Ion ICs.  If/when that lands, this problem with mprotect will likely go away.  Jandem or h4writer probably has a better idea on how soon that work might land, and if it's actually relevant to this case.

	Jan de Mooij [:jandem]
	Comment 6 • 8 years ago

(In reply to Kannan Vijayan [:djvj] from comment #5)
> Alternatively, I know that there is work being done on using the Baseline IC
> scheme (which does not require code repatches when adding stubs) for Ion
> ICs.  If/when that lands, this problem with mprotect will likely go away. 
> Jandem or h4writer probably has a better idea on how soon that work might
> land, and if it's actually relevant to this case.

I'm planning to work on this (and other IC improvements) the coming weeks/months (starting with bug 1255352). Note that mprotect is a bit slower on OS X than on Linux and Windows, but we need to fix this and other IC problems that keep coming up.

	Kartikaya Gupta (email:kats@mozilla.staktrace.com)
	Comment 7 • 8 years ago

Thanks for the update!

	Kartikaya Gupta (email:kats@mozilla.staktrace.com)
	Comment 8 • 8 years ago

I'm going to dupe this over to the checkerboarding meta bug since there doesn't seem to be much value in leaving this specific bug open. It looks like the JS improvements are underway but will take a while.