sync: Introduce support for split transaction apply/commit changes. Change_processors can now perform I/O heavy work in a commitchanges phase during which the syncable::WriteTransaction lock is not held, thereby not janking the UI. AutofillChangeProcessor updated to make use of this.

Added ServerChangeRace test to ProfileSyncServiceAutofillTest in order test newfound jank-lessness. Simulates a server initiated change with modified UnlockAndLog which puts thread to sleep before completion so a syncapi initiated change can happen. Then, a second "server" change posts before first has completed. Test succeeds if all three entries are successfully created.

BUG=53601
TEST=unit_tests --gtest_filter="*ServerChangeRace*"

Original patch by zea@chromium.org
Original review: http://codereview.chromium.org/3326015/show

Review URL: http://codereview.chromium.org/3480002

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@60315 0039d316-1c4b-4281-b951-d872f2087c98

10 files changed, 416 insertions, 42 deletions

diff --git a/chrome/browser/sync/engine/syncapi.cc b/chrome/browser/sync/engine/syncapi.cc
index 97ab4e8..4728534 100644
--- a/chrome/browser/sync/engine/syncapi.cc
+++ b/chrome/browser/sync/engine/syncapi.cc
@@ -6,6 +6,7 @@
 
 #include "build/build_config.h"
 
+#include <bitset>
 #include <iomanip>
 #include <list>
 #include <string>
@@ -963,6 +964,8 @@ class SyncManager::SyncInternal
   // builds the list of sync-engine initiated changes that will be forwarded to
   // the SyncManager's Observers.
   virtual void HandleChannelEvent(const syncable::DirectoryChangeEvent& event);
