Thumbnails: Make sure there are no race conditions |
|||
Issue descriptionAs bug 774798 has proven, we don't have sufficient test coverage for thumbnail capturing. Add tests that make sure thumbnails get captured at the right moments, contain the correct image data, and get associated with the correct URL. Bonus points: Also check the various types of redirects.
,
Oct 25 2017
,
Nov 2 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/cbc140c9ece3d71c6c4233b20ccfb5d52cbb2229 commit cbc140c9ece3d71c6c4233b20ccfb5d52cbb2229 Author: Marc Treib <treib@chromium.org> Date: Thu Nov 02 17:49:28 2017 Thumbnail capturing: Resolve raciness It looks like capturing a screenshot just when we're about to navigate away is racy, and sometimes captures the new page rather than the existing one. (Seen only in tests though, I couldn't reproduce this in practice.) To resolve this race condition, discard the screenshot if a DocumentAvailableInMainFrame event has happened since we started capturing. This CL also extends the tests to delay page loads until the capture has finished, so that capturing actually works in the tests. The tests now also verify the contents of the captured images. Bug: 778248 Change-Id: I332b4f0aa7f527360a5171152d97b687e7ecf559 Reviewed-on: https://chromium-review.googlesource.com/735486 Reviewed-by: Mikel Astiz <mastiz@chromium.org> Commit-Queue: Marc Treib <treib@chromium.org> Cr-Commit-Position: refs/heads/master@{#513540} [modify] https://crrev.com/cbc140c9ece3d71c6c4233b20ccfb5d52cbb2229/chrome/browser/thumbnails/thumbnail_browsertest.cc [modify] https://crrev.com/cbc140c9ece3d71c6c4233b20ccfb5d52cbb2229/chrome/browser/thumbnails/thumbnail_tab_helper.cc [modify] https://crrev.com/cbc140c9ece3d71c6c4233b20ccfb5d52cbb2229/chrome/browser/thumbnails/thumbnail_tab_helper.h [modify] https://crrev.com/cbc140c9ece3d71c6c4233b20ccfb5d52cbb2229/chrome/browser/thumbnails/thumbnailing_context.cc [modify] https://crrev.com/cbc140c9ece3d71c6c4233b20ccfb5d52cbb2229/chrome/browser/thumbnails/thumbnailing_context.h [add] https://crrev.com/cbc140c9ece3d71c6c4233b20ccfb5d52cbb2229/chrome/test/data/thumbnail_capture/red.html
,
Nov 6 2017
Currently, both tests are flaky on Mac and Windows. Failure output looks like this (for SlowPageLoad):
[ RUN ] ThumbnailTest.ShouldCaptureOnNavigatingAwaySlowPageLoad
[64352:775:1103/113227.760278:ERROR:gpu_process_transport_factory.cc(1011)] Lost UI shared context.
[64352:3843:1103/113227.789000:WARNING:notification_platform_bridge_mac.mm(527)] AlertNotificationService: XPC connection invalidated.
[64352:88835:1103/113229.461077:WARNING:embedded_test_server.cc(228)] Request not handled. Returning 404: /favicon.ico
unknown file: Failure
Unexpected mock function call - returning default value.
Function call: SetPageThumbnail(@0x7f95d3450350 184-byte object <01-00 00-00 00-00 00-40 A0-F4 4C-CE 95-7F 00-00 41-00 00-00 00-00 00-00 31-00 00-00 00-00 00-00 00-2B 45-D3 95-7F 00-00 01-00 00-00 00-00 00-40 00-00 00-00 04-00 00-00 00-00 00-00 FF-FF FF-FF ... 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 03-00 00-00 34-01 00-00 C0-00 00-00 FF-FF FF-FF 00-00 00-00 00-00 F0-3F 01-01 00-00 00-00 00-40 88-A8 49-9C AE-BB 2E-00 00-00 00-00 02-00 00-00>, @0x7fff5b9e5fd8 8-byte object <40-05 58-CE 95-7F 00-00>)
Returns: false
Google Mock tried the following 2 expectations, but none matched:
../../chrome/browser/thumbnails/thumbnail_browsertest.cc:282: tried expectation #0: EXPECT_CALL(*thumbnail_service(), SetPageThumbnail(Field(&ThumbnailingContext::url, about_blank_url), _))...
Expected arg #0: is an object whose given field is equal to about:blank
Actual: 184-byte object <01-00 00-00 00-00 00-40 A0-F4 4C-CE 95-7F 00-00 41-00 00-00 00-00 00-00 31-00 00-00 00-00 00-00 00-2B 45-D3 95-7F 00-00 01-00 00-00 00-00 00-40 00-00 00-00 04-00 00-00 00-00 00-00 FF-FF FF-FF ... 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 03-00 00-00 34-01 00-00 C0-00 00-00 FF-FF FF-FF 00-00 00-00 00-00 F0-3F 01-01 00-00 00-00 00-40 88-A8 49-9C AE-BB 2E-00 00-00 00-00 02-00 00-00>, whose given field is http://127.0.0.1:65191/thumbnail_capture/red.html
Expected: to be never called
Actual: never called - saturated and active
../../chrome/browser/thumbnails/thumbnail_browsertest.cc:293: tried expectation #1: EXPECT_CALL(*thumbnail_service(), SetPageThumbnail(Field(&ThumbnailingContext::url, red_url), ImageColorIs(static_cast<SkColor>(0xFFFF0000))))...
Expected arg #1: image color is 4294901760
Actual: 8-byte object <40-05 58-CE 95-7F 00-00>, expected color FFFF0000 but actual color is FFFFFFFF
Expected: to be called once
Actual: never called - unsatisfied and active
[64352:775:1103/113230.811681:INFO:chrome_cryptauth_service.cc(222)] Profile is not authenticated yet; waiting before starting CryptAuth managers.
../../chrome/browser/thumbnails/thumbnail_browsertest.cc:293: Failure
Actual function call count doesn't match EXPECT_CALL(*thumbnail_service(), SetPageThumbnail(Field(&ThumbnailingContext::url, red_url), ImageColorIs(static_cast<SkColor>(0xFFFF0000))))...
Expected: to be called once
Actual: never called - unsatisfied and active
[ FAILED ] ThumbnailTest.ShouldCaptureOnNavigatingAwaySlowPageLoad, where TypeParam = and GetParam() = (3194 ms)
i.e. we got a white thumbnail instead of a red one. Working theory: Either we navigated away from the red page before it got a chance to paint at all (so we actually captured the about:blank page from before), or the thumbnail took so long that the slow page managed to render first (seems unlikely).
,
Nov 6 2017
And a log from ExplicitWait:
[ RUN ] ThumbnailTest.ShouldCaptureOnNavigatingAwayExplicitWait
[3380:4584:1106/000046.355:ERROR:gpu_process_transport_factory.cc(1052)] Lost UI shared context.
[3380:4584:1106/000046.720:WARNING:chrome_browser_main_win.cc(613)] Command line too long for RegisterApplicationRestart: --brave-new-test-launcher --cfi-diag=0 --gtest_also_run_disabled_tests --gtest_filter=ThumbnailTest.ShouldCaptureOnNavigatingAwayExplicitWait --single_process --test-launcher-bot-mode --test-launcher-output="C:\Users\CHROME~2\AppData\Local\Temp\scoped_dir1600_1140\results1600_26138\test_results.xml" --test-launcher-summary-output="e:\b\swarm_slave\w\iokf37tv\output.json" --user-data-dir="C:\Users\CHROME~2\AppData\Local\Temp\scoped_dir1600_1140\d1600_30640" --disable-offline-auto-reload --disable-gpu --no-first-run --no-default-browser-check --enable-logging=stderr --safebrowsing-disable-auto-update --disable-default-apps --wm-window-animations-disabled --disable-component-update --test-type=browser --force-color-profile=srgb --disable-zero-browsers-open-for-tests --ipc-connection-timeout=45 --allow-file-access-from-files --dom-automation --log-gpu-control-list-decisions --disable-backgrounding-occluded-windows --override-use-software-gl-for-tests --force-color-profile=srgb --enable-features=CaptureThumbnailOnNavigatingAway --disable-features=NetworkPrediction --flag-switches-begin --flag-switches-end --restore-last-session about:blank
[3380:5604:1106/000046.940:ERROR:service_manager.cc(158)] Connection InterfaceProviderSpec prevented service: content_browser from binding interface: resource_coordinator::mojom::PageSignalGenerator exposed by: resource_coordinator
[3380:3528:1106/000049.694:WARNING:embedded_test_server.cc(228)] Request not handled. Returning 404: /favicon.ico
unknown file: error:
Unexpected mock function call - returning default value.
Function call: SetPageThumbnail(@360FB038 168-byte object <01-00 00-00 00-00 CD-CD 18-D9 E8-2F 10-16 42-36 A8-70 56-36 CD-CD CD-CD CD-CD CD-CD CD-CD CD-CD 22-00 00-00 2F-00 00-00 01-CD CD-CD 00-00 00-00 04-00 00-00 00-00 00-00 FF-FF FF-FF 00-00 00-00 ... FF-FF FF-FF 00-CD CD-CD 00-00 00-00 00-00 00-00 03-00 00-00 34-01 00-00 C0-00 00-00 CD-CD CD-CD 00-00 00-00 00-00 F0-3F 01-01 00-CD CD-CD CD-CD E7-9A D8-22 E2-BB 2E-00 00-00 00-00 CD-CD CD-CD>, @0018BA28 4-byte object <50-8E 49-36>)
Returns: false
Google Mock tried the following 3 expectations, but none matched:
../../chrome/browser/thumbnails/thumbnail_browsertest.cc(192): tried expectation #0: EXPECT_CALL(*thumbnail_service(), SetPageThumbnail(Field(&ThumbnailingContext::url, about_blank_url), _))...
Expected arg #0: is an object whose given field is equal to about:blank
Actual: 168-byte object <01-00 00-00 00-00 CD-CD 18-D9 E8-2F 10-16 42-36 A8-70 56-36 CD-CD CD-CD CD-CD CD-CD CD-CD CD-CD 22-00 00-00 2F-00 00-00 01-CD CD-CD 00-00 00-00 04-00 00-00 00-00 00-00 FF-FF FF-FF 00-00 00-00 ... FF-FF FF-FF 00-CD CD-CD 00-00 00-00 00-00 00-00 03-00 00-00 34-01 00-00 C0-00 00-00 CD-CD CD-CD 00-00 00-00 00-00 F0-3F 01-01 00-CD CD-CD CD-CD E7-9A D8-22 E2-BB 2E-00 00-00 00-00 CD-CD CD-CD>, whose given field is http://127.0.0.1:58624/yellow.html
Expected: to be never called
Actual: never called - saturated and active
../../chrome/browser/thumbnails/thumbnail_browsertest.cc(213): tried expectation #1: EXPECT_CALL(*thumbnail_service(), SetPageThumbnail(Field(&ThumbnailingContext::url, red_url), ImageColorIs(static_cast<SkColor>(0xFFFF0000))))...
Expected arg #0: is an object whose given field is equal to http://127.0.0.1:58624/red.html
Actual: 168-byte object <01-00 00-00 00-00 CD-CD 18-D9 E8-2F 10-16 42-36 A8-70 56-36 CD-CD CD-CD CD-CD CD-CD CD-CD CD-CD 22-00 00-00 2F-00 00-00 01-CD CD-CD 00-00 00-00 04-00 00-00 00-00 00-00 FF-FF FF-FF 00-00 00-00 ... FF-FF FF-FF 00-CD CD-CD 00-00 00-00 00-00 00-00 03-00 00-00 34-01 00-00 C0-00 00-00 CD-CD CD-CD 00-00 00-00 00-00 F0-3F 01-01 00-CD CD-CD CD-CD E7-9A D8-22 E2-BB 2E-00 00-00 00-00 CD-CD CD-CD>, whose given field is http://127.0.0.1:58624/yellow.html
Expected: to be called once
Actual: called once - saturated and active
../../chrome/browser/thumbnails/thumbnail_browsertest.cc(237): tried expectation #2: EXPECT_CALL(*thumbnail_service(), SetPageThumbnail(Field(&ThumbnailingContext::url, yellow_url), ImageColorIs(static_cast<SkColor>(0xFFFFFF00))))...
Expected arg #1: image color is 4294967040
Actual: 4-byte object <50-8E 49-36>, expected color FFFFFF00 but actual color is FFFF0000
Expected: to be called once
Actual: never called - unsatisfied and active
[118/392] ThumbnailTest.ShouldCaptureOnNavigatingAwayExplicitWait (TIMED OUT)
Here we got a red thumbnail instead of a yellow one. This test navigates about:blank -> red -> yellow -> green. So during the yellow->green navigation, we got a red screenshot, which is consistent with the theory that we are navigating away before the page (here the yellow one) had a chance to paint.
,
Nov 6 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/e59dfe517b360d0e321c333475adc5d9e9b1e6e0 commit e59dfe517b360d0e321c333475adc5d9e9b1e6e0 Author: Marc Treib <treib@chromium.org> Date: Mon Nov 06 15:53:48 2017 Thumbnail capturing: Resolve raciness, attempt 2 This CL adds a condition to not take thumbnails if we haven't painted anything since the last navigation start. The theory is that that can happen if we navigate away from a page very quickly (which tends to happen in tests). Bug: 778248 Change-Id: Ied351e5c7df5a196489b023633de07ff7729972e Reviewed-on: https://chromium-review.googlesource.com/754839 Reviewed-by: Mikel Astiz <mastiz@chromium.org> Commit-Queue: Marc Treib <treib@chromium.org> Cr-Commit-Position: refs/heads/master@{#514139} [modify] https://crrev.com/e59dfe517b360d0e321c333475adc5d9e9b1e6e0/chrome/browser/thumbnails/thumbnail_tab_helper.cc [modify] https://crrev.com/e59dfe517b360d0e321c333475adc5d9e9b1e6e0/chrome/browser/thumbnails/thumbnail_tab_helper.h
,
Nov 7 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/ac49b51fb4f4ca963225b364f4f4a3fe6ca210e3 commit ac49b51fb4f4ca963225b364f4f4a3fe6ca210e3 Author: Marc Treib <treib@chromium.org> Date: Tue Nov 07 11:09:09 2017 Thumbnail capturing: Add a test that doesn't block/delay the page load This way, a thumbnail might or might not get captured. But if it does, it must have the correct contents. Bug: 778248 Change-Id: Ic4c89f63976030f16134ce5521baebcac410b684 Reviewed-on: https://chromium-review.googlesource.com/754818 Commit-Queue: Marc Treib <treib@chromium.org> Reviewed-by: Mikel Astiz <mastiz@chromium.org> Cr-Commit-Position: refs/heads/master@{#514445} [modify] https://crrev.com/ac49b51fb4f4ca963225b364f4f4a3fe6ca210e3/chrome/browser/thumbnails/thumbnail_browsertest.cc [add] https://crrev.com/ac49b51fb4f4ca963225b364f4f4a3fe6ca210e3/chrome/test/data/thumbnail_capture/yellow.html
,
Nov 7 2017
Flakiness dashboard: https://test-results.appspot.com/dashboards/flakiness_dashboard.html#tests=ThumbnailTest It looks like the ExplicitWait test is now okay: It times out sometimes when we fail to get a screenshot at all, but it doesn't get wrong screenshots anymore. The timeouts should be fixable by waiting for the "FirstVisuallyNonEmptyPaint" before attempting a screenshot. However, the SlowPageLoad test still sometimes gets wrong screenshots, though less often than before. Logs look like in comment 4.
,
Nov 7 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/3e48b7eab9a6dc7d0a8c41160c2b0b866ceb10f1 commit 3e48b7eab9a6dc7d0a8c41160c2b0b866ceb10f1 Author: Marc Treib <treib@chromium.org> Date: Tue Nov 07 18:12:51 2017 Thumbnail capturing: Add a test for tab switching This is similar to crrev.com/c/754818: Thumbnails might or might not get captured, but if they do, they must have the correct contents. Bug: 778248 Change-Id: Ifa6a77b2cfc7c6f1b4d435b6de7fa184c635dfef Reviewed-on: https://chromium-review.googlesource.com/728419 Commit-Queue: Marc Treib <treib@chromium.org> Reviewed-by: Mikel Astiz <mastiz@chromium.org> Cr-Commit-Position: refs/heads/master@{#514507} [modify] https://crrev.com/3e48b7eab9a6dc7d0a8c41160c2b0b866ceb10f1/chrome/browser/thumbnails/thumbnail_browsertest.cc
,
Nov 8 2017
ShouldContainProperContentIfCapturedOnNavigatingAway is also flaky. The test navigates about:blank -> red -> yellow and expects a screenshot of the red page, but sometimes we get a white screenshot instead of a red one (similar to the SlowPageLoad test). Possible explanations: - The red page never managed to paint before we navigated away again. However, this should be prevented by waiting for DidFirstVisuallyNonEmptyPaint before capturing. - The surface we're copying gets cleared before we manage to copy it (and before the yellow page paints anything). This would be a bug in the paint logic, which isn't entirely implausible (see e.g. bug 21798 ). - The surface gets swapped out for a new one during the navigation. WebContentsObserver::RenderViewHostChanged should tell us about that. Full log output looks like this: [ RUN ] ThumbnailTest.ShouldContainProperContentIfCapturedOnNavigatingAway [5008:1732:1107/215925.105:ERROR:gpu_process_transport_factory.cc(1052)] Lost UI shared context. [5008:1732:1107/215925.145:WARNING:chrome_browser_main_win.cc(613)] Command line too long for RegisterApplicationRestart: --brave-new-test-launcher --cfi-diag=0 --gtest_also_run_disabled_tests --gtest_filter=ThumbnailTest.ShouldContainProperContentIfCapturedOnNavigatingAway --single_process --test-launcher-bot-mode --test-launcher-output="C:\Users\CHROME~2\AppData\Local\Temp\scoped_dir3372_15760\results3372_23839\test_results.xml" --test-launcher-summary-output="e:\b\s\w\iomlkpya\output.json" --user-data-dir="C:\Users\CHROME~2\AppData\Local\Temp\scoped_dir3372_15760\d3372_17559" --disable-offline-auto-reload --disable-gpu --no-first-run --no-default-browser-check --enable-logging=stderr --safebrowsing-disable-auto-update --disable-default-apps --wm-window-animations-disabled --disable-component-update --test-type=browser --force-color-profile=srgb --disable-zero-browsers-open-for-tests --ipc-connection-timeout=30 --allow-file-access-from-files --dom-automation --log-gpu-control-list-decisions --disable-backgrounding-occluded-windows --override-use-software-gl-for-tests --force-color-profile=srgb --enable-features=CaptureThumbnailOnNavigatingAway --disable-features=NetworkPrediction --flag-switches-begin --flag-switches-end --restore-last-session about:blank [5008:5480:1107/215925.151:ERROR:service_manager.cc(158)] Connection InterfaceProviderSpec prevented service: content_browser from binding interface: resource_coordinator::mojom::PageSignalGenerator exposed by: resource_coordinator [5008:1988:1107/215925.601:WARNING:embedded_test_server.cc(228)] Request not handled. Returning 404: /favicon.ico unknown file: error: Unexpected mock function call - returning default value. Function call: SetPageThumbnail(@0000000007FE8020 192-byte object <01-00 00-00 00-00 00-00 50-CA FE-07 00-00 00-00 F0-29 03-08 00-00 00-00 05-00 00-00 00-00 00-00 31-00 00-00 00-00 00-00 3F-00 00-00 00-00 00-00 01-33 5E-46 49-90 3E-EC 00-00 00-00 04-00 00-00 ... 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 03-00 00-00 34-01 00-00 C0-00 00-00 02-00 00-00 00-00 00-00 00-00 F0-3F 01-01 00-00 0F-50 31-F0 10-66 53-AC 08-BC 2E-00 00-00 00-00 00-00 00-00>, @000000000013D258 8-byte object <60-A4 0C-08 00-00 00-00>) Returns: false Google Mock tried the following 2 expectations, but none matched: ../../chrome/browser/thumbnails/thumbnail_browsertest.cc(327): tried expectation #0: EXPECT_CALL(*thumbnail_service(), SetPageThumbnail(Field(&ThumbnailingContext::url, about_blank_url), _))... Expected arg #0: is an object whose given field is equal to about:blank Actual: 192-byte object <01-00 00-00 00-00 00-00 50-CA FE-07 00-00 00-00 F0-29 03-08 00-00 00-00 05-00 00-00 00-00 00-00 31-00 00-00 00-00 00-00 3F-00 00-00 00-00 00-00 01-33 5E-46 49-90 3E-EC 00-00 00-00 04-00 00-00 ... 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 03-00 00-00 34-01 00-00 C0-00 00-00 02-00 00-00 00-00 00-00 00-00 F0-3F 01-01 00-00 0F-50 31-F0 10-66 53-AC 08-BC 2E-00 00-00 00-00 00-00 00-00>, whose given field is http://127.0.0.1:51443/thumbnail_capture/red.html Expected: to be never called Actual: never called - saturated and active ../../chrome/browser/thumbnails/thumbnail_browsertest.cc(338): tried expectation #1: EXPECT_CALL(*thumbnail_service(), SetPageThumbnail(Field(&ThumbnailingContext::url, red_url), ImageColorIs(static_cast<SkColor>(0xFFFF0000))))... Expected arg #1: image color is 4294901760 Actual: 8-byte object <60-A4 0C-08 00-00 00-00>, expected color FFFF0000 but actual color is FFFFFFFF Expected: to be called at most once Actual: never called - satisfied and active [5008:1732:1107/215925.658:INFO:chrome_cryptauth_service.cc(222)] Profile is not authenticated yet; waiting before starting CryptAuth managers. [ FAILED ] ThumbnailTest.ShouldContainProperContentIfCapturedOnNavigatingAway, where TypeParam = and GetParam() = (934 ms)
,
Nov 9 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/529b12fd82bcc73734e8d823d37d8be035d24962 commit 529b12fd82bcc73734e8d823d37d8be035d24962 Author: Marc Treib <treib@chromium.org> Date: Thu Nov 09 16:48:36 2017 Thumbnail capturing: Make sure to watch the correct RenderViewHost ThumbnailTabHelper already watched for RVH created/deleted notifications, but not for RenderViewHostChanged. Bug: 778248 Change-Id: Ic6106c9f810c584163723563c9af801e80faf0fc Reviewed-on: https://chromium-review.googlesource.com/758244 Commit-Queue: Marc Treib <treib@chromium.org> Reviewed-by: Mikel Astiz <mastiz@chromium.org> Cr-Commit-Position: refs/heads/master@{#515181} [modify] https://crrev.com/529b12fd82bcc73734e8d823d37d8be035d24962/chrome/browser/thumbnails/thumbnail_tab_helper.cc [modify] https://crrev.com/529b12fd82bcc73734e8d823d37d8be035d24962/chrome/browser/thumbnails/thumbnail_tab_helper.h
,
Nov 10 2017
ShouldCaptureOnNavigatingAwayExplicitWait often times out on all platforms (and I will disable it for now). In most cases, that's because it didn't get a screenshot at all (which is expected), but occasionally it does get a wrong one: Either white instead of red, or in one instance, red instead of yellow. So it looks like the page we're trying to capture didn't actually paint and so we end up getting a screenshot of the *previous* page, even though we're waiting for DidFirstVisuallyNonEmptyPaint.
,
Nov 10 2017
One more theory to what could be happening: - We navigate to about:blank. The renderer process paints and sends the DidFirstVisuallyNonEmptyPaint message (but it doesn't arrive yet). - The browser process starts the navigation to the red page. - Now the DidFirstVisuallyNonEmptyPaint message arrives and we set has_painted_since_navigation_start_. This is where the mistake happens: We now think the red page has painted, but it actually hasn't. - The browser process starts the navigation to the yellow page, and we start a screenshot. Per the above, we *think* the red page has painted, but we actually capture a screenshot of about:blank instead. (Clearly the same would apply to the red->yellow navigation.) If this is correct, then it should be fixable by tracking whether we painted since DocumentAvailableInMainFrame (instead of since navigation start).
,
Nov 10 2017
I could locally reproduce the situation described above, i.e. DidFirstVisuallyNonEmptyPaint arriving between DidStartNavigation and DocumentAvailableInMainFrame, by adding code to navigate very quickly between pages. This seems to confirm the theory; I'll send a CL shortly.
,
Nov 10 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/da33c66d427ec0df4fc172162d9abb129bb75b64 commit da33c66d427ec0df4fc172162d9abb129bb75b64 Author: Marc Treib <treib@chromium.org> Date: Fri Nov 10 14:06:00 2017 Thumbnail capturing: Disable ExplicitWait test for now It fails (times out) in two ways: - No thumbnail at all. This is a bug in the test: It needs an additional condition to wait for the first paint before attempting to take a thumbnail. - Sometimes it gets a thumbnail with wrong content. This is probably a bug in the real code, but it's covered by other tests. It's flaky enough to be annoying for other developers, and at the moment doesn't really provide value over the other tests. The plan is to fix and re-enable it once the flakiness of the remaining tests is sorted out. Bug: 778248 Change-Id: I0f57cecb2e74c019d3b38d32abc8b2d10e259ff2 Reviewed-on: https://chromium-review.googlesource.com/763507 Reviewed-by: Mikel Astiz <mastiz@chromium.org> Commit-Queue: Marc Treib <treib@chromium.org> Cr-Commit-Position: refs/heads/master@{#515544} [modify] https://crrev.com/da33c66d427ec0df4fc172162d9abb129bb75b64/chrome/browser/thumbnails/thumbnail_browsertest.cc
,
Nov 10 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/a5182dccf3f49471b9761e6018ac9d0977a13ce7 commit a5182dccf3f49471b9761e6018ac9d0977a13ce7 Author: Marc Treib <treib@chromium.org> Date: Fri Nov 10 18:57:17 2017 Thumbnail capturing: Resolve raciness, attempt 3 Before this CL, we already attempted to make sure the page had painted before capturing a thumbnail, by waiting for the DidFirstVisuallyNonEmptyPaint message. However, that message can arrive after the next navigation has already started, in which case we'd wrongly attribute it to the new page. This CL fixes that by ignoring DocumentAvailable and FirstPaint messages during navigations. Bug: 778248 Change-Id: I24027f4bfc5d9f6a63cfadf72d5a60d6e9843096 Reviewed-on: https://chromium-review.googlesource.com/763638 Commit-Queue: Marc Treib <treib@chromium.org> Reviewed-by: Chris Pickel <sfiera@chromium.org> Cr-Commit-Position: refs/heads/master@{#515617} [modify] https://crrev.com/a5182dccf3f49471b9761e6018ac9d0977a13ce7/chrome/browser/thumbnails/thumbnail_tab_helper.cc [modify] https://crrev.com/a5182dccf3f49471b9761e6018ac9d0977a13ce7/chrome/browser/thumbnails/thumbnail_tab_helper.h
,
Nov 13 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/a2e420066973de57222dcdefc73de13c17981189 commit a2e420066973de57222dcdefc73de13c17981189 Author: Marc Treib <treib@chromium.org> Date: Mon Nov 13 14:47:56 2017 Thumbnail capturing: Try to deflake SlowPageLoad test This CL adds an explicit wait after the navigation to the page in question has finished, to give the renderer some time to actually paint it before we attempt to take a screenshot. Bug: 778248 , 784300 Change-Id: I2a0ecd73b6f182a064728d03a380d2ed40fa50f8 Reviewed-on: https://chromium-review.googlesource.com/765828 Commit-Queue: Marc Treib <treib@chromium.org> Reviewed-by: Mikel Astiz <mastiz@chromium.org> Cr-Commit-Position: refs/heads/master@{#515943} [modify] https://crrev.com/a2e420066973de57222dcdefc73de13c17981189/chrome/browser/thumbnails/thumbnail_browsertest.cc
,
Nov 13 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/a2e420066973de57222dcdefc73de13c17981189 commit a2e420066973de57222dcdefc73de13c17981189 Author: Marc Treib <treib@chromium.org> Date: Mon Nov 13 14:47:56 2017 Thumbnail capturing: Try to deflake SlowPageLoad test This CL adds an explicit wait after the navigation to the page in question has finished, to give the renderer some time to actually paint it before we attempt to take a screenshot. Bug: 778248 , 784300 Change-Id: I2a0ecd73b6f182a064728d03a380d2ed40fa50f8 Reviewed-on: https://chromium-review.googlesource.com/765828 Commit-Queue: Marc Treib <treib@chromium.org> Reviewed-by: Mikel Astiz <mastiz@chromium.org> Cr-Commit-Position: refs/heads/master@{#515943} [modify] https://crrev.com/a2e420066973de57222dcdefc73de13c17981189/chrome/browser/thumbnails/thumbnail_browsertest.cc
,
Nov 14 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/c8a275d3b9d4f6c78c1f05d19e00aa29cdab97ae commit c8a275d3b9d4f6c78c1f05d19e00aa29cdab97ae Author: Marc Treib <treib@chromium.org> Date: Tue Nov 14 16:32:01 2017 Thumbnail capturing: Try to deflake and reenable ExplicitWait test This CL introduces a NavigationAndFirstPaintObserver and uses it in place of content::TestNavigationObserver. Bug: 778248 Change-Id: I9c42e384c48a4f5b2b85ca02ed931adf0178e086 Reviewed-on: https://chromium-review.googlesource.com/767388 Commit-Queue: Marc Treib <treib@chromium.org> Reviewed-by: Mikel Astiz <mastiz@chromium.org> Cr-Commit-Position: refs/heads/master@{#516323} [modify] https://crrev.com/c8a275d3b9d4f6c78c1f05d19e00aa29cdab97ae/chrome/browser/thumbnails/thumbnail_browsertest.cc
,
Nov 14 2017
Things look good now! The ExplicitWait test and both ShouldContainProperContent tests seem to be passing consistently. SlowPageLoad has a single flake on Win dbg where it failed to get a screenshot; presumably the 100ms delay before capturing wasn't enough in that case. The important thing is that it didn't get a wrong screenshot. I'll watch for another day or two and then declare this done if there are no further flakes.
,
Nov 17 2017
Update: SlowPageLoad has two more failures on Win dbg where it didn't get a thumbnail at all. I'll increase the sleep time a bit to hopefully resolve that. And ExplicitWait has a single failure, also on Win dbg, where apparently a callback was destructed on the wrong thread? Log output: [ RUN ] ThumbnailTest.ShouldCaptureOnNavigatingAwayExplicitWait [6328:1000:1116/104253.228:ERROR:gpu_process_transport_factory.cc(1010)] Lost UI shared context. [6328:1000:1116/104253.630:WARNING:chrome_browser_main_win.cc(613)] Command line too long for RegisterApplicationRestart: --brave-new-test-launcher --cfi-diag=0 --gtest_also_run_disabled_tests --gtest_filter=ThumbnailTest.ShouldCaptureOnNavigatingAwayExplicitWait --single_process --test-launcher-bot-mode --test-launcher-output="C:\Users\CHROME~2\AppData\Local\Temp\scoped_dir6840_4495\results6840_1762\test_results.xml" --test-launcher-summary-output="e:\b\swarm_slave\w\ioqq5l2j\output.json" --user-data-dir="C:\Users\CHROME~2\AppData\Local\Temp\scoped_dir6840_4495\d6840_5765" --disable-offline-auto-reload --disable-gpu --no-first-run --no-default-browser-check --enable-logging=stderr --safebrowsing-disable-auto-update --disable-default-apps --wm-window-animations-disabled --disable-component-update --test-type=browser --force-color-profile=srgb --disable-zero-browsers-open-for-tests --ipc-connection-timeout=45 --allow-file-access-from-files --dom-automation --log-gpu-control-list-decisions --disable-backgrounding-occluded-windows --override-use-software-gl-for-tests --force-color-profile=srgb --enable-features=CaptureThumbnailOnNavigatingAway,TestFeatureForBrowserTest1 --disable-features=NetworkPrediction,TestFeatureForBrowserTest2 --flag-switches-begin --flag-switches-end --restore-last-session about:blank [6328:6456:1116/104257.081:WARNING:embedded_test_server.cc(228)] Request not handled. Returning 404: /favicon.ico [6784:6388:1116/104257.496:FATAL:Functional.h(228)] Check failed: (sequence_checker_).CalledOnValidSequence(). Backtrace: base::debug::StackTrace::StackTrace [0x100BCEB6+102] base::debug::StackTrace::StackTrace [0x100BBA53+35] logging::LogMessage::~LogMessage [0x10132515+149] WTF::ThreadCheckingCallbackWrapper<base::RepeatingCallback<void __cdecl(enum blink::WebLayerTreeView::SwapResult,double)>,void __cdecl(enum blink::WebLayerTreeView::SwapResult,double)>::~ThreadCheckingCallbackWrapper<base::RepeatingCallback<void __cdecl(e [0x27DEFF08+216] std::default_delete<WTF::ThreadCheckingCallbackWrapper<base::RepeatingCallback<void __cdecl(enum blink::WebLayerTreeView::SwapResult,double)>,void __cdecl(enum blink::WebLayerTreeView::SwapResult,double)> >::operator() [0x27DEFE06+38] std::unique_ptr<WTF::ThreadCheckingCallbackWrapper<base::RepeatingCallback<void __cdecl(enum blink::WebLayerTreeView::SwapResult,double)>,void __cdecl(enum blink::WebLayerTreeView::SwapResult,double)>,std::default_delete<WTF::ThreadCheckingCallbackWrapper [0x27DED56D+61] std::_Tuple_val<std::unique_ptr<WTF::ThreadCheckingCallbackWrapper<base::RepeatingCallback<void __cdecl(enum blink::WebLayerTreeView::SwapResult,double)>,void __cdecl(enum blink::WebLayerTreeView::SwapResult,double)>,std::default_delete<WTF::ThreadCheckin [0x27DEF79F+15] std::tuple<std::unique_ptr<WTF::ThreadCheckingCallbackWrapper<base::RepeatingCallback<void __cdecl(enum blink::WebLayerTreeView::SwapResult,double)>,void __cdecl(enum blink::WebLayerTreeView::SwapResult,double)>,std::default_delete<WTF::ThreadCheckingCall [0x27DEF77F+15] base::internal::BindState<void (__thiscall WTF::ThreadCheckingCallbackWrapper<base::RepeatingCallback<void __cdecl(enum blink::WebLayerTreeView::SwapResult,double)>,void __cdecl(enum blink::WebLayerTreeView::SwapResult,double)>::*)(enum blink::WebLayerTre [0x27DEF74B+27] base::internal::BindState<void (__thiscall WTF::ThreadCheckingCallbackWrapper<base::RepeatingCallback<void __cdecl(enum blink::WebLayerTreeView::SwapResult,double)>,void __cdecl(enum blink::WebLayerTreeView::SwapResult,double)>::*)(enum blink::WebLayerTre [0x27DEF583+35] base::internal::BindStateBaseRefCountTraits::Destruct [0x1004836A+26] base::RefCountedThreadSafe<base::internal::BindStateBase,base::internal::BindStateBaseRefCountTraits>::Release [0x1003ED70+48] scoped_refptr<base::internal::BindStateBase>::Release [0x10048E92+18] scoped_refptr<base::internal::BindStateBase>::~scoped_refptr<base::internal::BindStateBase> [0x10048D05+37] base::internal::CallbackBase::~CallbackBase [0x1004833F+15] base::internal::CallbackBaseCopyable::~CallbackBaseCopyable [0x1003B13F+15] base::RepeatingCallback<void __cdecl(enum blink::WebLayerTreeView::SwapResult,double)>::~RepeatingCallback<void __cdecl(enum blink::WebLayerTreeView::SwapResult,double)> [0x1F1D6D30+16] base::RepeatingCallback<void __cdecl(enum blink::WebLayerTreeView::SwapResult,double)>::RepeatingCallback<void __cdecl(enum blink::WebLayerTreeView::SwapResult,double)> [0x1F1DC850+976] base::RepeatingCallback<void __cdecl(enum blink::WebLayerTreeView::SwapResult,double)>::RepeatingCallback<void __cdecl(enum blink::WebLayerTreeView::SwapResult,double)> [0x1F1DC4F5+117] std::default_delete<cc::SwapPromise>::operator() [0x1534D644+52] std::unique_ptr<cc::SwapPromise,std::default_delete<cc::SwapPromise> >::~unique_ptr<cc::SwapPromise,std::default_delete<cc::SwapPromise> > [0x1534CD9D+61] std::_Default_allocator_traits<std::allocator<std::unique_ptr<cc::SwapPromise,std::default_delete<cc::SwapPromise> > > >::destroy<std::unique_ptr<cc::SwapPromise,std::default_delete<cc::SwapPromise> > > [0x15389DCC+28] std::_Destroy_range1<std::allocator<std::unique_ptr<cc::SwapPromise,std::default_delete<cc::SwapPromise> > > > [0x15389D7E+62] std::_Destroy_range<std::allocator<std::unique_ptr<cc::SwapPromise,std::default_delete<cc::SwapPromise> > > > [0x15389D16+70] std::vector<std::unique_ptr<cc::SwapPromise,std::default_delete<cc::SwapPromise> >,std::allocator<std::unique_ptr<cc::SwapPromise,std::default_delete<cc::SwapPromise> > > >::_Destroy [0x15389BC3+51] std::vector<std::unique_ptr<cc::SwapPromise,std::default_delete<cc::SwapPromise> >,std::allocator<std::unique_ptr<cc::SwapPromise,std::default_delete<cc::SwapPromise> > > >::clear [0x153F7453+67] cc::LayerTreeImpl::ClearSwapPromises [0x15403184+180] cc::LayerTreeHostImpl::DrawLayers [0x153A7324+5636] cc::ProxyImpl::DrawInternal [0x154B28E6+886] cc::ProxyImpl::ScheduledActionDrawIfPossible [0x154B2475+773] cc::Scheduler::DrawIfPossible [0x1521C81C+156] cc::Scheduler::ProcessScheduledActions [0x1521549E+1054] cc::Scheduler::OnBeginImplFrameDeadline [0x15214FCB+395] ??$Invoke@ABV?$WeakPtr@VScheduler@cc@@@base@@$$V@?$FunctorTraits@P8Scheduler@cc@@AEXXZX@internal@base@@SAXP8Scheduler@cc@@AEXXZABV?$WeakPtr@VScheduler@cc@@@2@@Z [0x1521E421+33] ??$MakeItSo@ABQ8Scheduler@cc@@AEXXZABV?$WeakPtr@VScheduler@cc@@@base@@$$V@?$InvokeHelper@$00X@internal@base@@SAXABQ8Scheduler@cc@@AEXXZABV?$WeakPtr@VScheduler@cc@@@2@@Z [0x1521E314+100] base::internal::Invoker<base::internal::BindState<void (__thiscall cc::Scheduler::*)(void),base::WeakPtr<cc::Scheduler> >,void __cdecl(void)>::RunImpl<void (__thiscall cc::Scheduler::*const &)(void),std::tuple<base::WeakPtr<cc::Scheduler> > const &,0> [0x1521E28A+74] base::internal::Invoker<base::internal::BindState<void (__thiscall cc::Scheduler::*)(void),base::WeakPtr<cc::Scheduler> >,void __cdecl(void)>::Run [0x1521E16E+62] base::RepeatingCallback<void __cdecl(void)>::Run [0x15076112+50] ??$ForwardRepeating@$$V@?$CancelableCallbackImpl@V?$RepeatingCallback@$$A6AXXZ@base@@@internal@base@@AAEXXZ [0x15075E3F+15] ??$Invoke@ABV?$WeakPtr@V?$CancelableCallbackImpl@V?$RepeatingCallback@$$A6AXXZ@base@@@internal@base@@@base@@$$V@?$FunctorTraits@P8?$CancelableCallbackImpl@V?$RepeatingCallback@$$A6AXXZ@base@@@internal@base@@AEXXZX@internal@base@@SAXP8?$CancelableCallbackI [0x15076461+33] ??$MakeItSo@ABQ8?$CancelableCallbackImpl@V?$RepeatingCallback@$$A6AXXZ@base@@@internal@base@@AEXXZABV?$WeakPtr@V?$CancelableCallbackImpl@V?$RepeatingCallback@$$A6AXXZ@base@@@internal@base@@@3@$$V@?$InvokeHelper@$00X@internal@base@@SAXABQ8?$CancelableCallb [0x15076354+100] base::internal::Invoker<base::internal::BindState<void (__thiscall base::internal::CancelableCallbackImpl<base::RepeatingCallback<void __cdecl(void)> >::*)(void),base::WeakPtr<base::internal::CancelableCallbackImpl<base::RepeatingCallback<void __cdecl(voi [0x150762CA+74] base::internal::Invoker<base::internal::BindState<void (__thiscall base::internal::CancelableCallbackImpl<base::RepeatingCallback<void __cdecl(void)> >::*)(void),base::WeakPtr<base::internal::CancelableCallbackImpl<base::RepeatingCallback<void __cdecl(voi [0x1507616E+62] base::OnceCallback<void __cdecl(void)>::Run [0x10043C5E+78] base::debug::TaskAnnotator::RunTask [0x100C1905+1013] blink::scheduler::TaskQueueManager::ProcessTaskFromWorkQueue [0x24FEC690+2512] blink::scheduler::TaskQueueManager::DoWork [0x24FE6B0C+1820] base::internal::FunctorTraits<void (__thiscall blink::scheduler::TaskQueueManager::*)(bool),void>::Invoke<base::WeakPtr<blink::scheduler::TaskQueueManager> const &,bool const &> [0x250009C8+88] base::internal::InvokeHelper<1,void>::MakeItSo<void (__thiscall blink::scheduler::TaskQueueManager::*const &)(bool),base::WeakPtr<blink::scheduler::TaskQueueManager> const &,bool const &> [0x25000886+150] base::internal::Invoker<base::internal::BindState<void (__thiscall blink::scheduler::TaskQueueManager::*)(bool),base::WeakPtr<blink::scheduler::TaskQueueManager>,bool>,void __cdecl(void)>::RunImpl<void (__thiscall blink::scheduler::TaskQueueManager::*cons [0x250007BF+111] base::internal::Invoker<base::internal::BindState<void (__thiscall blink::scheduler::TaskQueueManager::*)(bool),base::WeakPtr<blink::scheduler::TaskQueueManager>,bool>,void __cdecl(void)>::Run [0x2500061E+62] base::OnceCallback<void __cdecl(void)>::Run [0x10043C5E+78] base::debug::TaskAnnotator::RunTask [0x100C1905+1013] base::internal::IncomingTaskQueue::RunTask [0x1016D9FD+253] base::MessageLoop::RunTask [0x10178B5D+1005] base::MessageLoop::DeferOrRunPendingTask [0x10179641+81] base::MessageLoop::DoWork [0x10179916+454] base::MessagePumpDefault::Run [0x10184FF8+88] base::MessageLoop::Run [0x1017822F+559] base::RunLoop::Run [0x1026E229+537] base::Thread::Run [0x10363648+424] base::Thread::ThreadMain [0x1036419E+1438] [124/395] ThumbnailTest.ShouldCaptureOnNavigatingAwayExplicitWait (TIMED OUT)
,
Nov 17 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/a001a5d9a77902fb8890a660e6652925387153c5 commit a001a5d9a77902fb8890a660e6652925387153c5 Author: Marc Treib <treib@chromium.org> Date: Fri Nov 17 17:39:47 2017 Thumbnail capturing: Increase sleep time in SlowPageLoad test The test has some flakes on Win dbg, which is likely just a bit too slow. This CL increases the sleep time from 100 to 200 ms to hopefully resolve the flakes. TBRing this single-character test-only change, so it can accumulate some runs over the weekend. TBR=mastiz Bug: 778248 Change-Id: I9c9d0a39023d76ad4bea05aa8f700bd310d4f284 Reviewed-on: https://chromium-review.googlesource.com/776660 Reviewed-by: Marc Treib <treib@chromium.org> Commit-Queue: Marc Treib <treib@chromium.org> Cr-Commit-Position: refs/heads/master@{#517455} [modify] https://crrev.com/a001a5d9a77902fb8890a660e6652925387153c5/chrome/browser/thumbnails/thumbnail_browsertest.cc
,
Nov 20 2017
No more flakes since Friday. Woo! Let's consider this done.
,
Nov 22 2017
(Hopefully) final update here: There's one new "flake" of ShouldContainProperContentIfCapturedOnNavigatingAway on Win7 dbg, where the test actually passed, but leaked the MockThumbnailService object: ../../chrome/browser/thumbnails/thumbnail_browsertest.cc(362): ERROR: this mock object (used in test ThumbnailTest.ShouldContainProperContentIfCapturedOnNavigatingAway) should be deleted but never is. Its address is @08ABD008. ERROR: 1 leaked mock object found at program exit. Looking over the code, my guess is that the test finished while ComputeThumbnailScore (which keeps a reference to the ThumbnailService via ThumbnailingContext) was running on a background thread. So "just" a problem with the test setup. I think the fix is simply to remove the ThumbnailService ref from ThumbnailingContext since it doesn't really seem to be needed.
,
Nov 24 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/bd7d03ca6fb52b09a5acde4b1e7450bf2ad04010 commit bd7d03ca6fb52b09a5acde4b1e7450bf2ad04010 Author: Marc Treib <treib@chromium.org> Date: Fri Nov 24 11:31:23 2017 Thumbnail capturing: Cleanups - Move logic out of ThumbnailingContext and into ThumbnailTabHelper, because the previous split was confusing and actually lead to bugs. - Use WebContentsObserver::RenderViewCreated instead of registering for a notification. - Rename some methods to more clearly reflect what they do. Bug: 778248 Change-Id: I2128a3d0458e167fab207d9e62343cde62eb045e Reviewed-on: https://chromium-review.googlesource.com/785410 Reviewed-by: Mikel Astiz <mastiz@chromium.org> Commit-Queue: Marc Treib <treib@chromium.org> Cr-Commit-Position: refs/heads/master@{#519085} [modify] https://crrev.com/bd7d03ca6fb52b09a5acde4b1e7450bf2ad04010/chrome/browser/thumbnails/thumbnail_tab_helper.cc [modify] https://crrev.com/bd7d03ca6fb52b09a5acde4b1e7450bf2ad04010/chrome/browser/thumbnails/thumbnail_tab_helper.h [modify] https://crrev.com/bd7d03ca6fb52b09a5acde4b1e7450bf2ad04010/chrome/browser/thumbnails/thumbnailing_context.cc [modify] https://crrev.com/bd7d03ca6fb52b09a5acde4b1e7450bf2ad04010/chrome/browser/thumbnails/thumbnailing_context.h |
|||
►
Sign in to add a comment |
|||
Comment 1 by treib@chromium.org
, Oct 25 2017