Issue metadata
Sign in to add a comment
|
DCHECK(IsListening()) in BreakingNewsGCMAppHandler is causing test failures |
||||||||||||||||||||
Issue descriptionChrome Version: OS: Android What steps will reproduce the problem? (1) Run a CQ Dry Run. What is the expected result? Successfully and consistently have a green build. What happens instead? Flaky test. Example tombstone: tombstone_00 created on 2017-10-18 20:41:00, about this long ago: 0:00:12 Device: 01efd82de9631398 Searching for native crashes in: /b/swarming/w/itmSrE7S/tmpzUPbmj Reading Android symbols from: /b/swarming/w/ir Searching for Chrome symbols from within: /b/swarming/w/ir/out/Release/lib.unstripped:/b/swarming/w/ir/out/Release/lib:/b/swarming/w/ir/out/Release Using toolchain from: /b/swarming/w/ir/third_party/android_tools/ndk/toolchains/aarch64-linux-android-4.9/prebuilt/linux-x86_64/bin/aarch64-linux-android- pid: 16233, tid: 16233, name: rome.sync_shell >>> org.chromium.chrome.sync_shell <<< signal 6 (SIGABRT), code -6 (SI_TKILL), fault addr -------- [FATAL:breaking_news_gcm_app_handler.cc(250)] Check failed: IsListening(). Stack Trace: RELADDR FUNCTION FILE:LINE 000000000129b6a3 media::AliveChecker::AliveChecker(base::RepeatingCallback<void ()>, base::TimeDelta, base::TimeDelta, bool, bool, base::OnceCallback<std::__ndk1::unique_ptr<media::PowerObserverHelper, std::__ndk1::default_delete<media::PowerObserverHelper> > (scoped_refptr<base::SequencedTaskRunner>, base::RepeatingCallback<void ()>, base::RepeatingCallback<void ()>)>)+199 /b/c/b/android_n5x_swarming_rel/src/media/audio/alive_checker.cc:54 00000000043b0423 blink::V0CustomElementProcessingStack::Enqueue(blink::V0CustomElementCallbackQueue*)+67 /b/c/b/android_n5x_swarming_rel/src/third_party/WebKit/Source/core/html/custom/V0CustomElementProcessingStack.cpp:83 00000000043b0dc3 blink::V0CustomElementRegistrationContext::ResolveOrScheduleResolution(blink::Element*, WTF::AtomicString const&)+311 /b/c/b/android_n5x_swarming_rel/src/third_party/WebKit/Source/core/html/custom/V0CustomElementRegistrationContext.cpp:114 000000000197e01f resource_coordinator::mojom::CoordinationUnitProviderProxy::CreateCoordinationUnit(mojo::InterfaceRequest<resource_coordinator::mojom::CoordinationUnit>, resource_coordinator::CoordinationUnitID const&)+427 /b/c/b/android_n5x_swarming_rel/src/out/Release/gen/services/resource_coordinator/public/interfaces/coordination_unit_provider.mojom.cc:67 000000000006a144 tgkill+8 /system/lib64/libc.so 00000000000678d4 pthread_kill+68 /system/lib64/libc.so 0000000000023838 raise+28 /system/lib64/libc.so 000000000001dfd8 abort+60 /system/lib64/libc.so 000000000019457c offset 0x10ea000 /data/app/org.chromium.chrome.sync_shell-1/libchrome.so 00000000001b1a54 offset 0x10ea000 /data/app/org.chromium.chrome.sync_shell-1/libchrome.so 00000000032c6420 offset 0x10ea000 /data/app/org.chromium.chrome.sync_shell-1/libchrome.so 00000000032c6dc0 offset 0x10ea000 /data/app/org.chromium.chrome.sync_shell-1/libchrome.so 000000000089401c offset 0x10ea000 /data/app/org.chromium.chrome.sync_shell-1/libchrome.so 00000000031db6ec offset 0x10ea000 /data/app/org.chromium.chrome.sync_shell-1/libchrome.so 00000000031db5c4 offset 0x10ea000 /data/app/org.chromium.chrome.sync_shell-1/libchrome.so 0000000001c70c88 offset 0xa31000) (void org.chromium.components.gcm_driver.instance_id.InstanceIDBridge.nativeDidGetToken(long, int, java.lang.String)+172 /data/app/org.chromium.chrome.sync_shell.tests-1/oat/arm64/base.odex 0000000001c70038 offset 0xa31000) (void org.chromium.components.gcm_driver.instance_id.InstanceIDBridge.b(org.chromium.components.gcm_driver.instance_id.InstanceIDBridge, long, int, java.lang.String)+92 /data/app/org.chromium.chrome.sync_shell.tests-1/oat/arm64/base.odex 00000000014e4670 offset 0xa31000) (void bbT.a(java.lang.Object)+276 /data/app/org.chromium.chrome.sync_shell.tests-1/oat/arm64/base.odex 00000000014e57d0 offset 0xa31000) (void bbX.onPostExecute(java.lang.Object)+324 /data/app/org.chromium.chrome.sync_shell.tests-1/oat/arm64/base.odex 00000000736e4d24 offset 0x1ed8000 /data/dalvik-cache/arm64/system@framework@boot.oat Full link to flaky tests overview: https://test-results.appspot.com/dashboards/flakiness_dashboard.html#testType=chrome_sync_shell_test_apk&tests=org.chromium.chrome.browser.sync.SyncTest%23testStopAndClear Example failed build: https://ci.chromium.org/buildbot/tryserver.chromium.android/android_n5x_swarming_rel/285445 (click on "result details" under "chrome_sync_shell_test_apk (with patch) on Android" for details. (CCed current Android sheriffs, feel free to un-CC yourselves)
,
Oct 19 2017
disabling the test: https://chromium-review.googlesource.com/c/chromium/src/+/728220
,
Oct 19 2017
details about the crash that might help: signal 6 (SIGABRT), code -6 (SI_TKILL), fault addr -------- [FATAL:breaking_news_gcm_app_handler.cc(250)] Check failed: IsListening(). Stack Trace: RELADDR FUNCTION FILE:LINE 000000000129b6a3 media::AliveChecker::AliveChecker(base::RepeatingCallback<void ()>, base::TimeDelta, base::TimeDelta, bool, bool, base::OnceCallback<std::__ndk1::unique_ptr<media::PowerObserverHelper, std::__ndk1::default_delete<media::PowerObserverHelper> > (scoped_refptr<base::SequencedTaskRunner>, base::RepeatingCallback<void ()>, base::RepeatingCallback<void ()>)>)+199 /b/c/b/android_n5x_swarming_rel/src/media/audio/alive_checker.cc:54 00000000043b0423 blink::V0CustomElementProcessingStack::Enqueue(blink::V0CustomElementCallbackQueue*)+67 /b/c/b/android_n5x_swarming_rel/src/third_party/WebKit/Source/core/html/custom/V0CustomElementProcessingStack.cpp:83 00000000043b0dc3 blink::V0CustomElementRegistrationContext::ResolveOrScheduleResolution(blink::Element*, WTF::AtomicString const&)+311 /b/c/b/android_n5x_swarming_rel/src/third_party/WebKit/Source/core/html/custom/V0CustomElementRegistrationContext.cpp:114 000000000197e01f resource_coordinator::mojom::CoordinationUnitProviderProxy::CreateCoordinationUnit(mojo::InterfaceRequest<resource_coordinator::mojom::CoordinationUnit>, resource_coordinator::CoordinationUnitID const&)+427 /b/c/b/android_n5x_swarming_rel/src/out/Release/gen/services/resource_coordinator/public/interfaces/coordination_unit_provider.mojom.cc:67 000000000006a144 tgkill+8
,
Oct 19 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/8041b888e493e56d808a8f5202b58d22c67b9c9d commit 8041b888e493e56d808a8f5202b58d22c67b9c9d Author: Egor Pasko <pasko@chromium.org> Date: Thu Oct 19 13:54:45 2017 Disable o.c.c.b.sync.SyncTest#testStopAndClear Reason: flaky TBR=zea@chromium.org Bug: 776251 Change-Id: I82c27e2a9586fb9560a03ed9d2f823020c7a55e0 Reviewed-on: https://chromium-review.googlesource.com/728220 Reviewed-by: Egor Pasko <pasko@chromium.org> Commit-Queue: Egor Pasko <pasko@chromium.org> Cr-Commit-Position: refs/heads/master@{#510074} [modify] https://crrev.com/8041b888e493e56d808a8f5202b58d22c67b9c9d/chrome/android/sync_shell/javatests/src/org/chromium/chrome/browser/sync/SyncTest.java
,
Oct 19 2017
vitaliii: I assigned the bug to you, because as you can see in the tombstone in the original bug report the DCHECK that is failing is one you added in https://chromium-review.googlesource.com/c/chromium/src/+/574232
,
Oct 19 2017
Indeed I missed the DCHECK in the log. That's my DCHECK and I will have a look at this.
,
Oct 19 2017
Awesome! Thanks! Adding zea@ back to CC in case he has any input.
,
Jan 12 2018
This DCHECK keeps triggering on HistoryActivityTest#testSupervisedUser: https://test-results.appspot.com/dashboards/flakiness_dashboard.html#testType=chrome_public_test_apk&tests=org.chromium.chrome.browser.history.HistoryActivityTest%23testSupervisedUser. I've checked a bunch of recent crashes in this test and all of them crashed with the same error message: [FATAL:breaking_news_gcm_app_handler.cc(261)] Check failed: IsListening(). I'm going to disable the test for now. Vasilii, please re-enable it after fixing the root cause of these DCHECK failures.
,
Jan 12 2018
Forgot to add link to failed build: https://uberchromegw.corp.google.com/i/chromium.android/builders/Lollipop%20Phone%20Tester/builds/17962
,
Jan 12 2018
Another failed build: https://ci.chromium.org/buildbot/chromium.android/Marshmallow%2064%20bit%20Tester/18703
,
Jan 12 2018
Sample logcat and tombstone of https://uberchromegw.corp.google.com/i/chromium.android/builders/Lollipop%20Phone%20Tester/builds/17962
,
Jan 12 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/47ffcd963bbe2cc63acdd8b09399082a06cdfe01 commit 47ffcd963bbe2cc63acdd8b09399082a06cdfe01 Author: Boris Sazonov <bsazonov@chromium.org> Date: Fri Jan 12 15:00:57 2018 [Android] Disable HistoryActivityTest.testSupervisedUser Reason: flaky Failed builds: https://uberchromegw.corp.google.com/i/chromium.android/builders/Lollipop%20Phone%20Tester/builds/17962 https://ci.chromium.org/buildbot/chromium.android/Marshmallow%2064%20bit%20Tester/18703 TBR=twellington@chromium.org Bug: 776251 Change-Id: I1e7613dbee3524ecd7ea827e52f5e237eb3c3b96 Reviewed-on: https://chromium-review.googlesource.com/864150 Reviewed-by: Boris Sazonov <bsazonov@chromium.org> Commit-Queue: Boris Sazonov <bsazonov@chromium.org> Cr-Commit-Position: refs/heads/master@{#528944} [modify] https://crrev.com/47ffcd963bbe2cc63acdd8b09399082a06cdfe01/chrome/android/javatests/src/org/chromium/chrome/browser/history/HistoryActivityTest.java
,
Jan 12 2018
This is starting to affect multiple unrelated tests. Updating the priority.
,
Jan 12 2018
,
Jan 15 2018
,
Jan 15 2018
I have a highly likely hypothesis based on the tombstone from #11. There I saw that the DCHECK is triggered in ntp_snippets::BreakingNewsGCMAppHandler::ScheduleNextTokenValidation, which is called from ntp_snippets::BreakingNewsGCMAppHandler::DidReceiveTokenForValidation. This means that GCM returned a token after |StopListening|. It is a shame that after the first test disabled I did not know that it is possible to get a tombstone from the bot. Otherwise, I would have figured the issue out much sooner.
,
Jan 15 2018
The CL in progress is https://chromium-review.googlesource.com/c/chromium/src/+/866873.
,
Jan 16 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/874a966938f2288ea7be714cb7274950962d0141 commit 874a966938f2288ea7be714cb7274950962d0141 Author: vitaliii <vitaliii@chromium.org> Date: Tue Jan 16 12:05:47 2018 [NTP::Push] Ignore tokens received after |StopListening|. Previously it was possible that GCM returned a token via the callback after |StopListening| has been called. This could lead to a DCHECK failing. This CL handles this case. Such a callback call is just ignored. Bug: 776251 Change-Id: Idc7c1159af6bbc147097a0df4524ef9b1613c1d9 Reviewed-on: https://chromium-review.googlesource.com/866873 Commit-Queue: vitaliii <vitaliii@chromium.org> Reviewed-by: Marc Treib <treib@chromium.org> Cr-Commit-Position: refs/heads/master@{#529405} [modify] https://crrev.com/874a966938f2288ea7be714cb7274950962d0141/components/ntp_snippets/breaking_news/breaking_news_gcm_app_handler.cc [modify] https://crrev.com/874a966938f2288ea7be714cb7274950962d0141/components/ntp_snippets/breaking_news/breaking_news_gcm_app_handler_unittest.cc
,
Jan 16 2018
I will wait for a couple of days to ensure that the fix does not introduce new issues and then reenable the tests.
,
Jan 18 2018
The NextAction date has arrived: 2018-01-18
,
Jan 18 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/c9f119bcbee97cbad092b430a4a4d27c6920140e commit c9f119bcbee97cbad092b430a4a4d27c6920140e Author: vitaliii <vitaliii@chromium.org> Date: Thu Jan 18 16:42:28 2018 Enable SyncTest#testStopAndClear, HistoryActivityTest#testSupervisedUser This CL re-enables - chromium.chrome.browser.sync.SyncTest#testStopAndClear - chromium.chrome.browser.history.HistoryActivityTest#testSupervisedUser by reverting - 8041b888e493e56d808a8f5202b58d22c67b9c9d https://chromium-review.googlesource.com/c/chromium/src/+/728220 - 47ffcd963bbe2cc63acdd8b09399082a06cdfe01 https://chromium-review.googlesource.com/c/chromium/src/+/864150 where these tests were disabled, because they were flaky. The underlying issue presumably has been fixed in https://chromium-review.googlesource.com/#/c/866873/ (see the bug for details). TBR=zea@chromium.org,twellington@chromium.org Bug: 776251 Change-Id: I5644916dbb311768c9ed6da8a20915c20600ce20 Reviewed-on: https://chromium-review.googlesource.com/873876 Commit-Queue: vitaliii <vitaliii@chromium.org> Reviewed-by: vitaliii <vitaliii@chromium.org> Cr-Commit-Position: refs/heads/master@{#530164} [modify] https://crrev.com/c9f119bcbee97cbad092b430a4a4d27c6920140e/chrome/android/javatests/src/org/chromium/chrome/browser/history/HistoryActivityTest.java [modify] https://crrev.com/c9f119bcbee97cbad092b430a4a4d27c6920140e/chrome/android/sync_shell/javatests/src/org/chromium/chrome/browser/sync/SyncTest.java
,
Jan 24 2018
|
|||||||||||||||||||||
►
Sign in to add a comment |
|||||||||||||||||||||
Comment 1 by vitaliii@chromium.org
, Oct 19 2017Owner: ----
Status: Untriaged (was: Assigned)