blob: 883c132b8b60640ac63b481c31618557ce636d6f [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
Ben Chan2e6543d2014-02-05 23:26:25 -080025using base::FilePath;
26using base::StringPrintf;
Darin Petkovf27f0362010-06-04 13:14:19 -070027using base::Time;
28using base::TimeDelta;
29using base::TimeTicks;
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -080030using chromeos_metrics::PersistentInteger;
Luigi Semenzato8accd332011-05-17 16:37:18 -070031using std::map;
Darin Petkov38d5cb02010-06-24 12:10:26 -070032using std::string;
Luigi Semenzato8accd332011-05-17 16:37:18 -070033using std::vector;
34
Darin Petkovf27f0362010-06-04 13:14:19 -070035
Darin Petkov703ec972010-04-27 11:02:18 -070036#define SAFE_MESSAGE(e) (e.message ? e.message : "unknown error")
Darin Petkov40f25732013-04-29 15:07:31 +020037
38static const char kCrashReporterInterface[] = "org.chromium.CrashReporter";
39static const char kCrashReporterUserCrashSignal[] = "UserCrash";
Darin Petkov41e06232010-05-03 16:45:37 -070040
Darin Petkov41e06232010-05-03 16:45:37 -070041static const int kSecondsPerMinute = 60;
42static const int kMinutesPerHour = 60;
43static const int kHoursPerDay = 24;
44static const int kMinutesPerDay = kHoursPerDay * kMinutesPerHour;
Darin Petkov1bb904e2010-06-16 15:58:06 -070045static const int kSecondsPerDay = kSecondsPerMinute * kMinutesPerDay;
46static const int kDaysPerWeek = 7;
47static const int kSecondsPerWeek = kSecondsPerDay * kDaysPerWeek;
Darin Petkov41e06232010-05-03 16:45:37 -070048
49// The daily use monitor is scheduled to a 1-minute interval after
50// initial user activity and then it's exponentially backed off to
51// 10-minute intervals. Although not required, the back off is
52// implemented because the histogram buckets are spaced exponentially
53// anyway and to avoid too frequent metrics daemon process wake-ups
54// and file I/O.
55static const int kUseMonitorIntervalInit = 1 * kSecondsPerMinute;
56static const int kUseMonitorIntervalMax = 10 * kSecondsPerMinute;
Darin Petkov65b01462010-04-14 13:32:20 -070057
Luigi Semenzatoc5a92342014-02-14 15:05:51 -080058const char kKernelCrashDetectedFile[] = "/var/run/kernel-crash-detected";
Ken Mixterccd84c02010-08-16 19:57:13 -070059static const char kUncleanShutdownDetectedFile[] =
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -080060 "/var/run/unclean-shutdown-detected";
Ken Mixterccd84c02010-08-16 19:57:13 -070061
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -080062// disk stats metrics
63
64// The {Read,Write}Sectors numbers are in sectors/second.
65// A sector is usually 512 bytes.
66
67const char MetricsDaemon::kMetricReadSectorsLongName[] =
68 "Platform.ReadSectorsLong";
69const char MetricsDaemon::kMetricWriteSectorsLongName[] =
70 "Platform.WriteSectorsLong";
71const char MetricsDaemon::kMetricReadSectorsShortName[] =
72 "Platform.ReadSectorsShort";
73const char MetricsDaemon::kMetricWriteSectorsShortName[] =
74 "Platform.WriteSectorsShort";
75
Luigi Semenzato5bd764f2011-10-14 12:03:35 -070076const int MetricsDaemon::kMetricStatsShortInterval = 1; // seconds
77const int MetricsDaemon::kMetricStatsLongInterval = 30; // seconds
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -080078
Luigi Semenzato29c7ef92011-04-12 14:12:35 -070079const int MetricsDaemon::kMetricMeminfoInterval = 30; // seconds
80
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -080081// Assume a max rate of 250Mb/s for reads (worse for writes) and 512 byte
82// sectors.
83const int MetricsDaemon::kMetricSectorsIOMax = 500000; // sectors/second
84const int MetricsDaemon::kMetricSectorsBuckets = 50; // buckets
Luigi Semenzato5bd764f2011-10-14 12:03:35 -070085// Page size is 4k, sector size is 0.5k. We're not interested in page fault
86// rates that the disk cannot sustain.
87const int MetricsDaemon::kMetricPageFaultsMax = kMetricSectorsIOMax / 8;
88const int MetricsDaemon::kMetricPageFaultsBuckets = 50;
89
90// Major page faults, i.e. the ones that require data to be read from disk.
91
92const char MetricsDaemon::kMetricPageFaultsLongName[] =
93 "Platform.PageFaultsLong";
94const char MetricsDaemon::kMetricPageFaultsShortName[] =
95 "Platform.PageFaultsShort";
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -080096
Sonny Rao4b8aebb2013-07-31 23:18:31 -070097// Swap in and Swap out
98
99const char MetricsDaemon::kMetricSwapInLongName[] =
100 "Platform.SwapInLong";
101const char MetricsDaemon::kMetricSwapInShortName[] =
102 "Platform.SwapInShort";
103
104const char MetricsDaemon::kMetricSwapOutLongName[] =
105 "Platform.SwapOutLong";
106const char MetricsDaemon::kMetricSwapOutShortName[] =
107 "Platform.SwapOutShort";
108
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700109// Thermal CPU throttling.
110
111const char MetricsDaemon::kMetricScaledCpuFrequencyName[] =
112 "Platform.CpuFrequencyThermalScaling";
113
Darin Petkov703ec972010-04-27 11:02:18 -0700114// static
Darin Petkov41e06232010-05-03 16:45:37 -0700115const char* MetricsDaemon::kPowerStates_[] = {
Darin Petkov703ec972010-04-27 11:02:18 -0700116#define STATE(name, capname) #name,
117#include "power_states.h"
118};
119
Darin Petkov41e06232010-05-03 16:45:37 -0700120// static
Darin Petkov41e06232010-05-03 16:45:37 -0700121const char* MetricsDaemon::kSessionStates_[] = {
122#define STATE(name, capname) #name,
123#include "session_states.h"
124};
125
Luigi Semenzato8accd332011-05-17 16:37:18 -0700126// Memory use stats collection intervals. We collect some memory use interval
127// at these intervals after boot, and we stop collecting after the last one,
128// with the assumption that in most cases the memory use won't change much
129// after that.
130static const int kMemuseIntervals[] = {
131 1 * kSecondsPerMinute, // 1 minute mark
132 4 * kSecondsPerMinute, // 5 minute mark
133 25 * kSecondsPerMinute, // 0.5 hour mark
134 120 * kSecondsPerMinute, // 2.5 hour mark
135 600 * kSecondsPerMinute, // 12.5 hour mark
136};
137
Darin Petkovf1e85e42010-06-10 15:59:53 -0700138MetricsDaemon::MetricsDaemon()
Sam Leffler239b8262010-08-30 08:56:58 -0700139 : power_state_(kUnknownPowerState),
Darin Petkovf1e85e42010-06-10 15:59:53 -0700140 session_state_(kUnknownSessionState),
141 user_active_(false),
142 usemon_interval_(0),
Luigi Semenzato8accd332011-05-17 16:37:18 -0700143 usemon_source_(NULL),
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -0800144 memuse_final_time_(0),
Luigi Semenzato8accd332011-05-17 16:37:18 -0700145 memuse_interval_index_(0),
146 read_sectors_(0),
147 write_sectors_(0),
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700148 vmstats_(),
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700149 stats_state_(kStatsShort),
150 stats_initial_time_(0) {}
Darin Petkovf1e85e42010-06-10 15:59:53 -0700151
Ken Mixter4c5daa42010-08-26 18:35:06 -0700152MetricsDaemon::~MetricsDaemon() {
Ken Mixter4c5daa42010-08-26 18:35:06 -0700153}
154
Luigi Semenzato8accd332011-05-17 16:37:18 -0700155double MetricsDaemon::GetActiveTime() {
156 struct timespec ts;
157 int r = clock_gettime(CLOCK_MONOTONIC, &ts);
158 if (r < 0) {
159 PLOG(WARNING) << "clock_gettime(CLOCK_MONOTONIC) failed";
160 return 0;
161 } else {
162 return ts.tv_sec + ((double) ts.tv_nsec) / (1000 * 1000 * 1000);
163 }
164}
165
Darin Petkov2ccef012010-05-05 16:06:37 -0700166void MetricsDaemon::Run(bool run_as_daemon) {
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800167 base::AtExitManager at_exit_manager;
168
Darin Petkov38d5cb02010-06-24 12:10:26 -0700169 if (run_as_daemon && daemon(0, 0) != 0)
170 return;
171
Ken Mixterccd84c02010-08-16 19:57:13 -0700172 if (CheckSystemCrash(kKernelCrashDetectedFile)) {
173 ProcessKernelCrash();
174 }
175
176 if (CheckSystemCrash(kUncleanShutdownDetectedFile)) {
177 ProcessUncleanShutdown();
178 }
179
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800180 // On OS version change, clear version stats (which are reported daily).
181 int32 version = GetOsVersionHash();
182 if (version_cycle_->Get() != version) {
183 version_cycle_->Set(version);
184 SendKernelCrashesCumulativeCountSample();
185 kernel_crashes_version_count_->Set(0);
186 }
187
Darin Petkov38d5cb02010-06-24 12:10:26 -0700188 Loop();
Darin Petkov65b01462010-04-14 13:32:20 -0700189}
190
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800191uint32 MetricsDaemon::GetOsVersionHash() {
192 static uint32 cached_version_hash = 0;
193 static bool version_hash_is_cached = false;
194 if (version_hash_is_cached)
195 return cached_version_hash;
196 version_hash_is_cached = true;
197 std::string version;
198 if (base::SysInfo::GetLsbReleaseValue("CHROMEOS_RELEASE_VERSION", &version)) {
199 cached_version_hash = base::Hash(version);
200 } else if (testing_) {
201 cached_version_hash = 42; // return any plausible value for the hash
202 } else {
203 LOG(FATAL) << "could not find CHROMEOS_RELEASE_VERSION";
204 }
205 return cached_version_hash;
206}
207
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800208void MetricsDaemon::Init(bool testing, MetricsLibraryInterface* metrics_lib,
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700209 const string& diskstats_path,
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700210 const string& vmstats_path,
211 const string& scaling_max_freq_path,
212 const string& cpuinfo_max_freq_path
213 ) {
Darin Petkov65b01462010-04-14 13:32:20 -0700214 testing_ = testing;
Darin Petkovfc91b422010-05-12 13:05:45 -0700215 DCHECK(metrics_lib != NULL);
216 metrics_lib_ = metrics_lib;
Darin Petkov38d5cb02010-06-24 12:10:26 -0700217
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800218 daily_use_.reset(
219 new PersistentInteger("Logging.DailyUseTime"));
Darin Petkov38d5cb02010-06-24 12:10:26 -0700220
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800221 kernel_crash_interval_.reset(
222 new PersistentInteger("Logging.KernelCrashInterval"));
223 unclean_shutdown_interval_.reset(
224 new PersistentInteger("Logging.UncleanShutdownInterval"));
225 user_crash_interval_.reset(
226 new PersistentInteger("Logging.UserCrashInterval"));
Darin Petkov2ccef012010-05-05 16:06:37 -0700227
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800228 any_crashes_daily_count_.reset(
229 new PersistentInteger("Logging.AnyCrashesDaily"));
230 any_crashes_weekly_count_.reset(
231 new PersistentInteger("Logging.AnyCrashesWeekly"));
232 user_crashes_daily_count_.reset(
233 new PersistentInteger("Logging.UserCrashesDaily"));
234 user_crashes_weekly_count_.reset(
235 new PersistentInteger("Logging.UserCrashesWeekly"));
236 kernel_crashes_daily_count_.reset(
237 new PersistentInteger("Logging.KernelCrashesDaily"));
238 kernel_crashes_weekly_count_.reset(
239 new PersistentInteger("Logging.KernelCrashesWeekly"));
240 kernel_crashes_version_count_.reset(
241 new PersistentInteger("Logging.KernelCrashesSinceUpdate"));
242 unclean_shutdowns_daily_count_.reset(
243 new PersistentInteger("Logging.UncleanShutdownsDaily"));
244 unclean_shutdowns_weekly_count_.reset(
245 new PersistentInteger("Logging.UncleanShutdownsWeekly"));
Darin Petkov38d5cb02010-06-24 12:10:26 -0700246
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800247 daily_cycle_.reset(new PersistentInteger("daily.cycle"));
248 weekly_cycle_.reset(new PersistentInteger("weekly.cycle"));
249 version_cycle_.reset(new PersistentInteger("version.cycle"));
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800250
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700251 diskstats_path_ = diskstats_path;
252 vmstats_path_ = vmstats_path;
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700253 scaling_max_freq_path_ = scaling_max_freq_path;
254 cpuinfo_max_freq_path_ = cpuinfo_max_freq_path;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700255 StatsReporterInit();
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800256
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700257 // Start collecting meminfo stats.
258 ScheduleMeminfoCallback(kMetricMeminfoInterval);
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -0800259 memuse_final_time_ = GetActiveTime() + kMemuseIntervals[0];
260 ScheduleMemuseCallback(kMemuseIntervals[0]);
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700261
Darin Petkov2ccef012010-05-05 16:06:37 -0700262 // Don't setup D-Bus and GLib in test mode.
263 if (testing)
264 return;
Darin Petkov65b01462010-04-14 13:32:20 -0700265
Darin Petkov703ec972010-04-27 11:02:18 -0700266 g_type_init();
Ben Chan6f598422013-06-22 06:29:36 -0700267 dbus_threads_init_default();
Darin Petkov65b01462010-04-14 13:32:20 -0700268
Darin Petkov703ec972010-04-27 11:02:18 -0700269 DBusError error;
270 dbus_error_init(&error);
Darin Petkov65b01462010-04-14 13:32:20 -0700271
David James3b3add52010-06-04 15:01:19 -0700272 DBusConnection* connection = dbus_bus_get(DBUS_BUS_SYSTEM, &error);
Darin Petkov703ec972010-04-27 11:02:18 -0700273 LOG_IF(FATAL, dbus_error_is_set(&error)) <<
274 "No D-Bus connection: " << SAFE_MESSAGE(error);
Darin Petkov65b01462010-04-14 13:32:20 -0700275
Darin Petkov703ec972010-04-27 11:02:18 -0700276 dbus_connection_setup_with_g_main(connection, NULL);
Darin Petkov65b01462010-04-14 13:32:20 -0700277
Darin Petkov40f25732013-04-29 15:07:31 +0200278 vector<string> matches;
279 matches.push_back(
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800280 base::StringPrintf("type='signal',interface='%s',path='/',member='%s'",
281 kCrashReporterInterface,
282 kCrashReporterUserCrashSignal));
Darin Petkov40f25732013-04-29 15:07:31 +0200283 matches.push_back(
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800284 base::StringPrintf("type='signal',interface='%s',path='%s',member='%s'",
285 power_manager::kPowerManagerInterface,
286 power_manager::kPowerManagerServicePath,
287 power_manager::kPowerStateChangedSignal));
Darin Petkov40f25732013-04-29 15:07:31 +0200288 matches.push_back(
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800289 base::StringPrintf("type='signal',sender='%s',interface='%s',path='%s'",
290 login_manager::kSessionManagerServiceName,
291 login_manager::kSessionManagerInterface,
292 login_manager::kSessionManagerServicePath));
Darin Petkov40f25732013-04-29 15:07:31 +0200293
Darin Petkov703ec972010-04-27 11:02:18 -0700294 // Registers D-Bus matches for the signals we would like to catch.
Darin Petkov40f25732013-04-29 15:07:31 +0200295 for (vector<string>::const_iterator it = matches.begin();
296 it != matches.end(); ++it) {
297 const char* match = it->c_str();
Darin Petkov41e06232010-05-03 16:45:37 -0700298 DLOG(INFO) << "adding dbus match: " << match;
Darin Petkov703ec972010-04-27 11:02:18 -0700299 dbus_bus_add_match(connection, match, &error);
300 LOG_IF(FATAL, dbus_error_is_set(&error)) <<
301 "unable to add a match: " << SAFE_MESSAGE(error);
302 }
303
304 // Adds the D-Bus filter routine to be called back whenever one of
305 // the registered D-Bus matches is successful. The daemon is not
306 // activated for D-Bus messages that don't match.
307 CHECK(dbus_connection_add_filter(connection, MessageFilter, this, NULL));
Darin Petkov65b01462010-04-14 13:32:20 -0700308}
309
310void MetricsDaemon::Loop() {
Darin Petkov703ec972010-04-27 11:02:18 -0700311 GMainLoop* loop = g_main_loop_new(NULL, false);
312 g_main_loop_run(loop);
Darin Petkov65b01462010-04-14 13:32:20 -0700313}
314
Darin Petkov703ec972010-04-27 11:02:18 -0700315// static
316DBusHandlerResult MetricsDaemon::MessageFilter(DBusConnection* connection,
317 DBusMessage* message,
318 void* user_data) {
Darin Petkovf27f0362010-06-04 13:14:19 -0700319 Time now = Time::Now();
Darin Petkovf27f0362010-06-04 13:14:19 -0700320 DLOG(INFO) << "message intercepted @ " << now.ToInternalValue();
Darin Petkov703ec972010-04-27 11:02:18 -0700321
322 int message_type = dbus_message_get_type(message);
323 if (message_type != DBUS_MESSAGE_TYPE_SIGNAL) {
Darin Petkov41e06232010-05-03 16:45:37 -0700324 DLOG(WARNING) << "unexpected message type " << message_type;
Darin Petkov703ec972010-04-27 11:02:18 -0700325 return DBUS_HANDLER_RESULT_NOT_YET_HANDLED;
326 }
327
328 // Signal messages always have interfaces.
329 const char* interface = dbus_message_get_interface(message);
330 CHECK(interface != NULL);
331
332 MetricsDaemon* daemon = static_cast<MetricsDaemon*>(user_data);
333
334 DBusMessageIter iter;
335 dbus_message_iter_init(message, &iter);
Darin Petkov40f25732013-04-29 15:07:31 +0200336 if (strcmp(interface, kCrashReporterInterface) == 0) {
Darin Petkov1bb904e2010-06-16 15:58:06 -0700337 CHECK(strcmp(dbus_message_get_member(message),
Darin Petkov40f25732013-04-29 15:07:31 +0200338 kCrashReporterUserCrashSignal) == 0);
Darin Petkov1bb904e2010-06-16 15:58:06 -0700339 daemon->ProcessUserCrash();
Darin Petkov40f25732013-04-29 15:07:31 +0200340 } else if (strcmp(interface, power_manager::kPowerManagerInterface) == 0) {
Darin Petkov41e06232010-05-03 16:45:37 -0700341 CHECK(strcmp(dbus_message_get_member(message),
Darin Petkov40f25732013-04-29 15:07:31 +0200342 power_manager::kPowerStateChangedSignal) == 0);
David James3b3add52010-06-04 15:01:19 -0700343 char* state_name;
Darin Petkov41e06232010-05-03 16:45:37 -0700344 dbus_message_iter_get_basic(&iter, &state_name);
Darin Petkov40f25732013-04-29 15:07:31 +0200345 daemon->PowerStateChanged(state_name, now);
346 } else if (strcmp(interface, login_manager::kSessionManagerInterface) == 0) {
347 const char* member = dbus_message_get_member(message);
348 if (strcmp(member, login_manager::kScreenIsLockedSignal) == 0) {
349 daemon->SetUserActiveState(false, now);
350 } else if (strcmp(member, login_manager::kScreenIsUnlockedSignal) == 0) {
351 daemon->SetUserActiveState(true, now);
352 } else if (strcmp(member, login_manager::kSessionStateChangedSignal) == 0) {
353 char* state_name;
354 dbus_message_iter_get_basic(&iter, &state_name);
355 daemon->SessionStateChanged(state_name, now);
356 }
Darin Petkov703ec972010-04-27 11:02:18 -0700357 } else {
Darin Petkov41e06232010-05-03 16:45:37 -0700358 DLOG(WARNING) << "unexpected interface: " << interface;
Darin Petkov703ec972010-04-27 11:02:18 -0700359 return DBUS_HANDLER_RESULT_NOT_YET_HANDLED;
360 }
361
362 return DBUS_HANDLER_RESULT_HANDLED;
Darin Petkov65b01462010-04-14 13:32:20 -0700363}
364
Darin Petkovf27f0362010-06-04 13:14:19 -0700365void MetricsDaemon::PowerStateChanged(const char* state_name, Time now) {
Darin Petkov41e06232010-05-03 16:45:37 -0700366 DLOG(INFO) << "power state: " << state_name;
Darin Petkov703ec972010-04-27 11:02:18 -0700367 power_state_ = LookupPowerState(state_name);
Darin Petkov41e06232010-05-03 16:45:37 -0700368
369 if (power_state_ != kPowerStateOn)
370 SetUserActiveState(false, now);
Darin Petkov703ec972010-04-27 11:02:18 -0700371}
372
373MetricsDaemon::PowerState
374MetricsDaemon::LookupPowerState(const char* state_name) {
375 for (int i = 0; i < kNumberPowerStates; i++) {
Darin Petkov41e06232010-05-03 16:45:37 -0700376 if (strcmp(state_name, kPowerStates_[i]) == 0) {
Darin Petkov703ec972010-04-27 11:02:18 -0700377 return static_cast<PowerState>(i);
378 }
379 }
Darin Petkov41e06232010-05-03 16:45:37 -0700380 DLOG(WARNING) << "unknown power state: " << state_name;
Darin Petkov703ec972010-04-27 11:02:18 -0700381 return kUnknownPowerState;
Darin Petkov65b01462010-04-14 13:32:20 -0700382}
383
Darin Petkovf27f0362010-06-04 13:14:19 -0700384void MetricsDaemon::SessionStateChanged(const char* state_name, Time now) {
Darin Petkov41e06232010-05-03 16:45:37 -0700385 DLOG(INFO) << "user session state: " << state_name;
386 session_state_ = LookupSessionState(state_name);
387 SetUserActiveState(session_state_ == kSessionStateStarted, now);
388}
389
390MetricsDaemon::SessionState
391MetricsDaemon::LookupSessionState(const char* state_name) {
392 for (int i = 0; i < kNumberSessionStates; i++) {
393 if (strcmp(state_name, kSessionStates_[i]) == 0) {
394 return static_cast<SessionState>(i);
395 }
396 }
397 DLOG(WARNING) << "unknown user session state: " << state_name;
398 return kUnknownSessionState;
399}
400
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800401void MetricsDaemon::ReportStats(Time now) {
402 TimeDelta since_epoch = now - Time::UnixEpoch();
403 int day = since_epoch.InDays();
404 int week = day / 7;
405
406 if (daily_cycle_->Get() == day) {
407 // We did today already.
408 return;
409 }
410 daily_cycle_->Set(day);
411
412 // Daily stats.
413 SendCrashFrequencySample(any_crashes_daily_count_);
414 SendCrashFrequencySample(user_crashes_daily_count_);
415 SendCrashFrequencySample(kernel_crashes_daily_count_);
416 SendCrashFrequencySample(unclean_shutdowns_daily_count_);
417 SendKernelCrashesCumulativeCountSample();
418
419 if (weekly_cycle_->Get() == week) {
420 // We did this week already.
421 return;
422 }
423 weekly_cycle_->Set(week);
424
425 // Weekly stats.
426 SendCrashFrequencySample(any_crashes_weekly_count_);
427 SendCrashFrequencySample(user_crashes_weekly_count_);
428 SendCrashFrequencySample(kernel_crashes_weekly_count_);
429 SendCrashFrequencySample(unclean_shutdowns_weekly_count_);
430}
431
Darin Petkovf27f0362010-06-04 13:14:19 -0700432void MetricsDaemon::SetUserActiveState(bool active, Time now) {
Darin Petkov41e06232010-05-03 16:45:37 -0700433 DLOG(INFO) << "user: " << (active ? "active" : "inactive");
434
435 // Calculates the seconds of active use since the last update and
Darin Petkovf27f0362010-06-04 13:14:19 -0700436 // the day since Epoch, and logs the usage data. Guards against the
437 // time jumping back and forth due to the user changing it by
438 // discarding the new use time.
439 int seconds = 0;
440 if (user_active_ && now > user_active_last_) {
441 TimeDelta since_active = now - user_active_last_;
442 if (since_active < TimeDelta::FromSeconds(
443 kUseMonitorIntervalMax + kSecondsPerMinute)) {
444 seconds = static_cast<int>(since_active.InSeconds());
445 }
446 }
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800447 daily_use_->Add(seconds);
448 user_crash_interval_->Add(seconds);
449 kernel_crash_interval_->Add(seconds);
Darin Petkov41e06232010-05-03 16:45:37 -0700450
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800451 // Report daily and weekly stats as needed.
452 ReportStats(now);
Ken Mixter4c5daa42010-08-26 18:35:06 -0700453
Darin Petkov41e06232010-05-03 16:45:37 -0700454 // Schedules a use monitor on inactive->active transitions and
455 // unschedules it on active->inactive transitions.
456 if (!user_active_ && active)
457 ScheduleUseMonitor(kUseMonitorIntervalInit, /* backoff */ false);
458 else if (user_active_ && !active)
459 UnscheduleUseMonitor();
460
461 // Remembers the current active state and the time of the last
462 // activity update.
463 user_active_ = active;
464 user_active_last_ = now;
465}
466
Darin Petkov1bb904e2010-06-16 15:58:06 -0700467void MetricsDaemon::ProcessUserCrash() {
468 // Counts the active use time up to now.
469 SetUserActiveState(user_active_, Time::Now());
470
471 // Reports the active use time since the last crash and resets it.
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800472 SendCrashIntervalSample(user_crash_interval_);
Ken Mixterccd84c02010-08-16 19:57:13 -0700473
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800474 any_crashes_daily_count_->Add(1);
475 any_crashes_weekly_count_->Add(1);
476 user_crashes_daily_count_->Add(1);
477 user_crashes_weekly_count_->Add(1);
Darin Petkov1bb904e2010-06-16 15:58:06 -0700478}
479
Darin Petkov38d5cb02010-06-24 12:10:26 -0700480void MetricsDaemon::ProcessKernelCrash() {
481 // Counts the active use time up to now.
482 SetUserActiveState(user_active_, Time::Now());
483
484 // Reports the active use time since the last crash and resets it.
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800485 SendCrashIntervalSample(kernel_crash_interval_);
Ken Mixterccd84c02010-08-16 19:57:13 -0700486
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800487 any_crashes_daily_count_->Add(1);
488 any_crashes_weekly_count_->Add(1);
489 kernel_crashes_daily_count_->Add(1);
490 kernel_crashes_weekly_count_->Add(1);
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800491
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800492 kernel_crashes_version_count_->Add(1);
Darin Petkov38d5cb02010-06-24 12:10:26 -0700493}
494
Ken Mixterccd84c02010-08-16 19:57:13 -0700495void MetricsDaemon::ProcessUncleanShutdown() {
496 // Counts the active use time up to now.
497 SetUserActiveState(user_active_, Time::Now());
498
499 // Reports the active use time since the last crash and resets it.
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800500 SendCrashIntervalSample(unclean_shutdown_interval_);
Ken Mixterccd84c02010-08-16 19:57:13 -0700501
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800502 unclean_shutdowns_daily_count_->Add(1);
503 unclean_shutdowns_weekly_count_->Add(1);
504 any_crashes_daily_count_->Add(1);
505 any_crashes_weekly_count_->Add(1);
Ken Mixterccd84c02010-08-16 19:57:13 -0700506}
507
Luigi Semenzato8accd332011-05-17 16:37:18 -0700508bool MetricsDaemon::CheckSystemCrash(const string& crash_file) {
Darin Petkov38d5cb02010-06-24 12:10:26 -0700509 FilePath crash_detected(crash_file);
Ben Chan2e6543d2014-02-05 23:26:25 -0800510 if (!base::PathExists(crash_detected))
Ken Mixterccd84c02010-08-16 19:57:13 -0700511 return false;
Darin Petkov38d5cb02010-06-24 12:10:26 -0700512
513 // Deletes the crash-detected file so that the daemon doesn't report
514 // another kernel crash in case it's restarted.
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800515 base::DeleteFile(crash_detected, false); // not recursive
Ken Mixterccd84c02010-08-16 19:57:13 -0700516 return true;
Darin Petkov38d5cb02010-06-24 12:10:26 -0700517}
518
Darin Petkov41e06232010-05-03 16:45:37 -0700519// static
520gboolean MetricsDaemon::UseMonitorStatic(gpointer data) {
521 return static_cast<MetricsDaemon*>(data)->UseMonitor() ? TRUE : FALSE;
522}
523
524bool MetricsDaemon::UseMonitor() {
Darin Petkovf27f0362010-06-04 13:14:19 -0700525 SetUserActiveState(user_active_, Time::Now());
Darin Petkov41e06232010-05-03 16:45:37 -0700526
527 // If a new monitor source/instance is scheduled, returns false to
528 // tell GLib to destroy this monitor source/instance. Returns true
529 // otherwise to keep calling back this monitor.
530 return !ScheduleUseMonitor(usemon_interval_ * 2, /* backoff */ true);
531}
532
533bool MetricsDaemon::ScheduleUseMonitor(int interval, bool backoff)
534{
Darin Petkov2ccef012010-05-05 16:06:37 -0700535 if (testing_)
536 return false;
537
Darin Petkov41e06232010-05-03 16:45:37 -0700538 // Caps the interval -- the bigger the interval, the more active use
539 // time will be potentially dropped on system shutdown.
540 if (interval > kUseMonitorIntervalMax)
541 interval = kUseMonitorIntervalMax;
542
543 if (backoff) {
544 // Back-off mode is used by the use monitor to reschedule itself
545 // with exponential back-off in time. This mode doesn't create a
546 // new timeout source if the new interval is the same as the old
547 // one. Also, if a new timeout source is created, the old one is
548 // not destroyed explicitly here -- it will be destroyed by GLib
549 // when the monitor returns FALSE (see UseMonitor and
550 // UseMonitorStatic).
551 if (interval == usemon_interval_)
552 return false;
553 } else {
554 UnscheduleUseMonitor();
555 }
556
557 // Schedules a new use monitor for |interval| seconds from now.
558 DLOG(INFO) << "scheduling use monitor in " << interval << " seconds";
559 usemon_source_ = g_timeout_source_new_seconds(interval);
560 g_source_set_callback(usemon_source_, UseMonitorStatic, this,
561 NULL); // No destroy notification.
562 g_source_attach(usemon_source_,
563 NULL); // Default context.
564 usemon_interval_ = interval;
565 return true;
566}
567
568void MetricsDaemon::UnscheduleUseMonitor() {
569 // If there's a use monitor scheduled already, destroys it.
570 if (usemon_source_ == NULL)
571 return;
572
573 DLOG(INFO) << "destroying use monitor";
574 g_source_destroy(usemon_source_);
575 usemon_source_ = NULL;
576 usemon_interval_ = 0;
577}
578
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700579void MetricsDaemon::StatsReporterInit() {
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800580 DiskStatsReadStats(&read_sectors_, &write_sectors_);
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700581 VmStatsReadStats(&vmstats_);
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800582 // The first time around just run the long stat, so we don't delay boot.
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700583 stats_state_ = kStatsLong;
584 stats_initial_time_ = GetActiveTime();
585 if (stats_initial_time_ < 0) {
Luigi Semenzato8accd332011-05-17 16:37:18 -0700586 LOG(WARNING) << "not collecting disk stats";
587 } else {
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700588 ScheduleStatsCallback(kMetricStatsLongInterval);
Luigi Semenzato8accd332011-05-17 16:37:18 -0700589 }
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800590}
591
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700592void MetricsDaemon::ScheduleStatsCallback(int wait) {
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800593 if (testing_) {
594 return;
595 }
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700596 g_timeout_add_seconds(wait, StatsCallbackStatic, this);
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800597}
598
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700599bool MetricsDaemon::DiskStatsReadStats(long int* read_sectors,
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800600 long int* write_sectors) {
601 int nchars;
602 int nitems;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700603 bool success = false;
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800604 char line[200];
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700605 if (diskstats_path_.empty()) {
606 return false;
607 }
Luigi Semenzato0f132bb2011-02-28 11:17:43 -0800608 int file = HANDLE_EINTR(open(diskstats_path_.c_str(), O_RDONLY));
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800609 if (file < 0) {
610 PLOG(WARNING) << "cannot open " << diskstats_path_;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700611 return false;
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800612 }
613 nchars = HANDLE_EINTR(read(file, line, sizeof(line)));
614 if (nchars < 0) {
615 PLOG(WARNING) << "cannot read from " << diskstats_path_;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700616 return false;
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800617 } else {
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700618 LOG_IF(WARNING, nchars == sizeof(line))
619 << "line too long in " << diskstats_path_;
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800620 line[nchars] = '\0';
621 nitems = sscanf(line, "%*d %*d %ld %*d %*d %*d %ld",
622 read_sectors, write_sectors);
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700623 if (nitems == 2) {
624 success = true;
625 } else {
626 LOG(WARNING) << "found " << nitems << " items in "
627 << diskstats_path_ << ", expected 2";
628 }
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800629 }
630 HANDLE_EINTR(close(file));
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700631 return success;
632}
633
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700634bool MetricsDaemon::VmStatsParseStats(const char* stats,
635 struct VmstatRecord* record) {
636 // a mapping of string name to field in VmstatRecord and whether we found it
637 struct mapping {
638 const string name;
639 uint64_t* value_p;
640 bool found;
641 } map[] =
642 { { .name = "pgmajfault",
643 .value_p = &record->page_faults_,
644 .found = false },
645 { .name = "pswpin",
646 .value_p = &record->swap_in_,
647 .found = false },
648 { .name = "pswpout",
649 .value_p = &record->swap_out_,
650 .found = false }, };
651
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700652 // Each line in the file has the form
653 // <ID> <VALUE>
654 // for instance:
655 // nr_free_pages 213427
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700656 vector<string> lines;
657 Tokenize(stats, "\n", &lines);
658 for (vector<string>::iterator it = lines.begin();
659 it != lines.end(); ++it) {
660 vector<string> tokens;
661 base::SplitString(*it, ' ', &tokens);
662 if (tokens.size() == 2) {
663 for (unsigned int i = 0; i < sizeof(map)/sizeof(struct mapping); i++) {
664 if (!tokens[0].compare(map[i].name)) {
665 if (!base::StringToUint64(tokens[1], map[i].value_p))
666 return false;
667 map[i].found = true;
668 }
669 }
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700670 } else {
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700671 LOG(WARNING) << "unexpected vmstat format";
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700672 }
673 }
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700674 // make sure we got all the stats
675 for (unsigned i = 0; i < sizeof(map)/sizeof(struct mapping); i++) {
676 if (map[i].found == false) {
677 LOG(WARNING) << "vmstat missing " << map[i].name;
678 return false;
679 }
680 }
681 return true;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700682}
683
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700684bool MetricsDaemon::VmStatsReadStats(struct VmstatRecord* stats) {
685 string value_string;
686 FilePath* path = new FilePath(vmstats_path_);
Ben Chan2e6543d2014-02-05 23:26:25 -0800687 if (!base::ReadFileToString(*path, &value_string)) {
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700688 delete path;
689 LOG(WARNING) << "cannot read " << vmstats_path_;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700690 return false;
691 }
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700692 delete path;
693 return VmStatsParseStats(value_string.c_str(), stats);
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800694}
695
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700696bool MetricsDaemon::ReadFreqToInt(const string& sysfs_file_name, int* value) {
Luigi Semenzatod92d18c2013-06-04 13:24:21 -0700697 const FilePath sysfs_path(sysfs_file_name);
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700698 string value_string;
Ben Chan2e6543d2014-02-05 23:26:25 -0800699 if (!base::ReadFileToString(sysfs_path, &value_string)) {
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700700 LOG(WARNING) << "cannot read " << sysfs_path.value().c_str();
701 return false;
702 }
Ben Chan2e6543d2014-02-05 23:26:25 -0800703 if (!base::RemoveChars(value_string, "\n", &value_string)) {
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700704 LOG(WARNING) << "no newline in " << value_string;
705 // Continue even though the lack of newline is suspicious.
706 }
707 if (!base::StringToInt(value_string, value)) {
708 LOG(WARNING) << "cannot convert " << value_string << " to int";
709 return false;
710 }
711 return true;
712}
713
714void MetricsDaemon::SendCpuThrottleMetrics() {
715 // |max_freq| is 0 only the first time through.
716 static int max_freq = 0;
717 if (max_freq == -1)
718 // Give up, as sysfs did not report max_freq correctly.
719 return;
720 if (max_freq == 0 || testing_) {
721 // One-time initialization of max_freq. (Every time when testing.)
722 if (!ReadFreqToInt(cpuinfo_max_freq_path_, &max_freq)) {
723 max_freq = -1;
724 return;
725 }
726 if (max_freq == 0) {
727 LOG(WARNING) << "sysfs reports 0 max CPU frequency\n";
728 max_freq = -1;
729 return;
730 }
731 if (max_freq % 10000 == 1000) {
732 // Special case: system has turbo mode, and max non-turbo frequency is
733 // max_freq - 1000. This relies on "normal" (non-turbo) frequencies
734 // being multiples of (at least) 10 MHz. Although there is no guarantee
735 // of this, it seems a fairly reasonable assumption. Otherwise we should
736 // read scaling_available_frequencies, sort the frequencies, compare the
737 // two highest ones, and check if they differ by 1000 (kHz) (and that's a
738 // hack too, no telling when it will change).
739 max_freq -= 1000;
740 }
741 }
742 int scaled_freq = 0;
743 if (!ReadFreqToInt(scaling_max_freq_path_, &scaled_freq))
744 return;
745 // Frequencies are in kHz. If scaled_freq > max_freq, turbo is on, but
746 // scaled_freq is not the actual turbo frequency. We indicate this situation
747 // with a 101% value.
748 int percent = scaled_freq > max_freq ? 101 : scaled_freq / (max_freq / 100);
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800749 SendLinearSample(kMetricScaledCpuFrequencyName, percent, 101, 102);
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700750}
751
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800752// static
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700753gboolean MetricsDaemon::StatsCallbackStatic(void* handle) {
754 (static_cast<MetricsDaemon*>(handle))->StatsCallback();
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800755 return false; // one-time callback
756}
757
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700758// Collects disk and vm stats alternating over a short and a long interval.
Luigi Semenzato8accd332011-05-17 16:37:18 -0700759
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700760void MetricsDaemon::StatsCallback() {
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700761 long int read_sectors_now, write_sectors_now;
762 struct VmstatRecord vmstats_now;
Luigi Semenzato8accd332011-05-17 16:37:18 -0700763 double time_now = GetActiveTime();
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700764 double delta_time = time_now - stats_initial_time_;
Luigi Semenzato8accd332011-05-17 16:37:18 -0700765 if (testing_) {
766 // Fake the time when testing.
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700767 delta_time = stats_state_ == kStatsShort ?
768 kMetricStatsShortInterval : kMetricStatsLongInterval;
Luigi Semenzato8accd332011-05-17 16:37:18 -0700769 }
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700770 bool diskstats_success = DiskStatsReadStats(&read_sectors_now,
771 &write_sectors_now);
Luigi Semenzato8accd332011-05-17 16:37:18 -0700772 int delta_read = read_sectors_now - read_sectors_;
773 int delta_write = write_sectors_now - write_sectors_;
774 int read_sectors_per_second = delta_read / delta_time;
775 int write_sectors_per_second = delta_write / delta_time;
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700776 bool vmstats_success = VmStatsReadStats(&vmstats_now);
777 uint64_t delta_faults = vmstats_now.page_faults_ - vmstats_.page_faults_;
778 uint64_t delta_swap_in = vmstats_now.swap_in_ - vmstats_.swap_in_;
779 uint64_t delta_swap_out = vmstats_now.swap_out_ - vmstats_.swap_out_;
780 uint64_t page_faults_per_second = delta_faults / delta_time;
781 uint64_t swap_in_per_second = delta_swap_in / delta_time;
782 uint64_t swap_out_per_second = delta_swap_out / delta_time;
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800783
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700784 switch (stats_state_) {
785 case kStatsShort:
786 if (diskstats_success) {
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800787 SendSample(kMetricReadSectorsShortName,
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700788 read_sectors_per_second,
789 1,
790 kMetricSectorsIOMax,
791 kMetricSectorsBuckets);
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800792 SendSample(kMetricWriteSectorsShortName,
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700793 write_sectors_per_second,
794 1,
795 kMetricSectorsIOMax,
796 kMetricSectorsBuckets);
797 }
798 if (vmstats_success) {
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800799 SendSample(kMetricPageFaultsShortName,
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700800 page_faults_per_second,
801 1,
802 kMetricPageFaultsMax,
803 kMetricPageFaultsBuckets);
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800804 SendSample(kMetricSwapInShortName,
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700805 swap_in_per_second,
806 1,
807 kMetricPageFaultsMax,
808 kMetricPageFaultsBuckets);
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800809 SendSample(kMetricSwapOutShortName,
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700810 swap_out_per_second,
811 1,
812 kMetricPageFaultsMax,
813 kMetricPageFaultsBuckets);
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700814 }
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800815 // Schedule long callback.
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700816 stats_state_ = kStatsLong;
817 ScheduleStatsCallback(kMetricStatsLongInterval -
818 kMetricStatsShortInterval);
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800819 break;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700820 case kStatsLong:
821 if (diskstats_success) {
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800822 SendSample(kMetricReadSectorsLongName,
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700823 read_sectors_per_second,
824 1,
825 kMetricSectorsIOMax,
826 kMetricSectorsBuckets);
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800827 SendSample(kMetricWriteSectorsLongName,
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700828 write_sectors_per_second,
829 1,
830 kMetricSectorsIOMax,
831 kMetricSectorsBuckets);
832 // Reset sector counters.
833 read_sectors_ = read_sectors_now;
834 write_sectors_ = write_sectors_now;
835 }
836 if (vmstats_success) {
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800837 SendSample(kMetricPageFaultsLongName,
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700838 page_faults_per_second,
839 1,
840 kMetricPageFaultsMax,
841 kMetricPageFaultsBuckets);
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800842 SendSample(kMetricSwapInLongName,
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700843 swap_in_per_second,
844 1,
845 kMetricPageFaultsMax,
846 kMetricPageFaultsBuckets);
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800847 SendSample(kMetricSwapOutLongName,
Sonny Rao4b8aebb2013-07-31 23:18:31 -0700848 swap_out_per_second,
849 1,
850 kMetricPageFaultsMax,
851 kMetricPageFaultsBuckets);
852
853 vmstats_ = vmstats_now;
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700854 }
Luigi Semenzatofb3a8212013-05-07 16:55:00 -0700855 SendCpuThrottleMetrics();
Luigi Semenzato8accd332011-05-17 16:37:18 -0700856 // Set start time for new cycle.
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700857 stats_initial_time_ = time_now;
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800858 // Schedule short callback.
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700859 stats_state_ = kStatsShort;
860 ScheduleStatsCallback(kMetricStatsShortInterval);
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800861 break;
862 default:
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700863 LOG(FATAL) << "Invalid stats state";
Luigi Semenzatoc88e42d2011-02-17 10:21:16 -0800864 }
865}
866
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700867void MetricsDaemon::ScheduleMeminfoCallback(int wait) {
868 if (testing_) {
869 return;
870 }
871 g_timeout_add_seconds(wait, MeminfoCallbackStatic, this);
872}
873
874// static
875gboolean MetricsDaemon::MeminfoCallbackStatic(void* handle) {
876 return (static_cast<MetricsDaemon*>(handle))->MeminfoCallback();
877}
878
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700879bool MetricsDaemon::MeminfoCallback() {
Luigi Semenzato8accd332011-05-17 16:37:18 -0700880 string meminfo_raw;
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700881 const FilePath meminfo_path("/proc/meminfo");
Ben Chan2e6543d2014-02-05 23:26:25 -0800882 if (!base::ReadFileToString(meminfo_path, &meminfo_raw)) {
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700883 LOG(WARNING) << "cannot read " << meminfo_path.value().c_str();
884 return false;
885 }
Luigi Semenzato8accd332011-05-17 16:37:18 -0700886 return ProcessMeminfo(meminfo_raw);
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700887}
888
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700889bool MetricsDaemon::ProcessMeminfo(const string& meminfo_raw) {
Luigi Semenzato8accd332011-05-17 16:37:18 -0700890 static const MeminfoRecord fields_array[] = {
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700891 { "MemTotal", "MemTotal" }, // SPECIAL CASE: total system memory
892 { "MemFree", "MemFree" },
893 { "Buffers", "Buffers" },
894 { "Cached", "Cached" },
895 // { "SwapCached", "SwapCached" },
896 { "Active", "Active" },
897 { "Inactive", "Inactive" },
898 { "ActiveAnon", "Active(anon)" },
899 { "InactiveAnon", "Inactive(anon)" },
900 { "ActiveFile" , "Active(file)" },
901 { "InactiveFile", "Inactive(file)" },
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800902 { "Unevictable", "Unevictable", kMeminfoOp_HistLog },
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700903 // { "Mlocked", "Mlocked" },
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800904 { "SwapTotal", "SwapTotal", kMeminfoOp_SwapTotal },
905 { "SwapFree", "SwapFree", kMeminfoOp_SwapFree },
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700906 // { "Dirty", "Dirty" },
907 // { "Writeback", "Writeback" },
908 { "AnonPages", "AnonPages" },
909 { "Mapped", "Mapped" },
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800910 { "Shmem", "Shmem", kMeminfoOp_HistLog },
911 { "Slab", "Slab", kMeminfoOp_HistLog },
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700912 // { "SReclaimable", "SReclaimable" },
913 // { "SUnreclaim", "SUnreclaim" },
914 };
Luigi Semenzato8accd332011-05-17 16:37:18 -0700915 vector<MeminfoRecord> fields(fields_array,
916 fields_array + arraysize(fields_array));
917 if (!FillMeminfo(meminfo_raw, &fields)) {
918 return false;
919 }
920 int total_memory = fields[0].value;
921 if (total_memory == 0) {
922 // this "cannot happen"
923 LOG(WARNING) << "borked meminfo parser";
924 return false;
925 }
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800926 int swap_total = 0;
927 int swap_free = 0;
Luigi Semenzato8accd332011-05-17 16:37:18 -0700928 // Send all fields retrieved, except total memory.
929 for (unsigned int i = 1; i < fields.size(); i++) {
Luigi Semenzato859b3f02014-02-05 15:33:19 -0800930 string metrics_name = base::StringPrintf("Platform.Meminfo%s",
931 fields[i].name);
Luigi Semenzato3ccca062013-02-04 19:50:45 -0800932 int percent;
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800933 switch (fields[i].op) {
934 case kMeminfoOp_HistPercent:
Luigi Semenzato3ccca062013-02-04 19:50:45 -0800935 // report value as percent of total memory
936 percent = fields[i].value * 100 / total_memory;
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800937 SendLinearSample(metrics_name, percent, 100, 101);
Luigi Semenzato3ccca062013-02-04 19:50:45 -0800938 break;
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800939 case kMeminfoOp_HistLog:
Luigi Semenzato3ccca062013-02-04 19:50:45 -0800940 // report value in kbytes, log scale, 4Gb max
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800941 SendSample(metrics_name, fields[i].value, 1, 4 * 1000 * 1000, 100);
Luigi Semenzato3ccca062013-02-04 19:50:45 -0800942 break;
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800943 case kMeminfoOp_SwapTotal:
944 swap_total = fields[i].value;
945 case kMeminfoOp_SwapFree:
946 swap_free = fields[i].value;
Luigi Semenzato3ccca062013-02-04 19:50:45 -0800947 break;
Luigi Semenzato8accd332011-05-17 16:37:18 -0700948 }
949 }
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800950 if (swap_total > 0) {
951 int swap_used = swap_total - swap_free;
952 int swap_used_percent = swap_used * 100 / swap_total;
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -0800953 SendSample("Platform.MeminfoSwapUsed", swap_used, 1, 8 * 1000 * 1000, 100);
954 SendLinearSample("Platform.MeminfoSwapUsedPercent", swap_used_percent,
Luigi Semenzato942cbab2013-02-12 13:17:07 -0800955 100, 101);
956 }
Luigi Semenzato8accd332011-05-17 16:37:18 -0700957 return true;
958}
959
Luigi Semenzato5bd764f2011-10-14 12:03:35 -0700960bool MetricsDaemon::FillMeminfo(const string& meminfo_raw,
961 vector<MeminfoRecord>* fields) {
Luigi Semenzato8accd332011-05-17 16:37:18 -0700962 vector<string> lines;
963 unsigned int nlines = Tokenize(meminfo_raw, "\n", &lines);
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700964
965 // Scan meminfo output and collect field values. Each field name has to
966 // match a meminfo entry (case insensitive) after removing non-alpha
967 // characters from the entry.
Luigi Semenzato8accd332011-05-17 16:37:18 -0700968 unsigned int ifield = 0;
969 for (unsigned int iline = 0;
970 iline < nlines && ifield < fields->size();
971 iline++) {
972 vector<string> tokens;
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700973 Tokenize(lines[iline], ": ", &tokens);
Luigi Semenzato8accd332011-05-17 16:37:18 -0700974 if (strcmp((*fields)[ifield].match, tokens[0].c_str()) == 0) {
975 // Name matches. Parse value and save.
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700976 char* rest;
Luigi Semenzato8accd332011-05-17 16:37:18 -0700977 (*fields)[ifield].value =
978 static_cast<int>(strtol(tokens[1].c_str(), &rest, 10));
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700979 if (*rest != '\0') {
980 LOG(WARNING) << "missing meminfo value";
981 return false;
982 }
Luigi Semenzato8accd332011-05-17 16:37:18 -0700983 ifield++;
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700984 }
Luigi Semenzato29c7ef92011-04-12 14:12:35 -0700985 }
Luigi Semenzato8accd332011-05-17 16:37:18 -0700986 if (ifield < fields->size()) {
987 // End of input reached while scanning.
988 LOG(WARNING) << "cannot find field " << (*fields)[ifield].match
989 << " and following";
990 return false;
991 }
992 return true;
993}
994
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -0800995void MetricsDaemon::ScheduleMemuseCallback(double interval) {
Luigi Semenzato8accd332011-05-17 16:37:18 -0700996 if (testing_) {
997 return;
998 }
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -0800999 g_timeout_add_seconds(interval, MemuseCallbackStatic, this);
Luigi Semenzato8accd332011-05-17 16:37:18 -07001000}
1001
1002// static
1003gboolean MetricsDaemon::MemuseCallbackStatic(void* handle) {
1004 MetricsDaemon* daemon = static_cast<MetricsDaemon*>(handle);
1005 daemon->MemuseCallback();
1006 return false;
1007}
1008
1009void MetricsDaemon::MemuseCallback() {
1010 // Since we only care about active time (i.e. uptime minus sleep time) but
1011 // the callbacks are driven by real time (uptime), we check if we should
1012 // reschedule this callback due to intervening sleep periods.
1013 double now = GetActiveTime();
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -08001014 // Avoid intervals of less than one second.
1015 double remaining_time = ceil(memuse_final_time_ - now);
1016 if (remaining_time > 0) {
1017 ScheduleMemuseCallback(remaining_time);
Luigi Semenzato8accd332011-05-17 16:37:18 -07001018 } else {
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -08001019 // Report stats and advance the measurement interval unless there are
1020 // errors or we've completed the last interval.
Luigi Semenzato8accd332011-05-17 16:37:18 -07001021 if (MemuseCallbackWork() &&
Luigi Semenzato0d9a9c92013-12-05 15:55:12 -08001022 memuse_interval_index_ < arraysize(kMemuseIntervals)) {
1023 double interval = kMemuseIntervals[memuse_interval_index_++];
1024 memuse_final_time_ = now + interval;
1025 ScheduleMemuseCallback(interval);
Luigi Semenzato8accd332011-05-17 16:37:18 -07001026 }
1027 }
1028}
1029
Luigi Semenzato5bd764f2011-10-14 12:03:35 -07001030bool MetricsDaemon::MemuseCallbackWork() {
Luigi Semenzato8accd332011-05-17 16:37:18 -07001031 string meminfo_raw;
1032 const FilePath meminfo_path("/proc/meminfo");
Ben Chan2e6543d2014-02-05 23:26:25 -08001033 if (!base::ReadFileToString(meminfo_path, &meminfo_raw)) {
Luigi Semenzato8accd332011-05-17 16:37:18 -07001034 LOG(WARNING) << "cannot read " << meminfo_path.value().c_str();
1035 return false;
1036 }
1037 return ProcessMemuse(meminfo_raw);
1038}
1039
Luigi Semenzato5bd764f2011-10-14 12:03:35 -07001040bool MetricsDaemon::ProcessMemuse(const string& meminfo_raw) {
Luigi Semenzato8accd332011-05-17 16:37:18 -07001041 static const MeminfoRecord fields_array[] = {
1042 { "MemTotal", "MemTotal" }, // SPECIAL CASE: total system memory
1043 { "ActiveAnon", "Active(anon)" },
1044 { "InactiveAnon", "Inactive(anon)" },
1045 };
1046 vector<MeminfoRecord> fields(fields_array,
1047 fields_array + arraysize(fields_array));
1048 if (!FillMeminfo(meminfo_raw, &fields)) {
1049 return false;
1050 }
1051 int total = fields[0].value;
1052 int active_anon = fields[1].value;
1053 int inactive_anon = fields[2].value;
1054 if (total == 0) {
1055 // this "cannot happen"
1056 LOG(WARNING) << "borked meminfo parser";
1057 return false;
1058 }
Luigi Semenzato859b3f02014-02-05 15:33:19 -08001059 string metrics_name = base::StringPrintf("Platform.MemuseAnon%d",
1060 memuse_interval_index_);
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -08001061 SendLinearSample(metrics_name, (active_anon + inactive_anon) * 100 / total,
Luigi Semenzato8accd332011-05-17 16:37:18 -07001062 100, 101);
1063 return true;
Luigi Semenzato29c7ef92011-04-12 14:12:35 -07001064}
1065
Darin Petkovf1e85e42010-06-10 15:59:53 -07001066// static
Luigi Semenzato859b3f02014-02-05 15:33:19 -08001067void MetricsDaemon::ReportDailyUse(void* handle, int count) {
Darin Petkov1bb904e2010-06-16 15:58:06 -07001068 if (count <= 0)
1069 return;
1070
Darin Petkovf1e85e42010-06-10 15:59:53 -07001071 MetricsDaemon* daemon = static_cast<MetricsDaemon*>(handle);
1072 int minutes = (count + kSecondsPerMinute / 2) / kSecondsPerMinute;
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -08001073 daemon->SendSample("Logging.DailyUseTime",
1074 minutes,
1075 1,
1076 kMinutesPerDay,
1077 50);
Darin Petkovf1e85e42010-06-10 15:59:53 -07001078}
1079
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -08001080void MetricsDaemon::SendSample(const string& name, int sample,
Darin Petkov11b8eb32010-05-18 11:00:59 -07001081 int min, int max, int nbuckets) {
Darin Petkovfc91b422010-05-12 13:05:45 -07001082 DLOG(INFO) << "received metric: " << name << " " << sample << " "
1083 << min << " " << max << " " << nbuckets;
1084 metrics_lib_->SendToUMA(name, sample, min, max, nbuckets);
Darin Petkov65b01462010-04-14 13:32:20 -07001085}
Luigi Semenzato29c7ef92011-04-12 14:12:35 -07001086
Luigi Semenzato2fd51cc2014-02-26 11:53:16 -08001087void MetricsDaemon::SendKernelCrashesCumulativeCountSample() {
1088 // Report the number of crashes for this OS version, but don't clear the
1089 // counter. It is cleared elsewhere on version change.
1090 SendSample(kernel_crashes_version_count_->Name(),
1091 kernel_crashes_version_count_->Get(),
1092 1, // value of first bucket
1093 500, // value of last bucket
1094 100); // number of buckets
1095}
1096
1097void MetricsDaemon::SendCrashIntervalSample(
1098 const scoped_ptr<PersistentInteger>& interval) {
1099 SendSample(interval->Name(),
1100 interval->GetAndClear(),
1101 1, // value of first bucket
1102 4 * kSecondsPerWeek, // value of last bucket
1103 50); // number of buckets
1104}
1105
1106void MetricsDaemon::SendCrashFrequencySample(
1107 const scoped_ptr<PersistentInteger>& frequency) {
1108 SendSample(frequency->Name(),
1109 frequency->GetAndClear(),
1110 1, // value of first bucket
1111 100, // value of last bucket
1112 50); // number of buckets
1113}
1114
1115void MetricsDaemon::SendLinearSample(const string& name, int sample,
Luigi Semenzato29c7ef92011-04-12 14:12:35 -07001116 int max, int nbuckets) {
1117 DLOG(INFO) << "received linear metric: " << name << " " << sample << " "
1118 << max << " " << nbuckets;
1119 // TODO(semenzato): add a proper linear histogram to the Chrome external
1120 // metrics API.
1121 LOG_IF(FATAL, nbuckets != max + 1) << "unsupported histogram scale";
1122 metrics_lib_->SendEnumToUMA(name, sample, max);
1123}