external_metrics.cc revision 5821806d5e7f356e8fa4b058a389a808ea183019 
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 "chrome/browser/chromeos/external_metrics.h"
6
7#include <fcntl.h>
8#include <stdio.h>
9#include <stdlib.h>
10#include <string.h>
11#include <sys/file.h>
12#include <sys/stat.h>
13#include <sys/types.h>
14#include <unistd.h>
15
16#include <string>
17
18#include "base/basictypes.h"
19#include "base/bind.h"
20#include "base/eintr_wrapper.h"
21#include "base/metrics/histogram.h"
22#include "base/metrics/statistics_recorder.h"
23#include "base/perftimer.h"
24#include "base/time.h"
25#include "chrome/browser/browser_process.h"
26#include "chrome/browser/metrics/metrics_service.h"
27#include "content/public/browser/browser_thread.h"
28#include "content/public/browser/user_metrics.h"
29
30using content::BrowserThread;
31using content::UserMetricsAction;
32
33namespace chromeos {
34
35namespace {
36
37bool CheckValues(const std::string& name,
38                 int minimum,
39                 int maximum,
40                 size_t bucket_count) {
41  if (!base::Histogram::InspectConstructionArguments(
42      name, &minimum, &maximum, &bucket_count))
43    return false;
44  base::HistogramBase* histogram =
45      base::StatisticsRecorder::FindHistogram(name);
46  if (!histogram)
47    return true;
48  return histogram->HasConstructionArguments(minimum, maximum, bucket_count);
49}
50
51bool CheckLinearValues(const std::string& name, int maximum) {
52  return CheckValues(name, 1, maximum, maximum + 1);
53}
54
55}  // namespace
56
57// The interval between external metrics collections in seconds
58static const int kExternalMetricsCollectionIntervalSeconds = 30;
59
60ExternalMetrics::ExternalMetrics()
61    : test_recorder_(NULL) {
62}
63
64ExternalMetrics::~ExternalMetrics() {}
65
66void ExternalMetrics::Start() {
67  // Register user actions external to the browser.
68  // chrome/tools/extract_actions.py won't understand these lines, so all of
69  // these are explicitly added in that script.
70  // TODO(derat): We shouldn't need to verify actions before reporting them;
71  // remove all of this once http://crosbug.com/11125 is fixed.
72  valid_user_actions_.insert("Cryptohome.PKCS11InitFail");
73  valid_user_actions_.insert("Updater.ServerCertificateChanged");
74  valid_user_actions_.insert("Updater.ServerCertificateFailed");
75
76  ScheduleCollector();
77}
78
79void ExternalMetrics::RecordActionUI(std::string action_string) {
80  if (valid_user_actions_.count(action_string)) {
81    content::RecordComputedAction(action_string);
82  } else {
83    LOG(ERROR) << "undefined UMA action: " << action_string;
84  }
85}
86
87void ExternalMetrics::RecordAction(const char* action) {
88  std::string action_string(action);
89  BrowserThread::PostTask(
90      BrowserThread::UI, FROM_HERE,
91      base::Bind(&ExternalMetrics::RecordActionUI, this, action_string));
92}
93
94void ExternalMetrics::RecordCrashUI(const std::string& crash_kind) {
95  if (g_browser_process && g_browser_process->metrics_service()) {
96    g_browser_process->metrics_service()->LogChromeOSCrash(crash_kind);
97  }
98}
99
100void ExternalMetrics::RecordCrash(const std::string& crash_kind) {
101  BrowserThread::PostTask(
102      BrowserThread::UI, FROM_HERE,
103      base::Bind(&ExternalMetrics::RecordCrashUI, this, crash_kind));
104}
105
106void ExternalMetrics::RecordHistogram(const char* histogram_data) {
107  int sample, min, max, nbuckets;
108  char name[128];   // length must be consistent with sscanf format below.
109  int n = sscanf(histogram_data, "%127s %d %d %d %d",
110                 name, &sample, &min, &max, &nbuckets);
111  if (n != 5) {
112    LOG(ERROR) << "bad histogram request: " << histogram_data;
113    return;
114  }
115
116  if (!CheckValues(name, min, max, nbuckets)) {
117    LOG(ERROR) << "Invalid histogram " << name
118               << ", min=" << min
119               << ", max=" << max
120               << ", nbuckets=" << nbuckets;
121    return;
122  }
123  // Do not use the UMA_HISTOGRAM_... macros here.  They cache the Histogram
124  // instance and thus only work if |name| is constant.
125  base::Histogram* counter = base::Histogram::FactoryGet(
126      name, min, max, nbuckets, base::Histogram::kUmaTargetedHistogramFlag);
127  counter->Add(sample);
128}
129
130void ExternalMetrics::RecordLinearHistogram(const char* histogram_data) {
131  int sample, max;
132  char name[128];   // length must be consistent with sscanf format below.
133  int n = sscanf(histogram_data, "%127s %d %d", name, &sample, &max);
134  if (n != 3) {
135    LOG(ERROR) << "bad linear histogram request: " << histogram_data;
136    return;
137  }
138
139  if (!CheckLinearValues(name, max)) {
140    LOG(ERROR) << "Invalid linear histogram " << name
141               << ", max=" << max;
142    return;
143  }
144  // Do not use the UMA_HISTOGRAM_... macros here.  They cache the Histogram
145  // instance and thus only work if |name| is constant.
146  base::Histogram* counter = base::LinearHistogram::FactoryGet(
147      name, 1, max, max + 1, base::Histogram::kUmaTargetedHistogramFlag);
148  counter->Add(sample);
149}
150
151void ExternalMetrics::CollectEvents() {
152  const char* event_file_path = "/var/log/metrics/uma-events";
153  struct stat stat_buf;
154  int result;
155  if (!test_path_.empty()) {
156    event_file_path = test_path_.value().c_str();
157  }
158  result = stat(event_file_path, &stat_buf);
159  if (result < 0) {
160    if (errno != ENOENT) {
161      PLOG(ERROR) << event_file_path << ": bad metrics file stat";
162    }
163    // Nothing to collect---try later.
164    return;
165  }
166  if (stat_buf.st_size == 0) {
167    // Also nothing to collect.
168    return;
169  }
170  int fd = open(event_file_path, O_RDWR);
171  if (fd < 0) {
172    PLOG(ERROR) << event_file_path << ": cannot open";
173    return;
174  }
175  result = flock(fd, LOCK_EX);
176  if (result < 0) {
177    PLOG(ERROR) << event_file_path << ": cannot lock";
178    close(fd);
179    return;
180  }
181  // This processes all messages in the log.  Each message starts with a 4-byte
182  // field containing the length of the entire message.  The length is followed
183  // by a name-value pair of null-terminated strings.  When all messages are
184  // read and processed, or an error occurs, truncate the file to zero size.
185  for (;;) {
186    int32 message_size;
187    result = HANDLE_EINTR(read(fd, &message_size, sizeof(message_size)));
188    if (result < 0) {
189      PLOG(ERROR) << "reading metrics message header";
190      break;
191    }
192    if (result == 0) {  // normal EOF
193      break;
194    }
195    if (result < static_cast<int>(sizeof(message_size))) {
196      LOG(ERROR) << "bad read size " << result <<
197                    ", expecting " << sizeof(message_size);
198      break;
199    }
200    // kMetricsMessageMaxLength applies to the entire message: the 4-byte
201    // length field and the two null-terminated strings.
202    if (message_size < 2 + static_cast<int>(sizeof(message_size)) ||
203        message_size > static_cast<int>(kMetricsMessageMaxLength)) {
204      LOG(ERROR) << "bad message size " << message_size;
205      break;
206    }
207    message_size -= sizeof(message_size);  // already read this much
208    uint8 buffer[kMetricsMessageMaxLength];
209    result = HANDLE_EINTR(read(fd, buffer, message_size));
210    if (result < 0) {
211      PLOG(ERROR) << "reading metrics message body";
212      break;
213    }
214    if (result < message_size) {
215      LOG(ERROR) << "message too short: length " << result <<
216                    ", expected " << message_size;
217      break;
218    }
219    // The buffer should now contain a pair of null-terminated strings.
220    uint8* p = reinterpret_cast<uint8*>(memchr(buffer, '\0', message_size));
221    uint8* q = NULL;
222    if (p != NULL) {
223      q = reinterpret_cast<uint8*>(
224        memchr(p + 1, '\0', message_size - (p + 1 - buffer)));
225    }
226    if (q == NULL) {
227      LOG(ERROR) << "bad name-value pair for metrics";
228      break;
229    } else {
230      char* name = reinterpret_cast<char*>(buffer);
231      char* value = reinterpret_cast<char*>(p + 1);
232      if (test_recorder_ != NULL) {
233        test_recorder_(name, value);
234      } else if (strcmp(name, "crash") == 0) {
235        RecordCrash(value);
236      } else if (strcmp(name, "histogram") == 0) {
237        RecordHistogram(value);
238      } else if (strcmp(name, "linearhistogram") == 0) {
239        RecordLinearHistogram(value);
240      } else if (strcmp(name, "useraction") == 0) {
241        RecordAction(value);
242      } else {
243        LOG(ERROR) << "invalid event type: " << name;
244      }
245    }
246  }
247
248  result = ftruncate(fd, 0);
249  if (result < 0) {
250    PLOG(ERROR) << "truncate metrics log";
251  }
252  result = flock(fd, LOCK_UN);
253  if (result < 0) {
254    PLOG(ERROR) << "unlock metrics log";
255  }
256  result = close(fd);
257  if (result < 0) {
258    PLOG(ERROR) << "close metrics log";
259  }
260}
261
262void ExternalMetrics::CollectEventsAndReschedule() {
263  PerfTimer timer;
264  CollectEvents();
265  UMA_HISTOGRAM_TIMES("UMA.CollectExternalEventsTime", timer.Elapsed());
266  ScheduleCollector();
267}
268
269void ExternalMetrics::ScheduleCollector() {
270  bool result;
271  result = BrowserThread::PostDelayedTask(
272    BrowserThread::FILE, FROM_HERE,
273    base::Bind(&chromeos::ExternalMetrics::CollectEventsAndReschedule, this),
274    base::TimeDelta::FromSeconds(kExternalMetricsCollectionIntervalSeconds));
275  DCHECK(result);
276}
277
278}  // namespace chromeos
279