My favorites ▼ | Sign in
Project Home Downloads Wiki Issues Code Search
New issue   Search
for
  Advanced search   Search tips   Subscriptions
Issue 39070: SyncerThreadWithSyncerTest.Pause timing out
5 people starred this issue and may be notified of changes. Back to list
Status:  WontFix
Owner:  zea@chromium.org
Closed:  Jun 2011
Cc:  sky@chromium.org

Restricted
  • Only users with Commit permission may comment.


Sign in to add a comment
 
Project Member Reported by tim@chromium.org, Mar 23, 2010 
I'm temporarily disabling the test.  I'm not sure if it's hanging up on the 
initial sync or the post-pause sync_cycle_ended_event.Wait...

http://chrome-
buildbot.corp.google.com:8010/builders/XP%20Tests%20(dbg)(1)/builds/20817/s
teps/sync_unit_tests/logs/stdio

 RUN      ] SyncerThreadWithSyncerTest.AuthInvalid
[       OK ] SyncerThreadWithSyncerTest.AuthInvalid (3094 ms)
[ RUN      ] SyncerThreadWithSyncerTest.Pause
[3144:3756:0323/113640:192470953:ERROR:download_updates_command.cc(70)] 
PostClientToServerMessage() failed
Mar 24, 2010
#1 bugdroid1@gmail.com 
The following revision refers to this bug:
    http://src.chromium.org/viewvc/chrome?view=rev&revision=42369 

------------------------------------------------------------------------
r42369 | tim@chromium.org | 2010-03-23 12:20:04 -0700 (Tue, 23 Mar 2010) | 6 lines
Changed paths:
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/engine/syncer_thread_unittest.cc?r1=42369&r2=42368

Disable SyncerThreadWithSyncerTest.Pause.  It's timing out, so I can't use FLAKY :(

TBR=skrul
BUG=39070

Review URL: http://codereview.chromium.org/1189001
------------------------------------------------------------------------
Apr 14, 2010
#2 tim@chromium.org 
(No comment was entered for this change.)
Labels: Mstone-X
Jun 30, 2010
#3 sk...@chromium.org 
This was re-enabled in r51158 and so far seems to be fine.
Status: Fixed
Jul 1, 2010
#4 bugdroid1@gmail.com 
The following revision refers to this bug:
    http://src.chromium.org/viewvc/chrome?view=rev&revision=51427 

------------------------------------------------------------------------
r51427 | vandebo@chromium.org | 2010-07-01 14:44:06 -0700 (Thu, 01 Jul 2010) | 8 lines
Changed paths:
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/engine/syncer_thread_unittest.cc?r1=51427&r2=51426

This is still timing out.

i.e. http://build.chromium.org/buildbot/waterfall/builders/XP%20Tests%20(dbg)(1)/builds/25113/steps/sync_unit_tests/logs/stdio

BUG=39070
TEST=SyncerThreadWithSyncerTest.Pause

Review URL: http://codereview.chromium.org/2852038
------------------------------------------------------------------------
Jul 1, 2010
#5 vandebo@chromium.org 
(No comment was entered for this change.)
Status: Assigned
Jul 2, 2010
#6 bugdroid1@gmail.com 
The following revision refers to this bug:
    http://src.chromium.org/viewvc/chrome?view=rev&revision=51505 

------------------------------------------------------------------------
r51505 | tim@chromium.org | 2010-07-01 23:21:03 -0700 (Thu, 01 Jul 2010) | 7 lines
Changed paths:
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/engine/syncer_thread_unittest.cc?r1=51505&r2=51504
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/engine/syncer_unittest.cc?r1=51505&r2=51504

Mark PauseWhenNotConnected as flaky as it keeps timing out,
and ServerDeletingFolderWeHaveAnOpenEntryIn is failing 100% of the time.

BUG=39070, 46621
TEST=Syncer unittest, SyncerThreadTest
TBR=skrul
Review URL: http://codereview.chromium.org/2873039
------------------------------------------------------------------------
Jul 9, 2010
#7 bugdroid1@gmail.com 
The following revision refers to this bug:
    http://src.chromium.org/viewvc/chrome?view=rev&revision=51980 

------------------------------------------------------------------------
r51980 | skrul@chromium.org | 2010-07-09 10:51:18 -0700 (Fri, 09 Jul 2010) | 8 lines
Changed paths:
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/engine/syncer_thread_unittest.cc?r1=51980&r2=51979

Use TimedWait everywhere to prevent hangs.
I'm having a hard time reproing this hang locally -- I ran the test for several days on windows with no hangs.  So this change should prevent any individual test in this test from hanging and hopefully help provide some helpful info when it hangs again.

And since the tests won't hang anymore, I believe we can make them FLAKY.

BUG=39070

Review URL: http://codereview.chromium.org/2864043
------------------------------------------------------------------------
Jul 12, 2010
#8 sk...@chromium.org 
Checked up on this today and so far the test has not flaked at all, according to the flakiness dashboard.
Jul 13, 2010
#9 tim@chromium.org 
A few of the Pause tests have been failing consistently for me.  I focused on PauseResumeWhenNotConnected and ran with --gtest_repeat=10 and always saw a failure.  I noticed several problems, but haven't managed to get it reliably passing yet.

1) TimedWait return false -- this one is the least troublesome as the timed waits were added for debugging, but I still should have caught this on code review :)  Asserting that the timedWait returned true is incorrect, as a return value of false does _not_ mean that the event timed out.  As with condition variables, waitable events can be spuriously signaled, and you have to re-check your condition.  

