• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1 /*
2  * Copyright (C) 2018 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 <cinttypes>
18 #include <cstddef>
19 #include <cstdint>
20 #include <functional>
21 #include <optional>
22 #include <utility>
23 
24 #include "perfetto/base/logging.h"
25 #include "perfetto/ext/base/hash.h"
26 #include "src/trace_processor/importers/common/args_translation_table.h"
27 #include "src/trace_processor/importers/common/slice_tracker.h"
28 #include "src/trace_processor/importers/common/slice_translation_table.h"
29 #include "src/trace_processor/storage/stats.h"
30 #include "src/trace_processor/storage/trace_storage.h"
31 #include "src/trace_processor/tables/slice_tables_py.h"
32 #include "src/trace_processor/types/trace_processor_context.h"
33 #include "src/trace_processor/types/variadic.h"
34 
35 namespace perfetto::trace_processor {
36 namespace {
37 constexpr uint32_t kMaxDepth = 512;
38 }
39 
SliceTracker(TraceProcessorContext * context)40 SliceTracker::SliceTracker(TraceProcessorContext* context)
41     : legacy_unnestable_begin_count_string_id_(
42           context->storage->InternString("legacy_unnestable_begin_count")),
43       legacy_unnestable_last_begin_ts_string_id_(
44           context->storage->InternString("legacy_unnestable_last_begin_ts")),
45       context_(context) {}
46 
47 SliceTracker::~SliceTracker() = default;
48 
Begin(int64_t timestamp,TrackId track_id,StringId category,StringId raw_name,SetArgsCallback args_callback)49 std::optional<SliceId> SliceTracker::Begin(int64_t timestamp,
50                                            TrackId track_id,
51                                            StringId category,
52                                            StringId raw_name,
53                                            SetArgsCallback args_callback) {
54   const StringId name =
55       context_->slice_translation_table->TranslateName(raw_name);
56   tables::SliceTable::Row row(timestamp, kPendingDuration, track_id, category,
57                               name);
58   return StartSlice(timestamp, track_id, args_callback, [this, &row]() {
59     return context_->storage->mutable_slice_table()->Insert(row).id;
60   });
61 }
62 
BeginLegacyUnnestable(tables::SliceTable::Row row,SetArgsCallback args_callback)63 void SliceTracker::BeginLegacyUnnestable(tables::SliceTable::Row row,
64                                          SetArgsCallback args_callback) {
65   if (row.name) {
66     row.name = context_->slice_translation_table->TranslateName(*row.name);
67   }
68 
69   // Ensure that the duration is pending for this row.
70   // TODO(lalitm): change this to eventually use null instead of -1.
71   row.dur = kPendingDuration;
72 
73   // Double check that if we've seen this track in the past, it was also
74   // marked as unnestable then.
75 #if PERFETTO_DCHECK_IS_ON()
76   auto* it = stacks_.Find(row.track_id);
77   PERFETTO_DCHECK(!it || it->is_legacy_unnestable);
78 #endif
79 
80   // Ensure that StartSlice knows that this track is unnestable.
81   stacks_[row.track_id].is_legacy_unnestable = true;
82 
83   StartSlice(row.ts, row.track_id, args_callback, [this, &row]() {
84     return context_->storage->mutable_slice_table()->Insert(row).id;
85   });
86 }
87 
Scoped(int64_t timestamp,TrackId track_id,StringId category,StringId raw_name,int64_t duration,SetArgsCallback args_callback)88 std::optional<SliceId> SliceTracker::Scoped(int64_t timestamp,
89                                             TrackId track_id,
90                                             StringId category,
91                                             StringId raw_name,
92                                             int64_t duration,
93                                             SetArgsCallback args_callback) {
94   PERFETTO_DCHECK(duration >= 0);
95 
96   const StringId name =
97       context_->slice_translation_table->TranslateName(raw_name);
98   tables::SliceTable::Row row(timestamp, duration, track_id, category, name);
99   return StartSlice(timestamp, track_id, args_callback, [this, &row]() {
100     return context_->storage->mutable_slice_table()->Insert(row).id;
101   });
102 }
103 
End(int64_t timestamp,TrackId track_id,StringId category,StringId raw_name,SetArgsCallback args_callback)104 std::optional<SliceId> SliceTracker::End(int64_t timestamp,
105                                          TrackId track_id,
106                                          StringId category,
107                                          StringId raw_name,
108                                          SetArgsCallback args_callback) {
109   const StringId name =
110       context_->slice_translation_table->TranslateName(raw_name);
111   auto finder = [this, category, name](const SlicesStack& stack) {
112     return MatchingIncompleteSliceIndex(stack, name, category);
113   };
114   return CompleteSlice(timestamp, track_id, args_callback, finder);
115 }
116 
AddArgs(TrackId track_id,StringId category,StringId name,SetArgsCallback args_callback)117 std::optional<uint32_t> SliceTracker::AddArgs(TrackId track_id,
118                                               StringId category,
119                                               StringId name,
120                                               SetArgsCallback args_callback) {
121   auto* it = stacks_.Find(track_id);
122   if (!it)
123     return std::nullopt;
124 
125   auto& stack = it->slice_stack;
126   if (stack.empty())
127     return std::nullopt;
128 
129   auto* slices = context_->storage->mutable_slice_table();
130   std::optional<uint32_t> stack_idx =
131       MatchingIncompleteSliceIndex(stack, name, category);
132   if (!stack_idx.has_value())
133     return std::nullopt;
134 
135   tables::SliceTable::RowNumber num = stack[*stack_idx].row;
136   tables::SliceTable::RowReference ref = num.ToRowReference(slices);
137   PERFETTO_DCHECK(ref.dur() == kPendingDuration);
138 
139   // Add args to current pending slice.
140   ArgsTracker* tracker = &stack[*stack_idx].args_tracker;
141   auto bound_inserter = tracker->AddArgsTo(ref.id());
142   args_callback(&bound_inserter);
143   return num.row_number();
144 }
145 
StartSlice(int64_t timestamp,TrackId track_id,SetArgsCallback args_callback,std::function<SliceId ()> inserter)146 std::optional<SliceId> SliceTracker::StartSlice(
147     int64_t timestamp,
148     TrackId track_id,
149     SetArgsCallback args_callback,
150     std::function<SliceId()> inserter) {
151   auto& track_info = stacks_[track_id];
152   auto& stack = track_info.slice_stack;
153 
154   if (track_info.is_legacy_unnestable) {
155     PERFETTO_DCHECK(stack.size() <= 1);
156 
157     track_info.legacy_unnestable_begin_count++;
158     track_info.legacy_unnestable_last_begin_ts = timestamp;
159 
160     // If this is an unnestable track, don't start a new slice if one already
161     // exists.
162     if (!stack.empty()) {
163       return std::nullopt;
164     }
165   }
166 
167   auto* slices = context_->storage->mutable_slice_table();
168   MaybeCloseStack(timestamp, stack, track_id);
169 
170   size_t depth = stack.size();
171 
172   std::optional<tables::SliceTable::RowReference> parent_ref =
173       depth == 0 ? std::nullopt
174                  : std::make_optional(stack.back().row.ToRowReference(slices));
175   int64_t parent_stack_id = parent_ref ? parent_ref->stack_id() : 0;
176   std::optional<tables::SliceTable::Id> parent_id =
177       parent_ref ? std::make_optional(parent_ref->id()) : std::nullopt;
178 
179   SliceId id = inserter();
180   tables::SliceTable::RowReference ref = *slices->FindById(id);
181   if (depth >= kMaxDepth) {
182     auto parent_name = context_->storage->GetString(
183         parent_ref->name().value_or(kNullStringId));
184     auto name =
185         context_->storage->GetString(ref.name().value_or(kNullStringId));
186     PERFETTO_DLOG("Last slice: %s", parent_name.c_str());
187     PERFETTO_DLOG("Current slice: %s", name.c_str());
188     PERFETTO_DFATAL("Slices with too large depth found.");
189     return std::nullopt;
190   }
191   StackPush(track_id, ref);
192 
193   // Post fill all the relevant columns. All the other columns should have
194   // been filled by the inserter.
195   ref.set_depth(static_cast<uint32_t>(depth));
196   ref.set_parent_stack_id(parent_stack_id);
197   ref.set_stack_id(GetStackHash(stack));
198   if (parent_id)
199     ref.set_parent_id(*parent_id);
200 
201   if (args_callback) {
202     auto bound_inserter = stack.back().args_tracker.AddArgsTo(id);
203     args_callback(&bound_inserter);
204   }
205   return id;
206 }
207 
CompleteSlice(int64_t timestamp,TrackId track_id,SetArgsCallback args_callback,std::function<std::optional<uint32_t> (const SlicesStack &)> finder)208 std::optional<SliceId> SliceTracker::CompleteSlice(
209     int64_t timestamp,
210     TrackId track_id,
211     SetArgsCallback args_callback,
212     std::function<std::optional<uint32_t>(const SlicesStack&)> finder) {
213   auto* it = stacks_.Find(track_id);
214   if (!it)
215     return std::nullopt;
216 
217   TrackInfo& track_info = *it;
218   SlicesStack& stack = track_info.slice_stack;
219   MaybeCloseStack(timestamp, stack, track_id);
220   if (stack.empty())
221     return std::nullopt;
222 
223   auto* slices = context_->storage->mutable_slice_table();
224   std::optional<uint32_t> stack_idx = finder(stack);
225 
226   // If we are trying to close slices that are not open on the stack (e.g.,
227   // slices that began before tracing started), bail out.
228   if (!stack_idx)
229     return std::nullopt;
230 
231   const auto& slice_info = stack[stack_idx.value()];
232 
233   tables::SliceTable::RowReference ref = slice_info.row.ToRowReference(slices);
234   PERFETTO_DCHECK(ref.dur() == kPendingDuration);
235   ref.set_dur(timestamp - ref.ts());
236 
237   ArgsTracker& tracker = stack[stack_idx.value()].args_tracker;
238   if (args_callback) {
239     auto bound_inserter = tracker.AddArgsTo(ref.id());
240     args_callback(&bound_inserter);
241   }
242 
243   // Add the legacy unnestable args if they exist.
244   if (track_info.is_legacy_unnestable) {
245     auto bound_inserter = tracker.AddArgsTo(ref.id());
246     bound_inserter.AddArg(
247         legacy_unnestable_begin_count_string_id_,
248         Variadic::Integer(track_info.legacy_unnestable_begin_count));
249     bound_inserter.AddArg(
250         legacy_unnestable_last_begin_ts_string_id_,
251         Variadic::Integer(track_info.legacy_unnestable_last_begin_ts));
252   }
253 
254   // If this slice is the top slice on the stack, pop it off.
255   if (*stack_idx == stack.size() - 1) {
256     StackPop(track_id);
257   }
258   return ref.id();
259 }
260 
261 // Returns the first incomplete slice in the stack with matching name and
262 // category. We assume null category/name matches everything. Returns
263 // std::nullopt if no matching slice is found.
MatchingIncompleteSliceIndex(const SlicesStack & stack,StringId name,StringId category)264 std::optional<uint32_t> SliceTracker::MatchingIncompleteSliceIndex(
265     const SlicesStack& stack,
266     StringId name,
267     StringId category) {
268   auto* slices = context_->storage->mutable_slice_table();
269   for (int i = static_cast<int>(stack.size()) - 1; i >= 0; i--) {
270     tables::SliceTable::RowReference ref =
271         stack[static_cast<size_t>(i)].row.ToRowReference(slices);
272     if (ref.dur() != kPendingDuration)
273       continue;
274     std::optional<StringId> other_category = ref.category();
275     if (!category.is_null() && (!other_category || other_category->is_null() ||
276                                 category != other_category)) {
277       continue;
278     }
279     std::optional<StringId> other_name = ref.name();
280     if (!name.is_null() && other_name && !other_name->is_null() &&
281         name != other_name) {
282       continue;
283     }
284     return static_cast<uint32_t>(i);
285   }
286   return std::nullopt;
287 }
288 
MaybeAddTranslatableArgs(SliceInfo & slice_info)289 void SliceTracker::MaybeAddTranslatableArgs(SliceInfo& slice_info) {
290   if (!slice_info.args_tracker.NeedsTranslation(
291           *context_->args_translation_table)) {
292     return;
293   }
294   const auto& table = context_->storage->slice_table();
295   tables::SliceTable::ConstRowReference ref =
296       slice_info.row.ToRowReference(table);
297   translatable_args_.emplace_back(TranslatableArgs{
298       ref.id(),
299       std::move(slice_info.args_tracker)
300           .ToCompactArgSet(table.arg_set_id(), slice_info.row.row_number())});
301 }
302 
FlushPendingSlices()303 void SliceTracker::FlushPendingSlices() {
304   // Clear the remaining stack entries. This ensures that any pending args are
305   // written to the storage. We don't close any slices with kPendingDuration so
306   // that the UI can still distinguish such "incomplete" slices.
307   //
308   // TODO(eseckler): Reconsider whether we want to close pending slices by
309   // setting their duration to |trace_end - event_start|. Might still want some
310   // additional way of flagging these events as "incomplete" to the UI.
311 
312   // Make sure that args for all incomplete slice are translated.
313   for (auto it = stacks_.GetIterator(); it; ++it) {
314     auto& track_info = it.value();
315     for (auto& slice_info : track_info.slice_stack) {
316       MaybeAddTranslatableArgs(slice_info);
317     }
318   }
319 
320   // Translate and flush all pending args.
321   for (const auto& translatable_arg : translatable_args_) {
322     auto bound_inserter =
323         context_->args_tracker->AddArgsTo(translatable_arg.slice_id);
324     context_->args_translation_table->TranslateArgs(
325         translatable_arg.compact_arg_set, bound_inserter);
326   }
327   translatable_args_.clear();
328 
329   stacks_.Clear();
330 }
331 
SetOnSliceBeginCallback(OnSliceBeginCallback callback)332 void SliceTracker::SetOnSliceBeginCallback(OnSliceBeginCallback callback) {
333   on_slice_begin_callback_ = callback;
334 }
335 
GetTopmostSliceOnTrack(TrackId track_id) const336 std::optional<SliceId> SliceTracker::GetTopmostSliceOnTrack(
337     TrackId track_id) const {
338   const auto* iter = stacks_.Find(track_id);
339   if (!iter)
340     return std::nullopt;
341   const auto& stack = iter->slice_stack;
342   if (stack.empty())
343     return std::nullopt;
344   const auto& slice = context_->storage->slice_table();
345   return stack.back().row.ToRowReference(slice).id();
346 }
347 
MaybeCloseStack(int64_t ts,const SlicesStack & stack,TrackId track_id)348 void SliceTracker::MaybeCloseStack(int64_t ts,
349                                    const SlicesStack& stack,
350                                    TrackId track_id) {
351   auto* slices = context_->storage->mutable_slice_table();
352   bool incomplete_descendent = false;
353   for (int i = static_cast<int>(stack.size()) - 1; i >= 0; i--) {
354     tables::SliceTable::RowReference ref =
355         stack[static_cast<size_t>(i)].row.ToRowReference(slices);
356 
357     int64_t start_ts = ref.ts();
358     int64_t dur = ref.dur();
359     int64_t end_ts = start_ts + dur;
360     if (dur == kPendingDuration) {
361       incomplete_descendent = true;
362       continue;
363     }
364 
365     if (incomplete_descendent) {
366       PERFETTO_DCHECK(ts >= start_ts);
367 
368       // Only process slices if the ts is past the end of the slice.
369       if (ts <= end_ts)
370         continue;
371 
372       // This usually happens because we have two slices that are partially
373       // overlapping.
374       // [  slice  1    ]
375       //          [     slice 2     ]
376       // This is invalid in chrome and should be fixed. Duration events should
377       // either be nested or disjoint, never partially intersecting.
378       // KI: if tracing both binder and system calls on android, "binder reply"
379       // slices will try to escape the enclosing sys_ioctl.
380       PERFETTO_DLOG(
381           "Incorrect ordering of begin/end slice events. "
382           "Truncating incomplete descendants to the end of slice "
383           "%s[%" PRId64 ", %" PRId64 "] due to an event at ts=%" PRId64 ".",
384           context_->storage->GetString(ref.name().value_or(kNullStringId))
385               .c_str(),
386           start_ts, end_ts, ts);
387       context_->storage->IncrementStats(stats::misplaced_end_event);
388 
389       // Every slice below this one should have a pending duration. Update
390       // of them to have the end ts of the current slice and pop them
391       // all off.
392       for (int j = static_cast<int>(stack.size()) - 1; j > i; --j) {
393         tables::SliceTable::RowReference child_ref =
394             stack[static_cast<size_t>(j)].row.ToRowReference(slices);
395         PERFETTO_DCHECK(child_ref.dur() == kPendingDuration);
396         child_ref.set_dur(end_ts - child_ref.ts());
397         StackPop(track_id);
398       }
399 
400       // Also pop the current row itself and reset the incomplete flag.
401       StackPop(track_id);
402       incomplete_descendent = false;
403 
404       continue;
405     }
406 
407     if (end_ts <= ts) {
408       StackPop(track_id);
409     }
410   }
411 }
412 
GetStackHash(const SlicesStack & stack)413 int64_t SliceTracker::GetStackHash(const SlicesStack& stack) {
414   PERFETTO_DCHECK(!stack.empty());
415 
416   const auto& slices = context_->storage->slice_table();
417 
418   base::Hasher hash;
419   for (const auto& i : stack) {
420     auto ref = i.row.ToRowReference(slices);
421     hash.Update(ref.category().value_or(kNullStringId).raw_id());
422     hash.Update(ref.name().value_or(kNullStringId).raw_id());
423   }
424 
425   // For clients which don't have an integer type (i.e. Javascript), returning
426   // hashes which have the top 11 bits set leads to numbers which are
427   // unrepresenatble. This means that clients cannot filter using this number as
428   // it will be meaningless when passed back to us. For this reason, make sure
429   // that the hash is always less than 2^53 - 1.
430   constexpr uint64_t kSafeBitmask = (1ull << 53) - 1;
431   return static_cast<int64_t>(hash.digest() & kSafeBitmask);
432 }
433 
StackPop(TrackId track_id)434 void SliceTracker::StackPop(TrackId track_id) {
435   auto& stack = stacks_[track_id].slice_stack;
436   MaybeAddTranslatableArgs(stack.back());
437   stack.pop_back();
438 }
439 
StackPush(TrackId track_id,tables::SliceTable::RowReference ref)440 void SliceTracker::StackPush(TrackId track_id,
441                              tables::SliceTable::RowReference ref) {
442   stacks_[track_id].slice_stack.push_back(
443       SliceInfo{ref.ToRowNumber(), ArgsTracker(context_)});
444   if (on_slice_begin_callback_) {
445     on_slice_begin_callback_(track_id, ref.id());
446   }
447 }
448 
449 }  // namespace perfetto::trace_processor
450