Add log date to the metrics log

components/metrics/persisted_logs.cc

 // Copyright 2014 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 "components/metrics/persisted_logs.h"
 
 #include <string>
 
 #include "base/base64.h"
 #include "base/md5.h"
 #include "base/metrics/histogram_macros.h"
 #include "base/sha1.h"
 #include "base/timer/elapsed_timer.h"
 #include "components/prefs/pref_service.h"
 #include "components/prefs/scoped_user_pref_update.h"
 #include "third_party/zlib/google/compression_utils.h"
 
 namespace metrics {
 
 namespace {

[Alexei Svitkine (slow), 2016/09/28 18:50:30]

Nit: add line after

[gayane -on leave until 09-2017, 2016/09/28 20:50:50]

Done.

+const char kLogHashKey[] = "hash";
+const char kLogTimestampKey[] = "timestamp";
+const char kLogDataKey[] = "data";
 
 PersistedLogs::LogReadStatus MakeRecallStatusHistogram(
     PersistedLogs::LogReadStatus status) {
   UMA_HISTOGRAM_ENUMERATION("PrefService.PersistentLogRecallProtobufs",
                             status, PersistedLogs::END_RECALL_STATUS);
   return status;
 }
 
 // Reads the value at |index| from |list_value| as a string and Base64-decodes
 // it into |result|. Returns true on success.
 bool ReadBase64String(const base::ListValue& list_value,
                       size_t index,
                       std::string* result) {
   std::string base64_result;
   if (!list_value.GetString(index, &base64_result))
     return false;
   return base::Base64Decode(base64_result, result);
 }
 
-// Base64-encodes |str| and appends the result to |list_value|.
-void AppendBase64String(const std::string& str, base::ListValue* list_value) {
-  std::string base64_str;
-  base::Base64Encode(str, &base64_str);
-  list_value->AppendString(base64_str);
+std::string EncodeToBase64(const std::string& to_convert) {
+  std::string base64_result;
+  base::Base64Encode(to_convert, &base64_result);
+  return base64_result;
+}
+
+std::string DecodeFromBase64(const std::string& to_convert) {
+  std::string result;
+  base::Base64Decode(to_convert, &result);
+  return result;
 }
 
 }  // namespace
 
-void PersistedLogs::LogHashPair::Init(const std::string& log_data) {
+void PersistedLogs::LogInfo::Init(const std::string& log_data) {
   DCHECK(!log_data.empty());
 
   if (!compression::GzipCompress(log_data, &compressed_log_data)) {
     NOTREACHED();
     return;
   }
 
   UMA_HISTOGRAM_PERCENTAGE(
       "UMA.ProtoCompressionRatio",
       static_cast<int>(100 * compressed_log_data.size() / log_data.size()));
 
   hash = base::SHA1HashString(log_data);
+  timestamp = (base::Time::Now() - base::Time::UnixEpoch()).InSeconds();

[Alexei Svitkine (slow), 2016/09/28 18:50:30]

Isn't return value int64_t but your field is an int?

[gayane -on leave until 09-2017, 2016/09/28 20:50:49]

hmm right. I had a look and dictionaries have only SetInteger and SetDouble and
no long. 
i calculated that 100 years in seconds will fit in 32bits

[Alexei Svitkine (slow), 2016/09/29 16:46:40]

That's a 100 years since unix epoch? So 56 years at this point?

I looked at how we store other timestamps and looks like we just use strings and
store the TimeT of the value.

e.g.

    local_state_->SetInt64(prefs::kInstallDate,
                           client_info_backup->installation_date != 0
                               ? client_info_backup->installation_date
                               : now.ToTimeT());

Which just ends up being:

  SetUserPrefValue(path, new base::StringValue(base::Int64ToString(value)));

So let's just register this as a string pref and use base::Int64ToString().

 }
 
 PersistedLogs::PersistedLogs(PrefService* local_state,
                              const char* pref_name,
                              size_t min_log_count,
                              size_t min_log_bytes,
                              size_t max_log_size)
     : local_state_(local_state),
       pref_name_(pref_name),
       min_log_count_(min_log_count),
@@ skipping 10 matching lines @@
 void PersistedLogs::SerializeLogs() const {
   ListPrefUpdate update(local_state_, pref_name_);
   WriteLogsToPrefList(update.Get());
 }
 
 PersistedLogs::LogReadStatus PersistedLogs::DeserializeLogs() {
   return ReadLogsFromPrefList(*local_state_->GetList(pref_name_));
 }
 
 void PersistedLogs::StoreLog(const std::string& log_data) {
-  list_.push_back(LogHashPair());
+  list_.push_back(LogInfo());
   list_.back().Init(log_data);
 }
 
 void PersistedLogs::StageLog() {
   // CHECK, rather than DCHECK, because swap()ing with an empty list causes
   // hard-to-identify crashes much later.
   CHECK(!list_.empty());
   DCHECK(!has_staged_log());
   staged_log_index_ = list_.size() - 1;
   DCHECK(has_staged_log());
 }
 
 void PersistedLogs::DiscardStagedLog() {
   DCHECK(has_staged_log());
   DCHECK_LT(static_cast<size_t>(staged_log_index_), list_.size());
   list_.erase(list_.begin() + staged_log_index_);
   staged_log_index_ = -1;
 }
 
-void PersistedLogs::WriteLogsToPrefList(base::ListValue* list_value) const {
+void PersistedLogs::MigrateFromOldFormat(const char* old_pref_name) {
+  ReadLogsFromPrefList_OldFormat(*local_state_->GetList(old_pref_name));
+  ListPrefUpdate update(local_state_, pref_name_);
+  WriteLogsToPrefList(update.Get());

[Alexei Svitkine (slow), 2016/09/28 18:50:30]

I don't see where WriteLogsToPrefList is implemented?

[gayane -on leave until 09-2017, 2016/09/28 20:50:50]

opps deleted that instead of WriteLogsToPrefList_OldFormat

+}

[Alexei Svitkine (slow), 2016/09/28 18:50:30]

I'm not sure we need an explicit migrate function. Just have the write function
always write in new format and things will migrate themselves whenever it's
updated.

[gayane -on leave until 09-2017, 2016/09/28 20:50:49]

But then when we read we need to read from two different prefs in two different
ways. is it preferable ? 

[Alexei Svitkine (slow), 2016/09/29 16:46:40]

Well, you're already reading from both prefs - just one of them is done in the
migrate function... so I don't really see the difference. I guess we need a tiny
bit of extra logic (if statement) about which pref to read from, but that should
be minimal.

We won't ever have data in both at the same time - since I think the full data
is written at once when writing (and so when writing in the new way, we should
clear the old pref with a todo). So then the read function just needs to have an
"if has old data, return readold();" which can have a todo to be removed when we
migrate.

+
+PersistedLogs::LogReadStatus PersistedLogs::ReadLogsFromPrefList(
+    const base::ListValue& list_value) {
+  if (list_value.empty())
+    return MakeRecallStatusHistogram(LIST_EMPTY);
+
+  const size_t log_count = list_value.GetSize();
+
+  DCHECK(list_.empty());
+  list_.resize(log_count);
+
+  for (size_t i = 0; i < log_count; ++i) {
+    const base::DictionaryValue* dict;
+    if (!list_value.GetDictionary(i, &dict) ||
+        !dict->GetString(kLogDataKey, &list_[i].compressed_log_data) ||
+        !dict->GetString(kLogHashKey, &list_[i].hash)) {
+      list_.clear();
+      return MakeRecallStatusHistogram(LOG_STRING_CORRUPTION);
+    }
+
+    list_[i].compressed_log_data =
+        DecodeFromBase64(list_[i].compressed_log_data);
+    list_[i].hash = DecodeFromBase64(list_[i].hash);
+    // Ignoring the success of this step as timestamp might not be there for
+    // older logs.
+    // NOTE: Should be added to the check with other fields once migration is
+    // over.
+    dict->GetInteger(kLogTimestampKey, &list_[i].timestamp);
+  }
+
+  return MakeRecallStatusHistogram(RECALL_SUCCESS);
+}
+
+void PersistedLogs::WriteLogsToPrefList_OldFormat(

[Alexei Svitkine (slow), 2016/09/28 18:50:30]

Do we need this anymore?

[gayane -on leave until 09-2017, 2016/09/28 20:50:49]

Nope

+    base::ListValue* list_value) const {
   list_value->Clear();
 
   // Keep the most recent logs which are smaller than |max_log_size_|.
   // We keep at least |min_log_bytes_| and |min_log_count_| of logs before
   // discarding older logs.
   size_t start = list_.size();
   size_t saved_log_count = 0;
   size_t bytes_used = 0;
   for (; start > 0; --start) {
     size_t log_size = list_[start - 1].compressed_log_data.length();
@@ skipping 17 matching lines @@
       dropped_logs_num++;
       continue;
     }
     AppendBase64String(list_[i].compressed_log_data, list_value);
     AppendBase64String(list_[i].hash, list_value);
   }
   if (dropped_logs_num > 0)
     UMA_HISTOGRAM_COUNTS("UMA.UnsentLogs.Dropped", dropped_logs_num);
 }
 
-PersistedLogs::LogReadStatus PersistedLogs::ReadLogsFromPrefList(
+PersistedLogs::LogReadStatus PersistedLogs::ReadLogsFromPrefList_OldFormat(

[Alexei Svitkine (slow), 2016/09/28 18:50:30]

Nit: ReadLogsFromOldFormatPrefList

[gayane -on leave until 09-2017, 2016/09/28 20:50:49]

Done.

     const base::ListValue& list_value) {
   if (list_value.empty())
     return MakeRecallStatusHistogram(LIST_EMPTY);
 
   // For each log, there's two entries in the list (the data and the hash).
   DCHECK_EQ(0U, list_value.GetSize() % 2);
   const size_t log_count = list_value.GetSize() / 2;
 
   // Resize |list_| ahead of time, so that values can be decoded directly into
   // the elements of the list.
   DCHECK(list_.empty());
   list_.resize(log_count);
 
   for (size_t i = 0; i < log_count; ++i) {
     if (!ReadBase64String(list_value, i * 2, &list_[i].compressed_log_data) ||
         !ReadBase64String(list_value, i * 2 + 1, &list_[i].hash)) {
       list_.clear();
       return MakeRecallStatusHistogram(LOG_STRING_CORRUPTION);
     }
   }
 
   return MakeRecallStatusHistogram(RECALL_SUCCESS);
 }
 
 }  // namespace metrics