"TwoClientAutofillSyncTest.ConflictingFields" is flaky |
||||||||||
Issue description"TwoClientAutofillSyncTest.ConflictingFields" is flaky. This issue was created automatically by the chromium-try-flakes app. Please find the right owner to fix the respective test/step and assign this issue to them. If the step/test is infrastructure-related, please add Infra-Troopers label and change issue status to Untriaged. When done, please remove the issue from Sheriff Bug Queue by removing the Sheriff-Chromium label. We have detected 3 recent flakes. List of all flakes can be found at https://chromium-try-flakes.appspot.com/all_flake_occurrences?key=ahVzfmNocm9taXVtLXRyeS1mbGFrZXNyNgsSBUZsYWtlIitUd29DbGllbnRBdXRvZmlsbFN5bmNUZXN0LkNvbmZsaWN0aW5nRmllbGRzDA. Flaky tests should be disabled within 30 minutes unless culprit CL is found and reverted. Please see more details here: https://sites.google.com/a/chromium.org/dev/developers/tree-sheriffs/sheriffing-bug-queues#triaging-auto-filed-flakiness-bugs
,
Mar 21 2017
Detected 3 new flakes for test/step "TwoClientAutofillSyncTest.ConflictingFields". To see the actual flakes, please visit https://chromium-try-flakes.appspot.com/all_flake_occurrences?key=ahVzfmNocm9taXVtLXRyeS1mbGFrZXNyNgsSBUZsYWtlIitUd29DbGllbnRBdXRvZmlsbFN5bmNUZXN0LkNvbmZsaWN0aW5nRmllbGRzDA. This message was posted automatically by the chromium-try-flakes app. Since flakiness is ongoing, the issue was moved back into Sheriff Bug Queue (unless already there).
,
Mar 25 2017
Sync + Autofill test, hoping skym@ can take a look?
,
Mar 25 2017
Looks like this test case has been flaking since 3/14, all on linux_chromium_chromeos_*. I think like this was caused by https://codereview.chromium.org/2738243002 , which turned on the sync integration tests from ChromeOS. Will look into the root cause, but it doesn't look like this was a regression, per say.
,
Mar 27 2017
,
Mar 27 2017
Ran this test locally with target_os = "chromeos" ~600 times and saw one failure that looked like the flakes. Will continue to investigate later in the week.
,
Mar 31 2017
After digging into what was going on, I understand a bit more. TwoClientAutofillSyncTest.ConflictingFields is a little bit special in that there are two clients making concurrent changes. The other TwoClientAutofillSyncTest.* tests either make concurrent changes before calling SetupSync(), or make a change, and then immediately wait for it to show up on the other device. The reason the concurrent changes is nasty, is because of how we wait/expect for model changes to happen. We tell the PersonalDataManager to do something, while we have this observer waiting for events, and when it's notified, we call QuitWhenIdle, and verify we were only notified once. But if that remote change has perfect timing, it can slip in there and cause a second notification. I'm hesitant to relax our mock expectations here. While it is probably always okay to get an extra notification, it isn't okay to see a single unexpected notification and return before the notification you were supposed to be waiting for was fired. I think the right solution here is to setup the tests in such a way that we avoid this race altogether. It would be nice if our testing infrastructure had a way to turn on/off invalidations on demand. This doesn't seem too unreasonable, since we're faking them anyways. Then we could disable invalidations, write to the two clients, and then re-enable them and then let the GetUpdates get called.
,
Apr 3 2017
Tried re-ordering the MakeABookmarkChange() calls, to delay the commits (and thus notifications and thus GU calls and thus ProcessSyncChanges()), but that didn't work since we reduced test nudge delays to ~0 ms. Actually all the MakeABookmarkChange() calls are useless now, removing. Tried adding a way to disable the FakeServerInvalidationService. This didn't work because apparently the original AddProfile() call actually triggers two separate commits. The first of which's invalidation causes a GU which is usually enough to pass the blocking checker, and then we race with that second GU. This can be fixed by switching the test file to use self notifications and AwaitQuiescence first, but the amount of hacking at this point is getting a bit ridiculous. It seems clear that these tests are riddled with foot guns that we've mostly managed to avoid so far, maybe by accident. Instead I investigated how and why autofill_helper blocks for the PersonalDataManager. I don't think expecting a single OnPersonalDataChanged() call really makes the most sense. If we allow races and multiple updates, but just make sure that our reads are at least happening after our local writes, I think it should sufficient.
,
Apr 4 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/fce24c540141bc39ca8aa0b29b4a16debfbdb5d4 commit fce24c540141bc39ca8aa0b29b4a16debfbdb5d4 Author: skym <skym@chromium.org> Date: Tue Apr 04 23:21:37 2017 [Sync] Fix flaky TwoClientAutofillSyncTest.ConflictingFields. Reworked how autofill_helper waits for PersonalDataManager. Expecting a single OnPersonalDataChanged was extremely fragile due to race conditions from remote changes being applied, and removing the possibility for race conditions involved increasing the complexity of test cases significantly. Instead, replaced the single expected call by completely removing waits from modifications, and changing the wait on read to post a task to the DB thread and wait for it to be run. While the PersonalDataManager does sometimes cancel these query tasks, this is safe because we block the UI thread which is where the PersonalDataManager operates. Removed obsolete MakeABookmarkChange method. A while back the nudge handler was changed to schedule commits almost immediately for integration tests, which was essentially what MakeABookmarkChange was trying to achieve. Removed unused SyncTest::notifications_enabled_ field, removed AllProfilesMatch() method, and other minor refactoring changes. BUG= 701814 Review-Url: https://codereview.chromium.org/2791793002 Cr-Commit-Position: refs/heads/master@{#461889} [modify] https://crrev.com/fce24c540141bc39ca8aa0b29b4a16debfbdb5d4/chrome/browser/sync/test/integration/autofill_helper.cc [modify] https://crrev.com/fce24c540141bc39ca8aa0b29b4a16debfbdb5d4/chrome/browser/sync/test/integration/autofill_helper.h [modify] https://crrev.com/fce24c540141bc39ca8aa0b29b4a16debfbdb5d4/chrome/browser/sync/test/integration/performance/autofill_sync_perf_test.cc [modify] https://crrev.com/fce24c540141bc39ca8aa0b29b4a16debfbdb5d4/chrome/browser/sync/test/integration/sync_test.cc [modify] https://crrev.com/fce24c540141bc39ca8aa0b29b4a16debfbdb5d4/chrome/browser/sync/test/integration/sync_test.h [modify] https://crrev.com/fce24c540141bc39ca8aa0b29b4a16debfbdb5d4/chrome/browser/sync/test/integration/two_client_autofill_sync_test.cc
,
Apr 5 2017
,
May 30 2017
,
Aug 1 2017
,
Jan 22 2018
|
||||||||||
►
Sign in to add a comment |
||||||||||
Comment 1 by vasi...@chromium.org
, Mar 17 2017Owner: ma...@chromium.org
Assigning for triaging [ RUN ] TwoClientAutofillSyncTest.ConflictingFields [32246:32246:0317/001318.796202:WARNING:chrome_browser_main_chromeos.cc(371)] Running as stub user with profile dir: test-user [32246:32246:0317/001318.997895:WARNING:audio_manager.cc(295)] Multiple instances of AudioManager detected [32246:32246:0317/001318.997923:WARNING:audio_manager.cc(254)] Multiple instances of AudioManager detected [32246:32246:0317/001319.019711:ERROR:logging_chrome.cc(175)] Unable to create symlink /b/s/w/itja3bE_/.org.chromium.Chromium.nDTU6J/dML9sla/test-user/chrome_debug.log pointing at /b/s/w/itja3bE_/.org.chromium.Chromium.nDTU6J/dML9sla/test-user/chrome_debug_20170317-001319.log: No such file or directory Xlib: extension "RANDR" missing on display ":99". [32246:32246:0317/001319.163752:WARNING:signin_screen_policy_provider.cc(61)] Denying load of Extension : ahfgeienlihckogmohjhadlkjgocpleb / Web Store because of 'signin_screen' is only allowed for packaged apps, but this is a hosted app. [32246:32246:0317/001319.163785:WARNING:signin_screen_policy_provider.cc(61)] Denying load of Extension : eemcgdkfndhakfknompkggombfjjjeno / Bookmark Manager because of 'signin_screen' is only allowed for packaged apps, but this is a extension. [32246:32246:0317/001319.163809:WARNING:signin_screen_policy_provider.cc(61)] Denying load of Extension : mgndgikekgjfcpckkfioiadnlibdjbkf / Chromium because of 'signin_screen' is only allowed for packaged apps, but this is a hosted app. [32246:32246:0317/001319.163832:WARNING:signin_screen_policy_provider.cc(61)] Denying load of Extension : nkoccljplnhpfnfiajclkommnmllphnl / crosh_builtin because of 'signin_screen' is only allowed for packaged apps, but this is a extension. [32246:32307:0317/001319.180759:WARNING:freezer_cgroup_process_manager.cc(61)] Cgroup freezer does not exist or is not writable. Unable to freeze renderer processes. [32246:32246:0317/001319.298161:WARNING:signin_screen_policy_provider.cc(61)] Denying load of Extension : ahfgeienlihckogmohjhadlkjgocpleb / Web Store because of 'signin_screen' is only allowed for packaged apps, but this is a hosted app. [32246:32246:0317/001319.298219:WARNING:signin_screen_policy_provider.cc(61)] Denying load of Extension : eemcgdkfndhakfknompkggombfjjjeno / Bookmark Manager because of 'signin_screen' is only allowed for packaged apps, but this is a extension. [32246:32246:0317/001319.298263:WARNING:signin_screen_policy_provider.cc(61)] Denying load of Extension : mgndgikekgjfcpckkfioiadnlibdjbkf / Chromium because of 'signin_screen' is only allowed for packaged apps, but this is a hosted app. [32246:32246:0317/001319.298312:WARNING:signin_screen_policy_provider.cc(61)] Denying load of Extension : nkoccljplnhpfnfiajclkommnmllphnl / crosh_builtin because of 'signin_screen' is only allowed for packaged apps, but this is a extension. [32246:32466:0317/001319.849203:WARNING:syncer_proto_util.cc(338)] Error posting from syncer: Response Code (bogus on error): -1 Content-Length (bogus on error): -1 Server Status: SYNC_AUTH_ERROR [32246:32466:0317/001319.850426:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Bookmarks [32246:32466:0317/001319.850631:WARNING:sync_encryption_handler_impl.cc(971)] Nigori had empty encryption keybag. [32246:32466:0317/001319.851035:WARNING:sync_encryption_handler_impl.cc(971)] Nigori had empty encryption keybag. [32246:32246:0317/001319.866263:ERROR:chrome_signin_client.cc(179)] Device ID is not set for user. [32246:32466:0317/001319.869080:WARNING:sync_encryption_handler_impl.cc(347)] Ignoring new implicit passphrase. Keystore migration already performed. [32246:32466:0317/001319.898948:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Bookmarks [32246:32316:0317/001319.909159:WARNING:simple_synchronous_entry.cc(1054)] Could not open platform files for entry. [32246:32336:0317/001319.909175:WARNING:simple_synchronous_entry.cc(1054)] Could not open platform files for entry. [32246:32471:0317/001319.953837:WARNING:syncer_proto_util.cc(338)] Error posting from syncer: Response Code (bogus on error): -1 Content-Length (bogus on error): -1 Server Status: SYNC_AUTH_ERROR [32246:32471:0317/001319.954826:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Bookmarks [32246:32471:0317/001319.955119:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Preferences [32246:32471:0317/001319.955129:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Themes [32246:32471:0317/001319.955135:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Search Engines [32246:32471:0317/001319.955140:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Sessions [32246:32471:0317/001319.955145:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Apps [32246:32471:0317/001319.955151:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Device Info [32246:32471:0317/001319.955156:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Priority Preferences [32246:32471:0317/001319.955162:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type App List [32246:32246:0317/001319.963562:ERROR:chrome_signin_client.cc(179)] Device ID is not set for user. [32246:32471:0317/001319.965799:WARNING:sync_encryption_handler_impl.cc(347)] Ignoring new implicit passphrase. Keystore migration already performed. [32246:32471:0317/001320.023925:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Bookmarks [32246:32471:0317/001320.025191:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Preferences [32246:32471:0317/001320.025208:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Themes [32246:32471:0317/001320.025219:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Search Engines [32246:32471:0317/001320.025229:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Sessions [32246:32471:0317/001320.025238:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Apps [32246:32471:0317/001320.025253:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type App List [32246:32471:0317/001320.027238:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Device Info [32246:32471:0317/001320.027256:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Priority Preferences [32246:32336:0317/001320.036823:WARNING:simple_synchronous_entry.cc(1054)] Could not open platform files for entry. ../../chrome/browser/sync/test/integration/autofill_helper.cc:260: Failure Mock function called more times than expected - returning directly. Function call: OnPersonalDataChanged() Expected: to be called once Actual: called twice - over-saturated and active [32246:32246:0317/001320.544674:WARNING:url_request_context_getter.cc(43)] URLRequestContextGetter leaking due to no owning thread. [32246:32246:0317/001320.546974:WARNING:url_request_context_getter.cc(43)] URLRequestContextGetter leaking due to no owning thread. [32246:32246:0317/001320.548594:WARNING:url_request_context_getter.cc(43)] URLRequestContextGetter leaking due to no owning thread. [32246:32246:0317/001320.551244:WARNING:url_request_context_getter.cc(43)] URLRequestContextGetter leaking due to no owning thread. [32246:32246:0317/001320.551266:WARNING:url_request_context_getter.cc(43)] URLRequestContextGetter leaking due to no owning thread. [ FAILED ] TwoClientAutofillSyncTest.ConflictingFields, where TypeParam = and GetParam() = (1814 ms)