[Telemetry] Migrate the rest of BeginInteraction to CreateInteraction.
[chromium-blink-merge.git] / sync / engine / syncer_proto_util.cc
blobc28d7c22a136ea0becbddaa1f554e47b19c455ec
1 // Copyright (c) 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.
5 #include "sync/engine/syncer_proto_util.h"
7 #include "base/format_macros.h"
8 #include "base/strings/stringprintf.h"
9 #include "google_apis/google_api_keys.h"
10 #include "sync/engine/net/server_connection_manager.h"
11 #include "sync/engine/syncer.h"
12 #include "sync/engine/syncer_types.h"
13 #include "sync/engine/traffic_logger.h"
14 #include "sync/internal_api/public/base/model_type.h"
15 #include "sync/protocol/sync_enums.pb.h"
16 #include "sync/protocol/sync_protocol_error.h"
17 #include "sync/sessions/sync_session.h"
18 #include "sync/syncable/directory.h"
19 #include "sync/syncable/entry.h"
20 #include "sync/syncable/syncable-inl.h"
21 #include "sync/syncable/syncable_proto_util.h"
22 #include "sync/util/time.h"
24 using std::string;
25 using std::stringstream;
26 using sync_pb::ClientToServerMessage;
27 using sync_pb::ClientToServerResponse;
29 namespace syncer {
31 using sessions::SyncSession;
32 using syncable::BASE_VERSION;
33 using syncable::CTIME;
34 using syncable::ID;
35 using syncable::IS_DEL;
36 using syncable::IS_DIR;
37 using syncable::IS_UNSYNCED;
38 using syncable::MTIME;
39 using syncable::PARENT_ID;
41 namespace {
43 // Time to backoff syncing after receiving a throttled response.
44 const int kSyncDelayAfterThrottled = 2 * 60 * 60; // 2 hours
46 void LogResponseProfilingData(const ClientToServerResponse& response) {
47 if (response.has_profiling_data()) {
48 stringstream response_trace;
49 response_trace << "Server response trace:";
51 if (response.profiling_data().has_user_lookup_time()) {
52 response_trace << " user lookup: "
53 << response.profiling_data().user_lookup_time() << "ms";
56 if (response.profiling_data().has_meta_data_write_time()) {
57 response_trace << " meta write: "
58 << response.profiling_data().meta_data_write_time()
59 << "ms";
62 if (response.profiling_data().has_meta_data_read_time()) {
63 response_trace << " meta read: "
64 << response.profiling_data().meta_data_read_time() << "ms";
67 if (response.profiling_data().has_file_data_write_time()) {
68 response_trace << " file write: "
69 << response.profiling_data().file_data_write_time()
70 << "ms";
73 if (response.profiling_data().has_file_data_read_time()) {
74 response_trace << " file read: "
75 << response.profiling_data().file_data_read_time() << "ms";
78 if (response.profiling_data().has_total_request_time()) {
79 response_trace << " total time: "
80 << response.profiling_data().total_request_time() << "ms";
82 DVLOG(1) << response_trace.str();
86 SyncerError ServerConnectionErrorAsSyncerError(
87 const HttpResponse::ServerConnectionCode server_status) {
88 switch (server_status) {
89 case HttpResponse::CONNECTION_UNAVAILABLE:
90 return NETWORK_CONNECTION_UNAVAILABLE;
91 case HttpResponse::IO_ERROR:
92 return NETWORK_IO_ERROR;
93 case HttpResponse::SYNC_SERVER_ERROR:
94 // FIXME what does this mean?
95 return SYNC_SERVER_ERROR;
96 case HttpResponse::SYNC_AUTH_ERROR:
97 return SYNC_AUTH_ERROR;
98 case HttpResponse::RETRY:
99 return SERVER_RETURN_TRANSIENT_ERROR;
100 case HttpResponse::SERVER_CONNECTION_OK:
101 case HttpResponse::NONE:
102 default:
103 NOTREACHED();
104 return UNSET;
108 SyncProtocolErrorType ConvertSyncProtocolErrorTypePBToLocalType(
109 const sync_pb::SyncEnums::ErrorType& error_type) {
110 switch (error_type) {
111 case sync_pb::SyncEnums::SUCCESS:
112 return SYNC_SUCCESS;
113 case sync_pb::SyncEnums::NOT_MY_BIRTHDAY:
114 return NOT_MY_BIRTHDAY;
115 case sync_pb::SyncEnums::THROTTLED:
116 return THROTTLED;
117 case sync_pb::SyncEnums::CLEAR_PENDING:
118 return CLEAR_PENDING;
119 case sync_pb::SyncEnums::TRANSIENT_ERROR:
120 return TRANSIENT_ERROR;
121 case sync_pb::SyncEnums::MIGRATION_DONE:
122 return MIGRATION_DONE;
123 case sync_pb::SyncEnums::DISABLED_BY_ADMIN:
124 return DISABLED_BY_ADMIN;
125 case sync_pb::SyncEnums::USER_ROLLBACK:
126 return USER_ROLLBACK;
127 case sync_pb::SyncEnums::PARTIAL_FAILURE:
128 return PARTIAL_FAILURE;
129 case sync_pb::SyncEnums::UNKNOWN:
130 return UNKNOWN_ERROR;
131 case sync_pb::SyncEnums::USER_NOT_ACTIVATED:
132 case sync_pb::SyncEnums::AUTH_INVALID:
133 case sync_pb::SyncEnums::ACCESS_DENIED:
134 return INVALID_CREDENTIAL;
135 default:
136 NOTREACHED();
137 return UNKNOWN_ERROR;
141 ClientAction ConvertClientActionPBToLocalClientAction(
142 const sync_pb::SyncEnums::Action& action) {
143 switch (action) {
144 case sync_pb::SyncEnums::UPGRADE_CLIENT:
145 return UPGRADE_CLIENT;
146 case sync_pb::SyncEnums::CLEAR_USER_DATA_AND_RESYNC:
147 return CLEAR_USER_DATA_AND_RESYNC;
148 case sync_pb::SyncEnums::ENABLE_SYNC_ON_ACCOUNT:
149 return ENABLE_SYNC_ON_ACCOUNT;
150 case sync_pb::SyncEnums::STOP_AND_RESTART_SYNC:
151 return STOP_AND_RESTART_SYNC;
152 case sync_pb::SyncEnums::DISABLE_SYNC_ON_CLIENT:
153 return DISABLE_SYNC_ON_CLIENT;
154 case sync_pb::SyncEnums::UNKNOWN_ACTION:
155 return UNKNOWN_ACTION;
156 default:
157 NOTREACHED();
158 return UNKNOWN_ACTION;
162 } // namespace
164 ModelTypeSet GetTypesToMigrate(const ClientToServerResponse& response) {
165 ModelTypeSet to_migrate;
166 for (int i = 0; i < response.migrated_data_type_id_size(); i++) {
167 int field_number = response.migrated_data_type_id(i);
168 ModelType model_type = GetModelTypeFromSpecificsFieldNumber(field_number);
169 if (!IsRealDataType(model_type)) {
170 DLOG(WARNING) << "Unknown field number " << field_number;
171 continue;
173 to_migrate.Put(model_type);
175 return to_migrate;
178 SyncProtocolError ConvertErrorPBToLocalType(
179 const sync_pb::ClientToServerResponse_Error& error) {
180 SyncProtocolError sync_protocol_error;
181 sync_protocol_error.error_type = ConvertSyncProtocolErrorTypePBToLocalType(
182 error.error_type());
183 sync_protocol_error.error_description = error.error_description();
184 sync_protocol_error.url = error.url();
185 sync_protocol_error.action = ConvertClientActionPBToLocalClientAction(
186 error.action());
188 if (error.error_data_type_ids_size() > 0) {
189 // THROTTLED and PARTIAL_FAILURE are currently the only error codes
190 // that uses |error_data_types|.
191 // In both cases, |error_data_types| are throttled.
192 for (int i = 0; i < error.error_data_type_ids_size(); ++i) {
193 int field_number = error.error_data_type_ids(i);
194 ModelType model_type =
195 GetModelTypeFromSpecificsFieldNumber(field_number);
196 if (!IsRealDataType(model_type)) {
197 DLOG(WARNING) << "Unknown field number " << field_number;
198 continue;
200 sync_protocol_error.error_data_types.Put(model_type);
204 return sync_protocol_error;
207 // static
208 bool SyncerProtoUtil::VerifyResponseBirthday(
209 const ClientToServerResponse& response,
210 syncable::Directory* dir) {
212 std::string local_birthday = dir->store_birthday();
214 if (local_birthday.empty()) {
215 if (!response.has_store_birthday()) {
216 LOG(WARNING) << "Expected a birthday on first sync.";
217 return false;
220 DVLOG(1) << "New store birthday: " << response.store_birthday();
221 dir->set_store_birthday(response.store_birthday());
222 return true;
225 // Error situation, but we're not stuck.
226 if (!response.has_store_birthday()) {
227 LOG(WARNING) << "No birthday in server response?";
228 return true;
231 if (response.store_birthday() != local_birthday) {
232 LOG(WARNING) << "Birthday changed, showing syncer stuck";
233 return false;
236 return true;
239 // static
240 bool SyncerProtoUtil::IsSyncDisabledByAdmin(
241 const sync_pb::ClientToServerResponse& response) {
242 return (response.has_error_code() &&
243 response.error_code() == sync_pb::SyncEnums::DISABLED_BY_ADMIN);
246 // static
247 void SyncerProtoUtil::AddRequestBirthday(syncable::Directory* dir,
248 ClientToServerMessage* msg) {
249 if (!dir->store_birthday().empty())
250 msg->set_store_birthday(dir->store_birthday());
253 // static
254 void SyncerProtoUtil::AddBagOfChips(syncable::Directory* dir,
255 ClientToServerMessage* msg) {
256 msg->mutable_bag_of_chips()->ParseFromString(dir->bag_of_chips());
259 // static
260 void SyncerProtoUtil::SetProtocolVersion(ClientToServerMessage* msg) {
261 const int current_version =
262 ClientToServerMessage::default_instance().protocol_version();
263 msg->set_protocol_version(current_version);
266 // static
267 bool SyncerProtoUtil::PostAndProcessHeaders(ServerConnectionManager* scm,
268 sessions::SyncSession* session,
269 const ClientToServerMessage& msg,
270 ClientToServerResponse* response) {
271 ServerConnectionManager::PostBufferParams params;
272 DCHECK(msg.has_protocol_version());
273 DCHECK_EQ(msg.protocol_version(),
274 ClientToServerMessage::default_instance().protocol_version());
275 msg.SerializeToString(&params.buffer_in);
277 ScopedServerStatusWatcher server_status_watcher(scm, &params.response);
278 // Fills in params.buffer_out and params.response.
279 if (!scm->PostBufferWithCachedAuth(&params, &server_status_watcher)) {
280 LOG(WARNING) << "Error posting from syncer:" << params.response;
281 return false;
284 if (response->ParseFromString(params.buffer_out)) {
285 // TODO(tim): This is an egregious layering violation (bug 35060).
286 switch (response->error_code()) {
287 case sync_pb::SyncEnums::ACCESS_DENIED:
288 case sync_pb::SyncEnums::AUTH_INVALID:
289 case sync_pb::SyncEnums::USER_NOT_ACTIVATED:
290 // Fires on ScopedServerStatusWatcher
291 params.response.server_status = HttpResponse::SYNC_AUTH_ERROR;
292 return false;
293 default:
294 return true;
298 return false;
301 base::TimeDelta SyncerProtoUtil::GetThrottleDelay(
302 const ClientToServerResponse& response) {
303 base::TimeDelta throttle_delay =
304 base::TimeDelta::FromSeconds(kSyncDelayAfterThrottled);
305 if (response.has_client_command()) {
306 const sync_pb::ClientCommand& command = response.client_command();
307 if (command.has_throttle_delay_seconds()) {
308 throttle_delay =
309 base::TimeDelta::FromSeconds(command.throttle_delay_seconds());
312 return throttle_delay;
315 namespace {
317 // Helper function for an assertion in PostClientToServerMessage.
318 bool IsVeryFirstGetUpdates(const ClientToServerMessage& message) {
319 if (!message.has_get_updates())
320 return false;
321 DCHECK_LT(0, message.get_updates().from_progress_marker_size());
322 for (int i = 0; i < message.get_updates().from_progress_marker_size(); ++i) {
323 if (!message.get_updates().from_progress_marker(i).token().empty())
324 return false;
326 return true;
329 // TODO(lipalani) : Rename these function names as per the CR for issue 7740067.
330 SyncProtocolError ConvertLegacyErrorCodeToNewError(
331 const sync_pb::SyncEnums::ErrorType& error_type) {
332 SyncProtocolError error;
333 error.error_type = ConvertSyncProtocolErrorTypePBToLocalType(error_type);
334 if (error_type == sync_pb::SyncEnums::CLEAR_PENDING ||
335 error_type == sync_pb::SyncEnums::NOT_MY_BIRTHDAY) {
336 error.action = DISABLE_SYNC_ON_CLIENT;
337 } else if (error_type == sync_pb::SyncEnums::DISABLED_BY_ADMIN) {
338 error.action = STOP_SYNC_FOR_DISABLED_ACCOUNT;
339 } else if (error_type == sync_pb::SyncEnums::USER_ROLLBACK) {
340 error.action = DISABLE_SYNC_AND_ROLLBACK;
341 } // There is no other action we can compute for legacy server.
342 return error;
345 } // namespace
347 // static
348 SyncerError SyncerProtoUtil::PostClientToServerMessage(
349 ClientToServerMessage* msg,
350 ClientToServerResponse* response,
351 SyncSession* session,
352 ModelTypeSet* partial_failure_data_types) {
353 CHECK(response);
354 DCHECK(!msg->get_updates().has_from_timestamp()); // Deprecated.
355 DCHECK(!msg->get_updates().has_requested_types()); // Deprecated.
357 // Add must-have fields.
358 SetProtocolVersion(msg);
359 AddRequestBirthday(session->context()->directory(), msg);
360 DCHECK(msg->has_store_birthday() || IsVeryFirstGetUpdates(*msg));
361 AddBagOfChips(session->context()->directory(), msg);
362 msg->set_api_key(google_apis::GetAPIKey());
363 msg->mutable_client_status()->CopyFrom(session->context()->client_status());
364 msg->set_invalidator_client_id(session->context()->invalidator_client_id());
366 syncable::Directory* dir = session->context()->directory();
368 LogClientToServerMessage(*msg);
369 if (!PostAndProcessHeaders(session->context()->connection_manager(), session,
370 *msg, response)) {
371 // There was an error establishing communication with the server.
372 // We can not proceed beyond this point.
373 const HttpResponse::ServerConnectionCode server_status =
374 session->context()->connection_manager()->server_status();
376 DCHECK_NE(server_status, HttpResponse::NONE);
377 DCHECK_NE(server_status, HttpResponse::SERVER_CONNECTION_OK);
379 return ServerConnectionErrorAsSyncerError(server_status);
381 LogClientToServerResponse(*response);
383 // Persist a bag of chips if it has been sent by the server.
384 PersistBagOfChips(dir, *response);
386 SyncProtocolError sync_protocol_error;
388 // The DISABLED_BY_ADMIN error overrides other errors sent by the server.
389 if (IsSyncDisabledByAdmin(*response)) {
390 sync_protocol_error.error_type = DISABLED_BY_ADMIN;
391 sync_protocol_error.action = STOP_SYNC_FOR_DISABLED_ACCOUNT;
392 } else if (!VerifyResponseBirthday(*response, dir)) {
393 // If sync isn't disabled, first check for a birthday mismatch error.
394 sync_protocol_error.error_type = NOT_MY_BIRTHDAY;
395 sync_protocol_error.action = DISABLE_SYNC_ON_CLIENT;
396 } else if (response->has_error()) {
397 // This is a new server. Just get the error from the protocol.
398 sync_protocol_error = ConvertErrorPBToLocalType(response->error());
399 } else {
400 // Legacy server implementation. Compute the error based on |error_code|.
401 sync_protocol_error = ConvertLegacyErrorCodeToNewError(
402 response->error_code());
405 // Inform the delegate of the error we got.
406 session->delegate()->OnSyncProtocolError(sync_protocol_error);
408 // Update our state for any other commands we've received.
409 if (response->has_client_command()) {
410 const sync_pb::ClientCommand& command = response->client_command();
411 if (command.has_max_commit_batch_size()) {
412 session->context()->set_max_commit_batch_size(
413 command.max_commit_batch_size());
416 if (command.has_set_sync_long_poll_interval()) {
417 session->delegate()->OnReceivedLongPollIntervalUpdate(
418 base::TimeDelta::FromSeconds(command.set_sync_long_poll_interval()));
421 if (command.has_set_sync_poll_interval()) {
422 session->delegate()->OnReceivedShortPollIntervalUpdate(
423 base::TimeDelta::FromSeconds(command.set_sync_poll_interval()));
426 if (command.has_sessions_commit_delay_seconds()) {
427 std::map<ModelType, base::TimeDelta> delay_map;
428 delay_map[SESSIONS] =
429 base::TimeDelta::FromSeconds(command.sessions_commit_delay_seconds());
430 session->delegate()->OnReceivedCustomNudgeDelays(delay_map);
433 if (command.has_client_invalidation_hint_buffer_size()) {
434 session->delegate()->OnReceivedClientInvalidationHintBufferSize(
435 command.client_invalidation_hint_buffer_size());
438 if (command.has_gu_retry_delay_seconds()) {
439 session->delegate()->OnReceivedGuRetryDelay(
440 base::TimeDelta::FromSeconds(command.gu_retry_delay_seconds()));
443 if (command.custom_nudge_delays_size() > 0) {
444 // Note that because this happens after the sessions_commit_delay_seconds
445 // handling, any SESSIONS value in this map will override the one in
446 // sessions_commit_delay_seconds.
447 std::map<ModelType, base::TimeDelta> delay_map;
448 for (int i = 0; i < command.custom_nudge_delays_size(); ++i) {
449 ModelType type = GetModelTypeFromSpecificsFieldNumber(
450 command.custom_nudge_delays(i).datatype_id());
451 if (ProtocolTypes().Has(type)) {
452 delay_map[type] = base::TimeDelta::FromMilliseconds(
453 command.custom_nudge_delays(i).delay_ms());
456 session->delegate()->OnReceivedCustomNudgeDelays(delay_map);
460 // Now do any special handling for the error type and decide on the return
461 // value.
462 switch (sync_protocol_error.error_type) {
463 case UNKNOWN_ERROR:
464 LOG(WARNING) << "Sync protocol out-of-date. The server is using a more "
465 << "recent version.";
466 return SERVER_RETURN_UNKNOWN_ERROR;
467 case SYNC_SUCCESS:
468 LogResponseProfilingData(*response);
469 return SYNCER_OK;
470 case THROTTLED:
471 if (sync_protocol_error.error_data_types.Empty()) {
472 DLOG(WARNING) << "Client fully throttled by syncer.";
473 session->delegate()->OnThrottled(GetThrottleDelay(*response));
474 } else {
475 DLOG(WARNING) << "Some types throttled by syncer.";
476 session->delegate()->OnTypesThrottled(
477 sync_protocol_error.error_data_types,
478 GetThrottleDelay(*response));
480 return SERVER_RETURN_THROTTLED;
481 case TRANSIENT_ERROR:
482 return SERVER_RETURN_TRANSIENT_ERROR;
483 case MIGRATION_DONE:
484 LOG_IF(ERROR, 0 >= response->migrated_data_type_id_size())
485 << "MIGRATION_DONE but no types specified.";
486 session->delegate()->OnReceivedMigrationRequest(
487 GetTypesToMigrate(*response));
488 return SERVER_RETURN_MIGRATION_DONE;
489 case CLEAR_PENDING:
490 return SERVER_RETURN_CLEAR_PENDING;
491 case NOT_MY_BIRTHDAY:
492 return SERVER_RETURN_NOT_MY_BIRTHDAY;
493 case DISABLED_BY_ADMIN:
494 return SERVER_RETURN_DISABLED_BY_ADMIN;
495 case USER_ROLLBACK:
496 return SERVER_RETURN_USER_ROLLBACK;
497 case PARTIAL_FAILURE:
498 // This only happens when partial throttling during GetUpdates.
499 if (!sync_protocol_error.error_data_types.Empty()) {
500 DLOG(WARNING) << "Some types throttled by syncer during GetUpdates.";
501 session->delegate()->OnTypesThrottled(
502 sync_protocol_error.error_data_types, GetThrottleDelay(*response));
504 if (partial_failure_data_types != NULL) {
505 *partial_failure_data_types = sync_protocol_error.error_data_types;
507 return SERVER_RETURN_PARTIAL_FAILURE;
508 default:
509 NOTREACHED();
510 return UNSET;
514 // static
515 bool SyncerProtoUtil::ShouldMaintainPosition(
516 const sync_pb::SyncEntity& sync_entity) {
517 // Maintain positions for bookmarks that are not server-defined top-level
518 // folders.
519 return GetModelType(sync_entity) == BOOKMARKS
520 && !(sync_entity.folder() &&
521 !sync_entity.server_defined_unique_tag().empty());
524 // static
525 void SyncerProtoUtil::CopyProtoBytesIntoBlob(const std::string& proto_bytes,
526 syncable::Blob* blob) {
527 syncable::Blob proto_blob(proto_bytes.begin(), proto_bytes.end());
528 blob->swap(proto_blob);
531 // static
532 bool SyncerProtoUtil::ProtoBytesEqualsBlob(const std::string& proto_bytes,
533 const syncable::Blob& blob) {
534 if (proto_bytes.size() != blob.size())
535 return false;
536 return std::equal(proto_bytes.begin(), proto_bytes.end(), blob.begin());
539 // static
540 void SyncerProtoUtil::CopyBlobIntoProtoBytes(const syncable::Blob& blob,
541 std::string* proto_bytes) {
542 std::string blob_string(blob.begin(), blob.end());
543 proto_bytes->swap(blob_string);
546 // static
547 const std::string& SyncerProtoUtil::NameFromSyncEntity(
548 const sync_pb::SyncEntity& entry) {
549 if (entry.has_non_unique_name())
550 return entry.non_unique_name();
551 return entry.name();
554 // static
555 const std::string& SyncerProtoUtil::NameFromCommitEntryResponse(
556 const sync_pb::CommitResponse_EntryResponse& entry) {
557 if (entry.has_non_unique_name())
558 return entry.non_unique_name();
559 return entry.name();
562 // static
563 void SyncerProtoUtil::PersistBagOfChips(syncable::Directory* dir,
564 const sync_pb::ClientToServerResponse& response) {
565 if (!response.has_new_bag_of_chips())
566 return;
567 std::string bag_of_chips;
568 if (response.new_bag_of_chips().SerializeToString(&bag_of_chips))
569 dir->set_bag_of_chips(bag_of_chips);
572 std::string SyncerProtoUtil::SyncEntityDebugString(
573 const sync_pb::SyncEntity& entry) {
574 const std::string& mtime_str =
575 GetTimeDebugString(ProtoTimeToTime(entry.mtime()));
576 const std::string& ctime_str =
577 GetTimeDebugString(ProtoTimeToTime(entry.ctime()));
578 return base::StringPrintf(
579 "id: %s, parent_id: %s, "
580 "version: %" PRId64"d, "
581 "mtime: %" PRId64"d (%s), "
582 "ctime: %" PRId64"d (%s), "
583 "name: %s, sync_timestamp: %" PRId64"d, "
584 "%s ",
585 entry.id_string().c_str(),
586 entry.parent_id_string().c_str(),
587 entry.version(),
588 entry.mtime(), mtime_str.c_str(),
589 entry.ctime(), ctime_str.c_str(),
590 entry.name().c_str(), entry.sync_timestamp(),
591 entry.deleted() ? "deleted, ":"");
594 namespace {
595 std::string GetUpdatesResponseString(
596 const sync_pb::GetUpdatesResponse& response) {
597 std::string output;
598 output.append("GetUpdatesResponse:\n");
599 for (int i = 0; i < response.entries_size(); i++) {
600 output.append(SyncerProtoUtil::SyncEntityDebugString(response.entries(i)));
601 output.append("\n");
603 return output;
605 } // namespace
607 std::string SyncerProtoUtil::ClientToServerResponseDebugString(
608 const ClientToServerResponse& response) {
609 // Add more handlers as needed.
610 std::string output;
611 if (response.has_get_updates())
612 output.append(GetUpdatesResponseString(response.get_updates()));
613 return output;
616 } // namespace syncer