1 /*
2 * Copyright (C) 2019 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
17 #include "perfetto/tracing/internal/track_event_internal.h"
18
19 #include "perfetto/base/proc_utils.h"
20 #include "perfetto/base/thread_utils.h"
21 #include "perfetto/base/time.h"
22 #include "perfetto/tracing/core/data_source_config.h"
23 #include "perfetto/tracing/internal/track_event_interned_fields.h"
24 #include "perfetto/tracing/track_event.h"
25 #include "perfetto/tracing/track_event_category_registry.h"
26 #include "perfetto/tracing/track_event_interned_data_index.h"
27 #include "protos/perfetto/common/data_source_descriptor.gen.h"
28 #include "protos/perfetto/common/track_event_descriptor.pbzero.h"
29 #include "protos/perfetto/trace/clock_snapshot.pbzero.h"
30 #include "protos/perfetto/trace/interned_data/interned_data.pbzero.h"
31 #include "protos/perfetto/trace/trace_packet_defaults.pbzero.h"
32 #include "protos/perfetto/trace/track_event/debug_annotation.pbzero.h"
33 #include "protos/perfetto/trace/track_event/track_descriptor.pbzero.h"
34
35 using perfetto::protos::pbzero::ClockSnapshot;
36
37 namespace perfetto {
38
39 TrackEventSessionObserver::~TrackEventSessionObserver() = default;
OnSetup(const DataSourceBase::SetupArgs &)40 void TrackEventSessionObserver::OnSetup(const DataSourceBase::SetupArgs&) {}
OnStart(const DataSourceBase::StartArgs &)41 void TrackEventSessionObserver::OnStart(const DataSourceBase::StartArgs&) {}
OnStop(const DataSourceBase::StopArgs &)42 void TrackEventSessionObserver::OnStop(const DataSourceBase::StopArgs&) {}
43
44 namespace internal {
45
46 BaseTrackEventInternedDataIndex::~BaseTrackEventInternedDataIndex() = default;
47
48 namespace {
49
50 std::atomic<perfetto::base::PlatformThreadId> g_main_thread;
51 static constexpr const char kLegacySlowPrefix[] = "disabled-by-default-";
52 static constexpr const char kSlowTag[] = "slow";
53 static constexpr const char kDebugTag[] = "debug";
54 // Allows to specify a custom unit different than the default (ns) for
55 // the incremental clock.
56 // A multiplier of 1000 means that a timestamp = 3 should be
57 // interpreted as 3000 ns = 3 us.
58 // TODO(mohitms): Move it to TrackEventConfig.
59 constexpr uint64_t kIncrementalTimestampUnitMultiplier = 1;
60 static_assert(kIncrementalTimestampUnitMultiplier >= 1, "");
61
62 constexpr auto kClockIdIncremental =
63 TrackEventIncrementalState::kClockIdIncremental;
64
ForEachObserver(std::function<bool (TrackEventSessionObserver * &)> callback)65 void ForEachObserver(
66 std::function<bool(TrackEventSessionObserver*&)> callback) {
67 // Session observers, shared by all track event data source instances.
68 static constexpr int kMaxObservers = 8;
69 static std::recursive_mutex* mutex = new std::recursive_mutex{}; // Leaked.
70 static std::array<TrackEventSessionObserver*, kMaxObservers> observers{};
71 std::unique_lock<std::recursive_mutex> lock(*mutex);
72 for (auto& o : observers) {
73 if (!callback(o))
74 break;
75 }
76 }
77
78 enum class MatchType { kExact, kPattern };
79
NameMatchesPattern(const std::string & pattern,const std::string & name,MatchType match_type)80 bool NameMatchesPattern(const std::string& pattern,
81 const std::string& name,
82 MatchType match_type) {
83 // To avoid pulling in all of std::regex, for now we only support a single "*"
84 // wildcard at the end of the pattern.
85 size_t i = pattern.find('*');
86 if (i != std::string::npos) {
87 PERFETTO_DCHECK(i == pattern.size() - 1);
88 if (match_type != MatchType::kPattern)
89 return false;
90 return name.substr(0, i) == pattern.substr(0, i);
91 }
92 return name == pattern;
93 }
94
NameMatchesPatternList(const std::vector<std::string> & patterns,const std::string & name,MatchType match_type)95 bool NameMatchesPatternList(const std::vector<std::string>& patterns,
96 const std::string& name,
97 MatchType match_type) {
98 for (const auto& pattern : patterns) {
99 if (NameMatchesPattern(pattern, name, match_type))
100 return true;
101 }
102 return false;
103 }
104
105 } // namespace
106
107 // static
108 const Track TrackEventInternal::kDefaultTrack{};
109
110 // static
111 std::atomic<int> TrackEventInternal::session_count_{};
112
113 // static
Initialize(const TrackEventCategoryRegistry & registry,bool (* register_data_source)(const DataSourceDescriptor &))114 bool TrackEventInternal::Initialize(
115 const TrackEventCategoryRegistry& registry,
116 bool (*register_data_source)(const DataSourceDescriptor&)) {
117 if (!g_main_thread)
118 g_main_thread = perfetto::base::GetThreadId();
119
120 DataSourceDescriptor dsd;
121 dsd.set_name("track_event");
122
123 protozero::HeapBuffered<protos::pbzero::TrackEventDescriptor> ted;
124 for (size_t i = 0; i < registry.category_count(); i++) {
125 auto category = registry.GetCategory(i);
126 // Don't register group categories.
127 if (category->IsGroup())
128 continue;
129 auto cat = ted->add_available_categories();
130 cat->set_name(category->name);
131 if (category->description)
132 cat->set_description(category->description);
133 for (const auto& tag : category->tags) {
134 if (tag)
135 cat->add_tags(tag);
136 }
137 // Disabled-by-default categories get a "slow" tag.
138 if (!strncmp(category->name, kLegacySlowPrefix, strlen(kLegacySlowPrefix)))
139 cat->add_tags(kSlowTag);
140 }
141 dsd.set_track_event_descriptor_raw(ted.SerializeAsString());
142
143 return register_data_source(dsd);
144 }
145
146 // static
AddSessionObserver(TrackEventSessionObserver * observer)147 bool TrackEventInternal::AddSessionObserver(
148 TrackEventSessionObserver* observer) {
149 bool result = false;
150 ForEachObserver([&](TrackEventSessionObserver*& o) {
151 if (!o) {
152 o = observer;
153 result = true;
154 return false;
155 }
156 return true;
157 });
158 return result;
159 }
160
161 // static
RemoveSessionObserver(TrackEventSessionObserver * observer)162 void TrackEventInternal::RemoveSessionObserver(
163 TrackEventSessionObserver* observer) {
164 ForEachObserver([&](TrackEventSessionObserver*& o) {
165 if (o == observer) {
166 o = nullptr;
167 return false;
168 }
169 return true;
170 });
171 }
172
173 // static
EnableTracing(const TrackEventCategoryRegistry & registry,const protos::gen::TrackEventConfig & config,const DataSourceBase::SetupArgs & args)174 void TrackEventInternal::EnableTracing(
175 const TrackEventCategoryRegistry& registry,
176 const protos::gen::TrackEventConfig& config,
177 const DataSourceBase::SetupArgs& args) {
178 for (size_t i = 0; i < registry.category_count(); i++) {
179 if (IsCategoryEnabled(registry, config, *registry.GetCategory(i)))
180 registry.EnableCategoryForInstance(i, args.internal_instance_index);
181 }
182 ForEachObserver([&](TrackEventSessionObserver*& o) {
183 if (o)
184 o->OnSetup(args);
185 return true;
186 });
187 }
188
189 // static
OnStart(const DataSourceBase::StartArgs & args)190 void TrackEventInternal::OnStart(const DataSourceBase::StartArgs& args) {
191 session_count_.fetch_add(1);
192 ForEachObserver([&](TrackEventSessionObserver*& o) {
193 if (o)
194 o->OnStart(args);
195 return true;
196 });
197 }
198
199 // static
DisableTracing(const TrackEventCategoryRegistry & registry,const DataSourceBase::StopArgs & args)200 void TrackEventInternal::DisableTracing(
201 const TrackEventCategoryRegistry& registry,
202 const DataSourceBase::StopArgs& args) {
203 ForEachObserver([&](TrackEventSessionObserver*& o) {
204 if (o)
205 o->OnStop(args);
206 return true;
207 });
208 for (size_t i = 0; i < registry.category_count(); i++)
209 registry.DisableCategoryForInstance(i, args.internal_instance_index);
210 }
211
212 // static
IsCategoryEnabled(const TrackEventCategoryRegistry & registry,const protos::gen::TrackEventConfig & config,const Category & category)213 bool TrackEventInternal::IsCategoryEnabled(
214 const TrackEventCategoryRegistry& registry,
215 const protos::gen::TrackEventConfig& config,
216 const Category& category) {
217 // If this is a group category, check if any of its constituent categories are
218 // enabled. If so, then this one is enabled too.
219 if (category.IsGroup()) {
220 bool result = false;
221 category.ForEachGroupMember([&](const char* member_name, size_t name_size) {
222 for (size_t i = 0; i < registry.category_count(); i++) {
223 const auto ref_category = registry.GetCategory(i);
224 // Groups can't refer to other groups.
225 if (ref_category->IsGroup())
226 continue;
227 // Require an exact match.
228 if (ref_category->name_size() != name_size ||
229 strncmp(ref_category->name, member_name, name_size)) {
230 continue;
231 }
232 if (IsCategoryEnabled(registry, config, *ref_category)) {
233 result = true;
234 // Break ForEachGroupMember() loop.
235 return false;
236 }
237 break;
238 }
239 // No match? Must be a dynamic category.
240 DynamicCategory dyn_category(std::string(member_name, name_size));
241 Category ref_category{Category::FromDynamicCategory(dyn_category)};
242 if (IsCategoryEnabled(registry, config, ref_category)) {
243 result = true;
244 // Break ForEachGroupMember() loop.
245 return false;
246 }
247 // No match found => keep iterating.
248 return true;
249 });
250 return result;
251 }
252
253 auto has_matching_tag = [&](std::function<bool(const char*)> matcher) {
254 for (const auto& tag : category.tags) {
255 if (!tag)
256 break;
257 if (matcher(tag))
258 return true;
259 }
260 // Legacy "disabled-by-default" categories automatically get the "slow" tag.
261 if (!strncmp(category.name, kLegacySlowPrefix, strlen(kLegacySlowPrefix)) &&
262 matcher(kSlowTag)) {
263 return true;
264 }
265 return false;
266 };
267
268 // First try exact matches, then pattern matches.
269 const std::array<MatchType, 2> match_types = {
270 {MatchType::kExact, MatchType::kPattern}};
271 for (auto match_type : match_types) {
272 // 1. Enabled categories.
273 if (NameMatchesPatternList(config.enabled_categories(), category.name,
274 match_type)) {
275 return true;
276 }
277
278 // 2. Enabled tags.
279 if (has_matching_tag([&](const char* tag) {
280 return NameMatchesPatternList(config.enabled_tags(), tag, match_type);
281 })) {
282 return true;
283 }
284
285 // 3. Disabled categories.
286 if (NameMatchesPatternList(config.disabled_categories(), category.name,
287 match_type)) {
288 return false;
289 }
290
291 // 4. Disabled tags.
292 if (has_matching_tag([&](const char* tag) {
293 if (config.disabled_tags_size()) {
294 return NameMatchesPatternList(config.disabled_tags(), tag,
295 match_type);
296 } else {
297 // The "slow" and "debug" tags are disabled by default.
298 return NameMatchesPattern(kSlowTag, tag, match_type) ||
299 NameMatchesPattern(kDebugTag, tag, match_type);
300 }
301 })) {
302 return false;
303 }
304 }
305
306 // If nothing matched, enable the category by default.
307 return true;
308 }
309
310 // static
GetTimeNs()311 uint64_t TrackEventInternal::GetTimeNs() {
312 if (GetClockId() == protos::pbzero::BUILTIN_CLOCK_BOOTTIME)
313 return static_cast<uint64_t>(perfetto::base::GetBootTimeNs().count());
314 PERFETTO_DCHECK(GetClockId() == protos::pbzero::BUILTIN_CLOCK_MONOTONIC);
315 return static_cast<uint64_t>(perfetto::base::GetWallTimeNs().count());
316 }
317
318 // static
GetTraceTime()319 TraceTimestamp TrackEventInternal::GetTraceTime() {
320 return {kClockIdIncremental, GetTimeNs()};
321 }
322
323 // static
GetSessionCount()324 int TrackEventInternal::GetSessionCount() {
325 return session_count_.load();
326 }
327
328 // static
ResetIncrementalState(TraceWriterBase * trace_writer,TrackEventIncrementalState * incr_state,const TrackEventTlsState & tls_state,const TraceTimestamp & timestamp)329 void TrackEventInternal::ResetIncrementalState(
330 TraceWriterBase* trace_writer,
331 TrackEventIncrementalState* incr_state,
332 const TrackEventTlsState& tls_state,
333 const TraceTimestamp& timestamp) {
334 auto sequence_timestamp = timestamp;
335 if (timestamp.clock_id != TrackEventInternal::GetClockId() &&
336 timestamp.clock_id != kClockIdIncremental) {
337 sequence_timestamp = TrackEventInternal::GetTraceTime();
338 }
339
340 incr_state->last_timestamp_ns = sequence_timestamp.value;
341 auto default_track = ThreadTrack::Current();
342 {
343 // Mark any incremental state before this point invalid. Also set up
344 // defaults so that we don't need to repeat constant data for each packet.
345 auto packet = NewTracePacket(
346 trace_writer, incr_state, tls_state, timestamp,
347 protos::pbzero::TracePacket::SEQ_INCREMENTAL_STATE_CLEARED);
348 auto defaults = packet->set_trace_packet_defaults();
349
350 // Establish the default track for this event sequence.
351 auto track_defaults = defaults->set_track_event_defaults();
352 track_defaults->set_track_uuid(default_track.uuid);
353
354 if (PERFETTO_LIKELY(!tls_state.disable_incremental_timestamps)) {
355 defaults->set_timestamp_clock_id(kClockIdIncremental);
356 ClockSnapshot* clocks = packet->set_clock_snapshot();
357 // Trace clock.
358 ClockSnapshot::Clock* trace_clock = clocks->add_clocks();
359 trace_clock->set_clock_id(GetClockId());
360 trace_clock->set_timestamp(sequence_timestamp.value);
361 // Delta-encoded incremental clock in nano seconds.
362 // TODO(b/168311581): Make the unit of this clock configurable to allow
363 // trade-off between precision and encoded trace size.
364 ClockSnapshot::Clock* clock_incremental = clocks->add_clocks();
365 clock_incremental->set_clock_id(kClockIdIncremental);
366 auto ts_unit_multiplier = kIncrementalTimestampUnitMultiplier;
367 clock_incremental->set_timestamp(sequence_timestamp.value /
368 ts_unit_multiplier);
369 clock_incremental->set_is_incremental(true);
370 clock_incremental->set_unit_multiplier_ns(ts_unit_multiplier);
371 } else {
372 defaults->set_timestamp_clock_id(GetClockId());
373 }
374 }
375
376 // Every thread should write a descriptor for its default track, because most
377 // trace points won't explicitly reference it. We also write the process
378 // descriptor from every thread that writes trace events to ensure it gets
379 // emitted at least once.
380 WriteTrackDescriptor(default_track, trace_writer, incr_state, tls_state,
381 sequence_timestamp);
382
383 WriteTrackDescriptor(ProcessTrack::Current(), trace_writer, incr_state,
384 tls_state, sequence_timestamp);
385 }
386
387 // static
388 protozero::MessageHandle<protos::pbzero::TracePacket>
NewTracePacket(TraceWriterBase * trace_writer,TrackEventIncrementalState * incr_state,const TrackEventTlsState & tls_state,TraceTimestamp timestamp,uint32_t seq_flags)389 TrackEventInternal::NewTracePacket(TraceWriterBase* trace_writer,
390 TrackEventIncrementalState* incr_state,
391 const TrackEventTlsState& tls_state,
392 TraceTimestamp timestamp,
393 uint32_t seq_flags) {
394 if (PERFETTO_UNLIKELY(tls_state.disable_incremental_timestamps &&
395 timestamp.clock_id == kClockIdIncremental)) {
396 timestamp.clock_id = GetClockId();
397 }
398 auto packet = trace_writer->NewTracePacket();
399 // TODO(mohitms): Consider using kIncrementalTimestampUnitMultiplier.
400 if (PERFETTO_LIKELY(timestamp.clock_id == kClockIdIncremental)) {
401 if (PERFETTO_LIKELY(incr_state->last_timestamp_ns <= timestamp.value)) {
402 // No need to set the clock id here, since kClockIdIncremental is the
403 // clock id assumed by default.
404 auto ts_unit_multiplier = kIncrementalTimestampUnitMultiplier;
405 auto time_diff_ns = timestamp.value - incr_state->last_timestamp_ns;
406 packet->set_timestamp(time_diff_ns / ts_unit_multiplier);
407 incr_state->last_timestamp_ns = timestamp.value;
408 } else {
409 packet->set_timestamp(timestamp.value);
410 packet->set_timestamp_clock_id(GetClockId());
411 }
412 } else {
413 packet->set_timestamp(timestamp.value);
414 auto default_clock = tls_state.disable_incremental_timestamps
415 ? static_cast<uint32_t>(GetClockId())
416 : kClockIdIncremental;
417 if (PERFETTO_UNLIKELY(timestamp.clock_id != default_clock))
418 packet->set_timestamp_clock_id(timestamp.clock_id);
419 }
420 packet->set_sequence_flags(seq_flags);
421 return packet;
422 }
423
424 // static
WriteEvent(TraceWriterBase * trace_writer,TrackEventIncrementalState * incr_state,const TrackEventTlsState & tls_state,const Category * category,const char * name,perfetto::protos::pbzero::TrackEvent::Type type,const TraceTimestamp & timestamp)425 EventContext TrackEventInternal::WriteEvent(
426 TraceWriterBase* trace_writer,
427 TrackEventIncrementalState* incr_state,
428 const TrackEventTlsState& tls_state,
429 const Category* category,
430 const char* name,
431 perfetto::protos::pbzero::TrackEvent::Type type,
432 const TraceTimestamp& timestamp) {
433 PERFETTO_DCHECK(g_main_thread);
434 PERFETTO_DCHECK(!incr_state->was_cleared);
435 auto packet = NewTracePacket(trace_writer, incr_state, tls_state, timestamp);
436 EventContext ctx(std::move(packet), incr_state, &tls_state);
437
438 auto track_event = ctx.event();
439 if (type != protos::pbzero::TrackEvent::TYPE_UNSPECIFIED)
440 track_event->set_type(type);
441
442 // We assume that |category| and |name| point to strings with static lifetime.
443 // This means we can use their addresses as interning keys.
444 // TODO(skyostil): Intern categories at compile time.
445 if (category && type != protos::pbzero::TrackEvent::TYPE_SLICE_END &&
446 type != protos::pbzero::TrackEvent::TYPE_COUNTER) {
447 category->ForEachGroupMember(
448 [&](const char* member_name, size_t name_size) {
449 size_t category_iid =
450 InternedEventCategory::Get(&ctx, member_name, name_size);
451 track_event->add_category_iids(category_iid);
452 return true;
453 });
454 }
455 if (name && type != protos::pbzero::TrackEvent::TYPE_SLICE_END) {
456 size_t name_iid = InternedEventName::Get(&ctx, name);
457 track_event->set_name_iid(name_iid);
458 }
459 return ctx;
460 }
461
462 // static
AddDebugAnnotation(perfetto::EventContext * event_ctx,const char * name)463 protos::pbzero::DebugAnnotation* TrackEventInternal::AddDebugAnnotation(
464 perfetto::EventContext* event_ctx,
465 const char* name) {
466 auto annotation = event_ctx->event()->add_debug_annotations();
467 annotation->set_name_iid(InternedDebugAnnotationName::Get(event_ctx, name));
468 return annotation;
469 }
470
471 } // namespace internal
472 } // namespace perfetto
473