• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
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