blob: d6eb8a3025dd49af9f4d19b340513cc2b178c966 [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
5#include "metrics_daemon.h"
Darin Petkov65b01462010-04-14 13:32:20 -07006
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -08007#include <fcntl.h>
Luigi Semenzato8accd332011-05-17 16:37:18 -07008#include <math.h>
Ken Mixter4c5daa42010-08-26 18:35:06 -07009#include <string.h>
Luigi Semenzato8accd332011-05-17 16:37:18 -070010#include <time.h>
Darin Petkov65b01462010-04-14 13:32:20 -070011
Luigi Semenzato859b3f02014-02-05 15:33:19 -080012#include <base/at_exit.h>
Darin Petkov38d5cb02010-06-24 12:10:26 -070013#include <base/file_util.h>
Luigi Semenzato859b3f02014-02-05 15:33:19 -080014#include <base/files/file_path.h>
15#include <base/hash.h>
Darin Petkov65b01462010-04-14 13:32:20 -070016#include <base/logging.h>
Ben Chan2e6543d2014-02-05 23:26:25 -080017#include <base/strings/string_number_conversions.h>
18#include <base/strings/string_split.h>
19#include <base/strings/string_util.h>
20#include <base/strings/stringprintf.h>
Luigi Semenzato859b3f02014-02-05 15:33:19 -080021#include <base/sys_info.h>
Darin Petkov40f25732013-04-29 15:07:31 +020022#include <chromeos/dbus/service_constants.h>
Ken Mixter4c5daa42010-08-26 18:35:06 -070023#include <dbus/dbus-glib-lowlevel.h>
Darin Petkov65b01462010-04-14 13:32:20 -070024
Darin Petkovf1e85e42010-06-10 15:59:53 -070025#include "counter.h"
26
Ben Chan2e6543d2014-02-05 23:26:25 -080027using base::FilePath;
28using base::StringPrintf;
Darin Petkovf27f0362010-06-04 13:14:19 -070029using base::Time;
30using base::TimeDelta;
31using base::TimeTicks;
Luigi Semenzato8accd332011-05-17 16:37:18 -070032using std::map;
Darin Petkov38d5cb02010-06-24 12:10:26 -070033using std::string;
Luigi Semenzato8accd332011-05-17 16:37:18 -070034using std::vector;
35
Darin Petkovf27f0362010-06-04 13:14:19 -070036
Darin Petkov703ec972010-04-27 11:02:18 -070037#define SAFE_MESSAGE(e) (e.message ? e.message : "unknown error")
Darin Petkov40f25732013-04-29 15:07:31 +020038
39static const char kCrashReporterInterface[] = "org.chromium.CrashReporter";
40static const char kCrashReporterUserCrashSignal[] = "UserCrash";
Darin Petkov41e06232010-05-03 16:45:37 -070041
Darin Petkov41e06232010-05-03 16:45:37 -070042static const int kSecondsPerMinute = 60;
43static const int kMinutesPerHour = 60;
44static const int kHoursPerDay = 24;
45static const int kMinutesPerDay = kHoursPerDay * kMinutesPerHour;
Darin Petkov1bb904e2010-06-16 15:58:06 -070046static const int kSecondsPerDay = kSecondsPerMinute * kMinutesPerDay;
47static const int kDaysPerWeek = 7;
48static const int kSecondsPerWeek = kSecondsPerDay * kDaysPerWeek;
Darin Petkov41e06232010-05-03 16:45:37 -070049
50// The daily use monitor is scheduled to a 1-minute interval after
51// initial user activity and then it's exponentially backed off to
52// 10-minute intervals. Although not required, the back off is
53// implemented because the histogram buckets are spaced exponentially
54// anyway and to avoid too frequent metrics daemon process wake-ups
55// and file I/O.
56static const int kUseMonitorIntervalInit = 1 * kSecondsPerMinute;
57static const int kUseMonitorIntervalMax = 10 * kSecondsPerMinute;
Darin Petkov65b01462010-04-14 13:32:20 -070058
Luigi Semenzatoc5a92342014-02-14 15:05:51 -080059const char kKernelCrashDetectedFile[] = "/var/run/kernel-crash-detected";
Ken Mixterccd84c02010-08-16 19:57:13 -070060static const char kUncleanShutdownDetectedFile[] =
Luigi Semenzatoc5a92342014-02-14 15:05:51 -080061 "/var/run/unclean-shutdown-detected";
Ken Mixterccd84c02010-08-16 19:57:13 -070062
Ken Mixter4c5daa42010-08-26 18:35:06 -070063// static metrics parameters
Darin Petkov2ccef012010-05-05 16:06:37 -070064const char MetricsDaemon::kMetricDailyUseTimeName[] =
65 "Logging.DailyUseTime";
66const int MetricsDaemon::kMetricDailyUseTimeMin = 1;
67const int MetricsDaemon::kMetricDailyUseTimeMax = kMinutesPerDay;
68const int MetricsDaemon::kMetricDailyUseTimeBuckets = 50;
69
Ken Mixterccd84c02010-08-16 19:57:13 -070070// crash interval metrics
71const char MetricsDaemon::kMetricKernelCrashIntervalName[] =
72 "Logging.KernelCrashInterval";
73const char MetricsDaemon::kMetricUncleanShutdownIntervalName[] =
74 "Logging.UncleanShutdownInterval";
Darin Petkov1bb904e2010-06-16 15:58:06 -070075const char MetricsDaemon::kMetricUserCrashIntervalName[] =
76 "Logging.UserCrashInterval";
Ken Mixterccd84c02010-08-16 19:57:13 -070077
78const int MetricsDaemon::kMetricCrashIntervalMin = 1;
79const int MetricsDaemon::kMetricCrashIntervalMax =
80 4 * kSecondsPerWeek;
81const int MetricsDaemon::kMetricCrashIntervalBuckets = 50;
82
83// crash frequency metrics
84const char MetricsDaemon::kMetricAnyCrashesDailyName[] =
85 "Logging.AnyCrashesDaily";
Ken Mixter4c5daa42010-08-26 18:35:06 -070086const char MetricsDaemon::kMetricAnyCrashesWeeklyName[] =
87 "Logging.AnyCrashesWeekly";
Ken Mixterccd84c02010-08-16 19:57:13 -070088const char MetricsDaemon::kMetricKernelCrashesDailyName[] =
89 "Logging.KernelCrashesDaily";
Ken Mixter4c5daa42010-08-26 18:35:06 -070090const char MetricsDaemon::kMetricKernelCrashesWeeklyName[] =
91 "Logging.KernelCrashesWeekly";
Luigi Semenzato859b3f02014-02-05 15:33:19 -080092const char MetricsDaemon::kMetricKernelCrashesVersionName[] =
93 "Logging.KernelCrashesSinceUpdate";
94const int MetricsDaemon::kMetricCumulativeCrashCountMin = 1;
95const int MetricsDaemon::kMetricCumulativeCrashCountMax = 500;
96const int MetricsDaemon::kMetricCumulativeCrashCountBuckets = 100;
97
Ken Mixterccd84c02010-08-16 19:57:13 -070098const char MetricsDaemon::kMetricUncleanShutdownsDailyName[] =
99 "Logging.UncleanShutdownsDaily";
Ken Mixter4c5daa42010-08-26 18:35:06 -0700100const char MetricsDaemon::kMetricUncleanShutdownsWeeklyName[] =
101 "Logging.UncleanShutdownsWeekly";
Ken Mixterccd84c02010-08-16 19:57:13 -0700102const char MetricsDaemon::kMetricUserCrashesDailyName[] =
103 "Logging.UserCrashesDaily";
Ken Mixter4c5daa42010-08-26 18:35:06 -0700104const char MetricsDaemon::kMetricUserCrashesWeeklyName[] =
105 "Logging.UserCrashesWeekly";
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800106const int MetricsDaemon::kMetricCrashFrequencyMin = 1;
107const int MetricsDaemon::kMetricCrashFrequencyMax = 100;
108const int MetricsDaemon::kMetricCrashFrequencyBuckets = 50;
Ken Mixterccd84c02010-08-16 19:57:13 -0700109
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800110// disk stats metrics
111
112// The {Read,Write}Sectors numbers are in sectors/second.
113// A sector is usually 512 bytes.
114
115const char MetricsDaemon::kMetricReadSectorsLongName[] =
116 "Platform.ReadSectorsLong";
117const char MetricsDaemon::kMetricWriteSectorsLongName[] =
118 "Platform.WriteSectorsLong";
119const char MetricsDaemon::kMetricReadSectorsShortName[] =
120 "Platform.ReadSectorsShort";
121const char MetricsDaemon::kMetricWriteSectorsShortName[] =
122 "Platform.WriteSectorsShort";
123
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700124const int MetricsDaemon::kMetricStatsShortInterval = 1; // seconds
125const int MetricsDaemon::kMetricStatsLongInterval = 30; // seconds
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800126
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700127const int MetricsDaemon::kMetricMeminfoInterval = 30; // seconds
128
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800129// Assume a max rate of 250Mb/s for reads (worse for writes) and 512 byte
130// sectors.
131const int MetricsDaemon::kMetricSectorsIOMax = 500000; // sectors/second
132const int MetricsDaemon::kMetricSectorsBuckets = 50; // buckets
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700133// Page size is 4k, sector size is 0.5k. We're not interested in page fault
134// rates that the disk cannot sustain.
135const int MetricsDaemon::kMetricPageFaultsMax = kMetricSectorsIOMax / 8;
136const int MetricsDaemon::kMetricPageFaultsBuckets = 50;
137
138// Major page faults, i.e. the ones that require data to be read from disk.
139
140const char MetricsDaemon::kMetricPageFaultsLongName[] =
141 "Platform.PageFaultsLong";
142const char MetricsDaemon::kMetricPageFaultsShortName[] =
143 "Platform.PageFaultsShort";
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800144
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700145// Swap in and Swap out
146
147const char MetricsDaemon::kMetricSwapInLongName[] =
148 "Platform.SwapInLong";
149const char MetricsDaemon::kMetricSwapInShortName[] =
150 "Platform.SwapInShort";
151
152const char MetricsDaemon::kMetricSwapOutLongName[] =
153 "Platform.SwapOutLong";
154const char MetricsDaemon::kMetricSwapOutShortName[] =
155 "Platform.SwapOutShort";
156
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700157// Thermal CPU throttling.
158
159const char MetricsDaemon::kMetricScaledCpuFrequencyName[] =
160 "Platform.CpuFrequencyThermalScaling";
161
Ken Mixter4c5daa42010-08-26 18:35:06 -0700162// persistent metrics path
163const char MetricsDaemon::kMetricsPath[] = "/var/log/metrics";
Ken Mixterccd84c02010-08-16 19:57:13 -0700164
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800165// file containing OS version string
166const char MetricsDaemon::kLsbReleasePath[] = "/etc/lsb-release";
167
168
Darin Petkov703ec972010-04-27 11:02:18 -0700169// static
Darin Petkov41e06232010-05-03 16:45:37 -0700170const char* MetricsDaemon::kPowerStates_[] = {
Darin Petkov703ec972010-04-27 11:02:18 -0700171#define STATE(name, capname) #name,
172#include "power_states.h"
173};
174
Darin Petkov41e06232010-05-03 16:45:37 -0700175// static
Darin Petkov41e06232010-05-03 16:45:37 -0700176const char* MetricsDaemon::kSessionStates_[] = {
177#define STATE(name, capname) #name,
178#include "session_states.h"
179};
180
Luigi Semenzato8accd332011-05-17 16:37:18 -0700181// Memory use stats collection intervals. We collect some memory use interval
182// at these intervals after boot, and we stop collecting after the last one,
183// with the assumption that in most cases the memory use won't change much
184// after that.
185static const int kMemuseIntervals[] = {
186 1 * kSecondsPerMinute, // 1 minute mark
187 4 * kSecondsPerMinute, // 5 minute mark
188 25 * kSecondsPerMinute, // 0.5 hour mark
189 120 * kSecondsPerMinute, // 2.5 hour mark
190 600 * kSecondsPerMinute, // 12.5 hour mark
191};
192
Darin Petkovf1e85e42010-06-10 15:59:53 -0700193MetricsDaemon::MetricsDaemon()
Sam Leffler239b8262010-08-30 08:56:58 -0700194 : power_state_(kUnknownPowerState),
Darin Petkovf1e85e42010-06-10 15:59:53 -0700195 session_state_(kUnknownSessionState),
196 user_active_(false),
197 usemon_interval_(0),
Luigi Semenzato8accd332011-05-17 16:37:18 -0700198 usemon_source_(NULL),
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -0800199 memuse_final_time_(0),
Luigi Semenzato8accd332011-05-17 16:37:18 -0700200 memuse_interval_index_(0),
201 read_sectors_(0),
202 write_sectors_(0),
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700203 vmstats_(),
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700204 stats_state_(kStatsShort),
205 stats_initial_time_(0) {}
Darin Petkovf1e85e42010-06-10 15:59:53 -0700206
Ken Mixter4c5daa42010-08-26 18:35:06 -0700207MetricsDaemon::~MetricsDaemon() {
208 DeleteFrequencyCounters();
209}
210
Luigi Semenzato8accd332011-05-17 16:37:18 -0700211double MetricsDaemon::GetActiveTime() {
212 struct timespec ts;
213 int r = clock_gettime(CLOCK_MONOTONIC, &ts);
214 if (r < 0) {
215 PLOG(WARNING) << "clock_gettime(CLOCK_MONOTONIC) failed";
216 return 0;
217 } else {
218 return ts.tv_sec + ((double) ts.tv_nsec) / (1000 * 1000 * 1000);
219 }
220}
221
Ken Mixter4c5daa42010-08-26 18:35:06 -0700222void MetricsDaemon::DeleteFrequencyCounters() {
223 for (FrequencyCounters::iterator i = frequency_counters_.begin();
224 i != frequency_counters_.end(); ++i) {
225 delete i->second;
226 i->second = NULL;
227 }
228}
Darin Petkovf1e85e42010-06-10 15:59:53 -0700229
Darin Petkov2ccef012010-05-05 16:06:37 -0700230void MetricsDaemon::Run(bool run_as_daemon) {
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800231 base::AtExitManager at_exit_manager;
232
Darin Petkov38d5cb02010-06-24 12:10:26 -0700233 if (run_as_daemon && daemon(0, 0) != 0)
234 return;
235
Ken Mixterccd84c02010-08-16 19:57:13 -0700236 if (CheckSystemCrash(kKernelCrashDetectedFile)) {
237 ProcessKernelCrash();
238 }
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800239 kernel_crash_version_counter_->FlushOnChange(GetOsVersionHash());
Ken Mixterccd84c02010-08-16 19:57:13 -0700240
241 if (CheckSystemCrash(kUncleanShutdownDetectedFile)) {
242 ProcessUncleanShutdown();
243 }
244
Darin Petkov38d5cb02010-06-24 12:10:26 -0700245 Loop();
Darin Petkov65b01462010-04-14 13:32:20 -0700246}
247
Ken Mixter4c5daa42010-08-26 18:35:06 -0700248FilePath MetricsDaemon::GetHistogramPath(const char* histogram_name) {
249 return FilePath(kMetricsPath).Append(histogram_name);
250}
251
252void MetricsDaemon::ConfigureCrashIntervalReporter(
253 const char* histogram_name,
254 scoped_ptr<chromeos_metrics::TaggedCounterReporter>* reporter) {
255 reporter->reset(new chromeos_metrics::TaggedCounterReporter());
256 FilePath file_path = GetHistogramPath(histogram_name);
257 (*reporter)->Init(file_path.value().c_str(),
258 histogram_name,
259 kMetricCrashIntervalMin,
260 kMetricCrashIntervalMax,
261 kMetricCrashIntervalBuckets);
262}
263
264void MetricsDaemon::ConfigureCrashFrequencyReporter(
265 const char* histogram_name) {
266 scoped_ptr<chromeos_metrics::TaggedCounterReporter> reporter(
267 new chromeos_metrics::TaggedCounterReporter());
268 FilePath file_path = GetHistogramPath(histogram_name);
269 reporter->Init(file_path.value().c_str(),
270 histogram_name,
271 kMetricCrashFrequencyMin,
272 kMetricCrashFrequencyMax,
273 kMetricCrashFrequencyBuckets);
274 scoped_ptr<chromeos_metrics::FrequencyCounter> new_counter(
275 new chromeos_metrics::FrequencyCounter());
276 time_t cycle_duration = strstr(histogram_name, "Weekly") != NULL ?
277 chromeos_metrics::kSecondsPerWeek :
278 chromeos_metrics::kSecondsPerDay;
279 new_counter->Init(
280 static_cast<chromeos_metrics::TaggedCounterInterface*>(
281 reporter.release()),
282 cycle_duration);
283 frequency_counters_[histogram_name] = new_counter.release();
284}
285
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800286void MetricsDaemon::ConfigureCrashVersionReporter(
287 const char* histogram_name) {
288 scoped_ptr<chromeos_metrics::TaggedCounterReporter> reporter(
289 new chromeos_metrics::TaggedCounterReporter());
290 FilePath file_path = GetHistogramPath(histogram_name);
291 reporter->Init(file_path.value().c_str(),
292 histogram_name,
293 kMetricCumulativeCrashCountMin,
294 kMetricCumulativeCrashCountMax,
295 kMetricCumulativeCrashCountBuckets);
296 scoped_ptr<chromeos_metrics::VersionCounter> new_counter(
297 new chromeos_metrics::VersionCounter());
298 new_counter->Init(
299 static_cast<chromeos_metrics::TaggedCounterInterface*>(
300 reporter.release()),
301 chromeos_metrics::kSecondsPerDay);
302 kernel_crash_version_counter_ = new_counter.release();
303}
304
305uint32 MetricsDaemon::GetOsVersionHash() {
306 static uint32 cached_version_hash = 0;
307 static bool version_hash_is_cached = false;
308 if (version_hash_is_cached)
309 return cached_version_hash;
310 version_hash_is_cached = true;
311 std::string version;
312 if (base::SysInfo::GetLsbReleaseValue("CHROMEOS_RELEASE_VERSION", &version)) {
313 cached_version_hash = base::Hash(version);
314 } else if (testing_) {
315 cached_version_hash = 42; // return any plausible value for the hash
316 } else {
317 LOG(FATAL) << "could not find CHROMEOS_RELEASE_VERSION";
318 }
319 return cached_version_hash;
320}
321
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800322void MetricsDaemon::Init(bool testing, MetricsLibraryInterface* metrics_lib,
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700323 const string& diskstats_path,
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700324 const string& vmstats_path,
325 const string& scaling_max_freq_path,
326 const string& cpuinfo_max_freq_path
327 ) {
Darin Petkov65b01462010-04-14 13:32:20 -0700328 testing_ = testing;
Darin Petkovfc91b422010-05-12 13:05:45 -0700329 DCHECK(metrics_lib != NULL);
330 metrics_lib_ = metrics_lib;
Ken Mixter4c5daa42010-08-26 18:35:06 -0700331 chromeos_metrics::TaggedCounterReporter::
332 SetMetricsLibraryInterface(metrics_lib);
Darin Petkov38d5cb02010-06-24 12:10:26 -0700333
334 static const char kDailyUseRecordFile[] = "/var/log/metrics/daily-usage";
Darin Petkovf1e85e42010-06-10 15:59:53 -0700335 daily_use_.reset(new chromeos_metrics::TaggedCounter());
Ken Mixterccd84c02010-08-16 19:57:13 -0700336 daily_use_->Init(kDailyUseRecordFile, &ReportDailyUse, this);
Darin Petkov38d5cb02010-06-24 12:10:26 -0700337
Ken Mixter4c5daa42010-08-26 18:35:06 -0700338 ConfigureCrashIntervalReporter(kMetricKernelCrashIntervalName,
339 &kernel_crash_interval_);
340 ConfigureCrashIntervalReporter(kMetricUncleanShutdownIntervalName,
341 &unclean_shutdown_interval_);
342 ConfigureCrashIntervalReporter(kMetricUserCrashIntervalName,
343 &user_crash_interval_);
Darin Petkov2ccef012010-05-05 16:06:37 -0700344
Ken Mixter4c5daa42010-08-26 18:35:06 -0700345 DeleteFrequencyCounters();
346 ConfigureCrashFrequencyReporter(kMetricAnyCrashesDailyName);
Ken Mixter4c5daa42010-08-26 18:35:06 -0700347 ConfigureCrashFrequencyReporter(kMetricAnyCrashesWeeklyName);
348 ConfigureCrashFrequencyReporter(kMetricKernelCrashesDailyName);
349 ConfigureCrashFrequencyReporter(kMetricKernelCrashesWeeklyName);
350 ConfigureCrashFrequencyReporter(kMetricUncleanShutdownsDailyName);
351 ConfigureCrashFrequencyReporter(kMetricUncleanShutdownsWeeklyName);
352 ConfigureCrashFrequencyReporter(kMetricUserCrashesDailyName);
353 ConfigureCrashFrequencyReporter(kMetricUserCrashesWeeklyName);
Darin Petkov38d5cb02010-06-24 12:10:26 -0700354
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800355 ConfigureCrashVersionReporter(kMetricKernelCrashesVersionName);
356
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700357 diskstats_path_ = diskstats_path;
358 vmstats_path_ = vmstats_path;
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700359 scaling_max_freq_path_ = scaling_max_freq_path;
360 cpuinfo_max_freq_path_ = cpuinfo_max_freq_path;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700361 StatsReporterInit();
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800362
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700363 // Start collecting meminfo stats.
364 ScheduleMeminfoCallback(kMetricMeminfoInterval);
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -0800365 memuse_final_time_ = GetActiveTime() + kMemuseIntervals[0];
366 ScheduleMemuseCallback(kMemuseIntervals[0]);
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700367
Darin Petkov2ccef012010-05-05 16:06:37 -0700368 // Don't setup D-Bus and GLib in test mode.
369 if (testing)
370 return;
Darin Petkov65b01462010-04-14 13:32:20 -0700371
Darin Petkov703ec972010-04-27 11:02:18 -0700372 g_type_init();
Ben Chan6f598422013-06-22 06:29:36 -0700373 dbus_threads_init_default();
Darin Petkov65b01462010-04-14 13:32:20 -0700374
Darin Petkov703ec972010-04-27 11:02:18 -0700375 DBusError error;
376 dbus_error_init(&error);
Darin Petkov65b01462010-04-14 13:32:20 -0700377
David James3b3add52010-06-04 15:01:19 -0700378 DBusConnection* connection = dbus_bus_get(DBUS_BUS_SYSTEM, &error);
Darin Petkov703ec972010-04-27 11:02:18 -0700379 LOG_IF(FATAL, dbus_error_is_set(&error)) <<
380 "No D-Bus connection: " << SAFE_MESSAGE(error);
Darin Petkov65b01462010-04-14 13:32:20 -0700381
Darin Petkov703ec972010-04-27 11:02:18 -0700382 dbus_connection_setup_with_g_main(connection, NULL);
Darin Petkov65b01462010-04-14 13:32:20 -0700383
Darin Petkov40f25732013-04-29 15:07:31 +0200384 vector<string> matches;
385 matches.push_back(
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800386 base::StringPrintf("type='signal',interface='%s',path='/',member='%s'",
387 kCrashReporterInterface,
388 kCrashReporterUserCrashSignal));
Darin Petkov40f25732013-04-29 15:07:31 +0200389 matches.push_back(
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800390 base::StringPrintf("type='signal',interface='%s',path='%s',member='%s'",
391 power_manager::kPowerManagerInterface,
392 power_manager::kPowerManagerServicePath,
393 power_manager::kPowerStateChangedSignal));
Darin Petkov40f25732013-04-29 15:07:31 +0200394 matches.push_back(
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800395 base::StringPrintf("type='signal',sender='%s',interface='%s',path='%s'",
396 login_manager::kSessionManagerServiceName,
397 login_manager::kSessionManagerInterface,
398 login_manager::kSessionManagerServicePath));
Darin Petkov40f25732013-04-29 15:07:31 +0200399
Darin Petkov703ec972010-04-27 11:02:18 -0700400 // Registers D-Bus matches for the signals we would like to catch.
Darin Petkov40f25732013-04-29 15:07:31 +0200401 for (vector<string>::const_iterator it = matches.begin();
402 it != matches.end(); ++it) {
403 const char* match = it->c_str();
Darin Petkov41e06232010-05-03 16:45:37 -0700404 DLOG(INFO) << "adding dbus match: " << match;
Darin Petkov703ec972010-04-27 11:02:18 -0700405 dbus_bus_add_match(connection, match, &error);
406 LOG_IF(FATAL, dbus_error_is_set(&error)) <<
407 "unable to add a match: " << SAFE_MESSAGE(error);
408 }
409
410 // Adds the D-Bus filter routine to be called back whenever one of
411 // the registered D-Bus matches is successful. The daemon is not
412 // activated for D-Bus messages that don't match.
413 CHECK(dbus_connection_add_filter(connection, MessageFilter, this, NULL));
Darin Petkov65b01462010-04-14 13:32:20 -0700414}
415
416void MetricsDaemon::Loop() {
Darin Petkov703ec972010-04-27 11:02:18 -0700417 GMainLoop* loop = g_main_loop_new(NULL, false);
418 g_main_loop_run(loop);
Darin Petkov65b01462010-04-14 13:32:20 -0700419}
420
Darin Petkov703ec972010-04-27 11:02:18 -0700421// static
422DBusHandlerResult MetricsDaemon::MessageFilter(DBusConnection* connection,
423 DBusMessage* message,
424 void* user_data) {
Darin Petkovf27f0362010-06-04 13:14:19 -0700425 Time now = Time::Now();
Darin Petkovf27f0362010-06-04 13:14:19 -0700426 DLOG(INFO) << "message intercepted @ " << now.ToInternalValue();
Darin Petkov703ec972010-04-27 11:02:18 -0700427
428 int message_type = dbus_message_get_type(message);
429 if (message_type != DBUS_MESSAGE_TYPE_SIGNAL) {
Darin Petkov41e06232010-05-03 16:45:37 -0700430 DLOG(WARNING) << "unexpected message type " << message_type;
Darin Petkov703ec972010-04-27 11:02:18 -0700431 return DBUS_HANDLER_RESULT_NOT_YET_HANDLED;
432 }
433
434 // Signal messages always have interfaces.
435 const char* interface = dbus_message_get_interface(message);
436 CHECK(interface != NULL);
437
438 MetricsDaemon* daemon = static_cast<MetricsDaemon*>(user_data);
439
440 DBusMessageIter iter;
441 dbus_message_iter_init(message, &iter);
Darin Petkov40f25732013-04-29 15:07:31 +0200442 if (strcmp(interface, kCrashReporterInterface) == 0) {
Darin Petkov1bb904e2010-06-16 15:58:06 -0700443 CHECK(strcmp(dbus_message_get_member(message),
Darin Petkov40f25732013-04-29 15:07:31 +0200444 kCrashReporterUserCrashSignal) == 0);
Darin Petkov1bb904e2010-06-16 15:58:06 -0700445 daemon->ProcessUserCrash();
Darin Petkov40f25732013-04-29 15:07:31 +0200446 } else if (strcmp(interface, power_manager::kPowerManagerInterface) == 0) {
Darin Petkov41e06232010-05-03 16:45:37 -0700447 CHECK(strcmp(dbus_message_get_member(message),
Darin Petkov40f25732013-04-29 15:07:31 +0200448 power_manager::kPowerStateChangedSignal) == 0);
David James3b3add52010-06-04 15:01:19 -0700449 char* state_name;
Darin Petkov41e06232010-05-03 16:45:37 -0700450 dbus_message_iter_get_basic(&iter, &state_name);
Darin Petkov40f25732013-04-29 15:07:31 +0200451 daemon->PowerStateChanged(state_name, now);
452 } else if (strcmp(interface, login_manager::kSessionManagerInterface) == 0) {
453 const char* member = dbus_message_get_member(message);
454 if (strcmp(member, login_manager::kScreenIsLockedSignal) == 0) {
455 daemon->SetUserActiveState(false, now);
456 } else if (strcmp(member, login_manager::kScreenIsUnlockedSignal) == 0) {
457 daemon->SetUserActiveState(true, now);
458 } else if (strcmp(member, login_manager::kSessionStateChangedSignal) == 0) {
459 char* state_name;
460 dbus_message_iter_get_basic(&iter, &state_name);
461 daemon->SessionStateChanged(state_name, now);
462 }
Darin Petkov703ec972010-04-27 11:02:18 -0700463 } else {
Darin Petkov41e06232010-05-03 16:45:37 -0700464 DLOG(WARNING) << "unexpected interface: " << interface;
Darin Petkov703ec972010-04-27 11:02:18 -0700465 return DBUS_HANDLER_RESULT_NOT_YET_HANDLED;
466 }
467
468 return DBUS_HANDLER_RESULT_HANDLED;
Darin Petkov65b01462010-04-14 13:32:20 -0700469}
470
Darin Petkovf27f0362010-06-04 13:14:19 -0700471void MetricsDaemon::PowerStateChanged(const char* state_name, Time now) {
Darin Petkov41e06232010-05-03 16:45:37 -0700472 DLOG(INFO) << "power state: " << state_name;
Darin Petkov703ec972010-04-27 11:02:18 -0700473 power_state_ = LookupPowerState(state_name);
Darin Petkov41e06232010-05-03 16:45:37 -0700474
475 if (power_state_ != kPowerStateOn)
476 SetUserActiveState(false, now);
Darin Petkov703ec972010-04-27 11:02:18 -0700477}
478
479MetricsDaemon::PowerState
480MetricsDaemon::LookupPowerState(const char* state_name) {
481 for (int i = 0; i < kNumberPowerStates; i++) {
Darin Petkov41e06232010-05-03 16:45:37 -0700482 if (strcmp(state_name, kPowerStates_[i]) == 0) {
Darin Petkov703ec972010-04-27 11:02:18 -0700483 return static_cast<PowerState>(i);
484 }
485 }
Darin Petkov41e06232010-05-03 16:45:37 -0700486 DLOG(WARNING) << "unknown power state: " << state_name;
Darin Petkov703ec972010-04-27 11:02:18 -0700487 return kUnknownPowerState;
Darin Petkov65b01462010-04-14 13:32:20 -0700488}
489
Darin Petkovf27f0362010-06-04 13:14:19 -0700490void MetricsDaemon::SessionStateChanged(const char* state_name, Time now) {
Darin Petkov41e06232010-05-03 16:45:37 -0700491 DLOG(INFO) << "user session state: " << state_name;
492 session_state_ = LookupSessionState(state_name);
493 SetUserActiveState(session_state_ == kSessionStateStarted, now);
494}
495
496MetricsDaemon::SessionState
497MetricsDaemon::LookupSessionState(const char* state_name) {
498 for (int i = 0; i < kNumberSessionStates; i++) {
499 if (strcmp(state_name, kSessionStates_[i]) == 0) {
500 return static_cast<SessionState>(i);
501 }
502 }
503 DLOG(WARNING) << "unknown user session state: " << state_name;
504 return kUnknownSessionState;
505}
506
Darin Petkovf27f0362010-06-04 13:14:19 -0700507void MetricsDaemon::SetUserActiveState(bool active, Time now) {
Darin Petkov41e06232010-05-03 16:45:37 -0700508 DLOG(INFO) << "user: " << (active ? "active" : "inactive");
509
510 // Calculates the seconds of active use since the last update and
Darin Petkovf27f0362010-06-04 13:14:19 -0700511 // the day since Epoch, and logs the usage data. Guards against the
512 // time jumping back and forth due to the user changing it by
513 // discarding the new use time.
514 int seconds = 0;
515 if (user_active_ && now > user_active_last_) {
516 TimeDelta since_active = now - user_active_last_;
517 if (since_active < TimeDelta::FromSeconds(
518 kUseMonitorIntervalMax + kSecondsPerMinute)) {
519 seconds = static_cast<int>(since_active.InSeconds());
520 }
521 }
522 TimeDelta since_epoch = now - Time();
523 int day = since_epoch.InDays();
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800524 daily_use_->Update(day, seconds, 0);
525 user_crash_interval_->Update(0, seconds, 0);
526 kernel_crash_interval_->Update(0, seconds, 0);
Darin Petkov41e06232010-05-03 16:45:37 -0700527
Ken Mixter4c5daa42010-08-26 18:35:06 -0700528 // Flush finished cycles of all frequency counters.
529 for (FrequencyCounters::iterator i = frequency_counters_.begin();
530 i != frequency_counters_.end(); ++i) {
531 i->second->FlushFinishedCycles();
532 }
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800533 // Report count if we're on a new cycle. FlushOnChange can also reset the
534 // counter, but not when called from here, because any version change has
535 // already been processed during initialization.
536 kernel_crash_version_counter_->FlushOnChange(GetOsVersionHash());
Ken Mixter4c5daa42010-08-26 18:35:06 -0700537
Darin Petkov41e06232010-05-03 16:45:37 -0700538 // Schedules a use monitor on inactive->active transitions and
539 // unschedules it on active->inactive transitions.
540 if (!user_active_ && active)
541 ScheduleUseMonitor(kUseMonitorIntervalInit, /* backoff */ false);
542 else if (user_active_ && !active)
543 UnscheduleUseMonitor();
544
545 // Remembers the current active state and the time of the last
546 // activity update.
547 user_active_ = active;
548 user_active_last_ = now;
549}
550
Darin Petkov1bb904e2010-06-16 15:58:06 -0700551void MetricsDaemon::ProcessUserCrash() {
552 // Counts the active use time up to now.
553 SetUserActiveState(user_active_, Time::Now());
554
555 // Reports the active use time since the last crash and resets it.
556 user_crash_interval_->Flush();
Ken Mixterccd84c02010-08-16 19:57:13 -0700557
Ken Mixter4c5daa42010-08-26 18:35:06 -0700558 frequency_counters_[kMetricUserCrashesDailyName]->Update(1);
559 frequency_counters_[kMetricUserCrashesWeeklyName]->Update(1);
560 frequency_counters_[kMetricAnyCrashesDailyName]->Update(1);
561 frequency_counters_[kMetricAnyCrashesWeeklyName]->Update(1);
Darin Petkov1bb904e2010-06-16 15:58:06 -0700562}
563
Darin Petkov38d5cb02010-06-24 12:10:26 -0700564void MetricsDaemon::ProcessKernelCrash() {
565 // Counts the active use time up to now.
566 SetUserActiveState(user_active_, Time::Now());
567
568 // Reports the active use time since the last crash and resets it.
569 kernel_crash_interval_->Flush();
Ken Mixterccd84c02010-08-16 19:57:13 -0700570
Ken Mixter4c5daa42010-08-26 18:35:06 -0700571 frequency_counters_[kMetricKernelCrashesDailyName]->Update(1);
572 frequency_counters_[kMetricKernelCrashesWeeklyName]->Update(1);
573 frequency_counters_[kMetricAnyCrashesDailyName]->Update(1);
574 frequency_counters_[kMetricAnyCrashesWeeklyName]->Update(1);
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800575
576 kernel_crash_version_counter_->Update(1, GetOsVersionHash());
Darin Petkov38d5cb02010-06-24 12:10:26 -0700577}
578
Ken Mixterccd84c02010-08-16 19:57:13 -0700579void MetricsDaemon::ProcessUncleanShutdown() {
580 // Counts the active use time up to now.
581 SetUserActiveState(user_active_, Time::Now());
582
583 // Reports the active use time since the last crash and resets it.
584 unclean_shutdown_interval_->Flush();
585
Ken Mixter4c5daa42010-08-26 18:35:06 -0700586 frequency_counters_[kMetricUncleanShutdownsDailyName]->Update(1);
587 frequency_counters_[kMetricUncleanShutdownsWeeklyName]->Update(1);
588 frequency_counters_[kMetricAnyCrashesDailyName]->Update(1);
589 frequency_counters_[kMetricAnyCrashesWeeklyName]->Update(1);
Ken Mixterccd84c02010-08-16 19:57:13 -0700590}
591
Luigi Semenzato8accd332011-05-17 16:37:18 -0700592bool MetricsDaemon::CheckSystemCrash(const string& crash_file) {
Darin Petkov38d5cb02010-06-24 12:10:26 -0700593 FilePath crash_detected(crash_file);
Ben Chan2e6543d2014-02-05 23:26:25 -0800594 if (!base::PathExists(crash_detected))
Ken Mixterccd84c02010-08-16 19:57:13 -0700595 return false;
Darin Petkov38d5cb02010-06-24 12:10:26 -0700596
597 // Deletes the crash-detected file so that the daemon doesn't report
598 // another kernel crash in case it's restarted.
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800599 base::DeleteFile(crash_detected, false); // not recursive
Ken Mixterccd84c02010-08-16 19:57:13 -0700600 return true;
Darin Petkov38d5cb02010-06-24 12:10:26 -0700601}
602
Darin Petkov41e06232010-05-03 16:45:37 -0700603// static
604gboolean MetricsDaemon::UseMonitorStatic(gpointer data) {
605 return static_cast<MetricsDaemon*>(data)->UseMonitor() ? TRUE : FALSE;
606}
607
608bool MetricsDaemon::UseMonitor() {
Darin Petkovf27f0362010-06-04 13:14:19 -0700609 SetUserActiveState(user_active_, Time::Now());
Darin Petkov41e06232010-05-03 16:45:37 -0700610
611 // If a new monitor source/instance is scheduled, returns false to
612 // tell GLib to destroy this monitor source/instance. Returns true
613 // otherwise to keep calling back this monitor.
614 return !ScheduleUseMonitor(usemon_interval_ * 2, /* backoff */ true);
615}
616
617bool MetricsDaemon::ScheduleUseMonitor(int interval, bool backoff)
618{
Darin Petkov2ccef012010-05-05 16:06:37 -0700619 if (testing_)
620 return false;
621
Darin Petkov41e06232010-05-03 16:45:37 -0700622 // Caps the interval -- the bigger the interval, the more active use
623 // time will be potentially dropped on system shutdown.
624 if (interval > kUseMonitorIntervalMax)
625 interval = kUseMonitorIntervalMax;
626
627 if (backoff) {
628 // Back-off mode is used by the use monitor to reschedule itself
629 // with exponential back-off in time. This mode doesn't create a
630 // new timeout source if the new interval is the same as the old
631 // one. Also, if a new timeout source is created, the old one is
632 // not destroyed explicitly here -- it will be destroyed by GLib
633 // when the monitor returns FALSE (see UseMonitor and
634 // UseMonitorStatic).
635 if (interval == usemon_interval_)
636 return false;
637 } else {
638 UnscheduleUseMonitor();
639 }
640
641 // Schedules a new use monitor for |interval| seconds from now.
642 DLOG(INFO) << "scheduling use monitor in " << interval << " seconds";
643 usemon_source_ = g_timeout_source_new_seconds(interval);
644 g_source_set_callback(usemon_source_, UseMonitorStatic, this,
645 NULL); // No destroy notification.
646 g_source_attach(usemon_source_,
647 NULL); // Default context.
648 usemon_interval_ = interval;
649 return true;
650}
651
652void MetricsDaemon::UnscheduleUseMonitor() {
653 // If there's a use monitor scheduled already, destroys it.
654 if (usemon_source_ == NULL)
655 return;
656
657 DLOG(INFO) << "destroying use monitor";
658 g_source_destroy(usemon_source_);
659 usemon_source_ = NULL;
660 usemon_interval_ = 0;
661}
662
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700663void MetricsDaemon::StatsReporterInit() {
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800664 DiskStatsReadStats(&read_sectors_, &write_sectors_);
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700665 VmStatsReadStats(&vmstats_);
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800666 // The first time around just run the long stat, so we don't delay boot.
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700667 stats_state_ = kStatsLong;
668 stats_initial_time_ = GetActiveTime();
669 if (stats_initial_time_ < 0) {
Luigi Semenzato8accd332011-05-17 16:37:18 -0700670 LOG(WARNING) << "not collecting disk stats";
671 } else {
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700672 ScheduleStatsCallback(kMetricStatsLongInterval);
Luigi Semenzato8accd332011-05-17 16:37:18 -0700673 }
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800674}
675
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700676void MetricsDaemon::ScheduleStatsCallback(int wait) {
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800677 if (testing_) {
678 return;
679 }
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700680 g_timeout_add_seconds(wait, StatsCallbackStatic, this);
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800681}
682
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700683bool MetricsDaemon::DiskStatsReadStats(long int* read_sectors,
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800684 long int* write_sectors) {
685 int nchars;
686 int nitems;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700687 bool success = false;
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800688 char line[200];
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700689 if (diskstats_path_.empty()) {
690 return false;
691 }
Luigi Semenzato0f132bb2011-02-28 11:17:43 -0800692 int file = HANDLE_EINTR(open(diskstats_path_.c_str(), O_RDONLY));
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800693 if (file < 0) {
694 PLOG(WARNING) << "cannot open " << diskstats_path_;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700695 return false;
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800696 }
697 nchars = HANDLE_EINTR(read(file, line, sizeof(line)));
698 if (nchars < 0) {
699 PLOG(WARNING) << "cannot read from " << diskstats_path_;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700700 return false;
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800701 } else {
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700702 LOG_IF(WARNING, nchars == sizeof(line))
703 << "line too long in " << diskstats_path_;
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800704 line[nchars] = '\0';
705 nitems = sscanf(line, "%*d %*d %ld %*d %*d %*d %ld",
706 read_sectors, write_sectors);
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700707 if (nitems == 2) {
708 success = true;
709 } else {
710 LOG(WARNING) << "found " << nitems << " items in "
711 << diskstats_path_ << ", expected 2";
712 }
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800713 }
714 HANDLE_EINTR(close(file));
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700715 return success;
716}
717
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700718bool MetricsDaemon::VmStatsParseStats(const char* stats,
719 struct VmstatRecord* record) {
720 // a mapping of string name to field in VmstatRecord and whether we found it
721 struct mapping {
722 const string name;
723 uint64_t* value_p;
724 bool found;
725 } map[] =
726 { { .name = "pgmajfault",
727 .value_p = &record->page_faults_,
728 .found = false },
729 { .name = "pswpin",
730 .value_p = &record->swap_in_,
731 .found = false },
732 { .name = "pswpout",
733 .value_p = &record->swap_out_,
734 .found = false }, };
735
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700736 // Each line in the file has the form
737 // <ID> <VALUE>
738 // for instance:
739 // nr_free_pages 213427
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700740 vector<string> lines;
741 Tokenize(stats, "\n", &lines);
742 for (vector<string>::iterator it = lines.begin();
743 it != lines.end(); ++it) {
744 vector<string> tokens;
745 base::SplitString(*it, ' ', &tokens);
746 if (tokens.size() == 2) {
747 for (unsigned int i = 0; i < sizeof(map)/sizeof(struct mapping); i++) {
748 if (!tokens[0].compare(map[i].name)) {
749 if (!base::StringToUint64(tokens[1], map[i].value_p))
750 return false;
751 map[i].found = true;
752 }
753 }
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700754 } else {
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700755 LOG(WARNING) << "unexpected vmstat format";
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700756 }
757 }
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700758 // make sure we got all the stats
759 for (unsigned i = 0; i < sizeof(map)/sizeof(struct mapping); i++) {
760 if (map[i].found == false) {
761 LOG(WARNING) << "vmstat missing " << map[i].name;
762 return false;
763 }
764 }
765 return true;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700766}
767
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700768bool MetricsDaemon::VmStatsReadStats(struct VmstatRecord* stats) {
769 string value_string;
770 FilePath* path = new FilePath(vmstats_path_);
Ben Chan2e6543d2014-02-05 23:26:25 -0800771 if (!base::ReadFileToString(*path, &value_string)) {
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700772 delete path;
773 LOG(WARNING) << "cannot read " << vmstats_path_;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700774 return false;
775 }
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700776 delete path;
777 return VmStatsParseStats(value_string.c_str(), stats);
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800778}
779
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700780bool MetricsDaemon::ReadFreqToInt(const string& sysfs_file_name, int* value) {
Luigi Semenzatod92d18c2013-06-04 13:24:21 -0700781 const FilePath sysfs_path(sysfs_file_name);
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700782 string value_string;
Ben Chan2e6543d2014-02-05 23:26:25 -0800783 if (!base::ReadFileToString(sysfs_path, &value_string)) {
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700784 LOG(WARNING) << "cannot read " << sysfs_path.value().c_str();
785 return false;
786 }
Ben Chan2e6543d2014-02-05 23:26:25 -0800787 if (!base::RemoveChars(value_string, "\n", &value_string)) {
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700788 LOG(WARNING) << "no newline in " << value_string;
789 // Continue even though the lack of newline is suspicious.
790 }
791 if (!base::StringToInt(value_string, value)) {
792 LOG(WARNING) << "cannot convert " << value_string << " to int";
793 return false;
794 }
795 return true;
796}
797
798void MetricsDaemon::SendCpuThrottleMetrics() {
799 // |max_freq| is 0 only the first time through.
800 static int max_freq = 0;
801 if (max_freq == -1)
802 // Give up, as sysfs did not report max_freq correctly.
803 return;
804 if (max_freq == 0 || testing_) {
805 // One-time initialization of max_freq. (Every time when testing.)
806 if (!ReadFreqToInt(cpuinfo_max_freq_path_, &max_freq)) {
807 max_freq = -1;
808 return;
809 }
810 if (max_freq == 0) {
811 LOG(WARNING) << "sysfs reports 0 max CPU frequency\n";
812 max_freq = -1;
813 return;
814 }
815 if (max_freq % 10000 == 1000) {
816 // Special case: system has turbo mode, and max non-turbo frequency is
817 // max_freq - 1000. This relies on "normal" (non-turbo) frequencies
818 // being multiples of (at least) 10 MHz. Although there is no guarantee
819 // of this, it seems a fairly reasonable assumption. Otherwise we should
820 // read scaling_available_frequencies, sort the frequencies, compare the
821 // two highest ones, and check if they differ by 1000 (kHz) (and that's a
822 // hack too, no telling when it will change).
823 max_freq -= 1000;
824 }
825 }
826 int scaled_freq = 0;
827 if (!ReadFreqToInt(scaling_max_freq_path_, &scaled_freq))
828 return;
829 // Frequencies are in kHz. If scaled_freq > max_freq, turbo is on, but
830 // scaled_freq is not the actual turbo frequency. We indicate this situation
831 // with a 101% value.
832 int percent = scaled_freq > max_freq ? 101 : scaled_freq / (max_freq / 100);
833 SendLinearMetric(kMetricScaledCpuFrequencyName, percent, 101, 102);
834}
835
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800836// static
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700837gboolean MetricsDaemon::StatsCallbackStatic(void* handle) {
838 (static_cast<MetricsDaemon*>(handle))->StatsCallback();
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800839 return false; // one-time callback
840}
841
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700842// Collects disk and vm stats alternating over a short and a long interval.
Luigi Semenzato8accd332011-05-17 16:37:18 -0700843
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700844void MetricsDaemon::StatsCallback() {
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700845 long int read_sectors_now, write_sectors_now;
846 struct VmstatRecord vmstats_now;
Luigi Semenzato8accd332011-05-17 16:37:18 -0700847 double time_now = GetActiveTime();
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700848 double delta_time = time_now - stats_initial_time_;
Luigi Semenzato8accd332011-05-17 16:37:18 -0700849 if (testing_) {
850 // Fake the time when testing.
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700851 delta_time = stats_state_ == kStatsShort ?
852 kMetricStatsShortInterval : kMetricStatsLongInterval;
Luigi Semenzato8accd332011-05-17 16:37:18 -0700853 }
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700854 bool diskstats_success = DiskStatsReadStats(&read_sectors_now,
855 &write_sectors_now);
Luigi Semenzato8accd332011-05-17 16:37:18 -0700856 int delta_read = read_sectors_now - read_sectors_;
857 int delta_write = write_sectors_now - write_sectors_;
858 int read_sectors_per_second = delta_read / delta_time;
859 int write_sectors_per_second = delta_write / delta_time;
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700860 bool vmstats_success = VmStatsReadStats(&vmstats_now);
861 uint64_t delta_faults = vmstats_now.page_faults_ - vmstats_.page_faults_;
862 uint64_t delta_swap_in = vmstats_now.swap_in_ - vmstats_.swap_in_;
863 uint64_t delta_swap_out = vmstats_now.swap_out_ - vmstats_.swap_out_;
864 uint64_t page_faults_per_second = delta_faults / delta_time;
865 uint64_t swap_in_per_second = delta_swap_in / delta_time;
866 uint64_t swap_out_per_second = delta_swap_out / delta_time;
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800867
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700868 switch (stats_state_) {
869 case kStatsShort:
870 if (diskstats_success) {
871 SendMetric(kMetricReadSectorsShortName,
872 read_sectors_per_second,
873 1,
874 kMetricSectorsIOMax,
875 kMetricSectorsBuckets);
876 SendMetric(kMetricWriteSectorsShortName,
877 write_sectors_per_second,
878 1,
879 kMetricSectorsIOMax,
880 kMetricSectorsBuckets);
881 }
882 if (vmstats_success) {
883 SendMetric(kMetricPageFaultsShortName,
884 page_faults_per_second,
885 1,
886 kMetricPageFaultsMax,
887 kMetricPageFaultsBuckets);
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700888 SendMetric(kMetricSwapInShortName,
889 swap_in_per_second,
890 1,
891 kMetricPageFaultsMax,
892 kMetricPageFaultsBuckets);
893 SendMetric(kMetricSwapOutShortName,
894 swap_out_per_second,
895 1,
896 kMetricPageFaultsMax,
897 kMetricPageFaultsBuckets);
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700898 }
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800899 // Schedule long callback.
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700900 stats_state_ = kStatsLong;
901 ScheduleStatsCallback(kMetricStatsLongInterval -
902 kMetricStatsShortInterval);
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800903 break;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700904 case kStatsLong:
905 if (diskstats_success) {
906 SendMetric(kMetricReadSectorsLongName,
907 read_sectors_per_second,
908 1,
909 kMetricSectorsIOMax,
910 kMetricSectorsBuckets);
911 SendMetric(kMetricWriteSectorsLongName,
912 write_sectors_per_second,
913 1,
914 kMetricSectorsIOMax,
915 kMetricSectorsBuckets);
916 // Reset sector counters.
917 read_sectors_ = read_sectors_now;
918 write_sectors_ = write_sectors_now;
919 }
920 if (vmstats_success) {
921 SendMetric(kMetricPageFaultsLongName,
922 page_faults_per_second,
923 1,
924 kMetricPageFaultsMax,
925 kMetricPageFaultsBuckets);
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700926 SendMetric(kMetricSwapInLongName,
927 swap_in_per_second,
928 1,
929 kMetricPageFaultsMax,
930 kMetricPageFaultsBuckets);
931 SendMetric(kMetricSwapOutLongName,
932 swap_out_per_second,
933 1,
934 kMetricPageFaultsMax,
935 kMetricPageFaultsBuckets);
936
937 vmstats_ = vmstats_now;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700938 }
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700939 SendCpuThrottleMetrics();
Luigi Semenzato8accd332011-05-17 16:37:18 -0700940 // Set start time for new cycle.
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700941 stats_initial_time_ = time_now;
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800942 // Schedule short callback.
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700943 stats_state_ = kStatsShort;
944 ScheduleStatsCallback(kMetricStatsShortInterval);
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800945 break;
946 default:
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700947 LOG(FATAL) << "Invalid stats state";
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800948 }
949}
950
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700951void MetricsDaemon::ScheduleMeminfoCallback(int wait) {
952 if (testing_) {
953 return;
954 }
955 g_timeout_add_seconds(wait, MeminfoCallbackStatic, this);
956}
957
958// static
959gboolean MetricsDaemon::MeminfoCallbackStatic(void* handle) {
960 return (static_cast<MetricsDaemon*>(handle))->MeminfoCallback();
961}
962
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700963bool MetricsDaemon::MeminfoCallback() {
Luigi Semenzato8accd332011-05-17 16:37:18 -0700964 string meminfo_raw;
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700965 const FilePath meminfo_path("/proc/meminfo");
Ben Chan2e6543d2014-02-05 23:26:25 -0800966 if (!base::ReadFileToString(meminfo_path, &meminfo_raw)) {
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700967 LOG(WARNING) << "cannot read " << meminfo_path.value().c_str();
968 return false;
969 }
Luigi Semenzato8accd332011-05-17 16:37:18 -0700970 return ProcessMeminfo(meminfo_raw);
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700971}
972
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700973bool MetricsDaemon::ProcessMeminfo(const string& meminfo_raw) {
Luigi Semenzato8accd332011-05-17 16:37:18 -0700974 static const MeminfoRecord fields_array[] = {
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700975 { "MemTotal", "MemTotal" }, // SPECIAL CASE: total system memory
976 { "MemFree", "MemFree" },
977 { "Buffers", "Buffers" },
978 { "Cached", "Cached" },
979 // { "SwapCached", "SwapCached" },
980 { "Active", "Active" },
981 { "Inactive", "Inactive" },
982 { "ActiveAnon", "Active(anon)" },
983 { "InactiveAnon", "Inactive(anon)" },
984 { "ActiveFile" , "Active(file)" },
985 { "InactiveFile", "Inactive(file)" },
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800986 { "Unevictable", "Unevictable", kMeminfoOp_HistLog },
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700987 // { "Mlocked", "Mlocked" },
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800988 { "SwapTotal", "SwapTotal", kMeminfoOp_SwapTotal },
989 { "SwapFree", "SwapFree", kMeminfoOp_SwapFree },
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700990 // { "Dirty", "Dirty" },
991 // { "Writeback", "Writeback" },
992 { "AnonPages", "AnonPages" },
993 { "Mapped", "Mapped" },
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800994 { "Shmem", "Shmem", kMeminfoOp_HistLog },
995 { "Slab", "Slab", kMeminfoOp_HistLog },
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700996 // { "SReclaimable", "SReclaimable" },
997 // { "SUnreclaim", "SUnreclaim" },
998 };
Luigi Semenzato8accd332011-05-17 16:37:18 -0700999 vector<MeminfoRecord> fields(fields_array,
1000 fields_array + arraysize(fields_array));
1001 if (!FillMeminfo(meminfo_raw, &fields)) {
1002 return false;
1003 }
1004 int total_memory = fields[0].value;
1005 if (total_memory == 0) {
1006 // this "cannot happen"
1007 LOG(WARNING) << "borked meminfo parser";
1008 return false;
1009 }
Luigi Semenzato942cbab2013-02-12 13:17:07 -08001010 int swap_total = 0;
1011 int swap_free = 0;
Luigi Semenzato8accd332011-05-17 16:37:18 -07001012 // Send all fields retrieved, except total memory.
1013 for (unsigned int i = 1; i < fields.size(); i++) {
Luigi Semenzato859b3f02014-02-05 15:33:19 -08001014 string metrics_name = base::StringPrintf("Platform.Meminfo%s",
1015 fields[i].name);
Luigi Semenzato3ccca062013-02-04 19:50:45 -08001016 int percent;
Luigi Semenzato942cbab2013-02-12 13:17:07 -08001017 switch (fields[i].op) {
1018 case kMeminfoOp_HistPercent:
Luigi Semenzato3ccca062013-02-04 19:50:45 -08001019 // report value as percent of total memory
1020 percent = fields[i].value * 100 / total_memory;
1021 SendLinearMetric(metrics_name, percent, 100, 101);
1022 break;
Luigi Semenzato942cbab2013-02-12 13:17:07 -08001023 case kMeminfoOp_HistLog:
Luigi Semenzato3ccca062013-02-04 19:50:45 -08001024 // report value in kbytes, log scale, 4Gb max
1025 SendMetric(metrics_name, fields[i].value, 1, 4 * 1000 * 1000, 100);
1026 break;
Luigi Semenzato942cbab2013-02-12 13:17:07 -08001027 case kMeminfoOp_SwapTotal:
1028 swap_total = fields[i].value;
1029 case kMeminfoOp_SwapFree:
1030 swap_free = fields[i].value;
Luigi Semenzato3ccca062013-02-04 19:50:45 -08001031 break;
Luigi Semenzato8accd332011-05-17 16:37:18 -07001032 }
1033 }
Luigi Semenzato942cbab2013-02-12 13:17:07 -08001034 if (swap_total > 0) {
1035 int swap_used = swap_total - swap_free;
1036 int swap_used_percent = swap_used * 100 / swap_total;
1037 SendMetric("Platform.MeminfoSwapUsed", swap_used, 1, 8 * 1000 * 1000, 100);
1038 SendLinearMetric("Platform.MeminfoSwapUsedPercent", swap_used_percent,
1039 100, 101);
1040 }
Luigi Semenzato8accd332011-05-17 16:37:18 -07001041 return true;
1042}
1043
Luigi Semenzato5bd764f2011-10-14 12:03:35 -07001044bool MetricsDaemon::FillMeminfo(const string& meminfo_raw,
1045 vector<MeminfoRecord>* fields) {
Luigi Semenzato8accd332011-05-17 16:37:18 -07001046 vector<string> lines;
1047 unsigned int nlines = Tokenize(meminfo_raw, "\n", &lines);
Luigi Semenzato29c7ef92011-04-12 14:12:35 -07001048
1049 // Scan meminfo output and collect field values. Each field name has to
1050 // match a meminfo entry (case insensitive) after removing non-alpha
1051 // characters from the entry.
Luigi Semenzato8accd332011-05-17 16:37:18 -07001052 unsigned int ifield = 0;
1053 for (unsigned int iline = 0;
1054 iline < nlines && ifield < fields->size();
1055 iline++) {
1056 vector<string> tokens;
Luigi Semenzato29c7ef92011-04-12 14:12:35 -07001057 Tokenize(lines[iline], ": ", &tokens);
Luigi Semenzato8accd332011-05-17 16:37:18 -07001058 if (strcmp((*fields)[ifield].match, tokens[0].c_str()) == 0) {
1059 // Name matches. Parse value and save.
Luigi Semenzato29c7ef92011-04-12 14:12:35 -07001060 char* rest;
Luigi Semenzato8accd332011-05-17 16:37:18 -07001061 (*fields)[ifield].value =
1062 static_cast<int>(strtol(tokens[1].c_str(), &rest, 10));
Luigi Semenzato29c7ef92011-04-12 14:12:35 -07001063 if (*rest != '\0') {
1064 LOG(WARNING) << "missing meminfo value";
1065 return false;
1066 }
Luigi Semenzato8accd332011-05-17 16:37:18 -07001067 ifield++;
Luigi Semenzato29c7ef92011-04-12 14:12:35 -07001068 }
Luigi Semenzato29c7ef92011-04-12 14:12:35 -07001069 }
Luigi Semenzato8accd332011-05-17 16:37:18 -07001070 if (ifield < fields->size()) {
1071 // End of input reached while scanning.
1072 LOG(WARNING) << "cannot find field " << (*fields)[ifield].match
1073 << " and following";
1074 return false;
1075 }
1076 return true;
1077}
1078
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -08001079void MetricsDaemon::ScheduleMemuseCallback(double interval) {
Luigi Semenzato8accd332011-05-17 16:37:18 -07001080 if (testing_) {
1081 return;
1082 }
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -08001083 g_timeout_add_seconds(interval, MemuseCallbackStatic, this);
Luigi Semenzato8accd332011-05-17 16:37:18 -07001084}
1085
1086// static
1087gboolean MetricsDaemon::MemuseCallbackStatic(void* handle) {
1088 MetricsDaemon* daemon = static_cast<MetricsDaemon*>(handle);
1089 daemon->MemuseCallback();
1090 return false;
1091}
1092
1093void MetricsDaemon::MemuseCallback() {
1094 // Since we only care about active time (i.e. uptime minus sleep time) but
1095 // the callbacks are driven by real time (uptime), we check if we should
1096 // reschedule this callback due to intervening sleep periods.
1097 double now = GetActiveTime();
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -08001098 // Avoid intervals of less than one second.
1099 double remaining_time = ceil(memuse_final_time_ - now);
1100 if (remaining_time > 0) {
1101 ScheduleMemuseCallback(remaining_time);
Luigi Semenzato8accd332011-05-17 16:37:18 -07001102 } else {
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -08001103 // Report stats and advance the measurement interval unless there are
1104 // errors or we've completed the last interval.
Luigi Semenzato8accd332011-05-17 16:37:18 -07001105 if (MemuseCallbackWork() &&
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -08001106 memuse_interval_index_ < arraysize(kMemuseIntervals)) {
1107 double interval = kMemuseIntervals[memuse_interval_index_++];
1108 memuse_final_time_ = now + interval;
1109 ScheduleMemuseCallback(interval);
Luigi Semenzato8accd332011-05-17 16:37:18 -07001110 }
1111 }
1112}
1113
Luigi Semenzato5bd764f2011-10-14 12:03:35 -07001114bool MetricsDaemon::MemuseCallbackWork() {
Luigi Semenzato8accd332011-05-17 16:37:18 -07001115 string meminfo_raw;
1116 const FilePath meminfo_path("/proc/meminfo");
Ben Chan2e6543d2014-02-05 23:26:25 -08001117 if (!base::ReadFileToString(meminfo_path, &meminfo_raw)) {
Luigi Semenzato8accd332011-05-17 16:37:18 -07001118 LOG(WARNING) << "cannot read " << meminfo_path.value().c_str();
1119 return false;
1120 }
1121 return ProcessMemuse(meminfo_raw);
1122}
1123
Luigi Semenzato5bd764f2011-10-14 12:03:35 -07001124bool MetricsDaemon::ProcessMemuse(const string& meminfo_raw) {
Luigi Semenzato8accd332011-05-17 16:37:18 -07001125 static const MeminfoRecord fields_array[] = {
1126 { "MemTotal", "MemTotal" }, // SPECIAL CASE: total system memory
1127 { "ActiveAnon", "Active(anon)" },
1128 { "InactiveAnon", "Inactive(anon)" },
1129 };
1130 vector<MeminfoRecord> fields(fields_array,
1131 fields_array + arraysize(fields_array));
1132 if (!FillMeminfo(meminfo_raw, &fields)) {
1133 return false;
1134 }
1135 int total = fields[0].value;
1136 int active_anon = fields[1].value;
1137 int inactive_anon = fields[2].value;
1138 if (total == 0) {
1139 // this "cannot happen"
1140 LOG(WARNING) << "borked meminfo parser";
1141 return false;
1142 }
Luigi Semenzato859b3f02014-02-05 15:33:19 -08001143 string metrics_name = base::StringPrintf("Platform.MemuseAnon%d",
1144 memuse_interval_index_);
Luigi Semenzato8accd332011-05-17 16:37:18 -07001145 SendLinearMetric(metrics_name, (active_anon + inactive_anon) * 100 / total,
1146 100, 101);
1147 return true;
Luigi Semenzato29c7ef92011-04-12 14:12:35 -07001148}
1149
Darin Petkovf1e85e42010-06-10 15:59:53 -07001150// static
Luigi Semenzato859b3f02014-02-05 15:33:19 -08001151void MetricsDaemon::ReportDailyUse(void* handle, int count) {
Darin Petkov1bb904e2010-06-16 15:58:06 -07001152 if (count <= 0)
1153 return;
1154
Darin Petkovf1e85e42010-06-10 15:59:53 -07001155 MetricsDaemon* daemon = static_cast<MetricsDaemon*>(handle);
1156 int minutes = (count + kSecondsPerMinute / 2) / kSecondsPerMinute;
1157 daemon->SendMetric(kMetricDailyUseTimeName, minutes,
1158 kMetricDailyUseTimeMin,
1159 kMetricDailyUseTimeMax,
1160 kMetricDailyUseTimeBuckets);
1161}
1162
Darin Petkov38d5cb02010-06-24 12:10:26 -07001163void MetricsDaemon::SendMetric(const string& name, int sample,
Darin Petkov11b8eb32010-05-18 11:00:59 -07001164 int min, int max, int nbuckets) {
Darin Petkovfc91b422010-05-12 13:05:45 -07001165 DLOG(INFO) << "received metric: " << name << " " << sample << " "
1166 << min << " " << max << " " << nbuckets;
1167 metrics_lib_->SendToUMA(name, sample, min, max, nbuckets);
Darin Petkov65b01462010-04-14 13:32:20 -07001168}
Luigi Semenzato29c7ef92011-04-12 14:12:35 -07001169
1170void MetricsDaemon::SendLinearMetric(const string& name, int sample,
1171 int max, int nbuckets) {
1172 DLOG(INFO) << "received linear metric: " << name << " " << sample << " "
1173 << max << " " << nbuckets;
1174 // TODO(semenzato): add a proper linear histogram to the Chrome external
1175 // metrics API.
1176 LOG_IF(FATAL, nbuckets != max + 1) << "unsupported histogram scale";
1177 metrics_lib_->SendEnumToUMA(name, sample, max);
1178}