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"
25 using std::stringstream
;
26 using sync_pb::ClientToServerMessage
;
27 using sync_pb::ClientToServerResponse
;
31 using sessions::SyncSession
;
32 using syncable::BASE_VERSION
;
33 using syncable::CTIME
;
35 using syncable::IS_DEL
;
36 using syncable::IS_DIR
;
37 using syncable::IS_UNSYNCED
;
38 using syncable::MTIME
;
39 using syncable::PARENT_ID
;
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()
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()
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
:
108 SyncProtocolErrorType
ConvertSyncProtocolErrorTypePBToLocalType(
109 const sync_pb::SyncEnums::ErrorType
& error_type
) {
110 switch (error_type
) {
111 case sync_pb::SyncEnums::SUCCESS
:
113 case sync_pb::SyncEnums::NOT_MY_BIRTHDAY
:
114 return NOT_MY_BIRTHDAY
;
115 case sync_pb::SyncEnums::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
;
137 return UNKNOWN_ERROR
;
141 ClientAction
ConvertClientActionPBToLocalClientAction(
142 const sync_pb::SyncEnums::Action
& 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
;
158 return UNKNOWN_ACTION
;
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
;
173 to_migrate
.Put(model_type
);
178 SyncProtocolError
ConvertErrorPBToLocalType(
179 const sync_pb::ClientToServerResponse_Error
& error
) {
180 SyncProtocolError sync_protocol_error
;
181 sync_protocol_error
.error_type
= ConvertSyncProtocolErrorTypePBToLocalType(
183 sync_protocol_error
.error_description
= error
.error_description();
184 sync_protocol_error
.url
= error
.url();
185 sync_protocol_error
.action
= ConvertClientActionPBToLocalClientAction(
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
;
200 sync_protocol_error
.error_data_types
.Put(model_type
);
204 return sync_protocol_error
;
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.";
220 DVLOG(1) << "New store birthday: " << response
.store_birthday();
221 dir
->set_store_birthday(response
.store_birthday());
225 // Error situation, but we're not stuck.
226 if (!response
.has_store_birthday()) {
227 LOG(WARNING
) << "No birthday in server response?";
231 if (response
.store_birthday() != local_birthday
) {
232 LOG(WARNING
) << "Birthday changed, showing syncer stuck";
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
);
247 void SyncerProtoUtil::AddRequestBirthday(syncable::Directory
* dir
,
248 ClientToServerMessage
* msg
) {
249 if (!dir
->store_birthday().empty())
250 msg
->set_store_birthday(dir
->store_birthday());
254 void SyncerProtoUtil::AddBagOfChips(syncable::Directory
* dir
,
255 ClientToServerMessage
* msg
) {
256 msg
->mutable_bag_of_chips()->ParseFromString(dir
->bag_of_chips());
260 void SyncerProtoUtil::SetProtocolVersion(ClientToServerMessage
* msg
) {
261 const int current_version
=
262 ClientToServerMessage::default_instance().protocol_version();
263 msg
->set_protocol_version(current_version
);
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(¶ms
.buffer_in
);
277 ScopedServerStatusWatcher
server_status_watcher(scm
, ¶ms
.response
);
278 // Fills in params.buffer_out and params.response.
279 if (!scm
->PostBufferWithCachedAuth(¶ms
, &server_status_watcher
)) {
280 LOG(WARNING
) << "Error posting from syncer:" << params
.response
;
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
;
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()) {
309 base::TimeDelta::FromSeconds(command
.throttle_delay_seconds());
312 return throttle_delay
;
317 // Returns true iff |message| is an initial GetUpdates request.
318 bool IsVeryFirstGetUpdates(const ClientToServerMessage
& message
) {
319 if (!message
.has_get_updates())
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())
329 // Returns true iff |message| should contain a store birthday.
330 bool IsBirthdayRequired(const ClientToServerMessage
& message
) {
331 if (message
.has_clear_server_data())
333 if (message
.has_commit())
335 if (message
.has_get_updates())
336 return !IsVeryFirstGetUpdates(message
);
341 // TODO(lipalani) : Rename these function names as per the CR for issue 7740067.
342 SyncProtocolError
ConvertLegacyErrorCodeToNewError(
343 const sync_pb::SyncEnums::ErrorType
& error_type
) {
344 SyncProtocolError error
;
345 error
.error_type
= ConvertSyncProtocolErrorTypePBToLocalType(error_type
);
346 if (error_type
== sync_pb::SyncEnums::CLEAR_PENDING
||
347 error_type
== sync_pb::SyncEnums::NOT_MY_BIRTHDAY
) {
348 error
.action
= DISABLE_SYNC_ON_CLIENT
;
349 } else if (error_type
== sync_pb::SyncEnums::DISABLED_BY_ADMIN
) {
350 error
.action
= STOP_SYNC_FOR_DISABLED_ACCOUNT
;
351 } else if (error_type
== sync_pb::SyncEnums::USER_ROLLBACK
) {
352 error
.action
= DISABLE_SYNC_AND_ROLLBACK
;
353 } // There is no other action we can compute for legacy server.
360 SyncerError
SyncerProtoUtil::PostClientToServerMessage(
361 ClientToServerMessage
* msg
,
362 ClientToServerResponse
* response
,
363 SyncSession
* session
,
364 ModelTypeSet
* partial_failure_data_types
) {
366 DCHECK(!msg
->get_updates().has_from_timestamp()); // Deprecated.
367 DCHECK(!msg
->get_updates().has_requested_types()); // Deprecated.
369 // Add must-have fields.
370 SetProtocolVersion(msg
);
371 AddRequestBirthday(session
->context()->directory(), msg
);
372 DCHECK(msg
->has_store_birthday() || !IsBirthdayRequired(*msg
));
373 AddBagOfChips(session
->context()->directory(), msg
);
374 msg
->set_api_key(google_apis::GetAPIKey());
375 msg
->mutable_client_status()->CopyFrom(session
->context()->client_status());
376 msg
->set_invalidator_client_id(session
->context()->invalidator_client_id());
378 syncable::Directory
* dir
= session
->context()->directory();
380 LogClientToServerMessage(*msg
);
381 if (!PostAndProcessHeaders(session
->context()->connection_manager(), session
,
383 // There was an error establishing communication with the server.
384 // We can not proceed beyond this point.
385 const HttpResponse::ServerConnectionCode server_status
=
386 session
->context()->connection_manager()->server_status();
388 DCHECK_NE(server_status
, HttpResponse::NONE
);
389 DCHECK_NE(server_status
, HttpResponse::SERVER_CONNECTION_OK
);
391 return ServerConnectionErrorAsSyncerError(server_status
);
393 LogClientToServerResponse(*response
);
395 // Persist a bag of chips if it has been sent by the server.
396 PersistBagOfChips(dir
, *response
);
398 SyncProtocolError sync_protocol_error
;
400 // The DISABLED_BY_ADMIN error overrides other errors sent by the server.
401 if (IsSyncDisabledByAdmin(*response
)) {
402 sync_protocol_error
.error_type
= DISABLED_BY_ADMIN
;
403 sync_protocol_error
.action
= STOP_SYNC_FOR_DISABLED_ACCOUNT
;
404 } else if (!VerifyResponseBirthday(*response
, dir
)) {
405 // If sync isn't disabled, first check for a birthday mismatch error.
406 sync_protocol_error
.error_type
= NOT_MY_BIRTHDAY
;
407 sync_protocol_error
.action
= DISABLE_SYNC_ON_CLIENT
;
408 } else if (response
->has_error()) {
409 // This is a new server. Just get the error from the protocol.
410 sync_protocol_error
= ConvertErrorPBToLocalType(response
->error());
412 // Legacy server implementation. Compute the error based on |error_code|.
413 sync_protocol_error
= ConvertLegacyErrorCodeToNewError(
414 response
->error_code());
417 // Inform the delegate of the error we got.
418 session
->delegate()->OnSyncProtocolError(sync_protocol_error
);
420 // Update our state for any other commands we've received.
421 if (response
->has_client_command()) {
422 const sync_pb::ClientCommand
& command
= response
->client_command();
423 if (command
.has_max_commit_batch_size()) {
424 session
->context()->set_max_commit_batch_size(
425 command
.max_commit_batch_size());
428 if (command
.has_set_sync_long_poll_interval()) {
429 session
->delegate()->OnReceivedLongPollIntervalUpdate(
430 base::TimeDelta::FromSeconds(command
.set_sync_long_poll_interval()));
433 if (command
.has_set_sync_poll_interval()) {
434 session
->delegate()->OnReceivedShortPollIntervalUpdate(
435 base::TimeDelta::FromSeconds(command
.set_sync_poll_interval()));
438 if (command
.has_sessions_commit_delay_seconds()) {
439 std::map
<ModelType
, base::TimeDelta
> delay_map
;
440 delay_map
[SESSIONS
] =
441 base::TimeDelta::FromSeconds(command
.sessions_commit_delay_seconds());
442 session
->delegate()->OnReceivedCustomNudgeDelays(delay_map
);
445 if (command
.has_client_invalidation_hint_buffer_size()) {
446 session
->delegate()->OnReceivedClientInvalidationHintBufferSize(
447 command
.client_invalidation_hint_buffer_size());
450 if (command
.has_gu_retry_delay_seconds()) {
451 session
->delegate()->OnReceivedGuRetryDelay(
452 base::TimeDelta::FromSeconds(command
.gu_retry_delay_seconds()));
455 if (command
.custom_nudge_delays_size() > 0) {
456 // Note that because this happens after the sessions_commit_delay_seconds
457 // handling, any SESSIONS value in this map will override the one in
458 // sessions_commit_delay_seconds.
459 std::map
<ModelType
, base::TimeDelta
> delay_map
;
460 for (int i
= 0; i
< command
.custom_nudge_delays_size(); ++i
) {
461 ModelType type
= GetModelTypeFromSpecificsFieldNumber(
462 command
.custom_nudge_delays(i
).datatype_id());
463 if (ProtocolTypes().Has(type
)) {
464 delay_map
[type
] = base::TimeDelta::FromMilliseconds(
465 command
.custom_nudge_delays(i
).delay_ms());
468 session
->delegate()->OnReceivedCustomNudgeDelays(delay_map
);
472 // Now do any special handling for the error type and decide on the return
474 switch (sync_protocol_error
.error_type
) {
476 LOG(WARNING
) << "Sync protocol out-of-date. The server is using a more "
477 << "recent version.";
478 return SERVER_RETURN_UNKNOWN_ERROR
;
480 LogResponseProfilingData(*response
);
483 if (sync_protocol_error
.error_data_types
.Empty()) {
484 DLOG(WARNING
) << "Client fully throttled by syncer.";
485 session
->delegate()->OnThrottled(GetThrottleDelay(*response
));
487 DLOG(WARNING
) << "Some types throttled by syncer.";
488 session
->delegate()->OnTypesThrottled(
489 sync_protocol_error
.error_data_types
,
490 GetThrottleDelay(*response
));
492 return SERVER_RETURN_THROTTLED
;
493 case TRANSIENT_ERROR
:
494 return SERVER_RETURN_TRANSIENT_ERROR
;
496 LOG_IF(ERROR
, 0 >= response
->migrated_data_type_id_size())
497 << "MIGRATION_DONE but no types specified.";
498 session
->delegate()->OnReceivedMigrationRequest(
499 GetTypesToMigrate(*response
));
500 return SERVER_RETURN_MIGRATION_DONE
;
502 return SERVER_RETURN_CLEAR_PENDING
;
503 case NOT_MY_BIRTHDAY
:
504 return SERVER_RETURN_NOT_MY_BIRTHDAY
;
505 case DISABLED_BY_ADMIN
:
506 return SERVER_RETURN_DISABLED_BY_ADMIN
;
508 return SERVER_RETURN_USER_ROLLBACK
;
509 case PARTIAL_FAILURE
:
510 // This only happens when partial throttling during GetUpdates.
511 if (!sync_protocol_error
.error_data_types
.Empty()) {
512 DLOG(WARNING
) << "Some types throttled by syncer during GetUpdates.";
513 session
->delegate()->OnTypesThrottled(
514 sync_protocol_error
.error_data_types
, GetThrottleDelay(*response
));
516 if (partial_failure_data_types
!= NULL
) {
517 *partial_failure_data_types
= sync_protocol_error
.error_data_types
;
519 return SERVER_RETURN_PARTIAL_FAILURE
;
527 bool SyncerProtoUtil::ShouldMaintainPosition(
528 const sync_pb::SyncEntity
& sync_entity
) {
529 // Maintain positions for bookmarks that are not server-defined top-level
531 return GetModelType(sync_entity
) == BOOKMARKS
532 && !(sync_entity
.folder() &&
533 !sync_entity
.server_defined_unique_tag().empty());
537 bool SyncerProtoUtil::ShouldMaintainHierarchy(
538 const sync_pb::SyncEntity
& sync_entity
) {
539 // Maintain hierarchy for bookmarks or top-level items.
540 return GetModelType(sync_entity
) == BOOKMARKS
||
541 sync_entity
.parent_id_string() == "0";
545 const std::string
& SyncerProtoUtil::NameFromSyncEntity(
546 const sync_pb::SyncEntity
& entry
) {
547 if (entry
.has_non_unique_name())
548 return entry
.non_unique_name();
553 const std::string
& SyncerProtoUtil::NameFromCommitEntryResponse(
554 const sync_pb::CommitResponse_EntryResponse
& entry
) {
555 if (entry
.has_non_unique_name())
556 return entry
.non_unique_name();
561 void SyncerProtoUtil::PersistBagOfChips(syncable::Directory
* dir
,
562 const sync_pb::ClientToServerResponse
& response
) {
563 if (!response
.has_new_bag_of_chips())
565 std::string bag_of_chips
;
566 if (response
.new_bag_of_chips().SerializeToString(&bag_of_chips
))
567 dir
->set_bag_of_chips(bag_of_chips
);
570 std::string
SyncerProtoUtil::SyncEntityDebugString(
571 const sync_pb::SyncEntity
& entry
) {
572 const std::string
& mtime_str
=
573 GetTimeDebugString(ProtoTimeToTime(entry
.mtime()));
574 const std::string
& ctime_str
=
575 GetTimeDebugString(ProtoTimeToTime(entry
.ctime()));
576 return base::StringPrintf(
577 "id: %s, parent_id: %s, "
578 "version: %" PRId64
"d, "
579 "mtime: %" PRId64
"d (%s), "
580 "ctime: %" PRId64
"d (%s), "
581 "name: %s, sync_timestamp: %" PRId64
"d, "
583 entry
.id_string().c_str(),
584 entry
.parent_id_string().c_str(),
586 entry
.mtime(), mtime_str
.c_str(),
587 entry
.ctime(), ctime_str
.c_str(),
588 entry
.name().c_str(), entry
.sync_timestamp(),
589 entry
.deleted() ? "deleted, ":"");
593 std::string
GetUpdatesResponseString(
594 const sync_pb::GetUpdatesResponse
& response
) {
596 output
.append("GetUpdatesResponse:\n");
597 for (int i
= 0; i
< response
.entries_size(); i
++) {
598 output
.append(SyncerProtoUtil::SyncEntityDebugString(response
.entries(i
)));
605 std::string
SyncerProtoUtil::ClientToServerResponseDebugString(
606 const ClientToServerResponse
& response
) {
607 // Add more handlers as needed.
609 if (response
.has_get_updates())
610 output
.append(GetUpdatesResponseString(response
.get_updates()));
614 } // namespace syncer