syncer_thread_unittest.cc revision c407dc5cd9bdc5668497f21b26b09d988ab439de 
1// Copyright (c) 2009 The Chromium Authors. All rights reserved.
2// Use of this source code is governed by a BSD-style license that can be
3// found in the LICENSE file.
4
5#include <list>
6#include <map>
7#include <set>
8
9#include "base/lock.h"
10#include "base/scoped_ptr.h"
11#include "base/time.h"
12#include "base/waitable_event.h"
13#include "chrome/browser/sync/engine/model_safe_worker.h"
14#include "chrome/browser/sync/engine/syncer_thread.h"
15#include "chrome/browser/sync/engine/syncer_types.h"
16#include "chrome/browser/sync/sessions/sync_session_context.h"
17#include "chrome/browser/sync/util/channel.h"
18#include "chrome/test/sync/engine/mock_connection_manager.h"
19#include "chrome/test/sync/engine/test_directory_setter_upper.h"
20#include "testing/gmock/include/gmock/gmock.h"
21#include "testing/gtest/include/gtest/gtest.h"
22
23using base::TimeTicks;
24using base::TimeDelta;
25using base::WaitableEvent;
26using testing::_;
27using testing::AnyNumber;
28using testing::Field;
29
30namespace browser_sync {
31using sessions::SyncSessionContext;
32
33typedef testing::Test SyncerThreadTest;
34typedef SyncerThread::WaitInterval WaitInterval;
35
36ACTION_P(SignalEvent, event) {
37  event->Signal();
38}
39
40class ListenerMock : public ChannelEventHandler<SyncerEvent> {
41 public:
42  MOCK_METHOD1(HandleChannelEvent, void(const SyncerEvent&));
43};
44
45class SyncerThreadWithSyncerTest : public testing::Test,
46                                   public ModelSafeWorkerRegistrar,
47                                   public ChannelEventHandler<SyncerEvent> {
48 public:
49  SyncerThreadWithSyncerTest()
50      : max_wait_time_(TimeDelta::FromSeconds(10)),
51        sync_cycle_ended_event_(false, false) {}
52  virtual void SetUp() {
53    metadb_.SetUp();
54    connection_.reset(new MockConnectionManager(metadb_.manager(),
55                                                metadb_.name()));
56    allstatus_.reset(new AllStatus());
57    worker_ = new ModelSafeWorker();
58    SyncSessionContext* context = new SyncSessionContext(connection_.get(),
59        NULL, metadb_.manager(), this);
60    syncer_thread_ = new SyncerThread(context, allstatus_.get());
61    syncer_event_hookup_.reset(
62        syncer_thread_->relay_channel()->AddObserver(this));
63    allstatus_->WatchSyncerThread(syncer_thread_);
64    syncer_thread_->SetConnected(true);
65    syncable::ModelTypeBitSet expected_types;
66    expected_types[syncable::BOOKMARKS] = true;
67    connection_->ExpectGetUpdatesRequestTypes(expected_types);
68  }
69  virtual void TearDown() {
70    syncer_event_hookup_.reset();
71    allstatus_.reset();
72    syncer_thread_ = NULL;
73    connection_.reset();
74    metadb_.TearDown();
75  }
76
77  // ModelSafeWorkerRegistrar implementation.
78  virtual void GetWorkers(std::vector<ModelSafeWorker*>* out) {
79    out->push_back(worker_.get());
80  }
81
82  virtual void GetModelSafeRoutingInfo(ModelSafeRoutingInfo* out) {
83    // We're just testing the sync engine here, so we shunt everything to
84    // the SyncerThread.
85    (*out)[syncable::BOOKMARKS] = GROUP_PASSIVE;
86  }
87
88  ManuallyOpenedTestDirectorySetterUpper* metadb() { return &metadb_; }
89  MockConnectionManager* connection() { return connection_.get(); }
90  SyncerThread* syncer_thread() { return syncer_thread_; }
91
92  // Waits an indefinite amount of sync cycles for the syncer thread to become
93  // throttled.  Only call this if a throttle is supposed to occur!
94  bool WaitForThrottle() {
95    int max_cycles = 5;
96    while (max_cycles && !syncer_thread()->IsSyncingCurrentlySilenced()) {
97      sync_cycle_ended_event_.TimedWait(max_wait_time_);
98      max_cycles--;
99    }
100
101    return syncer_thread()->IsSyncingCurrentlySilenced();
102  }
103
104  void WaitForDisconnect() {
105    // Wait for the SyncerThread to detect loss of connection, up to a max of
106    // 10 seconds to timeout the test.
107    AutoLock lock(syncer_thread()->lock_);
108    TimeTicks start = TimeTicks::Now();
109    TimeDelta ten_seconds = TimeDelta::FromSeconds(10);
110    while (syncer_thread()->vault_.connected_) {
111      syncer_thread()->vault_field_changed_.TimedWait(ten_seconds);
112      if (TimeTicks::Now() - start > ten_seconds)
113        break;
114    }
115    EXPECT_FALSE(syncer_thread()->vault_.connected_);
116  }
117
118  bool Pause(ListenerMock* listener) {
119    WaitableEvent event(false, false);
120    {
121      AutoLock lock(syncer_thread()->lock_);
122      EXPECT_CALL(*listener, HandleChannelEvent(
123          Field(&SyncerEvent::what_happened, SyncerEvent::PAUSED))).
124          WillOnce(SignalEvent(&event));
125    }
126    if (!syncer_thread()->RequestPause())
127      return false;
128    return event.TimedWait(max_wait_time_);
129  }
130
131  bool Resume(ListenerMock* listener) {
132    WaitableEvent event(false, false);
133    {
134      AutoLock lock(syncer_thread()->lock_);
135      EXPECT_CALL(*listener, HandleChannelEvent(
136          Field(&SyncerEvent::what_happened, SyncerEvent::RESUMED))).
137          WillOnce(SignalEvent(&event));
138    }
139    if (!syncer_thread()->RequestResume())
140      return false;
141    return event.TimedWait(max_wait_time_);
142  }
143
144  void PreventThreadFromPolling() {
145    const TimeDelta poll_interval = TimeDelta::FromMinutes(5);
146    syncer_thread()->SetSyncerShortPollInterval(poll_interval);
147  }
148
149 private:
150
151  void HandleChannelEvent(const SyncerEvent& event) {
152    if (event.what_happened == SyncerEvent::SYNC_CYCLE_ENDED)
153      sync_cycle_ended_event_.Signal();
154  }
155
156 protected:
157  TimeDelta max_wait_time_;
158
159 private:
160  ManuallyOpenedTestDirectorySetterUpper metadb_;
161  scoped_ptr<MockConnectionManager> connection_;
162  scoped_ptr<AllStatus> allstatus_;
163  scoped_refptr<SyncerThread> syncer_thread_;
164  scoped_refptr<ModelSafeWorker> worker_;
165  scoped_ptr<ChannelHookup<SyncerEvent> > syncer_event_hookup_;
166  base::WaitableEvent sync_cycle_ended_event_;
167  DISALLOW_COPY_AND_ASSIGN(SyncerThreadWithSyncerTest);
168};
169
170class SyncShareIntercept
171    : public MockConnectionManager::ResponseCodeOverrideRequestor,
172      public MockConnectionManager::MidCommitObserver {
173 public:
174  SyncShareIntercept() : sync_occured_(false, false),
175                         allow_multiple_interceptions_(true) {}
176  virtual ~SyncShareIntercept() {}
177  virtual void Observe() {
178    if (!allow_multiple_interceptions_ && !times_sync_occured_.empty())
179      FAIL() << "Multiple sync shares occured.";
180    times_sync_occured_.push_back(TimeTicks::Now());
181    sync_occured_.Signal();
182  }
183
184  // ResponseCodeOverrideRequestor implementation. This assumes any override
185  // requested is intended to silence the SyncerThread.
186  virtual void OnOverrideComplete() {
187    // We should not see any syncing.
188    allow_multiple_interceptions_ = false;
189    times_sync_occured_.clear();
190  }
191
192  void WaitForSyncShare(int at_least_this_many, TimeDelta max_wait) {
193    while (at_least_this_many-- > 0)
194      sync_occured_.TimedWait(max_wait);
195  }
196  std::vector<TimeTicks> times_sync_occured() const {
197    return times_sync_occured_;
198  }
199
200  void Reset() {
201    allow_multiple_interceptions_ = true;
202    times_sync_occured_.clear();
203    sync_occured_.Reset();
204  }
205 private:
206  std::vector<TimeTicks> times_sync_occured_;
207  base::WaitableEvent sync_occured_;
208  bool allow_multiple_interceptions_;
209  DISALLOW_COPY_AND_ASSIGN(SyncShareIntercept);
210};
211
212TEST_F(SyncerThreadTest, Construction) {
213  SyncSessionContext* context = new SyncSessionContext(NULL, NULL, NULL, NULL);
214  scoped_refptr<SyncerThread> syncer_thread(new SyncerThread(context, NULL));
215}
216
217TEST_F(SyncerThreadTest, StartStop) {
218  SyncSessionContext* context = new SyncSessionContext(NULL, NULL, NULL, NULL);
219  scoped_refptr<SyncerThread> syncer_thread(new SyncerThread(context, NULL));
220  EXPECT_TRUE(syncer_thread->Start());
221  EXPECT_TRUE(syncer_thread->Stop(2000));
222
223  // Do it again for good measure.  I caught some bugs by adding this so
224  // I would recommend keeping it.
225  EXPECT_TRUE(syncer_thread->Start());
226  EXPECT_TRUE(syncer_thread->Stop(2000));
227}
228
229TEST_F(SyncerThreadTest, CalculateSyncWaitTime) {
230  SyncSessionContext* context = new SyncSessionContext(NULL, NULL, NULL, NULL);
231  scoped_refptr<SyncerThread> syncer_thread(new SyncerThread(context, NULL));
232  syncer_thread->DisableIdleDetection();
233
234  // Syncer_polling_interval_ is less than max poll interval.
235  TimeDelta syncer_polling_interval = TimeDelta::FromSeconds(1);
236
237  syncer_thread->SetSyncerPollingInterval(syncer_polling_interval);
238
239  // user_idle_ms is less than 10 * (syncer_polling_interval*1000).
240  ASSERT_EQ(syncer_polling_interval.InMilliseconds(),
241            syncer_thread->CalculateSyncWaitTime(1000, 0));
242  ASSERT_EQ(syncer_polling_interval.InMilliseconds(),
243            syncer_thread->CalculateSyncWaitTime(1000, 1));
244
245  // user_idle_ms is ge than 10 * (syncer_polling_interval*1000).
246  int last_poll_time = 2000;
247  ASSERT_TRUE(last_poll_time <=
248              syncer_thread->CalculateSyncWaitTime(last_poll_time, 10000));
249  ASSERT_TRUE(last_poll_time * 3 >=
250              syncer_thread->CalculateSyncWaitTime(last_poll_time, 10000));
251  ASSERT_TRUE(last_poll_time <=
252              syncer_thread->CalculateSyncWaitTime(last_poll_time, 100000));
253  ASSERT_TRUE(last_poll_time * 3 >=
254              syncer_thread->CalculateSyncWaitTime(last_poll_time, 100000));
255
256  // Maximum backoff time should be syncer_max_interval.
257  int near_threshold = SyncerThread::kDefaultMaxPollIntervalMs / 2 - 1;
258  int threshold = SyncerThread::kDefaultMaxPollIntervalMs;
259  int over_threshold = SyncerThread::kDefaultMaxPollIntervalMs + 1;
260  ASSERT_TRUE(near_threshold <=
261              syncer_thread->CalculateSyncWaitTime(near_threshold, 10000));
262  ASSERT_TRUE(SyncerThread::kDefaultMaxPollIntervalMs >=
263              syncer_thread->CalculateSyncWaitTime(near_threshold, 10000));
264  ASSERT_TRUE(SyncerThread::kDefaultMaxPollIntervalMs ==
265              syncer_thread->CalculateSyncWaitTime(threshold, 10000));
266  ASSERT_TRUE(SyncerThread::kDefaultMaxPollIntervalMs ==
267              syncer_thread->CalculateSyncWaitTime(over_threshold, 10000));
268
269  // Possible idle time must be capped by syncer_max_interval.
270  int over_sync_max_interval =
271      SyncerThread::kDefaultMaxPollIntervalMs + 1;
272  syncer_polling_interval = TimeDelta::FromSeconds(
273      over_sync_max_interval / 100);  // so 1000* is right
274  syncer_thread->SetSyncerPollingInterval(syncer_polling_interval);
275  ASSERT_EQ(syncer_polling_interval.InSeconds() * 1000,
276            syncer_thread->CalculateSyncWaitTime(1000, over_sync_max_interval));
277  syncer_polling_interval = TimeDelta::FromSeconds(1);
278  syncer_thread->SetSyncerPollingInterval(syncer_polling_interval);
279  ASSERT_TRUE(last_poll_time <=
280              syncer_thread->CalculateSyncWaitTime(last_poll_time,
281                                                   over_sync_max_interval));
282  ASSERT_TRUE(last_poll_time * 3 >=
283              syncer_thread->CalculateSyncWaitTime(last_poll_time,
284                                                   over_sync_max_interval));
285}
286
287TEST_F(SyncerThreadTest, CalculatePollingWaitTime) {
288  // Set up the environment.
289  int user_idle_milliseconds_param = 0;
290  SyncSessionContext* context = new SyncSessionContext(NULL, NULL, NULL, NULL);
291  scoped_refptr<SyncerThread> syncer_thread(new SyncerThread(context, NULL));
292  syncer_thread->DisableIdleDetection();
293  // Hold the lock to appease asserts in code.
294  AutoLock lock(syncer_thread->lock_);
295
296  // Notifications disabled should result in a polling interval of
297  // kDefaultShortPollInterval.
298  {
299    AllStatus::Status status = {};
300    status.notifications_enabled = 0;
301    bool continue_sync_cycle_param = false;
302
303    // No work and no backoff.
304    WaitInterval interval = syncer_thread->CalculatePollingWaitTime(
305        status,
306        0,
307        &user_idle_milliseconds_param,
308        &continue_sync_cycle_param,
309        false);
310
311    ASSERT_EQ(SyncerThread::kDefaultShortPollIntervalSeconds,
312              interval.poll_delta.InSeconds());
313    ASSERT_EQ(WaitInterval::NORMAL, interval.mode);
314    ASSERT_FALSE(interval.had_nudge_during_backoff);
315    ASSERT_FALSE(continue_sync_cycle_param);
316
317    // In this case the continue_sync_cycle is turned off.
318    continue_sync_cycle_param = true;
319    interval = syncer_thread->CalculatePollingWaitTime(
320        status,
321        0,
322        &user_idle_milliseconds_param,
323        &continue_sync_cycle_param,
324        false);
325
326    ASSERT_EQ(SyncerThread::kDefaultShortPollIntervalSeconds,
327        interval.poll_delta.InSeconds());
328    ASSERT_EQ(WaitInterval::NORMAL, interval.mode);
329    ASSERT_FALSE(interval.had_nudge_during_backoff);
330    ASSERT_FALSE(continue_sync_cycle_param);
331  }
332
333  // Notifications enabled should result in a polling interval of
334  // SyncerThread::kDefaultLongPollIntervalSeconds.
335  {
336    AllStatus::Status status = {};
337    status.notifications_enabled = 1;
338    bool continue_sync_cycle_param = false;
339
340    // No work and no backoff.
341    WaitInterval interval = syncer_thread->CalculatePollingWaitTime(
342        status,
343        0,
344        &user_idle_milliseconds_param,
345        &continue_sync_cycle_param,
346        false);
347
348    ASSERT_EQ(SyncerThread::kDefaultLongPollIntervalSeconds,
349              interval.poll_delta.InSeconds());
350    ASSERT_EQ(WaitInterval::NORMAL, interval.mode);
351    ASSERT_FALSE(interval.had_nudge_during_backoff);
352    ASSERT_FALSE(continue_sync_cycle_param);
353
354    // In this case the continue_sync_cycle is turned off.
355    continue_sync_cycle_param = true;
356    interval = syncer_thread->CalculatePollingWaitTime(
357        status,
358        0,
359        &user_idle_milliseconds_param,
360        &continue_sync_cycle_param,
361        false);
362
363    ASSERT_EQ(SyncerThread::kDefaultLongPollIntervalSeconds,
364              interval.poll_delta.InSeconds());
365    ASSERT_EQ(WaitInterval::NORMAL, interval.mode);
366    ASSERT_FALSE(interval.had_nudge_during_backoff);
367    ASSERT_FALSE(continue_sync_cycle_param);
368  }
369
370  // There are two states which can cause a continuation, either the updates
371  // available do not match the updates received, or the unsynced count is
372  // non-zero.
373  {
374    AllStatus::Status status = {};
375    status.updates_available = 1;
376    status.updates_received = 0;
377    bool continue_sync_cycle_param = false;
378
379    WaitInterval interval = syncer_thread->CalculatePollingWaitTime(
380        status,
381        0,
382        &user_idle_milliseconds_param,
383        &continue_sync_cycle_param,
384        false);
385
386    ASSERT_LE(0, interval.poll_delta.InSeconds());
387    ASSERT_EQ(WaitInterval::NORMAL, interval.mode);
388    ASSERT_FALSE(interval.had_nudge_during_backoff);
389    ASSERT_TRUE(continue_sync_cycle_param);
390
391    continue_sync_cycle_param = false;
392    interval = syncer_thread->CalculatePollingWaitTime(
393        status,
394        0,
395        &user_idle_milliseconds_param,
396        &continue_sync_cycle_param,
397        false);
398
399    ASSERT_GE(3, interval.poll_delta.InSeconds());
400    ASSERT_EQ(WaitInterval::NORMAL, interval.mode);
401    ASSERT_FALSE(interval.had_nudge_during_backoff);
402    ASSERT_TRUE(continue_sync_cycle_param);
403
404    interval = syncer_thread->CalculatePollingWaitTime(
405        status,
406        0,
407        &user_idle_milliseconds_param,
408        &continue_sync_cycle_param,
409        false);
410
411    ASSERT_LE(0, interval.poll_delta.InSeconds());
412    ASSERT_EQ(WaitInterval::EXPONENTIAL_BACKOFF, interval.mode);
413    ASSERT_FALSE(interval.had_nudge_during_backoff);
414
415    interval = syncer_thread->CalculatePollingWaitTime(
416        status,
417        0,
418        &user_idle_milliseconds_param,
419        &continue_sync_cycle_param,
420        false);
421
422    ASSERT_GE(2, interval.poll_delta.InSeconds());
423    ASSERT_EQ(WaitInterval::EXPONENTIAL_BACKOFF, interval.mode);
424    ASSERT_FALSE(interval.had_nudge_during_backoff);
425    ASSERT_TRUE(continue_sync_cycle_param);
426
427    status.updates_received = 1;
428    interval = syncer_thread->CalculatePollingWaitTime(
429        status,
430        0,
431        &user_idle_milliseconds_param,
432        &continue_sync_cycle_param,
433        false);
434
435    ASSERT_EQ(SyncerThread::kDefaultShortPollIntervalSeconds,
436                interval.poll_delta.InSeconds());
437    ASSERT_EQ(WaitInterval::NORMAL, interval.mode);
438    ASSERT_FALSE(interval.had_nudge_during_backoff);
439    ASSERT_FALSE(continue_sync_cycle_param);
440  }
441
442  {
443    AllStatus::Status status = {};
444    status.unsynced_count = 1;
445    bool continue_sync_cycle_param = false;
446
447    WaitInterval interval = syncer_thread->CalculatePollingWaitTime(
448        status,
449        0,
450        &user_idle_milliseconds_param,
451        &continue_sync_cycle_param,
452        false);
453
454    ASSERT_LE(0, interval.poll_delta.InSeconds());
455    ASSERT_EQ(WaitInterval::NORMAL, interval.mode);
456    ASSERT_FALSE(interval.had_nudge_during_backoff);
457    ASSERT_TRUE(continue_sync_cycle_param);
458
459    continue_sync_cycle_param = false;
460    interval = syncer_thread->CalculatePollingWaitTime(
461        status,
462        0,
463        &user_idle_milliseconds_param,
464        &continue_sync_cycle_param,
465        false);
466
467    ASSERT_GE(2, interval.poll_delta.InSeconds());
468    ASSERT_EQ(WaitInterval::NORMAL, interval.mode);
469    ASSERT_FALSE(interval.had_nudge_during_backoff);
470    ASSERT_TRUE(continue_sync_cycle_param);
471
472    status.unsynced_count = 0;
473    interval = syncer_thread->CalculatePollingWaitTime(
474        status,
475        4,
476        &user_idle_milliseconds_param,
477        &continue_sync_cycle_param,
478        false);
479
480    ASSERT_EQ(SyncerThread::kDefaultShortPollIntervalSeconds,
481              interval.poll_delta.InSeconds());
482    ASSERT_EQ(WaitInterval::NORMAL, interval.mode);
483    ASSERT_FALSE(interval.had_nudge_during_backoff);
484    ASSERT_FALSE(continue_sync_cycle_param);
485  }
486
487  // Regression for exponential backoff reset when the syncer is nudged.
488  {
489    AllStatus::Status status = {};
490    status.unsynced_count = 1;
491    bool continue_sync_cycle_param = false;
492
493    // Expect move from default polling interval to exponential backoff due to
494    // unsynced_count != 0.
495    WaitInterval interval = syncer_thread->CalculatePollingWaitTime(
496        status,
497        3600,
498        &user_idle_milliseconds_param,
499        &continue_sync_cycle_param,
500        false);
501
502    ASSERT_LE(0, interval.poll_delta.InSeconds());
503    ASSERT_EQ(WaitInterval::NORMAL, interval.mode);
504    ASSERT_FALSE(interval.had_nudge_during_backoff);
505    ASSERT_TRUE(continue_sync_cycle_param);
506
507    continue_sync_cycle_param = false;
508    interval = syncer_thread->CalculatePollingWaitTime(
509        status,
510        3600,
511        &user_idle_milliseconds_param,
512        &continue_sync_cycle_param,
513        false);
514
515    ASSERT_GE(2, interval.poll_delta.InSeconds());
516    ASSERT_EQ(WaitInterval::NORMAL, interval.mode);
517    ASSERT_FALSE(interval.had_nudge_during_backoff);
518    ASSERT_TRUE(continue_sync_cycle_param);
519
520    // Expect exponential backoff.
521    interval = syncer_thread->CalculatePollingWaitTime(
522        status,
523        2,
524        &user_idle_milliseconds_param,
525        &continue_sync_cycle_param,
526        false);
527
528    ASSERT_LE(2, interval.poll_delta.InSeconds());
529    ASSERT_EQ(WaitInterval::EXPONENTIAL_BACKOFF, interval.mode);
530    ASSERT_FALSE(interval.had_nudge_during_backoff);
531    ASSERT_TRUE(continue_sync_cycle_param);
532
533    interval = syncer_thread->CalculatePollingWaitTime(
534        status,
535        2,
536        &user_idle_milliseconds_param,
537        &continue_sync_cycle_param,
538        false);
539
540    ASSERT_GE(6, interval.poll_delta.InSeconds());
541    ASSERT_EQ(WaitInterval::EXPONENTIAL_BACKOFF, interval.mode);
542    ASSERT_FALSE(interval.had_nudge_during_backoff);
543    ASSERT_TRUE(continue_sync_cycle_param);
544
545    syncer_thread->vault_.current_wait_interval_ = interval;
546
547    interval = syncer_thread->CalculatePollingWaitTime(
548        status,
549        static_cast<int>(interval.poll_delta.InSeconds()),
550        &user_idle_milliseconds_param,
551        &continue_sync_cycle_param,
552        true);
553
554    // Don't change poll on a failed nudge during backoff.
555    ASSERT_TRUE(syncer_thread->vault_.current_wait_interval_.poll_delta ==
556              interval.poll_delta);
557    ASSERT_EQ(WaitInterval::EXPONENTIAL_BACKOFF, interval.mode);
558    ASSERT_TRUE(interval.had_nudge_during_backoff);
559    ASSERT_TRUE(continue_sync_cycle_param);
560
561    // If we got a nudge and we weren't in backoff mode, we see exponential
562    // backoff.
563    syncer_thread->vault_.current_wait_interval_.mode = WaitInterval::NORMAL;
564    interval = syncer_thread->CalculatePollingWaitTime(
565        status,
566        2,
567        &user_idle_milliseconds_param,
568        &continue_sync_cycle_param,
569        true);
570
571    // 5 and 3 are bounds on the backoff randomization formula given input of 2.
572    ASSERT_GE(5, interval.poll_delta.InSeconds());
573    ASSERT_LE(3, interval.poll_delta.InSeconds());
574    ASSERT_EQ(WaitInterval::EXPONENTIAL_BACKOFF, interval.mode);
575    ASSERT_FALSE(interval.had_nudge_during_backoff);
576    ASSERT_TRUE(continue_sync_cycle_param);
577
578    // And if another interval expires, we get a bigger backoff.
579    WaitInterval new_interval = syncer_thread->CalculatePollingWaitTime(
580        status,
581        static_cast<int>(interval.poll_delta.InSeconds()),
582        &user_idle_milliseconds_param,
583        &continue_sync_cycle_param,
584        false);
585
586    ASSERT_GE(12, new_interval.poll_delta.InSeconds());
587    ASSERT_LE(5, new_interval.poll_delta.InSeconds());
588    ASSERT_EQ(WaitInterval::EXPONENTIAL_BACKOFF, interval.mode);
589    ASSERT_FALSE(new_interval.had_nudge_during_backoff);
590    ASSERT_TRUE(continue_sync_cycle_param);
591
592    // A nudge resets the continue_sync_cycle_param value, so our backoff
593    // should return to the minimum.
594    continue_sync_cycle_param = false;
595    interval = syncer_thread->CalculatePollingWaitTime(
596        status,
597        3600,
598        &user_idle_milliseconds_param,
599        &continue_sync_cycle_param,
600        true);
601
602    ASSERT_LE(0, interval.poll_delta.InSeconds());
603    ASSERT_EQ(WaitInterval::NORMAL, interval.mode);
604    ASSERT_FALSE(interval.had_nudge_during_backoff);
605    ASSERT_TRUE(continue_sync_cycle_param);
606
607    continue_sync_cycle_param = false;
608    interval = syncer_thread->CalculatePollingWaitTime(
609        status,
610        3600,
611        &user_idle_milliseconds_param,
612        &continue_sync_cycle_param,
613        true);
614
615    ASSERT_GE(2, interval.poll_delta.InSeconds());
616    ASSERT_EQ(WaitInterval::NORMAL, interval.mode);
617    ASSERT_FALSE(interval.had_nudge_during_backoff);
618    ASSERT_TRUE(continue_sync_cycle_param);
619
620    // Setting unsynced_count = 0 returns us to the default polling interval.
621    status.unsynced_count = 0;
622    interval = syncer_thread->CalculatePollingWaitTime(
623        status,
624        4,
625        &user_idle_milliseconds_param,
626        &continue_sync_cycle_param,
627        true);
628
629    ASSERT_EQ(SyncerThread::kDefaultShortPollIntervalSeconds,
630              interval.poll_delta.InSeconds());
631    ASSERT_EQ(WaitInterval::NORMAL, interval.mode);
632    ASSERT_FALSE(interval.had_nudge_during_backoff);
633    ASSERT_FALSE(continue_sync_cycle_param);
634  }
635}
636
637TEST_F(SyncerThreadWithSyncerTest, Polling) {
638  SyncShareIntercept interceptor;
639  connection()->SetMidCommitObserver(&interceptor);
640
641  const TimeDelta poll_interval = TimeDelta::FromSeconds(1);
642  syncer_thread()->SetSyncerShortPollInterval(poll_interval);
643  EXPECT_TRUE(syncer_thread()->Start());
644
645  // Calling Open() should cause the SyncerThread to create a Syncer.
646  metadb()->Open();
647
648  TimeDelta two_polls = poll_interval + poll_interval;
649  // We could theoretically return immediately from the wait if the interceptor
650  // was already signaled for a SyncShare (the first one comes quick).
651  interceptor.WaitForSyncShare(1, two_polls);
652  EXPECT_FALSE(interceptor.times_sync_occured().empty());
653
654  // Wait for at least 2 more SyncShare operations.
655  interceptor.WaitForSyncShare(2, two_polls);
656  EXPECT_TRUE(syncer_thread()->Stop(2000));
657
658  // Now analyze the run.
659  std::vector<TimeTicks> data = interceptor.times_sync_occured();
660
661  EXPECT_GE(data.size(), static_cast<unsigned int>(3));
662  for (unsigned int i = 0; i < data.size() - 1; i++) {
663    TimeTicks optimal_next_sync = data[i] + poll_interval;
664    EXPECT_TRUE(data[i + 1] >= optimal_next_sync);
665    // This should be reliable, as there are no blocking or I/O operations
666    // except the explicit 2 second wait, so if it takes longer than this
667    // there is a problem.
668    EXPECT_TRUE(data[i + 1] < optimal_next_sync + poll_interval);
669  }
670}
671
672TEST_F(SyncerThreadWithSyncerTest, Nudge) {
673  SyncShareIntercept interceptor;
674  connection()->SetMidCommitObserver(&interceptor);
675  // We don't want a poll to happen during this test (except the first one).
676  PreventThreadFromPolling();
677  EXPECT_TRUE(syncer_thread()->Start());
678  metadb()->Open();
679  const TimeDelta poll_interval = TimeDelta::FromMinutes(5);
680  interceptor.WaitForSyncShare(1, poll_interval + poll_interval);
681
682  EXPECT_EQ(static_cast<unsigned int>(1),
683            interceptor.times_sync_occured().size());
684  // The SyncerThread should be waiting for the poll now.  Nudge it to sync
685  // immediately (5ms).
686  syncer_thread()->NudgeSyncer(5, SyncerThread::kUnknown);
687  interceptor.WaitForSyncShare(1, TimeDelta::FromSeconds(1));
688  EXPECT_EQ(static_cast<unsigned int>(2),
689      interceptor.times_sync_occured().size());
690
691  // SyncerThread should be waiting again.  Signal it to stop.
692  EXPECT_TRUE(syncer_thread()->Stop(2000));
693}
694
695TEST_F(SyncerThreadWithSyncerTest, Throttling) {
696  SyncShareIntercept interceptor;
697  connection()->SetMidCommitObserver(&interceptor);
698  const TimeDelta poll_interval = TimeDelta::FromMilliseconds(10);
699  syncer_thread()->SetSyncerShortPollInterval(poll_interval);
700
701  EXPECT_TRUE(syncer_thread()->Start());
702  metadb()->Open();
703
704  // Wait for some healthy syncing.
705  interceptor.WaitForSyncShare(4, poll_interval + poll_interval);
706
707  // Tell the server to throttle a single request, which should be all it takes
708  // to silence our syncer (for 2 hours, so we shouldn't hit that in this test).
709  // This will atomically visit the interceptor so it can switch to throttled
710  // mode and fail on multiple requests.
711  connection()->ThrottleNextRequest(&interceptor);
712
713  // Try to trigger a sync (we have a really short poll interval already).
714  syncer_thread()->NudgeSyncer(0, SyncerThread::kUnknown);
715  syncer_thread()->NudgeSyncer(0, SyncerThread::kUnknown);
716
717  // Wait until the syncer thread reports that it is throttled.  Any further
718  // sync share interceptions will result in failure.  If things are broken,
719  // we may never halt.
720  ASSERT_TRUE(WaitForThrottle());
721  EXPECT_TRUE(syncer_thread()->IsSyncingCurrentlySilenced());
722
723  EXPECT_TRUE(syncer_thread()->Stop(2000));
724}
725
726TEST_F(SyncerThreadWithSyncerTest, StopSyncPermanently) {
727  // The SyncerThread should request an exit from the Syncer and set
728  // conditions for termination.
729  const TimeDelta poll_interval = TimeDelta::FromMilliseconds(10);
730  syncer_thread()->SetSyncerShortPollInterval(poll_interval);
731
732  ListenerMock listener;
733  WaitableEvent sync_cycle_ended_event(false, false);
734  WaitableEvent syncer_thread_exiting_event(false, false);
735  scoped_ptr<ChannelHookup<SyncerEvent> > hookup;
736  hookup.reset(syncer_thread()->relay_channel()->AddObserver(&listener));
737
738  EXPECT_CALL(listener, HandleChannelEvent(
739      Field(&SyncerEvent::what_happened, SyncerEvent::STATUS_CHANGED))).
740      Times(AnyNumber());
741
742  EXPECT_CALL(listener, HandleChannelEvent(
743      Field(&SyncerEvent::what_happened, SyncerEvent::SYNC_CYCLE_ENDED))).
744      Times(AnyNumber()).
745      WillOnce(SignalEvent(&sync_cycle_ended_event));
746
747  EXPECT_CALL(listener, HandleChannelEvent(
748      Field(&SyncerEvent::what_happened,
749          SyncerEvent::STOP_SYNCING_PERMANENTLY)));
750  EXPECT_CALL(listener, HandleChannelEvent(
751      Field(&SyncerEvent::what_happened, SyncerEvent::SYNCER_THREAD_EXITING))).
752      WillOnce(SignalEvent(&syncer_thread_exiting_event));
753
754  EXPECT_TRUE(syncer_thread()->Start());
755  metadb()->Open();
756  ASSERT_TRUE(sync_cycle_ended_event.TimedWait(max_wait_time_));
757
758  connection()->set_store_birthday("NotYourLuckyDay");
759  ASSERT_TRUE(syncer_thread_exiting_event.TimedWait(max_wait_time_));
760  EXPECT_TRUE(syncer_thread()->Stop(0));
761}
762
763TEST_F(SyncerThreadWithSyncerTest, AuthInvalid) {
764  SyncShareIntercept interceptor;
765  connection()->SetMidCommitObserver(&interceptor);
766  const TimeDelta poll_interval = TimeDelta::FromMilliseconds(1);
767
768  syncer_thread()->SetSyncerShortPollInterval(poll_interval);
769  EXPECT_TRUE(syncer_thread()->Start());
770  metadb()->Open();
771
772  // Wait for some healthy syncing.
773  interceptor.WaitForSyncShare(2, TimeDelta::FromSeconds(10));
774  EXPECT_GE(interceptor.times_sync_occured().size(), 2U);
775
776  // Atomically start returning auth invalid and set the interceptor to fail
777  // on any sync.
778  connection()->FailWithAuthInvalid(&interceptor);
779  WaitForDisconnect();
780
781  // Try to trigger a sync (the interceptor will assert if one occurs).
782  syncer_thread()->NudgeSyncer(0, SyncerThread::kUnknown);
783  syncer_thread()->NudgeSyncer(0, SyncerThread::kUnknown);
784
785  // Wait several poll intervals but don't expect any syncing besides the cycle
786  // that lost the connection.
787  interceptor.WaitForSyncShare(1, TimeDelta::FromSeconds(1));
788  EXPECT_EQ(1U, interceptor.times_sync_occured().size());
789
790  // Simulate a valid re-authentication and expect resumption of syncing.
791  interceptor.Reset();
792  ASSERT_TRUE(interceptor.times_sync_occured().empty());
793  connection()->StopFailingWithAuthInvalid(NULL);
794  ServerConnectionEvent e = {ServerConnectionEvent::STATUS_CHANGED,
795                             HttpResponse::SERVER_CONNECTION_OK,
796                             true};
797  connection()->channel()->NotifyListeners(e);
798
799  interceptor.WaitForSyncShare(1, TimeDelta::FromSeconds(10));
800  EXPECT_FALSE(interceptor.times_sync_occured().empty());
801
802  EXPECT_TRUE(syncer_thread()->Stop(2000));
803}
804
805// TODO(skrul): The "Pause" and "PauseWhenNotConnected" tests are
806// marked FLAKY because they sometimes fail on the Windows buildbots.
807// I have been unable to reproduce this hang after extensive testing
808// on a local Windows machine so these tests will remain flaky in
809// order to help diagnose the problem.
810TEST_F(SyncerThreadWithSyncerTest, FLAKY_Pause) {
811  WaitableEvent sync_cycle_ended_event(false, false);
812  WaitableEvent paused_event(false, false);
813  WaitableEvent resumed_event(false, false);
814  PreventThreadFromPolling();
815
816  ListenerMock listener;
817  scoped_ptr<ChannelHookup<SyncerEvent> > hookup;
818  hookup.reset(syncer_thread()->relay_channel()->AddObserver(&listener));
819
820  EXPECT_CALL(listener, HandleChannelEvent(
821      Field(&SyncerEvent::what_happened, SyncerEvent::STATUS_CHANGED))).
822      Times(AnyNumber());
823
824  // Wait for the initial sync to complete.
825  EXPECT_CALL(listener, HandleChannelEvent(
826      Field(&SyncerEvent::what_happened, SyncerEvent::SYNC_CYCLE_ENDED))).
827      WillOnce(SignalEvent(&sync_cycle_ended_event));
828  EXPECT_CALL(listener, HandleChannelEvent(
829      Field(&SyncerEvent::what_happened, SyncerEvent::SYNCER_THREAD_EXITING)));
830  ASSERT_TRUE(syncer_thread()->Start());
831  metadb()->Open();
832  ASSERT_TRUE(sync_cycle_ended_event.TimedWait(max_wait_time_));
833
834  // Request a pause.
835  ASSERT_TRUE(Pause(&listener));
836
837  // Resuming the pause.
838  ASSERT_TRUE(Resume(&listener));
839
840  // Not paused, should fail.
841  EXPECT_FALSE(syncer_thread()->RequestResume());
842
843  // Request a pause.
844  ASSERT_TRUE(Pause(&listener));
845
846  // Nudge the syncer, this should do nothing while we are paused.
847  syncer_thread()->NudgeSyncer(0, SyncerThread::kUnknown);
848
849  // Resuming will cause the nudge to be processed and a sync cycle to run.
850  EXPECT_CALL(listener, HandleChannelEvent(
851      Field(&SyncerEvent::what_happened, SyncerEvent::SYNC_CYCLE_ENDED))).
852      WillOnce(SignalEvent(&sync_cycle_ended_event));
853  ASSERT_TRUE(Resume(&listener));
854  ASSERT_TRUE(sync_cycle_ended_event.TimedWait(max_wait_time_));
855
856  EXPECT_TRUE(syncer_thread()->Stop(2000));
857}
858
859TEST_F(SyncerThreadWithSyncerTest, StartWhenNotConnected) {
860  WaitableEvent sync_cycle_ended_event(false, false);
861  WaitableEvent event(false, false);
862  ListenerMock listener;
863  scoped_ptr<ChannelHookup<SyncerEvent> > hookup;
864  hookup.reset(syncer_thread()->relay_channel()->AddObserver(&listener));
865  PreventThreadFromPolling();
866
867  EXPECT_CALL(listener, HandleChannelEvent(
868      Field(&SyncerEvent::what_happened, SyncerEvent::STATUS_CHANGED))).
869      Times(AnyNumber());
870  EXPECT_CALL(listener, HandleChannelEvent(
871      Field(&SyncerEvent::what_happened, SyncerEvent::SYNCER_THREAD_EXITING)));
872
873  connection()->SetServerNotReachable();
874  metadb()->Open();
875
876  // Syncer thread will always go through once cycle at the start,
877  // then it will wait for a connection.
878  EXPECT_CALL(listener, HandleChannelEvent(
879      Field(&SyncerEvent::what_happened, SyncerEvent::SYNC_CYCLE_ENDED))).
880      WillOnce(SignalEvent(&sync_cycle_ended_event));
881  EXPECT_CALL(listener, HandleChannelEvent(
882      Field(&SyncerEvent::what_happened, SyncerEvent::WAITING_FOR_CONNECTION))).
883      WillOnce(SignalEvent(&event));
884  ASSERT_TRUE(syncer_thread()->Start());
885  ASSERT_TRUE(sync_cycle_ended_event.TimedWait(max_wait_time_));
886  ASSERT_TRUE(event.TimedWait(max_wait_time_));
887
888  // Connect, will put the syncer thread into its usually poll wait.
889  EXPECT_CALL(listener, HandleChannelEvent(
890      Field(&SyncerEvent::what_happened, SyncerEvent::CONNECTED))).
891      WillOnce(SignalEvent(&event));
892  connection()->SetServerReachable();
893  ASSERT_TRUE(event.TimedWait(max_wait_time_));
894
895  // Nudge the syncer to complete a cycle.
896  EXPECT_CALL(listener, HandleChannelEvent(
897      Field(&SyncerEvent::what_happened, SyncerEvent::SYNC_CYCLE_ENDED))).
898      WillOnce(SignalEvent(&sync_cycle_ended_event));
899  syncer_thread()->NudgeSyncer(0, SyncerThread::kUnknown);
900  ASSERT_TRUE(sync_cycle_ended_event.TimedWait(max_wait_time_));
901
902  EXPECT_TRUE(syncer_thread()->Stop(2000));
903}
904
905// TODO(skrul): See TODO comment on the "Pause" test above for an
906// explanation of the usage of FLAKY here.
907// TODO(pinkerton): disabled due to hanging on test bots http://crbug.com/39070
908TEST_F(SyncerThreadWithSyncerTest, DISABLED_PauseWhenNotConnected) {
909  WaitableEvent sync_cycle_ended_event(false, false);
910  WaitableEvent event(false, false);
911  ListenerMock listener;
912  scoped_ptr<ChannelHookup<SyncerEvent> > hookup;
913  hookup.reset(syncer_thread()->relay_channel()->AddObserver(&listener));
914  PreventThreadFromPolling();
915
916  EXPECT_CALL(listener, HandleChannelEvent(
917      Field(&SyncerEvent::what_happened, SyncerEvent::STATUS_CHANGED))).
918      Times(AnyNumber());
919
920  // Put the thread into a "waiting for connection" state.
921  connection()->SetServerNotReachable();
922  EXPECT_CALL(listener, HandleChannelEvent(
923      Field(&SyncerEvent::what_happened, SyncerEvent::SYNC_CYCLE_ENDED))).
924      WillOnce(SignalEvent(&sync_cycle_ended_event));
925  EXPECT_CALL(listener, HandleChannelEvent(
926      Field(&SyncerEvent::what_happened, SyncerEvent::WAITING_FOR_CONNECTION))).
927      WillOnce(SignalEvent(&event));
928  metadb()->Open();
929  ASSERT_TRUE(syncer_thread()->Start());
930  ASSERT_TRUE(sync_cycle_ended_event.TimedWait(max_wait_time_));
931  ASSERT_TRUE(event.TimedWait(max_wait_time_));
932
933  // Pause and resume the thread while waiting for a connection.
934  ASSERT_TRUE(Pause(&listener));
935  ASSERT_TRUE(Resume(&listener));
936
937  // Make a connection and let the syncer cycle.
938  EXPECT_CALL(listener, HandleChannelEvent(
939      Field(&SyncerEvent::what_happened, SyncerEvent::SYNC_CYCLE_ENDED))).
940      WillOnce(SignalEvent(&sync_cycle_ended_event));
941  EXPECT_CALL(listener, HandleChannelEvent(
942      Field(&SyncerEvent::what_happened, SyncerEvent::CONNECTED))).
943      WillOnce(SignalEvent(&event));
944  connection()->SetServerReachable();
945  ASSERT_TRUE(event.TimedWait(max_wait_time_));
946  syncer_thread()->NudgeSyncer(0, SyncerThread::kUnknown);
947  ASSERT_TRUE(sync_cycle_ended_event.TimedWait(max_wait_time_));
948
949  // Disconnect and get into the waiting for a connection state.
950  EXPECT_CALL(listener, HandleChannelEvent(
951      Field(&SyncerEvent::what_happened, SyncerEvent::WAITING_FOR_CONNECTION))).
952      WillOnce(SignalEvent(&event));
953  connection()->SetServerNotReachable();
954  ASSERT_TRUE(event.TimedWait(max_wait_time_));
955
956  // Pause so we can test getting a connection while paused.
957  ASSERT_TRUE(Pause(&listener));
958
959  // Get a connection then resume.
960  EXPECT_CALL(listener, HandleChannelEvent(
961      Field(&SyncerEvent::what_happened, SyncerEvent::CONNECTED))).
962      WillOnce(SignalEvent(&event));
963  connection()->SetServerReachable();
964  ASSERT_TRUE(event.TimedWait(max_wait_time_));
965
966  ASSERT_TRUE(Resume(&listener));
967
968  // Cycle the syncer to show we are not longer paused.
969  EXPECT_CALL(listener, HandleChannelEvent(
970      Field(&SyncerEvent::what_happened, SyncerEvent::SYNC_CYCLE_ENDED))).
971      WillOnce(SignalEvent(&sync_cycle_ended_event));
972  EXPECT_CALL(listener, HandleChannelEvent(
973      Field(&SyncerEvent::what_happened, SyncerEvent::SYNCER_THREAD_EXITING)));
974
975  syncer_thread()->NudgeSyncer(0, SyncerThread::kUnknown);
976  ASSERT_TRUE(sync_cycle_ended_event.TimedWait(max_wait_time_));
977
978  EXPECT_TRUE(syncer_thread()->Stop(2000));
979}
980
981TEST_F(SyncerThreadWithSyncerTest, PauseResumeWhenNotRunning) {
982  WaitableEvent sync_cycle_ended_event(false, false);
983  WaitableEvent event(false, false);
984  ListenerMock listener;
985  scoped_ptr<ChannelHookup<SyncerEvent> > hookup;
986  hookup.reset(syncer_thread()->relay_channel()->AddObserver(&listener));
987  PreventThreadFromPolling();
988
989  EXPECT_CALL(listener, HandleChannelEvent(
990      Field(&SyncerEvent::what_happened, SyncerEvent::STATUS_CHANGED))).
991      Times(AnyNumber());
992
993  // Pause and resume the syncer while not running
994  ASSERT_TRUE(Pause(&listener));
995  ASSERT_TRUE(Resume(&listener));
996
997  // Pause the thread then start the syncer.
998  ASSERT_TRUE(Pause(&listener));
999  metadb()->Open();
1000  ASSERT_TRUE(syncer_thread()->Start());
1001
1002  // Resume and let the syncer cycle.
1003  EXPECT_CALL(listener, HandleChannelEvent(
1004      Field(&SyncerEvent::what_happened, SyncerEvent::SYNC_CYCLE_ENDED))).
1005      WillOnce(SignalEvent(&sync_cycle_ended_event));
1006  EXPECT_CALL(listener, HandleChannelEvent(
1007      Field(&SyncerEvent::what_happened, SyncerEvent::SYNCER_THREAD_EXITING)));
1008
1009  ASSERT_TRUE(Resume(&listener));
1010  ASSERT_TRUE(sync_cycle_ended_event.TimedWait(max_wait_time_));
1011  EXPECT_TRUE(syncer_thread()->Stop(2000));
1012}
1013
1014}  // namespace browser_sync
1015