• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1 // Copyright (c) 2010 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 "chrome/browser/sync/engine/process_commit_response_command.h"
6 
7 #include <set>
8 #include <string>
9 #include <vector>
10 
11 #include "base/basictypes.h"
12 #include "chrome/browser/sync/engine/syncer_proto_util.h"
13 #include "chrome/browser/sync/engine/syncer_util.h"
14 #include "chrome/browser/sync/engine/syncproto.h"
15 #include "chrome/browser/sync/sessions/sync_session.h"
16 #include "chrome/browser/sync/syncable/directory_manager.h"
17 #include "chrome/browser/sync/syncable/syncable.h"
18 
19 using syncable::ScopedDirLookup;
20 using syncable::WriteTransaction;
21 using syncable::MutableEntry;
22 using syncable::Entry;
23 
24 using std::set;
25 using std::string;
26 using std::vector;
27 
28 using syncable::BASE_VERSION;
29 using syncable::GET_BY_ID;
30 using syncable::ID;
31 using syncable::IS_DEL;
32 using syncable::IS_DIR;
33 using syncable::IS_UNAPPLIED_UPDATE;
34 using syncable::IS_UNSYNCED;
35 using syncable::PARENT_ID;
36 using syncable::SERVER_IS_DEL;
37 using syncable::SERVER_PARENT_ID;
38 using syncable::SERVER_POSITION_IN_PARENT;
39 using syncable::SERVER_VERSION;
40 using syncable::SYNCER;
41 using syncable::SYNCING;
42 
43 namespace browser_sync {
44 
45 using sessions::OrderedCommitSet;
46 using sessions::StatusController;
47 using sessions::SyncSession;
48 using sessions::ConflictProgress;
49 
IncrementErrorCounters(StatusController * status)50 void IncrementErrorCounters(StatusController* status) {
51   status->increment_num_consecutive_errors();
52 }
ResetErrorCounters(StatusController * status)53 void ResetErrorCounters(StatusController* status) {
54   status->set_num_consecutive_errors(0);
55 }
56 
ProcessCommitResponseCommand()57 ProcessCommitResponseCommand::ProcessCommitResponseCommand() {}
~ProcessCommitResponseCommand()58 ProcessCommitResponseCommand::~ProcessCommitResponseCommand() {}
59 
ModelNeutralExecuteImpl(sessions::SyncSession * session)60 bool ProcessCommitResponseCommand::ModelNeutralExecuteImpl(
61     sessions::SyncSession* session) {
62   ScopedDirLookup dir(session->context()->directory_manager(),
63                       session->context()->account_name());
64   if (!dir.good()) {
65     LOG(ERROR) << "Scoped dir lookup failed!";
66     return false;
67   }
68 
69   StatusController* status = session->status_controller();
70   const ClientToServerResponse& response(status->commit_response());
71   const vector<syncable::Id>& commit_ids(status->commit_ids());
72 
73   if (!response.has_commit()) {
74     // TODO(sync): What if we didn't try to commit anything?
75     LOG(WARNING) << "Commit response has no commit body!";
76     IncrementErrorCounters(status);
77     return false;
78   }
79 
80   const CommitResponse& cr = response.commit();
81   int commit_count = commit_ids.size();
82   if (cr.entryresponse_size() != commit_count) {
83     LOG(ERROR) << "Commit response has wrong number of entries! Expected:" <<
84                commit_count << " Got:" << cr.entryresponse_size();
85     for (int i = 0 ; i < cr.entryresponse_size() ; i++) {
86       LOG(ERROR) << "Response #" << i << " Value: " <<
87                  cr.entryresponse(i).response_type();
88       if (cr.entryresponse(i).has_error_message())
89         LOG(ERROR) << "  " << cr.entryresponse(i).error_message();
90     }
91     IncrementErrorCounters(status);
92     return false;
93   }
94   return true;
95 }
96 
ModelChangingExecuteImpl(SyncSession * session)97 void ProcessCommitResponseCommand::ModelChangingExecuteImpl(
98     SyncSession* session) {
99   ProcessCommitResponse(session);
100   ExtensionsActivityMonitor* monitor = session->context()->extensions_monitor();
101   if (session->status_controller()->HasBookmarkCommitActivity() &&
102       session->status_controller()->syncer_status()
103           .num_successful_bookmark_commits == 0) {
104     monitor->PutRecords(session->extensions_activity());
105     session->mutable_extensions_activity()->clear();
106   }
107 }
108 
ProcessCommitResponse(SyncSession * session)109 void ProcessCommitResponseCommand::ProcessCommitResponse(
110     SyncSession* session) {
111   // TODO(sync): This function returns if it sees problems. We probably want
112   // to flag the need for an update or similar.
113   ScopedDirLookup dir(session->context()->directory_manager(),
114                       session->context()->account_name());
115   if (!dir.good()) {
116     LOG(ERROR) << "Scoped dir lookup failed!";
117     return;
118   }
119 
120   StatusController* status = session->status_controller();
121   const ClientToServerResponse& response(status->commit_response());
122   const CommitResponse& cr = response.commit();
123   const sync_pb::CommitMessage& commit_message =
124       status->commit_message().commit();
125 
126   // If we try to commit a parent and child together and the parent conflicts
127   // the child will have a bad parent causing an error. As this is not a
128   // critical error, we trap it and don't LOG(ERROR). To enable this we keep
129   // a map of conflicting new folders.
130   int transient_error_commits = 0;
131   int conflicting_commits = 0;
132   int error_commits = 0;
133   int successes = 0;
134   set<syncable::Id> conflicting_new_folder_ids;
135   set<syncable::Id> deleted_folders;
136   ConflictProgress* conflict_progress = status->mutable_conflict_progress();
137   OrderedCommitSet::Projection proj = status->commit_id_projection();
138   if (!proj.empty()) { // Scope for WriteTransaction.
139     WriteTransaction trans(dir, SYNCER, __FILE__, __LINE__);
140     for (size_t i = 0; i < proj.size(); i++) {
141       CommitResponse::ResponseType response_type =
142           ProcessSingleCommitResponse(&trans, cr.entryresponse(proj[i]),
143                                       commit_message.entries(proj[i]),
144                                       status->GetCommitIdAt(proj[i]),
145                                       &conflicting_new_folder_ids,
146                                       &deleted_folders);
147       switch (response_type) {
148         case CommitResponse::INVALID_MESSAGE:
149           ++error_commits;
150           break;
151         case CommitResponse::CONFLICT:
152           ++conflicting_commits;
153           // Only server CONFLICT responses will activate conflict resolution.
154           conflict_progress->AddConflictingItemById(
155               status->GetCommitIdAt(proj[i]));
156           break;
157         case CommitResponse::SUCCESS:
158           // TODO(sync): worry about sync_rate_ rate calc?
159           ++successes;
160           if (status->GetCommitIdModelTypeAt(proj[i]) == syncable::BOOKMARKS)
161             status->increment_num_successful_bookmark_commits();
162           status->increment_num_successful_commits();
163           break;
164         case CommitResponse::OVER_QUOTA:
165           // We handle over quota like a retry, which is same as transient.
166         case CommitResponse::RETRY:
167         case CommitResponse::TRANSIENT_ERROR:
168           // TODO(tim): Now that we have SyncSession::Delegate, we
169           // should plumb this directly for exponential backoff purposes rather
170           // than trying to infer from HasMoreToSync(). See
171           // SyncerThread::CalculatePollingWaitTime.
172           ++transient_error_commits;
173           break;
174         default:
175           LOG(FATAL) << "Bad return from ProcessSingleCommitResponse";
176       }
177     }
178   }
179 
180   // TODO(sync): move status reporting elsewhere.
181   status->increment_num_conflicting_commits_by(conflicting_commits);
182   if (0 == successes) {
183     status->increment_num_consecutive_transient_error_commits_by(
184         transient_error_commits);
185     status->increment_num_consecutive_errors_by(transient_error_commits);
186   } else {
187     status->set_num_consecutive_transient_error_commits(0);
188     status->set_num_consecutive_errors(0);
189   }
190   int commit_count = static_cast<int>(proj.size());
191   if (commit_count != (conflicting_commits + error_commits +
192                        transient_error_commits)) {
193     ResetErrorCounters(status);
194   }
195   SyncerUtil::MarkDeletedChildrenSynced(dir, &deleted_folders);
196 
197   return;
198 }
199 
LogServerError(const CommitResponse_EntryResponse & res)200 void LogServerError(const CommitResponse_EntryResponse& res) {
201   if (res.has_error_message())
202     LOG(WARNING) << "  " << res.error_message();
203   else
204     LOG(WARNING) << "  No detailed error message returned from server";
205 }
206 
207 CommitResponse::ResponseType
ProcessSingleCommitResponse(syncable::WriteTransaction * trans,const sync_pb::CommitResponse_EntryResponse & pb_server_entry,const sync_pb::SyncEntity & commit_request_entry,const syncable::Id & pre_commit_id,std::set<syncable::Id> * conflicting_new_folder_ids,set<syncable::Id> * deleted_folders)208 ProcessCommitResponseCommand::ProcessSingleCommitResponse(
209     syncable::WriteTransaction* trans,
210     const sync_pb::CommitResponse_EntryResponse& pb_server_entry,
211     const sync_pb::SyncEntity& commit_request_entry,
212     const syncable::Id& pre_commit_id,
213     std::set<syncable::Id>* conflicting_new_folder_ids,
214     set<syncable::Id>* deleted_folders) {
215 
216   const CommitResponse_EntryResponse& server_entry =
217       *static_cast<const CommitResponse_EntryResponse*>(&pb_server_entry);
218   MutableEntry local_entry(trans, GET_BY_ID, pre_commit_id);
219   CHECK(local_entry.good());
220   bool syncing_was_set = local_entry.Get(SYNCING);
221   local_entry.Put(SYNCING, false);
222 
223   CommitResponse::ResponseType response = (CommitResponse::ResponseType)
224       server_entry.response_type();
225   if (!CommitResponse::ResponseType_IsValid(response)) {
226     LOG(ERROR) << "Commit response has unknown response type! Possibly out "
227                "of date client?";
228     return CommitResponse::INVALID_MESSAGE;
229   }
230   if (CommitResponse::TRANSIENT_ERROR == response) {
231     VLOG(1) << "Transient Error Committing: " << local_entry;
232     LogServerError(server_entry);
233     return CommitResponse::TRANSIENT_ERROR;
234   }
235   if (CommitResponse::INVALID_MESSAGE == response) {
236     LOG(ERROR) << "Error Commiting: " << local_entry;
237     LogServerError(server_entry);
238     return response;
239   }
240   if (CommitResponse::CONFLICT == response) {
241     VLOG(1) << "Conflict Committing: " << local_entry;
242     // TODO(nick): conflicting_new_folder_ids is a purposeless anachronism.
243     if (!pre_commit_id.ServerKnows() && local_entry.Get(IS_DIR)) {
244       conflicting_new_folder_ids->insert(pre_commit_id);
245     }
246     return response;
247   }
248   if (CommitResponse::RETRY == response) {
249     VLOG(1) << "Retry Committing: " << local_entry;
250     return response;
251   }
252   if (CommitResponse::OVER_QUOTA == response) {
253     LOG(WARNING) << "Hit deprecated OVER_QUOTA Committing: " << local_entry;
254     return response;
255   }
256   if (!server_entry.has_id_string()) {
257     LOG(ERROR) << "Commit response has no id";
258     return CommitResponse::INVALID_MESSAGE;
259   }
260 
261   // Implied by the IsValid call above, but here for clarity.
262   DCHECK_EQ(CommitResponse::SUCCESS, response) << response;
263   // Check to see if we've been given the ID of an existing entry. If so treat
264   // it as an error response and retry later.
265   if (pre_commit_id != server_entry.id()) {
266     Entry e(trans, GET_BY_ID, server_entry.id());
267     if (e.good()) {
268       LOG(ERROR) << "Got duplicate id when commiting id: " << pre_commit_id <<
269                  ". Treating as an error return";
270       return CommitResponse::INVALID_MESSAGE;
271     }
272   }
273 
274   if (server_entry.version() == 0) {
275     LOG(WARNING) << "Server returned a zero version on a commit response.";
276   }
277 
278   ProcessSuccessfulCommitResponse(commit_request_entry, server_entry,
279       pre_commit_id, &local_entry, syncing_was_set, deleted_folders);
280   return response;
281 }
282 
GetResultingPostCommitName(const sync_pb::SyncEntity & committed_entry,const CommitResponse_EntryResponse & entry_response)283 const string& ProcessCommitResponseCommand::GetResultingPostCommitName(
284     const sync_pb::SyncEntity& committed_entry,
285     const CommitResponse_EntryResponse& entry_response) {
286   const string& response_name =
287       SyncerProtoUtil::NameFromCommitEntryResponse(entry_response);
288   if (!response_name.empty())
289     return response_name;
290   return SyncerProtoUtil::NameFromSyncEntity(committed_entry);
291 }
292 
UpdateVersionAfterCommit(const sync_pb::SyncEntity & committed_entry,const CommitResponse_EntryResponse & entry_response,const syncable::Id & pre_commit_id,syncable::MutableEntry * local_entry)293 bool ProcessCommitResponseCommand::UpdateVersionAfterCommit(
294     const sync_pb::SyncEntity& committed_entry,
295     const CommitResponse_EntryResponse& entry_response,
296     const syncable::Id& pre_commit_id,
297     syncable::MutableEntry* local_entry) {
298   int64 old_version = local_entry->Get(BASE_VERSION);
299   int64 new_version = entry_response.version();
300   bool bad_commit_version = false;
301   if (committed_entry.deleted() &&
302       !local_entry->Get(syncable::UNIQUE_CLIENT_TAG).empty()) {
303     // If the item was deleted, and it's undeletable (uses the client tag),
304     // change the version back to zero.  We must set the version to zero so
305     // that the server knows to re-create the item if it gets committed
306     // later for undeletion.
307     new_version = 0;
308   } else if (!pre_commit_id.ServerKnows()) {
309     bad_commit_version = 0 == new_version;
310   } else {
311     bad_commit_version = old_version > new_version;
312   }
313   if (bad_commit_version) {
314     LOG(ERROR) << "Bad version in commit return for " << *local_entry
315                << " new_id:" << entry_response.id() << " new_version:"
316                << entry_response.version();
317     return false;
318   }
319 
320   // Update the base version and server version.  The base version must change
321   // here, even if syncing_was_set is false; that's because local changes were
322   // on top of the successfully committed version.
323   local_entry->Put(BASE_VERSION, new_version);
324   VLOG(1) << "Commit is changing base version of " << local_entry->Get(ID)
325           << " to: " << new_version;
326   local_entry->Put(SERVER_VERSION, new_version);
327   return true;
328 }
329 
ChangeIdAfterCommit(const CommitResponse_EntryResponse & entry_response,const syncable::Id & pre_commit_id,syncable::MutableEntry * local_entry)330 bool ProcessCommitResponseCommand::ChangeIdAfterCommit(
331     const CommitResponse_EntryResponse& entry_response,
332     const syncable::Id& pre_commit_id,
333     syncable::MutableEntry* local_entry) {
334   syncable::WriteTransaction* trans = local_entry->write_transaction();
335   if (entry_response.id() != pre_commit_id) {
336     if (pre_commit_id.ServerKnows()) {
337       // The server can sometimes generate a new ID on commit; for example,
338       // when committing an undeletion.
339       VLOG(1) << " ID changed while committing an old entry. "
340               << pre_commit_id << " became " << entry_response.id() << ".";
341     }
342     MutableEntry same_id(trans, GET_BY_ID, entry_response.id());
343     // We should trap this before this function.
344     if (same_id.good()) {
345       LOG(ERROR) << "ID clash with id " << entry_response.id()
346                  << " during commit " << same_id;
347       return false;
348     }
349     SyncerUtil::ChangeEntryIDAndUpdateChildren(
350         trans, local_entry, entry_response.id());
351     VLOG(1) << "Changing ID to " << entry_response.id();
352   }
353   return true;
354 }
355 
UpdateServerFieldsAfterCommit(const sync_pb::SyncEntity & committed_entry,const CommitResponse_EntryResponse & entry_response,syncable::MutableEntry * local_entry)356 void ProcessCommitResponseCommand::UpdateServerFieldsAfterCommit(
357     const sync_pb::SyncEntity& committed_entry,
358     const CommitResponse_EntryResponse& entry_response,
359     syncable::MutableEntry* local_entry) {
360 
361   // We just committed an entry successfully, and now we want to make our view
362   // of the server state consistent with the server state. We must be careful;
363   // |entry_response| and |committed_entry| have some identically named
364   // fields.  We only want to consider fields from |committed_entry| when there
365   // is not an overriding field in the |entry_response|.  We do not want to
366   // update the server data from the local data in the entry -- it's possible
367   // that the local data changed during the commit, and even if not, the server
368   // has the last word on the values of several properties.
369 
370   local_entry->Put(SERVER_IS_DEL, committed_entry.deleted());
371   if (committed_entry.deleted()) {
372     // Don't clobber any other fields of deleted objects.
373     return;
374   }
375 
376   local_entry->Put(syncable::SERVER_IS_DIR,
377       (committed_entry.folder() ||
378        committed_entry.bookmarkdata().bookmark_folder()));
379   local_entry->Put(syncable::SERVER_SPECIFICS,
380       committed_entry.specifics());
381   local_entry->Put(syncable::SERVER_MTIME,
382       committed_entry.mtime());
383   local_entry->Put(syncable::SERVER_CTIME,
384       committed_entry.ctime());
385   local_entry->Put(syncable::SERVER_POSITION_IN_PARENT,
386       entry_response.position_in_parent());
387   // TODO(nick): The server doesn't set entry_response.server_parent_id in
388   // practice; to update SERVER_PARENT_ID appropriately here we'd need to
389   // get the post-commit ID of the parent indicated by
390   // committed_entry.parent_id_string(). That should be inferrable from the
391   // information we have, but it's a bit convoluted to pull it out directly.
392   // Getting this right is important: SERVER_PARENT_ID gets fed back into
393   // old_parent_id during the next commit.
394   local_entry->Put(syncable::SERVER_PARENT_ID,
395       local_entry->Get(syncable::PARENT_ID));
396   local_entry->Put(syncable::SERVER_NON_UNIQUE_NAME,
397       GetResultingPostCommitName(committed_entry, entry_response));
398 
399   if (local_entry->Get(IS_UNAPPLIED_UPDATE)) {
400     // This shouldn't happen; an unapplied update shouldn't be committed, and
401     // if it were, the commit should have failed.  But if it does happen: we've
402     // just overwritten the update info, so clear the flag.
403     local_entry->Put(IS_UNAPPLIED_UPDATE, false);
404   }
405 }
406 
OverrideClientFieldsAfterCommit(const sync_pb::SyncEntity & committed_entry,const CommitResponse_EntryResponse & entry_response,syncable::MutableEntry * local_entry)407 void ProcessCommitResponseCommand::OverrideClientFieldsAfterCommit(
408     const sync_pb::SyncEntity& committed_entry,
409     const CommitResponse_EntryResponse& entry_response,
410     syncable::MutableEntry* local_entry) {
411   if (committed_entry.deleted()) {
412     // If an entry's been deleted, nothing else matters.
413     DCHECK(local_entry->Get(IS_DEL));
414     return;
415   }
416 
417   // Update the name.
418   const string& server_name =
419       GetResultingPostCommitName(committed_entry, entry_response);
420   const string& old_name =
421       local_entry->Get(syncable::NON_UNIQUE_NAME);
422 
423   if (!server_name.empty() && old_name != server_name) {
424     VLOG(1) << "During commit, server changed name: " << old_name
425             << " to new name: " << server_name;
426     local_entry->Put(syncable::NON_UNIQUE_NAME, server_name);
427   }
428 
429   // The server has the final say on positioning, so apply the absolute
430   // position that it returns.
431   if (entry_response.has_position_in_parent()) {
432     // The SERVER_ field should already have been written.
433     DCHECK_EQ(entry_response.position_in_parent(),
434         local_entry->Get(SERVER_POSITION_IN_PARENT));
435 
436     // We just committed successfully, so we assume that the position
437     // value we got applies to the PARENT_ID we submitted.
438     syncable::Id new_prev = local_entry->ComputePrevIdFromServerPosition(
439         local_entry->Get(PARENT_ID));
440     if (!local_entry->PutPredecessor(new_prev))
441       LOG(WARNING) << "PutPredecessor failed after successful commit";
442   }
443 }
444 
ProcessSuccessfulCommitResponse(const sync_pb::SyncEntity & committed_entry,const CommitResponse_EntryResponse & entry_response,const syncable::Id & pre_commit_id,syncable::MutableEntry * local_entry,bool syncing_was_set,set<syncable::Id> * deleted_folders)445 void ProcessCommitResponseCommand::ProcessSuccessfulCommitResponse(
446     const sync_pb::SyncEntity& committed_entry,
447     const CommitResponse_EntryResponse& entry_response,
448     const syncable::Id& pre_commit_id, syncable::MutableEntry* local_entry,
449     bool syncing_was_set, set<syncable::Id>* deleted_folders) {
450   DCHECK(local_entry->Get(IS_UNSYNCED));
451 
452   // Update SERVER_VERSION and BASE_VERSION.
453   if (!UpdateVersionAfterCommit(committed_entry, entry_response, pre_commit_id,
454                                 local_entry)) {
455     LOG(ERROR) << "Bad version in commit return for " << *local_entry
456                << " new_id:" << entry_response.id() << " new_version:"
457                << entry_response.version();
458     return;
459   }
460 
461   // If the server gave us a new ID, apply it.
462   if (!ChangeIdAfterCommit(entry_response, pre_commit_id, local_entry)) {
463     return;
464   }
465 
466   // Update our stored copy of the server state.
467   UpdateServerFieldsAfterCommit(committed_entry, entry_response, local_entry);
468 
469   // If the item doesn't need to be committed again (an item might need to be
470   // committed again if it changed locally during the commit), we can remove
471   // it from the unsynced list.  Also, we should change the locally-
472   // visible properties to apply any canonicalizations or fixups
473   // that the server introduced during the commit.
474   if (syncing_was_set) {
475     OverrideClientFieldsAfterCommit(committed_entry, entry_response,
476                                     local_entry);
477     local_entry->Put(IS_UNSYNCED, false);
478   }
479 
480   // Make a note of any deleted folders, whose children would have
481   // been recursively deleted.
482   // TODO(nick): Here, commit_message.deleted() would be more correct than
483   // local_entry->Get(IS_DEL).  For example, an item could be renamed, and then
484   // deleted during the commit of the rename.  Unit test & fix.
485   if (local_entry->Get(IS_DIR) && local_entry->Get(IS_DEL)) {
486     deleted_folders->insert(local_entry->Get(ID));
487   }
488 }
489 
490 }  // namespace browser_sync
491