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
19 namespace base {
20 namespace trace_event {
21
22 namespace {
23
24 int g_atrace_fd = -1;
25 const char kATraceMarkerFile[] = "/sys/kernel/debug/tracing/trace_marker";
26
WriteToATrace(int fd,const char * buffer,size_t size)27 void 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
WriteEvent(char phase,const char * category_group,const char * name,unsigned long long id,const char ** arg_names,const unsigned char * arg_types,const TraceEvent::TraceValue * arg_values,const std::unique_ptr<ConvertableToTraceFormat> * convertable_values,unsigned int flags)42 void 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
NoOpOutputCallback(WaitableEvent * complete_event,const scoped_refptr<RefCountedString> &,bool has_more_events)82 void 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
EndChromeTracing(TraceLog * trace_log,WaitableEvent * complete_event)89 void 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
StartATrace()108 void 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
StopATrace()122 void 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
SendToATrace()141 void 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
AddClockSyncMetadataEvent()197 void 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 = (TRACE_TIME_TICKS_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