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 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 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 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 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 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 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 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