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