perf_provider_chromeos.cc revision 1320f92c476a1ad9d19dba2a48c72b75566198e9
1// Copyright (c) 2012 The Chromium Authors. All rights reserved.
2// Use of this source code is governed by a BSD-style license that can be
3// found in the LICENSE file.
4
5#include <string>
6
7#include "base/bind.h"
8#include "base/bind_helpers.h"
9#include "base/callback.h"
10#include "base/command_line.h"
11#include "base/compiler_specific.h"
12#include "base/metrics/histogram.h"
13#include "base/rand_util.h"
14#include "base/strings/string_number_conversions.h"
15#include "base/threading/sequenced_worker_pool.h"
16#include "chrome/browser/chrome_notification_types.h"
17#include "chrome/browser/metrics/perf_provider_chromeos.h"
18#include "chrome/browser/profiles/profile.h"
19#include "chrome/browser/ui/browser.h"
20#include "chrome/browser/ui/browser_list.h"
21#include "chrome/browser/ui/browser_list_observer.h"
22#include "chrome/common/chrome_switches.h"
23#include "chromeos/dbus/dbus_thread_manager.h"
24#include "chromeos/dbus/debug_daemon_client.h"
25#include "content/public/browser/notification_service.h"
26
27namespace {
28
29// Partition time since login into successive intervals of this size. In each
30// interval, pick a random time to collect a profile.
31const size_t kPerfProfilingIntervalMs = 3 * 60 * 60 * 1000;
32
33// Default time in seconds perf is run for.
34const size_t kPerfCommandDurationDefaultSeconds = 2;
35
36// Limit the total size of protobufs that can be cached, so they don't take up
37// too much memory. If the size of cached protobufs exceeds this value, stop
38// collecting further perf data. The current value is 4 MB.
39const size_t kCachedPerfDataProtobufSizeThreshold = 4 * 1024 * 1024;
40
41// There may be too many suspends to collect a profile each time there is a
42// resume. To limit the number of profiles, collect one for 1 in 10 resumes.
43// Adjust this number as needed.
44const int kResumeSamplingFactor = 10;
45
46// There may be too many session restores to collect a profile each time. Limit
47// the collection rate by collecting one per 10 restores. Adjust this number as
48// needed.
49const int kRestoreSessionSamplingFactor = 10;
50
51// This is used to space out session restore collections in the face of several
52// notifications in a short period of time. There should be no less than this
53// much time between collections. The current value is 30 seconds.
54const int kMinIntervalBetweenSessionRestoreCollectionsMs = 30 * 1000;
55
56// If collecting after a resume, add a random delay before collecting. The delay
57// should be randomly selected between 0 and this value. Currently the value is
58// equal to 5 seconds.
59const int kMaxResumeCollectionDelayMs = 5 * 1000;
60
61// If collecting after a session restore, add a random delay before collecting.
62// The delay should be randomly selected between 0 and this value. Currently the
63// value is equal to 10 seconds.
64const int kMaxRestoreSessionCollectionDelayMs = 10 * 1000;
65
66// Enumeration representing success and various failure modes for collecting and
67// sending perf data.
68enum GetPerfDataOutcome {
69  SUCCESS,
70  NOT_READY_TO_UPLOAD,
71  NOT_READY_TO_COLLECT,
72  INCOGNITO_ACTIVE,
73  INCOGNITO_LAUNCHED,
74  PROTOBUF_NOT_PARSED,
75  NUM_OUTCOMES
76};
77
78// Name of the histogram that represents the success and various failure modes
79// for collecting and sending perf data.
80const char kGetPerfDataOutcomeHistogram[] = "UMA.Perf.GetData";
81
82void AddToPerfHistogram(GetPerfDataOutcome outcome) {
83  UMA_HISTOGRAM_ENUMERATION(kGetPerfDataOutcomeHistogram,
84                            outcome,
85                            NUM_OUTCOMES);
86}
87
88// Returns true if a normal user is logged in. Returns false otherwise (e.g. if
89// logged in as a guest or as a kiosk app).
90bool IsNormalUserLoggedIn() {
91  return chromeos::LoginState::Get()->IsUserAuthenticated();
92}
93
94}  // namespace
95
96
97namespace metrics {
98
99// This class must be created and used on the UI thread. It watches for any
100// incognito window being opened from the time it is instantiated to the time it
101// is destroyed.
102class WindowedIncognitoObserver : public chrome::BrowserListObserver {
103 public:
104  WindowedIncognitoObserver() : incognito_launched_(false) {
105    BrowserList::AddObserver(this);
106  }
107
108  virtual ~WindowedIncognitoObserver() {
109    BrowserList::RemoveObserver(this);
110  }
111
112  // This method can be checked to see whether any incognito window has been
113  // opened since the time this object was created.
114  bool incognito_launched() {
115    return incognito_launched_;
116  }
117
118 private:
119  // chrome::BrowserListObserver implementation.
120  virtual void OnBrowserAdded(Browser* browser) OVERRIDE {
121    if (browser->profile()->IsOffTheRecord())
122      incognito_launched_ = true;
123  }
124
125  bool incognito_launched_;
126};
127
128PerfProvider::PerfProvider()
129      : login_observer_(this),
130        next_profiling_interval_start_(base::TimeTicks::Now()),
131        weak_factory_(this) {
132  // Register the login observer with LoginState.
133  chromeos::LoginState::Get()->AddObserver(&login_observer_);
134
135  // Register as an observer of power manager events.
136  chromeos::DBusThreadManager::Get()->GetPowerManagerClient()->
137      AddObserver(this);
138
139  // Register as an observer of session restore.
140  // TODO(sque): clean this up to use something other than notifications.
141  session_restore_registrar_.Add(
142      this,
143      chrome::NOTIFICATION_SESSION_RESTORE_DONE,
144      content::NotificationService::AllBrowserContextsAndSources());
145
146  // Check the login state. At the time of writing, this class is instantiated
147  // before login. A subsequent login would activate the profiling. However,
148  // that behavior may change in the future so that the user is already logged
149  // when this class is instantiated. By calling LoggedInStateChanged() here,
150  // PerfProvider will recognize that the system is already logged in.
151  login_observer_.LoggedInStateChanged();
152}
153
154PerfProvider::~PerfProvider() {
155  chromeos::LoginState::Get()->RemoveObserver(&login_observer_);
156}
157
158bool PerfProvider::GetSampledProfiles(
159    std::vector<SampledProfile>* sampled_profiles) {
160  DCHECK(CalledOnValidThread());
161  if (cached_perf_data_.empty()) {
162    AddToPerfHistogram(NOT_READY_TO_UPLOAD);
163    return false;
164  }
165
166  sampled_profiles->swap(cached_perf_data_);
167  cached_perf_data_.clear();
168
169  AddToPerfHistogram(SUCCESS);
170  return true;
171}
172
173PerfProvider::LoginObserver::LoginObserver(PerfProvider* perf_provider)
174    : perf_provider_(perf_provider) {}
175
176void PerfProvider::LoginObserver::LoggedInStateChanged() {
177  if (IsNormalUserLoggedIn())
178    perf_provider_->OnUserLoggedIn();
179  else
180    perf_provider_->Deactivate();
181}
182
183void PerfProvider::SuspendDone(const base::TimeDelta& sleep_duration) {
184  // A zero value for the suspend duration indicates that the suspend was
185  // canceled. Do not collect anything if that's the case.
186  if (sleep_duration == base::TimeDelta())
187    return;
188
189  // Do not collect a profile unless logged in. The system behavior when closing
190  // the lid or idling when not logged in is currently to shut down instead of
191  // suspending. But it's good to enforce the rule here in case that changes.
192  if (!IsNormalUserLoggedIn())
193    return;
194
195  // Collect a profile only 1/|kResumeSamplingFactor| of the time, to avoid
196  // collecting too much data.
197  if (base::RandGenerator(kResumeSamplingFactor) != 0)
198    return;
199
200  // Override any existing profiling.
201  if (timer_.IsRunning())
202    timer_.Stop();
203
204  // Randomly pick a delay before doing the collection.
205  base::TimeDelta collection_delay =
206      base::TimeDelta::FromMilliseconds(
207          base::RandGenerator(kMaxResumeCollectionDelayMs));
208  timer_.Start(FROM_HERE,
209               collection_delay,
210               base::Bind(&PerfProvider::CollectPerfDataAfterResume,
211                          weak_factory_.GetWeakPtr(),
212                          sleep_duration,
213                          collection_delay));
214}
215
216void PerfProvider::Observe(int type,
217                           const content::NotificationSource& source,
218                           const content::NotificationDetails& details) {
219  // Only handle session restore notifications.
220  DCHECK_EQ(type, chrome::NOTIFICATION_SESSION_RESTORE_DONE);
221
222  // Do not collect a profile unless logged in as a normal user.
223  if (!IsNormalUserLoggedIn())
224    return;
225
226  // Collect a profile only 1/|kRestoreSessionSamplingFactor| of the time, to
227  // avoid collecting too much data and potentially causing UI latency.
228  if (base::RandGenerator(kRestoreSessionSamplingFactor) != 0)
229    return;
230
231  const base::TimeDelta min_interval =
232      base::TimeDelta::FromMilliseconds(
233          kMinIntervalBetweenSessionRestoreCollectionsMs);
234  const base::TimeDelta time_since_last_collection =
235      (base::TimeTicks::Now() - last_session_restore_collection_time_);
236  // Do not collect if there hasn't been enough elapsed time since the last
237  // collection.
238  if (!last_session_restore_collection_time_.is_null() &&
239      time_since_last_collection < min_interval) {
240    return;
241  }
242
243  // Stop any existing scheduled collection.
244  if (timer_.IsRunning())
245    timer_.Stop();
246
247  // Randomly pick a delay before doing the collection.
248  base::TimeDelta collection_delay =
249      base::TimeDelta::FromMilliseconds(
250          base::RandGenerator(kMaxRestoreSessionCollectionDelayMs));
251  timer_.Start(
252      FROM_HERE,
253      collection_delay,
254      base::Bind(&PerfProvider::CollectPerfDataAfterSessionRestore,
255                 weak_factory_.GetWeakPtr(),
256                 collection_delay));
257}
258
259void PerfProvider::OnUserLoggedIn() {
260  login_time_ = base::TimeTicks::Now();
261  ScheduleIntervalCollection();
262}
263
264void PerfProvider::Deactivate() {
265  // Stop the timer, but leave |cached_perf_data_| intact.
266  timer_.Stop();
267}
268
269void PerfProvider::ScheduleIntervalCollection() {
270  DCHECK(CalledOnValidThread());
271  if (timer_.IsRunning())
272    return;
273
274  // Pick a random time in the current interval.
275  base::TimeTicks scheduled_time =
276      next_profiling_interval_start_ +
277      base::TimeDelta::FromMilliseconds(
278          base::RandGenerator(kPerfProfilingIntervalMs));
279
280  // If the scheduled time has already passed in the time it took to make the
281  // above calculations, trigger the collection event immediately.
282  base::TimeTicks now = base::TimeTicks::Now();
283  if (scheduled_time < now)
284    scheduled_time = now;
285
286  timer_.Start(FROM_HERE, scheduled_time - now, this,
287               &PerfProvider::DoPeriodicCollection);
288
289  // Update the profiling interval tracker to the start of the next interval.
290  next_profiling_interval_start_ +=
291      base::TimeDelta::FromMilliseconds(kPerfProfilingIntervalMs);
292}
293
294void PerfProvider::CollectIfNecessary(
295    scoped_ptr<SampledProfile> sampled_profile) {
296  DCHECK(CalledOnValidThread());
297
298  // Schedule another interval collection. This call makes sense regardless of
299  // whether or not the current collection was interval-triggered. If it had
300  // been another type of trigger event, the interval timer would have been
301  // halted, so it makes sense to reschedule a new interval collection.
302  ScheduleIntervalCollection();
303
304  // Do not collect further data if we've already collected a substantial amount
305  // of data, as indicated by |kCachedPerfDataProtobufSizeThreshold|.
306  size_t cached_perf_data_size = 0;
307  for (size_t i = 0; i < cached_perf_data_.size(); ++i) {
308    cached_perf_data_size += cached_perf_data_[i].ByteSize();
309  }
310  if (cached_perf_data_size >= kCachedPerfDataProtobufSizeThreshold) {
311    AddToPerfHistogram(NOT_READY_TO_COLLECT);
312    return;
313  }
314
315  // For privacy reasons, Chrome should only collect perf data if there is no
316  // incognito session active (or gets spawned during the collection).
317  if (BrowserList::IsOffTheRecordSessionActive()) {
318    AddToPerfHistogram(INCOGNITO_ACTIVE);
319    return;
320  }
321
322  scoped_ptr<WindowedIncognitoObserver> incognito_observer(
323      new WindowedIncognitoObserver);
324
325  chromeos::DebugDaemonClient* client =
326      chromeos::DBusThreadManager::Get()->GetDebugDaemonClient();
327
328  base::TimeDelta collection_duration = base::TimeDelta::FromSeconds(
329      kPerfCommandDurationDefaultSeconds);
330
331  client->GetPerfData(collection_duration.InSeconds(),
332                      base::Bind(&PerfProvider::ParseProtoIfValid,
333                                 weak_factory_.GetWeakPtr(),
334                                 base::Passed(&incognito_observer),
335                                 base::Passed(&sampled_profile)));
336}
337
338void PerfProvider::DoPeriodicCollection() {
339  scoped_ptr<SampledProfile> sampled_profile(new SampledProfile);
340  sampled_profile->set_trigger_event(SampledProfile::PERIODIC_COLLECTION);
341
342  CollectIfNecessary(sampled_profile.Pass());
343}
344
345void PerfProvider::CollectPerfDataAfterResume(
346    const base::TimeDelta& sleep_duration,
347    const base::TimeDelta& time_after_resume) {
348  // Fill out a SampledProfile protobuf that will contain the collected data.
349  scoped_ptr<SampledProfile> sampled_profile(new SampledProfile);
350  sampled_profile->set_trigger_event(SampledProfile::RESUME_FROM_SUSPEND);
351  sampled_profile->set_suspend_duration_ms(sleep_duration.InMilliseconds());
352  sampled_profile->set_ms_after_resume(time_after_resume.InMilliseconds());
353
354  CollectIfNecessary(sampled_profile.Pass());
355}
356
357void PerfProvider::CollectPerfDataAfterSessionRestore(
358    const base::TimeDelta& time_after_restore) {
359  // Fill out a SampledProfile protobuf that will contain the collected data.
360  scoped_ptr<SampledProfile> sampled_profile(new SampledProfile);
361  sampled_profile->set_trigger_event(SampledProfile::RESTORE_SESSION);
362  sampled_profile->set_ms_after_restore(time_after_restore.InMilliseconds());
363
364  CollectIfNecessary(sampled_profile.Pass());
365  last_session_restore_collection_time_ = base::TimeTicks::Now();
366}
367
368void PerfProvider::ParseProtoIfValid(
369    scoped_ptr<WindowedIncognitoObserver> incognito_observer,
370    scoped_ptr<SampledProfile> sampled_profile,
371    const std::vector<uint8>& data) {
372  DCHECK(CalledOnValidThread());
373
374  if (incognito_observer->incognito_launched()) {
375    AddToPerfHistogram(INCOGNITO_LAUNCHED);
376    return;
377  }
378
379  PerfDataProto perf_data_proto;
380  if (!perf_data_proto.ParseFromArray(data.data(), data.size())) {
381    AddToPerfHistogram(PROTOBUF_NOT_PARSED);
382    return;
383  }
384
385  // Populate a profile collection protobuf with the collected perf data and
386  // extra metadata.
387  cached_perf_data_.resize(cached_perf_data_.size() + 1);
388  SampledProfile& collection_data = cached_perf_data_.back();
389  collection_data.Swap(sampled_profile.get());
390
391  // Fill out remaining fields of the SampledProfile protobuf.
392  collection_data.set_ms_after_boot(
393      perf_data_proto.timestamp_sec() * base::Time::kMillisecondsPerSecond);
394
395  DCHECK(!login_time_.is_null());
396  collection_data.
397      set_ms_after_login((base::TimeTicks::Now() - login_time_)
398          .InMilliseconds());
399
400  // Finally, store the perf data itself.
401  collection_data.mutable_perf_data()->Swap(&perf_data_proto);
402}
403
404}  // namespace metrics
405