+  void HandleTransactionCompleteChangeEvent(
+      const syncable::DirectoryChangeEvent& event);
   void HandleTransactionEndingChangeEvent(
       const syncable::DirectoryChangeEvent& event);
   void HandleCalculateChangesChangeEventFromSyncApi(
@@ -1160,9 +1163,17 @@ class SyncManager::SyncInternal
   // HandleChangeEvent during the CALCULATE_CHANGES step.  The changes are
   // segregated by model type, and are stored here to be processed and
   // forwarded to the observer slightly later, at the TRANSACTION_ENDING
-  // step by HandleTransactionEndingChangeEvent.
+  // step by HandleTransactionEndingChangeEvent. The list is cleared in the
+  // TRANSACTION_COMPLETE step by HandleTransactionCompleteChangeEvent.
   ChangeReorderBuffer change_buffers_[syncable::MODEL_TYPE_COUNT];
 
+  // Bit vector keeping track of which models need to have their
+  // OnChangesComplete observer set.
+  //
+  // Set by HandleTransactionEndingChangeEvent, cleared in
+  // HandleTransactionCompleteChangeEvent.
+  std::bitset<syncable::MODEL_TYPE_COUNT> model_has_change_;
+
   // The event listener hookup that is registered for HandleChangeEvent.
   scoped_ptr<browser_sync::ChannelHookup<syncable::DirectoryChangeEvent> >
       dir_change_hookup_;
@@ -1604,7 +1615,11 @@ void SyncManager::SyncInternal::OnIPAddressChanged() {
 // ApplyUpdates) to data_->changelist.
 void SyncManager::SyncInternal::HandleChannelEvent(
     const syncable::DirectoryChangeEvent& event) {
-  if (event.todo == syncable::DirectoryChangeEvent::TRANSACTION_ENDING) {
+  if (event.todo == syncable::DirectoryChangeEvent::TRANSACTION_COMPLETE) {
+    // Safe to perform slow I/O operations now, go ahead and commit.
+    HandleTransactionCompleteChangeEvent(event);
+    return;
+  } else if (event.todo == syncable::DirectoryChangeEvent::TRANSACTION_ENDING) {
     HandleTransactionEndingChangeEvent(event);
     return;
   } else if (event.todo == syncable::DirectoryChangeEvent::CALCULATE_CHANGES) {
@@ -1619,6 +1634,24 @@ void SyncManager::SyncInternal::HandleChannelEvent(
   }
 }
 
+void SyncManager::SyncInternal::HandleTransactionCompleteChangeEvent(
+    const syncable::DirectoryChangeEvent& event) {
+  // This notification happens immediately after the channel mutex is released
+  // This allows work to be performed without holding the WriteTransaction lock
+  // but before the transaction is finished.
+  DCHECK_EQ(event.todo, syncable::DirectoryChangeEvent::TRANSACTION_COMPLETE);
+  if (!observer_)
+    return;
+
+  // Call commit
+  for (int i = 0; i < syncable::MODEL_TYPE_COUNT; ++i) {
+    if (model_has_change_.test(i)) {
+      observer_->OnChangesComplete(syncable::ModelTypeFromInt(i));
+      model_has_change_.reset(i);
+    }
+  }
+}
+
 void SyncManager::SyncInternal::HandleServerConnectionEvent(
     const ServerConnectionEvent& event) {
   allstatus_.HandleServerConnectionEvent(event);
@@ -1662,6 +1695,7 @@ void SyncManager::SyncInternal::HandleTransactionEndingChangeEvent(
     if (!ordered_changes.empty()) {
       observer_->OnChangesApplied(syncable::ModelTypeFromInt(i), &trans,
                                   &ordered_changes[0], ordered_changes.size());
+      model_has_change_.set(i, true);
     }
     change_buffers_[i].Clear();
   }
diff --git a/chrome/browser/sync/engine/syncapi.h b/chrome/browser/sync/engine/syncapi.h
index e34b1f9..8ffd729 100644
--- a/chrome/browser/sync/engine/syncapi.h
+++ b/chrome/browser/sync/engine/syncapi.h
@@ -691,6 +691,19 @@ class SyncManager {
                                   const ChangeRecord* changes,
                                   int change_count) = 0;
 
+    // OnChangesComplete gets called when the TransactionComplete event is
+    // posted (after OnChangesApplied finishes), after the transaction lock
+    // and the change channel mutex are released.
+    //
+    // The purpose of this function is to support processors that require
+    // split-transactions changes. For example, if a model processor wants to
+    // perform blocking I/O due to a change, it should calculate the changes
+    // while holding the transaction lock (from within OnChangesApplied), buffer
+    // those changes, let the transaction fall out of scope, and then commit
+    // those changes from within OnChangesComplete (postponing the blocking
+    // I/O to when it no longer holds any lock).
+    virtual void OnChangesComplete(syncable::ModelType model_type) = 0;
+
     // A round-trip sync-cycle took place and the syncer has resolved any
     // conflicts that may have arisen.
     virtual void OnSyncCycleCompleted(
diff --git a/chrome/browser/sync/glue/autofill_change_processor.cc b/chrome/browser/sync/glue/autofill_change_processor.cc
index b7db1a1..aac46c0 100644
--- a/chrome/browser/sync/glue/autofill_change_processor.cc
+++ b/chrome/browser/sync/glue/autofill_change_processor.cc
@@ -305,7 +305,6 @@ void AutofillChangeProcessor::ApplyChangesFromSyncModel(
     return;
   }
 
-  std::vector<AutofillEntry> new_entries;
   for (int i = 0; i < change_count; ++i) {
     sync_api::SyncManager::ChangeRecord::Action action(changes[i].action);
     if (sync_api::SyncManager::ChangeRecord::ACTION_DELETE == action) {
@@ -313,12 +312,13 @@ void AutofillChangeProcessor::ApplyChangesFromSyncModel(
           << "Autofill specifics data not present on delete!";
       const sync_pb::AutofillSpecifics& autofill =
           changes[i].specifics.GetExtension(sync_pb::autofill);
-      if (autofill.has_value())
-        ApplySyncAutofillEntryDelete(autofill);
-      else if (autofill.has_profile())
-        ApplySyncAutofillProfileDelete(autofill.profile(), changes[i].id);
-      else
+      if (autofill.has_value() || autofill.has_profile()) {
+        autofill_changes_.push_back(AutofillChangeRecord(changes[i].action,
+                                                         changes[i].id,
+                                                         autofill));
+      } else {
         NOTREACHED() << "Autofill specifics has no data!";
+      }
       continue;
     }
 
@@ -337,17 +337,59 @@ void AutofillChangeProcessor::ApplyChangesFromSyncModel(
     const sync_pb::AutofillSpecifics& autofill(
         sync_node.GetAutofillSpecifics());
     int64 sync_id = sync_node.GetId();
-    if (autofill.has_value())
-      ApplySyncAutofillEntryChange(action, autofill, &new_entries, sync_id);
-    else if (autofill.has_profile())
-      ApplySyncAutofillProfileChange(action, autofill.profile(), sync_id);
-    else
+    if (autofill.has_value() || autofill.has_profile()) {
+      autofill_changes_.push_back(AutofillChangeRecord(changes[i].action,
+                                                       sync_id, autofill));
+    } else {
       NOTREACHED() << "Autofill specifics has no data!";
+    }
+  }
+
+  StartObserving();
+}
+
+void AutofillChangeProcessor::CommitChangesFromSyncModel() {
+  DCHECK(ChromeThread::CurrentlyOn(ChromeThread::DB));
+  if (!running())
+    return;
+  StopObserving();
+
+  std::vector<AutofillEntry> new_entries;
+  for (unsigned int i = 0; i < autofill_changes_.size(); i++) {
+    // Handle deletions.
+    if (sync_api::SyncManager::ChangeRecord::ACTION_DELETE ==
+        autofill_changes_[i].action_) {
+      if (autofill_changes_[i].autofill_.has_value()) {
+        ApplySyncAutofillEntryDelete(autofill_changes_[i].autofill_);
+      } else if (autofill_changes_[i].autofill_.has_profile()) {
+        ApplySyncAutofillProfileDelete(autofill_changes_[i].autofill_.profile(),
+                                       autofill_changes_[i].id_);
+      } else {
+        NOTREACHED() << "Autofill's CommitChanges received change with no"
+            " data!";
+      }
+      continue;
+    }
+
+    // Handle update/adds.
+    if (autofill_changes_[i].autofill_.has_value()) {
+      ApplySyncAutofillEntryChange(autofill_changes_[i].action_,
+                                   autofill_changes_[i].autofill_, &new_entries,
+                                   autofill_changes_[i].id_);
+    } else if (autofill_changes_[i].autofill_.has_profile()) {
+      ApplySyncAutofillProfileChange(autofill_changes_[i].action_,
+                                     autofill_changes_[i].autofill_.profile(),
+                                     autofill_changes_[i].id_);
+    } else {
+      NOTREACHED() << "Autofill's CommitChanges received change with no data!";
+    }
   }
+  autofill_changes_.clear();
 
+  // Make changes
   if (!web_database_->UpdateAutofillEntries(new_entries)) {
     error_handler()->OnUnrecoverableError(FROM_HERE,
-        "Could not update autofill entries.");
+                                          "Could not update autofill entries.");
     return;
   }
 
diff --git a/chrome/browser/sync/glue/autofill_change_processor.h b/chrome/browser/sync/glue/autofill_change_processor.h
index bcc2d88..0680d0c 100644
--- a/chrome/browser/sync/glue/autofill_change_processor.h
+++ b/chrome/browser/sync/glue/autofill_change_processor.h
@@ -6,6 +6,8 @@
 #define CHROME_BROWSER_SYNC_GLUE_AUTOFILL_CHANGE_PROCESSOR_H_
 #pragma once
 
+#include <vector>
+
 #include "chrome/browser/autofill/autofill_profile.h"
 #include "chrome/browser/autofill/credit_card.h"
 #include "chrome/browser/autofill/personal_data_manager.h"
@@ -52,6 +54,10 @@ class AutofillChangeProcessor : public ChangeProcessor,
       const sync_api::SyncManager::ChangeRecord* changes,
       int change_count);
 
+  // Commit any changes from ApplyChangesFromSyncModel buffered in
+  // autofill_changes_.
+  virtual void CommitChangesFromSyncModel();
+
   // Copy the properties of the given Autofill entry into the sync
   // node.
   static void WriteAutofillEntry(const AutofillEntry& entry,
@@ -67,6 +73,17 @@ class AutofillChangeProcessor : public ChangeProcessor,
   virtual void StopImpl();
 
  private:
+  struct AutofillChangeRecord {
+    sync_api::SyncManager::ChangeRecord::Action action_;
+    int64 id_;
+    sync_pb::AutofillSpecifics autofill_;
+    AutofillChangeRecord(sync_api::SyncManager::ChangeRecord::Action action,
+                         int64 id, const sync_pb::AutofillSpecifics& autofill)
+        : action_(action),
+          id_(id),
+          autofill_(autofill) { }
+  };
+
   void StartObserving();
   void StopObserving();
 
@@ -151,6 +168,10 @@ class AutofillChangeProcessor : public ChangeProcessor,
 
   bool observing_;
 
+  // Record of changes from ApplyChangesFromSyncModel. These are then processed
+  // in CommitChangesFromSyncModel.
+  std::vector<AutofillChangeRecord> autofill_changes_;
+
   DISALLOW_COPY_AND_ASSIGN(AutofillChangeProcessor);
 };
 
diff --git a/chrome/browser/sync/glue/change_processor.h b/chrome/browser/sync/glue/change_processor.h
index eb10f3e..4d6ec09 100644
--- a/chrome/browser/sync/glue/change_processor.h
+++ b/chrome/browser/sync/glue/change_processor.h
@@ -44,6 +44,13 @@ class ChangeProcessor {
       const sync_api::SyncManager::ChangeRecord* changes,
       int change_count) = 0;
 
+  // The changes found in ApplyChangesFromSyncModel may be too slow to be
+  // performed while holding a [Read/Write]Transaction lock. This function
+  // is called once the lock is released and performs any slow I/O operations
+  // without unnecessarily slowing the UI. Note that not all datatypes need
+  // this, so we provide an empty default version.
+  virtual void CommitChangesFromSyncModel() { }
+
  protected:
   // These methods are invoked by Start() and Stop() to do
   // implementation-specific work.
diff --git a/chrome/browser/sync/glue/sync_backend_host.cc b/chrome/browser/sync/glue/sync_backend_host.cc
index 149f5c4..74a8c47 100644
--- a/chrome/browser/sync/glue/sync_backend_host.cc
+++ b/chrome/browser/sync/glue/sync_backend_host.cc
@@ -118,7 +118,7 @@ void SyncBackendHost::Initialize(
   // TODO(tim): This should be encryption-specific instead of passwords
   // specific.  For now we have to do this to avoid NIGORI node lookups when
   // we haven't downloaded that node.
-  if (profile_->GetPrefs()->GetBoolean(prefs::kSyncPasswords) ) {
+  if (profile_->GetPrefs()->GetBoolean(prefs::kSyncPasswords)) {
     registrar_.routing_info[syncable::NIGORI] = GROUP_PASSIVE;
   }
 
@@ -521,16 +521,8 @@ void SyncBackendHost::Core::DoShutdown(bool sync_disabled) {
   host_ = NULL;
 }
 
-void SyncBackendHost::Core::OnChangesApplied(
-    syncable::ModelType model_type,
-    const sync_api::BaseTransaction* trans,
-    const sync_api::SyncManager::ChangeRecord* changes,
-    int change_count) {
-  if (!host_ || !host_->frontend_) {
-    DCHECK(false) << "OnChangesApplied called after Shutdown?";
-    return;
-  }
-
+ChangeProcessor* SyncBackendHost::Core::GetProcessor(
+    syncable::ModelType model_type) {
   std::map<syncable::ModelType, ChangeProcessor*>::const_iterator it =
       host_->processors_.find(model_type);
 
@@ -542,11 +534,11 @@ void SyncBackendHost::Core::OnChangesApplied(
   // the UI thread so we will never drop any changes after model
   // association.
   if (it == host_->processors_.end())
-    return;
+    return NULL;
 
   if (!IsCurrentThreadSafeForModel(model_type)) {
     NOTREACHED() << "Changes applied on wrong thread.";
-    return;
+    return NULL;
   }
 
   // Now that we're sure we're on the correct thread, we can access the
@@ -555,11 +547,44 @@ void SyncBackendHost::Core::OnChangesApplied(
 
   // Ensure the change processor is willing to accept changes.
   if (!processor->IsRunning())
+    return NULL;
+
+  return processor;
+}
+
+void SyncBackendHost::Core::OnChangesApplied(
+    syncable::ModelType model_type,
+    const sync_api::BaseTransaction* trans,
+    const sync_api::SyncManager::ChangeRecord* changes,
+    int change_count) {
+  if (!host_ || !host_->frontend_) {
+    DCHECK(false) << "OnChangesApplied called after Shutdown?";
+    return;
+  }
+  ChangeProcessor* processor = GetProcessor(model_type);
+  if (!processor)
     return;
 
   processor->ApplyChangesFromSyncModel(trans, changes, change_count);
 }
 
+void SyncBackendHost::Core::OnChangesComplete(
+    syncable::ModelType model_type) {
+  if (!host_ || !host_->frontend_) {
+    DCHECK(false) << "OnChangesComplete called after Shutdown?";
+    return;
+  }
+
+  ChangeProcessor* processor = GetProcessor(model_type);
+  if (!processor)
+    return;
+
+  // This call just notifies the processor that it can commit, it already
+  // buffered any changes it plans to makes so needs no further information.
+  processor->CommitChangesFromSyncModel();
+}
+
+
 void SyncBackendHost::Core::OnSyncCycleCompleted(
     const SyncSessionSnapshot* snapshot) {
   host_->frontend_loop_->PostTask(FROM_HERE, NewRunnableMethod(this,
diff --git a/chrome/browser/sync/glue/sync_backend_host.h b/chrome/browser/sync/glue/sync_backend_host.h
index 3cd75ce..3da5648 100644
--- a/chrome/browser/sync/glue/sync_backend_host.h
+++ b/chrome/browser/sync/glue/sync_backend_host.h
@@ -206,6 +206,7 @@ class SyncBackendHost : public browser_sync::ModelSafeWorkerRegistrar {
         const sync_api::BaseTransaction* trans,
         const sync_api::SyncManager::ChangeRecord* changes,
         int change_count);
+    virtual void OnChangesComplete(syncable::ModelType model_type);
     virtual void OnSyncCycleCompleted(
         const sessions::SyncSessionSnapshot* snapshot);
     virtual void OnInitializationComplete();
@@ -324,6 +325,10 @@ class SyncBackendHost : public browser_sync::ModelSafeWorkerRegistrar {
 
     ~Core();
 
+    // Return change processor for a particular model (return NULL on failure).
+    ChangeProcessor* GetProcessor(syncable::ModelType modeltype);
+
+
     // Sends a SYNC_PAUSED notification to the notification service on
     // the UI thread.
     void NotifyPaused();
diff --git a/chrome/browser/sync/profile_sync_service_autofill_unittest.cc b/chrome/browser/sync/profile_sync_service_autofill_unittest.cc
index 3691905..1d5d7d4 100644
--- a/chrome/browser/sync/profile_sync_service_autofill_unittest.cc
+++ b/chrome/browser/sync/profile_sync_service_autofill_unittest.cc
@@ -8,6 +8,7 @@
 
 #include "testing/gtest/include/gtest/gtest.h"
 
+#include "base/callback.h"
 #include "base/message_loop.h"
 #include "base/ref_counted.h"
 #include "base/scoped_ptr.h"
@@ -15,10 +16,13 @@
 #include "base/task.h"
 #include "base/time.h"
 #include "base/utf_string_conversions.h"
+#include "base/waitable_event.h"
 #include "chrome/browser/autofill/autofill_common_unittest.h"
 #include "chrome/browser/chrome_thread.h"
 #include "chrome/browser/sync/abstract_profile_sync_service_test.h"
+#include "chrome/browser/sync/engine/model_changing_syncer_command.h"
 #include "chrome/browser/sync/engine/syncapi.h"
+#include "chrome/browser/sync/engine/syncer_util.h"
 #include "chrome/browser/sync/glue/autofill_change_processor.h"
 #include "chrome/browser/sync/glue/autofill_data_type_controller.h"
 #include "chrome/browser/sync/glue/autofill_model_associator.h"
@@ -26,6 +30,7 @@
 #include "chrome/browser/sync/profile_sync_service.h"
 #include "chrome/browser/sync/profile_sync_test_util.h"
 #include "chrome/browser/sync/protocol/autofill_specifics.pb.h"
+#include "chrome/browser/sync/syncable/syncable.h"
 #include "chrome/browser/sync/syncable/model_type.h"
 #include "chrome/browser/sync/test_profile_sync_service.h"
 #include "chrome/browser/webdata/autofill_change.h"
@@ -35,13 +40,28 @@
 #include "chrome/common/notification_source.h"
 #include "chrome/common/notification_type.h"
 #include "chrome/test/profile_mock.h"
+#include "chrome/test/sync/engine/test_id_factory.h"
 #include "testing/gmock/include/gmock/gmock.h"
 
 using base::Time;
+using base::WaitableEvent;
 using browser_sync::AutofillChangeProcessor;
 using browser_sync::AutofillDataTypeController;
 using browser_sync::AutofillModelAssociator;
+using browser_sync::GROUP_DB;
+using browser_sync::kAutofillTag;
 using browser_sync::SyncBackendHostForProfileSyncTest;
+using browser_sync::SyncerUtil;
+using browser_sync::UnrecoverableErrorHandler;
+using syncable::CREATE_NEW_UPDATE_ITEM;
+using syncable::AUTOFILL;
+using syncable::DirectoryChangeEvent;
+using syncable::GET_BY_SERVER_TAG;
+using syncable::INVALID;
+using syncable::SERVER_PARENT_ID;
+using syncable::SERVER_SPECIFICS;
+using syncable::OriginalEntries;
+using syncable::WriterTag;
 using syncable::WriteTransaction;
 using testing::_;
 using testing::DoAll;
@@ -54,6 +74,10 @@ using testing::Return;
 using testing::SaveArg;
 using testing::SetArgumentPointee;
 
+namespace syncable {
+class Id;
+}
+
 class WebDatabaseMock : public WebDatabase {
  public:
   MOCK_METHOD2(RemoveFormElement,
@@ -277,6 +301,7 @@ class ProfileSyncServiceAutofillTest : public AbstractProfileSyncServiceTest {
   }
 
   friend class AddAutofillEntriesTask;
+  friend class FakeServerUpdater;
 
   ChromeThread db_thread_;
   scoped_refptr<ThreadNotificationService> notification_service_;
@@ -318,6 +343,139 @@ class AddAutofillEntriesTask : public Task {
   bool success_;
 };
 
+// Overload write transaction to use custom NotifyTransactionComplete
+static const bool kLoggingInfo = true;
+class WriteTransactionTest: public WriteTransaction {
+ public:
+  WriteTransactionTest(const ScopedDirLookup& directory,
+                       WriterTag writer, const char* source_file,
+                       int line,
+                       scoped_ptr<WaitableEvent> *wait_for_syncapi)
+      : WriteTransaction(directory, writer, source_file, line),
+        wait_for_syncapi_(wait_for_syncapi) { }
+
+  virtual void NotifyTransactionComplete() {
+    // This is where we differ. Force a thread change here, giving another
+    // thread a chance to create a WriteTransaction
+    (*wait_for_syncapi_)->Wait();
+
+    WriteTransaction::NotifyTransactionComplete();
+  }
+
+ private:
+  scoped_ptr<WaitableEvent> *wait_for_syncapi_;
+};
+
+// Our fake server updater. Needs the RefCountedThreadSafe inheritance so we can
+// post tasks with it.
+class FakeServerUpdater: public base::RefCountedThreadSafe<FakeServerUpdater> {
+ public:
+  FakeServerUpdater(TestProfileSyncService *service,
+                    scoped_ptr<WaitableEvent> *wait_for_start,
+                    scoped_ptr<WaitableEvent> *wait_for_syncapi)
+      : entry_(ProfileSyncServiceAutofillTest::MakeAutofillEntry("0", "0", 0)),
+        service_(service),
+        wait_for_start_(wait_for_start),
+        wait_for_syncapi_(wait_for_syncapi),
+        is_finished_(false, false) { }
+
+  void Update() {
+    // This gets called in a modelsafeworker thread.
+    ASSERT_TRUE(ChromeThread::CurrentlyOn(ChromeThread::DB));
+
+    UserShare* user_share = service_->backend()->GetUserShareHandle();
+    DirectoryManager* dir_manager = user_share->dir_manager.get();
+    ScopedDirLookup dir(dir_manager, user_share->name);
+    ASSERT_TRUE(dir.good());
+
+    // Create autofill protobuf
+    std::string tag = AutofillModelAssociator::KeyToTag(entry_.key().name(),
+                                                        entry_.key().value());
+    sync_pb::AutofillSpecifics new_autofill;
+    new_autofill.set_name(UTF16ToUTF8(entry_.key().name()));
+    new_autofill.set_value(UTF16ToUTF8(entry_.key().value()));
+    const std::vector<base::Time>& ts(entry_.timestamps());
+    for (std::vector<base::Time>::const_iterator timestamp = ts.begin();
+         timestamp != ts.end(); ++timestamp) {
+      new_autofill.add_usage_timestamp(timestamp->ToInternalValue());
+    }
+
+    sync_pb::EntitySpecifics entity_specifics;
+    entity_specifics.MutableExtension(sync_pb::autofill)->
+        CopyFrom(new_autofill);
+
+    {
+      // Tell main thread we've started
+      (*wait_for_start_)->Signal();
+
+      // Create write transaction.
+      WriteTransactionTest trans(dir, UNITTEST, __FILE__, __LINE__,
+                                 wait_for_syncapi_);
+
+      // Create actual entry based on autofill protobuf information.
+      // Simulates effects of SyncerUtil::UpdateLocalDataFromServerData
+      MutableEntry parent(&trans, GET_BY_SERVER_TAG, kAutofillTag);
+      MutableEntry item(&trans, CREATE, parent.Get(syncable::ID), tag);
+      ASSERT_TRUE(item.good());
+      item.Put(SPECIFICS, entity_specifics);
+      item.Put(SERVER_SPECIFICS, entity_specifics);
+      item.Put(BASE_VERSION, 1);
+      syncable::Id server_parent_id = ids_.NewServerId();
+      item.Put(syncable::ID, server_parent_id);
+      syncable::Id new_predecessor =
+          SyncerUtil::ComputePrevIdFromServerPosition(&trans, &item,
+          server_parent_id);
+      ASSERT_TRUE(item.PutPredecessor(new_predecessor));
+    }
+    LOG(INFO) << "FakeServerUpdater finishing.";
+    is_finished_.Signal();
+  }
+
+  void CreateNewEntry(const AutofillEntry& entry) {
+    entry_ = entry;
+    scoped_ptr<Callback0::Type> c(NewCallback((FakeServerUpdater *)this,
+                                              &FakeServerUpdater::Update));
+    std::vector<browser_sync::ModelSafeWorker*> workers;
+    service_->backend()->GetWorkers(&workers);
+
+    ASSERT_FALSE(ChromeThread::CurrentlyOn(ChromeThread::DB));
+    if (!ChromeThread::PostTask(ChromeThread::DB, FROM_HERE,
+         NewRunnableMethod(this, &FakeServerUpdater::Update))) {
+      NOTREACHED() << "Failed to post task to the db thread.";
+      return;
+    }
+  }
+
+  void CreateNewEntryAndWait(const AutofillEntry& entry) {
+    entry_ = entry;
+    scoped_ptr<Callback0::Type> c(NewCallback((FakeServerUpdater *)this,
+                                              &FakeServerUpdater::Update));
+    std::vector<browser_sync::ModelSafeWorker*> workers;
+    service_->backend()->GetWorkers(&workers);
+
+    ASSERT_FALSE(ChromeThread::CurrentlyOn(ChromeThread::DB));
+    is_finished_.Reset();
+    if (!ChromeThread::PostTask(ChromeThread::DB, FROM_HERE,
+         NewRunnableMethod(this, &FakeServerUpdater::Update))) {
+      NOTREACHED() << "Failed to post task to the db thread.";
+      return;
+    }
+    is_finished_.Wait();
+  }
+
+ private:
+  friend class base::RefCountedThreadSafe<FakeServerUpdater>;
+  ~FakeServerUpdater() { }
+
+  AutofillEntry entry_;
+  TestProfileSyncService *service_;
+  scoped_ptr<WaitableEvent> *wait_for_start_;
+  scoped_ptr<WaitableEvent> *wait_for_syncapi_;
+  WaitableEvent is_finished_;
+  syncable::Id parent_id_;
+  TestIdFactory ids_;
+};
+
 // TODO(skrul): Test abort startup.
 // TODO(skrul): Test processing of cloud changes.
 // TODO(tim): Add autofill data type controller test, and a case to cover
@@ -1005,3 +1163,46 @@ TEST_F(ProfileSyncServiceAutofillTest, ProcessUserChangeError) {
                    Source<WebDataService>(web_data_service_.get()),
                    Details<AutofillChangeList>(&changes));
 }
+
+TEST_F(ProfileSyncServiceAutofillTest, ServerChangeRace) {
+  EXPECT_CALL(web_database_, GetAllAutofillEntries(_)).WillOnce(Return(true));
+  EXPECT_CALL(web_database_, GetAutoFillProfiles(_)).WillOnce(Return(true));
+  EXPECT_CALL(web_database_, UpdateAutofillEntries(_)).
+      WillRepeatedly(Return(true));
+  EXPECT_CALL(*personal_data_manager_, Refresh()).Times(3);
+  CreateRootTask task(this, syncable::AUTOFILL);
+  StartSyncService(&task, false);
+  ASSERT_TRUE(task.success());
+
+  // (true, false) means we have to reset after |Signal|, init to unsignaled.
+  scoped_ptr<WaitableEvent> wait_for_start(new WaitableEvent(true, false));
+  scoped_ptr<WaitableEvent> wait_for_syncapi(new WaitableEvent(true, false));
+  scoped_refptr<FakeServerUpdater> updater = new FakeServerUpdater(
+      service_.get(), &wait_for_start, &wait_for_syncapi);
+
+  // This server side update will stall waiting for CommitWaiter.
+  updater->CreateNewEntry(MakeAutofillEntry("server", "entry", 1));
+  wait_for_start->Wait();
+
+  AutofillEntry syncapi_entry(MakeAutofillEntry("syncapi", "entry", 2));
+  ASSERT_TRUE(AddAutofillSyncNode(syncapi_entry));
+  LOG(INFO) << "Syncapi update finished.";
+
+  // If we reach here, it means syncapi succeeded and we didn't deadlock. Yay!
+  // Signal FakeServerUpdater that it can complete.
+  wait_for_syncapi->Signal();
+
+  // Make another entry to ensure nothing broke afterwards and wait for finish
+  // to clean up.
+  updater->CreateNewEntryAndWait(MakeAutofillEntry("server2", "entry2", 3));
+
+  std::vector<AutofillEntry> sync_entries;
+  std::vector<AutoFillProfile> sync_profiles;
+  ASSERT_TRUE(GetAutofillEntriesFromSyncDB(&sync_entries, &sync_profiles));
+  EXPECT_EQ(3U, sync_entries.size());
+  EXPECT_EQ(0U, sync_profiles.size());
+  for (size_t i = 0; i < sync_entries.size(); i++) {
+    LOG(INFO) << "Entry " << i << ": " << sync_entries[i].key().name() << ", "
+              << sync_entries[i].key().value();
+  }
+}
diff --git a/chrome/browser/sync/syncable/syncable.cc b/chrome/browser/sync/syncable/syncable.cc
index a711f55..d1fd9d6 100644
--- a/chrome/browser/sync/syncable/syncable.cc
+++ b/chrome/browser/sync/syncable/syncable.cc
@@ -963,6 +963,19 @@ BaseTransaction::BaseTransaction(Directory* directory, const char* name,
 BaseTransaction::~BaseTransaction() {}
 
 void BaseTransaction::UnlockAndLog(OriginalEntries* originals_arg) {
+  // Triggers the CALCULATE_CHANGES and TRANSACTION_ENDING events while
+  // holding dir_kernel_'s transaction_mutex and changes_channel mutex.
+  // Releases all mutexes upon completion.
+  if (!NotifyTransactionChangingAndEnding(originals_arg)) {
+    return;
+  }
+
+  // Triggers the TRANSACTION_COMPLETE event (and does not hold any mutexes).
+  NotifyTransactionComplete();
+}
+
+bool BaseTransaction::NotifyTransactionChangingAndEnding(
+    OriginalEntries* originals_arg) {
   dirkernel_->transaction_mutex.AssertAcquired();
 
   scoped_ptr<OriginalEntries> originals(originals_arg);
@@ -975,26 +988,37 @@ void BaseTransaction::UnlockAndLog(OriginalEntries* originals_arg) {
 
   if (NULL == originals.get() || originals->empty()) {
     dirkernel_->transaction_mutex.Release();
-    return;
+    return false;
   }
 
-  AutoLock scoped_lock(dirkernel_->changes_channel_mutex);
-  // Tell listeners to calculate changes while we still have the mutex.
-  DirectoryChangeEvent event = { DirectoryChangeEvent::CALCULATE_CHANGES,
-                                 originals.get(), this, writer_ };
-  dirkernel_->changes_channel.Notify(event);
 
-  // Necessary for reads to be performed prior to transaction mutex release.
-  // Allows the listener to use the current transaction to perform reads.
-  DirectoryChangeEvent ending_event =
-      { DirectoryChangeEvent::TRANSACTION_ENDING,
-        NULL, this, INVALID };
-  dirkernel_->changes_channel.Notify(ending_event);
+  {
+    // Scoped_lock is only active through the calculate_changes and
+    // transaction_ending events.
+    AutoLock scoped_lock(dirkernel_->changes_channel_mutex);
+
+    // Tell listeners to calculate changes while we still have the mutex.
+    DirectoryChangeEvent event = { DirectoryChangeEvent::CALCULATE_CHANGES,
+                                   originals.get(), this, writer_ };
+    dirkernel_->changes_channel.Notify(event);
+
+    // Necessary for reads to be performed prior to transaction mutex release.
+    // Allows the listener to use the current transaction to perform reads.
+    DirectoryChangeEvent ending_event =
+        { DirectoryChangeEvent::TRANSACTION_ENDING,
+          NULL, this, INVALID };
+    dirkernel_->changes_channel.Notify(ending_event);
+
+    dirkernel_->transaction_mutex.Release();
+  }
 
-  dirkernel_->transaction_mutex.Release();
+  return true;
+}
 
-  // Directly after transaction mutex release, but lock on changes channel.
-  // You cannot be re-entrant to a transaction in this handler.
+void BaseTransaction::NotifyTransactionComplete() {
+  // Transaction is no longer holding any locks/mutexes, notify that we're
+  // complete (and commit any outstanding changes that should not be performed
+  // while holding mutexes).
   DirectoryChangeEvent complete_event =
       { DirectoryChangeEvent::TRANSACTION_COMPLETE,
         NULL, NULL, INVALID };
diff --git a/chrome/browser/sync/syncable/syncable.h b/chrome/browser/sync/syncable/syncable.h
index cbdd03a..7cdae1c 100644
--- a/chrome/browser/sync/syncable/syncable.h
+++ b/chrome/browser/sync/syncable/syncable.h
@@ -1053,6 +1053,8 @@ class BaseTransaction {
                   const char* source_file, int line, WriterTag writer);
 
   void UnlockAndLog(OriginalEntries* entries);
+  bool NotifyTransactionChangingAndEnding(OriginalEntries* entries);
+  virtual void NotifyTransactionComplete();
 
   Directory* const directory_;
   Directory::Kernel* const dirkernel_;  // for brevity