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 "base/trace_event/trace_event_impl.h"
6
7#include <fcntl.h>
8#include <stddef.h>
9#include <stdint.h>
10
11#include "base/format_macros.h"
12#include "base/logging.h"
13#include "base/posix/eintr_wrapper.h"
14#include "base/strings/stringprintf.h"
15#include "base/synchronization/waitable_event.h"
16#include "base/threading/thread.h"
17#include "base/trace_event/trace_event.h"
18
19namespace base {
20namespace trace_event {
21
22namespace {
23
24int g_atrace_fd = -1;
25const char kATraceMarkerFile[] = "/sys/kernel/debug/tracing/trace_marker";
26
27void WriteToATrace(int fd, const char* buffer, size_t size) {
28  size_t total_written = 0;
29  while (total_written < size) {
30    ssize_t written = HANDLE_EINTR(write(
31        fd, buffer + total_written, size - total_written));
32    if (written <= 0)
33      break;
34    total_written += written;
35  }
36  if (total_written < size) {
37    PLOG(WARNING) << "Failed to write buffer '" << std::string(buffer, size)
38                  << "' to " << kATraceMarkerFile;
39  }
40}
41
42void WriteEvent(
43    char phase,
44    const char* category_group,
45    const char* name,
46    unsigned long long id,
47    const char** arg_names,
48    const unsigned char* arg_types,
49    const TraceEvent::TraceValue* arg_values,
50    const std::unique_ptr<ConvertableToTraceFormat>* convertable_values,
51    unsigned int flags) {
52  std::string out = StringPrintf("%c|%d|%s", phase, getpid(), name);
53  if (flags & TRACE_EVENT_FLAG_HAS_ID)
54    StringAppendF(&out, "-%" PRIx64, static_cast<uint64_t>(id));
55  out += '|';
56
57  for (int i = 0; i < kTraceMaxNumArgs && arg_names[i];
58       ++i) {
59    if (i)
60      out += ';';
61    out += arg_names[i];
62    out += '=';
63    std::string::size_type value_start = out.length();
64    if (arg_types[i] == TRACE_VALUE_TYPE_CONVERTABLE)
65      convertable_values[i]->AppendAsTraceFormat(&out);
66    else
67      TraceEvent::AppendValueAsJSON(arg_types[i], arg_values[i], &out);
68
69    // Remove the quotes which may confuse the atrace script.
70    ReplaceSubstringsAfterOffset(&out, value_start, "\\\"", "'");
71    ReplaceSubstringsAfterOffset(&out, value_start, "\"", "");
72    // Replace chars used for separators with similar chars in the value.
73    std::replace(out.begin() + value_start, out.end(), ';', ',');
74    std::replace(out.begin() + value_start, out.end(), '|', '!');
75  }
76
77  out += '|';
78  out += category_group;
79  WriteToATrace(g_atrace_fd, out.c_str(), out.size());
80}
81
82void NoOpOutputCallback(WaitableEvent* complete_event,
83                        const scoped_refptr<RefCountedString>&,
84                        bool has_more_events) {
85  if (!has_more_events)
86    complete_event->Signal();
87}
88
89void EndChromeTracing(TraceLog* trace_log,
90                      WaitableEvent* complete_event) {
91  trace_log->SetDisabled();
92  // Delete the buffered trace events as they have been sent to atrace.
93  trace_log->Flush(Bind(&NoOpOutputCallback, complete_event));
94}
95
96}  // namespace
97
98// These functions support Android systrace.py when 'webview' category is
99// traced. With the new adb_profile_chrome, we may have two phases:
100// - before WebView is ready for combined tracing, we can use adb_profile_chrome
101//   to trace android categories other than 'webview' and chromium categories.
102//   In this way we can avoid the conflict between StartATrace/StopATrace and
103//   the intents.
104// - TODO(wangxianzhu): after WebView is ready for combined tracing, remove
105//   StartATrace, StopATrace and SendToATrace, and perhaps send Java traces
106//   directly to atrace in trace_event_binding.cc.
107
108void TraceLog::StartATrace() {
109  if (g_atrace_fd != -1)
110    return;
111
112  g_atrace_fd = HANDLE_EINTR(open(kATraceMarkerFile, O_WRONLY));
113  if (g_atrace_fd == -1) {
114    PLOG(WARNING) << "Couldn't open " << kATraceMarkerFile;
115    return;
116  }
117  TraceConfig trace_config;
118  trace_config.SetTraceRecordMode(RECORD_CONTINUOUSLY);
119  SetEnabled(trace_config, TraceLog::RECORDING_MODE);
120}
121
122void TraceLog::StopATrace() {
123  if (g_atrace_fd == -1)
124    return;
125
126  close(g_atrace_fd);
127  g_atrace_fd = -1;
128
129  // TraceLog::Flush() requires the current thread to have a message loop, but
130  // this thread called from Java may not have one, so flush in another thread.
131  Thread end_chrome_tracing_thread("end_chrome_tracing");
132  WaitableEvent complete_event(WaitableEvent::ResetPolicy::AUTOMATIC,
133                               WaitableEvent::InitialState::NOT_SIGNALED);
134  end_chrome_tracing_thread.Start();
135  end_chrome_tracing_thread.task_runner()->PostTask(
136      FROM_HERE, base::Bind(&EndChromeTracing, Unretained(this),
137                            Unretained(&complete_event)));
138  complete_event.Wait();
139}
140
141void TraceEvent::SendToATrace() {
142  if (g_atrace_fd == -1)
143    return;
144
145  const char* category_group =
146      TraceLog::GetCategoryGroupName(category_group_enabled_);
147
148  switch (phase_) {
149    case TRACE_EVENT_PHASE_BEGIN:
150      WriteEvent('B', category_group, name_, id_,
151                 arg_names_, arg_types_, arg_values_, convertable_values_,
152                 flags_);
153      break;
154
155    case TRACE_EVENT_PHASE_COMPLETE:
156      WriteEvent(duration_.ToInternalValue() == -1 ? 'B' : 'E',
157                 category_group, name_, id_,
158                 arg_names_, arg_types_, arg_values_, convertable_values_,
159                 flags_);
160      break;
161
162    case TRACE_EVENT_PHASE_END:
163      // Though a single 'E' is enough, here append pid, name and
164      // category_group etc. So that unpaired events can be found easily.
165      WriteEvent('E', category_group, name_, id_,
166                 arg_names_, arg_types_, arg_values_, convertable_values_,
167                 flags_);
168      break;
169
170    case TRACE_EVENT_PHASE_INSTANT:
171      // Simulate an instance event with a pair of begin/end events.
172      WriteEvent('B', category_group, name_, id_,
173                 arg_names_, arg_types_, arg_values_, convertable_values_,
174                 flags_);
175      WriteToATrace(g_atrace_fd, "E", 1);
176      break;
177
178    case TRACE_EVENT_PHASE_COUNTER:
179      for (int i = 0; i < kTraceMaxNumArgs && arg_names_[i]; ++i) {
180        DCHECK(arg_types_[i] == TRACE_VALUE_TYPE_INT);
181        std::string out = base::StringPrintf(
182            "C|%d|%s-%s", getpid(), name_, arg_names_[i]);
183        if (flags_ & TRACE_EVENT_FLAG_HAS_ID)
184          StringAppendF(&out, "-%" PRIx64, static_cast<uint64_t>(id_));
185        StringAppendF(&out, "|%d|%s",
186                      static_cast<int>(arg_values_[i].as_int), category_group);
187        WriteToATrace(g_atrace_fd, out.c_str(), out.size());
188      }
189      break;
190
191    default:
192      // Do nothing.
193      break;
194  }
195}
196
197void TraceLog::AddClockSyncMetadataEvent() {
198  int atrace_fd = HANDLE_EINTR(open(kATraceMarkerFile, O_WRONLY | O_APPEND));
199  if (atrace_fd == -1) {
200    PLOG(WARNING) << "Couldn't open " << kATraceMarkerFile;
201    return;
202  }
203
204  // Android's kernel trace system has a trace_marker feature: this is a file on
205  // debugfs that takes the written data and pushes it onto the trace
206  // buffer. So, to establish clock sync, we write our monotonic clock into that
207  // trace buffer.
208  double now_in_seconds = (TimeTicks::Now() - TimeTicks()).InSecondsF();
209  std::string marker = StringPrintf(
210      "trace_event_clock_sync: parent_ts=%f\n", now_in_seconds);
211  WriteToATrace(atrace_fd, marker.c_str(), marker.size());
212  close(atrace_fd);
213}
214
215}  // namespace trace_event
216}  // namespace base
217