James Robinson | 646469d | 2014-10-03 15:33:28 -0700 | [diff] [blame] | 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; |
James Robinson | e1b30cf | 2014-10-21 12:25:40 -0700 | [diff] [blame] | 18 | const char kATraceMarkerFile[] = "/sys/kernel/debug/tracing/trace_marker"; |
James Robinson | 646469d | 2014-10-03 15:33:28 -0700 | [diff] [blame] | 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 |