2) vault fields are modified without signals / broadcasts.  I caught a hang in the debugger where the SyncerThread was in PauseUntilResumedOrConnected, blocked on the Wait(), but vault_.paused_ was false!  The main thread, on the other hand, was in the test Resume() function -- RequestResume apparently returned true, and we were waiting on the thread to exit pause.  The last thing printed to std out was "Syncer thread entering pause".  I feel like there is some race between resuming and the Enter/ExitPauseState functions, but haven't put my finger on it yet.  I tried adding Broadcast()s everywhere paused_ is updated and haven't yet seen the hang, but still saw the following problem...

3) I've caught what I believe to be the original failure / crash in a debugger.  It appears that the test harness is shutting down (it's in TearDown, and has deleted the allstatus_ and has released it's ref to the syncer_thread_), but the SyncerThread wasn't done yet; the crash is in ThreadMainLoop, near the bottom when it tries to dereference the allstatus_ member to get the status() object.  I thought this may have been due to ASSERTs in the test bailing out early, so I tried replacing them with EXPECTs, but I still got the failure.  It tends to crash somewhere deep inside EnterCriticalSection because there is apparently enough legit garbage around to bring you right into AllStatus::status() { }, where the first line is an AutoLock; no stack traces show up, it just dies without a peep if you're not attached in the debugger.

I still don't have this test fixed with some bandaids on the above and I spent a while messing around with it...  perhaps this info will help Steve.
Jul 13, 2010
#10 tim@chromium.org 
Also note - I'm suspicious of the use of the EventChannels by these tests.  Err, I should say, I'm suspicious of the Channel impl itself.  I'd put money on a race/bug being in there, in the Notify implementation.  The test does this in the base class, maybe it's something to do with the gmock interaction that triggers badness... anyway  I tried gtest_repeat=100 for all of the other tests in here that don't use the mocker + an extra hookup and they've been passing 100% of the time.

