unsent_log_store.cc 16 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473
  1. // Copyright 2014 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.
  4. #include "components/metrics/unsent_log_store.h"
  5. #include <cmath>
  6. #include <memory>
  7. #include <string>
  8. #include <utility>
  9. #include "base/base64.h"
  10. #include "base/hash/sha1.h"
  11. #include "base/metrics/histogram_macros.h"
  12. #include "base/strings/string_number_conversions.h"
  13. #include "base/strings/string_util.h"
  14. #include "base/timer/elapsed_timer.h"
  15. #include "components/metrics/unsent_log_store_metrics.h"
  16. #include "components/prefs/pref_service.h"
  17. #include "components/prefs/scoped_user_pref_update.h"
  18. #include "crypto/hmac.h"
  19. #include "third_party/zlib/google/compression_utils.h"
  20. namespace metrics {
  21. namespace {
  22. const char kLogHashKey[] = "hash";
  23. const char kLogSignatureKey[] = "signature";
  24. const char kLogTimestampKey[] = "timestamp";
  25. const char kLogDataKey[] = "data";
  26. const char kLogUnsentCountKey[] = "unsent_samples_count";
  27. const char kLogSentCountKey[] = "sent_samples_count";
  28. const char kLogPersistedSizeInKbKey[] = "unsent_persisted_size_in_kb";
  29. const char kLogUserIdKey[] = "user_id";
  30. std::string EncodeToBase64(const std::string& to_convert) {
  31. DCHECK(to_convert.data());
  32. std::string base64_result;
  33. base::Base64Encode(to_convert, &base64_result);
  34. return base64_result;
  35. }
  36. std::string DecodeFromBase64(const std::string& to_convert) {
  37. std::string result;
  38. base::Base64Decode(to_convert, &result);
  39. return result;
  40. }
  41. // Used to write unsent logs to prefs.
  42. class LogsPrefWriter {
  43. public:
  44. // Create a writer that will write unsent logs to |list_value|. |list_value|
  45. // should be a base::Value::List representing a pref. Clears the contents of
  46. // |list_value|.
  47. explicit LogsPrefWriter(base::Value::List* list_value)
  48. : list_value_(list_value) {
  49. DCHECK(list_value);
  50. list_value->clear();
  51. };
  52. LogsPrefWriter(const LogsPrefWriter&) = delete;
  53. LogsPrefWriter& operator=(const LogsPrefWriter&) = delete;
  54. ~LogsPrefWriter() { DCHECK(finished_); }
  55. // Persists |log| by appending it to |list_value_|.
  56. void WriteLogEntry(UnsentLogStore::LogInfo* log) {
  57. DCHECK(!finished_);
  58. base::Value dict_value{base::Value::Type::DICTIONARY};
  59. dict_value.SetStringKey(kLogHashKey, EncodeToBase64(log->hash));
  60. dict_value.SetStringKey(kLogSignatureKey, EncodeToBase64(log->signature));
  61. dict_value.SetStringKey(kLogDataKey,
  62. EncodeToBase64(log->compressed_log_data));
  63. dict_value.SetStringKey(kLogTimestampKey, log->timestamp);
  64. auto user_id = log->log_metadata.user_id;
  65. if (user_id.has_value()) {
  66. dict_value.SetStringKey(
  67. kLogUserIdKey, EncodeToBase64(base::NumberToString(user_id.value())));
  68. }
  69. list_value_->Append(std::move(dict_value));
  70. auto samples_count = log->log_metadata.samples_count;
  71. if (samples_count.has_value()) {
  72. unsent_samples_count_ += samples_count.value();
  73. }
  74. unsent_persisted_size_ += log->compressed_log_data.length();
  75. ++unsent_logs_count_;
  76. }
  77. // Indicates to this writer that it is finished, and that it should not write
  78. // any more logs. This also reverses |list_value_| in order to maintain the
  79. // original order of the logs that were written.
  80. void Finish() {
  81. DCHECK(!finished_);
  82. finished_ = true;
  83. std::reverse(list_value_->begin(), list_value_->end());
  84. }
  85. base::HistogramBase::Count unsent_samples_count() const {
  86. return unsent_samples_count_;
  87. }
  88. size_t unsent_persisted_size() const { return unsent_persisted_size_; }
  89. size_t unsent_logs_count() const { return unsent_logs_count_; }
  90. private:
  91. // The list where the logs will be written to. This should represent a pref.
  92. raw_ptr<base::Value::List> list_value_;
  93. // Whether or not this writer has finished writing to pref.
  94. bool finished_ = false;
  95. // The total number of histogram samples written so far.
  96. base::HistogramBase::Count unsent_samples_count_ = 0;
  97. // The total size of logs written so far.
  98. size_t unsent_persisted_size_ = 0;
  99. // The total number of logs written so far.
  100. size_t unsent_logs_count_ = 0;
  101. };
  102. bool GetString(const base::Value::Dict& dict,
  103. base::StringPiece key,
  104. std::string& out) {
  105. const std::string* value = dict.FindString(key);
  106. if (!value)
  107. return false;
  108. out = *value;
  109. return true;
  110. }
  111. } // namespace
  112. UnsentLogStore::LogInfo::LogInfo() = default;
  113. UnsentLogStore::LogInfo::LogInfo(const UnsentLogStore::LogInfo& other) =
  114. default;
  115. UnsentLogStore::LogInfo::~LogInfo() = default;
  116. void UnsentLogStore::LogInfo::Init(UnsentLogStoreMetrics* metrics,
  117. const std::string& log_data,
  118. const std::string& log_timestamp,
  119. const std::string& signing_key,
  120. const LogMetadata& optional_log_metadata) {
  121. DCHECK(!log_data.empty());
  122. if (!compression::GzipCompress(log_data, &compressed_log_data)) {
  123. NOTREACHED();
  124. return;
  125. }
  126. metrics->RecordCompressionRatio(compressed_log_data.size(), log_data.size());
  127. hash = base::SHA1HashString(log_data);
  128. if (!ComputeHMACForLog(log_data, signing_key, &signature)) {
  129. NOTREACHED() << "HMAC signing failed";
  130. }
  131. timestamp = log_timestamp;
  132. this->log_metadata = optional_log_metadata;
  133. }
  134. UnsentLogStore::UnsentLogStore(std::unique_ptr<UnsentLogStoreMetrics> metrics,
  135. PrefService* local_state,
  136. const char* log_data_pref_name,
  137. const char* metadata_pref_name,
  138. size_t min_log_count,
  139. size_t min_log_bytes,
  140. size_t max_log_size,
  141. const std::string& signing_key)
  142. : metrics_(std::move(metrics)),
  143. local_state_(local_state),
  144. log_data_pref_name_(log_data_pref_name),
  145. metadata_pref_name_(metadata_pref_name),
  146. min_log_count_(min_log_count),
  147. min_log_bytes_(min_log_bytes),
  148. max_log_size_(max_log_size != 0 ? max_log_size : static_cast<size_t>(-1)),
  149. signing_key_(signing_key),
  150. staged_log_index_(-1) {
  151. DCHECK(local_state_);
  152. // One of the limit arguments must be non-zero.
  153. DCHECK(min_log_count_ > 0 || min_log_bytes_ > 0);
  154. }
  155. UnsentLogStore::~UnsentLogStore() {}
  156. bool UnsentLogStore::has_unsent_logs() const {
  157. return !!size();
  158. }
  159. // True if a log has been staged.
  160. bool UnsentLogStore::has_staged_log() const {
  161. return staged_log_index_ != -1;
  162. }
  163. // Returns the compressed data of the element in the front of the list.
  164. const std::string& UnsentLogStore::staged_log() const {
  165. DCHECK(has_staged_log());
  166. return list_[staged_log_index_]->compressed_log_data;
  167. }
  168. // Returns the hash of element in the front of the list.
  169. const std::string& UnsentLogStore::staged_log_hash() const {
  170. DCHECK(has_staged_log());
  171. return list_[staged_log_index_]->hash;
  172. }
  173. // Returns the signature of element in the front of the list.
  174. const std::string& UnsentLogStore::staged_log_signature() const {
  175. DCHECK(has_staged_log());
  176. return list_[staged_log_index_]->signature;
  177. }
  178. // Returns the timestamp of the element in the front of the list.
  179. const std::string& UnsentLogStore::staged_log_timestamp() const {
  180. DCHECK(has_staged_log());
  181. return list_[staged_log_index_]->timestamp;
  182. }
  183. // Returns the user id of the current staged log.
  184. absl::optional<uint64_t> UnsentLogStore::staged_log_user_id() const {
  185. DCHECK(has_staged_log());
  186. return list_[staged_log_index_]->log_metadata.user_id;
  187. }
  188. // static
  189. bool UnsentLogStore::ComputeHMACForLog(const std::string& log_data,
  190. const std::string& signing_key,
  191. std::string* signature) {
  192. crypto::HMAC hmac(crypto::HMAC::SHA256);
  193. const size_t digest_length = hmac.DigestLength();
  194. unsigned char* hmac_data = reinterpret_cast<unsigned char*>(
  195. base::WriteInto(signature, digest_length + 1));
  196. return hmac.Init(signing_key) &&
  197. hmac.Sign(log_data, hmac_data, digest_length);
  198. }
  199. void UnsentLogStore::StageNextLog() {
  200. // CHECK, rather than DCHECK, because swap()ing with an empty list causes
  201. // hard-to-identify crashes much later.
  202. CHECK(!list_.empty());
  203. DCHECK(!has_staged_log());
  204. staged_log_index_ = list_.size() - 1;
  205. DCHECK(has_staged_log());
  206. }
  207. void UnsentLogStore::DiscardStagedLog() {
  208. DCHECK(has_staged_log());
  209. DCHECK_LT(static_cast<size_t>(staged_log_index_), list_.size());
  210. list_.erase(list_.begin() + staged_log_index_);
  211. staged_log_index_ = -1;
  212. }
  213. void UnsentLogStore::MarkStagedLogAsSent() {
  214. DCHECK(has_staged_log());
  215. DCHECK_LT(static_cast<size_t>(staged_log_index_), list_.size());
  216. auto samples_count = list_[staged_log_index_]->log_metadata.samples_count;
  217. if (samples_count.has_value())
  218. total_samples_sent_ += samples_count.value();
  219. }
  220. void UnsentLogStore::TrimAndPersistUnsentLogs(bool overwrite_in_memory_store) {
  221. ListPrefUpdate update(local_state_, log_data_pref_name_);
  222. LogsPrefWriter writer(&update->GetList());
  223. std::vector<std::unique_ptr<LogInfo>> trimmed_list;
  224. size_t bytes_used = 0;
  225. // The distance of the staged log from the end of the list of logs, which is
  226. // usually 0 (end of list). This is used in case there is currently a staged
  227. // log, which may or may not get trimmed. We want to keep track of the new
  228. // position of the staged log after trimming so that we can update
  229. // |staged_log_index_|.
  230. absl::optional<size_t> staged_index_distance;
  231. // Reverse order, so newest ones are prioritized.
  232. for (int i = list_.size() - 1; i >= 0; --i) {
  233. size_t log_size = list_[i]->compressed_log_data.length();
  234. // Hit the caps, we can stop moving the logs.
  235. if (bytes_used >= min_log_bytes_ &&
  236. writer.unsent_logs_count() >= min_log_count_) {
  237. break;
  238. }
  239. // Omit overly large individual logs.
  240. if (log_size > max_log_size_) {
  241. metrics_->RecordDroppedLogSize(log_size);
  242. continue;
  243. }
  244. bytes_used += log_size;
  245. if (staged_log_index_ == i) {
  246. staged_index_distance = writer.unsent_logs_count();
  247. }
  248. // Append log to prefs.
  249. writer.WriteLogEntry(list_[i].get());
  250. if (overwrite_in_memory_store)
  251. trimmed_list.emplace_back(std::move(list_[i]));
  252. }
  253. writer.Finish();
  254. if (overwrite_in_memory_store) {
  255. // We went in reverse order, but appended entries. So reverse list to
  256. // correct.
  257. std::reverse(trimmed_list.begin(), trimmed_list.end());
  258. size_t dropped_logs_count = list_.size() - trimmed_list.size();
  259. if (dropped_logs_count > 0)
  260. metrics_->RecordDroppedLogsNum(dropped_logs_count);
  261. // Put the trimmed list in the correct place.
  262. list_.swap(trimmed_list);
  263. // We may need to adjust the staged index since the number of logs may be
  264. // reduced.
  265. if (staged_index_distance.has_value()) {
  266. staged_log_index_ = list_.size() - 1 - staged_index_distance.value();
  267. } else {
  268. // Set |staged_log_index_| to -1. It might already be -1. E.g., at the
  269. // time we are trimming logs, there was no staged log. However, it is also
  270. // possible that we trimmed away the staged log, so we need to update the
  271. // index to -1.
  272. staged_log_index_ = -1;
  273. }
  274. }
  275. WriteToMetricsPref(writer.unsent_samples_count(), total_samples_sent_,
  276. writer.unsent_persisted_size());
  277. }
  278. void UnsentLogStore::LoadPersistedUnsentLogs() {
  279. ReadLogsFromPrefList(local_state_->GetValueList(log_data_pref_name_));
  280. RecordMetaDataMetrics();
  281. }
  282. void UnsentLogStore::StoreLog(const std::string& log_data,
  283. const LogMetadata& log_metadata) {
  284. LogInfo info;
  285. info.Init(metrics_.get(), log_data,
  286. base::NumberToString(base::Time::Now().ToTimeT()), signing_key_,
  287. log_metadata);
  288. list_.emplace_back(std::make_unique<LogInfo>(info));
  289. }
  290. const std::string& UnsentLogStore::GetLogAtIndex(size_t index) {
  291. DCHECK_GE(index, 0U);
  292. DCHECK_LT(index, list_.size());
  293. return list_[index]->compressed_log_data;
  294. }
  295. std::string UnsentLogStore::ReplaceLogAtIndex(size_t index,
  296. const std::string& new_log_data,
  297. const LogMetadata& log_metadata) {
  298. DCHECK_GE(index, 0U);
  299. DCHECK_LT(index, list_.size());
  300. // Avoid copying of long strings.
  301. std::string old_log_data;
  302. old_log_data.swap(list_[index]->compressed_log_data);
  303. std::string old_timestamp;
  304. old_timestamp.swap(list_[index]->timestamp);
  305. // TODO(rkaplow): Would be a bit simpler if we had a method that would
  306. // just return a pointer to the logInfo so we could combine the next 3 lines.
  307. LogInfo info;
  308. info.Init(metrics_.get(), new_log_data, old_timestamp, signing_key_,
  309. log_metadata);
  310. list_[index] = std::make_unique<LogInfo>(info);
  311. return old_log_data;
  312. }
  313. void UnsentLogStore::Purge() {
  314. if (has_staged_log()) {
  315. DiscardStagedLog();
  316. }
  317. list_.clear();
  318. local_state_->ClearPref(log_data_pref_name_);
  319. // The |total_samples_sent_| isn't cleared intentionally because it is still
  320. // meaningful.
  321. if (metadata_pref_name_)
  322. local_state_->ClearPref(metadata_pref_name_);
  323. }
  324. void UnsentLogStore::ReadLogsFromPrefList(const base::Value::List& list_value) {
  325. if (list_value.empty()) {
  326. metrics_->RecordLogReadStatus(UnsentLogStoreMetrics::LIST_EMPTY);
  327. return;
  328. }
  329. const size_t log_count = list_value.size();
  330. DCHECK(list_.empty());
  331. list_.resize(log_count);
  332. for (size_t i = 0; i < log_count; ++i) {
  333. const base::Value::Dict* dict = list_value[i].GetIfDict();
  334. LogInfo info;
  335. if (!dict || !GetString(*dict, kLogDataKey, info.compressed_log_data) ||
  336. !GetString(*dict, kLogHashKey, info.hash) ||
  337. !GetString(*dict, kLogTimestampKey, info.timestamp) ||
  338. !GetString(*dict, kLogSignatureKey, info.signature)) {
  339. // Something is wrong, so we don't try to get any persisted logs.
  340. list_.clear();
  341. metrics_->RecordLogReadStatus(
  342. UnsentLogStoreMetrics::LOG_STRING_CORRUPTION);
  343. return;
  344. }
  345. info.compressed_log_data = DecodeFromBase64(info.compressed_log_data);
  346. info.hash = DecodeFromBase64(info.hash);
  347. info.signature = DecodeFromBase64(info.signature);
  348. // timestamp doesn't need to be decoded.
  349. // Extract user id of the log if it exists.
  350. const std::string* user_id_str = dict->FindString(kLogUserIdKey);
  351. if (user_id_str) {
  352. uint64_t user_id;
  353. // Only initialize the metadata if conversion was successful.
  354. if (base::StringToUint64(DecodeFromBase64(*user_id_str), &user_id))
  355. info.log_metadata.user_id = user_id;
  356. }
  357. list_[i] = std::make_unique<LogInfo>(info);
  358. }
  359. metrics_->RecordLogReadStatus(UnsentLogStoreMetrics::RECALL_SUCCESS);
  360. }
  361. void UnsentLogStore::WriteToMetricsPref(
  362. base::HistogramBase::Count unsent_samples_count,
  363. base::HistogramBase::Count sent_samples_count,
  364. size_t unsent_persisted_size) const {
  365. if (metadata_pref_name_ == nullptr)
  366. return;
  367. DictionaryPrefUpdate update(local_state_, metadata_pref_name_);
  368. base::Value::Dict& pref_data = update->GetDict();
  369. pref_data.Set(kLogUnsentCountKey, unsent_samples_count);
  370. pref_data.Set(kLogSentCountKey, sent_samples_count);
  371. // Round up to kb.
  372. pref_data.Set(kLogPersistedSizeInKbKey,
  373. static_cast<int>(std::ceil(unsent_persisted_size / 1024.0)));
  374. }
  375. void UnsentLogStore::RecordMetaDataMetrics() {
  376. if (metadata_pref_name_ == nullptr)
  377. return;
  378. const base::Value::Dict& value =
  379. local_state_->GetValueDict(metadata_pref_name_);
  380. auto unsent_samples_count = value.FindInt(kLogUnsentCountKey);
  381. auto sent_samples_count = value.FindInt(kLogSentCountKey);
  382. auto unsent_persisted_size_in_kb = value.FindInt(kLogPersistedSizeInKbKey);
  383. if (unsent_samples_count && sent_samples_count &&
  384. unsent_persisted_size_in_kb) {
  385. metrics_->RecordLastUnsentLogMetadataMetrics(
  386. unsent_samples_count.value(), sent_samples_count.value(),
  387. unsent_persisted_size_in_kb.value());
  388. }
  389. }
  390. } // namespace metrics