OLD | NEW |
1 // Copyright 2015 The Chromium Authors. All rights reserved. | 1 // Copyright 2015 The Chromium Authors. All rights reserved. |
2 // Use of this source code is governed by a BSD-style license that can be | 2 // Use of this source code is governed by a BSD-style license that can be |
3 // found in the LICENSE file. | 3 // found in the LICENSE file. |
4 | 4 |
5 #include "base/trace_event/trace_log.h" | 5 #include "base/trace_event/trace_log.h" |
6 | 6 |
7 #include <algorithm> | 7 #include <algorithm> |
8 #include <cmath> | 8 #include <cmath> |
9 | 9 |
10 #include "base/base_switches.h" | 10 #include "base/base_switches.h" |
(...skipping 119 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
130 const T& value) { | 130 const T& value) { |
131 if (!trace_event) | 131 if (!trace_event) |
132 return; | 132 return; |
133 | 133 |
134 int num_args = 1; | 134 int num_args = 1; |
135 unsigned char arg_type; | 135 unsigned char arg_type; |
136 unsigned long long arg_value; | 136 unsigned long long arg_value; |
137 ::trace_event_internal::SetTraceValue(value, &arg_type, &arg_value); | 137 ::trace_event_internal::SetTraceValue(value, &arg_type, &arg_value); |
138 trace_event->Initialize( | 138 trace_event->Initialize( |
139 thread_id, | 139 thread_id, |
140 TraceTicks(), | 140 TimeTicks(), |
141 ThreadTicks(), | 141 ThreadTicks(), |
142 TRACE_EVENT_PHASE_METADATA, | 142 TRACE_EVENT_PHASE_METADATA, |
143 &g_category_group_enabled[g_category_metadata], | 143 &g_category_group_enabled[g_category_metadata], |
144 metadata_name, | 144 metadata_name, |
145 trace_event_internal::kNoId, // id | 145 trace_event_internal::kNoId, // id |
146 trace_event_internal::kNoId, // context_id | 146 trace_event_internal::kNoId, // context_id |
147 trace_event_internal::kNoId, // bind_id | 147 trace_event_internal::kNoId, // bind_id |
148 num_args, | 148 num_args, |
149 &arg_name, | 149 &arg_name, |
150 &arg_type, | 150 &arg_type, |
(...skipping 922 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
1073 const unsigned char* category_group_enabled, | 1073 const unsigned char* category_group_enabled, |
1074 const char* name, | 1074 const char* name, |
1075 unsigned long long id, | 1075 unsigned long long id, |
1076 int num_args, | 1076 int num_args, |
1077 const char** arg_names, | 1077 const char** arg_names, |
1078 const unsigned char* arg_types, | 1078 const unsigned char* arg_types, |
1079 const unsigned long long* arg_values, | 1079 const unsigned long long* arg_values, |
1080 const scoped_refptr<ConvertableToTraceFormat>* convertable_values, | 1080 const scoped_refptr<ConvertableToTraceFormat>* convertable_values, |
1081 unsigned int flags) { | 1081 unsigned int flags) { |
1082 int thread_id = static_cast<int>(base::PlatformThread::CurrentId()); | 1082 int thread_id = static_cast<int>(base::PlatformThread::CurrentId()); |
1083 base::TraceTicks now = base::TraceTicks::Now(); | 1083 base::TimeTicks now = base::TimeTicks::Now(); |
1084 return AddTraceEventWithThreadIdAndTimestamp( | 1084 return AddTraceEventWithThreadIdAndTimestamp( |
1085 phase, | 1085 phase, |
1086 category_group_enabled, | 1086 category_group_enabled, |
1087 name, | 1087 name, |
1088 id, | 1088 id, |
1089 trace_event_internal::kNoId, // context_id | 1089 trace_event_internal::kNoId, // context_id |
1090 trace_event_internal::kNoId, // bind_id | 1090 trace_event_internal::kNoId, // bind_id |
1091 thread_id, | 1091 thread_id, |
1092 now, | 1092 now, |
1093 num_args, | 1093 num_args, |
(...skipping 10 matching lines...) Expand all Loading... |
1104 const char* name, | 1104 const char* name, |
1105 unsigned long long id, | 1105 unsigned long long id, |
1106 unsigned long long context_id, | 1106 unsigned long long context_id, |
1107 int num_args, | 1107 int num_args, |
1108 const char** arg_names, | 1108 const char** arg_names, |
1109 const unsigned char* arg_types, | 1109 const unsigned char* arg_types, |
1110 const unsigned long long* arg_values, | 1110 const unsigned long long* arg_values, |
1111 const scoped_refptr<ConvertableToTraceFormat>* convertable_values, | 1111 const scoped_refptr<ConvertableToTraceFormat>* convertable_values, |
1112 unsigned int flags) { | 1112 unsigned int flags) { |
1113 int thread_id = static_cast<int>(base::PlatformThread::CurrentId()); | 1113 int thread_id = static_cast<int>(base::PlatformThread::CurrentId()); |
1114 base::TraceTicks now = base::TraceTicks::Now(); | 1114 base::TimeTicks now = base::TimeTicks::Now(); |
1115 return AddTraceEventWithThreadIdAndTimestamp( | 1115 return AddTraceEventWithThreadIdAndTimestamp( |
1116 phase, | 1116 phase, |
1117 category_group_enabled, | 1117 category_group_enabled, |
1118 name, | 1118 name, |
1119 id, | 1119 id, |
1120 context_id, | 1120 context_id, |
1121 trace_event_internal::kNoId, // bind_id | 1121 trace_event_internal::kNoId, // bind_id |
1122 thread_id, | 1122 thread_id, |
1123 now, | 1123 now, |
1124 num_args, | 1124 num_args, |
1125 arg_names, | 1125 arg_names, |
1126 arg_types, | 1126 arg_types, |
1127 arg_values, | 1127 arg_values, |
1128 convertable_values, | 1128 convertable_values, |
1129 flags | TRACE_EVENT_FLAG_HAS_CONTEXT_ID); | 1129 flags | TRACE_EVENT_FLAG_HAS_CONTEXT_ID); |
1130 } | 1130 } |
1131 | 1131 |
1132 TraceEventHandle TraceLog::AddTraceEventWithProcessId( | 1132 TraceEventHandle TraceLog::AddTraceEventWithProcessId( |
1133 char phase, | 1133 char phase, |
1134 const unsigned char* category_group_enabled, | 1134 const unsigned char* category_group_enabled, |
1135 const char* name, | 1135 const char* name, |
1136 unsigned long long id, | 1136 unsigned long long id, |
1137 int process_id, | 1137 int process_id, |
1138 int num_args, | 1138 int num_args, |
1139 const char** arg_names, | 1139 const char** arg_names, |
1140 const unsigned char* arg_types, | 1140 const unsigned char* arg_types, |
1141 const unsigned long long* arg_values, | 1141 const unsigned long long* arg_values, |
1142 const scoped_refptr<ConvertableToTraceFormat>* convertable_values, | 1142 const scoped_refptr<ConvertableToTraceFormat>* convertable_values, |
1143 unsigned int flags) { | 1143 unsigned int flags) { |
1144 base::TraceTicks now = base::TraceTicks::Now(); | 1144 base::TimeTicks now = base::TimeTicks::Now(); |
1145 return AddTraceEventWithThreadIdAndTimestamp( | 1145 return AddTraceEventWithThreadIdAndTimestamp( |
1146 phase, | 1146 phase, |
1147 category_group_enabled, | 1147 category_group_enabled, |
1148 name, | 1148 name, |
1149 id, | 1149 id, |
1150 trace_event_internal::kNoId, // context_id | 1150 trace_event_internal::kNoId, // context_id |
1151 trace_event_internal::kNoId, // bind_id | 1151 trace_event_internal::kNoId, // bind_id |
1152 process_id, | 1152 process_id, |
1153 now, | 1153 now, |
1154 num_args, | 1154 num_args, |
1155 arg_names, | 1155 arg_names, |
1156 arg_types, | 1156 arg_types, |
1157 arg_values, | 1157 arg_values, |
1158 convertable_values, | 1158 convertable_values, |
1159 flags | TRACE_EVENT_FLAG_HAS_PROCESS_ID); | 1159 flags | TRACE_EVENT_FLAG_HAS_PROCESS_ID); |
1160 } | 1160 } |
1161 | 1161 |
1162 // Handle legacy calls to AddTraceEventWithThreadIdAndTimestamp | 1162 // Handle legacy calls to AddTraceEventWithThreadIdAndTimestamp |
1163 // with kNoId as bind_id | 1163 // with kNoId as bind_id |
1164 TraceEventHandle TraceLog::AddTraceEventWithThreadIdAndTimestamp( | 1164 TraceEventHandle TraceLog::AddTraceEventWithThreadIdAndTimestamp( |
1165 char phase, | 1165 char phase, |
1166 const unsigned char* category_group_enabled, | 1166 const unsigned char* category_group_enabled, |
1167 const char* name, | 1167 const char* name, |
1168 unsigned long long id, | 1168 unsigned long long id, |
1169 unsigned long long context_id, | 1169 unsigned long long context_id, |
1170 int thread_id, | 1170 int thread_id, |
1171 const TraceTicks& timestamp, | 1171 const TimeTicks& timestamp, |
1172 int num_args, | 1172 int num_args, |
1173 const char** arg_names, | 1173 const char** arg_names, |
1174 const unsigned char* arg_types, | 1174 const unsigned char* arg_types, |
1175 const unsigned long long* arg_values, | 1175 const unsigned long long* arg_values, |
1176 const scoped_refptr<ConvertableToTraceFormat>* convertable_values, | 1176 const scoped_refptr<ConvertableToTraceFormat>* convertable_values, |
1177 unsigned int flags) { | 1177 unsigned int flags) { |
1178 return AddTraceEventWithThreadIdAndTimestamp( | 1178 return AddTraceEventWithThreadIdAndTimestamp( |
1179 phase, | 1179 phase, |
1180 category_group_enabled, | 1180 category_group_enabled, |
1181 name, | 1181 name, |
(...skipping 11 matching lines...) Expand all Loading... |
1193 } | 1193 } |
1194 | 1194 |
1195 TraceEventHandle TraceLog::AddTraceEventWithThreadIdAndTimestamp( | 1195 TraceEventHandle TraceLog::AddTraceEventWithThreadIdAndTimestamp( |
1196 char phase, | 1196 char phase, |
1197 const unsigned char* category_group_enabled, | 1197 const unsigned char* category_group_enabled, |
1198 const char* name, | 1198 const char* name, |
1199 unsigned long long id, | 1199 unsigned long long id, |
1200 unsigned long long context_id, | 1200 unsigned long long context_id, |
1201 unsigned long long bind_id, | 1201 unsigned long long bind_id, |
1202 int thread_id, | 1202 int thread_id, |
1203 const TraceTicks& timestamp, | 1203 const TimeTicks& timestamp, |
1204 int num_args, | 1204 int num_args, |
1205 const char** arg_names, | 1205 const char** arg_names, |
1206 const unsigned char* arg_types, | 1206 const unsigned char* arg_types, |
1207 const unsigned long long* arg_values, | 1207 const unsigned long long* arg_values, |
1208 const scoped_refptr<ConvertableToTraceFormat>* convertable_values, | 1208 const scoped_refptr<ConvertableToTraceFormat>* convertable_values, |
1209 unsigned int flags) { | 1209 unsigned int flags) { |
1210 TraceEventHandle handle = {0, 0, 0}; | 1210 TraceEventHandle handle = {0, 0, 0}; |
1211 if (!*category_group_enabled) | 1211 if (!*category_group_enabled) |
1212 return handle; | 1212 return handle; |
1213 | 1213 |
1214 // Avoid re-entrance of AddTraceEvent. This may happen in GPU process when | 1214 // Avoid re-entrance of AddTraceEvent. This may happen in GPU process when |
1215 // ECHO_TO_CONSOLE is enabled: AddTraceEvent -> LOG(ERROR) -> | 1215 // ECHO_TO_CONSOLE is enabled: AddTraceEvent -> LOG(ERROR) -> |
1216 // GpuProcessLogMessageHandler -> PostPendingTask -> TRACE_EVENT ... | 1216 // GpuProcessLogMessageHandler -> PostPendingTask -> TRACE_EVENT ... |
1217 if (thread_is_in_trace_event_.Get()) | 1217 if (thread_is_in_trace_event_.Get()) |
1218 return handle; | 1218 return handle; |
1219 | 1219 |
1220 AutoThreadLocalBoolean thread_is_in_trace_event(&thread_is_in_trace_event_); | 1220 AutoThreadLocalBoolean thread_is_in_trace_event(&thread_is_in_trace_event_); |
1221 | 1221 |
1222 DCHECK(name); | 1222 DCHECK(name); |
1223 DCHECK(!timestamp.is_null()); | 1223 DCHECK(!timestamp.is_null()); |
1224 | 1224 |
1225 if (flags & TRACE_EVENT_FLAG_MANGLE_ID) { | 1225 if (flags & TRACE_EVENT_FLAG_MANGLE_ID) { |
1226 if ((flags & TRACE_EVENT_FLAG_FLOW_IN) || | 1226 if ((flags & TRACE_EVENT_FLAG_FLOW_IN) || |
1227 (flags & TRACE_EVENT_FLAG_FLOW_OUT)) | 1227 (flags & TRACE_EVENT_FLAG_FLOW_OUT)) |
1228 bind_id = MangleEventId(bind_id); | 1228 bind_id = MangleEventId(bind_id); |
1229 id = MangleEventId(id); | 1229 id = MangleEventId(id); |
1230 } | 1230 } |
1231 | 1231 |
1232 TraceTicks offset_event_timestamp = OffsetTimestamp(timestamp); | 1232 TimeTicks offset_event_timestamp = OffsetTimestamp(timestamp); |
1233 ThreadTicks thread_now = ThreadNow(); | 1233 ThreadTicks thread_now = ThreadNow(); |
1234 | 1234 |
1235 // |thread_local_event_buffer_| can be null if the current thread doesn't have | 1235 // |thread_local_event_buffer_| can be null if the current thread doesn't have |
1236 // a message loop or the message loop is blocked. | 1236 // a message loop or the message loop is blocked. |
1237 InitializeThreadLocalEventBufferIfSupported(); | 1237 InitializeThreadLocalEventBufferIfSupported(); |
1238 auto thread_local_event_buffer = thread_local_event_buffer_.Get(); | 1238 auto thread_local_event_buffer = thread_local_event_buffer_.Get(); |
1239 | 1239 |
1240 // Check and update the current thread name only if the event is for the | 1240 // Check and update the current thread name only if the event is for the |
1241 // current thread to avoid locks in most cases. | 1241 // current thread to avoid locks in most cases. |
1242 if (thread_id == static_cast<int>(PlatformThread::CurrentId())) { | 1242 if (thread_id == static_cast<int>(PlatformThread::CurrentId())) { |
(...skipping 128 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
1371 const char* name, | 1371 const char* name, |
1372 int num_args, | 1372 int num_args, |
1373 const char** arg_names, | 1373 const char** arg_names, |
1374 const unsigned char* arg_types, | 1374 const unsigned char* arg_types, |
1375 const unsigned long long* arg_values, | 1375 const unsigned long long* arg_values, |
1376 const scoped_refptr<ConvertableToTraceFormat>* convertable_values, | 1376 const scoped_refptr<ConvertableToTraceFormat>* convertable_values, |
1377 unsigned int flags) { | 1377 unsigned int flags) { |
1378 scoped_ptr<TraceEvent> trace_event(new TraceEvent); | 1378 scoped_ptr<TraceEvent> trace_event(new TraceEvent); |
1379 trace_event->Initialize( | 1379 trace_event->Initialize( |
1380 0, // thread_id | 1380 0, // thread_id |
1381 TraceTicks(), ThreadTicks(), TRACE_EVENT_PHASE_METADATA, | 1381 TimeTicks(), ThreadTicks(), TRACE_EVENT_PHASE_METADATA, |
1382 &g_category_group_enabled[g_category_metadata], name, | 1382 &g_category_group_enabled[g_category_metadata], name, |
1383 trace_event_internal::kNoId, // id | 1383 trace_event_internal::kNoId, // id |
1384 trace_event_internal::kNoId, // context_id | 1384 trace_event_internal::kNoId, // context_id |
1385 trace_event_internal::kNoId, // bind_id | 1385 trace_event_internal::kNoId, // bind_id |
1386 num_args, arg_names, arg_types, arg_values, convertable_values, flags); | 1386 num_args, arg_names, arg_types, arg_values, convertable_values, flags); |
1387 AutoLock lock(lock_); | 1387 AutoLock lock(lock_); |
1388 metadata_events_.push_back(trace_event.Pass()); | 1388 metadata_events_.push_back(trace_event.Pass()); |
1389 } | 1389 } |
1390 | 1390 |
1391 // May be called when a COMPELETE event ends and the unfinished event has been | 1391 // May be called when a COMPELETE event ends and the unfinished event has been |
1392 // recycled (phase == TRACE_EVENT_PHASE_END and trace_event == NULL). | 1392 // recycled (phase == TRACE_EVENT_PHASE_END and trace_event == NULL). |
1393 std::string TraceLog::EventToConsoleMessage(unsigned char phase, | 1393 std::string TraceLog::EventToConsoleMessage(unsigned char phase, |
1394 const TraceTicks& timestamp, | 1394 const TimeTicks& timestamp, |
1395 TraceEvent* trace_event) { | 1395 TraceEvent* trace_event) { |
1396 AutoLock thread_info_lock(thread_info_lock_); | 1396 AutoLock thread_info_lock(thread_info_lock_); |
1397 | 1397 |
1398 // The caller should translate TRACE_EVENT_PHASE_COMPLETE to | 1398 // The caller should translate TRACE_EVENT_PHASE_COMPLETE to |
1399 // TRACE_EVENT_PHASE_BEGIN or TRACE_EVENT_END. | 1399 // TRACE_EVENT_PHASE_BEGIN or TRACE_EVENT_END. |
1400 DCHECK(phase != TRACE_EVENT_PHASE_COMPLETE); | 1400 DCHECK(phase != TRACE_EVENT_PHASE_COMPLETE); |
1401 | 1401 |
1402 TimeDelta duration; | 1402 TimeDelta duration; |
1403 int thread_id = | 1403 int thread_id = |
1404 trace_event ? trace_event->thread_id() : PlatformThread::CurrentId(); | 1404 trace_event ? trace_event->thread_id() : PlatformThread::CurrentId(); |
(...skipping 41 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
1446 | 1446 |
1447 // Avoid re-entrance of AddTraceEvent. This may happen in GPU process when | 1447 // Avoid re-entrance of AddTraceEvent. This may happen in GPU process when |
1448 // ECHO_TO_CONSOLE is enabled: AddTraceEvent -> LOG(ERROR) -> | 1448 // ECHO_TO_CONSOLE is enabled: AddTraceEvent -> LOG(ERROR) -> |
1449 // GpuProcessLogMessageHandler -> PostPendingTask -> TRACE_EVENT ... | 1449 // GpuProcessLogMessageHandler -> PostPendingTask -> TRACE_EVENT ... |
1450 if (thread_is_in_trace_event_.Get()) | 1450 if (thread_is_in_trace_event_.Get()) |
1451 return; | 1451 return; |
1452 | 1452 |
1453 AutoThreadLocalBoolean thread_is_in_trace_event(&thread_is_in_trace_event_); | 1453 AutoThreadLocalBoolean thread_is_in_trace_event(&thread_is_in_trace_event_); |
1454 | 1454 |
1455 ThreadTicks thread_now = ThreadNow(); | 1455 ThreadTicks thread_now = ThreadNow(); |
1456 TraceTicks now = OffsetNow(); | 1456 TimeTicks now = OffsetNow(); |
1457 | 1457 |
1458 #if defined(OS_WIN) | 1458 #if defined(OS_WIN) |
1459 // Generate an ETW event that marks the end of a complete event. | 1459 // Generate an ETW event that marks the end of a complete event. |
1460 if (category_group_enabled_local & ENABLED_FOR_ETW_EXPORT) | 1460 if (category_group_enabled_local & ENABLED_FOR_ETW_EXPORT) |
1461 TraceEventETWExport::AddCompleteEndEvent(name); | 1461 TraceEventETWExport::AddCompleteEndEvent(name); |
1462 #endif // OS_WIN | 1462 #endif // OS_WIN |
1463 | 1463 |
1464 std::string console_message; | 1464 std::string console_message; |
1465 if (category_group_enabled_local & ENABLED_FOR_RECORDING) { | 1465 if (category_group_enabled_local & ENABLED_FOR_RECORDING) { |
1466 OptionalAutoLock lock(&lock_); | 1466 OptionalAutoLock lock(&lock_); |
(...skipping 281 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
1748 name_ = name; | 1748 name_ = name; |
1749 if (*category_group_enabled_) { | 1749 if (*category_group_enabled_) { |
1750 event_handle_ = | 1750 event_handle_ = |
1751 TRACE_EVENT_API_ADD_TRACE_EVENT_WITH_THREAD_ID_AND_TIMESTAMP( | 1751 TRACE_EVENT_API_ADD_TRACE_EVENT_WITH_THREAD_ID_AND_TIMESTAMP( |
1752 TRACE_EVENT_PHASE_COMPLETE, | 1752 TRACE_EVENT_PHASE_COMPLETE, |
1753 category_group_enabled_, | 1753 category_group_enabled_, |
1754 name, | 1754 name, |
1755 trace_event_internal::kNoId, // id | 1755 trace_event_internal::kNoId, // id |
1756 trace_event_internal::kNoId, // context_id | 1756 trace_event_internal::kNoId, // context_id |
1757 static_cast<int>(base::PlatformThread::CurrentId()), // thread_id | 1757 static_cast<int>(base::PlatformThread::CurrentId()), // thread_id |
1758 base::TraceTicks::Now(), | 1758 base::TimeTicks::Now(), |
1759 trace_event_internal::kZeroNumArgs, | 1759 trace_event_internal::kZeroNumArgs, |
1760 nullptr, | 1760 nullptr, |
1761 nullptr, | 1761 nullptr, |
1762 nullptr, | 1762 nullptr, |
1763 nullptr, | 1763 nullptr, |
1764 TRACE_EVENT_FLAG_NONE); | 1764 TRACE_EVENT_FLAG_NONE); |
1765 } | 1765 } |
1766 } | 1766 } |
1767 | 1767 |
1768 ScopedTraceBinaryEfficient::~ScopedTraceBinaryEfficient() { | 1768 ScopedTraceBinaryEfficient::~ScopedTraceBinaryEfficient() { |
1769 if (*category_group_enabled_) { | 1769 if (*category_group_enabled_) { |
1770 TRACE_EVENT_API_UPDATE_TRACE_EVENT_DURATION(category_group_enabled_, name_, | 1770 TRACE_EVENT_API_UPDATE_TRACE_EVENT_DURATION(category_group_enabled_, name_, |
1771 event_handle_); | 1771 event_handle_); |
1772 } | 1772 } |
1773 } | 1773 } |
1774 | 1774 |
1775 } // namespace trace_event_internal | 1775 } // namespace trace_event_internal |
OLD | NEW |