blob: f3849eeefba9137e436be20fc9bcf5c8af4f4d45 [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
Darin Petkov38d5cb02010-06-24 12:10:26 -070012#include <base/file_util.h>
Darin Petkov65b01462010-04-14 13:32:20 -070013#include <base/logging.h>
Luigi Semenzatofb3a8212013-05-07 16:55:00 -070014#include <base/string_number_conversions.h>
Luigi Semenzato29c7ef92011-04-12 14:12:35 -070015#include <base/string_util.h>
Sonny Rao4b8aebb2013-07-31 23:18:31 -070016#include <base/string_split.h>
Mike Frysinger71ebf982012-03-07 10:35:29 -050017#include <base/stringprintf.h>
Darin Petkov40f25732013-04-29 15:07:31 +020018#include <chromeos/dbus/service_constants.h>
Ken Mixter4c5daa42010-08-26 18:35:06 -070019#include <dbus/dbus-glib-lowlevel.h>
Darin Petkov65b01462010-04-14 13:32:20 -070020
Darin Petkovf1e85e42010-06-10 15:59:53 -070021#include "counter.h"
22
Darin Petkovf27f0362010-06-04 13:14:19 -070023using base::Time;
24using base::TimeDelta;
25using base::TimeTicks;
Luigi Semenzato8accd332011-05-17 16:37:18 -070026using std::map;
Darin Petkov38d5cb02010-06-24 12:10:26 -070027using std::string;
Luigi Semenzato8accd332011-05-17 16:37:18 -070028using std::vector;
29
Darin Petkovf27f0362010-06-04 13:14:19 -070030
Darin Petkov703ec972010-04-27 11:02:18 -070031#define SAFE_MESSAGE(e) (e.message ? e.message : "unknown error")
Darin Petkov40f25732013-04-29 15:07:31 +020032
33static const char kCrashReporterInterface[] = "org.chromium.CrashReporter";
34static const char kCrashReporterUserCrashSignal[] = "UserCrash";
Darin Petkov41e06232010-05-03 16:45:37 -070035
Darin Petkov41e06232010-05-03 16:45:37 -070036static const int kSecondsPerMinute = 60;
37static const int kMinutesPerHour = 60;
38static const int kHoursPerDay = 24;
39static const int kMinutesPerDay = kHoursPerDay * kMinutesPerHour;
Darin Petkov1bb904e2010-06-16 15:58:06 -070040static const int kSecondsPerDay = kSecondsPerMinute * kMinutesPerDay;
41static const int kDaysPerWeek = 7;
42static const int kSecondsPerWeek = kSecondsPerDay * kDaysPerWeek;
Darin Petkov41e06232010-05-03 16:45:37 -070043
44// The daily use monitor is scheduled to a 1-minute interval after
45// initial user activity and then it's exponentially backed off to
46// 10-minute intervals. Although not required, the back off is
47// implemented because the histogram buckets are spaced exponentially
48// anyway and to avoid too frequent metrics daemon process wake-ups
49// and file I/O.
50static const int kUseMonitorIntervalInit = 1 * kSecondsPerMinute;
51static const int kUseMonitorIntervalMax = 10 * kSecondsPerMinute;
Darin Petkov65b01462010-04-14 13:32:20 -070052
Ken Mixterccd84c02010-08-16 19:57:13 -070053const char kKernelCrashDetectedFile[] = "/tmp/kernel-crash-detected";
54static const char kUncleanShutdownDetectedFile[] =
55 "/tmp/unclean-shutdown-detected";
56
Ken Mixter4c5daa42010-08-26 18:35:06 -070057// static metrics parameters
Darin Petkov2ccef012010-05-05 16:06:37 -070058const char MetricsDaemon::kMetricDailyUseTimeName[] =
59 "Logging.DailyUseTime";
60const int MetricsDaemon::kMetricDailyUseTimeMin = 1;
61const int MetricsDaemon::kMetricDailyUseTimeMax = kMinutesPerDay;
62const int MetricsDaemon::kMetricDailyUseTimeBuckets = 50;
63
Ken Mixterccd84c02010-08-16 19:57:13 -070064// crash interval metrics
65const char MetricsDaemon::kMetricKernelCrashIntervalName[] =
66 "Logging.KernelCrashInterval";
67const char MetricsDaemon::kMetricUncleanShutdownIntervalName[] =
68 "Logging.UncleanShutdownInterval";
Darin Petkov1bb904e2010-06-16 15:58:06 -070069const char MetricsDaemon::kMetricUserCrashIntervalName[] =
70 "Logging.UserCrashInterval";
Ken Mixterccd84c02010-08-16 19:57:13 -070071
72const int MetricsDaemon::kMetricCrashIntervalMin = 1;
73const int MetricsDaemon::kMetricCrashIntervalMax =
74 4 * kSecondsPerWeek;
75const int MetricsDaemon::kMetricCrashIntervalBuckets = 50;
76
77// crash frequency metrics
78const char MetricsDaemon::kMetricAnyCrashesDailyName[] =
79 "Logging.AnyCrashesDaily";
Ken Mixter4c5daa42010-08-26 18:35:06 -070080const char MetricsDaemon::kMetricAnyCrashesWeeklyName[] =
81 "Logging.AnyCrashesWeekly";
Ken Mixterccd84c02010-08-16 19:57:13 -070082const char MetricsDaemon::kMetricKernelCrashesDailyName[] =
83 "Logging.KernelCrashesDaily";
Ken Mixter4c5daa42010-08-26 18:35:06 -070084const char MetricsDaemon::kMetricKernelCrashesWeeklyName[] =
85 "Logging.KernelCrashesWeekly";
Ken Mixterccd84c02010-08-16 19:57:13 -070086const char MetricsDaemon::kMetricUncleanShutdownsDailyName[] =
87 "Logging.UncleanShutdownsDaily";
Ken Mixter4c5daa42010-08-26 18:35:06 -070088const char MetricsDaemon::kMetricUncleanShutdownsWeeklyName[] =
89 "Logging.UncleanShutdownsWeekly";
Ken Mixterccd84c02010-08-16 19:57:13 -070090const char MetricsDaemon::kMetricUserCrashesDailyName[] =
91 "Logging.UserCrashesDaily";
Ken Mixter4c5daa42010-08-26 18:35:06 -070092const char MetricsDaemon::kMetricUserCrashesWeeklyName[] =
93 "Logging.UserCrashesWeekly";
94const char MetricsDaemon::kMetricCrashFrequencyMin = 1;
95const char MetricsDaemon::kMetricCrashFrequencyMax = 100;
96const char MetricsDaemon::kMetricCrashFrequencyBuckets = 50;
Ken Mixterccd84c02010-08-16 19:57:13 -070097
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -080098// disk stats metrics
99
100// The {Read,Write}Sectors numbers are in sectors/second.
101// A sector is usually 512 bytes.
102
103const char MetricsDaemon::kMetricReadSectorsLongName[] =
104 "Platform.ReadSectorsLong";
105const char MetricsDaemon::kMetricWriteSectorsLongName[] =
106 "Platform.WriteSectorsLong";
107const char MetricsDaemon::kMetricReadSectorsShortName[] =
108 "Platform.ReadSectorsShort";
109const char MetricsDaemon::kMetricWriteSectorsShortName[] =
110 "Platform.WriteSectorsShort";
111
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700112const int MetricsDaemon::kMetricStatsShortInterval = 1; // seconds
113const int MetricsDaemon::kMetricStatsLongInterval = 30; // seconds
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800114
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700115const int MetricsDaemon::kMetricMeminfoInterval = 30; // seconds
116
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800117// Assume a max rate of 250Mb/s for reads (worse for writes) and 512 byte
118// sectors.
119const int MetricsDaemon::kMetricSectorsIOMax = 500000; // sectors/second
120const int MetricsDaemon::kMetricSectorsBuckets = 50; // buckets
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700121// Page size is 4k, sector size is 0.5k. We're not interested in page fault
122// rates that the disk cannot sustain.
123const int MetricsDaemon::kMetricPageFaultsMax = kMetricSectorsIOMax / 8;
124const int MetricsDaemon::kMetricPageFaultsBuckets = 50;
125
126// Major page faults, i.e. the ones that require data to be read from disk.
127
128const char MetricsDaemon::kMetricPageFaultsLongName[] =
129 "Platform.PageFaultsLong";
130const char MetricsDaemon::kMetricPageFaultsShortName[] =
131 "Platform.PageFaultsShort";
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800132
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700133// Swap in and Swap out
134
135const char MetricsDaemon::kMetricSwapInLongName[] =
136 "Platform.SwapInLong";
137const char MetricsDaemon::kMetricSwapInShortName[] =
138 "Platform.SwapInShort";
139
140const char MetricsDaemon::kMetricSwapOutLongName[] =
141 "Platform.SwapOutLong";
142const char MetricsDaemon::kMetricSwapOutShortName[] =
143 "Platform.SwapOutShort";
144
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700145// Thermal CPU throttling.
146
147const char MetricsDaemon::kMetricScaledCpuFrequencyName[] =
148 "Platform.CpuFrequencyThermalScaling";
149
Ken Mixter4c5daa42010-08-26 18:35:06 -0700150// persistent metrics path
151const char MetricsDaemon::kMetricsPath[] = "/var/log/metrics";
Ken Mixterccd84c02010-08-16 19:57:13 -0700152
Darin Petkov703ec972010-04-27 11:02:18 -0700153// static
Darin Petkov41e06232010-05-03 16:45:37 -0700154const char* MetricsDaemon::kPowerStates_[] = {
Darin Petkov703ec972010-04-27 11:02:18 -0700155#define STATE(name, capname) #name,
156#include "power_states.h"
157};
158
Darin Petkov41e06232010-05-03 16:45:37 -0700159// static
Darin Petkov41e06232010-05-03 16:45:37 -0700160const char* MetricsDaemon::kSessionStates_[] = {
161#define STATE(name, capname) #name,
162#include "session_states.h"
163};
164
Luigi Semenzato8accd332011-05-17 16:37:18 -0700165// Memory use stats collection intervals. We collect some memory use interval
166// at these intervals after boot, and we stop collecting after the last one,
167// with the assumption that in most cases the memory use won't change much
168// after that.
169static const int kMemuseIntervals[] = {
170 1 * kSecondsPerMinute, // 1 minute mark
171 4 * kSecondsPerMinute, // 5 minute mark
172 25 * kSecondsPerMinute, // 0.5 hour mark
173 120 * kSecondsPerMinute, // 2.5 hour mark
174 600 * kSecondsPerMinute, // 12.5 hour mark
175};
176
Darin Petkovf1e85e42010-06-10 15:59:53 -0700177MetricsDaemon::MetricsDaemon()
Sam Leffler239b8262010-08-30 08:56:58 -0700178 : power_state_(kUnknownPowerState),
Darin Petkovf1e85e42010-06-10 15:59:53 -0700179 session_state_(kUnknownSessionState),
180 user_active_(false),
181 usemon_interval_(0),
Luigi Semenzato8accd332011-05-17 16:37:18 -0700182 usemon_source_(NULL),
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -0800183 memuse_final_time_(0),
Luigi Semenzato8accd332011-05-17 16:37:18 -0700184 memuse_interval_index_(0),
185 read_sectors_(0),
186 write_sectors_(0),
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700187 vmstats_(),
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700188 stats_state_(kStatsShort),
189 stats_initial_time_(0) {}
Darin Petkovf1e85e42010-06-10 15:59:53 -0700190
Ken Mixter4c5daa42010-08-26 18:35:06 -0700191MetricsDaemon::~MetricsDaemon() {
192 DeleteFrequencyCounters();
193}
194
Luigi Semenzato8accd332011-05-17 16:37:18 -0700195double MetricsDaemon::GetActiveTime() {
196 struct timespec ts;
197 int r = clock_gettime(CLOCK_MONOTONIC, &ts);
198 if (r < 0) {
199 PLOG(WARNING) << "clock_gettime(CLOCK_MONOTONIC) failed";
200 return 0;
201 } else {
202 return ts.tv_sec + ((double) ts.tv_nsec) / (1000 * 1000 * 1000);
203 }
204}
205
Ken Mixter4c5daa42010-08-26 18:35:06 -0700206void MetricsDaemon::DeleteFrequencyCounters() {
207 for (FrequencyCounters::iterator i = frequency_counters_.begin();
208 i != frequency_counters_.end(); ++i) {
209 delete i->second;
210 i->second = NULL;
211 }
212}
Darin Petkovf1e85e42010-06-10 15:59:53 -0700213
Darin Petkov2ccef012010-05-05 16:06:37 -0700214void MetricsDaemon::Run(bool run_as_daemon) {
Darin Petkov38d5cb02010-06-24 12:10:26 -0700215 if (run_as_daemon && daemon(0, 0) != 0)
216 return;
217
Ken Mixterccd84c02010-08-16 19:57:13 -0700218 if (CheckSystemCrash(kKernelCrashDetectedFile)) {
219 ProcessKernelCrash();
220 }
221
222 if (CheckSystemCrash(kUncleanShutdownDetectedFile)) {
223 ProcessUncleanShutdown();
224 }
225
Darin Petkov38d5cb02010-06-24 12:10:26 -0700226 Loop();
Darin Petkov65b01462010-04-14 13:32:20 -0700227}
228
Ken Mixter4c5daa42010-08-26 18:35:06 -0700229FilePath MetricsDaemon::GetHistogramPath(const char* histogram_name) {
230 return FilePath(kMetricsPath).Append(histogram_name);
231}
232
233void MetricsDaemon::ConfigureCrashIntervalReporter(
234 const char* histogram_name,
235 scoped_ptr<chromeos_metrics::TaggedCounterReporter>* reporter) {
236 reporter->reset(new chromeos_metrics::TaggedCounterReporter());
237 FilePath file_path = GetHistogramPath(histogram_name);
238 (*reporter)->Init(file_path.value().c_str(),
239 histogram_name,
240 kMetricCrashIntervalMin,
241 kMetricCrashIntervalMax,
242 kMetricCrashIntervalBuckets);
243}
244
245void MetricsDaemon::ConfigureCrashFrequencyReporter(
246 const char* histogram_name) {
247 scoped_ptr<chromeos_metrics::TaggedCounterReporter> reporter(
248 new chromeos_metrics::TaggedCounterReporter());
249 FilePath file_path = GetHistogramPath(histogram_name);
250 reporter->Init(file_path.value().c_str(),
251 histogram_name,
252 kMetricCrashFrequencyMin,
253 kMetricCrashFrequencyMax,
254 kMetricCrashFrequencyBuckets);
255 scoped_ptr<chromeos_metrics::FrequencyCounter> new_counter(
256 new chromeos_metrics::FrequencyCounter());
257 time_t cycle_duration = strstr(histogram_name, "Weekly") != NULL ?
258 chromeos_metrics::kSecondsPerWeek :
259 chromeos_metrics::kSecondsPerDay;
260 new_counter->Init(
261 static_cast<chromeos_metrics::TaggedCounterInterface*>(
262 reporter.release()),
263 cycle_duration);
264 frequency_counters_[histogram_name] = new_counter.release();
265}
266
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800267void MetricsDaemon::Init(bool testing, MetricsLibraryInterface* metrics_lib,
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700268 const string& diskstats_path,
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700269 const string& vmstats_path,
270 const string& scaling_max_freq_path,
271 const string& cpuinfo_max_freq_path
272 ) {
Darin Petkov65b01462010-04-14 13:32:20 -0700273 testing_ = testing;
Darin Petkovfc91b422010-05-12 13:05:45 -0700274 DCHECK(metrics_lib != NULL);
275 metrics_lib_ = metrics_lib;
Ken Mixter4c5daa42010-08-26 18:35:06 -0700276 chromeos_metrics::TaggedCounterReporter::
277 SetMetricsLibraryInterface(metrics_lib);
Darin Petkov38d5cb02010-06-24 12:10:26 -0700278
279 static const char kDailyUseRecordFile[] = "/var/log/metrics/daily-usage";
Darin Petkovf1e85e42010-06-10 15:59:53 -0700280 daily_use_.reset(new chromeos_metrics::TaggedCounter());
Ken Mixterccd84c02010-08-16 19:57:13 -0700281 daily_use_->Init(kDailyUseRecordFile, &ReportDailyUse, this);
Darin Petkov38d5cb02010-06-24 12:10:26 -0700282
Ken Mixter4c5daa42010-08-26 18:35:06 -0700283 ConfigureCrashIntervalReporter(kMetricKernelCrashIntervalName,
284 &kernel_crash_interval_);
285 ConfigureCrashIntervalReporter(kMetricUncleanShutdownIntervalName,
286 &unclean_shutdown_interval_);
287 ConfigureCrashIntervalReporter(kMetricUserCrashIntervalName,
288 &user_crash_interval_);
Darin Petkov2ccef012010-05-05 16:06:37 -0700289
Ken Mixter4c5daa42010-08-26 18:35:06 -0700290 DeleteFrequencyCounters();
291 ConfigureCrashFrequencyReporter(kMetricAnyCrashesDailyName);
Ken Mixter4c5daa42010-08-26 18:35:06 -0700292 ConfigureCrashFrequencyReporter(kMetricAnyCrashesWeeklyName);
293 ConfigureCrashFrequencyReporter(kMetricKernelCrashesDailyName);
294 ConfigureCrashFrequencyReporter(kMetricKernelCrashesWeeklyName);
295 ConfigureCrashFrequencyReporter(kMetricUncleanShutdownsDailyName);
296 ConfigureCrashFrequencyReporter(kMetricUncleanShutdownsWeeklyName);
297 ConfigureCrashFrequencyReporter(kMetricUserCrashesDailyName);
298 ConfigureCrashFrequencyReporter(kMetricUserCrashesWeeklyName);
Darin Petkov38d5cb02010-06-24 12:10:26 -0700299
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700300 diskstats_path_ = diskstats_path;
301 vmstats_path_ = vmstats_path;
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700302 scaling_max_freq_path_ = scaling_max_freq_path;
303 cpuinfo_max_freq_path_ = cpuinfo_max_freq_path;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700304 StatsReporterInit();
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800305
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700306 // Start collecting meminfo stats.
307 ScheduleMeminfoCallback(kMetricMeminfoInterval);
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -0800308 memuse_final_time_ = GetActiveTime() + kMemuseIntervals[0];
309 ScheduleMemuseCallback(kMemuseIntervals[0]);
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700310
Darin Petkov2ccef012010-05-05 16:06:37 -0700311 // Don't setup D-Bus and GLib in test mode.
312 if (testing)
313 return;
Darin Petkov65b01462010-04-14 13:32:20 -0700314
Darin Petkov703ec972010-04-27 11:02:18 -0700315 g_type_init();
Ben Chan6f598422013-06-22 06:29:36 -0700316 dbus_threads_init_default();
Darin Petkov65b01462010-04-14 13:32:20 -0700317
Darin Petkov703ec972010-04-27 11:02:18 -0700318 DBusError error;
319 dbus_error_init(&error);
Darin Petkov65b01462010-04-14 13:32:20 -0700320
David James3b3add52010-06-04 15:01:19 -0700321 DBusConnection* connection = dbus_bus_get(DBUS_BUS_SYSTEM, &error);
Darin Petkov703ec972010-04-27 11:02:18 -0700322 LOG_IF(FATAL, dbus_error_is_set(&error)) <<
323 "No D-Bus connection: " << SAFE_MESSAGE(error);
Darin Petkov65b01462010-04-14 13:32:20 -0700324
Darin Petkov703ec972010-04-27 11:02:18 -0700325 dbus_connection_setup_with_g_main(connection, NULL);
Darin Petkov65b01462010-04-14 13:32:20 -0700326
Darin Petkov40f25732013-04-29 15:07:31 +0200327 vector<string> matches;
328 matches.push_back(
329 StringPrintf("type='signal',interface='%s',path='/',member='%s'",
330 kCrashReporterInterface,
331 kCrashReporterUserCrashSignal));
332 matches.push_back(
333 StringPrintf("type='signal',interface='%s',path='%s',member='%s'",
334 power_manager::kPowerManagerInterface,
335 power_manager::kPowerManagerServicePath,
336 power_manager::kPowerStateChangedSignal));
337 matches.push_back(
338 StringPrintf("type='signal',sender='%s',interface='%s',path='%s'",
339 login_manager::kSessionManagerServiceName,
340 login_manager::kSessionManagerInterface,
341 login_manager::kSessionManagerServicePath));
342
Darin Petkov703ec972010-04-27 11:02:18 -0700343 // Registers D-Bus matches for the signals we would like to catch.
Darin Petkov40f25732013-04-29 15:07:31 +0200344 for (vector<string>::const_iterator it = matches.begin();
345 it != matches.end(); ++it) {
346 const char* match = it->c_str();
Darin Petkov41e06232010-05-03 16:45:37 -0700347 DLOG(INFO) << "adding dbus match: " << match;
Darin Petkov703ec972010-04-27 11:02:18 -0700348 dbus_bus_add_match(connection, match, &error);
349 LOG_IF(FATAL, dbus_error_is_set(&error)) <<
350 "unable to add a match: " << SAFE_MESSAGE(error);
351 }
352
353 // Adds the D-Bus filter routine to be called back whenever one of
354 // the registered D-Bus matches is successful. The daemon is not
355 // activated for D-Bus messages that don't match.
356 CHECK(dbus_connection_add_filter(connection, MessageFilter, this, NULL));
Darin Petkov65b01462010-04-14 13:32:20 -0700357}
358
359void MetricsDaemon::Loop() {
Darin Petkov703ec972010-04-27 11:02:18 -0700360 GMainLoop* loop = g_main_loop_new(NULL, false);
361 g_main_loop_run(loop);
Darin Petkov65b01462010-04-14 13:32:20 -0700362}
363
Darin Petkov703ec972010-04-27 11:02:18 -0700364// static
365DBusHandlerResult MetricsDaemon::MessageFilter(DBusConnection* connection,
366 DBusMessage* message,
367 void* user_data) {
Darin Petkovf27f0362010-06-04 13:14:19 -0700368 Time now = Time::Now();
Darin Petkovf27f0362010-06-04 13:14:19 -0700369 DLOG(INFO) << "message intercepted @ " << now.ToInternalValue();
Darin Petkov703ec972010-04-27 11:02:18 -0700370
371 int message_type = dbus_message_get_type(message);
372 if (message_type != DBUS_MESSAGE_TYPE_SIGNAL) {
Darin Petkov41e06232010-05-03 16:45:37 -0700373 DLOG(WARNING) << "unexpected message type " << message_type;
Darin Petkov703ec972010-04-27 11:02:18 -0700374 return DBUS_HANDLER_RESULT_NOT_YET_HANDLED;
375 }
376
377 // Signal messages always have interfaces.
378 const char* interface = dbus_message_get_interface(message);
379 CHECK(interface != NULL);
380
381 MetricsDaemon* daemon = static_cast<MetricsDaemon*>(user_data);
382
383 DBusMessageIter iter;
384 dbus_message_iter_init(message, &iter);
Darin Petkov40f25732013-04-29 15:07:31 +0200385 if (strcmp(interface, kCrashReporterInterface) == 0) {
Darin Petkov1bb904e2010-06-16 15:58:06 -0700386 CHECK(strcmp(dbus_message_get_member(message),
Darin Petkov40f25732013-04-29 15:07:31 +0200387 kCrashReporterUserCrashSignal) == 0);
Darin Petkov1bb904e2010-06-16 15:58:06 -0700388 daemon->ProcessUserCrash();
Darin Petkov40f25732013-04-29 15:07:31 +0200389 } else if (strcmp(interface, power_manager::kPowerManagerInterface) == 0) {
Darin Petkov41e06232010-05-03 16:45:37 -0700390 CHECK(strcmp(dbus_message_get_member(message),
Darin Petkov40f25732013-04-29 15:07:31 +0200391 power_manager::kPowerStateChangedSignal) == 0);
David James3b3add52010-06-04 15:01:19 -0700392 char* state_name;
Darin Petkov41e06232010-05-03 16:45:37 -0700393 dbus_message_iter_get_basic(&iter, &state_name);
Darin Petkov40f25732013-04-29 15:07:31 +0200394 daemon->PowerStateChanged(state_name, now);
395 } else if (strcmp(interface, login_manager::kSessionManagerInterface) == 0) {
396 const char* member = dbus_message_get_member(message);
397 if (strcmp(member, login_manager::kScreenIsLockedSignal) == 0) {
398 daemon->SetUserActiveState(false, now);
399 } else if (strcmp(member, login_manager::kScreenIsUnlockedSignal) == 0) {
400 daemon->SetUserActiveState(true, now);
401 } else if (strcmp(member, login_manager::kSessionStateChangedSignal) == 0) {
402 char* state_name;
403 dbus_message_iter_get_basic(&iter, &state_name);
404 daemon->SessionStateChanged(state_name, now);
405 }
Darin Petkov703ec972010-04-27 11:02:18 -0700406 } else {
Darin Petkov41e06232010-05-03 16:45:37 -0700407 DLOG(WARNING) << "unexpected interface: " << interface;
Darin Petkov703ec972010-04-27 11:02:18 -0700408 return DBUS_HANDLER_RESULT_NOT_YET_HANDLED;
409 }
410
411 return DBUS_HANDLER_RESULT_HANDLED;
Darin Petkov65b01462010-04-14 13:32:20 -0700412}
413
Darin Petkovf27f0362010-06-04 13:14:19 -0700414void MetricsDaemon::PowerStateChanged(const char* state_name, Time now) {
Darin Petkov41e06232010-05-03 16:45:37 -0700415 DLOG(INFO) << "power state: " << state_name;
Darin Petkov703ec972010-04-27 11:02:18 -0700416 power_state_ = LookupPowerState(state_name);
Darin Petkov41e06232010-05-03 16:45:37 -0700417
418 if (power_state_ != kPowerStateOn)
419 SetUserActiveState(false, now);
Darin Petkov703ec972010-04-27 11:02:18 -0700420}
421
422MetricsDaemon::PowerState
423MetricsDaemon::LookupPowerState(const char* state_name) {
424 for (int i = 0; i < kNumberPowerStates; i++) {
Darin Petkov41e06232010-05-03 16:45:37 -0700425 if (strcmp(state_name, kPowerStates_[i]) == 0) {
Darin Petkov703ec972010-04-27 11:02:18 -0700426 return static_cast<PowerState>(i);
427 }
428 }
Darin Petkov41e06232010-05-03 16:45:37 -0700429 DLOG(WARNING) << "unknown power state: " << state_name;
Darin Petkov703ec972010-04-27 11:02:18 -0700430 return kUnknownPowerState;
Darin Petkov65b01462010-04-14 13:32:20 -0700431}
432
Darin Petkovf27f0362010-06-04 13:14:19 -0700433void MetricsDaemon::SessionStateChanged(const char* state_name, Time now) {
Darin Petkov41e06232010-05-03 16:45:37 -0700434 DLOG(INFO) << "user session state: " << state_name;
435 session_state_ = LookupSessionState(state_name);
436 SetUserActiveState(session_state_ == kSessionStateStarted, now);
437}
438
439MetricsDaemon::SessionState
440MetricsDaemon::LookupSessionState(const char* state_name) {
441 for (int i = 0; i < kNumberSessionStates; i++) {
442 if (strcmp(state_name, kSessionStates_[i]) == 0) {
443 return static_cast<SessionState>(i);
444 }
445 }
446 DLOG(WARNING) << "unknown user session state: " << state_name;
447 return kUnknownSessionState;
448}
449
Darin Petkovf27f0362010-06-04 13:14:19 -0700450void MetricsDaemon::SetUserActiveState(bool active, Time now) {
Darin Petkov41e06232010-05-03 16:45:37 -0700451 DLOG(INFO) << "user: " << (active ? "active" : "inactive");
452
453 // Calculates the seconds of active use since the last update and
Darin Petkovf27f0362010-06-04 13:14:19 -0700454 // the day since Epoch, and logs the usage data. Guards against the
455 // time jumping back and forth due to the user changing it by
456 // discarding the new use time.
457 int seconds = 0;
458 if (user_active_ && now > user_active_last_) {
459 TimeDelta since_active = now - user_active_last_;
460 if (since_active < TimeDelta::FromSeconds(
461 kUseMonitorIntervalMax + kSecondsPerMinute)) {
462 seconds = static_cast<int>(since_active.InSeconds());
463 }
464 }
465 TimeDelta since_epoch = now - Time();
466 int day = since_epoch.InDays();
Darin Petkovf1e85e42010-06-10 15:59:53 -0700467 daily_use_->Update(day, seconds);
Darin Petkov1bb904e2010-06-16 15:58:06 -0700468 user_crash_interval_->Update(0, seconds);
Darin Petkov38d5cb02010-06-24 12:10:26 -0700469 kernel_crash_interval_->Update(0, seconds);
Darin Petkov41e06232010-05-03 16:45:37 -0700470
Ken Mixter4c5daa42010-08-26 18:35:06 -0700471 // Flush finished cycles of all frequency counters.
472 for (FrequencyCounters::iterator i = frequency_counters_.begin();
473 i != frequency_counters_.end(); ++i) {
474 i->second->FlushFinishedCycles();
475 }
476
Darin Petkov41e06232010-05-03 16:45:37 -0700477 // Schedules a use monitor on inactive->active transitions and
478 // unschedules it on active->inactive transitions.
479 if (!user_active_ && active)
480 ScheduleUseMonitor(kUseMonitorIntervalInit, /* backoff */ false);
481 else if (user_active_ && !active)
482 UnscheduleUseMonitor();
483
484 // Remembers the current active state and the time of the last
485 // activity update.
486 user_active_ = active;
487 user_active_last_ = now;
488}
489
Darin Petkov1bb904e2010-06-16 15:58:06 -0700490void MetricsDaemon::ProcessUserCrash() {
491 // Counts the active use time up to now.
492 SetUserActiveState(user_active_, Time::Now());
493
494 // Reports the active use time since the last crash and resets it.
495 user_crash_interval_->Flush();
Ken Mixterccd84c02010-08-16 19:57:13 -0700496
Ken Mixter4c5daa42010-08-26 18:35:06 -0700497 frequency_counters_[kMetricUserCrashesDailyName]->Update(1);
498 frequency_counters_[kMetricUserCrashesWeeklyName]->Update(1);
499 frequency_counters_[kMetricAnyCrashesDailyName]->Update(1);
500 frequency_counters_[kMetricAnyCrashesWeeklyName]->Update(1);
Darin Petkov1bb904e2010-06-16 15:58:06 -0700501}
502
Darin Petkov38d5cb02010-06-24 12:10:26 -0700503void MetricsDaemon::ProcessKernelCrash() {
504 // Counts the active use time up to now.
505 SetUserActiveState(user_active_, Time::Now());
506
507 // Reports the active use time since the last crash and resets it.
508 kernel_crash_interval_->Flush();
Ken Mixterccd84c02010-08-16 19:57:13 -0700509
Ken Mixter4c5daa42010-08-26 18:35:06 -0700510 frequency_counters_[kMetricKernelCrashesDailyName]->Update(1);
511 frequency_counters_[kMetricKernelCrashesWeeklyName]->Update(1);
512 frequency_counters_[kMetricAnyCrashesDailyName]->Update(1);
513 frequency_counters_[kMetricAnyCrashesWeeklyName]->Update(1);
Darin Petkov38d5cb02010-06-24 12:10:26 -0700514}
515
Ken Mixterccd84c02010-08-16 19:57:13 -0700516void MetricsDaemon::ProcessUncleanShutdown() {
517 // Counts the active use time up to now.
518 SetUserActiveState(user_active_, Time::Now());
519
520 // Reports the active use time since the last crash and resets it.
521 unclean_shutdown_interval_->Flush();
522
Ken Mixter4c5daa42010-08-26 18:35:06 -0700523 frequency_counters_[kMetricUncleanShutdownsDailyName]->Update(1);
524 frequency_counters_[kMetricUncleanShutdownsWeeklyName]->Update(1);
525 frequency_counters_[kMetricAnyCrashesDailyName]->Update(1);
526 frequency_counters_[kMetricAnyCrashesWeeklyName]->Update(1);
Ken Mixterccd84c02010-08-16 19:57:13 -0700527}
528
Luigi Semenzato8accd332011-05-17 16:37:18 -0700529bool MetricsDaemon::CheckSystemCrash(const string& crash_file) {
Darin Petkov38d5cb02010-06-24 12:10:26 -0700530 FilePath crash_detected(crash_file);
531 if (!file_util::PathExists(crash_detected))
Ken Mixterccd84c02010-08-16 19:57:13 -0700532 return false;
Darin Petkov38d5cb02010-06-24 12:10:26 -0700533
534 // Deletes the crash-detected file so that the daemon doesn't report
535 // another kernel crash in case it's restarted.
536 file_util::Delete(crash_detected,
537 false); // recursive
Ken Mixterccd84c02010-08-16 19:57:13 -0700538 return true;
Darin Petkov38d5cb02010-06-24 12:10:26 -0700539}
540
Darin Petkov41e06232010-05-03 16:45:37 -0700541// static
542gboolean MetricsDaemon::UseMonitorStatic(gpointer data) {
543 return static_cast<MetricsDaemon*>(data)->UseMonitor() ? TRUE : FALSE;
544}
545
546bool MetricsDaemon::UseMonitor() {
Darin Petkovf27f0362010-06-04 13:14:19 -0700547 SetUserActiveState(user_active_, Time::Now());
Darin Petkov41e06232010-05-03 16:45:37 -0700548
549 // If a new monitor source/instance is scheduled, returns false to
550 // tell GLib to destroy this monitor source/instance. Returns true
551 // otherwise to keep calling back this monitor.
552 return !ScheduleUseMonitor(usemon_interval_ * 2, /* backoff */ true);
553}
554
555bool MetricsDaemon::ScheduleUseMonitor(int interval, bool backoff)
556{
Darin Petkov2ccef012010-05-05 16:06:37 -0700557 if (testing_)
558 return false;
559
Darin Petkov41e06232010-05-03 16:45:37 -0700560 // Caps the interval -- the bigger the interval, the more active use
561 // time will be potentially dropped on system shutdown.
562 if (interval > kUseMonitorIntervalMax)
563 interval = kUseMonitorIntervalMax;
564
565 if (backoff) {
566 // Back-off mode is used by the use monitor to reschedule itself
567 // with exponential back-off in time. This mode doesn't create a
568 // new timeout source if the new interval is the same as the old
569 // one. Also, if a new timeout source is created, the old one is
570 // not destroyed explicitly here -- it will be destroyed by GLib
571 // when the monitor returns FALSE (see UseMonitor and
572 // UseMonitorStatic).
573 if (interval == usemon_interval_)
574 return false;
575 } else {
576 UnscheduleUseMonitor();
577 }
578
579 // Schedules a new use monitor for |interval| seconds from now.
580 DLOG(INFO) << "scheduling use monitor in " << interval << " seconds";
581 usemon_source_ = g_timeout_source_new_seconds(interval);
582 g_source_set_callback(usemon_source_, UseMonitorStatic, this,
583 NULL); // No destroy notification.
584 g_source_attach(usemon_source_,
585 NULL); // Default context.
586 usemon_interval_ = interval;
587 return true;
588}
589
590void MetricsDaemon::UnscheduleUseMonitor() {
591 // If there's a use monitor scheduled already, destroys it.
592 if (usemon_source_ == NULL)
593 return;
594
595 DLOG(INFO) << "destroying use monitor";
596 g_source_destroy(usemon_source_);
597 usemon_source_ = NULL;
598 usemon_interval_ = 0;
599}
600
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700601void MetricsDaemon::StatsReporterInit() {
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800602 DiskStatsReadStats(&read_sectors_, &write_sectors_);
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700603 VmStatsReadStats(&vmstats_);
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800604 // The first time around just run the long stat, so we don't delay boot.
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700605 stats_state_ = kStatsLong;
606 stats_initial_time_ = GetActiveTime();
607 if (stats_initial_time_ < 0) {
Luigi Semenzato8accd332011-05-17 16:37:18 -0700608 LOG(WARNING) << "not collecting disk stats";
609 } else {
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700610 ScheduleStatsCallback(kMetricStatsLongInterval);
Luigi Semenzato8accd332011-05-17 16:37:18 -0700611 }
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800612}
613
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700614void MetricsDaemon::ScheduleStatsCallback(int wait) {
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800615 if (testing_) {
616 return;
617 }
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700618 g_timeout_add_seconds(wait, StatsCallbackStatic, this);
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800619}
620
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700621bool MetricsDaemon::DiskStatsReadStats(long int* read_sectors,
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800622 long int* write_sectors) {
623 int nchars;
624 int nitems;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700625 bool success = false;
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800626 char line[200];
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700627 if (diskstats_path_.empty()) {
628 return false;
629 }
Luigi Semenzato0f132bb2011-02-28 11:17:43 -0800630 int file = HANDLE_EINTR(open(diskstats_path_.c_str(), O_RDONLY));
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800631 if (file < 0) {
632 PLOG(WARNING) << "cannot open " << diskstats_path_;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700633 return false;
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800634 }
635 nchars = HANDLE_EINTR(read(file, line, sizeof(line)));
636 if (nchars < 0) {
637 PLOG(WARNING) << "cannot read from " << diskstats_path_;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700638 return false;
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800639 } else {
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700640 LOG_IF(WARNING, nchars == sizeof(line))
641 << "line too long in " << diskstats_path_;
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800642 line[nchars] = '\0';
643 nitems = sscanf(line, "%*d %*d %ld %*d %*d %*d %ld",
644 read_sectors, write_sectors);
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700645 if (nitems == 2) {
646 success = true;
647 } else {
648 LOG(WARNING) << "found " << nitems << " items in "
649 << diskstats_path_ << ", expected 2";
650 }
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800651 }
652 HANDLE_EINTR(close(file));
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700653 return success;
654}
655
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700656bool MetricsDaemon::VmStatsParseStats(const char* stats,
657 struct VmstatRecord* record) {
658 // a mapping of string name to field in VmstatRecord and whether we found it
659 struct mapping {
660 const string name;
661 uint64_t* value_p;
662 bool found;
663 } map[] =
664 { { .name = "pgmajfault",
665 .value_p = &record->page_faults_,
666 .found = false },
667 { .name = "pswpin",
668 .value_p = &record->swap_in_,
669 .found = false },
670 { .name = "pswpout",
671 .value_p = &record->swap_out_,
672 .found = false }, };
673
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700674 // Each line in the file has the form
675 // <ID> <VALUE>
676 // for instance:
677 // nr_free_pages 213427
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700678 vector<string> lines;
679 Tokenize(stats, "\n", &lines);
680 for (vector<string>::iterator it = lines.begin();
681 it != lines.end(); ++it) {
682 vector<string> tokens;
683 base::SplitString(*it, ' ', &tokens);
684 if (tokens.size() == 2) {
685 for (unsigned int i = 0; i < sizeof(map)/sizeof(struct mapping); i++) {
686 if (!tokens[0].compare(map[i].name)) {
687 if (!base::StringToUint64(tokens[1], map[i].value_p))
688 return false;
689 map[i].found = true;
690 }
691 }
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700692 } else {
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700693 LOG(WARNING) << "unexpected vmstat format";
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700694 }
695 }
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700696 // make sure we got all the stats
697 for (unsigned i = 0; i < sizeof(map)/sizeof(struct mapping); i++) {
698 if (map[i].found == false) {
699 LOG(WARNING) << "vmstat missing " << map[i].name;
700 return false;
701 }
702 }
703 return true;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700704}
705
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700706bool MetricsDaemon::VmStatsReadStats(struct VmstatRecord* stats) {
707 string value_string;
708 FilePath* path = new FilePath(vmstats_path_);
709 if (!file_util::ReadFileToString(*path, &value_string)) {
710 delete path;
711 LOG(WARNING) << "cannot read " << vmstats_path_;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700712 return false;
713 }
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700714 delete path;
715 return VmStatsParseStats(value_string.c_str(), stats);
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800716}
717
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700718bool MetricsDaemon::ReadFreqToInt(const string& sysfs_file_name, int* value) {
Luigi Semenzatod92d18c2013-06-04 13:24:21 -0700719 const FilePath sysfs_path(sysfs_file_name);
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700720 string value_string;
721 if (!file_util::ReadFileToString(sysfs_path, &value_string)) {
722 LOG(WARNING) << "cannot read " << sysfs_path.value().c_str();
723 return false;
724 }
725 if (!RemoveChars(value_string, "\n", &value_string)) {
726 LOG(WARNING) << "no newline in " << value_string;
727 // Continue even though the lack of newline is suspicious.
728 }
729 if (!base::StringToInt(value_string, value)) {
730 LOG(WARNING) << "cannot convert " << value_string << " to int";
731 return false;
732 }
733 return true;
734}
735
736void MetricsDaemon::SendCpuThrottleMetrics() {
737 // |max_freq| is 0 only the first time through.
738 static int max_freq = 0;
739 if (max_freq == -1)
740 // Give up, as sysfs did not report max_freq correctly.
741 return;
742 if (max_freq == 0 || testing_) {
743 // One-time initialization of max_freq. (Every time when testing.)
744 if (!ReadFreqToInt(cpuinfo_max_freq_path_, &max_freq)) {
745 max_freq = -1;
746 return;
747 }
748 if (max_freq == 0) {
749 LOG(WARNING) << "sysfs reports 0 max CPU frequency\n";
750 max_freq = -1;
751 return;
752 }
753 if (max_freq % 10000 == 1000) {
754 // Special case: system has turbo mode, and max non-turbo frequency is
755 // max_freq - 1000. This relies on "normal" (non-turbo) frequencies
756 // being multiples of (at least) 10 MHz. Although there is no guarantee
757 // of this, it seems a fairly reasonable assumption. Otherwise we should
758 // read scaling_available_frequencies, sort the frequencies, compare the
759 // two highest ones, and check if they differ by 1000 (kHz) (and that's a
760 // hack too, no telling when it will change).
761 max_freq -= 1000;
762 }
763 }
764 int scaled_freq = 0;
765 if (!ReadFreqToInt(scaling_max_freq_path_, &scaled_freq))
766 return;
767 // Frequencies are in kHz. If scaled_freq > max_freq, turbo is on, but
768 // scaled_freq is not the actual turbo frequency. We indicate this situation
769 // with a 101% value.
770 int percent = scaled_freq > max_freq ? 101 : scaled_freq / (max_freq / 100);
771 SendLinearMetric(kMetricScaledCpuFrequencyName, percent, 101, 102);
772}
773
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800774// static
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700775gboolean MetricsDaemon::StatsCallbackStatic(void* handle) {
776 (static_cast<MetricsDaemon*>(handle))->StatsCallback();
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800777 return false; // one-time callback
778}
779
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700780// Collects disk and vm stats alternating over a short and a long interval.
Luigi Semenzato8accd332011-05-17 16:37:18 -0700781
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700782void MetricsDaemon::StatsCallback() {
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700783 long int read_sectors_now, write_sectors_now;
784 struct VmstatRecord vmstats_now;
Luigi Semenzato8accd332011-05-17 16:37:18 -0700785 double time_now = GetActiveTime();
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700786 double delta_time = time_now - stats_initial_time_;
Luigi Semenzato8accd332011-05-17 16:37:18 -0700787 if (testing_) {
788 // Fake the time when testing.
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700789 delta_time = stats_state_ == kStatsShort ?
790 kMetricStatsShortInterval : kMetricStatsLongInterval;
Luigi Semenzato8accd332011-05-17 16:37:18 -0700791 }
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700792 bool diskstats_success = DiskStatsReadStats(&read_sectors_now,
793 &write_sectors_now);
Luigi Semenzato8accd332011-05-17 16:37:18 -0700794 int delta_read = read_sectors_now - read_sectors_;
795 int delta_write = write_sectors_now - write_sectors_;
796 int read_sectors_per_second = delta_read / delta_time;
797 int write_sectors_per_second = delta_write / delta_time;
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700798 bool vmstats_success = VmStatsReadStats(&vmstats_now);
799 uint64_t delta_faults = vmstats_now.page_faults_ - vmstats_.page_faults_;
800 uint64_t delta_swap_in = vmstats_now.swap_in_ - vmstats_.swap_in_;
801 uint64_t delta_swap_out = vmstats_now.swap_out_ - vmstats_.swap_out_;
802 uint64_t page_faults_per_second = delta_faults / delta_time;
803 uint64_t swap_in_per_second = delta_swap_in / delta_time;
804 uint64_t swap_out_per_second = delta_swap_out / delta_time;
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800805
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700806 switch (stats_state_) {
807 case kStatsShort:
808 if (diskstats_success) {
809 SendMetric(kMetricReadSectorsShortName,
810 read_sectors_per_second,
811 1,
812 kMetricSectorsIOMax,
813 kMetricSectorsBuckets);
814 SendMetric(kMetricWriteSectorsShortName,
815 write_sectors_per_second,
816 1,
817 kMetricSectorsIOMax,
818 kMetricSectorsBuckets);
819 }
820 if (vmstats_success) {
821 SendMetric(kMetricPageFaultsShortName,
822 page_faults_per_second,
823 1,
824 kMetricPageFaultsMax,
825 kMetricPageFaultsBuckets);
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700826 SendMetric(kMetricSwapInShortName,
827 swap_in_per_second,
828 1,
829 kMetricPageFaultsMax,
830 kMetricPageFaultsBuckets);
831 SendMetric(kMetricSwapOutShortName,
832 swap_out_per_second,
833 1,
834 kMetricPageFaultsMax,
835 kMetricPageFaultsBuckets);
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700836 }
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800837 // Schedule long callback.
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700838 stats_state_ = kStatsLong;
839 ScheduleStatsCallback(kMetricStatsLongInterval -
840 kMetricStatsShortInterval);
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800841 break;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700842 case kStatsLong:
843 if (diskstats_success) {
844 SendMetric(kMetricReadSectorsLongName,
845 read_sectors_per_second,
846 1,
847 kMetricSectorsIOMax,
848 kMetricSectorsBuckets);
849 SendMetric(kMetricWriteSectorsLongName,
850 write_sectors_per_second,
851 1,
852 kMetricSectorsIOMax,
853 kMetricSectorsBuckets);
854 // Reset sector counters.
855 read_sectors_ = read_sectors_now;
856 write_sectors_ = write_sectors_now;
857 }
858 if (vmstats_success) {
859 SendMetric(kMetricPageFaultsLongName,
860 page_faults_per_second,
861 1,
862 kMetricPageFaultsMax,
863 kMetricPageFaultsBuckets);
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700864 SendMetric(kMetricSwapInLongName,
865 swap_in_per_second,
866 1,
867 kMetricPageFaultsMax,
868 kMetricPageFaultsBuckets);
869 SendMetric(kMetricSwapOutLongName,
870 swap_out_per_second,
871 1,
872 kMetricPageFaultsMax,
873 kMetricPageFaultsBuckets);
874
875 vmstats_ = vmstats_now;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700876 }
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700877 SendCpuThrottleMetrics();
Luigi Semenzato8accd332011-05-17 16:37:18 -0700878 // Set start time for new cycle.
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700879 stats_initial_time_ = time_now;
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800880 // Schedule short callback.
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700881 stats_state_ = kStatsShort;
882 ScheduleStatsCallback(kMetricStatsShortInterval);
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800883 break;
884 default:
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700885 LOG(FATAL) << "Invalid stats state";
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800886 }
887}
888
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700889void MetricsDaemon::ScheduleMeminfoCallback(int wait) {
890 if (testing_) {
891 return;
892 }
893 g_timeout_add_seconds(wait, MeminfoCallbackStatic, this);
894}
895
896// static
897gboolean MetricsDaemon::MeminfoCallbackStatic(void* handle) {
898 return (static_cast<MetricsDaemon*>(handle))->MeminfoCallback();
899}
900
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700901bool MetricsDaemon::MeminfoCallback() {
Luigi Semenzato8accd332011-05-17 16:37:18 -0700902 string meminfo_raw;
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700903 const FilePath meminfo_path("/proc/meminfo");
Luigi Semenzato8accd332011-05-17 16:37:18 -0700904 if (!file_util::ReadFileToString(meminfo_path, &meminfo_raw)) {
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700905 LOG(WARNING) << "cannot read " << meminfo_path.value().c_str();
906 return false;
907 }
Luigi Semenzato8accd332011-05-17 16:37:18 -0700908 return ProcessMeminfo(meminfo_raw);
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700909}
910
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700911bool MetricsDaemon::ProcessMeminfo(const string& meminfo_raw) {
Luigi Semenzato8accd332011-05-17 16:37:18 -0700912 static const MeminfoRecord fields_array[] = {
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700913 { "MemTotal", "MemTotal" }, // SPECIAL CASE: total system memory
914 { "MemFree", "MemFree" },
915 { "Buffers", "Buffers" },
916 { "Cached", "Cached" },
917 // { "SwapCached", "SwapCached" },
918 { "Active", "Active" },
919 { "Inactive", "Inactive" },
920 { "ActiveAnon", "Active(anon)" },
921 { "InactiveAnon", "Inactive(anon)" },
922 { "ActiveFile" , "Active(file)" },
923 { "InactiveFile", "Inactive(file)" },
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800924 { "Unevictable", "Unevictable", kMeminfoOp_HistLog },
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700925 // { "Mlocked", "Mlocked" },
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800926 { "SwapTotal", "SwapTotal", kMeminfoOp_SwapTotal },
927 { "SwapFree", "SwapFree", kMeminfoOp_SwapFree },
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700928 // { "Dirty", "Dirty" },
929 // { "Writeback", "Writeback" },
930 { "AnonPages", "AnonPages" },
931 { "Mapped", "Mapped" },
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800932 { "Shmem", "Shmem", kMeminfoOp_HistLog },
933 { "Slab", "Slab", kMeminfoOp_HistLog },
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700934 // { "SReclaimable", "SReclaimable" },
935 // { "SUnreclaim", "SUnreclaim" },
936 };
Luigi Semenzato8accd332011-05-17 16:37:18 -0700937 vector<MeminfoRecord> fields(fields_array,
938 fields_array + arraysize(fields_array));
939 if (!FillMeminfo(meminfo_raw, &fields)) {
940 return false;
941 }
942 int total_memory = fields[0].value;
943 if (total_memory == 0) {
944 // this "cannot happen"
945 LOG(WARNING) << "borked meminfo parser";
946 return false;
947 }
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800948 int swap_total = 0;
949 int swap_free = 0;
Luigi Semenzato8accd332011-05-17 16:37:18 -0700950 // Send all fields retrieved, except total memory.
951 for (unsigned int i = 1; i < fields.size(); i++) {
952 string metrics_name = StringPrintf("Platform.Meminfo%s", fields[i].name);
Luigi Semenzato3ccca062013-02-04 19:50:45 -0800953 int percent;
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800954 switch (fields[i].op) {
955 case kMeminfoOp_HistPercent:
Luigi Semenzato3ccca062013-02-04 19:50:45 -0800956 // report value as percent of total memory
957 percent = fields[i].value * 100 / total_memory;
958 SendLinearMetric(metrics_name, percent, 100, 101);
959 break;
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800960 case kMeminfoOp_HistLog:
Luigi Semenzato3ccca062013-02-04 19:50:45 -0800961 // report value in kbytes, log scale, 4Gb max
962 SendMetric(metrics_name, fields[i].value, 1, 4 * 1000 * 1000, 100);
963 break;
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800964 case kMeminfoOp_SwapTotal:
965 swap_total = fields[i].value;
966 case kMeminfoOp_SwapFree:
967 swap_free = fields[i].value;
Luigi Semenzato3ccca062013-02-04 19:50:45 -0800968 break;
Luigi Semenzato8accd332011-05-17 16:37:18 -0700969 }
970 }
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800971 if (swap_total > 0) {
972 int swap_used = swap_total - swap_free;
973 int swap_used_percent = swap_used * 100 / swap_total;
974 SendMetric("Platform.MeminfoSwapUsed", swap_used, 1, 8 * 1000 * 1000, 100);
975 SendLinearMetric("Platform.MeminfoSwapUsedPercent", swap_used_percent,
976 100, 101);
977 }
Luigi Semenzato8accd332011-05-17 16:37:18 -0700978 return true;
979}
980
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700981bool MetricsDaemon::FillMeminfo(const string& meminfo_raw,
982 vector<MeminfoRecord>* fields) {
Luigi Semenzato8accd332011-05-17 16:37:18 -0700983 vector<string> lines;
984 unsigned int nlines = Tokenize(meminfo_raw, "\n", &lines);
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700985
986 // Scan meminfo output and collect field values. Each field name has to
987 // match a meminfo entry (case insensitive) after removing non-alpha
988 // characters from the entry.
Luigi Semenzato8accd332011-05-17 16:37:18 -0700989 unsigned int ifield = 0;
990 for (unsigned int iline = 0;
991 iline < nlines && ifield < fields->size();
992 iline++) {
993 vector<string> tokens;
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700994 Tokenize(lines[iline], ": ", &tokens);
Luigi Semenzato8accd332011-05-17 16:37:18 -0700995 if (strcmp((*fields)[ifield].match, tokens[0].c_str()) == 0) {
996 // Name matches. Parse value and save.
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700997 char* rest;
Luigi Semenzato8accd332011-05-17 16:37:18 -0700998 (*fields)[ifield].value =
999 static_cast<int>(strtol(tokens[1].c_str(), &rest, 10));
Luigi Semenzato29c7ef92011-04-12 14:12:35 -07001000 if (*rest != '\0') {
1001 LOG(WARNING) << "missing meminfo value";
1002 return false;
1003 }
Luigi Semenzato8accd332011-05-17 16:37:18 -07001004 ifield++;
Luigi Semenzato29c7ef92011-04-12 14:12:35 -07001005 }
Luigi Semenzato29c7ef92011-04-12 14:12:35 -07001006 }
Luigi Semenzato8accd332011-05-17 16:37:18 -07001007 if (ifield < fields->size()) {
1008 // End of input reached while scanning.
1009 LOG(WARNING) << "cannot find field " << (*fields)[ifield].match
1010 << " and following";
1011 return false;
1012 }
1013 return true;
1014}
1015
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -08001016void MetricsDaemon::ScheduleMemuseCallback(double interval) {
Luigi Semenzato8accd332011-05-17 16:37:18 -07001017 if (testing_) {
1018 return;
1019 }
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -08001020 g_timeout_add_seconds(interval, MemuseCallbackStatic, this);
Luigi Semenzato8accd332011-05-17 16:37:18 -07001021}
1022
1023// static
1024gboolean MetricsDaemon::MemuseCallbackStatic(void* handle) {
1025 MetricsDaemon* daemon = static_cast<MetricsDaemon*>(handle);
1026 daemon->MemuseCallback();
1027 return false;
1028}
1029
1030void MetricsDaemon::MemuseCallback() {
1031 // Since we only care about active time (i.e. uptime minus sleep time) but
1032 // the callbacks are driven by real time (uptime), we check if we should
1033 // reschedule this callback due to intervening sleep periods.
1034 double now = GetActiveTime();
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -08001035 // Avoid intervals of less than one second.
1036 double remaining_time = ceil(memuse_final_time_ - now);
1037 if (remaining_time > 0) {
1038 ScheduleMemuseCallback(remaining_time);
Luigi Semenzato8accd332011-05-17 16:37:18 -07001039 } else {
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -08001040 // Report stats and advance the measurement interval unless there are
1041 // errors or we've completed the last interval.
Luigi Semenzato8accd332011-05-17 16:37:18 -07001042 if (MemuseCallbackWork() &&
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -08001043 memuse_interval_index_ < arraysize(kMemuseIntervals)) {
1044 double interval = kMemuseIntervals[memuse_interval_index_++];
1045 memuse_final_time_ = now + interval;
1046 ScheduleMemuseCallback(interval);
Luigi Semenzato8accd332011-05-17 16:37:18 -07001047 }
1048 }
1049}
1050
Luigi Semenzato5bd764f2011-10-14 12:03:35 -07001051bool MetricsDaemon::MemuseCallbackWork() {
Luigi Semenzato8accd332011-05-17 16:37:18 -07001052 string meminfo_raw;
1053 const FilePath meminfo_path("/proc/meminfo");
1054 if (!file_util::ReadFileToString(meminfo_path, &meminfo_raw)) {
1055 LOG(WARNING) << "cannot read " << meminfo_path.value().c_str();
1056 return false;
1057 }
1058 return ProcessMemuse(meminfo_raw);
1059}
1060
Luigi Semenzato5bd764f2011-10-14 12:03:35 -07001061bool MetricsDaemon::ProcessMemuse(const string& meminfo_raw) {
Luigi Semenzato8accd332011-05-17 16:37:18 -07001062 static const MeminfoRecord fields_array[] = {
1063 { "MemTotal", "MemTotal" }, // SPECIAL CASE: total system memory
1064 { "ActiveAnon", "Active(anon)" },
1065 { "InactiveAnon", "Inactive(anon)" },
1066 };
1067 vector<MeminfoRecord> fields(fields_array,
1068 fields_array + arraysize(fields_array));
1069 if (!FillMeminfo(meminfo_raw, &fields)) {
1070 return false;
1071 }
1072 int total = fields[0].value;
1073 int active_anon = fields[1].value;
1074 int inactive_anon = fields[2].value;
1075 if (total == 0) {
1076 // this "cannot happen"
1077 LOG(WARNING) << "borked meminfo parser";
1078 return false;
1079 }
1080 string metrics_name = StringPrintf("Platform.MemuseAnon%d",
1081 memuse_interval_index_);
1082 SendLinearMetric(metrics_name, (active_anon + inactive_anon) * 100 / total,
1083 100, 101);
1084 return true;
Luigi Semenzato29c7ef92011-04-12 14:12:35 -07001085}
1086
Darin Petkovf1e85e42010-06-10 15:59:53 -07001087// static
Ken Mixterccd84c02010-08-16 19:57:13 -07001088void MetricsDaemon::ReportDailyUse(void* handle, int tag, int count) {
Darin Petkov1bb904e2010-06-16 15:58:06 -07001089 if (count <= 0)
1090 return;
1091
Darin Petkovf1e85e42010-06-10 15:59:53 -07001092 MetricsDaemon* daemon = static_cast<MetricsDaemon*>(handle);
1093 int minutes = (count + kSecondsPerMinute / 2) / kSecondsPerMinute;
1094 daemon->SendMetric(kMetricDailyUseTimeName, minutes,
1095 kMetricDailyUseTimeMin,
1096 kMetricDailyUseTimeMax,
1097 kMetricDailyUseTimeBuckets);
1098}
1099
Darin Petkov38d5cb02010-06-24 12:10:26 -07001100void MetricsDaemon::SendMetric(const string& name, int sample,
Darin Petkov11b8eb32010-05-18 11:00:59 -07001101 int min, int max, int nbuckets) {
Darin Petkovfc91b422010-05-12 13:05:45 -07001102 DLOG(INFO) << "received metric: " << name << " " << sample << " "
1103 << min << " " << max << " " << nbuckets;
1104 metrics_lib_->SendToUMA(name, sample, min, max, nbuckets);
Darin Petkov65b01462010-04-14 13:32:20 -07001105}
Luigi Semenzato29c7ef92011-04-12 14:12:35 -07001106
1107void MetricsDaemon::SendLinearMetric(const string& name, int sample,
1108 int max, int nbuckets) {
1109 DLOG(INFO) << "received linear metric: " << name << " " << sample << " "
1110 << max << " " << nbuckets;
1111 // TODO(semenzato): add a proper linear histogram to the Chrome external
1112 // metrics API.
1113 LOG_IF(FATAL, nbuckets != max + 1) << "unsupported histogram scale";
1114 metrics_lib_->SendEnumToUMA(name, sample, max);
1115}