TwoClientBookmarksSyncTest.FirstClientEnablesEncryptionWithPassSecondChanges flakey on Win7 |
||||||
Issue descriptionThis has been happening for a long time. 3 failures in the last 200 runs. https://build.chromium.org/p/chromium.win/builders/Win7%20Tests%20%28dbg%29%281%29/builds/52408 https://build.chromium.org/p/chromium.win/builders/Win7%20Tests%20%28dbg%29%281%29/builds/52346 https://build.chromium.org/p/chromium.win/builders/Win7%20Tests%20%28dbg%29%281%29/builds/52305 Output is consistently: [6020:6664:0906/102226:ERROR:bookmarks_helper.cc(372)] Title mismatch: URL Title 3 vs. URL Title 1 [6020:6664:0906/102226:ERROR:bookmarks_helper.cc(410)] Models do not match. [6020:6664:0906/102226:ERROR:bookmarks_helper.cc(782)] Model 1 does not match Model 0. c:\b\c\b\win\src\chrome\browser\sync\test\integration\two_client_bookmarks_sync_test.cc(2023): error: Value of: AllModelsMatch() Actual: false Expected: true [6020:6664:0906/102226:FATAL:bookmark_model.cc(630)] Check failed: false. Backtrace: base::debug::StackTrace::StackTrace [0x1007A737+23] logging::LogMessage::~LogMessage [0x100C7DBB+59] bookmarks::BookmarkModel::AddURLWithCreationTimeAndMetaInfo [0x0340A2CA+186] bookmarks::BookmarkModel::AddURL [0x0340A201+49] bookmarks_helper::AddURL [0x01941FAE+302] bookmarks_helper::AddURL [0x01941E75+37] TwoClientBookmarksSyncTest_FirstClientEnablesEncryptionWithPassSecondChanges_Test::RunTestOnMainThread [0x00547CE4+5876] Looking at the blame logs, the failing test has been around since 2011, and the triggered assert has been around since 2008. Not sure who I should send this over to. Might just MAYBE_ it on Windows.
,
Nov 22 2017
Looks like this is flaking on Mac now too, BrowserTestBase received signal: Terminated: 15. Backtrace: 0 sync_integration_tests 0x000000010ac8054c base::debug::StackTrace::StackTrace(unsigned long) + 28 1 sync_integration_tests 0x000000010f17e1f2 content::(anonymous namespace)::DumpStackTraceSignalHandler(int) + 226 2 libsystem_platform.dylib 0x00007fff90dbef1a _sigtramp + 26 3 sync_integration_tests 0x000000010aca4686 base::internal::IncomingTaskQueue::AddToIncomingQueue(base::Location const&, base::OnceCallback<void ()>, base::TimeDelta, base::Nestable) + 182 4 CoreFoundation 0x00007fff86915eb4 __CFRunLoopServiceMachPort + 212 5 CoreFoundation 0x00007fff8691537b __CFRunLoopRun + 1371 6 CoreFoundation 0x00007fff86914bd8 CFRunLoopRunSpecific + 296 7 HIToolbox 0x00007fff8639a56f RunCurrentEventLoopInMode + 235 8 HIToolbox 0x00007fff8639a2ea ReceiveNextEventCommon + 431 9 HIToolbox 0x00007fff8639a12b _BlockUntilNextEventMatchingListInModeWithFilter + 71 10 AppKit 0x00007fff8a3758ab _DPSNextEvent + 978 11 AppKit 0x00007fff8a374e58 -[NSApplication nextEventMatchingMask:untilDate:inMode:dequeue:] + 346 12 sync_integration_tests 0x000000010af7d120 __71-[BrowserCrApplication nextEventMatchingMask:untilDate:inMode:dequeue:]_block_invoke + 64 13 sync_integration_tests 0x000000010ac9a12a base::mac::CallWithEHFrame(void () block_pointer) + 10 14 sync_integration_tests 0x000000010af7d064 -[BrowserCrApplication nextEventMatchingMask:untilDate:inMode:dequeue:] + 164 15 AppKit 0x00007fff8a36aaf3 -[NSApplication run] + 594 16 sync_integration_tests 0x000000010aca9ba7 base::MessagePumpNSApplication::DoRun(base::MessagePump::Delegate*) + 359 17 sync_integration_tests 0x000000010aca86fe base::MessagePumpCFRunLoopBase::Run(base::MessagePump::Delegate*) + 110 18 sync_integration_tests 0x000000010accc5f4 base::RunLoop::Run() + 52 19 sync_integration_tests 0x000000010aa29d3f StatusChangeChecker::StartBlockingWait() + 223 20 sync_integration_tests 0x000000010aa29c4b StatusChangeChecker::Wait() + 27 21 sync_integration_tests 0x000000010903cf29 TwoClientBookmarksSyncTest_FirstClientEnablesEncryptionWithPassSecondChanges_Test::RunTestOnMainThread() + 4585 22 sync_integration_tests 0x000000010f17df1e content::BrowserTestBase::ProxyRunTestOnMainThreadLoop() + 334 23 sync_integration_tests 0x000000010af81d5a ChromeBrowserMainParts::PreMainMessageLoopRunImpl() + 4090 24 sync_integration_tests 0x000000010af80c5e ChromeBrowserMainParts::PreMainMessageLoopRun() + 62 25 sync_integration_tests 0x000000010980b343 content::BrowserMainLoop::PreMainMessageLoopRun() + 67 26 sync_integration_tests 0x0000000109bc0037 content::StartupTaskRunner::RunAllTasksNow() + 39 27 sync_integration_tests 0x0000000109809997 content::BrowserMainLoop::CreateStartupTasks() + 583 28 sync_integration_tests 0x000000010980e51a content::BrowserMainRunnerImpl::Initialize(content::MainFunctionParams const&) + 618 29 sync_integration_tests 0x00000001098079c4 content::BrowserMain(content::MainFunctionParams const&) + 180 30 sync_integration_tests 0x000000010a9f9fff content::ContentMainRunnerImpl::Run() + 383 31 sync_integration_tests 0x000000010c563a38 service_manager::Main(service_manager::MainParams const&) + 2344 32 sync_integration_tests 0x000000010a9f9504 content::ContentMain(content::ContentMainParams const&) + 68 33 sync_integration_tests 0x000000010f17dbed content::BrowserTestBase::SetUp() + 2285 34 sync_integration_tests 0x000000010aa3d798 InProcessBrowserTest::SetUp() + 392 35 sync_integration_tests 0x000000010aa2f896 SyncTest::SetUp() + 758 36 sync_integration_tests 0x000000010908a6c1 testing::Test::Run() + 97 37 sync_integration_tests 0x000000010908af30 testing::TestInfo::Run() + 288 38 sync_integration_tests 0x000000010908b497 testing::TestCase::Run() + 263 39 sync_integration_tests 0x00000001090915e7 testing::internal::UnitTestImpl::RunAllTests() + 871 40 sync_integration_tests 0x0000000109091253 testing::UnitTest::Run() + 163 41 sync_integration_tests 0x000000010ac6b1c7 base::TestSuite::Run() + 167 42 sync_integration_tests 0x000000010aa3bdd5 ChromeTestSuiteRunner::RunTestSuite(int, char**) + 37 43 sync_integration_tests 0x000000010f181983 content::LaunchTests(content::TestLauncherDelegate*, unsigned long, int, char**) + 387 44 sync_integration_tests 0x000000010aa3c1e7 LaunchChromeTests(unsigned long, content::TestLauncherDelegate*, int, char**) + 135 45 sync_integration_tests 0x000000010aa0c81e main + 94 46 libdyld.dylib 0x00007fff87a3e5c9 start + 1
,
Nov 22 2017
,
Nov 22 2017
Unable to repro on my mac. Unclear if https://chromium-review.googlesource.com/c/chromium/src/+/784790 is related to this, but also dealing with timing in the same class. Planning on waiting for that to land, and then see if the flakes continue or not.
,
Dec 7 2017
Doesn't look like things fixed themselves after the CL I linked landed, still seeing flakes as of today. In addition to the stack trace, this is the log before we hang for 30 seconds and fail [ RUN ] TwoClientBookmarksSyncTest.FirstClientEnablesEncryptionWithPassSecondChanges [94230:771:1207/104301.593608:29724380450560:WARNING:loopback_server.cc(638)] Loopback sync persistent state file does not exist. [94230:5123:1207/104301.722772:WARNING:notification_platform_bridge_mac.mm(535)] AlertNotificationService: XPC connection invalidated. [94230:116739:1207/104302.946248: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 [94230:116739:1207/104302.947232:WARNING:sync_encryption_handler_impl.cc(970)] Nigori had empty encryption keybag. [94230:116739:1207/104302.947554:WARNING:sync_encryption_handler_impl.cc(970)] Nigori had empty encryption keybag. [94230:116739:1207/104302.952719:WARNING:sync_encryption_handler_impl.cc(346)] Ignoring new implicit passphrase. Keystore migration already performed. [94230:120579:1207/104303.023889: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 [94230:120579:1207/104303.030057:WARNING:sync_encryption_handler_impl.cc(346)] Ignoring new implicit passphrase. Keystore migration already performed. [94230:771:1207/104303.442765:ERROR:bookmarks_helper.cc(384)] Cannot compare folder with bookmark [94230:771:1207/104303.442822:ERROR:bookmarks_helper.cc(426)] Models do not match. [94230:771:1207/104303.442851:ERROR:bookmarks_helper.cc(821)] Model 1 does not match the verifier. [94230:771:1207/104303.454957:ERROR:bookmarks_helper.cc(384)] Cannot compare folder with bookmark [94230:771:1207/104303.455004:ERROR:bookmarks_helper.cc(426)] Models do not match. [94230:771:1207/104303.455029:ERROR:bookmarks_helper.cc(821)] Model 1 does not match the verifier. [94230:771:1207/104303.458923:ERROR:bookmarks_helper.cc(384)] Cannot compare folder with bookmark [94230:771:1207/104303.458952:ERROR:bookmarks_helper.cc(426)] Models do not match. [94230:771:1207/104303.458965:ERROR:bookmarks_helper.cc(821)] Model 1 does not match the verifier. [94230:771:1207/104304.212258:ERROR:data_type_manager_impl.cc(36)] Bookmarks cryptographer error was encountered: [94230:771:1207/104304.212292:ERROR:data_type_manager_impl.cc(36)] Preferences cryptographer error was encountered: [94230:771:1207/104304.212306:ERROR:data_type_manager_impl.cc(36)] Passwords cryptographer error was encountered: [94230:771:1207/104304.212318:ERROR:data_type_manager_impl.cc(36)] Autofill Profiles cryptographer error was encountered: [94230:771:1207/104304.212330:ERROR:data_type_manager_impl.cc(36)] Autofill cryptographer error was encountered: [94230:771:1207/104304.212341:ERROR:data_type_manager_impl.cc(36)] Autofill Wallet Metadata cryptographer error was encountered: [94230:771:1207/104304.212353:ERROR:data_type_manager_impl.cc(36)] Themes cryptographer error was encountered: [94230:771:1207/104304.212365:ERROR:data_type_manager_impl.cc(36)] Typed URLs cryptographer error was encountered: [94230:771:1207/104304.212377:ERROR:data_type_manager_impl.cc(36)] Extensions cryptographer error was encountered: [94230:771:1207/104304.212389:ERROR:data_type_manager_impl.cc(36)] Search Engines cryptographer error was encountered: [94230:771:1207/104304.212401:ERROR:data_type_manager_impl.cc(36)] Sessions cryptographer error was encountered: [94230:771:1207/104304.212413:ERROR:data_type_manager_impl.cc(36)] Apps cryptographer error was encountered: [94230:771:1207/104304.212424:ERROR:data_type_manager_impl.cc(36)] App settings cryptographer error was encountered: [94230:771:1207/104304.212436:ERROR:data_type_manager_impl.cc(36)] Extension settings cryptographer error was encountered: [94230:771:1207/104304.212448:ERROR:data_type_manager_impl.cc(36)] Favicon Images cryptographer error was encountered: [94230:771:1207/104304.212473:ERROR:data_type_manager_impl.cc(36)] Favicon Tracking cryptographer error was encountered: [94230:771:1207/104304.221012:ERROR:bookmarks_helper.cc(388)] Title mismatch: URL Title 3 vs. URL Title 1 [94230:771:1207/104304.221056:ERROR:bookmarks_helper.cc(426)] Models do not match. [94230:771:1207/104304.221070:ERROR:bookmarks_helper.cc(821)] Model 1 does not match the verifier. [94230:771:1207/104304.221085:ERROR:bookmarks_helper.cc(388)] Title mismatch: URL Title 3 vs. URL Title 1 [94230:771:1207/104304.221099:ERROR:bookmarks_helper.cc(426)] Models do not match. [94230:771:1207/104304.221110:ERROR:bookmarks_helper.cc(841)] Model 1 does not match Model 0. [94230:771:1207/104304.223146:ERROR:bookmarks_helper.cc(388)] Title mismatch: URL Title 3 vs. URL Title 1 [94230:771:1207/104304.223173:ERROR:bookmarks_helper.cc(426)] Models do not match. [94230:771:1207/104304.223187:ERROR:bookmarks_helper.cc(841)] Model 1 does not match Model 0. [94230:771:1207/104304.229922:ERROR:bookmarks_helper.cc(388)] Title mismatch: URL Title 3 vs. URL Title 1 [94230:771:1207/104304.229956:ERROR:bookmarks_helper.cc(426)] Models do not match. [94230:771:1207/104304.229969:ERROR:bookmarks_helper.cc(841)] Model 1 does not match Model 0. [94230:771:1207/104304.231443:ERROR:bookmarks_helper.cc(388)] Title mismatch: URL Title 3 vs. URL Title 1 [94230:771:1207/104304.231472:ERROR:bookmarks_helper.cc(426)] Models do not match. [94230:771:1207/104304.231487:ERROR:bookmarks_helper.cc(841)] Model 1 does not match Model 0. [94230:771:1207/104304.231913:ERROR:bookmark_model_associator.cc(979)] Bookmarks persistence error was encountered: Native version (2) does not match sync version (1) [94230:771:1207/104304.236636:ERROR:bookmarks_helper.cc(388)] Title mismatch: URL Title 3 vs. URL Title 1 [94230:771:1207/104304.236670:ERROR:bookmarks_helper.cc(426)] Models do not match. [94230:771:1207/104304.236684:ERROR:bookmarks_helper.cc(841)] Model 1 does not match Model 0. [94230:771:1207/104304.237399:ERROR:bookmarks_helper.cc(388)] Title mismatch: URL Title 3 vs. URL Title 1 [94230:771:1207/104304.237426:ERROR:bookmarks_helper.cc(426)] Models do not match. [94230:771:1207/104304.237440:ERROR:bookmarks_helper.cc(841)] Model 1 does not match Model 0. [94230:771:1207/104304.238073:ERROR:bookmarks_helper.cc(388)] Title mismatch: URL Title 3 vs. URL Title 1 [94230:771:1207/104304.238117:ERROR:bookmarks_helper.cc(426)] Models do not match. [94230:771:1207/104304.238148:ERROR:bookmarks_helper.cc(841)] Model 1 does not match Model 0. [94230:771:1207/104304.241625:ERROR:bookmarks_helper.cc(388)] Title mismatch: URL Title 3 vs. URL Title 1 [94230:771:1207/104304.241659:ERROR:bookmarks_helper.cc(426)] Models do not match. [94230:771:1207/104304.241673:ERROR:bookmarks_helper.cc(841)] Model 1 does not match Model 0. So, it's possible that we are not being correctly notified of a change and reacting, but given the log, that seems unlikely. Rather I'm guessing the models do truly not match. And that bookmark_model_associator.cc seems suspicious. Especially since no one has shutdown/crashed, an inconsistency shouldn't be possible.
,
Dec 7 2017
I take it back, on Linux a successful run seems to have that error message. Confusing, concerning, but likely not the reason this is flaking on Mac. [142650:142650:1207/111032.898602:1990119083668:WARNING:loopback_server.cc(638)] Loopback sync persistent state file does not exist. [142650:142650:1207/111033.949064:WARNING:password_store_factory.cc(241)] Using basic (unencrypted) store for password storage. See https://chromium.googlesource.com/chromium/src/+/master/docs/linux_password_storage.md for more information about password storage options. [142650:142650:1207/111035.313174:WARNING:password_store_factory.cc(241)] Using basic (unencrypted) store for password storage. See https://chromium.googlesource.com/chromium/src/+/master/docs/linux_password_storage.md for more information about password storage options. [142650:142650:1207/111035.604913:WARNING:password_store_factory.cc(241)] Using basic (unencrypted) store for password storage. See https://chromium.googlesource.com/chromium/src/+/master/docs/linux_password_storage.md for more information about password storage options. [142650:142650:1207/111035.849615:WARNING:password_store_factory.cc(241)] Using basic (unencrypted) store for password storage. See https://chromium.googlesource.com/chromium/src/+/master/docs/linux_password_storage.md for more information about password storage options. [142710:142710:1207/111036.047700:WARNING:gpu_info.cc(104)] No active GPU found, returning primary GPU. [142650:142734:1207/111036.164229: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 [142650:142734:1207/111036.252937:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Bookmarks [142650:142734:1207/111036.253721:WARNING:sync_encryption_handler_impl.cc(970)] Nigori had empty encryption keybag. [142650:142734:1207/111036.255362:WARNING:sync_encryption_handler_impl.cc(970)] Nigori had empty encryption keybag. [142650:142734:1207/111036.304792:WARNING:sync_encryption_handler_impl.cc(346)] Ignoring new implicit passphrase. Keystore migration already performed. [142650:142734:1207/111036.354639:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Bookmarks [142650:142673:1207/111036.381753:WARNING:simple_synchronous_entry.cc(1170)] Could not open platform files for entry. [142650:142670:1207/111036.389211:WARNING:simple_synchronous_entry.cc(1170)] Could not open platform files for entry. [142650:142744:1207/111036.571336: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 [142650:142744:1207/111036.579103:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Bookmarks [142650:142744:1207/111036.579195:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Preferences [142650:142744:1207/111036.579294:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Themes [142650:142744:1207/111036.579404:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Search Engines [142650:142744:1207/111036.579520:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Sessions [142650:142744:1207/111036.579643:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Apps [142650:142744:1207/111036.579925:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Device Info [142650:142744:1207/111036.616754:WARNING:sync_encryption_handler_impl.cc(346)] Ignoring new implicit passphrase. Keystore migration already performed. [142650:142744:1207/111036.624389:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Bookmarks [142650:142744:1207/111036.624467:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Preferences [142650:142744:1207/111036.624594:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Themes [142650:142744:1207/111036.624722:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Search Engines [142650:142744:1207/111036.624848:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Sessions [142650:142744:1207/111036.624977:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Apps [142650:142744:1207/111036.635713:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Device Info [142650:142670:1207/111036.675200:WARNING:simple_synchronous_entry.cc(1170)] Could not open platform files for entry. [142650:142650:1207/111037.077537:ERROR:bookmarks_helper.cc(384)] Cannot compare folder with bookmark [142650:142650:1207/111037.077609:ERROR:bookmarks_helper.cc(426)] Models do not match. [142650:142650:1207/111037.077659:ERROR:bookmarks_helper.cc(821)] Model 1 does not match the verifier. [142650:142650:1207/111037.126602:ERROR:bookmarks_helper.cc(384)] Cannot compare folder with bookmark [142650:142650:1207/111037.126696:ERROR:bookmarks_helper.cc(426)] Models do not match. [142650:142650:1207/111037.126753:ERROR:bookmarks_helper.cc(821)] Model 1 does not match the verifier. [142650:142650:1207/111037.174785:ERROR:bookmarks_helper.cc(384)] Cannot compare folder with bookmark [142650:142650:1207/111037.174894:ERROR:bookmarks_helper.cc(426)] Models do not match. [142650:142650:1207/111037.175028:ERROR:bookmarks_helper.cc(821)] Model 1 does not match the verifier. [142650:142650:1207/111037.772840:ERROR:data_type_manager_impl.cc(36)] Bookmarks cryptographer error was encountered: [142650:142650:1207/111037.772917:ERROR:data_type_manager_impl.cc(36)] Preferences cryptographer error was encountered: [142650:142650:1207/111037.772968:ERROR:data_type_manager_impl.cc(36)] Passwords cryptographer error was encountered: [142650:142650:1207/111037.773015:ERROR:data_type_manager_impl.cc(36)] Autofill Profiles cryptographer error was encountered: [142650:142650:1207/111037.773064:ERROR:data_type_manager_impl.cc(36)] Autofill cryptographer error was encountered: [142650:142650:1207/111037.773111:ERROR:data_type_manager_impl.cc(36)] Autofill Wallet Metadata cryptographer error was encountered: [142650:142650:1207/111037.773159:ERROR:data_type_manager_impl.cc(36)] Themes cryptographer error was encountered: [142650:142650:1207/111037.773203:ERROR:data_type_manager_impl.cc(36)] Typed URLs cryptographer error was encountered: [142650:142650:1207/111037.773250:ERROR:data_type_manager_impl.cc(36)] Extensions cryptographer error was encountered: [142650:142650:1207/111037.773302:ERROR:data_type_manager_impl.cc(36)] Search Engines cryptographer error was encountered: [142650:142650:1207/111037.773351:ERROR:data_type_manager_impl.cc(36)] Sessions cryptographer error was encountered: [142650:142650:1207/111037.773395:ERROR:data_type_manager_impl.cc(36)] Apps cryptographer error was encountered: [142650:142650:1207/111037.773443:ERROR:data_type_manager_impl.cc(36)] App settings cryptographer error was encountered: [142650:142650:1207/111037.773491:ERROR:data_type_manager_impl.cc(36)] Extension settings cryptographer error was encountered: [142650:142650:1207/111037.773539:ERROR:data_type_manager_impl.cc(36)] Dictionary cryptographer error was encountered: [142650:142650:1207/111037.773586:ERROR:data_type_manager_impl.cc(36)] Favicon Images cryptographer error was encountered: [142650:142650:1207/111037.773633:ERROR:data_type_manager_impl.cc(36)] Favicon Tracking cryptographer error was encountered: [142650:142650:1207/111037.802818:ERROR:bookmarks_helper.cc(388)] Title mismatch: URL Title 3 vs. URL Title 1 [142650:142650:1207/111037.802879:ERROR:bookmarks_helper.cc(426)] Models do not match. [142650:142650:1207/111037.802911:ERROR:bookmarks_helper.cc(821)] Model 1 does not match the verifier. [142650:142650:1207/111037.802971:ERROR:bookmarks_helper.cc(388)] Title mismatch: URL Title 3 vs. URL Title 1 [142650:142650:1207/111037.803012:ERROR:bookmarks_helper.cc(426)] Models do not match. [142650:142650:1207/111037.803041:ERROR:bookmarks_helper.cc(841)] Model 1 does not match Model 0. [142650:142650:1207/111037.813310:ERROR:bookmarks_helper.cc(388)] Title mismatch: URL Title 3 vs. URL Title 1 [142650:142650:1207/111037.813349:ERROR:bookmarks_helper.cc(426)] Models do not match. [142650:142650:1207/111037.813371:ERROR:bookmarks_helper.cc(841)] Model 1 does not match Model 0. [142650:142650:1207/111037.819743:ERROR:bookmarks_helper.cc(388)] Title mismatch: URL Title 3 vs. URL Title 1 [142650:142650:1207/111037.819785:ERROR:bookmarks_helper.cc(426)] Models do not match. [142650:142650:1207/111037.819808:ERROR:bookmarks_helper.cc(841)] Model 1 does not match Model 0. [142650:142744:1207/111037.825790:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Device Info [142650:142650:1207/111037.830030:ERROR:bookmarks_helper.cc(388)] Title mismatch: URL Title 3 vs. URL Title 1 [142650:142650:1207/111037.830082:ERROR:bookmarks_helper.cc(426)] Models do not match. [142650:142650:1207/111037.830111:ERROR:bookmarks_helper.cc(841)] Model 1 does not match Model 0. [142650:142650:1207/111037.831073:ERROR:bookmark_model_associator.cc(979)] Bookmarks persistence error was encountered: Native version (2) does not match sync version (1) [142650:142744:1207/111037.884804:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Preferences [142650:142744:1207/111037.884875:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Themes [142650:142744:1207/111037.884928:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Search Engines [142650:142744:1207/111037.884987:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Sessions [142650:142744:1207/111037.885042:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Apps [142650:142744:1207/111037.885128:WARNING:get_updates_processor.cc(103)] Skipping unexpected progress marker for non-enabled type Device Info [142650:142650:1207/111037.886838:ERROR:bookmarks_helper.cc(388)] Title mismatch: URL Title 3 vs. URL Title 1 [142650:142650:1207/111037.886924:ERROR:bookmarks_helper.cc(426)] Models do not match. [142650:142650:1207/111037.887018:ERROR:bookmarks_helper.cc(841)] Model 1 does not match Model 0. [142650:142650:1207/111037.889344:ERROR:bookmarks_helper.cc(388)] Title mismatch: URL Title 3 vs. URL Title 1 [142650:142650:1207/111037.889450:ERROR:bookmarks_helper.cc(426)] Models do not match. [142650:142650:1207/111037.889519:ERROR:bookmarks_helper.cc(841)] Model 1 does not match Model 0. [142650:142650:1207/111037.899161:ERROR:bookmarks_helper.cc(384)] Cannot compare folder with bookmark [142650:142650:1207/111037.899228:ERROR:bookmarks_helper.cc(841)] Model 1 does not match Model 0. [142650:142650:1207/111037.936251:ERROR:bookmarks_helper.cc(384)] Cannot compare folder with bookmark [142650:142650:1207/111037.936328:ERROR:bookmarks_helper.cc(841)] Model 1 does not match Model 0. [142650:142650:1207/111037.968939:ERROR:bookmarks_helper.cc(384)] Cannot compare folder with bookmark [142650:142650:1207/111037.969039:ERROR:bookmarks_helper.cc(841)] Model 1 does not match Model 0. [142650:142650:1207/111038.009572:ERROR:bookmarks_helper.cc(384)] Cannot compare folder with bookmark [142650:142650:1207/111038.009633:ERROR:bookmarks_helper.cc(841)] Model 1 does not match Model 0. [142650:142650:1207/111038.450135:INFO:chrome_cryptauth_service.cc(233)] Profile is not authenticated yet; waiting before starting CryptAuth managers. [142650:142650:1207/111038.484856:INFO:chrome_cryptauth_service.cc(233)] Profile is not authenticated yet; waiting before starting CryptAuth managers. [142650:142650:1207/111038.518287:INFO:sync_scheduler_impl.cc(133)] Scheduling next sync for CryptAuth Enrollment: Strategy: Aggressive Recovery Time Delta: 0 seconds Previous Failures: 1 [142650:142650:1207/111038.608687:INFO:sync_scheduler_impl.cc(133)] Scheduling next sync for CryptAuth Enrollment: Strategy: Aggressive Recovery Time Delta: 0 seconds Previous Failures: 1 [142650:142650:1207/111038.755875:WARNING:url_request_context_getter.cc(43)] URLRequestContextGetter leaking due to no owning thread. [142650:142650:1207/111038.755944:WARNING:url_request_context_getter.cc(43)] URLRequestContextGetter leaking due to no owning thread. [142650:142650:1207/111038.756011:WARNING:url_request_context_getter.cc(43)] URLRequestContextGetter leaking due to no owning thread. [142650:142650:1207/111038.756075:WARNING:url_request_context_getter.cc(43)] URLRequestContextGetter leaking due to no owning thread. [ OK ] TwoClientBookmarksSyncTest.FirstClientEnablesEncryptionWithPassSecondChanges (5866 ms)
,
Dec 7 2017
Comparing the failure reasons from bookmarks_helper.cc, at some point it switches from title mismatch to folder/non-folder. This indicates we've changed checkers, it is the first BookmarksMatchChecker().Wait() that encounters the title issue, and the second BookmarksMatchChecker().Wait() that encounters the folder issue. This means the mac failure never make it past the first BookmarksMatchChecker, although they check against it more times. On successful runs, we get past the checker as we finish model association. This is where I start to run into problems not having a repro, because I don't know if failure run performs association, or not, or if it succeeded even. Maybe this is a dead end, we could add more logging. #0 0x7f5392d03e1d base::debug::StackTrace::StackTrace() #1 0x7f5392d0224c base::debug::StackTrace::StackTrace() #2 0x0000030a9ace BookmarksMatchChecker::IsExitConditionSatisfied() #3 0x0000030e64d0 StatusChangeChecker::CheckExitCondition() #4 0x0000030c299c MultiClientStatusChangeChecker::OnStateChanged() #5 0x0000064e34d6 syncer::SyncServiceBase::NotifyObservers() #6 0x0000064d109f browser_sync::ProfileSyncService::OnConfigureDone() #7 0x000006480dab syncer::DataTypeManagerImpl::NotifyDone() #8 0x0000064833cd syncer::DataTypeManagerImpl::OnModelAssociationDone() #9 0x00000648b73d syncer::ModelAssociationManager::ModelAssociationDone() #10 0x00000648c199 syncer::ModelAssociationManager::TypeStartCallback() #11 0x00000648d494 _ZN4base8internal13FunctorTraitsIMN6syncer23ModelAssociationManagerEFvNS2_9ModelTypeENS_9TimeTicksENS2_18DataTypeController15ConfigureResultERKNS2_15SyncMergeResultESA_EvE6InvokeIRKNS_7WeakPtrIS3_EEJRKS4_RKS5_S7_SA_SA_EEEvSC_OT_DpOT0_ #12 0x00000648d37c _ZN4base8internal12InvokeHelperILb1EvE8MakeItSoIRKMN6syncer23ModelAssociationManagerEFvNS4_9ModelTypeENS_9TimeTicksENS4_18DataTypeController15ConfigureResultERKNS4_15SyncMergeResultESC_ERKNS_7WeakPtrIS5_EEJRKS6_RKS7_S9_SC_SC_EEEvOT_OT0_DpOT1_ #13 0x00000648d293 _ZN4base8internal7InvokerINS0_9BindStateIMN6syncer23ModelAssociationManagerEFvNS3_9ModelTypeENS_9TimeTicksENS3_18DataTypeController15ConfigureResultERKNS3_15SyncMergeResultESB_EJNS_7WeakPtrIS4_EES5_S6_EEEFvS8_SB_SB_EE7RunImplIRKSD_RKNSt3__15tupleIJSF_S5_S6_EEEJLm0ELm1ELm2EEEEvOT_OT0_NSM_16integer_sequenceImJXspT1_EEEEOS8_SB_SB_ #14 0x00000648d109 _ZN4base8internal7InvokerINS0_9BindStateIMN6syncer23ModelAssociationManagerEFvNS3_9ModelTypeENS_9TimeTicksENS3_18DataTypeController15ConfigureResultERKNS3_15SyncMergeResultESB_EJNS_7WeakPtrIS4_EES5_S6_EEEFvS8_SB_SB_EE3RunEPNS0_13BindStateBaseES8_SB_SB_ #15 0x000003b9b411 _ZNKR4base17RepeatingCallbackIFvN6syncer18DataTypeController15ConfigureResultERKNS1_15SyncMergeResultES6_EE3RunES3_S6_S6_ #16 0x0000068054cd syncer::FrontendDataTypeController::StartDone() #17 0x0000068051f3 syncer::FrontendDataTypeController::Associate() #18 0x00000184278f _ZN4base8internal13FunctorTraitsIMN11google_apis19UrlFetchRequestBaseEFvvEvE6InvokeIRKNS_7WeakPtrINS2_5drive30SingleBatchableDelegateRequestEEEJEEEvS5_OT_DpOT0_ #19 0x00000184270a _ZN4base8internal12InvokeHelperILb1EvE8MakeItSoIRKMN11google_apis19UrlFetchRequestBaseEFvvERKNS_7WeakPtrINS4_5drive30SingleBatchableDelegateRequestEEEJEEEvOT_OT0_DpOT1_ #20 0x0000018426a0 _ZN4base8internal7InvokerINS0_9BindStateIMN11google_apis19UrlFetchRequestBaseEFvvEJNS_7WeakPtrINS3_5drive30SingleBatchableDelegateRequestEEEEEEFvvEE7RunImplIRKS6_RKNSt3__15tupleIJSA_EEEJLm0EEEEvOT_OT0_NSH_16integer_sequenceImJXspT1_EEEE #21 0x0000018425ec _ZN4base8internal7InvokerINS0_9BindStateIMN11google_apis19UrlFetchRequestBaseEFvvEJNS_7WeakPtrINS3_5drive30SingleBatchableDelegateRequestEEEEEEFvvEE3RunEPNS0_13BindStateBaseE #22 0x7f5392cae071 _ZNO4base12OnceCallbackIFvvEE3RunEv #23 0x7f5392d0860a base::debug::TaskAnnotator::RunTask() #24 0x7f5392da6425 base::internal::IncomingTaskQueue::RunTask() #25 0x7f5392daf3da base::MessageLoop::RunTask() #26 0x7f5392daf678 base::MessageLoop::DeferOrRunPendingTask() #27 0x7f5392daf9c0 base::MessageLoop::DoWork() #28 0x7f5392db30ac base::MessagePumpGlib::HandleDispatch() #29 0x7f5392db3851 base::(anonymous namespace)::WorkSourceDispatch() #30 0x7f537c566e04 g_main_context_dispatch #31 0x7f537c567048 <unknown> #32 0x7f537c5670ec g_main_context_iteration #33 0x7f5392db31af base::MessagePumpGlib::Run() #34 0x7f5392daeb5e base::MessageLoop::Run() #35 0x7f5392e5bc5c base::RunLoop::Run() #36 0x0000030e62ae StatusChangeChecker::StartBlockingWait() #37 0x0000030e60b2 StatusChangeChecker::Wait() #38 0x0000015d6c20 TwoClientBookmarksSyncTest_FirstClientEnablesEncryptionWithPassSecondChanges_Test::RunTestOnMainThread()
,
Dec 7 2017
Alright, I've started being able to repro this by setting the passphrase for client 1 earlier. Another thing to note, the comment that claims we're adding Title 3 and Title 4 to client 1 is wrong, it adds those bookmarks to client 0. So the race is then these two bookmarks going from client 0 to 1, and client 1 de/encrypting itself, and the configuration that comes along with that. The model association always seem to work, the problem is that the models look differently, which is why we see the title mismatch. The next step is finding out if these two bookmarks make it to the sync thread/directory for client 1 or not.
,
Dec 8 2017
It seems that they do not make it to client 1. It would seem the invalidation never makes it to SyncBackendHostImpl::OnIncomingInvalidation().
,
Dec 8 2017
It looks like when the invalidation comes through, InvalidatorRegistrar::handler_to_ids_map_ doesn't have BOOKMARKS in it. Okay, I think I may have finally found the original race condition that's causing the flakes. We disable BOOKMARKS because we don't have the encryption key, makes sense. And as part of disabling, we unsubscribe from invalidations. Okay so far. Then we get the key, we realizes we can make BOOKMARKS work, so we configure it. During this configuration we perform a GetUpdates, apply it to BOOKMARKS, merge and everything. The type looks healthy, so it's now enabled, and on the completion of configuration we subscribe to invalidations. But there was a hole there. Between when that GetUpdates call was made, and when we re-subscribed to invalidations, we can miss things. Another client has to commit to the server, have the invalidation get sent out, and fully reach our client - and get dropped by invalidations code before the re-subscription occurs.
,
Dec 8 2017
For posterity, my changes to make FirstClientEnablesEncryptionWithPassSecondChanges flake more often looked like: --- a/chrome/browser/sync/test/integration/two_client_bookmarks_sync_test.cc +++ b/chrome/browser/sync/test/integration/two_client_bookmarks_sync_test.cc @@ -1860,6 +1860,9 @@ IN_PROC_BROWSER_TEST_F(TwoClientBookmarksSyncTest, ASSERT_TRUE(IsEncryptionComplete(1)); ASSERT_TRUE(GetSyncService(1)->IsPassphraseRequired()); + ASSERT_TRUE(GetSyncService(1)->SetDecryptionPassphrase(kValidPassphrase)); + base::RunLoop().RunUntilIdle(); + // Client 1 adds bookmarks between the first two and between the second two. ASSERT_NE(nullptr, AddURL(0, 1, IndexedURLTitle(3), GURL(IndexedURL(3)))); ASSERT_NE(nullptr, AddURL(0, 3, IndexedURLTitle(4), GURL(IndexedURL(4)))); @@ -1867,8 +1870,8 @@ IN_PROC_BROWSER_TEST_F(TwoClientBookmarksSyncTest, EXPECT_FALSE(AllModelsMatch()); // Set the passphrase. Everything should resolve. - ASSERT_TRUE(PassphraseRequiredChecker(GetSyncService(1)).Wait()); - ASSERT_TRUE(GetSyncService(1)->SetDecryptionPassphrase(kValidPassphrase)); + // ASSERT_TRUE(PassphraseRequiredChecker(GetSyncService(1)).Wait()); + // ASSERT_TRUE(GetSyncService(1)->SetDecryptionPassphrase(kValidPassphrase)); ASSERT_TRUE(PassphraseAcceptedChecker(GetSyncService(1)).Wait()); ASSERT_TRUE(BookmarksMatchChecker().Wait()); ASSERT_EQ(0, GetClient(1)->GetLastCycleSnapshot().num_encryption_conflicts());
,
Dec 8 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/a8b389e6a5878933acb23a21dacd0a0cc3dbf09c commit a8b389e6a5878933acb23a21dacd0a0cc3dbf09c Author: Sky Malice <skym@chromium.org> Date: Fri Dec 08 23:17:34 2017 [Sync] Fix integ tests race condition missing invalidations. The test FirstClientEnablesEncryptionWithPassSecondChanges was flakey because one client would add a new bookmark while the other client was unsubscribed from invalidations during a configuration cycle. This change fixes this race condition by requesting another GetUpdates after configuration for any integration test that uses invalidations. There may be other integ flakes this will fix. Bug: 644367 Change-Id: Id56b16015c9faefdcff01e06b3f6536e6bf7e531 Reviewed-on: https://chromium-review.googlesource.com/817879 Commit-Queue: Sky Malice <skym@chromium.org> Reviewed-by: Nicolas Zea <zea@chromium.org> Cr-Commit-Position: refs/heads/master@{#522914} [add] https://crrev.com/a8b389e6a5878933acb23a21dacd0a0cc3dbf09c/chrome/browser/sync/test/integration/configuration_refresher.cc [add] https://crrev.com/a8b389e6a5878933acb23a21dacd0a0cc3dbf09c/chrome/browser/sync/test/integration/configuration_refresher.h [modify] https://crrev.com/a8b389e6a5878933acb23a21dacd0a0cc3dbf09c/chrome/browser/sync/test/integration/sync_test.cc [modify] https://crrev.com/a8b389e6a5878933acb23a21dacd0a0cc3dbf09c/chrome/browser/sync/test/integration/sync_test.h [modify] https://crrev.com/a8b389e6a5878933acb23a21dacd0a0cc3dbf09c/chrome/browser/sync/test/integration/two_client_bookmarks_sync_test.cc [modify] https://crrev.com/a8b389e6a5878933acb23a21dacd0a0cc3dbf09c/chrome/test/BUILD.gn [modify] https://crrev.com/a8b389e6a5878933acb23a21dacd0a0cc3dbf09c/components/sync/engine_impl/cycle/nudge_tracker.cc
,
Dec 8 2017
|
||||||
►
Sign in to add a comment |
||||||
Comment 1 by sheriffbot@chromium.org
, Sep 7 2017Status: Untriaged (was: Available)