[aside - We should really get rid of "Channel" and use ObserverListThreadSafe, but not feasible for right now.]
Jul 13, 2010
#11 tim@chromium.org 
also seeing

 	sync_unit_tests.exe!_crt_debugger_hook(int _Reserved=167566540)  Line 65	C
 	sync_unit_tests.exe!_invalid_parameter(const wchar_t * pszExpression=0x03c6d7bc, const wchar_t * pszFunction=0x03cc52a8, const wchar_t * pszFile=0x03c6d630, unsigned int nLine=138, unsigned int pReserved=0)  Line 112 + 0x7 bytes	C++
 	sync_unit_tests.exe!std::_Vector_const_iterator<testing::internal::linked_ptr<testing::internal::TypedExpectation<void __cdecl(browser_sync::SyncerEvent const &)> >,std::allocator<testing::internal::linked_ptr<testing::internal::TypedExpectation<void __cdecl(browser_sync::SyncerEvent const &)> > > >::operator--()  Line 138 + 0x4f bytes	C++
 	sync_unit_tests.exe!std::_Revranit<std::_Vector_const_iterator<testing::internal::linked_ptr<testing::internal::TypedExpectation<void __cdecl(browser_sync::SyncerEvent const &)> >,std::allocator<testing::internal::linked_ptr<testing::internal::TypedExpectation<void __cdecl(browser_sync::SyncerEvent const &)> > > >,std::iterator<std::random_access_iterator_tag,testing::internal::linked_ptr<testing::internal::TypedExpectation<void __cdecl(browser_sync::SyncerEvent const &)> >,int,testing::internal::linked_ptr<testing::internal::TypedExpectation<void __cdecl(browser_sync::SyncerEvent const &)> > const *,testing::internal::linked_ptr<testing::internal::TypedExpectation<void __cdecl(browser_sync::SyncerEvent const &)> > const &> >::operator++()  Line 1947	C++
 	sync_unit_tests.exe!std::reverse_iterator<std::_Vector_const_iterator<testing::internal::linked_ptr<testing::internal::TypedExpectation<void __cdecl(browser_sync::SyncerEvent const &)> >,std::allocator<testing::internal::linked_ptr<testing::internal::TypedExpectation<void __cdecl(browser_sync::SyncerEvent const &)> > > > >::operator++()  Line 2178	C++
 	sync_unit_tests.exe!testing::internal::FunctionMockerBase<void __cdecl(browser_sync::SyncerEvent const &)>::FindMatchingExpectationLocked(const std::tr1::tuple<browser_sync::SyncerEvent const &,void,void,void,void,void,void,void,void,void> & args=(...,...)  Line 1583 + 0x8 bytes	C++
 	sync_unit_tests.exe!testing::internal::FunctionMockerBase<void __cdecl(browser_sync::SyncerEvent const &)>::FindMatchingExpectationAndAction(const std::tr1::tuple<browser_sync::SyncerEvent const &,void,void,void,void,void,void,void,void,void> & args=(...,..., testing::internal::TypedExpectation<void __cdecl(browser_sync::SyncerEvent const &)> * * exp=0x09fcdf28, testing::Action<void __cdecl(browser_sync::SyncerEvent const &)> * action=0x09fcdf34, bool * is_excessive=0x09fce0f7, std::basic_ostream<char,std::char_traits<char> > * what=0x09fce06c, std::basic_ostream<char,std::char_traits<char> > * why=0x09fcdfdc)  Line 1560 + 0xc bytes	C++
 	sync_unit_tests.exe!testing::internal::FunctionMockerBase<void __cdecl(browser_sync::SyncerEvent const &)>::InvokeWith(const std::tr1::tuple<browser_sync::SyncerEvent const &,void,void,void,void,void,void,void,void,void> & args=(...,...)  Line 1766 + 0x79 bytes	C++
 	sync_unit_tests.exe!testing::internal::FunctionMocker<void __cdecl(browser_sync::SyncerEvent const &)>::Invoke(const browser_sync::SyncerEvent & a1={...})  Line 96	C++
 	sync_unit_tests.exe!browser_sync::ListenerMock::HandleChannelEvent(const browser_sync::SyncerEvent & gmock_a1={...})  Line 41 + 0x31 bytes	C++
 	sync_unit_tests.exe!browser_sync::Channel<browser_sync::SyncerEvent>::Notify(const browser_sync::SyncerEvent & event={...})  Line 125 + 0x30 bytes	C++
>	sync_unit_tests.exe!browser_sync::SyncerThread::HandleChannelEvent(const browser_sync::SyncerEvent & event={...})  Line 580	C++
 	sync_unit_tests.exe!browser_sync::Channel<browser_sync::SyncerEvent>::Notify(const browser_sync::SyncerEvent & event={...})  Line 125 + 0x30 bytes	C++
 	sync_unit_tests.exe!browser_sync::SyncerCommand::SendNotifications(browser_sync::sessions::SyncSession * session=0x09fcf040)  Line 38	C++
 	sync_unit_tests.exe!browser_sync::SyncerCommand::Execute(browser_sync::sessions::SyncSession * session=0x09fcf040)  Line 22	C++
 	sync_unit_tests.exe!browser_sync::Syncer::SyncShare(browser_sync::sessions::SyncSession * session=0x09fcf040, browser_sync::SyncerStep first_step=SYNCER_BEGIN, browser_sync::SyncerStep last_step=SYNCER_END)  Line 284	C++
 	sync_unit_tests.exe!browser_sync::Syncer::SyncShare(browser_sync::sessions::SyncSession * session=0x09fcf040)  Line 103	C++
 	sync_unit_tests.exe!browser_sync::Syncer::SyncShare(browser_sync::sessions::SyncSession::Delegate * delegate=0x08f41280)  Line 86 + 0xc bytes	C++
 	sync_unit_tests.exe!browser_sync::SyncerThread::SyncMain(browser_sync::Syncer * syncer=0x08ef40a0)  Line 519 + 0xc bytes	C++
 	sync_unit_tests.exe!browser_sync::SyncerThread::ThreadMainLoop()  Line 335	C++
 	sync_unit_tests.exe!browser_sync::SyncerThread::ThreadMain()  Line 505	C++
Jul 13, 2010
#12 oshima@chromium.org 
This is crashing on XP Test now so i'll disable this on Windows for now.


[ RUN      ] SyncerThreadWithSyncerTest.FLAKY_Pause

copying dashboard file gtest-results/sync_unit_tests\results.json to \\chrome-web.jail.google.com\chrome-bot\www\gtest_results\chromium-dbg-xp-tests\sync_unit_tests
saving results to \\chrome-web.jail.google.com\chrome-bot\www\gtest_results\chromium-dbg-xp-tests\sync_unit_tests

program finished with exit code -1073741811
elapsedTime=19.453000
Jul 13, 2010
#13 bugdroid1@gmail.com 
The following revision refers to this bug:
    http://src.chromium.org/viewvc/chrome?view=rev&revision=52247 

------------------------------------------------------------------------
r52247 | oshima@chromium.org | 2010-07-13 18:03:33 -0700 (Tue, 13 Jul 2010) | 7 lines
Changed paths:
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/engine/syncer_thread_unittest.cc?r1=52247&r2=52246

Disable SyncerThreadTest.Pause on Windows because it's crashing.

BUG=39070
BUG=skrul@chromium.org
TEST=none

Review URL: http://codereview.chromium.org/2981009
------------------------------------------------------------------------
Jul 13, 2010
#14 bugdroid1@gmail.com 
The following revision refers to this bug:
    http://src.chromium.org/viewvc/chrome?view=rev&revision=52259 

------------------------------------------------------------------------
r52259 | tim@chromium.org | 2010-07-13 18:31:36 -0700 (Tue, 13 Jul 2010) | 5 lines
Changed paths:
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/engine/all_status.cc?r1=52259&r2=52258
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/engine/syncapi.cc?r1=52259&r2=52258
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/engine/syncapi.h?r1=52259&r2=52258
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/engine/syncer_proto_util.cc?r1=52259&r2=52258
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/engine/syncer_thread.cc?r1=52259&r2=52258
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/engine/syncer_thread.h?r1=52259&r2=52258
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/engine/syncer_thread_unittest.cc?r1=52259&r2=52258
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/engine/syncer_types.h?r1=52259&r2=52258
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/engine/syncer_unittest.cc?r1=52259&r2=52258
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/glue/sync_backend_host.cc?r1=52259&r2=52258
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/glue/sync_backend_host.h?r1=52259&r2=52258
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/profile_sync_service.cc?r1=52259&r2=52258
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/profile_sync_service.h?r1=52259&r2=52258
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/sessions/sync_session.h?r1=52259&r2=52258
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/sessions/sync_session_unittest.cc?r1=52259&r2=52258
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/test/sync/engine/mock_connection_manager.h?r1=52259&r2=52258
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/test/sync/engine/syncer_command_test.h?r1=52259&r2=52258

Handle birthday errors by disabling sync and deleting sync data. Also added some CV broadcasts in SyncerThread, as changing vault_ fields and not signalling seems dubious (and I caught a hang in the debugger where the thread was waiting for an already true condition, thus deadlocked).

BUG=46807,39070

Review URL: http://codereview.chromium.org/2923006
------------------------------------------------------------------------
Jul 14, 2010
#15 bugdroid1@gmail.com 
The following revision refers to this bug:
    http://src.chromium.org/viewvc/chrome?view=rev&revision=52395 

------------------------------------------------------------------------
r52395 | skrul@chromium.org | 2010-07-14 13:54:28 -0700 (Wed, 14 Jul 2010) | 6 lines
Changed paths:
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/engine/syncer_thread_unittest.cc?r1=52395&r2=52394

Fix race condition in test Pause method.
Acquire a lock on the syncer thread vault before setting listener expectations so it is not possilbe to get a notification while setting expectations.

BUG=39070

Review URL: http://codereview.chromium.org/2991003
------------------------------------------------------------------------
Jul 21, 2010
#16 bugdroid1@gmail.com 
The following revision refers to this bug:
    http://src.chromium.org/viewvc/chrome?view=rev&revision=53063 

------------------------------------------------------------------------
r53063 | pinkerton@chromium.org | 2010-07-20 11:12:04 -0700 (Tue, 20 Jul 2010) | 4 lines
Changed paths:
   M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/engine/syncer_thread_unittest.cc?r1=53063&r2=53062

Disabling test that hangs bot
BUG=39070
TEST=none
Review URL: http://codereview.chromium.org/2819058
------------------------------------------------------------------------
Aug 11, 2010
#17 sk...@chromium.org 
(No comment was entered for this change.)
Owner: t...@chromium.org
Oct 11, 2010
#18 isherman@chromium.org 
This test is causing the test library to stop running again.  Sample output:

[ RUN      ] SyncerThreadWithSyncerTest.FLAKY_Pause
[1696:3612:1011/165849:357249250:INFO:syncer_thread.cc(112)] SyncerThread started.
[1696:1908:1011/165849:357249250:INFO:syncer_thread.cc(239)] In thread main loop.
[1696:1908:1011/165849:357249250:INFO:syncer_thread.cc(254)] Syncer thread waiting for database initialization.
[1696:3612:1011/165850:357249265:INFO:syncer_thread.cc(568)] Creating syncer up for: Test
[1696:1908:1011/165850:357249265:INFO:syncer_thread.cc(257)] Syncer was found after DB started.
[1696:1908:1011/165850:357249265:INFO:syncer_thread.cc(294)] end_wait is 300000000
[1696:1908:1011/165850:357249265:INFO:syncer_thread.cc(295)] next_poll is 300000000
[1696:1908:1011/165850:357249265:INFO:syncer_thread.cc(322)] Calling Sync Main at time 12931315130013280
[1696:1908:1011/165850:357249265:INFO:syncer_proto_util.cc(98)] New store birthday: Store BDay!
[1696:1908:1011/165850:357249265:INFO:verify_updates_command.cc(31)] Beginning Update Verification
[1696:1908:1011/165850:357249265:INFO:verify_updates_command.cc(43)] 0 entries to verify
[1696:3612:1011/165850:357249265:INFO:syncer_thread.cc(167)] Pause requested.
copying dashboard file gtest-results/sync_unit_tests\results.json to \\chrome-web.jail.google.com\chrome-bot\www\gtest_results\chromium-dbg-vista-tests\sync_unit_tests
saving results to \\chrome-web.jail.google.com\chrome-bot\www\gtest_results\chromium-dbg-vista-tests\sync_unit_tests
program finished with exit code -1073741811
Labels: -Mstone-X Mstone-9 Tests-Disabled
Nov 10, 2010
#19 akalin@chromium.org 
(No comment was entered for this change.)
Labels: -Mstone-9 Mstone-10
Nov 17, 2010
#20 bugdroid1@gmail.com 
The following revision refers to this bug:
    http://src.chromium.org/viewvc/chrome?view=rev&revision=66507

------------------------------------------------------------------------
r66507 | zea@chromium.org | Wed Nov 17 11:58:53 PST 2010

Changed paths:
 M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/engine/syncer_thread_unittest.cc?r1=66507&r2=66506&pathrev=66507
 M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/engine/syncer_thread.cc?r1=66507&r2=66506&pathrev=66507

Sync: Fix RequestResume in SyncerThread, and re-enable the various unit tests
that were breaking.

BUG=62880,39070,62880
TEST=sync_unit_tests

Review URL: http://codereview.chromium.org/5047002
------------------------------------------------------------------------
Nov 18, 2010
#21 zea@chromium.org 
(No comment was entered for this change.)
Owner: z...@chromium.org
Nov 18, 2010
#22 zea@chromium.org 
 Issue 63688  has been merged into this issue.
Nov 18, 2010
#23 bugdroid1@gmail.com 
The following revision refers to this bug:
    http://src.chromium.org/viewvc/chrome?view=rev&revision=66702

------------------------------------------------------------------------
r66702 | zea@chromium.org | Thu Nov 18 15:42:00 PST 2010

Changed paths:
 M http://src.chromium.org/viewvc/chrome/trunk/src/chrome/browser/sync/engine/syncer_thread_unittest.cc?r1=66702&r2=66701&pathrev=66702

Disabled flaky pause tests (again).

BUG=39070
TEST=none
TBR=tim@chromium.org

Review URL: http://codereview.chromium.org/5226002
------------------------------------------------------------------------
Dec 8, 2010
#24 zea@chromium.org 
(No comment was entered for this change.)
Labels: -Mstone-10 Mstone-11
Jan 28, 2011
#25 zea@chromium.org 
This is made obsolete by SyncerThread2.
Status: WontFix
Jan 28, 2011
#26 zea@chromium.org 
On second though, until SyncerThread2 isn't actually enabled yet, so we can leave it around until it's switched on.
Status: Available
Labels: -Pri-1 Pri-2
Feb 8, 2011
#27 zea@chromium.org 
(No comment was entered for this change.)
Labels: -Mstone-11 Mstone-X
Jun 27, 2011
#28 zea@chromium.org 
syncerthread2 is live
Status: WontFix
Oct 12, 2012
#29 bugdroid1@chromium.org 
This issue has been closed for some time. No one will pay attention to new comments.
If you are seeing this bug or have new data, please click New Issue to start a new bug.
Labels: Restrict-AddIssueComment-Commit
Mar 10, 2013
#30 bugdroid1@chromium.org 
(No comment was entered for this change.)
Labels: -Area-Internals -Feature-Sync -Tests-Disabled Cr-Services-Sync Cr-Internals Cr-Tests-Disabled
► Sign in to add a comment

Powered by Google Project Hosting