root/sync/engine/syncer_proto_util.cc

/* [<][>][^][v][top][bottom][index][help] */

DEFINITIONS

This source file includes following definitions.
  1. LogResponseProfilingData
  2. ServerConnectionErrorAsSyncerError
  3. ConvertSyncProtocolErrorTypePBToLocalType
  4. ConvertClientActionPBToLocalClientAction
  5. GetTypesToMigrate
  6. ConvertErrorPBToLocalType
  7. VerifyResponseBirthday
  8. IsSyncDisabledByAdmin
  9. AddRequestBirthday
  10. AddBagOfChips
  11. SetProtocolVersion
  12. PostAndProcessHeaders
  13. GetThrottleDelay
  14. IsVeryFirstGetUpdates
  15. ConvertLegacyErrorCodeToNewError
  16. PostClientToServerMessage
  17. ShouldMaintainPosition
  18. CopyProtoBytesIntoBlob
  19. ProtoBytesEqualsBlob
  20. CopyBlobIntoProtoBytes
  21. NameFromSyncEntity
  22. NameFromCommitEntryResponse
  23. PersistBagOfChips
  24. SyncEntityDebugString
  25. GetUpdatesResponseString
  26. ClientToServerResponseDebugString

// 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::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(&params.buffer_in);

  ScopedServerStatusWatcher server_status_watcher(scm, &params.response);
  // Fills in params.buffer_out and params.response.
  if (!scm->PostBufferWithCachedAuth(&params, &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;
  }  // 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;
    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

/* [<][>][^][v][top][bottom][index][help] */