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 "content/browser/tracing/trace_controller_impl.h"
6
7#include "base/bind.h"
8#include "base/command_line.h"
9#include "base/debug/trace_event.h"
10#include "base/strings/string_number_conversions.h"
11#include "content/browser/tracing/trace_message_filter.h"
12#include "content/browser/tracing/trace_subscriber_stdio.h"
13#include "content/common/child_process_messages.h"
14#include "content/public/browser/browser_message_filter.h"
15#include "content/public/common/content_switches.h"
16
17using base::debug::TraceLog;
18
19namespace content {
20
21namespace {
22
23base::LazyInstance<TraceControllerImpl>::Leaky g_controller =
24    LAZY_INSTANCE_INITIALIZER;
25
26class AutoStopTraceSubscriberStdio : public TraceSubscriberStdio {
27 public:
28  AutoStopTraceSubscriberStdio(const base::FilePath& file_path)
29      : TraceSubscriberStdio(file_path) {}
30
31  static void EndStartupTrace(TraceSubscriberStdio* subscriber) {
32    if (!TraceControllerImpl::GetInstance()->EndTracingAsync(subscriber))
33      delete subscriber;
34    // else, the tracing will end asynchronously in OnEndTracingComplete().
35  }
36
37  virtual void OnEndTracingComplete() OVERRIDE {
38    TraceSubscriberStdio::OnEndTracingComplete();
39    delete this;
40    // TODO(joth): this would be the time to automatically open up
41    // chrome://tracing/ and load up the trace data collected.
42  }
43};
44
45}  // namespace
46
47TraceController* TraceController::GetInstance() {
48  return TraceControllerImpl::GetInstance();
49}
50
51TraceControllerImpl::TraceControllerImpl() :
52    subscriber_(NULL),
53    pending_end_ack_count_(0),
54    pending_bpf_ack_count_(0),
55    maximum_bpf_(0.0f),
56    is_tracing_(false),
57    is_get_category_groups_(false),
58    category_filter_(
59        base::debug::CategoryFilter::kDefaultCategoryFilterString) {
60  TraceLog::GetInstance()->SetNotificationCallback(
61      base::Bind(&TraceControllerImpl::OnTraceNotification,
62                 base::Unretained(this)));
63}
64
65TraceControllerImpl::~TraceControllerImpl() {
66  // No need to SetNotificationCallback(nil) on the TraceLog since this is a
67  // Leaky instance.
68  NOTREACHED();
69}
70
71TraceControllerImpl* TraceControllerImpl::GetInstance() {
72  return g_controller.Pointer();
73}
74
75void TraceControllerImpl::InitStartupTracing(const CommandLine& command_line) {
76  DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI));
77  base::FilePath trace_file = command_line.GetSwitchValuePath(
78      switches::kTraceStartupFile);
79  // trace_file = "none" means that startup events will show up for the next
80  // begin/end tracing (via about:tracing or AutomationProxy::BeginTracing/
81  // EndTracing, for example).
82  if (trace_file == base::FilePath().AppendASCII("none"))
83    return;
84
85  if (trace_file.empty()) {
86    // Default to saving the startup trace into the current dir.
87    trace_file = base::FilePath().AppendASCII("chrometrace.log");
88  }
89  scoped_ptr<AutoStopTraceSubscriberStdio> subscriber(
90      new AutoStopTraceSubscriberStdio(trace_file));
91  DCHECK(can_begin_tracing(subscriber.get()));
92
93  std::string delay_str = command_line.GetSwitchValueASCII(
94      switches::kTraceStartupDuration);
95  int delay_secs = 5;
96  if (!delay_str.empty() && !base::StringToInt(delay_str, &delay_secs)) {
97    DLOG(WARNING) << "Could not parse --" << switches::kTraceStartupDuration
98        << "=" << delay_str << " defaulting to 5 (secs)";
99    delay_secs = 5;
100  }
101
102  OnTracingBegan(subscriber.get());
103  BrowserThread::PostDelayedTask(
104      BrowserThread::UI,
105      FROM_HERE,
106      base::Bind(&AutoStopTraceSubscriberStdio::EndStartupTrace,
107                 base::Unretained(subscriber.release())),
108      base::TimeDelta::FromSeconds(delay_secs));
109}
110
111bool TraceControllerImpl::GetKnownCategoryGroupsAsync(
112    TraceSubscriber* subscriber) {
113  DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI));
114
115  // Known categories come back from child processes with the EndTracingAck
116  // message. So to get known categories, just begin and end tracing immediately
117  // afterwards. This will ping all the child processes for categories.
118  is_get_category_groups_ = true;
119  bool success = BeginTracing(subscriber, "*",
120                              TraceLog::GetInstance()->trace_options()) &&
121                 EndTracingAsync(subscriber);
122  is_get_category_groups_ = success;
123  return success;
124}
125
126bool TraceControllerImpl::BeginTracing(TraceSubscriber* subscriber,
127                                       const std::string& category_patterns,
128                                       base::debug::TraceLog::Options options) {
129  DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI));
130
131  if (!can_begin_tracing(subscriber))
132    return false;
133
134  // Enable tracing
135  TraceLog::GetInstance()->SetEnabled(
136      base::debug::CategoryFilter(category_patterns), options);
137
138  OnTracingBegan(subscriber);
139
140  return true;
141}
142
143bool TraceControllerImpl::EndTracingAsync(TraceSubscriber* subscriber) {
144  DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI));
145
146  if (!can_end_tracing() || subscriber != subscriber_)
147    return false;
148
149  // There could be a case where there are no child processes and filters_
150  // is empty. In that case we can immediately tell the subscriber that tracing
151  // has ended. To avoid recursive calls back to the subscriber, we will just
152  // use the existing asynchronous OnEndTracingAck code.
153  // Count myself (local trace) in pending_end_ack_count_, acked below.
154  pending_end_ack_count_ = filters_.size() + 1;
155
156  // Handle special case of zero child processes.
157  if (pending_end_ack_count_ == 1) {
158    // Ack asynchronously now, because we don't have any children to wait for.
159    std::vector<std::string> category_groups;
160    TraceLog::GetInstance()->GetKnownCategoryGroups(&category_groups);
161    BrowserThread::PostTask(BrowserThread::UI, FROM_HERE,
162        base::Bind(&TraceControllerImpl::OnEndTracingAck,
163                   base::Unretained(this), category_groups));
164  }
165
166  // Notify all child processes.
167  for (FilterMap::iterator it = filters_.begin(); it != filters_.end(); ++it) {
168    it->get()->SendEndTracing();
169  }
170
171  return true;
172}
173
174bool TraceControllerImpl::GetTraceBufferPercentFullAsync(
175    TraceSubscriber* subscriber) {
176  DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI));
177
178  if (!can_get_buffer_percent_full() || subscriber != subscriber_)
179    return false;
180
181  maximum_bpf_ = 0.0f;
182  pending_bpf_ack_count_ = filters_.size() + 1;
183
184  // Handle special case of zero child processes.
185  if (pending_bpf_ack_count_ == 1) {
186    // Ack asynchronously now, because we don't have any children to wait for.
187    float bpf = TraceLog::GetInstance()->GetBufferPercentFull();
188    BrowserThread::PostTask(BrowserThread::UI, FROM_HERE,
189        base::Bind(&TraceControllerImpl::OnTraceBufferPercentFullReply,
190                   base::Unretained(this), bpf));
191  }
192
193  // Message all child processes.
194  for (FilterMap::iterator it = filters_.begin(); it != filters_.end(); ++it) {
195    it->get()->SendGetTraceBufferPercentFull();
196  }
197
198  return true;
199}
200
201bool TraceControllerImpl::SetWatchEvent(TraceSubscriber* subscriber,
202                                        const std::string& category_name,
203                                        const std::string& event_name) {
204  DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI));
205  if (subscriber != subscriber_)
206    return false;
207
208  watch_category_ = category_name;
209  watch_name_ = event_name;
210
211  TraceLog::GetInstance()->SetWatchEvent(category_name, event_name);
212  for (FilterMap::iterator it = filters_.begin(); it != filters_.end(); ++it)
213    it->get()->SendSetWatchEvent(category_name, event_name);
214
215  return true;
216}
217
218bool TraceControllerImpl::CancelWatchEvent(TraceSubscriber* subscriber) {
219  DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI));
220  if (subscriber != subscriber_)
221    return false;
222
223  watch_category_.clear();
224  watch_name_.clear();
225
226  TraceLog::GetInstance()->CancelWatchEvent();
227  for (FilterMap::iterator it = filters_.begin(); it != filters_.end(); ++it)
228    it->get()->SendCancelWatchEvent();
229
230  return true;
231}
232
233void TraceControllerImpl::CancelSubscriber(TraceSubscriber* subscriber) {
234  DCHECK(BrowserThread::CurrentlyOn(BrowserThread::UI));
235
236  if (subscriber == subscriber_) {
237    subscriber_ = NULL;
238    // End tracing if necessary.
239    if (is_tracing_ && pending_end_ack_count_ == 0)
240      EndTracingAsync(NULL);
241  }
242}
243
244void TraceControllerImpl::AddFilter(TraceMessageFilter* filter) {
245  if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) {
246    BrowserThread::PostTask(BrowserThread::UI, FROM_HERE,
247        base::Bind(&TraceControllerImpl::AddFilter, base::Unretained(this),
248                   make_scoped_refptr(filter)));
249    return;
250  }
251
252  filters_.insert(filter);
253  if (is_tracing_enabled()) {
254    std::string cf_str = category_filter_.ToString();
255    filter->SendBeginTracing(cf_str, trace_options_);
256    if (!watch_category_.empty())
257      filter->SendSetWatchEvent(watch_category_, watch_name_);
258  }
259}
260
261void TraceControllerImpl::RemoveFilter(TraceMessageFilter* filter) {
262  if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) {
263    BrowserThread::PostTask(BrowserThread::UI, FROM_HERE,
264        base::Bind(&TraceControllerImpl::RemoveFilter, base::Unretained(this),
265                   make_scoped_refptr(filter)));
266    return;
267  }
268
269  filters_.erase(filter);
270}
271
272void TraceControllerImpl::OnTracingBegan(TraceSubscriber* subscriber) {
273  is_tracing_ = true;
274
275  subscriber_ = subscriber;
276
277  category_filter_ = TraceLog::GetInstance()->GetCurrentCategoryFilter();
278  trace_options_ = TraceLog::GetInstance()->trace_options();
279
280  // Notify all child processes.
281  for (FilterMap::iterator it = filters_.begin(); it != filters_.end(); ++it) {
282    it->get()->SendBeginTracing(category_filter_.ToString(), trace_options_);
283  }
284}
285
286void TraceControllerImpl::OnEndTracingAck(
287    const std::vector<std::string>& known_category_groups) {
288  if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) {
289    BrowserThread::PostTask(BrowserThread::UI, FROM_HERE,
290        base::Bind(&TraceControllerImpl::OnEndTracingAck,
291                   base::Unretained(this), known_category_groups));
292    return;
293  }
294
295  // Merge known_category_groups with known_category_groups_
296  known_category_groups_.insert(known_category_groups.begin(),
297                                known_category_groups.end());
298
299  if (pending_end_ack_count_ == 0)
300    return;
301
302  if (--pending_end_ack_count_ == 0) {
303    // All acks have been received.
304    is_tracing_ = false;
305
306    // Disable local trace.
307    TraceLog::GetInstance()->SetDisabled();
308
309    // During this call, our OnTraceDataCollected will be
310    // called with the last of the local trace data. Since we are on the UI
311    // thread, the call to OnTraceDataCollected will be synchronous, so we can
312    // immediately call OnEndTracingComplete below.
313    TraceLog::GetInstance()->Flush(
314        base::Bind(&TraceControllerImpl::OnTraceDataCollected,
315                   base::Unretained(this)));
316
317    // Trigger callback if one is set.
318    if (subscriber_) {
319      if (is_get_category_groups_)
320        subscriber_->OnKnownCategoriesCollected(known_category_groups_);
321      else
322        subscriber_->OnEndTracingComplete();
323      // Clear subscriber so that others can use TraceController.
324      subscriber_ = NULL;
325    }
326
327    is_get_category_groups_ = false;
328  }
329
330  if (pending_end_ack_count_ == 1) {
331    // The last ack represents local trace, so we need to ack it now. Note that
332    // this code only executes if there were child processes.
333    std::vector<std::string> category_groups;
334    TraceLog::GetInstance()->GetKnownCategoryGroups(&category_groups);
335    BrowserThread::PostTask(BrowserThread::UI, FROM_HERE,
336        base::Bind(&TraceControllerImpl::OnEndTracingAck,
337                   base::Unretained(this), category_groups));
338  }
339}
340
341void TraceControllerImpl::OnTraceDataCollected(
342    const scoped_refptr<base::RefCountedString>& events_str_ptr) {
343  // OnTraceDataCollected may be called from any browser thread, either by the
344  // local event trace system or from child processes via TraceMessageFilter.
345  if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) {
346    BrowserThread::PostTask(BrowserThread::UI, FROM_HERE,
347        base::Bind(&TraceControllerImpl::OnTraceDataCollected,
348                   base::Unretained(this), events_str_ptr));
349    return;
350  }
351
352  // Drop trace events if we are just getting categories.
353  if (subscriber_ && !is_get_category_groups_)
354    subscriber_->OnTraceDataCollected(events_str_ptr);
355}
356
357void TraceControllerImpl::OnTraceNotification(int notification) {
358  // OnTraceNotification may be called from any browser thread, either by the
359  // local event trace system or from child processes via TraceMessageFilter.
360  if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) {
361    BrowserThread::PostTask(BrowserThread::UI, FROM_HERE,
362        base::Bind(&TraceControllerImpl::OnTraceNotification,
363                   base::Unretained(this), notification));
364    return;
365  }
366
367  if (notification & base::debug::TraceLog::TRACE_BUFFER_FULL) {
368    // EndTracingAsync may return false if tracing is already in the process
369    // of being ended. That is ok.
370    EndTracingAsync(subscriber_);
371  }
372  if (notification & base::debug::TraceLog::EVENT_WATCH_NOTIFICATION) {
373    if (subscriber_)
374      subscriber_->OnEventWatchNotification();
375  }
376}
377
378void TraceControllerImpl::OnTraceBufferPercentFullReply(float percent_full) {
379  if (!BrowserThread::CurrentlyOn(BrowserThread::UI)) {
380    BrowserThread::PostTask(BrowserThread::UI, FROM_HERE,
381        base::Bind(&TraceControllerImpl::OnTraceBufferPercentFullReply,
382                   base::Unretained(this), percent_full));
383    return;
384  }
385
386  if (pending_bpf_ack_count_ == 0)
387    return;
388
389  maximum_bpf_ = (maximum_bpf_ > percent_full)? maximum_bpf_ : percent_full;
390
391  if (--pending_bpf_ack_count_ == 0) {
392    // Trigger callback if one is set.
393    if (subscriber_)
394      subscriber_->OnTraceBufferPercentFullReply(maximum_bpf_);
395  }
396
397  if (pending_bpf_ack_count_ == 1) {
398    // The last ack represents local trace, so we need to ack it now. Note that
399    // this code only executes if there were child processes.
400    float bpf = TraceLog::GetInstance()->GetBufferPercentFull();
401    BrowserThread::PostTask(BrowserThread::UI, FROM_HERE,
402        base::Bind(&TraceControllerImpl::OnTraceBufferPercentFullReply,
403                   base::Unretained(this), bpf));
404  }
405}
406
407}  // namespace content
408