// Copyright (c) 2012 The Chromium Authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
#include "sync/engine/syncer_proto_util.h"
#include "base/format_macros.h"
#include "base/strings/stringprintf.h"
#include "google_apis/google_api_keys.h"
#include "sync/engine/net/server_connection_manager.h"
#include "sync/engine/syncer.h"
#include "sync/engine/syncer_types.h"
#include "sync/engine/traffic_logger.h"
#include "sync/internal_api/public/base/model_type.h"
#include "sync/protocol/sync_enums.pb.h"
#include "sync/protocol/sync_protocol_error.h"
#include "sync/sessions/sync_session.h"
#include "sync/syncable/directory.h"
#include "sync/syncable/entry.h"
#include "sync/syncable/syncable-inl.h"
#include "sync/syncable/syncable_proto_util.h"
#include "sync/util/time.h"
using std::string;
using std::stringstream;
using sync_pb::ClientToServerMessage;
using sync_pb::ClientToServerResponse;
namespace syncer {
using sessions::SyncSession;
using syncable::BASE_VERSION;
using syncable::CTIME;
using syncable::ID;
using syncable::IS_DEL;
using syncable::IS_DIR;
using syncable::IS_UNSYNCED;
using syncable::MTIME;
using syncable::PARENT_ID;
namespace {
// Time to backoff syncing after receiving a throttled response.
const int kSyncDelayAfterThrottled = 2 * 60 * 60; // 2 hours
void LogResponseProfilingData(const ClientToServerResponse& response) {
if (response.has_profiling_data()) {
stringstream response_trace;
response_trace << "Server response trace:";
if (response.profiling_data().has_user_lookup_time()) {
response_trace << " user lookup: "
<< response.profiling_data().user_lookup_time() << "ms";
}
if (response.profiling_data().has_meta_data_write_time()) {
response_trace << " meta write: "
<< response.profiling_data().meta_data_write_time()
<< "ms";
}
if (response.profiling_data().has_meta_data_read_time()) {
response_trace << " meta read: "
<< response.profiling_data().meta_data_read_time() << "ms";
}
if (response.profiling_data().has_file_data_write_time()) {
response_trace << " file write: "
<< response.profiling_data().file_data_write_time()
<< "ms";
}
if (response.profiling_data().has_file_data_read_time()) {
response_trace << " file read: "
<< response.profiling_data().file_data_read_time() << "ms";
}
if (response.profiling_data().has_total_request_time()) {
response_trace << " total time: "
<< response.profiling_data().total_request_time() << "ms";
}
DVLOG(1) << response_trace.str();
}
}
SyncerError ServerConnectionErrorAsSyncerError(
const HttpResponse::ServerConnectionCode server_status) {
switch (server_status) {
case HttpResponse::CONNECTION_UNAVAILABLE:
return NETWORK_CONNECTION_UNAVAILABLE;
case HttpResponse::IO_ERROR:
return NETWORK_IO_ERROR;
case HttpResponse::SYNC_SERVER_ERROR:
// FIXME what does this mean?
return SYNC_SERVER_ERROR;
case HttpResponse::SYNC_AUTH_ERROR:
return SYNC_AUTH_ERROR;
case HttpResponse::RETRY:
return SERVER_RETURN_TRANSIENT_ERROR;
case HttpResponse::SERVER_CONNECTION_OK:
case HttpResponse::NONE:
default:
NOTREACHED();
return UNSET;
}
}
SyncProtocolErrorType ConvertSyncProtocolErrorTypePBToLocalType(
const sync_pb::SyncEnums::ErrorType& error_type) {
switch (error_type) {
case sync_pb::SyncEnums::SUCCESS:
return SYNC_SUCCESS;
case sync_pb::SyncEnums::NOT_MY_BIRTHDAY:
return NOT_MY_BIRTHDAY;
case sync_pb::SyncEnums::THROTTLED:
return THROTTLED;
case sync_pb::SyncEnums::CLEAR_PENDING:
return CLEAR_PENDING;
case sync_pb::SyncEnums::TRANSIENT_ERROR:
return TRANSIENT_ERROR;
case sync_pb::SyncEnums::MIGRATION_DONE:
return MIGRATION_DONE;
case sync_pb::SyncEnums::DISABLED_BY_ADMIN:
return DISABLED_BY_ADMIN;
case sync_pb::SyncEnums::USER_ROLLBACK:
return USER_ROLLBACK;
case sync_pb::SyncEnums::UNKNOWN:
return UNKNOWN_ERROR;
case sync_pb::SyncEnums::USER_NOT_ACTIVATED:
case sync_pb::SyncEnums::AUTH_INVALID:
case sync_pb::SyncEnums::ACCESS_DENIED:
return INVALID_CREDENTIAL;
default:
NOTREACHED();
return UNKNOWN_ERROR;
}
}
ClientAction ConvertClientActionPBToLocalClientAction(
const sync_pb::SyncEnums::Action& action) {
switch (action) {
case sync_pb::SyncEnums::UPGRADE_CLIENT:
return UPGRADE_CLIENT;
case sync_pb::SyncEnums::CLEAR_USER_DATA_AND_RESYNC:
return CLEAR_USER_DATA_AND_RESYNC;
case sync_pb::SyncEnums::ENABLE_SYNC_ON_ACCOUNT:
return ENABLE_SYNC_ON_ACCOUNT;
case sync_pb::SyncEnums::STOP_AND_RESTART_SYNC:
return STOP_AND_RESTART_SYNC;
case sync_pb::SyncEnums::DISABLE_SYNC_ON_CLIENT:
return DISABLE_SYNC_ON_CLIENT;
case sync_pb::SyncEnums::UNKNOWN_ACTION:
return UNKNOWN_ACTION;
default:
NOTREACHED();
return UNKNOWN_ACTION;
}
}
} // namespace
ModelTypeSet GetTypesToMigrate(const ClientToServerResponse& response) {
ModelTypeSet to_migrate;
for (int i = 0; i < response.migrated_data_type_id_size(); i++) {
int field_number = response.migrated_data_type_id(i);
ModelType model_type = GetModelTypeFromSpecificsFieldNumber(field_number);
if (!IsRealDataType(model_type)) {
DLOG(WARNING) << "Unknown field number " << field_number;
continue;
}
to_migrate.Put(model_type);
}
return to_migrate;
}
SyncProtocolError ConvertErrorPBToLocalType(
const sync_pb::ClientToServerResponse_Error& error) {
SyncProtocolError sync_protocol_error;
sync_protocol_error.error_type = ConvertSyncProtocolErrorTypePBToLocalType(
error.error_type());
sync_protocol_error.error_description = error.error_description();
sync_protocol_error.url = error.url();
sync_protocol_error.action = ConvertClientActionPBToLocalClientAction(
error.action());
if (error.error_data_type_ids_size() > 0) {
// THROTTLED is currently the only error code that uses |error_data_types|.
DCHECK_EQ(error.error_type(), sync_pb::SyncEnums::THROTTLED);
for (int i = 0; i < error.error_data_type_ids_size(); ++i) {
int field_number = error.error_data_type_ids(i);
ModelType model_type =
GetModelTypeFromSpecificsFieldNumber(field_number);
if (!IsRealDataType(model_type)) {
DLOG(WARNING) << "Unknown field number " << field_number;
continue;
}
sync_protocol_error.error_data_types.Put(model_type);
}
}
return sync_protocol_error;
}
// static
bool SyncerProtoUtil::VerifyResponseBirthday(
const ClientToServerResponse& response,
syncable::Directory* dir) {
std::string local_birthday = dir->store_birthday();
if (local_birthday.empty()) {
if (!response.has_store_birthday()) {
LOG(WARNING) << "Expected a birthday on first sync.";
return false;
}
DVLOG(1) << "New store birthday: " << response.store_birthday();
dir->set_store_birthday(response.store_birthday());
return true;
}
// Error situation, but we're not stuck.
if (!response.has_store_birthday()) {
LOG(WARNING) << "No birthday in server response?";
return true;
}
if (response.store_birthday() != local_birthday) {
LOG(WARNING) << "Birthday changed, showing syncer stuck";
return false;
}
return true;
}
// static
bool SyncerProtoUtil::IsSyncDisabledByAdmin(
const sync_pb::ClientToServerResponse& response) {
return (response.has_error_code() &&
response.error_code() == sync_pb::SyncEnums::DISABLED_BY_ADMIN);
}
// static
void SyncerProtoUtil::AddRequestBirthday(syncable::Directory* dir,
ClientToServerMessage* msg) {
if (!dir->store_birthday().empty())
msg->set_store_birthday(dir->store_birthday());
}
// static
void SyncerProtoUtil::AddBagOfChips(syncable::Directory* dir,
ClientToServerMessage* msg) {
msg->mutable_bag_of_chips()->ParseFromString(dir->bag_of_chips());
}
// static
void SyncerProtoUtil::SetProtocolVersion(ClientToServerMessage* msg) {
const int current_version =
ClientToServerMessage::default_instance().protocol_version();
msg->set_protocol_version(current_version);
}
// static
bool SyncerProtoUtil::PostAndProcessHeaders(ServerConnectionManager* scm,
sessions::SyncSession* session,
const ClientToServerMessage& msg,
ClientToServerResponse* response) {
ServerConnectionManager::PostBufferParams params;
DCHECK(msg.has_protocol_version());
DCHECK_EQ(msg.protocol_version(),
ClientToServerMessage::default_instance().protocol_version());
msg.SerializeToString(¶ms.buffer_in);
ScopedServerStatusWatcher server_status_watcher(scm, ¶ms.response);
// Fills in params.buffer_out and params.response.
if (!scm->PostBufferWithCachedAuth(¶ms, &server_status_watcher)) {
LOG(WARNING) << "Error posting from syncer:" << params.response;
return false;
}
if (response->ParseFromString(params.buffer_out)) {
// TODO(tim): This is an egregious layering violation (bug 35060).
switch (response->error_code()) {
case sync_pb::SyncEnums::ACCESS_DENIED:
case sync_pb::SyncEnums::AUTH_INVALID:
case sync_pb::SyncEnums::USER_NOT_ACTIVATED:
// Fires on ScopedServerStatusWatcher
params.response.server_status = HttpResponse::SYNC_AUTH_ERROR;
return false;
default:
return true;
}
}
return false;
}
base::TimeDelta SyncerProtoUtil::GetThrottleDelay(
const ClientToServerResponse& response) {
base::TimeDelta throttle_delay =
base::TimeDelta::FromSeconds(kSyncDelayAfterThrottled);
if (response.has_client_command()) {
const sync_pb::ClientCommand& command = response.client_command();
if (command.has_throttle_delay_seconds()) {
throttle_delay =
base::TimeDelta::FromSeconds(command.throttle_delay_seconds());
}
}
return throttle_delay;
}
namespace {
// Helper function for an assertion in PostClientToServerMessage.
bool IsVeryFirstGetUpdates(const ClientToServerMessage& message) {
if (!message.has_get_updates())
return false;
DCHECK_LT(0, message.get_updates().from_progress_marker_size());
for (int i = 0; i < message.get_updates().from_progress_marker_size(); ++i) {
if (!message.get_updates().from_progress_marker(i).token().empty())
return false;
}
return true;
}
// TODO(lipalani) : Rename these function names as per the CR for issue 7740067.
SyncProtocolError ConvertLegacyErrorCodeToNewError(
const sync_pb::SyncEnums::ErrorType& error_type) {
SyncProtocolError error;
error.error_type = ConvertSyncProtocolErrorTypePBToLocalType(error_type);
if (error_type == sync_pb::SyncEnums::CLEAR_PENDING ||
error_type == sync_pb::SyncEnums::NOT_MY_BIRTHDAY) {
error.action = DISABLE_SYNC_ON_CLIENT;
} else if (error_type == sync_pb::SyncEnums::DISABLED_BY_ADMIN) {
error.action = STOP_SYNC_FOR_DISABLED_ACCOUNT;
} else if (error_type == sync_pb::SyncEnums::USER_ROLLBACK) {
error.action = DISABLE_SYNC_AND_ROLLBACK;
} // There is no other action we can compute for legacy server.
return error;
}
} // namespace
// static
SyncerError SyncerProtoUtil::PostClientToServerMessage(
ClientToServerMessage* msg,
ClientToServerResponse* response,
SyncSession* session) {
CHECK(response);
DCHECK(!msg->get_updates().has_from_timestamp()); // Deprecated.
DCHECK(!msg->get_updates().has_requested_types()); // Deprecated.
// Add must-have fields.
SetProtocolVersion(msg);
AddRequestBirthday(session->context()->directory(), msg);
DCHECK(msg->has_store_birthday() || IsVeryFirstGetUpdates(*msg));
AddBagOfChips(session->context()->directory(), msg);
msg->set_api_key(google_apis::GetAPIKey());
msg->mutable_client_status()->CopyFrom(session->context()->client_status());
msg->set_invalidator_client_id(session->context()->invalidator_client_id());
syncable::Directory* dir = session->context()->directory();
LogClientToServerMessage(*msg);
if (!PostAndProcessHeaders(session->context()->connection_manager(), session,
*msg, response)) {
// There was an error establishing communication with the server.
// We can not proceed beyond this point.
const HttpResponse::ServerConnectionCode server_status =
session->context()->connection_manager()->server_status();
DCHECK_NE(server_status, HttpResponse::NONE);
DCHECK_NE(server_status, HttpResponse::SERVER_CONNECTION_OK);
return ServerConnectionErrorAsSyncerError(server_status);
}
LogClientToServerResponse(*response);
// Persist a bag of chips if it has been sent by the server.
PersistBagOfChips(dir, *response);
SyncProtocolError sync_protocol_error;
// The DISABLED_BY_ADMIN error overrides other errors sent by the server.
if (IsSyncDisabledByAdmin(*response)) {
sync_protocol_error.error_type = DISABLED_BY_ADMIN;
sync_protocol_error.action = STOP_SYNC_FOR_DISABLED_ACCOUNT;
} else if (!VerifyResponseBirthday(*response, dir)) {
// If sync isn't disabled, first check for a birthday mismatch error.
sync_protocol_error.error_type = NOT_MY_BIRTHDAY;
sync_protocol_error.action = DISABLE_SYNC_ON_CLIENT;
} else if (response->has_error()) {
// This is a new server. Just get the error from the protocol.
sync_protocol_error = ConvertErrorPBToLocalType(response->error());
} else {
// Legacy server implementation. Compute the error based on |error_code|.
sync_protocol_error = ConvertLegacyErrorCodeToNewError(
response->error_code());
}
// Inform the delegate of the error we got.
session->delegate()->OnSyncProtocolError(sync_protocol_error);
// Update our state for any other commands we've received.
if (response->has_client_command()) {
const sync_pb::ClientCommand& command = response->client_command();
if (command.has_max_commit_batch_size()) {
session->context()->set_max_commit_batch_size(
command.max_commit_batch_size());
}
if (command.has_set_sync_long_poll_interval()) {
session->delegate()->OnReceivedLongPollIntervalUpdate(
base::TimeDelta::FromSeconds(command.set_sync_long_poll_interval()));
}
if (command.has_set_sync_poll_interval()) {
session->delegate()->OnReceivedShortPollIntervalUpdate(
base::TimeDelta::FromSeconds(command.set_sync_poll_interval()));
}
if (command.has_sessions_commit_delay_seconds()) {
session->delegate()->OnReceivedSessionsCommitDelay(
base::TimeDelta::FromSeconds(
command.sessions_commit_delay_seconds()));
}
if (command.has_client_invalidation_hint_buffer_size()) {
session->delegate()->OnReceivedClientInvalidationHintBufferSize(
command.client_invalidation_hint_buffer_size());
}
if (command.has_gu_retry_delay_seconds()) {
session->delegate()->OnReceivedGuRetryDelay(
base::TimeDelta::FromSeconds(command.gu_retry_delay_seconds()));
}
}
// Now do any special handling for the error type and decide on the return
// value.
switch (sync_protocol_error.error_type) {
case UNKNOWN_ERROR:
LOG(WARNING) << "Sync protocol out-of-date. The server is using a more "
<< "recent version.";
return SERVER_RETURN_UNKNOWN_ERROR;
case SYNC_SUCCESS:
LogResponseProfilingData(*response);
return SYNCER_OK;
case THROTTLED:
if (sync_protocol_error.error_data_types.Empty()) {
DLOG(WARNING) << "Client fully throttled by syncer.";
session->delegate()->OnThrottled(GetThrottleDelay(*response));
} else {
DLOG(WARNING) << "Some types throttled by syncer.";
session->delegate()->OnTypesThrottled(
sync_protocol_error.error_data_types,
GetThrottleDelay(*response));
}
return SERVER_RETURN_THROTTLED;
case TRANSIENT_ERROR:
return SERVER_RETURN_TRANSIENT_ERROR;
case MIGRATION_DONE:
LOG_IF(ERROR, 0 >= response->migrated_data_type_id_size())
<< "MIGRATION_DONE but no types specified.";
session->delegate()->OnReceivedMigrationRequest(
GetTypesToMigrate(*response));
return SERVER_RETURN_MIGRATION_DONE;
case CLEAR_PENDING:
return SERVER_RETURN_CLEAR_PENDING;
case NOT_MY_BIRTHDAY:
return SERVER_RETURN_NOT_MY_BIRTHDAY;
case DISABLED_BY_ADMIN:
return SERVER_RETURN_DISABLED_BY_ADMIN;
case USER_ROLLBACK:
return SERVER_RETURN_USER_ROLLBACK;
default:
NOTREACHED();
return UNSET;
}
}
// static
bool SyncerProtoUtil::ShouldMaintainPosition(
const sync_pb::SyncEntity& sync_entity) {
// Maintain positions for bookmarks that are not server-defined top-level
// folders.
return GetModelType(sync_entity) == BOOKMARKS
&& !(sync_entity.folder() &&
!sync_entity.server_defined_unique_tag().empty());
}
// static
void SyncerProtoUtil::CopyProtoBytesIntoBlob(const std::string& proto_bytes,
syncable::Blob* blob) {
syncable::Blob proto_blob(proto_bytes.begin(), proto_bytes.end());
blob->swap(proto_blob);
}
// static
bool SyncerProtoUtil::ProtoBytesEqualsBlob(const std::string& proto_bytes,
const syncable::Blob& blob) {
if (proto_bytes.size() != blob.size())
return false;
return std::equal(proto_bytes.begin(), proto_bytes.end(), blob.begin());
}
// static
void SyncerProtoUtil::CopyBlobIntoProtoBytes(const syncable::Blob& blob,
std::string* proto_bytes) {
std::string blob_string(blob.begin(), blob.end());
proto_bytes->swap(blob_string);
}
// static
const std::string& SyncerProtoUtil::NameFromSyncEntity(
const sync_pb::SyncEntity& entry) {
if (entry.has_non_unique_name())
return entry.non_unique_name();
return entry.name();
}
// static
const std::string& SyncerProtoUtil::NameFromCommitEntryResponse(
const sync_pb::CommitResponse_EntryResponse& entry) {
if (entry.has_non_unique_name())
return entry.non_unique_name();
return entry.name();
}
// static
void SyncerProtoUtil::PersistBagOfChips(syncable::Directory* dir,
const sync_pb::ClientToServerResponse& response) {
if (!response.has_new_bag_of_chips())
return;
std::string bag_of_chips;
if (response.new_bag_of_chips().SerializeToString(&bag_of_chips))
dir->set_bag_of_chips(bag_of_chips);
}
std::string SyncerProtoUtil::SyncEntityDebugString(
const sync_pb::SyncEntity& entry) {
const std::string& mtime_str =
GetTimeDebugString(ProtoTimeToTime(entry.mtime()));
const std::string& ctime_str =
GetTimeDebugString(ProtoTimeToTime(entry.ctime()));
return base::StringPrintf(
"id: %s, parent_id: %s, "
"version: %" PRId64"d, "
"mtime: %" PRId64"d (%s), "
"ctime: %" PRId64"d (%s), "
"name: %s, sync_timestamp: %" PRId64"d, "
"%s ",
entry.id_string().c_str(),
entry.parent_id_string().c_str(),
entry.version(),
entry.mtime(), mtime_str.c_str(),
entry.ctime(), ctime_str.c_str(),
entry.name().c_str(), entry.sync_timestamp(),
entry.deleted() ? "deleted, ":"");
}
namespace {
std::string GetUpdatesResponseString(
const sync_pb::GetUpdatesResponse& response) {
std::string output;
output.append("GetUpdatesResponse:\n");
for (int i = 0; i < response.entries_size(); i++) {
output.append(SyncerProtoUtil::SyncEntityDebugString(response.entries(i)));
output.append("\n");
}
return output;
}
} // namespace
std::string SyncerProtoUtil::ClientToServerResponseDebugString(
const ClientToServerResponse& response) {
// Add more handlers as needed.
std::string output;
if (response.has_get_updates())
output.append(GetUpdatesResponseString(response.get_updates()));
return output;
}
} // namespace syncer