chrome/chrome_cleaner/logging/registry_logger.cc

// Copyright 2018 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 "chrome/chrome_cleaner/logging/registry_logger.h"

#include <stdint.h>

#include <algorithm>

#include "base/files/file_path.h"
#include "base/strings/strcat.h"
#include "base/strings/string_number_conversions.h"
#include "base/strings/string_split.h"
#include "base/strings/string_util.h"
#include "base/strings/utf_string_conversions.h"
#include "base/time/time.h"
#include "base/version.h"
#include "chrome/chrome_cleaner/constants/version.h"
#include "chrome/chrome_cleaner/os/file_path_sanitization.h"
#include "chrome/chrome_cleaner/os/registry.h"
#include "chrome/chrome_cleaner/os/registry_util.h"
#include "components/chrome_cleaner/public/constants/constants.h"

namespace chrome_cleaner {

namespace {

const wchar_t kMultiSzSeparator = L'\0';  // Must be null char.

// The separator using to join and split pending log files.
const wchar_t* kPendingLogFilesSeparatorForLogs = L":";

// Maximum length for a registry name, according to Microsoft documentation.
// https://msdn.microsoft.com/en-us/library/windows/desktop/ms724872(v=vs.85).aspx
static const size_t kMaxRegistryLength = 0x3FFF;

// Encode the current tool's version number into a uint32_t suitable for
// e.g. reporting via an UMA histogram.
// This code is the same as in
// chrome/browser/safe_browsing/chrome_cleaner/reporter_runner_win.cc
// TODO(joenotcharles): Move the shared code to components/chrome_cleaner.
uint32_t GetVersionNumber() {
  base::Version version(CHROME_CLEANER_VERSION_UTF8_STRING);
  DCHECK(!version.components().empty());
  // The version number for X.Y.Z is X*256^3+Y*256+Z. If there are additional
  // components, only the first three count, and if there are less than 3, the
  // missing values are just replaced by zero. So 1 is equivalent 1.0.0.
  DCHECK_LT(version.components()[0], 0x100U);
  uint32_t version_number = 0x1000000 * version.components()[0];
  if (version.components().size() >= 2) {
    DCHECK_LT(version.components()[1], 0x10000U);
    version_number += 0x100 * version.components()[1];
  }
  if (version.components().size() >= 3) {
    DCHECK_LT(version.components()[2], 0x100U);
    version_number += version.components()[2];
  }
  return version_number;
}

void CreateRegKey(base::win::RegKey* reg_key, const base::string16& path) {
  if (reg_key->Create(HKEY_CURRENT_USER, path.c_str(),
                      KEY_SET_VALUE | KEY_QUERY_VALUE) != ERROR_SUCCESS) {
    PLOG(ERROR) << "Failed to open registry key" << path;
  }
}

}  // namespace

// static
const wchar_t RegistryLogger::kPendingLogFilesValue[] = L"PendingLogs";

// This is an arbitrary truncation length for log upload results, that allows
// for 64 states encoded as 1;0;1;1;. When the series exceeds this length, it is
// truncated to meet it.
// static
const size_t RegistryLogger::kMaxUploadResultLength = 128;

RegistryLogger::RegistryLogger(Mode mode) : RegistryLogger(mode, "") {}

RegistryLogger::RegistryLogger(Mode mode, const std::string& suffix)
    : mode_(mode) {
  if (mode == Mode::NOOP_FOR_TESTING)
    return;

  if (suffix.length() > kMaxRegistryLength) {
    LOG(WARNING) << "Attempted creating registry key longer than limit ("
                 << suffix << "). Logger not initialized.";
    return;
  }

  if (!base::IsStringASCII(suffix)) {
    LOG(WARNING) << "Value of registry suffix (" << suffix
                 << ") must be ASCII. "
                 << "Logger not initialized";
    return;
  }

  suffix_ = base::UTF8ToUTF16(suffix);
  CreateRegKey(&logging_key_, GetLoggingKeyPath(mode));
  CreateRegKey(&scan_times_key_, GetScanTimesKeyPath(mode));
}

RegistryLogger::~RegistryLogger() {}

void RegistryLogger::WriteVersion() {
  if (logging_key_.Valid())
    logging_key_.WriteValue(kVersionValueName, GetVersionNumber());
}

void RegistryLogger::WriteExitCode(int exit_code) {
  if (logging_key_.Valid())
    logging_key_.WriteValue(kExitCodeValueName, exit_code);
}

void RegistryLogger::ClearExitCode() {
  if (logging_key_.Valid())
    logging_key_.DeleteValue(kExitCodeValueName);
}

void RegistryLogger::WriteStartTime() {
  if (logging_key_.Valid()) {
    int64_t now = base::Time::Now().ToDeltaSinceWindowsEpoch().InMicroseconds();
    logging_key_.WriteValue(kStartTimeValueName, &now, sizeof(now), REG_QWORD);
  }
}

void RegistryLogger::WriteEndTime() {
  if (logging_key_.Valid()) {
    int64_t now = base::Time::Now().ToDeltaSinceWindowsEpoch().InMicroseconds();
    logging_key_.WriteValue(kEndTimeValueName, &now, sizeof(now), REG_QWORD);
  }
}

void RegistryLogger::ClearEndTime() {
  if (logging_key_.Valid())
    logging_key_.DeleteValue(kEndTimeValueName);
}

void RegistryLogger::ClearScanTimes() {
  DCHECK_CALLED_ON_VALID_THREAD(thread_checker_);
  if (!scan_times_key_.Valid())
    return;

  if (scan_times_key_.DeleteKey(L"") != ERROR_SUCCESS) {
    PLOG(ERROR) << "Failed to delete key: '" << GetScanTimesKeyPath(mode_)
                << "'";
    return;
  }

  CreateRegKey(&scan_times_key_, GetScanTimesKeyPath(mode_));
}

void RegistryLogger::WriteScanTime(UwSId pup_id,
                                   const base::TimeDelta& scan_time) {
  if (!scan_times_key_.Valid())
    return;

  int64_t scan_time_serialized = scan_time.InMicroseconds();
  scan_times_key_.WriteValue(base::NumberToString16(pup_id).c_str(),
                             &scan_time_serialized,
                             sizeof(scan_time_serialized), REG_QWORD);
}

void RegistryLogger::WriteMemoryUsage(size_t memory_used_kb) {
  if (logging_key_.Valid()) {
    DWORD memory = memory_used_kb;
    LONG result = logging_key_.WriteValue(kMemoryUsedValueName, memory);
    PLOG_IF(ERROR, result != ERROR_SUCCESS)
        << "Failed to write memory usage to the registry. Error: " << std::hex
        << result;
  }
}

void RegistryLogger::AppendLogUploadResult(bool success) {
  if (logging_key_.Valid()) {
    base::string16 upload_results;
    // Ignore the return value, if this fails, just overwrite what is there.
    LONG result =
        logging_key_.ReadValue(kUploadResultsValueName, &upload_results);
    PLOG_IF(ERROR, result != ERROR_SUCCESS && result != ERROR_FILE_NOT_FOUND)
        << "Failed to read log upload results.";

    upload_results += success ? L"1;" : L"0;";
    if (upload_results.size() > kMaxUploadResultLength) {
      upload_results.erase(upload_results.begin(),
                           upload_results.begin() + (upload_results.size() -
                                                     kMaxUploadResultLength));
    }

    result = logging_key_.WriteValue(kUploadResultsValueName,
                                     upload_results.c_str());
    PLOG_IF(ERROR, result != ERROR_SUCCESS)
        << "Failed to persist log upload results.";
  }
}

void RegistryLogger::WriteReporterLogsUploadResult(
    SafeBrowsingReporter::Result upload_result) {
  DCHECK(mode_ == Mode::REPORTER);

  if (logging_key_.Valid()) {
    LONG result = logging_key_.WriteValue(kLogsUploadResultValueName,
                                          static_cast<DWORD>(upload_result));
    PLOG_IF(ERROR, result != ERROR_SUCCESS)
        << "Failed to persist log upload results.";
  }
}

bool RegistryLogger::AppendLogFilePath(const base::FilePath& log_file) {
  if (!logging_key_.Valid())
    return false;

  base::string16 registry_value;
  std::vector<base::string16> log_files;
  if (ReadPendingLogFiles(&log_files, nullptr)) {
    log_files.push_back(log_file.value());
    registry_value =
        base::JoinString(log_files, base::StringPiece16(&kMultiSzSeparator, 1));
  } else {
    registry_value = log_file.value();
  }

  // REG_MULTI_SZ requires an extra \0 at the end of the string.
  registry_value.append(1, L'\0');
  LONG result = logging_key_.WriteValue(
      kPendingLogFilesValue,
      reinterpret_cast<const void*>(registry_value.c_str()),
      registry_value.size() * sizeof(base::string16::value_type), REG_MULTI_SZ);
  if (result != ERROR_SUCCESS) {
    PLOG(ERROR) << "Failed to write '" << registry_value
                << "' to pending logs registry entry. Error: " << result;
    return false;
  }
  return true;
}

// TODO(csharp): Maybe optimize these, which run in O(n^2) when used
// subsequently to remove all pending log files for example.
void RegistryLogger::GetNextLogFilePath(base::FilePath* log_file) {
  DCHECK(log_file);
  log_file->clear();
  if (!logging_key_.Valid() || !logging_key_.HasValue(kPendingLogFilesValue))
    return;

  std::vector<base::string16> log_files;
  RegistryError registry_error = RegistryError::SUCCESS;
  if (!ReadPendingLogFiles(&log_files, &registry_error)) {
    PLOG(WARNING)
        << "Failed to read the list of pending log files (registry_error = "
        << static_cast<int>(registry_error) << ")";
    return;
  }

  if (log_files.empty())
    return;

  *log_file = base::FilePath(log_files[0]);
}

bool RegistryLogger::RemoveLogFilePath(const base::FilePath& log_file) {
  if (!logging_key_.Valid())
    return false;  // Assume empty when we can't read the content.

  if (!logging_key_.HasValue(kPendingLogFilesValue))
    return false;

  std::vector<base::string16> log_files;
  RegistryError registry_error = RegistryError::SUCCESS;
  if (!ReadPendingLogFiles(&log_files, &registry_error)) {
    PLOG(WARNING) << "Empty pending log files registry entry when trying to "
                  << "remove '" << log_file.value()
                  << "' (registry_error = " << static_cast<int>(registry_error)
                  << ").";
    return false;
  }

  std::vector<base::string16>::const_iterator iter =
      std::find(log_files.begin(), log_files.end(), log_file.value());
  if (iter == log_files.end()) {
    PLOG(WARNING) << "Requested log file '" << SanitizePath(log_file)
                  << "', not found in registered log files '"
                  << base::JoinString(log_files,
                                      kPendingLogFilesSeparatorForLogs)
                  << "'.";
  } else {
    iter = log_files.erase(iter);
  }
  if (log_files.empty()) {
    logging_key_.DeleteValue(kPendingLogFilesValue);
    return false;
  }

  base::string16 registry_value(
      base::JoinString(log_files, base::StringPiece16(&kMultiSzSeparator, 1)));
  // REG_MULTI_SZ requires an extra \0 at the end of the string.
  registry_value.append(1, L'\0');
  LONG result = logging_key_.WriteValue(
      kPendingLogFilesValue,
      reinterpret_cast<const void*>(registry_value.c_str()),
      registry_value.size() * sizeof(base::string16::value_type), REG_MULTI_SZ);
  if (result != ERROR_SUCCESS) {
    LOG(ERROR) << "Failed to write '" << registry_value
               << "' to pending logs registry entry. Error: " << std::hex
               << result;
    // If we fail to write to this key, might as well delete it and let the
    // caller know that there are no more log files.
    logging_key_.DeleteValue(kPendingLogFilesValue);
    return false;
  }

  return true;
}

bool RegistryLogger::RecordFoundPUPs(const std::vector<UwSId>& pups_to_store) {
  base::string16 multi_sz_value;
  for (UwSId pup_to_store : pups_to_store) {
    multi_sz_value += base::NumberToString16(pup_to_store);
    multi_sz_value += kMultiSzSeparator;
  }
  multi_sz_value += kMultiSzSeparator;

  LONG result = logging_key_.WriteValue(
      kFoundUwsValueName, reinterpret_cast<const void*>(multi_sz_value.c_str()),
      multi_sz_value.size() * sizeof(base::string16::value_type), REG_MULTI_SZ);

  if (result != ERROR_SUCCESS) {
    LOG(ERROR) << "Failed to write '" << multi_sz_value
               << "' to found UwS registry entry. Error: " << std::hex
               << result;
    return false;
  }

  return true;
}

void RegistryLogger::WriteExperimentalEngineResultCode(int exit_code) {
  if (logging_key_.Valid()) {
    LONG result = logging_key_.WriteValue(kEngineErrorCodeValueName,
                                          static_cast<DWORD>(exit_code));
    PLOG_IF(ERROR, result != ERROR_SUCCESS)
        << "Failed to persist experimental engine error code.";
  }
}

void RegistryLogger::RecordCompletedCleanup() {
  if (logging_key_.Valid()) {
    LONG result = logging_key_.WriteValue(kCleanupCompletedValueName, 1);
    PLOG_IF(ERROR, result != ERROR_SUCCESS)
        << "Failed to persist completed cleanup.";
  }
}

void RegistryLogger::ResetCompletedCleanup() {
  if (logging_key_.Valid() &&
      logging_key_.HasValue(kCleanupCompletedValueName)) {
    LONG result = logging_key_.DeleteValue(kCleanupCompletedValueName);
    PLOG_IF(ERROR, result != ERROR_SUCCESS)
        << "Failed to reset completed cleanup.";
  }
}

base::string16 RegistryLogger::GetLoggingKeyPath(Mode mode) const {
  base::string16 key_path = base::string16(kSoftwareRemovalToolRegistryKey);
  if (mode == Mode::REMOVER)
    key_path += base::string16(L"\\") + kCleanerSubKey;
  if (!suffix_.empty())
    key_path += base::string16(L"\\") + suffix_;
  return key_path;
}

base::string16 RegistryLogger::GetScanTimesKeyPath(Mode mode) const {
  return base::StrCat({GetLoggingKeyPath(mode), L"\\", kScanTimesSubKey});
}

base::string16 RegistryLogger::GetKeySuffix() const {
  return suffix_;
}

// static.
bool RegistryLogger::ReadValues(const base::win::RegKey& logging_key,
                                const wchar_t* name,
                                std::vector<base::string16>* values,
                                RegistryError* registry_error) {
  DCHECK(name);
  DCHECK(values);
  values->clear();

  base::string16 content;
  uint32_t content_type;
  if (!ReadRegistryValue(logging_key, name, &content, &content_type,
                         registry_error) ||
      content_type != REG_MULTI_SZ) {
    return false;
  }

  // Parse the double-null-terminated list of strings.
  // Note: This code is paranoid to not read outside of |buf|, in the case where
  // it may not be properly terminated.
  if (!content.empty()) {
    const wchar_t* entry = &content[0];
    const wchar_t* buffer_end = entry + content.size();
    while (entry < buffer_end && entry[0] != '\0') {
      const wchar_t* entry_end = std::find(entry, buffer_end, L'\0');
      base::string16 value(entry, entry_end);
      DCHECK(!value.empty());
      values->push_back(value);
      entry = entry_end + 1;
    }
  }
  return true;
}

bool RegistryLogger::ReadPendingLogFiles(std::vector<base::string16>* log_files,
                                         RegistryError* registry_error) {
  DCHECK(log_files);
  if (!ReadValues(logging_key_, kPendingLogFilesValue, log_files,
                  registry_error)) {
    // Don't log here since in some case this is an expected behavior. Those not
    // expecting a failure are responsible to log appropriately.
    // Delete the value in case it is corrupted, so we can properly use it next
    // time around.
    logging_key_.DeleteValue(kPendingLogFilesValue);
    return false;
  }
  return true;
}

}  // namespace chrome_cleaner