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 "src/trace_processor/importers/systrace/systrace_parser.h"
18
19 #include "perfetto/ext/base/optional.h"
20 #include "src/trace_processor/importers/common/event_tracker.h"
21 #include "src/trace_processor/importers/common/process_tracker.h"
22 #include "src/trace_processor/importers/common/slice_tracker.h"
23 #include "src/trace_processor/importers/common/track_tracker.h"
24 #include "src/trace_processor/importers/proto/async_track_set_tracker.h"
25
26 namespace perfetto {
27 namespace trace_processor {
28
SystraceParser(TraceProcessorContext * ctx)29 SystraceParser::SystraceParser(TraceProcessorContext* ctx)
30 : context_(ctx),
31 lmk_id_(ctx->storage->InternString("mem.lmk")),
32 screen_state_id_(ctx->storage->InternString("ScreenState")),
33 cookie_id_(ctx->storage->InternString("cookie")) {}
34
35 SystraceParser::~SystraceParser() = default;
36
ParsePrintEvent(int64_t ts,uint32_t pid,base::StringView event)37 void SystraceParser::ParsePrintEvent(int64_t ts,
38 uint32_t pid,
39 base::StringView event) {
40 systrace_utils::SystraceTracePoint point{};
41 switch (ParseSystraceTracePoint(event, &point)) {
42 case systrace_utils::SystraceParseResult::kSuccess:
43 ParseSystracePoint(ts, pid, point);
44 break;
45 case systrace_utils::SystraceParseResult::kFailure:
46 context_->storage->IncrementStats(stats::systrace_parse_failure);
47 break;
48 case systrace_utils::SystraceParseResult::kUnsupported:
49 // Silently ignore unsupported results.
50 break;
51 }
52 }
53
ParseZeroEvent(int64_t ts,uint32_t pid,int32_t flag,base::StringView name,uint32_t,int64_t value)54 void SystraceParser::ParseZeroEvent(int64_t ts,
55 uint32_t pid,
56 int32_t flag,
57 base::StringView name,
58 uint32_t /* tgid */,
59 int64_t value) {
60 systrace_utils::SystraceTracePoint point{};
61 point.name = name;
62 point.value = static_cast<double>(value);
63
64 // Hardcode the tgid to 0 (i.e. no tgid available) because zero events can
65 // come from kernel threads and as we group kernel threads into the kthreadd
66 // process, we would want |point.tgid == kKthreaddPid|. However, we don't have
67 // acces to the ppid of this process so we have to not associate to any
68 // process and leave the resolution of process to other events.
69 // TODO(lalitm): remove this hack once we move kernel thread grouping to
70 // the UI.
71 point.tgid = 0;
72
73 // The value of these constants can be found in the msm-google kernel.
74 constexpr int32_t kSystraceEventBegin = 1 << 0;
75 constexpr int32_t kSystraceEventEnd = 1 << 1;
76 constexpr int32_t kSystraceEventInt64 = 1 << 2;
77
78 if ((flag & kSystraceEventBegin) != 0) {
79 point.phase = 'B';
80 } else if ((flag & kSystraceEventEnd) != 0) {
81 point.phase = 'E';
82 } else if ((flag & kSystraceEventInt64) != 0) {
83 point.phase = 'C';
84 } else {
85 context_->storage->IncrementStats(stats::systrace_parse_failure);
86 return;
87 }
88 ParseSystracePoint(ts, pid, point);
89 }
90
ParseTracingMarkWrite(int64_t ts,uint32_t pid,char trace_type,bool trace_begin,base::StringView trace_name,uint32_t,int64_t value)91 void SystraceParser::ParseTracingMarkWrite(int64_t ts,
92 uint32_t pid,
93 char trace_type,
94 bool trace_begin,
95 base::StringView trace_name,
96 uint32_t /* tgid */,
97 int64_t value) {
98 systrace_utils::SystraceTracePoint point{};
99 point.name = trace_name;
100
101 // Hardcode the tgid to 0 (i.e. no tgid available) because
102 // sde_tracing_mark_write events can come from kernel threads and because we
103 // group kernel threads into the kthreadd process, we would want |point.tgid
104 // == kKthreaddPid|. However, we don't have acces to the ppid of this process
105 // so we have to not associate to any process and leave the resolution of
106 // process to other events.
107 // TODO(lalitm): remove this hack once we move kernel thread grouping to
108 // the UI.
109 point.tgid = 0;
110
111 point.value = static_cast<double>(value);
112 // Some versions of this trace point fill trace_type with one of (B/E/C),
113 // others use the trace_begin boolean and only support begin/end events:
114 if (trace_type == 0) {
115 point.phase = trace_begin ? 'B' : 'E';
116 } else if (trace_type == 'B' || trace_type == 'E' || trace_type == 'C') {
117 point.phase = trace_type;
118 } else {
119 context_->storage->IncrementStats(stats::systrace_parse_failure);
120 return;
121 }
122
123 ParseSystracePoint(ts, pid, point);
124 }
125
ParseSystracePoint(int64_t ts,uint32_t pid,systrace_utils::SystraceTracePoint point)126 void SystraceParser::ParseSystracePoint(
127 int64_t ts,
128 uint32_t pid,
129 systrace_utils::SystraceTracePoint point) {
130 switch (point.phase) {
131 case 'B': {
132 StringId name_id = context_->storage->InternString(point.name);
133 UniqueTid utid;
134 if (point.tgid == 0) {
135 utid = context_->process_tracker->GetOrCreateThread(pid);
136 } else {
137 utid = context_->process_tracker->UpdateThread(pid, point.tgid);
138 }
139 TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
140 context_->slice_tracker->Begin(ts, track_id, kNullStringId /* cat */,
141 name_id);
142 break;
143 }
144
145 case 'E': {
146 // |point.tgid| can be 0 in older android versions where the end event
147 // would not contain the value.
148 UniqueTid utid;
149 if (point.tgid == 0) {
150 // If we haven't seen this thread before, there can't have been a Begin
151 // event for it so just ignore the event.
152 auto opt_utid = context_->process_tracker->GetThreadOrNull(pid);
153 if (!opt_utid)
154 break;
155 utid = *opt_utid;
156 } else {
157 utid = context_->process_tracker->UpdateThread(pid, point.tgid);
158 }
159 TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
160 context_->slice_tracker->End(ts, track_id);
161 break;
162 }
163
164 case 'S':
165 case 'F': {
166 StringId name_id = context_->storage->InternString(point.name);
167 int64_t cookie = static_cast<int64_t>(point.value);
168 UniquePid upid =
169 context_->process_tracker->GetOrCreateProcess(point.tgid);
170
171 auto track_set_id =
172 context_->async_track_set_tracker->InternAndroidSet(upid, name_id);
173
174 if (point.phase == 'S') {
175 // Historically, async slices on Android did not support nesting async
176 // slices (i.e. you could not have a stack of async slices). If clients
177 // were implemented correctly, we would simply be able to use the normal
178 // Begin method and we could rely on the traced code to never emit two
179 // 'S' events back to back on the same track.
180 // However, there exists buggy code in Android (in Wakelock class of
181 // PowerManager) which emits an arbitrary number of 'S' events and
182 // expects only the first one to be tracked. Moreover, this issue is
183 // compounded by an unfortunate implementation of async slices in
184 // Catapult (the legacy trace viewer) which simply tracks the details of
185 // the *most recent* emitted 'S' event which leads even more inaccurate
186 // behaviour. To support these quirks, we have the special 'unnestable'
187 // slice concept which implements workarounds for these very specific
188 // issues. No other code should ever use this method.
189 tables::SliceTable::Row row;
190 row.ts = ts;
191 row.track_id =
192 context_->async_track_set_tracker->Begin(track_set_id, cookie);
193 row.name = name_id;
194 context_->slice_tracker->BeginLegacyUnnestable(
195 row, [this, cookie](ArgsTracker::BoundInserter* inserter) {
196 inserter->AddArg(cookie_id_, Variadic::Integer(cookie));
197 });
198 } else {
199 TrackId track_id =
200 context_->async_track_set_tracker->End(track_set_id, cookie);
201 context_->slice_tracker->End(ts, track_id);
202 }
203 break;
204 }
205
206 case 'C': {
207 // LMK events from userspace are hacked as counter events with the "value"
208 // of the counter representing the pid of the killed process which is
209 // reset to 0 once the kill is complete.
210 // Homogenise this with kernel LMK events as an instant event, ignoring
211 // the resets to 0.
212 if (point.name == "kill_one_process") {
213 auto killed_pid = static_cast<uint32_t>(point.value);
214 if (killed_pid != 0) {
215 UniquePid killed_upid =
216 context_->process_tracker->GetOrCreateProcess(killed_pid);
217 context_->event_tracker->PushInstant(ts, lmk_id_, killed_upid,
218 RefType::kRefUpid);
219 }
220 // TODO(lalitm): we should not add LMK events to the counters table
221 // once the UI has support for displaying instants.
222 } else if (point.name == "ScreenState") {
223 // Promote ScreenState to its own top level counter.
224 TrackId track =
225 context_->track_tracker->InternGlobalCounterTrack(screen_state_id_);
226 context_->event_tracker->PushCounter(ts, point.value, track);
227 return;
228 }
229
230 StringId name_id = context_->storage->InternString(point.name);
231 TrackId track_id;
232 if (point.tgid == 0) {
233 // If tgid is 0 (likely because this is a kernel thread), we can do no
234 // better than using a thread track with the pid of the process.
235 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
236 track_id =
237 context_->track_tracker->InternThreadCounterTrack(name_id, utid);
238 } else {
239 // This is per upid on purpose. Some counters are pushed from arbitrary
240 // threads but are really per process.
241 UniquePid upid =
242 context_->process_tracker->GetOrCreateProcess(point.tgid);
243 track_id =
244 context_->track_tracker->InternProcessCounterTrack(name_id, upid);
245 }
246 context_->event_tracker->PushCounter(ts, point.value, track_id);
247 }
248 }
249 }
250
251 } // namespace trace_processor
252 } // namespace perfetto
253