summaryrefslogtreecommitdiffstats
path: root/chrome/browser/metrics
diff options
context:
space:
mode:
authorstuartmorgan@chromium.org <stuartmorgan@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98>2011-09-29 15:18:10 +0000
committerstuartmorgan@chromium.org <stuartmorgan@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98>2011-09-29 15:18:10 +0000
commitcac267c7b19dbe68dd36a2f4d206e1fa9f530048 (patch)
tree2dc638aefc766e5d2d279f5b1e22928a875dcb55 /chrome/browser/metrics
parent57c9ae399f80f00b533aa92c9eafeee748aa3b1c (diff)
downloadchromium_src-cac267c7b19dbe68dd36a2f4d206e1fa9f530048.zip
chromium_src-cac267c7b19dbe68dd36a2f4d206e1fa9f530048.tar.gz
chromium_src-cac267c7b19dbe68dd36a2f4d206e1fa9f530048.tar.bz2
Factor a log management helper out of MetricsService
This factors the details of the log transitions between current, staged (previously called pending; renamed for clarity), and unsent (i.e., to-be-stored) log, and all the encoding/compression involved in those transitions, into a helper class: MetricsLogManager. Also simplifies the state machine slightly by combining two states (SEND_OLD_INITIAL_LOGS and SENDING_OLD_LOGS) that behaved the same, moving the logic for deciding which log to send first into the new helper so that the behavior of prioritizing initial logs is unchanged). In order to allow this to continue to be shared with ChromeFrame, the serialization details are factored into a secondary helper; this isn't necessarily ideal, but it does have the benefit of making unit-testing the components easier. This is primarily to facilitate a second change that will add more cases where log serialization/deserialization happens, but even on its own it should be helpful since it moves a discrete chunk out of the overly-large MetricsService+MetricsServiceBase, increasing testability, readability, and maintainability. BUG=None TEST=Metrics should continue to work. Review URL: http://codereview.chromium.org/7237057 git-svn-id: svn://svn.chromium.org/chrome/trunk/src@103280 0039d316-1c4b-4281-b951-d872f2087c98
Diffstat (limited to 'chrome/browser/metrics')
-rw-r--r--chrome/browser/metrics/metrics_log_serializer.cc198
-rw-r--r--chrome/browser/metrics/metrics_log_serializer.h69
-rw-r--r--chrome/browser/metrics/metrics_log_serializer_unittest.cc192
-rw-r--r--chrome/browser/metrics/metrics_service.cc399
-rw-r--r--chrome/browser/metrics/metrics_service.h92
-rw-r--r--chrome/browser/metrics/metrics_service_unittest.cc173
6 files changed, 561 insertions, 562 deletions
diff --git a/chrome/browser/metrics/metrics_log_serializer.cc b/chrome/browser/metrics/metrics_log_serializer.cc
new file mode 100644
index 0000000..bbddf60
--- /dev/null
+++ b/chrome/browser/metrics/metrics_log_serializer.cc
@@ -0,0 +1,198 @@
+// Copyright (c) 2011 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/browser/metrics/metrics_log_serializer.h"
+
+#include "base/base64.h"
+#include "base/md5.h"
+#include "base/metrics/histogram.h"
+#include "chrome/browser/browser_process.h"
+#include "chrome/browser/prefs/pref_service.h"
+#include "chrome/browser/prefs/scoped_user_pref_update.h"
+#include "chrome/common/pref_names.h"
+
+// The number of "initial" logs we're willing to save, and hope to send during
+// a future Chrome session. Initial logs contain crash stats, and are pretty
+// small.
+static const size_t kMaxInitialLogsPersisted = 20;
+
+// The number of ongoing logs we're willing to save persistently, and hope to
+// send during a this or future sessions. Note that each log may be pretty
+// large, as presumably the related "initial" log wasn't sent (probably nothing
+// was, as the user was probably off-line). As a result, the log probably kept
+// accumulating while the "initial" log was stalled, and couldn't be sent. As a
+// result, we don't want to save too many of these mega-logs.
+// A "standard shutdown" will create a small log, including just the data that
+// was not yet been transmitted, and that is normal (to have exactly one
+// ongoing_log_ at startup).
+static const size_t kMaxOngoingLogsPersisted = 8;
+
+// We append (2) more elements to persisted lists: the size of the list and a
+// checksum of the elements.
+static const size_t kChecksumEntryCount = 2;
+
+namespace {
+// TODO(ziadh): This is here temporarily for a side experiment. Remove later
+// on.
+enum LogStoreStatus {
+ STORE_SUCCESS, // Successfully presisted log.
+ ENCODE_FAIL, // Failed to encode log.
+ COMPRESS_FAIL, // Failed to compress log.
+ END_STORE_STATUS // Number of bins to use to create the histogram.
+};
+
+MetricsLogSerializer::LogReadStatus MakeRecallStatusHistogram(
+ MetricsLogSerializer::LogReadStatus status) {
+ UMA_HISTOGRAM_ENUMERATION("PrefService.PersistentLogRecall", status,
+ MetricsLogSerializer::END_RECALL_STATUS);
+ return status;
+}
+
+// TODO(ziadh): Remove this when done with experiment.
+void MakeStoreStatusHistogram(LogStoreStatus status) {
+ UMA_HISTOGRAM_ENUMERATION("PrefService.PersistentLogStore2", status,
+ END_STORE_STATUS);
+}
+} // namespace
+
+
+MetricsLogSerializer::MetricsLogSerializer() {}
+
+MetricsLogSerializer::~MetricsLogSerializer() {}
+
+void MetricsLogSerializer::SerializeLogs(const std::vector<std::string>& logs,
+ MetricsLogManager::LogType log_type) {
+ PrefService* local_state = g_browser_process->local_state();
+ DCHECK(local_state);
+ const char* pref = NULL;
+ size_t max_store_count = 0;
+ switch (log_type) {
+ case MetricsLogManager::INITIAL_LOG:
+ pref = prefs::kMetricsInitialLogs;
+ max_store_count = kMaxInitialLogsPersisted;
+ break;
+ case MetricsLogManager::ONGOING_LOG:
+ pref = prefs::kMetricsOngoingLogs;
+ max_store_count = kMaxOngoingLogsPersisted;
+ break;
+ default:
+ NOTREACHED();
+ return;
+ };
+ ListPrefUpdate update(local_state, pref);
+ ListValue* pref_list = update.Get();
+ WriteLogsToPrefList(logs, max_store_count, pref_list);
+}
+
+void MetricsLogSerializer::DeserializeLogs(MetricsLogManager::LogType log_type,
+ std::vector<std::string>* logs) {
+ DCHECK(logs);
+ PrefService* local_state = g_browser_process->local_state();
+ DCHECK(local_state);
+
+ const char* pref = (log_type == MetricsLogManager::INITIAL_LOG) ?
+ prefs::kMetricsInitialLogs : prefs::kMetricsOngoingLogs;
+ const ListValue* unsent_logs = local_state->GetList(pref);
+ ReadLogsFromPrefList(*unsent_logs, logs);
+}
+
+// static
+void MetricsLogSerializer::WriteLogsToPrefList(
+ const std::vector<std::string>& local_list,
+ const size_t kMaxLocalListSize,
+ ListValue* list) {
+ list->Clear();
+ size_t start = 0;
+ if (local_list.size() > kMaxLocalListSize)
+ start = local_list.size() - kMaxLocalListSize;
+ DCHECK(start <= local_list.size());
+ if (local_list.size() <= start)
+ return;
+
+ // Store size at the beginning of the list.
+ list->Append(Value::CreateIntegerValue(local_list.size() - start));
+
+ base::MD5Context ctx;
+ base::MD5Init(&ctx);
+ std::string encoded_log;
+ for (std::vector<std::string>::const_iterator it = local_list.begin() + start;
+ it != local_list.end(); ++it) {
+ // We encode the compressed log as Value::CreateStringValue() expects to
+ // take a valid UTF8 string.
+ if (!base::Base64Encode(*it, &encoded_log)) {
+ MakeStoreStatusHistogram(ENCODE_FAIL);
+ list->Clear();
+ return;
+ }
+ base::MD5Update(&ctx, encoded_log);
+ list->Append(Value::CreateStringValue(encoded_log));
+ }
+
+ // Append hash to the end of the list.
+ base::MD5Digest digest;
+ base::MD5Final(&digest, &ctx);
+ list->Append(Value::CreateStringValue(base::MD5DigestToBase16(digest)));
+ DCHECK(list->GetSize() >= 3); // Minimum of 3 elements (size, data, hash).
+ MakeStoreStatusHistogram(STORE_SUCCESS);
+}
+
+// static
+MetricsLogSerializer::LogReadStatus MetricsLogSerializer::ReadLogsFromPrefList(
+ const ListValue& list,
+ std::vector<std::string>* local_list) {
+ DCHECK(local_list->empty());
+ if (list.GetSize() == 0)
+ return MakeRecallStatusHistogram(LIST_EMPTY);
+ if (list.GetSize() < 3)
+ return MakeRecallStatusHistogram(LIST_SIZE_TOO_SMALL);
+
+ // The size is stored at the beginning of the list.
+ int size;
+ bool valid = (*list.begin())->GetAsInteger(&size);
+ if (!valid)
+ return MakeRecallStatusHistogram(LIST_SIZE_MISSING);
+
+ // Account for checksum and size included in the list.
+ if (static_cast<unsigned int>(size) !=
+ list.GetSize() - kChecksumEntryCount) {
+ return MakeRecallStatusHistogram(LIST_SIZE_CORRUPTION);
+ }
+
+ base::MD5Context ctx;
+ base::MD5Init(&ctx);
+ std::string encoded_log;
+ std::string decoded_log;
+ for (ListValue::const_iterator it = list.begin() + 1;
+ it != list.end() - 1; ++it) { // Last element is the checksum.
+ valid = (*it)->GetAsString(&encoded_log);
+ if (!valid) {
+ local_list->clear();
+ return MakeRecallStatusHistogram(LOG_STRING_CORRUPTION);
+ }
+
+ base::MD5Update(&ctx, encoded_log);
+
+ if (!base::Base64Decode(encoded_log, &decoded_log)) {
+ local_list->clear();
+ return MakeRecallStatusHistogram(DECODE_FAIL);
+ }
+ local_list->push_back(decoded_log);
+ }
+
+ // Verify checksum.
+ base::MD5Digest digest;
+ base::MD5Final(&digest, &ctx);
+ std::string recovered_md5;
+ // We store the hash at the end of the list.
+ valid = (*(list.end() - 1))->GetAsString(&recovered_md5);
+ if (!valid) {
+ local_list->clear();
+ return MakeRecallStatusHistogram(CHECKSUM_STRING_CORRUPTION);
+ }
+ if (recovered_md5 != base::MD5DigestToBase16(digest)) {
+ local_list->clear();
+ return MakeRecallStatusHistogram(CHECKSUM_CORRUPTION);
+ }
+ return MakeRecallStatusHistogram(RECALL_SUCCESS);
+}
diff --git a/chrome/browser/metrics/metrics_log_serializer.h b/chrome/browser/metrics/metrics_log_serializer.h
new file mode 100644
index 0000000..d698164
--- /dev/null
+++ b/chrome/browser/metrics/metrics_log_serializer.h
@@ -0,0 +1,69 @@
+// Copyright (c) 2011 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.
+
+#ifndef CHROME_BROWSER_METRICS_METRICS_LOG_SERIALIZER_H_
+#define CHROME_BROWSER_METRICS_METRICS_LOG_SERIALIZER_H_
+#pragma once
+
+#include "base/basictypes.h"
+#include "base/gtest_prod_util.h"
+#include "chrome/common/metrics_log_manager.h"
+
+namespace base {
+class ListValue;
+}
+
+// Serializer for persisting metrics logs to prefs.
+class MetricsLogSerializer : public MetricsLogManager::LogSerializer {
+ public:
+ // Used to produce a historgram that keeps track of the status of recalling
+ // persisted per logs.
+ enum LogReadStatus {
+ RECALL_SUCCESS, // We were able to correctly recall a persisted log.
+ LIST_EMPTY, // Attempting to recall from an empty list.
+ LIST_SIZE_MISSING, // Failed to recover list size using GetAsInteger().
+ LIST_SIZE_TOO_SMALL, // Too few elements in the list (less than 3).
+ LIST_SIZE_CORRUPTION, // List size is not as expected.
+ LOG_STRING_CORRUPTION, // Failed to recover log string using GetAsString().
+ CHECKSUM_CORRUPTION, // Failed to verify checksum.
+ CHECKSUM_STRING_CORRUPTION, // Failed to recover checksum string using
+ // GetAsString().
+ DECODE_FAIL, // Failed to decode log.
+ END_RECALL_STATUS // Number of bins to use to create the histogram.
+ };
+
+ MetricsLogSerializer();
+ virtual ~MetricsLogSerializer();
+
+ // Implementation of MetricsLogManager::LogSerializer
+ virtual void SerializeLogs(const std::vector<std::string>& logs,
+ MetricsLogManager::LogType log_type);
+ virtual void DeserializeLogs(MetricsLogManager::LogType log_type,
+ std::vector<std::string>* logs);
+
+ private:
+ // Encodes the textual log data from |local_list| and writes it to the given
+ // pref list, along with list size and checksum.
+ static void WriteLogsToPrefList(const std::vector<std::string>& local_list,
+ const size_t kMaxLocalListSize,
+ base::ListValue* list);
+
+ // Decodes and verifies the textual log data from |list|, populating
+ // |local_list| and returning a status code.
+ static LogReadStatus ReadLogsFromPrefList(
+ const base::ListValue& list,
+ std::vector<std::string>* local_list);
+
+ FRIEND_TEST_ALL_PREFIXES(MetricsLogSerializerTest, EmptyLogList);
+ FRIEND_TEST_ALL_PREFIXES(MetricsLogSerializerTest, SingleElementLogList);
+ FRIEND_TEST_ALL_PREFIXES(MetricsLogSerializerTest, OverLimitLogList);
+ FRIEND_TEST_ALL_PREFIXES(MetricsLogSerializerTest, SmallRecoveredListSize);
+ FRIEND_TEST_ALL_PREFIXES(MetricsLogSerializerTest, RemoveSizeFromLogList);
+ FRIEND_TEST_ALL_PREFIXES(MetricsLogSerializerTest, CorruptSizeOfLogList);
+ FRIEND_TEST_ALL_PREFIXES(MetricsLogSerializerTest, CorruptChecksumOfLogList);
+
+ DISALLOW_COPY_AND_ASSIGN(MetricsLogSerializer);
+};
+
+#endif // CHROME_BROWSER_METRICS_METRICS_LOG_SERIALIZER_H_
diff --git a/chrome/browser/metrics/metrics_log_serializer_unittest.cc b/chrome/browser/metrics/metrics_log_serializer_unittest.cc
new file mode 100644
index 0000000..59c257b
--- /dev/null
+++ b/chrome/browser/metrics/metrics_log_serializer_unittest.cc
@@ -0,0 +1,192 @@
+// Copyright (c) 2011 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 "base/base64.h"
+#include "base/md5.h"
+#include "base/values.h"
+#include "chrome/browser/metrics/metrics_log_serializer.h"
+#include "testing/gtest/include/gtest/gtest.h"
+
+namespace {
+ class MetricsLogSerializerTest : public ::testing::Test {
+ };
+}
+
+static const size_t kMaxLocalListSize = 3;
+
+// Store and retrieve empty list.
+TEST(MetricsLogSerializerTest, EmptyLogList) {
+ ListValue list;
+ std::vector<std::string> local_list;
+
+ MetricsLogSerializer::WriteLogsToPrefList(local_list, kMaxLocalListSize,
+ &list);
+ EXPECT_EQ(0U, list.GetSize());
+
+ local_list.clear(); // ReadLogsFromPrefList() expects empty |local_list|.
+ EXPECT_EQ(MetricsLogSerializer::LIST_EMPTY,
+ MetricsLogSerializer::ReadLogsFromPrefList(list, &local_list));
+ EXPECT_EQ(0U, local_list.size());
+}
+
+// Store and retrieve a single log value.
+TEST(MetricsLogSerializerTest, SingleElementLogList) {
+ ListValue list;
+ std::vector<std::string> local_list;
+
+ local_list.push_back("Hello world!");
+ EXPECT_EQ(1U, local_list.size());
+
+ MetricsLogSerializer::WriteLogsToPrefList(local_list, kMaxLocalListSize,
+ &list);
+
+ // |list| will now contain the following:
+ // [1, Base64Encode("Hello world!"), MD5("Hello world!")].
+ EXPECT_EQ(3U, list.GetSize());
+
+ // Examine each element.
+ ListValue::const_iterator it = list.begin();
+ int size = 0;
+ (*it)->GetAsInteger(&size);
+ EXPECT_EQ(1, size);
+
+ ++it;
+ std::string str;
+ (*it)->GetAsString(&str); // Base64 encoded "Hello world!" string.
+ std::string encoded;
+ base::Base64Encode("Hello world!", &encoded);
+ EXPECT_TRUE(encoded == str);
+
+ ++it;
+ (*it)->GetAsString(&str); // MD5 for encoded "Hello world!" string.
+ EXPECT_TRUE(base::MD5String(encoded) == str);
+
+ ++it;
+ EXPECT_TRUE(it == list.end()); // Reached end of list.
+
+ local_list.clear();
+ EXPECT_EQ(MetricsLogSerializer::RECALL_SUCCESS,
+ MetricsLogSerializer::ReadLogsFromPrefList(list, &local_list));
+ EXPECT_EQ(1U, local_list.size());
+}
+
+// Store elements greater than the limit.
+TEST(MetricsLogSerializerTest, OverLimitLogList) {
+ ListValue list;
+ std::vector<std::string> local_list;
+
+ local_list.push_back("one");
+ local_list.push_back("two");
+ local_list.push_back("three");
+ local_list.push_back("four");
+ EXPECT_EQ(4U, local_list.size());
+
+ std::string expected_first;
+ base::Base64Encode(local_list[local_list.size() - kMaxLocalListSize],
+ &expected_first);
+ std::string expected_last;
+ base::Base64Encode(local_list[local_list.size() - 1],
+ &expected_last);
+
+ MetricsLogSerializer::WriteLogsToPrefList(local_list, kMaxLocalListSize,
+ &list);
+ EXPECT_EQ(kMaxLocalListSize + 2, list.GetSize());
+
+ std::string actual_first;
+ EXPECT_TRUE((*(list.begin() + 1))->GetAsString(&actual_first));
+ EXPECT_TRUE(expected_first == actual_first);
+
+ std::string actual_last;
+ EXPECT_TRUE((*(list.end() - 2))->GetAsString(&actual_last));
+ EXPECT_TRUE(expected_last == actual_last);
+
+ local_list.clear();
+ EXPECT_EQ(MetricsLogSerializer::RECALL_SUCCESS,
+ MetricsLogSerializer::ReadLogsFromPrefList(list, &local_list));
+ EXPECT_EQ(kMaxLocalListSize, local_list.size());
+}
+
+// Induce LIST_SIZE_TOO_SMALL corruption
+TEST(MetricsLogSerializerTest, SmallRecoveredListSize) {
+ ListValue list;
+ std::vector<std::string> local_list;
+
+ local_list.push_back("Hello world!");
+ EXPECT_EQ(1U, local_list.size());
+ MetricsLogSerializer::WriteLogsToPrefList(local_list, kMaxLocalListSize,
+ &list);
+ EXPECT_EQ(3U, list.GetSize());
+
+ // Remove last element.
+ list.Remove(list.GetSize() - 1, NULL);
+ EXPECT_EQ(2U, list.GetSize());
+
+ local_list.clear();
+ EXPECT_EQ(MetricsLogSerializer::LIST_SIZE_TOO_SMALL,
+ MetricsLogSerializer::ReadLogsFromPrefList(list, &local_list));
+}
+
+// Remove size from the stored list.
+TEST(MetricsLogSerializerTest, RemoveSizeFromLogList) {
+ ListValue list;
+ std::vector<std::string> local_list;
+
+ local_list.push_back("one");
+ local_list.push_back("two");
+ EXPECT_EQ(2U, local_list.size());
+ MetricsLogSerializer::WriteLogsToPrefList(local_list, kMaxLocalListSize,
+ &list);
+ EXPECT_EQ(4U, list.GetSize());
+
+ list.Remove(0, NULL); // Delete size (1st element).
+ EXPECT_EQ(3U, list.GetSize());
+
+ local_list.clear();
+ EXPECT_EQ(MetricsLogSerializer::LIST_SIZE_MISSING,
+ MetricsLogSerializer::ReadLogsFromPrefList(list, &local_list));
+}
+
+// Corrupt size of stored list.
+TEST(MetricsLogSerializerTest, CorruptSizeOfLogList) {
+ ListValue list;
+ std::vector<std::string> local_list;
+
+ local_list.push_back("Hello world!");
+ EXPECT_EQ(1U, local_list.size());
+ MetricsLogSerializer::WriteLogsToPrefList(local_list, kMaxLocalListSize,
+ &list);
+ EXPECT_EQ(3U, list.GetSize());
+
+ // Change list size from 1 to 2.
+ EXPECT_TRUE(list.Set(0, Value::CreateIntegerValue(2)));
+ EXPECT_EQ(3U, list.GetSize());
+
+ local_list.clear();
+ EXPECT_EQ(MetricsLogSerializer::LIST_SIZE_CORRUPTION,
+ MetricsLogSerializer::ReadLogsFromPrefList(list, &local_list));
+}
+
+// Corrupt checksum of stored list.
+TEST(MetricsLogSerializerTest, CorruptChecksumOfLogList) {
+ ListValue list;
+ std::vector<std::string> local_list;
+
+ local_list.clear();
+ local_list.push_back("Hello world!");
+ EXPECT_EQ(1U, local_list.size());
+ MetricsLogSerializer::WriteLogsToPrefList(local_list, kMaxLocalListSize,
+ &list);
+ EXPECT_EQ(3U, list.GetSize());
+
+ // Fetch checksum (last element) and change it.
+ std::string checksum;
+ EXPECT_TRUE((*(list.end() - 1))->GetAsString(&checksum));
+ checksum[0] = (checksum[0] == 'a') ? 'b' : 'a';
+ EXPECT_TRUE(list.Set(2, Value::CreateStringValue(checksum)));
+ EXPECT_EQ(3U, list.GetSize());
+
+ local_list.clear();
+ EXPECT_EQ(MetricsLogSerializer::CHECKSUM_CORRUPTION,
+ MetricsLogSerializer::ReadLogsFromPrefList(list, &local_list));
+}
diff --git a/chrome/browser/metrics/metrics_service.cc b/chrome/browser/metrics/metrics_service.cc
index 4efdc8c..2072626 100644
--- a/chrome/browser/metrics/metrics_service.cc
+++ b/chrome/browser/metrics/metrics_service.cc
@@ -49,10 +49,7 @@
//
// When the browser shuts down, there will typically be a fragment of an ongoing
// log that has not yet been transmitted. At shutdown time, that fragment
-// is closed (including snapshotting histograms), and converted to text. Note
-// that memory stats are not gathered during shutdown, as gathering *might* be
-// too time consuming. The textual representation of the fragment of the
-// ongoing log is then stored persistently as a string in the PrefServices, for
+// is closed (including snapshotting histograms), and persisted, for
// potential transmission during a future run of the product.
//
// There are two slightly abnormal shutdown conditions. There is a
@@ -82,7 +79,6 @@
// INIT_TASK_SCHEDULED, // Waiting for deferred init tasks to complete.
// INIT_TASK_DONE, // Waiting for timer to send initial log.
// INITIAL_LOG_READY, // Initial log generated, and waiting for reply.
-// SEND_OLD_INITIAL_LOGS, // Sending unsent logs from previous session.
// SENDING_OLD_LOGS, // Sending unsent logs from previous session.
// SENDING_CURRENT_LOGS, // Sending standard current logs as they accrue.
//
@@ -109,17 +105,12 @@
// prepared for transmission. It is also the case that any previously unsent
// logs have been loaded into instance variables for possible transmission.
//
-// SEND_OLD_INITIAL_LOGS, // Sending unsent logs from previous session.
-// This state indicates that the initial log for this session has been
-// successfully sent and it is now time to send any "initial logs" that were
-// saved from previous sessions. Most commonly, there are none, but all old
-// logs that were "initial logs" must be sent before this state is exited.
-//
// SENDING_OLD_LOGS, // Sending unsent logs from previous session.
-// This state indicates that there are no more unsent initial logs, and now any
-// ongoing logs from previous sessions should be transmitted. All such logs
-// will be transmitted before exiting this state, and proceeding with ongoing
-// logs from the current session (see next state).
+// This state indicates that the initial log for this session has been
+// successfully sent and it is now time to send any logs that were
+// saved from previous sessions. All such logs will be transmitted before
+// exiting this state, and proceeding with ongoing logs from the current session
+// (see next state).
//
// SENDING_CURRENT_LOGS, // Sending standard current logs as they accrue.
// Current logs are being accumulated. Typically every 20 minutes a log is
@@ -131,19 +122,16 @@
// and remain in the latter until shutdown.
//
// The one unusual case is when the user asks that we stop logging. When that
-// happens, any pending (transmission in progress) log is pushed into the list
-// of old unsent logs (the appropriate list, depending on whether it is an
-// initial log, or an ongoing log). An addition, any log that is currently
-// accumulating is also finalized, and pushed into the unsent log list. With
-// those pushes performed, we regress back to the SEND_OLD_INITIAL_LOGS state in
-// case the user enables log recording again during this session. This way
-// anything we have "pushed back" will be sent automatically if/when we progress
-// back to SENDING_CURRENT_LOG state.
+// happens, any staged (transmission in progress) log is persisted, and any log
+// log that is currently accumulating is also finalized and persisted. We then
+// regress back to the SEND_OLD_LOGS state in case the user enables log
+// recording again during this session. This way anything we have persisted
+// will be sent automatically if/when we progress back to SENDING_CURRENT_LOG
+// state.
//
-// Also note that whenever the member variables containing unsent logs are
-// modified (i.e., when we send an old log), we mirror the list of logs into
-// the PrefServices. This ensures that IF we crash, we won't start up and
-// retransmit our old logs again.
+// Also note that whenever we successfully send an old log, we mirror the list
+// of logs into the PrefService. This ensures that IF we crash, we won't start
+// up and retransmit our old logs again.
//
// Due to race conditions, it is always possible that a log file could be sent
// twice. For example, if a log file is sent, but not yet acknowledged by
@@ -156,14 +144,12 @@
#include "chrome/browser/metrics/metrics_service.h"
-#include "base/base64.h"
#include "base/bind.h"
#include "base/callback.h"
#include "base/command_line.h"
#include "base/md5.h"
#include "base/metrics/histogram.h"
#include "base/string_number_conversions.h"
-#include "base/string_util.h" // For WriteInto().
#include "base/threading/platform_thread.h"
#include "base/threading/thread.h"
#include "base/utf_string_conversions.h"
@@ -173,6 +159,7 @@
#include "chrome/browser/memory_details.h"
#include "chrome/browser/metrics/histogram_synchronizer.h"
#include "chrome/browser/metrics/metrics_log.h"
+#include "chrome/browser/metrics/metrics_log_serializer.h"
#include "chrome/browser/metrics/metrics_reporting_scheduler.h"
#include "chrome/browser/net/network_stats.h"
#include "chrome/browser/prefs/pref_service.h"
@@ -184,6 +171,7 @@
#include "chrome/common/chrome_notification_types.h"
#include "chrome/common/chrome_switches.h"
#include "chrome/common/guid.h"
+#include "chrome/common/metrics_log_manager.h"
#include "chrome/common/pref_names.h"
#include "chrome/common/render_messages.h"
#include "content/browser/load_notification_details.h"
@@ -205,21 +193,6 @@
#include "chrome/browser/chromeos/system/statistics_provider.h"
#endif
-namespace {
-MetricsService::LogRecallStatus MakeRecallStatusHistogram(
- MetricsService::LogRecallStatus status) {
- UMA_HISTOGRAM_ENUMERATION("PrefService.PersistentLogRecall", status,
- MetricsService::END_RECALL_STATUS);
- return status;
-}
-
-// TODO(ziadh): Remove this when done with experiment.
-void MakeStoreStatusHistogram(MetricsService::LogStoreStatus status) {
- UMA_HISTOGRAM_ENUMERATION("PrefService.PersistentLogStore2", status,
- MetricsService::END_STORE_STATUS);
-}
-} // namespace
-
using base::Time;
// Check to see that we're being called on only one thread.
@@ -247,26 +220,6 @@ static const int kUploadLogAvoidRetransmitSize = 50000;
// Interval, in seconds, between state saves.
static const int kSaveStateInterval = 5 * 60; // five minutes
-// The number of "initial" logs we're willing to save, and hope to send during
-// a future Chrome session. Initial logs contain crash stats, and are pretty
-// small.
-static const size_t kMaxInitialLogsPersisted = 20;
-
-// The number of ongoing logs we're willing to save persistently, and hope to
-// send during a this or future sessions. Note that each log may be pretty
-// large, as presumably the related "initial" log wasn't sent (probably nothing
-// was, as the user was probably off-line). As a result, the log probably kept
-// accumulating while the "initial" log was stalled (pending_), and couldn't be
-// sent. As a result, we don't want to save too many of these mega-logs.
-// A "standard shutdown" will create a small log, including just the data that
-// was not yet been transmitted, and that is normal (to have exactly one
-// ongoing_log_ at startup).
-static const size_t kMaxOngoingLogsPersisted = 8;
-
-// We append (2) more elements to persisted lists: the size of the list and a
-// checksum of the elements.
-static const size_t kChecksumEntryCount = 2;
-
// static
MetricsService::ShutdownCleanliness MetricsService::clean_shutdown_status_ =
MetricsService::CLEANLY_SHUTDOWN;
@@ -419,6 +372,8 @@ MetricsService::MetricsService()
base::Closure callback = base::Bind(&MetricsService::StartScheduledUpload,
base::Unretained(this));
scheduler_.reset(new MetricsReportingScheduler(callback));
+ log_manager_.set_log_serializer(new MetricsLogSerializer());
+ log_manager_.set_max_ongoing_log_store_size(kUploadLogAvoidRetransmitSize);
}
MetricsService::~MetricsService() {
@@ -472,10 +427,10 @@ void MetricsService::SetRecording(bool enabled) {
SetUpNotifications(&registrar_, this);
} else {
registrar_.RemoveAll();
- PushPendingLogsToUnsentLists();
- DCHECK(!pending_log());
- if (state_ > INITIAL_LOG_READY && unsent_logs())
- state_ = SEND_OLD_INITIAL_LOGS;
+ PushPendingLogsToPersistentStorage();
+ DCHECK(!log_manager_.has_staged_log());
+ if (state_ > INITIAL_LOG_READY && log_manager_.has_unsent_logs())
+ state_ = SENDING_OLD_LOGS;
}
recording_active_ = enabled;
}
@@ -536,7 +491,7 @@ void MetricsService::SetUpNotifications(NotificationRegistrar* registrar,
void MetricsService::Observe(int type,
const NotificationSource& source,
const NotificationDetails& details) {
- DCHECK(current_log_);
+ DCHECK(log_manager_.current_log());
DCHECK(IsSingleThreaded());
if (!CanLogNotification(type, source, details))
@@ -544,7 +499,8 @@ void MetricsService::Observe(int type,
switch (type) {
case content::NOTIFICATION_USER_ACTION:
- current_log_->RecordUserAction(*Details<const char*>(details).ptr());
+ log_manager_.current_log()->RecordUserAction(
+ *Details<const char*>(details).ptr());
break;
case chrome::NOTIFICATION_BROWSER_OPENED:
@@ -596,7 +552,7 @@ void MetricsService::Observe(int type,
break;
case chrome::NOTIFICATION_OMNIBOX_OPENED_URL: {
- MetricsLog* current_log = current_log_->AsMetricsLog();
+ MetricsLog* current_log = log_manager_.current_log()->AsMetricsLog();
DCHECK(current_log);
current_log->RecordOmniboxOpenedURL(
*Details<AutocompleteLog>(details).ptr());
@@ -616,8 +572,9 @@ void MetricsService::Observe(int type,
HandleIdleSinceLastTransmission(false);
- if (current_log_)
- DVLOG(1) << "METRICS: NUMBER OF EVENTS = " << current_log_->num_events();
+ if (log_manager_.current_log())
+ DVLOG(1) << "METRICS: NUMBER OF EVENTS = "
+ << log_manager_.current_log()->num_events();
}
void MetricsService::HandleIdleSinceLastTransmission(bool in_idle) {
@@ -830,10 +787,10 @@ void MetricsService::SaveLocalState() {
// Recording control methods
void MetricsService::StartRecording() {
- if (current_log_)
+ if (log_manager_.current_log())
return;
- current_log_ = new MetricsLog(client_id_, session_id_);
+ log_manager_.BeginLoggingWithLog(new MetricsLog(client_id_, session_id_));
if (state_ == INITIALIZED) {
// We only need to schedule that run once.
state_ = INIT_TASK_SCHEDULED;
@@ -851,71 +808,54 @@ void MetricsService::StartRecording() {
}
void MetricsService::StopRecording() {
- if (!current_log_)
+ if (!log_manager_.current_log())
return;
// TODO(jar): Integrate bounds on log recording more consistently, so that we
// can stop recording logs that are too big much sooner.
- if (current_log_->num_events() >= kEventLimit) {
+ if (log_manager_.current_log()->num_events() > kEventLimit) {
UMA_HISTOGRAM_COUNTS("UMA.Discarded Log Events",
- current_log_->num_events());
- current_log_->CloseLog();
- delete current_log_;
- current_log_ = NULL;
+ log_manager_.current_log()->num_events());
+ log_manager_.DiscardCurrentLog();
StartRecording(); // Start trivial log to hold our histograms.
}
- current_log_->set_hardware_class(hardware_class_); // Adds to ongoing logs.
+ // Adds to ongoing logs.
+ log_manager_.current_log()->set_hardware_class(hardware_class_);
// Put incremental data (histogram deltas, and realtime stats deltas) at the
// end of all log transmissions (initial log handles this separately).
// RecordIncrementalStabilityElements only exists on the derived
// MetricsLog class.
- MetricsLog* current_log = current_log_->AsMetricsLog();
+ MetricsLog* current_log = log_manager_.current_log()->AsMetricsLog();
DCHECK(current_log);
current_log->RecordIncrementalStabilityElements();
RecordCurrentHistograms();
- current_log_->CloseLog();
- pending_log_ = current_log_;
- current_log_ = NULL;
+ log_manager_.StageCurrentLogForUpload();
}
-void MetricsService::PushPendingLogsToUnsentLists() {
+void MetricsService::PushPendingLogsToPersistentStorage() {
if (state_ < INITIAL_LOG_READY)
return; // We didn't and still don't have time to get plugin list etc.
- if (pending_log()) {
- PreparePendingLogText();
+ if (log_manager_.has_staged_log()) {
if (state_ == INITIAL_LOG_READY) {
// We may race here, and send second copy of initial log later.
- unsent_initial_logs_.push_back(compressed_log_);
- state_ = SEND_OLD_INITIAL_LOGS;
+ log_manager_.StoreStagedLogAsUnsent(MetricsLogManager::INITIAL_LOG);
+ state_ = SENDING_OLD_LOGS;
} else {
// TODO(jar): Verify correctness in other states, including sending unsent
// initial logs.
- PushPendingLogTextToUnsentOngoingLogs();
+ log_manager_.StoreStagedLogAsUnsent(MetricsLogManager::ONGOING_LOG);
}
- DiscardPendingLog();
}
- DCHECK(!pending_log());
+ DCHECK(!log_manager_.has_staged_log());
StopRecording();
- PreparePendingLogText();
- PushPendingLogTextToUnsentOngoingLogs();
- DiscardPendingLog();
+ log_manager_.StoreStagedLogAsUnsent(MetricsLogManager::ONGOING_LOG);
StoreUnsentLogs();
}
-void MetricsService::PushPendingLogTextToUnsentOngoingLogs() {
- if (compressed_log_.length() >
- static_cast<size_t>(kUploadLogAvoidRetransmitSize)) {
- UMA_HISTOGRAM_COUNTS("UMA.Large Accumulated Log Not Persisted",
- static_cast<int>(compressed_log_.length()));
- return;
- }
- unsent_ongoing_logs_.push_back(compressed_log_);
-}
-
//------------------------------------------------------------------------------
// Transmission of logs methods
@@ -998,20 +938,20 @@ void MetricsService::OnHistogramSynchronizationDone() {
return;
}
- MakePendingLog();
+ MakeStagedLog();
- // MakePendingLog should have put something in the pending log, if it didn't,
- // we skip this upload and hope things work out next time.
- if (!pending_log()) {
+ // MakeStagedLog should have prepared log text; if it didn't, skip this
+ // upload and hope things work out next time.
+ if (log_manager_.staged_log_text().empty()) {
scheduler_->UploadCancelled();
return;
}
- PrepareFetchWithPendingLog();
+ PrepareFetchWithStagedLog();
if (!current_fetch_.get()) {
// Compression failed, and log discarded :-/.
- DiscardPendingLog();
+ log_manager_.DiscardStagedLog();
scheduler_->UploadCancelled();
// TODO(jar): If compression failed, we should have created a tiny log and
// compressed that, so that we can signal that we're losing logs.
@@ -1027,8 +967,8 @@ void MetricsService::OnHistogramSynchronizationDone() {
}
-void MetricsService::MakePendingLog() {
- if (pending_log())
+void MetricsService::MakeStagedLog() {
+ if (log_manager_.has_staged_log())
return;
switch (state_) {
@@ -1043,23 +983,13 @@ void MetricsService::MakePendingLog() {
// from us.
PrepareInitialLog();
DCHECK(state_ == INIT_TASK_DONE);
- RecallUnsentLogs();
+ log_manager_.LoadPersistedUnsentLogs();
state_ = INITIAL_LOG_READY;
break;
- case SEND_OLD_INITIAL_LOGS:
- if (!unsent_initial_logs_.empty()) {
- compressed_log_ = unsent_initial_logs_.back();
- unsent_initial_logs_.pop_back();
- break;
- }
- state_ = SENDING_OLD_LOGS;
- // Fall through.
-
case SENDING_OLD_LOGS:
- if (!unsent_ongoing_logs_.empty()) {
- compressed_log_ = unsent_ongoing_logs_.back();
- unsent_ongoing_logs_.pop_back();
+ if (log_manager_.has_unsent_logs()) {
+ log_manager_.StageNextStoredLogForUpload();
break;
}
state_ = SENDING_CURRENT_LOGS;
@@ -1075,7 +1005,7 @@ void MetricsService::MakePendingLog() {
return;
}
- DCHECK(pending_log());
+ DCHECK(log_manager_.has_staged_log());
}
void MetricsService::PrepareInitialLog() {
@@ -1085,187 +1015,35 @@ void MetricsService::PrepareInitialLog() {
log->set_hardware_class(hardware_class_); // Adds to initial log.
log->RecordEnvironment(plugins_, profile_dictionary_.get());
- // Histograms only get written to current_log_, so setup for the write.
- MetricsLogBase* save_log = current_log_;
- current_log_ = log;
- RecordCurrentHistograms(); // Into current_log_... which is really log.
- current_log_ = save_log;
-
- log->CloseLog();
- DCHECK(!pending_log());
- pending_log_ = log;
-}
-
-// static
-MetricsService::LogRecallStatus MetricsService::RecallUnsentLogsHelper(
- const ListValue& list,
- std::vector<std::string>* local_list) {
- DCHECK(local_list->empty());
- if (list.GetSize() == 0)
- return MakeRecallStatusHistogram(LIST_EMPTY);
- if (list.GetSize() < 3)
- return MakeRecallStatusHistogram(LIST_SIZE_TOO_SMALL);
-
- // The size is stored at the beginning of the list.
- int size;
- bool valid = (*list.begin())->GetAsInteger(&size);
- if (!valid)
- return MakeRecallStatusHistogram(LIST_SIZE_MISSING);
-
- // Account for checksum and size included in the list.
- if (static_cast<unsigned int>(size) !=
- list.GetSize() - kChecksumEntryCount)
- return MakeRecallStatusHistogram(LIST_SIZE_CORRUPTION);
-
- base::MD5Context ctx;
- base::MD5Init(&ctx);
- std::string encoded_log;
- std::string decoded_log;
- for (ListValue::const_iterator it = list.begin() + 1;
- it != list.end() - 1; ++it) { // Last element is the checksum.
- valid = (*it)->GetAsString(&encoded_log);
- if (!valid) {
- local_list->clear();
- return MakeRecallStatusHistogram(LOG_STRING_CORRUPTION);
- }
-
- base::MD5Update(&ctx, encoded_log);
-
- if (!base::Base64Decode(encoded_log, &decoded_log)) {
- local_list->clear();
- return MakeRecallStatusHistogram(DECODE_FAIL);
- }
- local_list->push_back(decoded_log);
- }
-
- // Verify checksum.
- base::MD5Digest digest;
- base::MD5Final(&digest, &ctx);
- std::string recovered_md5;
- // We store the hash at the end of the list.
- valid = (*(list.end() - 1))->GetAsString(&recovered_md5);
- if (!valid) {
- local_list->clear();
- return MakeRecallStatusHistogram(CHECKSUM_STRING_CORRUPTION);
- }
- if (recovered_md5 != base::MD5DigestToBase16(digest)) {
- local_list->clear();
- return MakeRecallStatusHistogram(CHECKSUM_CORRUPTION);
- }
- return MakeRecallStatusHistogram(RECALL_SUCCESS);
-}
-void MetricsService::RecallUnsentLogs() {
- PrefService* local_state = g_browser_process->local_state();
- DCHECK(local_state);
-
- const ListValue* unsent_initial_logs = local_state->GetList(
- prefs::kMetricsInitialLogs);
- RecallUnsentLogsHelper(*unsent_initial_logs, &unsent_initial_logs_);
-
- const ListValue* unsent_ongoing_logs = local_state->GetList(
- prefs::kMetricsOngoingLogs);
- RecallUnsentLogsHelper(*unsent_ongoing_logs, &unsent_ongoing_logs_);
-}
-
-// static
-void MetricsService::StoreUnsentLogsHelper(
- const std::vector<std::string>& local_list,
- const size_t kMaxLocalListSize,
- ListValue* list) {
- list->Clear();
- size_t start = 0;
- if (local_list.size() > kMaxLocalListSize)
- start = local_list.size() - kMaxLocalListSize;
- DCHECK(start <= local_list.size());
- if (local_list.size() == start)
- return;
-
- // Store size at the beginning of the list.
- list->Append(Value::CreateIntegerValue(local_list.size() - start));
-
- base::MD5Context ctx;
- base::MD5Init(&ctx);
- std::string encoded_log;
- for (std::vector<std::string>::const_iterator it = local_list.begin() + start;
- it != local_list.end(); ++it) {
- // We encode the compressed log as Value::CreateStringValue() expects to
- // take a valid UTF8 string.
- if (!base::Base64Encode(*it, &encoded_log)) {
- MakeStoreStatusHistogram(ENCODE_FAIL);
- list->Clear();
- return;
- }
- base::MD5Update(&ctx, encoded_log);
- list->Append(Value::CreateStringValue(encoded_log));
- }
+ // Histograms only get written to the current log, so make the new log current
+ // before writing them.
+ log_manager_.PauseCurrentLog();
+ log_manager_.BeginLoggingWithLog(log);
+ RecordCurrentHistograms();
- // Append hash to the end of the list.
- base::MD5Digest digest;
- base::MD5Final(&digest, &ctx);
- list->Append(Value::CreateStringValue(base::MD5DigestToBase16(digest)));
- DCHECK(list->GetSize() >= 3); // Minimum of 3 elements (size, data, hash).
- MakeStoreStatusHistogram(STORE_SUCCESS);
+ DCHECK(!log_manager_.has_staged_log());
+ log_manager_.StageCurrentLogForUpload();
+ log_manager_.ResumePausedLog();
}
void MetricsService::StoreUnsentLogs() {
if (state_ < INITIAL_LOG_READY)
return; // We never Recalled the prior unsent logs.
- PrefService* local_state = g_browser_process->local_state();
- DCHECK(local_state);
-
- {
- ListPrefUpdate update(local_state, prefs::kMetricsInitialLogs);
- ListValue* unsent_initial_logs = update.Get();
- StoreUnsentLogsHelper(unsent_initial_logs_, kMaxInitialLogsPersisted,
- unsent_initial_logs);
- }
-
- {
- ListPrefUpdate update(local_state, prefs::kMetricsOngoingLogs);
- ListValue* unsent_ongoing_logs = update.Get();
- StoreUnsentLogsHelper(unsent_ongoing_logs_, kMaxOngoingLogsPersisted,
- unsent_ongoing_logs);
- }
-}
-
-void MetricsService::PreparePendingLogText() {
- DCHECK(pending_log());
- if (!compressed_log_.empty())
- return;
- int text_size = pending_log_->GetEncodedLogSize();
-
- std::string pending_log_text;
- // Leave room for the NULL terminator.
- pending_log_->GetEncodedLog(WriteInto(&pending_log_text, text_size + 1),
- text_size);
-
- if (Bzip2Compress(pending_log_text, &compressed_log_)) {
- // Allow security conscious users to see all metrics logs that we send.
- VLOG(1) << "COMPRESSED FOLLOWING METRICS LOG: " << pending_log_text;
- } else {
- LOG(DFATAL) << "Failed to compress log for transmission.";
- // We can't discard the logs as other caller functions expect that
- // |compressed_log_| not be empty. We can detect this failure at the server
- // after we transmit.
- compressed_log_ = "Unable to compress!";
- MakeStoreStatusHistogram(COMPRESS_FAIL);
- return;
- }
+ log_manager_.PersistUnsentLogs();
}
-void MetricsService::PrepareFetchWithPendingLog() {
- DCHECK(pending_log());
+void MetricsService::PrepareFetchWithStagedLog() {
+ DCHECK(!log_manager_.staged_log_text().empty());
DCHECK(!current_fetch_.get());
- PreparePendingLogText();
- DCHECK(!compressed_log_.empty());
current_fetch_.reset(new URLFetcher(GURL(WideToUTF16(server_url_)),
URLFetcher::POST,
this));
current_fetch_->set_request_context(
g_browser_process->system_request_context());
- current_fetch_->set_upload_data(kMetricsType, compressed_log_);
+ current_fetch_->set_upload_data(kMetricsType,
+ log_manager_.staged_log_text());
}
static const char* StatusToString(const net::URLRequestStatus& status) {
@@ -1312,10 +1090,11 @@ void MetricsService::OnURLFetchComplete(const URLFetcher* source,
bool discard_log = false;
if (!upload_succeeded &&
- (compressed_log_.length() >
+ (log_manager_.staged_log_text().length() >
static_cast<size_t>(kUploadLogAvoidRetransmitSize))) {
- UMA_HISTOGRAM_COUNTS("UMA.Large Rejected Log was Discarded",
- static_cast<int>(compressed_log_.length()));
+ UMA_HISTOGRAM_COUNTS(
+ "UMA.Large Rejected Log was Discarded",
+ static_cast<int>(log_manager_.staged_log_text().length()));
discard_log = true;
} else if (response_code == 400) {
// Bad syntax. Retransmission won't work.
@@ -1331,10 +1110,9 @@ void MetricsService::OnURLFetchComplete(const URLFetcher* source,
VLOG(1) << "METRICS RESPONSE DATA: " << data;
switch (state_) {
case INITIAL_LOG_READY:
- state_ = SEND_OLD_INITIAL_LOGS;
+ state_ = SENDING_OLD_LOGS;
break;
- case SEND_OLD_INITIAL_LOGS:
case SENDING_OLD_LOGS:
// Store the updated list to disk now that the removed log is uploaded.
StoreUnsentLogs();
@@ -1348,14 +1126,14 @@ void MetricsService::OnURLFetchComplete(const URLFetcher* source,
break;
}
- DiscardPendingLog();
+ log_manager_.DiscardStagedLog();
// Since we sent a log, make sure our in-memory state is recorded to disk.
PrefService* local_state = g_browser_process->local_state();
DCHECK(local_state);
if (local_state)
local_state->ScheduleSavePersistentPrefs();
- if (unsent_logs())
+ if (log_manager_.has_unsent_logs())
DCHECK(state_ < SENDING_CURRENT_LOGS);
}
@@ -1363,7 +1141,8 @@ void MetricsService::OnURLFetchComplete(const URLFetcher* source,
// don't consider that a sign that the server is in trouble.
bool server_is_healthy = upload_succeeded || response_code == 400;
- scheduler_->UploadFinished(server_is_healthy, unsent_logs());
+ scheduler_->UploadFinished(server_is_healthy,
+ log_manager_.has_unsent_logs());
// Collect network stats if UMA upload succeeded.
if (server_is_healthy && io_thread_)
@@ -1373,11 +1152,11 @@ void MetricsService::OnURLFetchComplete(const URLFetcher* source,
void MetricsService::LogBadResponseCode() {
VLOG(1) << "Verify your metrics logs are formatted correctly. Verify server "
"is active at " << server_url_;
- if (!pending_log()) {
+ if (!log_manager_.has_staged_log()) {
VLOG(1) << "METRICS: Recorder shutdown during log transmission.";
} else {
VLOG(1) << "METRICS: transmission retry being scheduled for "
- << compressed_log_;
+ << log_manager_.staged_log_text();
}
}
@@ -1417,7 +1196,7 @@ void MetricsService::LogWindowChange(int type,
}
// TODO(brettw) we should have some kind of ID for the parent.
- current_log_->RecordWindowEvent(window_type, controller_id, 0);
+ log_manager_.current_log()->RecordWindowEvent(window_type, controller_id, 0);
}
void MetricsService::LogLoadComplete(int type,
@@ -1433,11 +1212,11 @@ void MetricsService::LogLoadComplete(int type,
const Details<LoadNotificationDetails> load_details(details);
int controller_id = window_map_[details.map_key()];
- current_log_->RecordLoadEvent(controller_id,
- load_details->url(),
- load_details->origin(),
- load_details->session_index(),
- load_details->load_time());
+ log_manager_.current_log()->RecordLoadEvent(controller_id,
+ load_details->url(),
+ load_details->origin(),
+ load_details->session_index(),
+ load_details->load_time());
}
void MetricsService::IncrementPrefValue(const char* path) {
diff --git a/chrome/browser/metrics/metrics_service.h b/chrome/browser/metrics/metrics_service.h
index b3e38f2..dc781e4 100644
--- a/chrome/browser/metrics/metrics_service.h
+++ b/chrome/browser/metrics/metrics_service.h
@@ -37,7 +37,6 @@ class TemplateURLService;
namespace base {
class DictionaryValue;
-class ListValue;
class MessageLoopProxy;
}
@@ -54,31 +53,6 @@ class MetricsService : public NotificationObserver,
public URLFetcher::Delegate,
public MetricsServiceBase {
public:
- // Used to produce a historgram that keeps track of the status of recalling
- // persisted per logs.
- enum LogRecallStatus {
- RECALL_SUCCESS, // We were able to correctly recall a persisted log.
- LIST_EMPTY, // Attempting to recall from an empty list.
- LIST_SIZE_MISSING, // Failed to recover list size using GetAsInteger().
- LIST_SIZE_TOO_SMALL, // Too few elements in the list (less than 3).
- LIST_SIZE_CORRUPTION, // List size is not as expected.
- LOG_STRING_CORRUPTION, // Failed to recover log string using GetAsString().
- CHECKSUM_CORRUPTION, // Failed to verify checksum.
- CHECKSUM_STRING_CORRUPTION, // Failed to recover checksum string using
- // GetAsString().
- DECODE_FAIL, // Failed to decode log.
- END_RECALL_STATUS // Number of bins to use to create the histogram.
- };
-
- // TODO(ziadh): This is here temporarily for a side experiment. Remove later
- // on.
- enum LogStoreStatus {
- STORE_SUCCESS, // Successfully presisted log.
- ENCODE_FAIL, // Failed to encode log.
- COMPRESS_FAIL, // Failed to compress log.
- END_STORE_STATUS // Number of bins to use to create the histogram.
- };
-
MetricsService();
virtual ~MetricsService();
@@ -156,7 +130,6 @@ class MetricsService : public NotificationObserver,
INIT_TASK_SCHEDULED, // Waiting for deferred init tasks to complete.
INIT_TASK_DONE, // Waiting for timer to send initial log.
INITIAL_LOG_READY, // Initial log generated, and waiting for reply.
- SEND_OLD_INITIAL_LOGS, // Sending unsent logs from previous session.
SENDING_OLD_LOGS, // Sending unsent logs from previous session.
SENDING_CURRENT_LOGS, // Sending standard current logs as they acrue.
};
@@ -221,17 +194,12 @@ class MetricsService : public NotificationObserver,
void StartRecording();
// Called to stop recording user experience metrics.
- // Adds any last information to current_log_ and then moves it to pending_log_
- // for upload.
+ // Adds any last information to current_log_ and then stages it for upload.
void StopRecording();
- // Deletes pending_log_ and current_log_, and pushes their text into the
- // appropriate unsent_log vectors. Called when Chrome shuts down.
- void PushPendingLogsToUnsentLists();
-
- // Save the pending_log_text_ persistently in a pref for transmission when we
- // next run. Note that IF this text is "too large," we just dicard it.
- void PushPendingLogTextToUnsentOngoingLogs();
+ // Pushes the text of the current and staged logs into persistent storage.
+ // Called when Chrome shuts down.
+ void PushPendingLogsToPersistentStorage();
// Ensures that scheduler is running, assuming the current settings are such
// that metrics should be reported. If not, this is a no-op.
@@ -247,34 +215,17 @@ class MetricsService : public NotificationObserver,
void OnHistogramSynchronizationDone();
// Takes whatever log should be uploaded next (according to the state_)
- // and makes it the pending log. If pending_log_ is not NULL,
- // MakePendingLog does nothing and returns.
- void MakePendingLog();
-
- // Check to see if there are any unsent logs from previous sessions.
- bool unsent_logs() const {
- return !unsent_initial_logs_.empty() || !unsent_ongoing_logs_.empty();
- }
+ // and makes it the staged log. If there is already a staged log, this is a
+ // no-op.
+ void MakeStagedLog();
+
// Record stats, client ID, Session ID, etc. in a special "first" log.
void PrepareInitialLog();
- // Pull copies of unsent logs from prefs into instance variables.
- void RecallUnsentLogs();
- // Decode and verify written pref log data.
- static MetricsService::LogRecallStatus RecallUnsentLogsHelper(
- const base::ListValue& list,
- std::vector<std::string>* local_list);
- // Encode and write list size and checksum for perf log data.
- static void StoreUnsentLogsHelper(const std::vector<std::string>& local_list,
- const size_t kMaxLocalListSize,
- base::ListValue* list);
- // Convert |pending_log_| to XML in |compressed_log_|, and compress it for
- // transmission.
- void PreparePendingLogText();
-
- // Convert pending_log_ to XML, compress it, and prepare to pass to server.
- // Upon return, current_fetch_ should be reset with its upload data set to
- // a compressed copy of the pending log.
- void PrepareFetchWithPendingLog();
+
+ // Prepared the staged log to be passed to the server. Upon return,
+ // current_fetch_ should be reset with its upload data set to a compressed
+ // copy of the staged log.
+ void PrepareFetchWithStagedLog();
// Implementation of URLFetcher::Delegate. Called after transmission
// completes (either successfully or with failure).
@@ -403,16 +354,6 @@ class MetricsService : public NotificationObserver,
// A number that identifies the how many times the app has been launched.
int session_id_;
- // When logs were not sent during a previous session they are queued to be
- // sent instead of currently accumulating logs. We give preference to sending
- // our inital log first, then unsent intial logs, then unsent ongoing logs.
- // Unsent logs are gathered at shutdown, and save in a persistent pref, one
- // log in each string in the following arrays.
- // Note that the vector has the oldest logs listed first (early in the
- // vector), and we'll discard old logs if we have gathered too many logs.
- std::vector<std::string> unsent_initial_logs_;
- std::vector<std::string> unsent_ongoing_logs_;
-
// Maps NavigationControllers (corresponding to tabs) or Browser
// (corresponding to Windows) to a unique integer that we will use to identify
// it. |next_window_id_| is used to track which IDs we have used so far.
@@ -448,13 +389,6 @@ class MetricsService : public NotificationObserver,
// exited-cleanly bit in the prefs.
static ShutdownCleanliness clean_shutdown_status_;
- FRIEND_TEST_ALL_PREFIXES(MetricsServiceTest, EmptyLogList);
- FRIEND_TEST_ALL_PREFIXES(MetricsServiceTest, SingleElementLogList);
- FRIEND_TEST_ALL_PREFIXES(MetricsServiceTest, OverLimitLogList);
- FRIEND_TEST_ALL_PREFIXES(MetricsServiceTest, SmallRecoveredListSize);
- FRIEND_TEST_ALL_PREFIXES(MetricsServiceTest, RemoveSizeFromLogList);
- FRIEND_TEST_ALL_PREFIXES(MetricsServiceTest, CorruptSizeOfLogList);
- FRIEND_TEST_ALL_PREFIXES(MetricsServiceTest, CorruptChecksumOfLogList);
FRIEND_TEST_ALL_PREFIXES(MetricsServiceTest, ClientIdGeneratesAllZeroes);
FRIEND_TEST_ALL_PREFIXES(MetricsServiceTest, ClientIdGeneratesCorrectly);
FRIEND_TEST_ALL_PREFIXES(MetricsServiceTest, ClientIdCorrectlyFormatted);
diff --git a/chrome/browser/metrics/metrics_service_unittest.cc b/chrome/browser/metrics/metrics_service_unittest.cc
index 2ddb2f8..01263de 100644
--- a/chrome/browser/metrics/metrics_service_unittest.cc
+++ b/chrome/browser/metrics/metrics_service_unittest.cc
@@ -5,19 +5,14 @@
#include "chrome/browser/metrics/metrics_service.h"
#include <string>
-#include <vector>
#include "base/base64.h"
-#include "base/md5.h"
-#include "base/values.h"
#include "testing/gtest/include/gtest/gtest.h"
class MetricsServiceTest : public ::testing::Test {
};
-static const size_t kMaxLocalListSize = 3;
-
// Ensure the ClientId is formatted as expected.
TEST(MetricsServiceTest, ClientIdCorrectlyFormatted) {
std::string clientid = MetricsService::GenerateClientID();
@@ -33,171 +28,3 @@ TEST(MetricsServiceTest, ClientIdCorrectlyFormatted) {
}
}
-// Store and retrieve empty list.
-TEST(MetricsServiceTest, EmptyLogList) {
- ListValue list;
- std::vector<std::string> local_list;
-
- MetricsService::StoreUnsentLogsHelper(local_list, kMaxLocalListSize, &list);
- EXPECT_EQ(0U, list.GetSize());
-
- local_list.clear(); // RecallUnsentLogsHelper() expects empty |local_list|.
- EXPECT_EQ(MetricsService::LIST_EMPTY,
- MetricsService::RecallUnsentLogsHelper(list, &local_list));
- EXPECT_EQ(0U, local_list.size());
-}
-
-// Store and retrieve a single log value.
-TEST(MetricsServiceTest, SingleElementLogList) {
- ListValue list;
- std::vector<std::string> local_list;
-
- local_list.push_back("Hello world!");
- EXPECT_EQ(1U, local_list.size());
-
- MetricsService::StoreUnsentLogsHelper(local_list, kMaxLocalListSize, &list);
-
- // |list| will now contain the following:
- // [1, Base64Encode("Hello world!"), MD5("Hello world!")].
- EXPECT_EQ(3U, list.GetSize());
-
- // Examine each element.
- ListValue::const_iterator it = list.begin();
- int size = 0;
- (*it)->GetAsInteger(&size);
- EXPECT_EQ(1, size);
-
- ++it;
- std::string str;
- (*it)->GetAsString(&str); // Base64 encoded "Hello world!" string.
- std::string encoded;
- base::Base64Encode("Hello world!", &encoded);
- EXPECT_TRUE(encoded == str);
-
- ++it;
- (*it)->GetAsString(&str); // MD5 for encoded "Hello world!" string.
- EXPECT_TRUE(base::MD5String(encoded) == str);
-
- ++it;
- EXPECT_TRUE(it == list.end()); // Reached end of list.
-
- local_list.clear();
- EXPECT_EQ(MetricsService::RECALL_SUCCESS,
- MetricsService::RecallUnsentLogsHelper(list, &local_list));
- EXPECT_EQ(1U, local_list.size());
-}
-
-// Store elements greater than the limit.
-TEST(MetricsServiceTest, OverLimitLogList) {
- ListValue list;
- std::vector<std::string> local_list;
-
- local_list.push_back("one");
- local_list.push_back("two");
- local_list.push_back("three");
- local_list.push_back("four");
- EXPECT_EQ(4U, local_list.size());
-
- std::string expected_first;
- base::Base64Encode(local_list[local_list.size() - kMaxLocalListSize],
- &expected_first);
- std::string expected_last;
- base::Base64Encode(local_list[local_list.size() - 1],
- &expected_last);
-
- MetricsService::StoreUnsentLogsHelper(local_list, kMaxLocalListSize, &list);
- EXPECT_EQ(kMaxLocalListSize + 2, list.GetSize());
-
- std::string actual_first;
- EXPECT_TRUE((*(list.begin() + 1))->GetAsString(&actual_first));
- EXPECT_TRUE(expected_first == actual_first);
-
- std::string actual_last;
- EXPECT_TRUE((*(list.end() - 2))->GetAsString(&actual_last));
- EXPECT_TRUE(expected_last == actual_last);
-
- local_list.clear();
- EXPECT_EQ(MetricsService::RECALL_SUCCESS,
- MetricsService::RecallUnsentLogsHelper(list, &local_list));
- EXPECT_EQ(kMaxLocalListSize, local_list.size());
-}
-
-// Induce LIST_SIZE_TOO_SMALL corruption
-TEST(MetricsServiceTest, SmallRecoveredListSize) {
- ListValue list;
- std::vector<std::string> local_list;
-
- local_list.push_back("Hello world!");
- EXPECT_EQ(1U, local_list.size());
- MetricsService::StoreUnsentLogsHelper(local_list, kMaxLocalListSize, &list);
- EXPECT_EQ(3U, list.GetSize());
-
- // Remove last element.
- list.Remove(list.GetSize() - 1, NULL);
- EXPECT_EQ(2U, list.GetSize());
-
- local_list.clear();
- EXPECT_EQ(MetricsService::LIST_SIZE_TOO_SMALL,
- MetricsService::RecallUnsentLogsHelper(list, &local_list));
-}
-
-// Remove size from the stored list.
-TEST(MetricsServiceTest, RemoveSizeFromLogList) {
- ListValue list;
- std::vector<std::string> local_list;
-
- local_list.push_back("one");
- local_list.push_back("two");
- EXPECT_EQ(2U, local_list.size());
- MetricsService::StoreUnsentLogsHelper(local_list, kMaxLocalListSize, &list);
- EXPECT_EQ(4U, list.GetSize());
-
- list.Remove(0, NULL); // Delete size (1st element).
- EXPECT_EQ(3U, list.GetSize());
-
- local_list.clear();
- EXPECT_EQ(MetricsService::LIST_SIZE_MISSING,
- MetricsService::RecallUnsentLogsHelper(list, &local_list));
-}
-
-// Corrupt size of stored list.
-TEST(MetricsServiceTest, CorruptSizeOfLogList) {
- ListValue list;
- std::vector<std::string> local_list;
-
- local_list.push_back("Hello world!");
- EXPECT_EQ(1U, local_list.size());
- MetricsService::StoreUnsentLogsHelper(local_list, kMaxLocalListSize, &list);
- EXPECT_EQ(3U, list.GetSize());
-
- // Change list size from 1 to 2.
- EXPECT_TRUE(list.Set(0, Value::CreateIntegerValue(2)));
- EXPECT_EQ(3U, list.GetSize());
-
- local_list.clear();
- EXPECT_EQ(MetricsService::LIST_SIZE_CORRUPTION,
- MetricsService::RecallUnsentLogsHelper(list, &local_list));
-}
-
-// Corrupt checksum of stored list.
-TEST(MetricsServiceTest, CorruptChecksumOfLogList) {
- ListValue list;
- std::vector<std::string> local_list;
-
- local_list.clear();
- local_list.push_back("Hello world!");
- EXPECT_EQ(1U, local_list.size());
- MetricsService::StoreUnsentLogsHelper(local_list, kMaxLocalListSize, &list);
- EXPECT_EQ(3U, list.GetSize());
-
- // Fetch checksum (last element) and change it.
- std::string checksum;
- EXPECT_TRUE((*(list.end() - 1))->GetAsString(&checksum));
- checksum[0] = (checksum[0] == 'a') ? 'b' : 'a';
- EXPECT_TRUE(list.Set(2, Value::CreateStringValue(checksum)));
- EXPECT_EQ(3U, list.GetSize());
-
- local_list.clear();
- EXPECT_EQ(MetricsService::CHECKSUM_CORRUPTION,
- MetricsService::RecallUnsentLogsHelper(list, &local_list));
-}