Add the attach file.

Deleted: testdrive.tar.gz 2.2 MB

testdrive.tar.gz 2.2 MB Download

Our guess is r530586: "blink/canvas: Switch Canvas to use cc's ImageDecodeCache".

Tested the issue on Win-10 using chrome reported version #66.0.3341.0 and chrome version #65.0.3322.0.

Attached a screen casts, gpu_details and win-10 specifications for reference for reference.

Following are the steps followed to reproduce the issue.
------------
1. Downloaded the attachment file "testdrive.tar.gz"
2. Unzipped it, then opened the "testdrive/Performance/DefaultMod.html" with Chrome Canary
3. Choose the 9000 fishes and observed the fps downgraded to 3-4 fps.

Note: The behaviour is same in both the chrome reported version #66.0.3341.0 and chrome version #65.0.3322.0.

reporter@ - Could you please check the attached screen casts and please let us know if anything missed from our side. Any further inputs from your end will help us in triaging the issue further.
Thanks...!!

Deleted: 809841@M65.mp4 15.4 MB

809841@M65.mp4 15.4 MB Download

Deleted: gpu_details.txt 10.5 KB

gpu_details.txt 10.5 KB View Download

Deleted: 809841@M66.mp4 11.6 MB

	809841@M66.mp4 11.6 MB View Download

Deleted: win-10 spec.PNG 44.0 KB

	win-10 spec.PNG 44.0 KB View Download

Not related to Performance APIs.

Relabeling, and assigning to khushalsagar as per #3.

Tested this on ToT with and without the code path that the change in #3 affected and I don't see any change.

> Fps downgrade 3-4 fps.

This doesn't give any indication as to whether the problem is serious or not. For instance, if the frame rate dropped from 1,000 to 997 fps then that would be considered irrelevant, probably just noise. However if the frame rate dropped from 4-5 fps to 1 fps then that would be a severe regression.

The videos in comment #4 show the frame rate at around 3-4 fps in both M65 and m66. On my machine I see 18-20 fps on M64 and 13-15 fps on M66. The measurements are not helped by the fact that the fish start very large and then gradually get smaller - it's not clear how long you have to wait for them to stabilize.

So, some questions:

Does this regression still repro with the latest M66 canary? (it looks like it does)
What frame rate did you see before and after?
Can you share your GPU details from chrome://gpu?
You mention that your GPU is "GPU: HD 630 / Nvidia GeForce GTX 1080" but Chrome usually doesn't use the Nvidia GPU, it uses the Intel GPU.

BTW, your testdrive download has two copies of TestDriveCommon.js, in the same directory, which is a bit confusing when extracting the contents.

Since I can repro this I'll gather some initial measurements. Temporarily assigning to myself.

I grabbed an ETW trace and it showed that in both cases (M64 and M66, 64-bit) the renderer process was using 2.16% of the CPU time on my 48-thread machine, so a bit more than one core. In both cases the main thread of the renderer process was using ~99.4% of a core. The GPU was mostly idle in both cases.

I then selected ten frames from each trace (easily visible from the GPU tracing data I captured) and looked at the flame graph of the CPU Usaged (sampled) data. The renderer process had 524 samples in M64 and 701 samples in M66 (sampling rate is ~1 kHz). The biggest difference was the number of samples in chrome_child.dll!blink::BaseRenderingContext2D::drawImage which had 260 samples (inclusive, children as well) and 419 in M66. That means that everything else was consuming 264 and 282 samples in M64 and M66, which is statistically identical.

So, we need to find where the extra ~159 samples are going. Exploring the CPU Usage (sampled) data stacks and flame graphs it looks like the biggest difference is:
    chrome_child.dll!blink::CanvasResourceProvider::CanvasImageProvider::GetDecodedDrawImage
This function is hit by 98 samples in M66 and zero samples in M64. Additionally there are another 14 samples in chrome_child.dll!cc::ImageProvider::ScopedDecodedDrawImage::~ScopedDecodedDrawImage.

I also see 14 samples in chrome_child.dll!WTF::CurrentTimeTicksInSeconds in M66 and this doesn't appear to show up in M64. It's called by chrome_child.dll!blink::BaseRenderingContext2D::drawImage. CurrentTimeTicksInSeconds comes from crrev.com/c/827545 which used that to replace WTF::MonotonicallyIncreasingTime which consumed 8 samples in the M64 trace - it's not clear if this is a minor regression or a statistical anomaly.

