blob: 2881f691b997cfb16afe9cd3569bca11e72abfd7 [file] [log] [blame]
Darin Petkov8032dd02011-05-09 16:33:19 -07001// Copyright (c) 2011 The Chromium OS Authors. All rights reserved.
Darin Petkov65b01462010-04-14 13:32:20 -07002// Use of this source code is governed by a BSD-style license that can be
3// found in the LICENSE file.
4
Bertrand SIMONNET4b915ae2015-07-28 15:38:14 -07005#include "metrics_daemon.h"
Darin Petkov65b01462010-04-14 13:32:20 -07006
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -08007#include <fcntl.h>
Luigi Semenzato4a6c9422014-06-30 18:12:28 -07008#include <inttypes.h>
Luigi Semenzato8accd332011-05-17 16:37:18 -07009#include <math.h>
Ken Mixter4c5daa42010-08-26 18:35:06 -070010#include <string.h>
Steve Funge86591e2014-12-01 13:38:21 -080011#include <sysexits.h>
Luigi Semenzato8accd332011-05-17 16:37:18 -070012#include <time.h>
Darin Petkov65b01462010-04-14 13:32:20 -070013
Bertrand SIMONNET4b915ae2015-07-28 15:38:14 -070014#include <base/bind.h>
Luigi Semenzato859b3f02014-02-05 15:33:19 -080015#include <base/files/file_path.h>
Ben Chan51bf92a2014-09-05 08:21:06 -070016#include <base/files/file_util.h>
Luigi Semenzato859b3f02014-02-05 15:33:19 -080017#include <base/hash.h>
Darin Petkov65b01462010-04-14 13:32:20 -070018#include <base/logging.h>
Ben Chan2e6543d2014-02-05 23:26:25 -080019#include <base/strings/string_number_conversions.h>
20#include <base/strings/string_split.h>
21#include <base/strings/string_util.h>
22#include <base/strings/stringprintf.h>
Luigi Semenzato859b3f02014-02-05 15:33:19 -080023#include <base/sys_info.h>
Steve Funge86591e2014-12-01 13:38:21 -080024#include <dbus/dbus.h>
25#include <dbus/message.h>
Bertrand SIMONNET46b49da2014-06-25 14:38:07 -070026#include "uploader/upload_service.h"
Darin Petkov65b01462010-04-14 13:32:20 -070027
Ben Chan2e6543d2014-02-05 23:26:25 -080028using base::FilePath;
29using base::StringPrintf;
Darin Petkovf27f0362010-06-04 13:14:19 -070030using base::Time;
31using base::TimeDelta;
32using base::TimeTicks;
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -080033using chromeos_metrics::PersistentInteger;
Luigi Semenzato8accd332011-05-17 16:37:18 -070034using std::map;
Darin Petkov38d5cb02010-06-24 12:10:26 -070035using std::string;
Luigi Semenzato8accd332011-05-17 16:37:18 -070036using std::vector;
37
Daniel Eratc83975a2014-04-04 08:53:44 -070038namespace {
Darin Petkovf27f0362010-06-04 13:14:19 -070039
Darin Petkov703ec972010-04-27 11:02:18 -070040#define SAFE_MESSAGE(e) (e.message ? e.message : "unknown error")
Darin Petkov40f25732013-04-29 15:07:31 +020041
Daniel Eratc83975a2014-04-04 08:53:44 -070042const char kCrashReporterInterface[] = "org.chromium.CrashReporter";
43const char kCrashReporterUserCrashSignal[] = "UserCrash";
Steve Funge86591e2014-12-01 13:38:21 -080044const char kCrashReporterMatchRule[] =
45 "type='signal',interface='%s',path='/',member='%s'";
Darin Petkov41e06232010-05-03 16:45:37 -070046
Ben Chan067ec8b2015-02-17 13:54:04 -080047// Build type of an official build.
48// See src/third_party/chromiumos-overlay/chromeos/scripts/cros_set_lsb_release.
49const char kOfficialBuild[] = "Official Build";
50
Daniel Eratc83975a2014-04-04 08:53:44 -070051const int kSecondsPerMinute = 60;
52const int kMinutesPerHour = 60;
53const int kHoursPerDay = 24;
54const int kMinutesPerDay = kHoursPerDay * kMinutesPerHour;
55const int kSecondsPerDay = kSecondsPerMinute * kMinutesPerDay;
56const int kDaysPerWeek = 7;
57const int kSecondsPerWeek = kSecondsPerDay * kDaysPerWeek;
Darin Petkov41e06232010-05-03 16:45:37 -070058
Daniel Eratc83975a2014-04-04 08:53:44 -070059// Interval between calls to UpdateStats().
Steve Funge86591e2014-12-01 13:38:21 -080060const uint32_t kUpdateStatsIntervalMs = 300000;
Darin Petkov65b01462010-04-14 13:32:20 -070061
Luigi Semenzatoc5a92342014-02-14 15:05:51 -080062const char kKernelCrashDetectedFile[] = "/var/run/kernel-crash-detected";
Daniel Eratc83975a2014-04-04 08:53:44 -070063const char kUncleanShutdownDetectedFile[] =
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -080064 "/var/run/unclean-shutdown-detected";
Ken Mixterccd84c02010-08-16 19:57:13 -070065
Daniel Eratc83975a2014-04-04 08:53:44 -070066} // namespace
67
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -080068// disk stats metrics
69
70// The {Read,Write}Sectors numbers are in sectors/second.
71// A sector is usually 512 bytes.
72
73const char MetricsDaemon::kMetricReadSectorsLongName[] =
74 "Platform.ReadSectorsLong";
75const char MetricsDaemon::kMetricWriteSectorsLongName[] =
76 "Platform.WriteSectorsLong";
77const char MetricsDaemon::kMetricReadSectorsShortName[] =
78 "Platform.ReadSectorsShort";
79const char MetricsDaemon::kMetricWriteSectorsShortName[] =
80 "Platform.WriteSectorsShort";
81
Luigi Semenzato5bd764f2011-10-14 12:03:35 -070082const int MetricsDaemon::kMetricStatsShortInterval = 1; // seconds
83const int MetricsDaemon::kMetricStatsLongInterval = 30; // seconds
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -080084
Luigi Semenzato29c7ef92011-04-12 14:12:35 -070085const int MetricsDaemon::kMetricMeminfoInterval = 30; // seconds
86
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -080087// Assume a max rate of 250Mb/s for reads (worse for writes) and 512 byte
88// sectors.
89const int MetricsDaemon::kMetricSectorsIOMax = 500000; // sectors/second
90const int MetricsDaemon::kMetricSectorsBuckets = 50; // buckets
Luigi Semenzato5bd764f2011-10-14 12:03:35 -070091// Page size is 4k, sector size is 0.5k. We're not interested in page fault
92// rates that the disk cannot sustain.
93const int MetricsDaemon::kMetricPageFaultsMax = kMetricSectorsIOMax / 8;
94const int MetricsDaemon::kMetricPageFaultsBuckets = 50;
95
96// Major page faults, i.e. the ones that require data to be read from disk.
97
98const char MetricsDaemon::kMetricPageFaultsLongName[] =
99 "Platform.PageFaultsLong";
100const char MetricsDaemon::kMetricPageFaultsShortName[] =
101 "Platform.PageFaultsShort";
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800102
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700103// Swap in and Swap out
104
105const char MetricsDaemon::kMetricSwapInLongName[] =
106 "Platform.SwapInLong";
107const char MetricsDaemon::kMetricSwapInShortName[] =
108 "Platform.SwapInShort";
109
110const char MetricsDaemon::kMetricSwapOutLongName[] =
111 "Platform.SwapOutLong";
112const char MetricsDaemon::kMetricSwapOutShortName[] =
113 "Platform.SwapOutShort";
114
Luigi Semenzatoba0c65d2014-03-17 12:28:38 -0700115const char MetricsDaemon::kMetricsProcStatFileName[] = "/proc/stat";
116const int MetricsDaemon::kMetricsProcStatFirstLineItemsCount = 11;
117
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700118// Thermal CPU throttling.
119
120const char MetricsDaemon::kMetricScaledCpuFrequencyName[] =
121 "Platform.CpuFrequencyThermalScaling";
122
Luigi Semenzato96360192014-06-04 10:53:35 -0700123// Zram sysfs entries.
124
125const char MetricsDaemon::kComprDataSizeName[] = "compr_data_size";
126const char MetricsDaemon::kOrigDataSizeName[] = "orig_data_size";
127const char MetricsDaemon::kZeroPagesName[] = "zero_pages";
128
Luigi Semenzato8accd332011-05-17 16:37:18 -0700129// Memory use stats collection intervals. We collect some memory use interval
130// at these intervals after boot, and we stop collecting after the last one,
131// with the assumption that in most cases the memory use won't change much
132// after that.
133static const int kMemuseIntervals[] = {
134 1 * kSecondsPerMinute, // 1 minute mark
135 4 * kSecondsPerMinute, // 5 minute mark
136 25 * kSecondsPerMinute, // 0.5 hour mark
137 120 * kSecondsPerMinute, // 2.5 hour mark
138 600 * kSecondsPerMinute, // 12.5 hour mark
139};
140
Darin Petkovf1e85e42010-06-10 15:59:53 -0700141MetricsDaemon::MetricsDaemon()
Steve Funge86591e2014-12-01 13:38:21 -0800142 : memuse_final_time_(0),
Luigi Semenzato8accd332011-05-17 16:37:18 -0700143 memuse_interval_index_(0),
144 read_sectors_(0),
145 write_sectors_(0),
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700146 vmstats_(),
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700147 stats_state_(kStatsShort),
Luigi Semenzatoba0c65d2014-03-17 12:28:38 -0700148 stats_initial_time_(0),
149 ticks_per_second_(0),
150 latest_cpu_use_ticks_(0) {}
Darin Petkovf1e85e42010-06-10 15:59:53 -0700151
Ken Mixter4c5daa42010-08-26 18:35:06 -0700152MetricsDaemon::~MetricsDaemon() {
Ken Mixter4c5daa42010-08-26 18:35:06 -0700153}
154
Luigi Semenzato8accd332011-05-17 16:37:18 -0700155double MetricsDaemon::GetActiveTime() {
156 struct timespec ts;
157 int r = clock_gettime(CLOCK_MONOTONIC, &ts);
158 if (r < 0) {
159 PLOG(WARNING) << "clock_gettime(CLOCK_MONOTONIC) failed";
160 return 0;
161 } else {
Luigi Semenzato4a6c9422014-06-30 18:12:28 -0700162 return ts.tv_sec + static_cast<double>(ts.tv_nsec) / (1000 * 1000 * 1000);
Luigi Semenzato8accd332011-05-17 16:37:18 -0700163 }
164}
165
Steve Funge86591e2014-12-01 13:38:21 -0800166int MetricsDaemon::Run() {
Ken Mixterccd84c02010-08-16 19:57:13 -0700167 if (CheckSystemCrash(kKernelCrashDetectedFile)) {
168 ProcessKernelCrash();
169 }
170
171 if (CheckSystemCrash(kUncleanShutdownDetectedFile)) {
172 ProcessUncleanShutdown();
173 }
174
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800175 // On OS version change, clear version stats (which are reported daily).
Ben Chanf05ab402014-08-07 00:54:59 -0700176 int32_t version = GetOsVersionHash();
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800177 if (version_cycle_->Get() != version) {
178 version_cycle_->Set(version);
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800179 kernel_crashes_version_count_->Set(0);
Luigi Semenzatoe5883fa2014-04-18 17:00:35 -0700180 version_cumulative_active_use_->Set(0);
Luigi Semenzatoba0c65d2014-03-17 12:28:38 -0700181 version_cumulative_cpu_use_->Set(0);
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800182 }
183
Steve Funge86591e2014-12-01 13:38:21 -0800184 return chromeos::DBusDaemon::Run();
Darin Petkov65b01462010-04-14 13:32:20 -0700185}
186
Bertrand SIMONNET46b49da2014-06-25 14:38:07 -0700187void MetricsDaemon::RunUploaderTest() {
Bertrand SIMONNET71a62ef2014-10-07 11:26:25 -0700188 upload_service_.reset(new UploadService(new SystemProfileCache(true,
189 config_root_),
Bertrand SIMONNETe4fa61e2015-02-18 09:38:55 -0800190 metrics_lib_,
Bertrand SIMONNET71a62ef2014-10-07 11:26:25 -0700191 server_));
Bertrand SIMONNETcac74e12014-10-09 10:14:13 -0700192 upload_service_->Init(upload_interval_, metrics_file_);
Bertrand SIMONNET46b49da2014-06-25 14:38:07 -0700193 upload_service_->UploadEvent();
194}
195
Ben Chanf05ab402014-08-07 00:54:59 -0700196uint32_t MetricsDaemon::GetOsVersionHash() {
197 static uint32_t cached_version_hash = 0;
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800198 static bool version_hash_is_cached = false;
199 if (version_hash_is_cached)
200 return cached_version_hash;
201 version_hash_is_cached = true;
202 std::string version;
203 if (base::SysInfo::GetLsbReleaseValue("CHROMEOS_RELEASE_VERSION", &version)) {
204 cached_version_hash = base::Hash(version);
205 } else if (testing_) {
206 cached_version_hash = 42; // return any plausible value for the hash
207 } else {
208 LOG(FATAL) << "could not find CHROMEOS_RELEASE_VERSION";
209 }
210 return cached_version_hash;
211}
212
Ben Chan067ec8b2015-02-17 13:54:04 -0800213bool MetricsDaemon::IsOnOfficialBuild() const {
214 std::string build_type;
215 return (base::SysInfo::GetLsbReleaseValue("CHROMEOS_RELEASE_BUILD_TYPE",
216 &build_type) &&
217 build_type == kOfficialBuild);
218}
219
Bertrand SIMONNET46b49da2014-06-25 14:38:07 -0700220void MetricsDaemon::Init(bool testing,
221 bool uploader_active,
222 MetricsLibraryInterface* metrics_lib,
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700223 const string& vmstats_path,
224 const string& scaling_max_freq_path,
Steve Fung67906c62014-10-06 15:15:30 -0700225 const string& cpuinfo_max_freq_path,
Bertrand SIMONNETcac74e12014-10-09 10:14:13 -0700226 const base::TimeDelta& upload_interval,
Steve Fung67906c62014-10-06 15:15:30 -0700227 const string& server,
Bertrand SIMONNET71a62ef2014-10-07 11:26:25 -0700228 const string& metrics_file,
229 const string& config_root) {
Darin Petkov65b01462010-04-14 13:32:20 -0700230 testing_ = testing;
Steve Funge86591e2014-12-01 13:38:21 -0800231 uploader_active_ = uploader_active;
Bertrand SIMONNET71a62ef2014-10-07 11:26:25 -0700232 config_root_ = config_root;
Alex Vakulenko14595032014-08-28 14:59:56 -0700233 DCHECK(metrics_lib != nullptr);
Darin Petkovfc91b422010-05-12 13:05:45 -0700234 metrics_lib_ = metrics_lib;
Darin Petkov38d5cb02010-06-24 12:10:26 -0700235
Bertrand SIMONNETcac74e12014-10-09 10:14:13 -0700236 upload_interval_ = upload_interval;
Steve Fung67906c62014-10-06 15:15:30 -0700237 server_ = server;
238 metrics_file_ = metrics_file;
239
Luigi Semenzatoba0c65d2014-03-17 12:28:38 -0700240 // Get ticks per second (HZ) on this system.
241 // Sysconf cannot fail, so no sanity checks are needed.
242 ticks_per_second_ = sysconf(_SC_CLK_TCK);
243
Luigi Semenzatoe5883fa2014-04-18 17:00:35 -0700244 daily_active_use_.reset(
Luigi Semenzatodc865892015-07-09 08:28:08 -0700245 new PersistentInteger("Platform.DailyUseTime"));
Luigi Semenzatoe5883fa2014-04-18 17:00:35 -0700246 version_cumulative_active_use_.reset(
Luigi Semenzatodc865892015-07-09 08:28:08 -0700247 new PersistentInteger("Platform.CumulativeDailyUseTime"));
Luigi Semenzatoba0c65d2014-03-17 12:28:38 -0700248 version_cumulative_cpu_use_.reset(
Luigi Semenzatodc865892015-07-09 08:28:08 -0700249 new PersistentInteger("Platform.CumulativeCpuTime"));
Darin Petkov38d5cb02010-06-24 12:10:26 -0700250
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800251 kernel_crash_interval_.reset(
Luigi Semenzatodc865892015-07-09 08:28:08 -0700252 new PersistentInteger("Platform.KernelCrashInterval"));
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800253 unclean_shutdown_interval_.reset(
Luigi Semenzatodc865892015-07-09 08:28:08 -0700254 new PersistentInteger("Platform.UncleanShutdownInterval"));
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800255 user_crash_interval_.reset(
Luigi Semenzatodc865892015-07-09 08:28:08 -0700256 new PersistentInteger("Platform.UserCrashInterval"));
Darin Petkov2ccef012010-05-05 16:06:37 -0700257
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800258 any_crashes_daily_count_.reset(
Luigi Semenzatodc865892015-07-09 08:28:08 -0700259 new PersistentInteger("Platform.AnyCrashesDaily"));
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800260 any_crashes_weekly_count_.reset(
Luigi Semenzatodc865892015-07-09 08:28:08 -0700261 new PersistentInteger("Platform.AnyCrashesWeekly"));
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800262 user_crashes_daily_count_.reset(
Luigi Semenzatodc865892015-07-09 08:28:08 -0700263 new PersistentInteger("Platform.UserCrashesDaily"));
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800264 user_crashes_weekly_count_.reset(
Luigi Semenzatodc865892015-07-09 08:28:08 -0700265 new PersistentInteger("Platform.UserCrashesWeekly"));
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800266 kernel_crashes_daily_count_.reset(
Luigi Semenzatodc865892015-07-09 08:28:08 -0700267 new PersistentInteger("Platform.KernelCrashesDaily"));
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800268 kernel_crashes_weekly_count_.reset(
Luigi Semenzatodc865892015-07-09 08:28:08 -0700269 new PersistentInteger("Platform.KernelCrashesWeekly"));
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800270 kernel_crashes_version_count_.reset(
Luigi Semenzatodc865892015-07-09 08:28:08 -0700271 new PersistentInteger("Platform.KernelCrashesSinceUpdate"));
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800272 unclean_shutdowns_daily_count_.reset(
Luigi Semenzatodc865892015-07-09 08:28:08 -0700273 new PersistentInteger("Platform.UncleanShutdownsDaily"));
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800274 unclean_shutdowns_weekly_count_.reset(
Luigi Semenzatodc865892015-07-09 08:28:08 -0700275 new PersistentInteger("Platform.UncleanShutdownsWeekly"));
Darin Petkov38d5cb02010-06-24 12:10:26 -0700276
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800277 daily_cycle_.reset(new PersistentInteger("daily.cycle"));
278 weekly_cycle_.reset(new PersistentInteger("weekly.cycle"));
279 version_cycle_.reset(new PersistentInteger("version.cycle"));
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800280
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700281 vmstats_path_ = vmstats_path;
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700282 scaling_max_freq_path_ = scaling_max_freq_path;
283 cpuinfo_max_freq_path_ = cpuinfo_max_freq_path;
Steve Funge86591e2014-12-01 13:38:21 -0800284}
285
286int MetricsDaemon::OnInit() {
287 int return_code = chromeos::DBusDaemon::OnInit();
288 if (return_code != EX_OK)
289 return return_code;
290
Steve Funge86591e2014-12-01 13:38:21 -0800291 if (testing_)
292 return EX_OK;
Darin Petkov65b01462010-04-14 13:32:20 -0700293
Steve Funge86591e2014-12-01 13:38:21 -0800294 bus_->AssertOnDBusThread();
295 CHECK(bus_->SetUpAsyncOperations());
Darin Petkov65b01462010-04-14 13:32:20 -0700296
Steve Funge86591e2014-12-01 13:38:21 -0800297 if (bus_->is_connected()) {
298 const std::string match_rule =
299 base::StringPrintf(kCrashReporterMatchRule,
300 kCrashReporterInterface,
301 kCrashReporterUserCrashSignal);
Darin Petkov65b01462010-04-14 13:32:20 -0700302
Steve Funge86591e2014-12-01 13:38:21 -0800303 bus_->AddFilterFunction(&MetricsDaemon::MessageFilter, this);
Darin Petkov65b01462010-04-14 13:32:20 -0700304
Steve Funge86591e2014-12-01 13:38:21 -0800305 DBusError error;
306 dbus_error_init(&error);
307 bus_->AddMatch(match_rule, &error);
Darin Petkov65b01462010-04-14 13:32:20 -0700308
Steve Funge86591e2014-12-01 13:38:21 -0800309 if (dbus_error_is_set(&error)) {
310 LOG(ERROR) << "Failed to add match rule \"" << match_rule << "\". Got "
311 << error.name << ": " << error.message;
312 return EX_SOFTWARE;
313 }
314 } else {
315 LOG(ERROR) << "DBus isn't connected.";
316 return EX_UNAVAILABLE;
Darin Petkov703ec972010-04-27 11:02:18 -0700317 }
318
Steve Funge86591e2014-12-01 13:38:21 -0800319 if (uploader_active_) {
Ben Chan067ec8b2015-02-17 13:54:04 -0800320 if (IsOnOfficialBuild()) {
321 LOG(INFO) << "uploader enabled";
322 upload_service_.reset(
Bertrand SIMONNETe4fa61e2015-02-18 09:38:55 -0800323 new UploadService(new SystemProfileCache(), metrics_lib_, server_));
Ben Chan067ec8b2015-02-17 13:54:04 -0800324 upload_service_->Init(upload_interval_, metrics_file_);
325 } else {
326 LOG(INFO) << "uploader disabled on non-official build";
327 }
Bertrand SIMONNET46b49da2014-06-25 14:38:07 -0700328 }
Steve Funge86591e2014-12-01 13:38:21 -0800329
330 return EX_OK;
Darin Petkov65b01462010-04-14 13:32:20 -0700331}
332
Steve Funge86591e2014-12-01 13:38:21 -0800333void MetricsDaemon::OnShutdown(int* return_code) {
334 if (!testing_ && bus_->is_connected()) {
335 const std::string match_rule =
336 base::StringPrintf(kCrashReporterMatchRule,
337 kCrashReporterInterface,
338 kCrashReporterUserCrashSignal);
339
340 bus_->RemoveFilterFunction(&MetricsDaemon::MessageFilter, this);
341
342 DBusError error;
343 dbus_error_init(&error);
344 bus_->RemoveMatch(match_rule, &error);
345
346 if (dbus_error_is_set(&error)) {
347 LOG(ERROR) << "Failed to remove match rule \"" << match_rule << "\". Got "
348 << error.name << ": " << error.message;
349 }
350 }
351 chromeos::DBusDaemon::OnShutdown(return_code);
Darin Petkov65b01462010-04-14 13:32:20 -0700352}
353
Darin Petkov703ec972010-04-27 11:02:18 -0700354// static
355DBusHandlerResult MetricsDaemon::MessageFilter(DBusConnection* connection,
356 DBusMessage* message,
357 void* user_data) {
Darin Petkov703ec972010-04-27 11:02:18 -0700358 int message_type = dbus_message_get_type(message);
359 if (message_type != DBUS_MESSAGE_TYPE_SIGNAL) {
Darin Petkov41e06232010-05-03 16:45:37 -0700360 DLOG(WARNING) << "unexpected message type " << message_type;
Darin Petkov703ec972010-04-27 11:02:18 -0700361 return DBUS_HANDLER_RESULT_NOT_YET_HANDLED;
362 }
363
364 // Signal messages always have interfaces.
Daniel Eratc83975a2014-04-04 08:53:44 -0700365 const std::string interface(dbus_message_get_interface(message));
366 const std::string member(dbus_message_get_member(message));
367 DLOG(INFO) << "Got " << interface << "." << member << " D-Bus signal";
Darin Petkov703ec972010-04-27 11:02:18 -0700368
369 MetricsDaemon* daemon = static_cast<MetricsDaemon*>(user_data);
370
371 DBusMessageIter iter;
372 dbus_message_iter_init(message, &iter);
Daniel Eratc83975a2014-04-04 08:53:44 -0700373 if (interface == kCrashReporterInterface) {
374 CHECK_EQ(member, kCrashReporterUserCrashSignal);
Darin Petkov1bb904e2010-06-16 15:58:06 -0700375 daemon->ProcessUserCrash();
Darin Petkov703ec972010-04-27 11:02:18 -0700376 } else {
Daniel Eratc83975a2014-04-04 08:53:44 -0700377 // Ignore messages from the bus itself.
Darin Petkov703ec972010-04-27 11:02:18 -0700378 return DBUS_HANDLER_RESULT_NOT_YET_HANDLED;
379 }
380
381 return DBUS_HANDLER_RESULT_HANDLED;
Darin Petkov65b01462010-04-14 13:32:20 -0700382}
383
Luigi Semenzatoba0c65d2014-03-17 12:28:38 -0700384// One might argue that parts of this should go into
385// chromium/src/base/sys_info_chromeos.c instead, but put it here for now.
386
387TimeDelta MetricsDaemon::GetIncrementalCpuUse() {
Luigi Semenzatoba0c65d2014-03-17 12:28:38 -0700388 FilePath proc_stat_path = FilePath(kMetricsProcStatFileName);
389 std::string proc_stat_string;
390 if (!base::ReadFileToString(proc_stat_path, &proc_stat_string)) {
391 LOG(WARNING) << "cannot open " << kMetricsProcStatFileName;
392 return TimeDelta();
393 }
394
395 std::vector<std::string> proc_stat_lines;
396 base::SplitString(proc_stat_string, '\n', &proc_stat_lines);
397 if (proc_stat_lines.empty()) {
398 LOG(WARNING) << "cannot parse " << kMetricsProcStatFileName
399 << ": " << proc_stat_string;
400 return TimeDelta();
401 }
402 std::vector<std::string> proc_stat_totals;
403 base::SplitStringAlongWhitespace(proc_stat_lines[0], &proc_stat_totals);
404
Ben Chanf05ab402014-08-07 00:54:59 -0700405 uint64_t user_ticks, user_nice_ticks, system_ticks;
Luigi Semenzatoba0c65d2014-03-17 12:28:38 -0700406 if (proc_stat_totals.size() != kMetricsProcStatFirstLineItemsCount ||
407 proc_stat_totals[0] != "cpu" ||
408 !base::StringToUint64(proc_stat_totals[1], &user_ticks) ||
409 !base::StringToUint64(proc_stat_totals[2], &user_nice_ticks) ||
410 !base::StringToUint64(proc_stat_totals[3], &system_ticks)) {
411 LOG(WARNING) << "cannot parse first line: " << proc_stat_lines[0];
412 return TimeDelta(base::TimeDelta::FromSeconds(0));
413 }
414
Ben Chanf05ab402014-08-07 00:54:59 -0700415 uint64_t total_cpu_use_ticks = user_ticks + user_nice_ticks + system_ticks;
Luigi Semenzatoba0c65d2014-03-17 12:28:38 -0700416
417 // Sanity check.
418 if (total_cpu_use_ticks < latest_cpu_use_ticks_) {
419 LOG(WARNING) << "CPU time decreasing from " << latest_cpu_use_ticks_
420 << " to " << total_cpu_use_ticks;
421 return TimeDelta();
422 }
423
Ben Chanf05ab402014-08-07 00:54:59 -0700424 uint64_t diff = total_cpu_use_ticks - latest_cpu_use_ticks_;
Luigi Semenzatoba0c65d2014-03-17 12:28:38 -0700425 latest_cpu_use_ticks_ = total_cpu_use_ticks;
426 // Use microseconds to avoid significant truncations.
427 return base::TimeDelta::FromMicroseconds(
428 diff * 1000 * 1000 / ticks_per_second_);
429}
430
Darin Petkov1bb904e2010-06-16 15:58:06 -0700431void MetricsDaemon::ProcessUserCrash() {
Daniel Eratc83975a2014-04-04 08:53:44 -0700432 // Counts the active time up to now.
433 UpdateStats(TimeTicks::Now(), Time::Now());
Darin Petkov1bb904e2010-06-16 15:58:06 -0700434
435 // Reports the active use time since the last crash and resets it.
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800436 SendCrashIntervalSample(user_crash_interval_);
Ken Mixterccd84c02010-08-16 19:57:13 -0700437
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800438 any_crashes_daily_count_->Add(1);
439 any_crashes_weekly_count_->Add(1);
440 user_crashes_daily_count_->Add(1);
441 user_crashes_weekly_count_->Add(1);
Darin Petkov1bb904e2010-06-16 15:58:06 -0700442}
443
Darin Petkov38d5cb02010-06-24 12:10:26 -0700444void MetricsDaemon::ProcessKernelCrash() {
Daniel Eratc83975a2014-04-04 08:53:44 -0700445 // Counts the active time up to now.
446 UpdateStats(TimeTicks::Now(), Time::Now());
Darin Petkov38d5cb02010-06-24 12:10:26 -0700447
448 // Reports the active use time since the last crash and resets it.
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800449 SendCrashIntervalSample(kernel_crash_interval_);
Ken Mixterccd84c02010-08-16 19:57:13 -0700450
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800451 any_crashes_daily_count_->Add(1);
452 any_crashes_weekly_count_->Add(1);
453 kernel_crashes_daily_count_->Add(1);
454 kernel_crashes_weekly_count_->Add(1);
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800455
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800456 kernel_crashes_version_count_->Add(1);
Darin Petkov38d5cb02010-06-24 12:10:26 -0700457}
458
Ken Mixterccd84c02010-08-16 19:57:13 -0700459void MetricsDaemon::ProcessUncleanShutdown() {
Daniel Eratc83975a2014-04-04 08:53:44 -0700460 // Counts the active time up to now.
461 UpdateStats(TimeTicks::Now(), Time::Now());
Ken Mixterccd84c02010-08-16 19:57:13 -0700462
463 // Reports the active use time since the last crash and resets it.
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800464 SendCrashIntervalSample(unclean_shutdown_interval_);
Ken Mixterccd84c02010-08-16 19:57:13 -0700465
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800466 unclean_shutdowns_daily_count_->Add(1);
467 unclean_shutdowns_weekly_count_->Add(1);
468 any_crashes_daily_count_->Add(1);
469 any_crashes_weekly_count_->Add(1);
Ken Mixterccd84c02010-08-16 19:57:13 -0700470}
471
Luigi Semenzato8accd332011-05-17 16:37:18 -0700472bool MetricsDaemon::CheckSystemCrash(const string& crash_file) {
Darin Petkov38d5cb02010-06-24 12:10:26 -0700473 FilePath crash_detected(crash_file);
Ben Chan2e6543d2014-02-05 23:26:25 -0800474 if (!base::PathExists(crash_detected))
Ken Mixterccd84c02010-08-16 19:57:13 -0700475 return false;
Darin Petkov38d5cb02010-06-24 12:10:26 -0700476
477 // Deletes the crash-detected file so that the daemon doesn't report
478 // another kernel crash in case it's restarted.
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800479 base::DeleteFile(crash_detected, false); // not recursive
Ken Mixterccd84c02010-08-16 19:57:13 -0700480 return true;
Darin Petkov38d5cb02010-06-24 12:10:26 -0700481}
482
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700483void MetricsDaemon::StatsReporterInit() {
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800484 DiskStatsReadStats(&read_sectors_, &write_sectors_);
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700485 VmStatsReadStats(&vmstats_);
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800486 // The first time around just run the long stat, so we don't delay boot.
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700487 stats_state_ = kStatsLong;
488 stats_initial_time_ = GetActiveTime();
489 if (stats_initial_time_ < 0) {
Luigi Semenzato8accd332011-05-17 16:37:18 -0700490 LOG(WARNING) << "not collecting disk stats";
491 } else {
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700492 ScheduleStatsCallback(kMetricStatsLongInterval);
Luigi Semenzato8accd332011-05-17 16:37:18 -0700493 }
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800494}
495
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700496void MetricsDaemon::ScheduleStatsCallback(int wait) {
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800497 if (testing_) {
498 return;
499 }
Steve Funge86591e2014-12-01 13:38:21 -0800500 base::MessageLoop::current()->PostDelayedTask(FROM_HERE,
501 base::Bind(&MetricsDaemon::StatsCallback, base::Unretained(this)),
502 base::TimeDelta::FromSeconds(wait));
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800503}
504
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700505bool MetricsDaemon::VmStatsParseStats(const char* stats,
506 struct VmstatRecord* record) {
507 // a mapping of string name to field in VmstatRecord and whether we found it
508 struct mapping {
509 const string name;
510 uint64_t* value_p;
511 bool found;
512 } map[] =
513 { { .name = "pgmajfault",
514 .value_p = &record->page_faults_,
515 .found = false },
516 { .name = "pswpin",
517 .value_p = &record->swap_in_,
518 .found = false },
519 { .name = "pswpout",
520 .value_p = &record->swap_out_,
521 .found = false }, };
522
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700523 // Each line in the file has the form
524 // <ID> <VALUE>
525 // for instance:
526 // nr_free_pages 213427
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700527 vector<string> lines;
528 Tokenize(stats, "\n", &lines);
529 for (vector<string>::iterator it = lines.begin();
530 it != lines.end(); ++it) {
531 vector<string> tokens;
532 base::SplitString(*it, ' ', &tokens);
533 if (tokens.size() == 2) {
534 for (unsigned int i = 0; i < sizeof(map)/sizeof(struct mapping); i++) {
535 if (!tokens[0].compare(map[i].name)) {
536 if (!base::StringToUint64(tokens[1], map[i].value_p))
537 return false;
538 map[i].found = true;
539 }
540 }
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700541 } else {
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700542 LOG(WARNING) << "unexpected vmstat format";
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700543 }
544 }
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700545 // make sure we got all the stats
546 for (unsigned i = 0; i < sizeof(map)/sizeof(struct mapping); i++) {
547 if (map[i].found == false) {
548 LOG(WARNING) << "vmstat missing " << map[i].name;
549 return false;
550 }
551 }
552 return true;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700553}
554
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700555bool MetricsDaemon::VmStatsReadStats(struct VmstatRecord* stats) {
556 string value_string;
557 FilePath* path = new FilePath(vmstats_path_);
Ben Chan2e6543d2014-02-05 23:26:25 -0800558 if (!base::ReadFileToString(*path, &value_string)) {
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700559 delete path;
560 LOG(WARNING) << "cannot read " << vmstats_path_;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700561 return false;
562 }
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700563 delete path;
564 return VmStatsParseStats(value_string.c_str(), stats);
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800565}
566
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700567bool MetricsDaemon::ReadFreqToInt(const string& sysfs_file_name, int* value) {
Luigi Semenzatod92d18c2013-06-04 13:24:21 -0700568 const FilePath sysfs_path(sysfs_file_name);
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700569 string value_string;
Ben Chan2e6543d2014-02-05 23:26:25 -0800570 if (!base::ReadFileToString(sysfs_path, &value_string)) {
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700571 LOG(WARNING) << "cannot read " << sysfs_path.value().c_str();
572 return false;
573 }
Ben Chan2e6543d2014-02-05 23:26:25 -0800574 if (!base::RemoveChars(value_string, "\n", &value_string)) {
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700575 LOG(WARNING) << "no newline in " << value_string;
576 // Continue even though the lack of newline is suspicious.
577 }
578 if (!base::StringToInt(value_string, value)) {
579 LOG(WARNING) << "cannot convert " << value_string << " to int";
580 return false;
581 }
582 return true;
583}
584
585void MetricsDaemon::SendCpuThrottleMetrics() {
586 // |max_freq| is 0 only the first time through.
587 static int max_freq = 0;
588 if (max_freq == -1)
589 // Give up, as sysfs did not report max_freq correctly.
590 return;
591 if (max_freq == 0 || testing_) {
592 // One-time initialization of max_freq. (Every time when testing.)
593 if (!ReadFreqToInt(cpuinfo_max_freq_path_, &max_freq)) {
594 max_freq = -1;
595 return;
596 }
597 if (max_freq == 0) {
598 LOG(WARNING) << "sysfs reports 0 max CPU frequency\n";
599 max_freq = -1;
600 return;
601 }
602 if (max_freq % 10000 == 1000) {
603 // Special case: system has turbo mode, and max non-turbo frequency is
604 // max_freq - 1000. This relies on "normal" (non-turbo) frequencies
605 // being multiples of (at least) 10 MHz. Although there is no guarantee
606 // of this, it seems a fairly reasonable assumption. Otherwise we should
607 // read scaling_available_frequencies, sort the frequencies, compare the
608 // two highest ones, and check if they differ by 1000 (kHz) (and that's a
609 // hack too, no telling when it will change).
610 max_freq -= 1000;
611 }
612 }
613 int scaled_freq = 0;
614 if (!ReadFreqToInt(scaling_max_freq_path_, &scaled_freq))
615 return;
616 // Frequencies are in kHz. If scaled_freq > max_freq, turbo is on, but
617 // scaled_freq is not the actual turbo frequency. We indicate this situation
618 // with a 101% value.
619 int percent = scaled_freq > max_freq ? 101 : scaled_freq / (max_freq / 100);
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800620 SendLinearSample(kMetricScaledCpuFrequencyName, percent, 101, 102);
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700621}
622
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700623// Collects disk and vm stats alternating over a short and a long interval.
Luigi Semenzato8accd332011-05-17 16:37:18 -0700624
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700625void MetricsDaemon::StatsCallback() {
Ben Chanf05ab402014-08-07 00:54:59 -0700626 uint64_t read_sectors_now, write_sectors_now;
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700627 struct VmstatRecord vmstats_now;
Luigi Semenzato8accd332011-05-17 16:37:18 -0700628 double time_now = GetActiveTime();
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700629 double delta_time = time_now - stats_initial_time_;
Luigi Semenzato8accd332011-05-17 16:37:18 -0700630 if (testing_) {
631 // Fake the time when testing.
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700632 delta_time = stats_state_ == kStatsShort ?
633 kMetricStatsShortInterval : kMetricStatsLongInterval;
Luigi Semenzato8accd332011-05-17 16:37:18 -0700634 }
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700635 bool diskstats_success = DiskStatsReadStats(&read_sectors_now,
636 &write_sectors_now);
Luigi Semenzato8accd332011-05-17 16:37:18 -0700637 int delta_read = read_sectors_now - read_sectors_;
638 int delta_write = write_sectors_now - write_sectors_;
639 int read_sectors_per_second = delta_read / delta_time;
640 int write_sectors_per_second = delta_write / delta_time;
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700641 bool vmstats_success = VmStatsReadStats(&vmstats_now);
642 uint64_t delta_faults = vmstats_now.page_faults_ - vmstats_.page_faults_;
643 uint64_t delta_swap_in = vmstats_now.swap_in_ - vmstats_.swap_in_;
644 uint64_t delta_swap_out = vmstats_now.swap_out_ - vmstats_.swap_out_;
645 uint64_t page_faults_per_second = delta_faults / delta_time;
646 uint64_t swap_in_per_second = delta_swap_in / delta_time;
647 uint64_t swap_out_per_second = delta_swap_out / delta_time;
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800648
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700649 switch (stats_state_) {
650 case kStatsShort:
651 if (diskstats_success) {
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800652 SendSample(kMetricReadSectorsShortName,
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700653 read_sectors_per_second,
654 1,
655 kMetricSectorsIOMax,
656 kMetricSectorsBuckets);
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800657 SendSample(kMetricWriteSectorsShortName,
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700658 write_sectors_per_second,
659 1,
660 kMetricSectorsIOMax,
661 kMetricSectorsBuckets);
662 }
663 if (vmstats_success) {
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800664 SendSample(kMetricPageFaultsShortName,
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700665 page_faults_per_second,
666 1,
667 kMetricPageFaultsMax,
668 kMetricPageFaultsBuckets);
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800669 SendSample(kMetricSwapInShortName,
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700670 swap_in_per_second,
671 1,
672 kMetricPageFaultsMax,
673 kMetricPageFaultsBuckets);
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800674 SendSample(kMetricSwapOutShortName,
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700675 swap_out_per_second,
676 1,
677 kMetricPageFaultsMax,
678 kMetricPageFaultsBuckets);
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700679 }
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800680 // Schedule long callback.
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700681 stats_state_ = kStatsLong;
682 ScheduleStatsCallback(kMetricStatsLongInterval -
683 kMetricStatsShortInterval);
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800684 break;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700685 case kStatsLong:
686 if (diskstats_success) {
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800687 SendSample(kMetricReadSectorsLongName,
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700688 read_sectors_per_second,
689 1,
690 kMetricSectorsIOMax,
691 kMetricSectorsBuckets);
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800692 SendSample(kMetricWriteSectorsLongName,
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700693 write_sectors_per_second,
694 1,
695 kMetricSectorsIOMax,
696 kMetricSectorsBuckets);
697 // Reset sector counters.
698 read_sectors_ = read_sectors_now;
699 write_sectors_ = write_sectors_now;
700 }
701 if (vmstats_success) {
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800702 SendSample(kMetricPageFaultsLongName,
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700703 page_faults_per_second,
704 1,
705 kMetricPageFaultsMax,
706 kMetricPageFaultsBuckets);
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800707 SendSample(kMetricSwapInLongName,
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700708 swap_in_per_second,
709 1,
710 kMetricPageFaultsMax,
711 kMetricPageFaultsBuckets);
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800712 SendSample(kMetricSwapOutLongName,
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700713 swap_out_per_second,
714 1,
715 kMetricPageFaultsMax,
716 kMetricPageFaultsBuckets);
717
718 vmstats_ = vmstats_now;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700719 }
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700720 SendCpuThrottleMetrics();
Luigi Semenzato8accd332011-05-17 16:37:18 -0700721 // Set start time for new cycle.
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700722 stats_initial_time_ = time_now;
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800723 // Schedule short callback.
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700724 stats_state_ = kStatsShort;
725 ScheduleStatsCallback(kMetricStatsShortInterval);
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800726 break;
727 default:
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700728 LOG(FATAL) << "Invalid stats state";
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800729 }
730}
731
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700732void MetricsDaemon::ScheduleMeminfoCallback(int wait) {
733 if (testing_) {
734 return;
735 }
Steve Funge86591e2014-12-01 13:38:21 -0800736 base::TimeDelta waitDelta = base::TimeDelta::FromSeconds(wait);
737 base::MessageLoop::current()->PostDelayedTask(FROM_HERE,
738 base::Bind(&MetricsDaemon::MeminfoCallback, base::Unretained(this),
Steve Fung8ab89c52015-01-05 13:48:30 -0800739 waitDelta),
Steve Funge86591e2014-12-01 13:38:21 -0800740 waitDelta);
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700741}
742
Steve Funge86591e2014-12-01 13:38:21 -0800743void MetricsDaemon::MeminfoCallback(base::TimeDelta wait) {
Luigi Semenzato8accd332011-05-17 16:37:18 -0700744 string meminfo_raw;
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700745 const FilePath meminfo_path("/proc/meminfo");
Ben Chan2e6543d2014-02-05 23:26:25 -0800746 if (!base::ReadFileToString(meminfo_path, &meminfo_raw)) {
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700747 LOG(WARNING) << "cannot read " << meminfo_path.value().c_str();
Steve Funge86591e2014-12-01 13:38:21 -0800748 return;
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700749 }
Luigi Semenzato96360192014-06-04 10:53:35 -0700750 // Make both calls even if the first one fails.
751 bool success = ProcessMeminfo(meminfo_raw);
Steve Funge86591e2014-12-01 13:38:21 -0800752 bool reschedule =
753 ReportZram(base::FilePath(FILE_PATH_LITERAL("/sys/block/zram0"))) &&
Luigi Semenzato96360192014-06-04 10:53:35 -0700754 success;
Steve Funge86591e2014-12-01 13:38:21 -0800755 if (reschedule) {
756 base::MessageLoop::current()->PostDelayedTask(FROM_HERE,
757 base::Bind(&MetricsDaemon::MeminfoCallback, base::Unretained(this),
Steve Fung8ab89c52015-01-05 13:48:30 -0800758 wait),
Steve Funge86591e2014-12-01 13:38:21 -0800759 wait);
760 }
Luigi Semenzato96360192014-06-04 10:53:35 -0700761}
762
763// static
764bool MetricsDaemon::ReadFileToUint64(const base::FilePath& path,
Ben Chanf05ab402014-08-07 00:54:59 -0700765 uint64_t* value) {
Luigi Semenzato96360192014-06-04 10:53:35 -0700766 std::string content;
767 if (!base::ReadFileToString(path, &content)) {
768 PLOG(WARNING) << "cannot read " << path.MaybeAsASCII();
769 return false;
770 }
Luigi Semenzato4a6c9422014-06-30 18:12:28 -0700771 // Remove final newline.
772 base::TrimWhitespaceASCII(content, base::TRIM_TRAILING, &content);
Luigi Semenzato96360192014-06-04 10:53:35 -0700773 if (!base::StringToUint64(content, value)) {
774 LOG(WARNING) << "invalid integer: " << content;
775 return false;
776 }
777 return true;
778}
779
780bool MetricsDaemon::ReportZram(const base::FilePath& zram_dir) {
781 // Data sizes are in bytes. |zero_pages| is in number of pages.
Ben Chanf05ab402014-08-07 00:54:59 -0700782 uint64_t compr_data_size, orig_data_size, zero_pages;
Luigi Semenzato96360192014-06-04 10:53:35 -0700783 const size_t page_size = 4096;
784
785 if (!ReadFileToUint64(zram_dir.Append(kComprDataSizeName),
786 &compr_data_size) ||
787 !ReadFileToUint64(zram_dir.Append(kOrigDataSizeName), &orig_data_size) ||
788 !ReadFileToUint64(zram_dir.Append(kZeroPagesName), &zero_pages)) {
789 return false;
790 }
791
792 // |orig_data_size| does not include zero-filled pages.
793 orig_data_size += zero_pages * page_size;
794
795 const int compr_data_size_mb = compr_data_size >> 20;
796 const int savings_mb = (orig_data_size - compr_data_size) >> 20;
797 const int zero_ratio_percent = zero_pages * page_size * 100 / orig_data_size;
798
799 // Report compressed size in megabytes. 100 MB or less has little impact.
800 SendSample("Platform.ZramCompressedSize", compr_data_size_mb, 100, 4000, 50);
801 SendSample("Platform.ZramSavings", savings_mb, 100, 4000, 50);
802 // The compression ratio is multiplied by 100 for better resolution. The
803 // ratios of interest are between 1 and 6 (100% and 600% as reported). We
804 // don't want samples when very little memory is being compressed.
805 if (compr_data_size_mb >= 1) {
806 SendSample("Platform.ZramCompressionRatioPercent",
807 orig_data_size * 100 / compr_data_size, 100, 600, 50);
808 }
809 // The values of interest for zero_pages are between 1MB and 1GB. The units
810 // are number of pages.
811 SendSample("Platform.ZramZeroPages", zero_pages, 256, 256 * 1024, 50);
812 SendSample("Platform.ZramZeroRatioPercent", zero_ratio_percent, 1, 50, 50);
813
814 return true;
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700815}
816
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700817bool MetricsDaemon::ProcessMeminfo(const string& meminfo_raw) {
Luigi Semenzato8accd332011-05-17 16:37:18 -0700818 static const MeminfoRecord fields_array[] = {
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700819 { "MemTotal", "MemTotal" }, // SPECIAL CASE: total system memory
820 { "MemFree", "MemFree" },
821 { "Buffers", "Buffers" },
822 { "Cached", "Cached" },
823 // { "SwapCached", "SwapCached" },
824 { "Active", "Active" },
825 { "Inactive", "Inactive" },
826 { "ActiveAnon", "Active(anon)" },
827 { "InactiveAnon", "Inactive(anon)" },
828 { "ActiveFile" , "Active(file)" },
829 { "InactiveFile", "Inactive(file)" },
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800830 { "Unevictable", "Unevictable", kMeminfoOp_HistLog },
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700831 // { "Mlocked", "Mlocked" },
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800832 { "SwapTotal", "SwapTotal", kMeminfoOp_SwapTotal },
833 { "SwapFree", "SwapFree", kMeminfoOp_SwapFree },
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700834 // { "Dirty", "Dirty" },
835 // { "Writeback", "Writeback" },
836 { "AnonPages", "AnonPages" },
837 { "Mapped", "Mapped" },
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800838 { "Shmem", "Shmem", kMeminfoOp_HistLog },
839 { "Slab", "Slab", kMeminfoOp_HistLog },
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700840 // { "SReclaimable", "SReclaimable" },
841 // { "SUnreclaim", "SUnreclaim" },
842 };
Luigi Semenzato8accd332011-05-17 16:37:18 -0700843 vector<MeminfoRecord> fields(fields_array,
844 fields_array + arraysize(fields_array));
845 if (!FillMeminfo(meminfo_raw, &fields)) {
846 return false;
847 }
848 int total_memory = fields[0].value;
849 if (total_memory == 0) {
850 // this "cannot happen"
851 LOG(WARNING) << "borked meminfo parser";
852 return false;
853 }
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800854 int swap_total = 0;
855 int swap_free = 0;
Luigi Semenzato8accd332011-05-17 16:37:18 -0700856 // Send all fields retrieved, except total memory.
857 for (unsigned int i = 1; i < fields.size(); i++) {
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800858 string metrics_name = base::StringPrintf("Platform.Meminfo%s",
859 fields[i].name);
Luigi Semenzato3ccca062013-02-04 19:50:45 -0800860 int percent;
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800861 switch (fields[i].op) {
862 case kMeminfoOp_HistPercent:
Luigi Semenzato3ccca062013-02-04 19:50:45 -0800863 // report value as percent of total memory
864 percent = fields[i].value * 100 / total_memory;
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800865 SendLinearSample(metrics_name, percent, 100, 101);
Luigi Semenzato3ccca062013-02-04 19:50:45 -0800866 break;
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800867 case kMeminfoOp_HistLog:
Luigi Semenzato3ccca062013-02-04 19:50:45 -0800868 // report value in kbytes, log scale, 4Gb max
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800869 SendSample(metrics_name, fields[i].value, 1, 4 * 1000 * 1000, 100);
Luigi Semenzato3ccca062013-02-04 19:50:45 -0800870 break;
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800871 case kMeminfoOp_SwapTotal:
872 swap_total = fields[i].value;
873 case kMeminfoOp_SwapFree:
874 swap_free = fields[i].value;
Luigi Semenzato3ccca062013-02-04 19:50:45 -0800875 break;
Luigi Semenzato8accd332011-05-17 16:37:18 -0700876 }
877 }
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800878 if (swap_total > 0) {
879 int swap_used = swap_total - swap_free;
880 int swap_used_percent = swap_used * 100 / swap_total;
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800881 SendSample("Platform.MeminfoSwapUsed", swap_used, 1, 8 * 1000 * 1000, 100);
882 SendLinearSample("Platform.MeminfoSwapUsedPercent", swap_used_percent,
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800883 100, 101);
884 }
Luigi Semenzato8accd332011-05-17 16:37:18 -0700885 return true;
886}
887
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700888bool MetricsDaemon::FillMeminfo(const string& meminfo_raw,
889 vector<MeminfoRecord>* fields) {
Luigi Semenzato8accd332011-05-17 16:37:18 -0700890 vector<string> lines;
891 unsigned int nlines = Tokenize(meminfo_raw, "\n", &lines);
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700892
893 // Scan meminfo output and collect field values. Each field name has to
894 // match a meminfo entry (case insensitive) after removing non-alpha
895 // characters from the entry.
Luigi Semenzato8accd332011-05-17 16:37:18 -0700896 unsigned int ifield = 0;
897 for (unsigned int iline = 0;
898 iline < nlines && ifield < fields->size();
899 iline++) {
900 vector<string> tokens;
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700901 Tokenize(lines[iline], ": ", &tokens);
Luigi Semenzato8accd332011-05-17 16:37:18 -0700902 if (strcmp((*fields)[ifield].match, tokens[0].c_str()) == 0) {
903 // Name matches. Parse value and save.
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700904 char* rest;
Luigi Semenzato8accd332011-05-17 16:37:18 -0700905 (*fields)[ifield].value =
906 static_cast<int>(strtol(tokens[1].c_str(), &rest, 10));
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700907 if (*rest != '\0') {
908 LOG(WARNING) << "missing meminfo value";
909 return false;
910 }
Luigi Semenzato8accd332011-05-17 16:37:18 -0700911 ifield++;
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700912 }
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700913 }
Luigi Semenzato8accd332011-05-17 16:37:18 -0700914 if (ifield < fields->size()) {
915 // End of input reached while scanning.
916 LOG(WARNING) << "cannot find field " << (*fields)[ifield].match
917 << " and following";
918 return false;
919 }
920 return true;
921}
922
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -0800923void MetricsDaemon::ScheduleMemuseCallback(double interval) {
Luigi Semenzato8accd332011-05-17 16:37:18 -0700924 if (testing_) {
925 return;
926 }
Steve Funge86591e2014-12-01 13:38:21 -0800927 base::MessageLoop::current()->PostDelayedTask(FROM_HERE,
928 base::Bind(&MetricsDaemon::MemuseCallback, base::Unretained(this)),
929 base::TimeDelta::FromSeconds(interval));
Luigi Semenzato8accd332011-05-17 16:37:18 -0700930}
931
932void MetricsDaemon::MemuseCallback() {
933 // Since we only care about active time (i.e. uptime minus sleep time) but
934 // the callbacks are driven by real time (uptime), we check if we should
935 // reschedule this callback due to intervening sleep periods.
936 double now = GetActiveTime();
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -0800937 // Avoid intervals of less than one second.
938 double remaining_time = ceil(memuse_final_time_ - now);
939 if (remaining_time > 0) {
940 ScheduleMemuseCallback(remaining_time);
Luigi Semenzato8accd332011-05-17 16:37:18 -0700941 } else {
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -0800942 // Report stats and advance the measurement interval unless there are
943 // errors or we've completed the last interval.
Luigi Semenzato8accd332011-05-17 16:37:18 -0700944 if (MemuseCallbackWork() &&
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -0800945 memuse_interval_index_ < arraysize(kMemuseIntervals)) {
946 double interval = kMemuseIntervals[memuse_interval_index_++];
947 memuse_final_time_ = now + interval;
948 ScheduleMemuseCallback(interval);
Luigi Semenzato8accd332011-05-17 16:37:18 -0700949 }
950 }
951}
952
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700953bool MetricsDaemon::MemuseCallbackWork() {
Luigi Semenzato8accd332011-05-17 16:37:18 -0700954 string meminfo_raw;
955 const FilePath meminfo_path("/proc/meminfo");
Ben Chan2e6543d2014-02-05 23:26:25 -0800956 if (!base::ReadFileToString(meminfo_path, &meminfo_raw)) {
Luigi Semenzato8accd332011-05-17 16:37:18 -0700957 LOG(WARNING) << "cannot read " << meminfo_path.value().c_str();
958 return false;
959 }
960 return ProcessMemuse(meminfo_raw);
961}
962
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700963bool MetricsDaemon::ProcessMemuse(const string& meminfo_raw) {
Luigi Semenzato8accd332011-05-17 16:37:18 -0700964 static const MeminfoRecord fields_array[] = {
965 { "MemTotal", "MemTotal" }, // SPECIAL CASE: total system memory
966 { "ActiveAnon", "Active(anon)" },
967 { "InactiveAnon", "Inactive(anon)" },
968 };
969 vector<MeminfoRecord> fields(fields_array,
970 fields_array + arraysize(fields_array));
971 if (!FillMeminfo(meminfo_raw, &fields)) {
972 return false;
973 }
974 int total = fields[0].value;
975 int active_anon = fields[1].value;
976 int inactive_anon = fields[2].value;
977 if (total == 0) {
978 // this "cannot happen"
979 LOG(WARNING) << "borked meminfo parser";
980 return false;
981 }
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800982 string metrics_name = base::StringPrintf("Platform.MemuseAnon%d",
983 memuse_interval_index_);
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800984 SendLinearSample(metrics_name, (active_anon + inactive_anon) * 100 / total,
Luigi Semenzato8accd332011-05-17 16:37:18 -0700985 100, 101);
986 return true;
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700987}
988
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800989void MetricsDaemon::SendSample(const string& name, int sample,
Darin Petkov11b8eb32010-05-18 11:00:59 -0700990 int min, int max, int nbuckets) {
Darin Petkovfc91b422010-05-12 13:05:45 -0700991 metrics_lib_->SendToUMA(name, sample, min, max, nbuckets);
Darin Petkov65b01462010-04-14 13:32:20 -0700992}
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700993
Luigi Semenzatoe5883fa2014-04-18 17:00:35 -0700994void MetricsDaemon::SendKernelCrashesCumulativeCountStats() {
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800995 // Report the number of crashes for this OS version, but don't clear the
996 // counter. It is cleared elsewhere on version change.
Ben Chanf05ab402014-08-07 00:54:59 -0700997 int64_t crashes_count = kernel_crashes_version_count_->Get();
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800998 SendSample(kernel_crashes_version_count_->Name(),
Luigi Semenzatoba0c65d2014-03-17 12:28:38 -0700999 crashes_count,
1000 1, // value of first bucket
1001 500, // value of last bucket
1002 100); // number of buckets
1003
1004
Ben Chanf05ab402014-08-07 00:54:59 -07001005 int64_t cpu_use_ms = version_cumulative_cpu_use_->Get();
Luigi Semenzatoba0c65d2014-03-17 12:28:38 -07001006 SendSample(version_cumulative_cpu_use_->Name(),
1007 cpu_use_ms / 1000, // stat is in seconds
1008 1, // device may be used very little...
1009 8 * 1000 * 1000, // ... or a lot (a little over 90 days)
1010 100);
1011
1012 // On the first run after an autoupdate, cpu_use_ms and active_use_seconds
1013 // can be zero. Avoid division by zero.
1014 if (cpu_use_ms > 0) {
1015 // Send the crash frequency since update in number of crashes per CPU year.
1016 SendSample("Logging.KernelCrashesPerCpuYear",
1017 crashes_count * kSecondsPerDay * 365 * 1000 / cpu_use_ms,
1018 1,
1019 1000 * 1000, // about one crash every 30s of CPU time
1020 100);
1021 }
1022
Ben Chanf05ab402014-08-07 00:54:59 -07001023 int64_t active_use_seconds = version_cumulative_active_use_->Get();
Luigi Semenzatoba0c65d2014-03-17 12:28:38 -07001024 if (active_use_seconds > 0) {
Luigi Semenzatoe5883fa2014-04-18 17:00:35 -07001025 SendSample(version_cumulative_active_use_->Name(),
1026 active_use_seconds / 1000, // stat is in seconds
1027 1, // device may be used very little...
1028 8 * 1000 * 1000, // ... or a lot (about 90 days)
1029 100);
Luigi Semenzatoba0c65d2014-03-17 12:28:38 -07001030 // Same as above, but per year of active time.
1031 SendSample("Logging.KernelCrashesPerActiveYear",
1032 crashes_count * kSecondsPerDay * 365 / active_use_seconds,
1033 1,
1034 1000 * 1000, // about one crash every 30s of active time
1035 100);
1036 }
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -08001037}
1038
Luigi Semenzatoe5883fa2014-04-18 17:00:35 -07001039void MetricsDaemon::SendDailyUseSample(
1040 const scoped_ptr<PersistentInteger>& use) {
1041 SendSample(use->Name(),
1042 use->GetAndClear(),
1043 1, // value of first bucket
1044 kSecondsPerDay, // value of last bucket
1045 50); // number of buckets
1046}
1047
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -08001048void MetricsDaemon::SendCrashIntervalSample(
1049 const scoped_ptr<PersistentInteger>& interval) {
1050 SendSample(interval->Name(),
1051 interval->GetAndClear(),
1052 1, // value of first bucket
1053 4 * kSecondsPerWeek, // value of last bucket
1054 50); // number of buckets
1055}
1056
1057void MetricsDaemon::SendCrashFrequencySample(
1058 const scoped_ptr<PersistentInteger>& frequency) {
1059 SendSample(frequency->Name(),
1060 frequency->GetAndClear(),
1061 1, // value of first bucket
1062 100, // value of last bucket
1063 50); // number of buckets
1064}
1065
1066void MetricsDaemon::SendLinearSample(const string& name, int sample,
Luigi Semenzato29c7ef92011-04-12 14:12:35 -07001067 int max, int nbuckets) {
Luigi Semenzato29c7ef92011-04-12 14:12:35 -07001068 // TODO(semenzato): add a proper linear histogram to the Chrome external
1069 // metrics API.
1070 LOG_IF(FATAL, nbuckets != max + 1) << "unsupported histogram scale";
1071 metrics_lib_->SendEnumToUMA(name, sample, max);
1072}
Daniel Eratc83975a2014-04-04 08:53:44 -07001073
1074void MetricsDaemon::UpdateStats(TimeTicks now_ticks,
1075 Time now_wall_time) {
1076 const int elapsed_seconds = (now_ticks - last_update_stats_time_).InSeconds();
Luigi Semenzatoe5883fa2014-04-18 17:00:35 -07001077 daily_active_use_->Add(elapsed_seconds);
1078 version_cumulative_active_use_->Add(elapsed_seconds);
Daniel Eratc83975a2014-04-04 08:53:44 -07001079 user_crash_interval_->Add(elapsed_seconds);
1080 kernel_crash_interval_->Add(elapsed_seconds);
1081 version_cumulative_cpu_use_->Add(GetIncrementalCpuUse().InMilliseconds());
1082 last_update_stats_time_ = now_ticks;
1083
1084 const TimeDelta since_epoch = now_wall_time - Time::UnixEpoch();
1085 const int day = since_epoch.InDays();
1086 const int week = day / 7;
1087
1088 if (daily_cycle_->Get() != day) {
1089 daily_cycle_->Set(day);
Luigi Semenzatoe5883fa2014-04-18 17:00:35 -07001090 SendDailyUseSample(daily_active_use_);
1091 SendDailyUseSample(version_cumulative_active_use_);
Daniel Eratc83975a2014-04-04 08:53:44 -07001092 SendCrashFrequencySample(any_crashes_daily_count_);
1093 SendCrashFrequencySample(user_crashes_daily_count_);
1094 SendCrashFrequencySample(kernel_crashes_daily_count_);
1095 SendCrashFrequencySample(unclean_shutdowns_daily_count_);
Luigi Semenzatoe5883fa2014-04-18 17:00:35 -07001096 SendKernelCrashesCumulativeCountStats();
Daniel Eratc83975a2014-04-04 08:53:44 -07001097 }
1098
1099 if (weekly_cycle_->Get() != week) {
1100 weekly_cycle_->Set(week);
1101 SendCrashFrequencySample(any_crashes_weekly_count_);
1102 SendCrashFrequencySample(user_crashes_weekly_count_);
1103 SendCrashFrequencySample(kernel_crashes_weekly_count_);
1104 SendCrashFrequencySample(unclean_shutdowns_weekly_count_);
1105 }
1106}
1107
Steve Funge86591e2014-12-01 13:38:21 -08001108void MetricsDaemon::HandleUpdateStatsTimeout() {
1109 UpdateStats(TimeTicks::Now(), Time::Now());
1110 base::MessageLoop::current()->PostDelayedTask(FROM_HERE,
1111 base::Bind(&MetricsDaemon::HandleUpdateStatsTimeout,
1112 base::Unretained(this)),
1113 base::TimeDelta::FromMilliseconds(kUpdateStatsIntervalMs));
Daniel Eratc83975a2014-04-04 08:53:44 -07001114}