1 // Copyright 2012 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 "sync/engine/process_commit_response_command.h" 6 7 #include <cstddef> 8 #include <set> 9 #include <string> 10 #include <vector> 11 12 #include "base/basictypes.h" 13 #include "base/location.h" 14 #include "sync/engine/syncer_proto_util.h" 15 #include "sync/engine/syncer_util.h" 16 #include "sync/internal_api/public/base/unique_position.h" 17 #include "sync/sessions/sync_session.h" 18 #include "sync/syncable/entry.h" 19 #include "sync/syncable/mutable_entry.h" 20 #include "sync/syncable/syncable_proto_util.h" 21 #include "sync/syncable/syncable_read_transaction.h" 22 #include "sync/syncable/syncable_util.h" 23 #include "sync/syncable/syncable_write_transaction.h" 24 #include "sync/util/time.h" 25 26 using std::set; 27 using std::string; 28 using std::vector; 29 using sync_pb::CommitResponse; 30 31 namespace syncer { 32 33 using sessions::OrderedCommitSet; 34 using sessions::StatusController; 35 using sessions::SyncSession; 36 using syncable::WriteTransaction; 37 using syncable::MutableEntry; 38 using syncable::Entry; 39 using syncable::BASE_VERSION; 40 using syncable::GET_BY_ID; 41 using syncable::ID; 42 using syncable::IS_DEL; 43 using syncable::IS_DIR; 44 using syncable::IS_UNAPPLIED_UPDATE; 45 using syncable::IS_UNSYNCED; 46 using syncable::PARENT_ID; 47 using syncable::SERVER_IS_DEL; 48 using syncable::SERVER_PARENT_ID; 49 using syncable::SERVER_VERSION; 50 using syncable::SYNCER; 51 using syncable::SYNCING; 52 53 ProcessCommitResponseCommand::ProcessCommitResponseCommand( 54 const sessions::OrderedCommitSet& commit_set, 55 const sync_pb::ClientToServerMessage& commit_message, 56 const sync_pb::ClientToServerResponse& commit_response) 57 : commit_set_(commit_set), 58 commit_message_(commit_message), 59 commit_response_(commit_response) { 60 } 61 62 ProcessCommitResponseCommand::~ProcessCommitResponseCommand() {} 63 64 std::set<ModelSafeGroup> ProcessCommitResponseCommand::GetGroupsToChange( 65 const sessions::SyncSession& session) const { 66 std::set<ModelSafeGroup> groups_with_commits; 67 68 syncable::Directory* dir = session.context()->directory(); 69 syncable::ReadTransaction trans(FROM_HERE, dir); 70 for (size_t i = 0; i < commit_set_.Size(); ++i) { 71 groups_with_commits.insert( 72 GetGroupForModelType(commit_set_.GetModelTypeAt(i), 73 session.context()->routing_info())); 74 } 75 76 return groups_with_commits; 77 } 78 79 80 SyncerError ProcessCommitResponseCommand::ModelChangingExecuteImpl( 81 SyncSession* session) { 82 syncable::Directory* dir = session->context()->directory(); 83 StatusController* status = session->mutable_status_controller(); 84 const CommitResponse& cr = commit_response_.commit(); 85 const sync_pb::CommitMessage& commit_message = commit_message_.commit(); 86 87 int transient_error_commits = 0; 88 int conflicting_commits = 0; 89 int error_commits = 0; 90 int successes = 0; 91 92 set<syncable::Id> deleted_folders; 93 OrderedCommitSet::Projection proj = status->commit_id_projection( 94 commit_set_); 95 96 if (!proj.empty()) { // Scope for WriteTransaction. 97 WriteTransaction trans(FROM_HERE, SYNCER, dir); 98 for (size_t i = 0; i < proj.size(); i++) { 99 CommitResponse::ResponseType response_type = ProcessSingleCommitResponse( 100 &trans, 101 cr.entryresponse(proj[i]), 102 commit_message.entries(proj[i]), 103 commit_set_.GetCommitIdAt(proj[i]), 104 &deleted_folders); 105 switch (response_type) { 106 case CommitResponse::INVALID_MESSAGE: 107 ++error_commits; 108 break; 109 case CommitResponse::CONFLICT: 110 ++conflicting_commits; 111 status->increment_num_server_conflicts(); 112 break; 113 case CommitResponse::SUCCESS: 114 // TODO(sync): worry about sync_rate_ rate calc? 115 ++successes; 116 if (commit_set_.GetModelTypeAt(proj[i]) == BOOKMARKS) 117 status->increment_num_successful_bookmark_commits(); 118 status->increment_num_successful_commits(); 119 break; 120 case CommitResponse::OVER_QUOTA: 121 // We handle over quota like a retry, which is same as transient. 122 case CommitResponse::RETRY: 123 case CommitResponse::TRANSIENT_ERROR: 124 ++transient_error_commits; 125 break; 126 default: 127 LOG(FATAL) << "Bad return from ProcessSingleCommitResponse"; 128 } 129 } 130 } 131 132 MarkDeletedChildrenSynced(dir, &deleted_folders); 133 134 int commit_count = static_cast<int>(proj.size()); 135 if (commit_count == successes) { 136 return SYNCER_OK; 137 } else if (error_commits > 0) { 138 return SERVER_RETURN_UNKNOWN_ERROR; 139 } else if (transient_error_commits > 0) { 140 return SERVER_RETURN_TRANSIENT_ERROR; 141 } else if (conflicting_commits > 0) { 142 // This means that the server already has an item with this version, but 143 // we haven't seen that update yet. 144 // 145 // A well-behaved client should respond to this by proceeding to the 146 // download updates phase, fetching the conflicting items, then attempting 147 // to resolve the conflict. That's not what this client does. 148 // 149 // We don't currently have any code to support that exceptional control 150 // flow. Instead, we abort the current sync cycle and start a new one. The 151 // end result is the same. 152 return SERVER_RETURN_CONFLICT; 153 } else { 154 LOG(FATAL) << "Inconsistent counts when processing commit response"; 155 return SYNCER_OK; 156 } 157 } 158 159 void LogServerError(const sync_pb::CommitResponse_EntryResponse& res) { 160 if (res.has_error_message()) 161 LOG(WARNING) << " " << res.error_message(); 162 else 163 LOG(WARNING) << " No detailed error message returned from server"; 164 } 165 166 CommitResponse::ResponseType 167 ProcessCommitResponseCommand::ProcessSingleCommitResponse( 168 syncable::WriteTransaction* trans, 169 const sync_pb::CommitResponse_EntryResponse& server_entry, 170 const sync_pb::SyncEntity& commit_request_entry, 171 const syncable::Id& pre_commit_id, 172 set<syncable::Id>* deleted_folders) { 173 174 MutableEntry local_entry(trans, GET_BY_ID, pre_commit_id); 175 CHECK(local_entry.good()); 176 bool syncing_was_set = local_entry.Get(SYNCING); 177 local_entry.Put(SYNCING, false); 178 179 CommitResponse::ResponseType response = (CommitResponse::ResponseType) 180 server_entry.response_type(); 181 if (!CommitResponse::ResponseType_IsValid(response)) { 182 LOG(ERROR) << "Commit response has unknown response type! Possibly out " 183 "of date client?"; 184 return CommitResponse::INVALID_MESSAGE; 185 } 186 if (CommitResponse::TRANSIENT_ERROR == response) { 187 DVLOG(1) << "Transient Error Committing: " << local_entry; 188 LogServerError(server_entry); 189 return CommitResponse::TRANSIENT_ERROR; 190 } 191 if (CommitResponse::INVALID_MESSAGE == response) { 192 LOG(ERROR) << "Error Commiting: " << local_entry; 193 LogServerError(server_entry); 194 return response; 195 } 196 if (CommitResponse::CONFLICT == response) { 197 DVLOG(1) << "Conflict Committing: " << local_entry; 198 return response; 199 } 200 if (CommitResponse::RETRY == response) { 201 DVLOG(1) << "Retry Committing: " << local_entry; 202 return response; 203 } 204 if (CommitResponse::OVER_QUOTA == response) { 205 LOG(WARNING) << "Hit deprecated OVER_QUOTA Committing: " << local_entry; 206 return response; 207 } 208 if (!server_entry.has_id_string()) { 209 LOG(ERROR) << "Commit response has no id"; 210 return CommitResponse::INVALID_MESSAGE; 211 } 212 213 // Implied by the IsValid call above, but here for clarity. 214 DCHECK_EQ(CommitResponse::SUCCESS, response) << response; 215 // Check to see if we've been given the ID of an existing entry. If so treat 216 // it as an error response and retry later. 217 const syncable::Id& server_entry_id = 218 SyncableIdFromProto(server_entry.id_string()); 219 if (pre_commit_id != server_entry_id) { 220 Entry e(trans, GET_BY_ID, server_entry_id); 221 if (e.good()) { 222 LOG(ERROR) << "Got duplicate id when commiting id: " << pre_commit_id << 223 ". Treating as an error return"; 224 return CommitResponse::INVALID_MESSAGE; 225 } 226 } 227 228 if (server_entry.version() == 0) { 229 LOG(WARNING) << "Server returned a zero version on a commit response."; 230 } 231 232 ProcessSuccessfulCommitResponse(commit_request_entry, server_entry, 233 pre_commit_id, &local_entry, syncing_was_set, deleted_folders); 234 return response; 235 } 236 237 const string& ProcessCommitResponseCommand::GetResultingPostCommitName( 238 const sync_pb::SyncEntity& committed_entry, 239 const sync_pb::CommitResponse_EntryResponse& entry_response) { 240 const string& response_name = 241 SyncerProtoUtil::NameFromCommitEntryResponse(entry_response); 242 if (!response_name.empty()) 243 return response_name; 244 return SyncerProtoUtil::NameFromSyncEntity(committed_entry); 245 } 246 247 bool ProcessCommitResponseCommand::UpdateVersionAfterCommit( 248 const sync_pb::SyncEntity& committed_entry, 249 const sync_pb::CommitResponse_EntryResponse& entry_response, 250 const syncable::Id& pre_commit_id, 251 syncable::MutableEntry* local_entry) { 252 int64 old_version = local_entry->Get(BASE_VERSION); 253 int64 new_version = entry_response.version(); 254 bool bad_commit_version = false; 255 if (committed_entry.deleted() && 256 !local_entry->Get(syncable::UNIQUE_CLIENT_TAG).empty()) { 257 // If the item was deleted, and it's undeletable (uses the client tag), 258 // change the version back to zero. We must set the version to zero so 259 // that the server knows to re-create the item if it gets committed 260 // later for undeletion. 261 new_version = 0; 262 } else if (!pre_commit_id.ServerKnows()) { 263 bad_commit_version = 0 == new_version; 264 } else { 265 bad_commit_version = old_version > new_version; 266 } 267 if (bad_commit_version) { 268 LOG(ERROR) << "Bad version in commit return for " << *local_entry 269 << " new_id:" << SyncableIdFromProto(entry_response.id_string()) 270 << " new_version:" << entry_response.version(); 271 return false; 272 } 273 274 // Update the base version and server version. The base version must change 275 // here, even if syncing_was_set is false; that's because local changes were 276 // on top of the successfully committed version. 277 local_entry->Put(BASE_VERSION, new_version); 278 DVLOG(1) << "Commit is changing base version of " << local_entry->Get(ID) 279 << " to: " << new_version; 280 local_entry->Put(SERVER_VERSION, new_version); 281 return true; 282 } 283 284 bool ProcessCommitResponseCommand::ChangeIdAfterCommit( 285 const sync_pb::CommitResponse_EntryResponse& entry_response, 286 const syncable::Id& pre_commit_id, 287 syncable::MutableEntry* local_entry) { 288 syncable::WriteTransaction* trans = local_entry->write_transaction(); 289 const syncable::Id& entry_response_id = 290 SyncableIdFromProto(entry_response.id_string()); 291 if (entry_response_id != pre_commit_id) { 292 if (pre_commit_id.ServerKnows()) { 293 // The server can sometimes generate a new ID on commit; for example, 294 // when committing an undeletion. 295 DVLOG(1) << " ID changed while committing an old entry. " 296 << pre_commit_id << " became " << entry_response_id << "."; 297 } 298 MutableEntry same_id(trans, GET_BY_ID, entry_response_id); 299 // We should trap this before this function. 300 if (same_id.good()) { 301 LOG(ERROR) << "ID clash with id " << entry_response_id 302 << " during commit " << same_id; 303 return false; 304 } 305 ChangeEntryIDAndUpdateChildren(trans, local_entry, entry_response_id); 306 DVLOG(1) << "Changing ID to " << entry_response_id; 307 } 308 return true; 309 } 310 311 void ProcessCommitResponseCommand::UpdateServerFieldsAfterCommit( 312 const sync_pb::SyncEntity& committed_entry, 313 const sync_pb::CommitResponse_EntryResponse& entry_response, 314 syncable::MutableEntry* local_entry) { 315 316 // We just committed an entry successfully, and now we want to make our view 317 // of the server state consistent with the server state. We must be careful; 318 // |entry_response| and |committed_entry| have some identically named 319 // fields. We only want to consider fields from |committed_entry| when there 320 // is not an overriding field in the |entry_response|. We do not want to 321 // update the server data from the local data in the entry -- it's possible 322 // that the local data changed during the commit, and even if not, the server 323 // has the last word on the values of several properties. 324 325 local_entry->Put(SERVER_IS_DEL, committed_entry.deleted()); 326 if (committed_entry.deleted()) { 327 // Don't clobber any other fields of deleted objects. 328 return; 329 } 330 331 local_entry->Put(syncable::SERVER_IS_DIR, 332 (committed_entry.folder() || 333 committed_entry.bookmarkdata().bookmark_folder())); 334 local_entry->Put(syncable::SERVER_SPECIFICS, 335 committed_entry.specifics()); 336 local_entry->Put(syncable::SERVER_MTIME, 337 ProtoTimeToTime(committed_entry.mtime())); 338 local_entry->Put(syncable::SERVER_CTIME, 339 ProtoTimeToTime(committed_entry.ctime())); 340 if (committed_entry.has_unique_position()) { 341 local_entry->Put(syncable::SERVER_UNIQUE_POSITION, 342 UniquePosition::FromProto( 343 committed_entry.unique_position())); 344 } 345 346 // TODO(nick): The server doesn't set entry_response.server_parent_id in 347 // practice; to update SERVER_PARENT_ID appropriately here we'd need to 348 // get the post-commit ID of the parent indicated by 349 // committed_entry.parent_id_string(). That should be inferrable from the 350 // information we have, but it's a bit convoluted to pull it out directly. 351 // Getting this right is important: SERVER_PARENT_ID gets fed back into 352 // old_parent_id during the next commit. 353 local_entry->Put(syncable::SERVER_PARENT_ID, 354 local_entry->Get(syncable::PARENT_ID)); 355 local_entry->Put(syncable::SERVER_NON_UNIQUE_NAME, 356 GetResultingPostCommitName(committed_entry, entry_response)); 357 358 if (local_entry->Get(IS_UNAPPLIED_UPDATE)) { 359 // This shouldn't happen; an unapplied update shouldn't be committed, and 360 // if it were, the commit should have failed. But if it does happen: we've 361 // just overwritten the update info, so clear the flag. 362 local_entry->Put(IS_UNAPPLIED_UPDATE, false); 363 } 364 } 365 366 void ProcessCommitResponseCommand::OverrideClientFieldsAfterCommit( 367 const sync_pb::SyncEntity& committed_entry, 368 const sync_pb::CommitResponse_EntryResponse& entry_response, 369 syncable::MutableEntry* local_entry) { 370 if (committed_entry.deleted()) { 371 // If an entry's been deleted, nothing else matters. 372 DCHECK(local_entry->Get(IS_DEL)); 373 return; 374 } 375 376 // Update the name. 377 const string& server_name = 378 GetResultingPostCommitName(committed_entry, entry_response); 379 const string& old_name = 380 local_entry->Get(syncable::NON_UNIQUE_NAME); 381 382 if (!server_name.empty() && old_name != server_name) { 383 DVLOG(1) << "During commit, server changed name: " << old_name 384 << " to new name: " << server_name; 385 local_entry->Put(syncable::NON_UNIQUE_NAME, server_name); 386 } 387 } 388 389 void ProcessCommitResponseCommand::ProcessSuccessfulCommitResponse( 390 const sync_pb::SyncEntity& committed_entry, 391 const sync_pb::CommitResponse_EntryResponse& entry_response, 392 const syncable::Id& pre_commit_id, syncable::MutableEntry* local_entry, 393 bool syncing_was_set, set<syncable::Id>* deleted_folders) { 394 DCHECK(local_entry->Get(IS_UNSYNCED)); 395 396 // Update SERVER_VERSION and BASE_VERSION. 397 if (!UpdateVersionAfterCommit(committed_entry, entry_response, pre_commit_id, 398 local_entry)) { 399 LOG(ERROR) << "Bad version in commit return for " << *local_entry 400 << " new_id:" << SyncableIdFromProto(entry_response.id_string()) 401 << " new_version:" << entry_response.version(); 402 return; 403 } 404 405 // If the server gave us a new ID, apply it. 406 if (!ChangeIdAfterCommit(entry_response, pre_commit_id, local_entry)) { 407 return; 408 } 409 410 // Update our stored copy of the server state. 411 UpdateServerFieldsAfterCommit(committed_entry, entry_response, local_entry); 412 413 // If the item doesn't need to be committed again (an item might need to be 414 // committed again if it changed locally during the commit), we can remove 415 // it from the unsynced list. Also, we should change the locally- 416 // visible properties to apply any canonicalizations or fixups 417 // that the server introduced during the commit. 418 if (syncing_was_set) { 419 OverrideClientFieldsAfterCommit(committed_entry, entry_response, 420 local_entry); 421 local_entry->Put(IS_UNSYNCED, false); 422 } 423 424 // Make a note of any deleted folders, whose children would have 425 // been recursively deleted. 426 // TODO(nick): Here, commit_message.deleted() would be more correct than 427 // local_entry->Get(IS_DEL). For example, an item could be renamed, and then 428 // deleted during the commit of the rename. Unit test & fix. 429 if (local_entry->Get(IS_DIR) && local_entry->Get(IS_DEL)) { 430 deleted_folders->insert(local_entry->Get(ID)); 431 } 432 } 433 434 } // namespace syncer 435