I have attached screen shots of the two ETW traces with most of the crucial data visible. I can also share the traces opened up to my analysis point but they are 40 MB apiece and not always the friendliest things to examine.

> Our guess is r530586: "blink/canvas: Switch Canvas to use cc's ImageDecodeCache".

That looks correct.

chrishtr@ - any thoughts on this?

Deleted: M64 profile.png 198 KB

	M64 profile.png 198 KB View Download

Deleted: M66 profile.png 253 KB

	M66 profile.png 253 KB View Download

This sounds like a Canvas regression, of which there have been some recently.
Justin?

Is it simple enough to run the test that a bisect is feasible?

That patch did result in a canvas regression from the lock/unlock on images that was fixed in  issue 804325 . But may be simply updating the ref count in the cache could also be the cause here. I tested on my linux machine with the cache disabled and couldn't reproduce a significant difference.

brucedawson@, can you verify if disabling the cc cache use in canvas fixes this on Win? Just commenting out this line should do it (https://cs.chromium.org/chromium/src/third_party/WebKit/Source/platform/graphics/CanvasResourceProvider.cpp?type=cs&q=CanvasResourceProvider&l=509). You shouldn't see any samples from ImageProvider.

I commented out that line and replaced it with "return nullptr;" and that improved the frame-rate on my local builds from ~13 fps to ~17 fps - the difference was quite clear and consistent.

I made testing a little bit easier by modifying this line in DefaultMod.html to change the default number of fish from 20 to 9000:

    var startFish = 9000;          //number of fish to start with

Changing this line makes this fish start out small instead of starting big and shrinking. There seems to be a bug in the script but I'm not motivated to find it but this makes the results more consistent:

    var z = Math.floor(0.3 * Math.random() * ((zFar - zClose)));              //set the starting z location 

Getting an image from cc's cache isn't as cheap as it was with skia, given that each call involves generating the cache key from DrawImages using the color space, other than the ref-count updates. And since this is an extreme case with 9000 of these calls every frame, it starts to have a noticeable impact. But I don't know much we can do to optimize here and whether this case is worth trying to optimize. ericrk@, ideas?

brucedawson@, Thank you for reproducing this bug.

Answer your question:
Does this regression still repro with the latest M66 canary? (it still exists.)
What frame rate did you see before and after? (fps downgrade from ~19 to ~15).
Can you share your GPU details from chrome://gpu?  (Please refer to the attach file.)
GPU : Intel HD Graphics 630

Deleted: GPU-info.txt 16.3 KB

GPU-info.txt 16.3 KB View Download

Based on a quick observation of the profile graph, it looks like the regression might be caused by the image getting re-color corrected each time it is drawn.  This should not be happening. If the cache is storing color-correct images.

Currently (with all experiments disabled), the canvas always wants to consume images in the sRGB color-space.  When using images that do not have an embedded profile, they should be assumed to be in sRGB space.  In any case, the image cache should always be providing images tagged with an sRGB color profile

@khushalsagar: Can you confirm this is the case?

I forced a color profile to test the color space conversion on my machine and I see that working as expected. Attaching a trace, there is a "GpuImageDecodeCache::UploadImage - color conversion" trace on the first frame and after that we just use the cached uploaded image for all subsequent frames. A few frames down the line I upped the fish number to 9000. Those frames are longer because of 9000 calls to GetDecodedImageForDraw from the cache (the tracing itself makes it look even worse).

Deleted: trace_gpu_cache_fish_tank.json.gz 4.5 MB

trace_gpu_cache_fish_tank.json.gz 4.5 MB Download

Closing this one. The regression is for an extreme case, and what could be done to address similar cases was done in  issue 804325 .

I check this issue on the latest canary chrome(66.0.3346.0), it still exists.
BTW, the CL(https://chromium-review.googlesource.com/c/chromium/src/+/884881) for   issue 804325   has been landed on 66.0.3337.0.
I file this issue from 66.0.3341.0.
Thanks.

The change which introduced it has a minor overhead for retrieving images from the cache, which becomes noticeable since its done 9000 times every frame in this test case. So this is a real regression, but there isn't anything actionable we can do to fix it.