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