Skip to content

Commit 3fdb390

Browse files
PriyankaSPXPriyankaSPX
authored
tp: Provide transition timestamps in table for drawing pending and playing stages. (#4733)
Less confusing UX in Winscope. Prioritise send time over dispatch time for transition timestamp. Set status and duration on flush after all proto packets have been processed for increased clarity. Bug: 481316747 Test: tools/diff_test_trace_processor.py out/linux_clang_release/trace_processor_shell --name-filter="ShellTransition|PerfettoTable:winscope"
1 parent b2adca0 commit 3fdb390

File tree

7 files changed

+188
-71
lines changed

7 files changed

+188
-71
lines changed

‎src/trace_processor/importers/proto/winscope/shell_transitions_parser.cc‎

Lines changed: 33 additions & 42 deletions
Original file line numberDiff line numberDiff line change
@@ -23,6 +23,7 @@
2323
#include "perfetto/ext/base/string_view.h"
2424
#include "perfetto/protozero/field.h"
2525
#include "protos/perfetto/trace/android/shell_transition.pbzero.h"
26+
#include "src/trace_processor/containers/string_pool.h"
2627
#include "src/trace_processor/importers/proto/args_parser.h"
2728
#include "src/trace_processor/importers/proto/winscope/shell_transitions_tracker.h"
2829
#include "src/trace_processor/importers/proto/winscope/winscope_context.h"
@@ -42,14 +43,16 @@ ShellTransitionsParser::ShellTransitionsParser(
4243

4344
void ShellTransitionsParser::ParseTransition(protozero::ConstBytes blob) {
4445
protos::pbzero::ShellTransition::Decoder transition(blob);
46+
auto transition_id = transition.id();
4547

4648
auto* storage = context_->trace_processor_context_->storage.get();
49+
auto* string_pool = storage->mutable_string_pool();
4750

4851
// Store the raw proto and its ID in a separate table to handle
4952
// transitions received over multiple packets for Winscope trace search.
5053
tables::WindowManagerShellTransitionProtosTable::Row row;
51-
row.transition_id = transition.id();
52-
row.base64_proto_id = storage->mutable_string_pool()
54+
row.transition_id = transition_id;
55+
row.base64_proto_id = string_pool
5356
->InternString(base::StringView(
5457
base::Base64Encode(blob.data, blob.size)))
5558
.raw_id();
@@ -58,8 +61,8 @@ void ShellTransitionsParser::ParseTransition(protozero::ConstBytes blob) {
5861
// Track transition args as the come in through different packets
5962
winscope::ShellTransitionsTracker& transition_tracker =
6063
context_->shell_transitions_tracker_;
61-
auto inserter = transition_tracker.AddArgsTo(transition.id());
62-
ArgsParser writer(/*timestamp=*/0, inserter, *storage);
64+
auto inserter = transition_tracker.AddArgsTo(transition_id);
65+
ArgsParser writer(/*packet_timestamp=*/0, inserter, *storage);
6366
base::Status status = args_parser_.ParseMessage(
6467
blob,
6568
*util::winscope_proto_mapping::GetProtoName(
@@ -71,64 +74,52 @@ void ShellTransitionsParser::ParseTransition(protozero::ConstBytes blob) {
7174
}
7275

7376
if (transition.has_type()) {
74-
transition_tracker.SetTransitionType(transition.id(), transition.type());
77+
transition_tracker.SetTransitionType(transition_id, transition.type());
7578
}
7679

77-
if (transition.has_dispatch_time_ns()) {
78-
transition_tracker.SetDispatchTime(transition.id(),
79-
transition.dispatch_time_ns());
80-
transition_tracker.SetTimestamp(transition.id(),
81-
transition.dispatch_time_ns());
80+
if (transition.has_send_time_ns()) {
81+
transition_tracker.SetSendTime(transition_id, transition.send_time_ns());
82+
transition_tracker.SetTimestamp(transition_id, transition.send_time_ns());
8283
}
8384

84-
if (transition.has_send_time_ns()) {
85-
transition_tracker.SetSendTime(transition.id(), transition.send_time_ns());
86-
transition_tracker.SetTimestampIfEmpty(transition.id(),
87-
transition.send_time_ns());
85+
if (transition.has_dispatch_time_ns()) {
86+
transition_tracker.SetDispatchTime(transition_id,
87+
transition.dispatch_time_ns());
88+
transition_tracker.SetTimestampIfEmpty(transition_id,
89+
transition.dispatch_time_ns());
8890
}
8991

9092
if (transition.has_shell_abort_time_ns()) {
91-
transition_tracker.SetShellAbortTime(transition.id(),
93+
transition_tracker.SetShellAbortTime(transition_id,
9294
transition.shell_abort_time_ns());
9395
}
9496

97+
if (transition.has_wm_abort_time_ns()) {
98+
transition_tracker.SetWmAbortTime(transition_id,
99+
transition.wm_abort_time_ns());
100+
}
101+
95102
if (transition.has_finish_time_ns()) {
96103
auto finish_time = transition.finish_time_ns();
97-
transition_tracker.SetFinishTime(transition.id(), finish_time);
98-
99-
if (finish_time > 0) {
100-
transition_tracker.SetStatus(
101-
transition.id(),
102-
storage->mutable_string_pool()->InternString("played"));
103-
}
104+
transition_tracker.SetFinishTime(transition_id, finish_time);
104105
}
105106

106107
if (transition.has_handler()) {
107-
transition_tracker.SetHandler(transition.id(), transition.handler());
108+
transition_tracker.SetHandler(transition_id, transition.handler());
108109
}
109110

110-
auto shell_aborted = transition.has_shell_abort_time_ns() &&
111-
transition.shell_abort_time_ns() > 0;
112-
auto wm_aborted =
113-
transition.has_wm_abort_time_ns() && transition.wm_abort_time_ns() > 0;
114-
115-
if (shell_aborted || wm_aborted) {
116-
transition_tracker.SetStatus(
117-
transition.id(),
118-
storage->mutable_string_pool()->InternString("aborted"));
111+
if (transition.has_merge_time_ns()) {
112+
transition_tracker.SetMergeTime(transition_id, transition.merge_time_ns());
119113
}
120114

121-
auto merged =
122-
transition.has_merge_time_ns() && transition.merge_time_ns() > 0;
123-
if (merged) {
124-
transition_tracker.SetStatus(
125-
transition.id(),
126-
storage->mutable_string_pool()->InternString("merged"));
115+
if (transition.has_create_time_ns()) {
116+
transition_tracker.SetCreateTime(transition_id,
117+
transition.create_time_ns());
127118
}
128119

129120
// set flags id and flags
130121
if (transition.has_flags()) {
131-
transition_tracker.SetFlags(transition.id(), transition.flags());
122+
transition_tracker.SetFlags(transition_id, transition.flags());
132123
}
133124

134125
// update participants
@@ -138,7 +129,7 @@ void ShellTransitionsParser::ParseTransition(protozero::ConstBytes blob) {
138129
for (auto it = transition.targets(); it; ++it) {
139130
tables::WindowManagerShellTransitionParticipantsTable::Row
140131
participant_row;
141-
participant_row.transition_id = transition.id();
132+
participant_row.transition_id = transition_id;
142133
protos::pbzero::ShellTransition::Target::Decoder target(*it);
143134
if (target.has_layer_id()) {
144135
participant_row.layer_id = target.layer_id();
@@ -151,13 +142,13 @@ void ShellTransitionsParser::ParseTransition(protozero::ConstBytes blob) {
151142
}
152143

153144
if (transition.has_start_transaction_id()) {
154-
transition_tracker.SetStartTransactionId(transition.id(),
145+
transition_tracker.SetStartTransactionId(transition_id,
155146
transition.start_transaction_id());
156147
}
157148

158149
if (transition.has_finish_transaction_id()) {
159150
transition_tracker.SetFinishTransactionId(
160-
transition.id(), transition.finish_transaction_id());
151+
transition_id, transition.finish_transaction_id());
161152
}
162153
}
163154

‎src/trace_processor/importers/proto/winscope/shell_transitions_tracker.cc‎

Lines changed: 68 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -16,10 +16,17 @@
1616

1717
#include "src/trace_processor/importers/proto/winscope/shell_transitions_tracker.h"
1818
#include <cstdint>
19+
#include <optional>
1920
#include "src/trace_processor/types/trace_processor_context.h"
2021

2122
namespace perfetto::trace_processor::winscope {
2223

24+
namespace {
25+
bool IsValid(std::optional<int64_t> timestamp_ns) {
26+
return timestamp_ns.has_value() && timestamp_ns.value() > 0;
27+
}
28+
} // namespace
29+
2330
ShellTransitionsTracker::ShellTransitionsTracker(TraceProcessorContext* context)
2431
: context_(context) {}
2532

@@ -63,10 +70,6 @@ void ShellTransitionsTracker::SetSendTime(int32_t transition_id,
6370
auto row = GetRowReference(transition_id);
6471
if (row.has_value()) {
6572
row.value().set_send_time_ns(send_time_ns);
66-
auto finish_time_ns = row->finish_time_ns();
67-
if (finish_time_ns.has_value()) {
68-
row.value().set_duration_ns(finish_time_ns.value() - send_time_ns);
69-
}
7073
}
7174
}
7275

@@ -83,10 +86,6 @@ void ShellTransitionsTracker::SetFinishTime(int32_t transition_id,
8386
auto row = GetRowReference(transition_id);
8487
if (row.has_value()) {
8588
row->set_finish_time_ns(finish_time_ns);
86-
auto send_time_ns = row->send_time_ns();
87-
if (send_time_ns.has_value()) {
88-
row.value().set_duration_ns(finish_time_ns - send_time_ns.value());
89-
}
9089
}
9190
}
9291

@@ -98,26 +97,42 @@ void ShellTransitionsTracker::SetShellAbortTime(int32_t transition_id,
9897
}
9998
}
10099

101-
void ShellTransitionsTracker::SetHandler(int32_t transition_id,
102-
int64_t handler) {
100+
void ShellTransitionsTracker::SetWmAbortTime(int32_t transition_id,
101+
int64_t timestamp_ns) {
103102
auto row = GetRowReference(transition_id);
104103
if (row.has_value()) {
105-
row.value().set_handler(handler);
104+
row.value().set_wm_abort_time_ns(timestamp_ns);
106105
}
107106
}
108107

109-
void ShellTransitionsTracker::SetFlags(int32_t transition_id, int32_t flags) {
108+
void ShellTransitionsTracker::SetMergeTime(int32_t transition_id,
109+
int64_t merge_time_ns) {
110110
auto row = GetRowReference(transition_id);
111111
if (row.has_value()) {
112-
row.value().set_flags(static_cast<uint32_t>(flags));
112+
row->set_merge_time_ns(merge_time_ns);
113113
}
114114
}
115115

116-
void ShellTransitionsTracker::SetStatus(int32_t transition_id,
117-
StringPool::Id status) {
116+
void ShellTransitionsTracker::SetCreateTime(int32_t transition_id,
117+
int64_t create_time_ns) {
118118
auto row = GetRowReference(transition_id);
119119
if (row.has_value()) {
120-
row.value().set_status(status);
120+
row->set_create_time_ns(create_time_ns);
121+
}
122+
}
123+
124+
void ShellTransitionsTracker::SetHandler(int32_t transition_id,
125+
int64_t handler) {
126+
auto row = GetRowReference(transition_id);
127+
if (row.has_value()) {
128+
row.value().set_handler(handler);
129+
}
130+
}
131+
132+
void ShellTransitionsTracker::SetFlags(int32_t transition_id, int32_t flags) {
133+
auto row = GetRowReference(transition_id);
134+
if (row.has_value()) {
135+
row.value().set_flags(static_cast<uint32_t>(flags));
121136
}
122137
}
123138

@@ -138,6 +153,7 @@ void ShellTransitionsTracker::SetFinishTransactionId(int32_t transition_id,
138153
}
139154

140155
void ShellTransitionsTracker::Flush() {
156+
SetStatusesAndDurations();
141157
// The destructor of ArgsTracker will flush the args to the tables.
142158
transitions_infos_.clear();
143159
}
@@ -163,6 +179,42 @@ ShellTransitionsTracker::GetOrInsertTransition(int32_t transition_id) {
163179
return &pos->second;
164180
}
165181

182+
void ShellTransitionsTracker::SetStatusesAndDurations() {
183+
auto* string_pool = context_->storage.get()->mutable_string_pool();
184+
auto* table =
185+
context_->storage->mutable_window_manager_shell_transitions_table();
186+
187+
for (auto it = table->IterateRows(); it; ++it) {
188+
if (IsValid(it.merge_time_ns())) {
189+
// Assume that merged transitions will never be dispatched.
190+
it.set_status(string_pool->InternString("merged"));
191+
continue;
192+
}
193+
194+
auto has_dispatch_time = IsValid(it.dispatch_time_ns());
195+
auto has_finish_time = IsValid(it.finish_time_ns());
196+
197+
if (has_dispatch_time && has_finish_time) {
198+
it.set_duration_ns(it.finish_time_ns().value() -
199+
it.dispatch_time_ns().value());
200+
// Only assume a transition has been played if it has been both dispatched
201+
// and finished.
202+
it.set_status(string_pool->InternString("played"));
203+
continue;
204+
}
205+
206+
auto has_abort_time =
207+
IsValid(it.shell_abort_time_ns()) || IsValid(it.wm_abort_time_ns());
208+
if (has_abort_time && !has_dispatch_time) {
209+
// WM can call abort at any time, but playing transitions cannot be
210+
// aborted, so only set status to "aborted" if transition has not been
211+
// dispatched.
212+
it.set_status(string_pool->InternString("aborted"));
213+
continue;
214+
}
215+
}
216+
}
217+
166218
std::optional<tables::WindowManagerShellTransitionsTable::RowReference>
167219
ShellTransitionsTracker::GetRowReference(int32_t transition_id) {
168220
auto pos = transitions_infos_.find(transition_id);

‎src/trace_processor/importers/proto/winscope/shell_transitions_tracker.h‎

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -40,10 +40,12 @@ class ShellTransitionsTracker {
4040
void SetSendTime(int32_t transition_id, int64_t timestamp_ns);
4141
void SetDispatchTime(int32_t transition_id, int64_t timestamp_ns);
4242
void SetShellAbortTime(int32_t transition_id, int64_t timestamp_ns);
43+
void SetWmAbortTime(int32_t transition_id, int64_t timestamp_ns);
4344
void SetFinishTime(int32_t transition_id, int64_t finish_time_ns);
45+
void SetMergeTime(int32_t transition_id, int64_t merge_time_ns);
46+
void SetCreateTime(int32_t transition_id, int64_t create_time_ns);
4447
void SetHandler(int32_t transition_id, int64_t handler);
4548
void SetFlags(int32_t transition_id, int32_t flags);
46-
void SetStatus(int32_t transition_id, StringPool::Id status);
4749
void SetStartTransactionId(int32_t transition_id, uint64_t transaction_id);
4850
void SetFinishTransactionId(int32_t transition_id, uint64_t transaction_id);
4951

@@ -60,6 +62,8 @@ class ShellTransitionsTracker {
6062
std::optional<tables::WindowManagerShellTransitionsTable::RowReference>
6163
GetRowReference(int32_t transition_id);
6264

65+
void SetStatusesAndDurations();
66+
6367
TraceProcessorContext* context_;
6468
std::unordered_map<int32_t, TransitionInfo> transitions_infos_;
6569
};

‎src/trace_processor/tables/winscope_tables.py‎

Lines changed: 21 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -616,6 +616,21 @@
616616
CppOptional(CppInt64()),
617617
cpp_access=CppAccess.READ_AND_LOW_PERF_WRITE,
618618
),
619+
C(
620+
'wm_abort_time_ns',
621+
CppOptional(CppInt64()),
622+
cpp_access=CppAccess.READ_AND_LOW_PERF_WRITE,
623+
),
624+
C(
625+
'merge_time_ns',
626+
CppOptional(CppInt64()),
627+
cpp_access=CppAccess.READ_AND_LOW_PERF_WRITE,
628+
),
629+
C(
630+
'create_time_ns',
631+
CppOptional(CppInt64()),
632+
cpp_access=CppAccess.READ_AND_LOW_PERF_WRITE,
633+
),
619634
C(
620635
'handler',
621636
CppOptional(CppInt64()),
@@ -664,6 +679,12 @@
664679
'Transition finish time',
665680
'shell_abort_time_ns':
666681
'Transition shell abort time',
682+
'wm_abort_time_ns':
683+
'Transition wm abort time',
684+
'merge_time_ns':
685+
'Transition merge time',
686+
'create_time_ns':
687+
'Transition create time',
667688
'handler':
668689
'Handler id',
669690
'status':

0 commit comments

Comments
 (0)