1 /*
2 * Copyright (C) 2020 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_line_parser.h"
18
19 #include "perfetto/ext/base/flat_hash_map.h"
20 #include "perfetto/ext/base/string_splitter.h"
21 #include "perfetto/ext/base/string_utils.h"
22 #include "src/trace_processor/importers/common/args_tracker.h"
23 #include "src/trace_processor/importers/common/event_tracker.h"
24 #include "src/trace_processor/importers/common/process_tracker.h"
25 #include "src/trace_processor/importers/common/slice_tracker.h"
26 #include "src/trace_processor/importers/common/thread_state_tracker.h"
27 #include "src/trace_processor/importers/common/track_tracker.h"
28 #include "src/trace_processor/importers/ftrace/binder_tracker.h"
29 #include "src/trace_processor/importers/ftrace/ftrace_sched_event_tracker.h"
30 #include "src/trace_processor/importers/systrace/systrace_parser.h"
31 #include "src/trace_processor/types/task_state.h"
32
33 #include <cctype>
34 #include <cinttypes>
35 #include <string>
36
37 namespace perfetto {
38 namespace trace_processor {
39
SystraceLineParser(TraceProcessorContext * ctx)40 SystraceLineParser::SystraceLineParser(TraceProcessorContext* ctx)
41 : context_(ctx),
42 rss_stat_tracker_(context_),
43 sched_wakeup_name_id_(ctx->storage->InternString("sched_wakeup")),
44 sched_waking_name_id_(ctx->storage->InternString("sched_waking")),
45 cpufreq_name_id_(ctx->storage->InternString("cpufreq")),
46 cpuidle_name_id_(ctx->storage->InternString("cpuidle")),
47 workqueue_name_id_(ctx->storage->InternString("workqueue")),
48 sched_blocked_reason_id_(
49 ctx->storage->InternString("sched_blocked_reason")),
50 io_wait_id_(ctx->storage->InternString("io_wait")),
51 waker_utid_id_(ctx->storage->InternString("waker_utid")),
52 unknown_thread_name_id_(ctx->storage->InternString("<...>")) {}
53
ParseLine(const SystraceLine & line)54 util::Status SystraceLineParser::ParseLine(const SystraceLine& line) {
55 const StringId line_task_id{
56 context_->storage->InternString(base::StringView(line.task))};
57 auto utid = context_->process_tracker->UpdateThreadName(
58 line.pid,
59 // Ftrace doesn't always know the thread name (see ftrace documentation
60 // for saved_cmdlines) so some lines name a process "<...>". Don't use
61 // this bogus name for thread naming otherwise a real name from a previous
62 // line could be overwritten.
63 line_task_id == unknown_thread_name_id_ ? StringId::Null() : line_task_id,
64 ThreadNamePriority::kFtrace);
65
66 if (!line.tgid_str.empty() && line.tgid_str != "-----") {
67 std::optional<uint32_t> tgid = base::StringToUInt32(line.tgid_str);
68 if (tgid) {
69 context_->process_tracker->UpdateThread(line.pid, tgid.value());
70 }
71 }
72
73 base::FlatHashMap<std::string, std::string> args;
74 for (base::StringSplitter ss(line.args_str, ' '); ss.Next();) {
75 std::string key;
76 std::string value;
77 if (!base::Contains(ss.cur_token(), "=")) {
78 key = "name";
79 value = ss.cur_token();
80 args.Insert(std::move(key), std::move(value));
81 continue;
82 }
83 for (base::StringSplitter inner(ss.cur_token(), '='); inner.Next();) {
84 if (key.empty()) {
85 key = inner.cur_token();
86 } else {
87 value = inner.cur_token();
88 }
89 }
90 args.Insert(std::move(key), std::move(value));
91 }
92 if (line.event_name == "sched_switch") {
93 auto prev_state_str = args["prev_state"];
94 int64_t prev_state =
95 ftrace_utils::TaskState::FromSystrace(prev_state_str.c_str())
96 .ToRawStateOnlyForSystraceConversions();
97
98 auto prev_pid = base::StringToUInt32(args["prev_pid"]);
99 auto prev_comm = base::StringView(args["prev_comm"]);
100 auto prev_prio = base::StringToInt32(args["prev_prio"]);
101 auto next_pid = base::StringToUInt32(args["next_pid"]);
102 auto next_comm = base::StringView(args["next_comm"]);
103 auto next_prio = base::StringToInt32(args["next_prio"]);
104
105 if (!(prev_pid.has_value() && prev_prio.has_value() &&
106 next_pid.has_value() && next_prio.has_value())) {
107 return util::Status("Could not parse sched_switch");
108 }
109
110 FtraceSchedEventTracker::GetOrCreate(context_)->PushSchedSwitch(
111 line.cpu, line.ts, prev_pid.value(), prev_comm, prev_prio.value(),
112 prev_state, next_pid.value(), next_comm, next_prio.value());
113 } else if (line.event_name == "tracing_mark_write" ||
114 line.event_name == "0" || line.event_name == "print") {
115 SystraceParser::GetOrCreate(context_)->ParsePrintEvent(
116 line.ts, line.pid, line.args_str.c_str());
117 } else if (line.event_name == "sched_waking") {
118 auto comm = args["comm"];
119 std::optional<uint32_t> wakee_pid = base::StringToUInt32(args["pid"]);
120 if (!wakee_pid.has_value()) {
121 return util::Status("Could not convert wakee_pid");
122 }
123
124 StringId name_id = context_->storage->InternString(base::StringView(comm));
125 auto wakee_utid = context_->process_tracker->UpdateThreadName(
126 wakee_pid.value(), name_id, ThreadNamePriority::kFtrace);
127
128 ThreadStateTracker::GetOrCreate(context_)->PushWakingEvent(
129 line.ts, wakee_utid, utid);
130
131 } else if (line.event_name == "cpu_frequency") {
132 std::optional<uint32_t> event_cpu = base::StringToUInt32(args["cpu_id"]);
133 std::optional<double> new_state = base::StringToDouble(args["state"]);
134 if (!event_cpu.has_value()) {
135 return util::Status("Could not convert event cpu");
136 }
137 if (!event_cpu.has_value()) {
138 return util::Status("Could not convert state");
139 }
140
141 TrackId track = context_->track_tracker->InternCpuCounterTrack(
142 cpufreq_name_id_, event_cpu.value());
143 context_->event_tracker->PushCounter(line.ts, new_state.value(), track);
144 } else if (line.event_name == "cpu_idle") {
145 std::optional<uint32_t> event_cpu = base::StringToUInt32(args["cpu_id"]);
146 std::optional<double> new_state = base::StringToDouble(args["state"]);
147 if (!event_cpu.has_value()) {
148 return util::Status("Could not convert event cpu");
149 }
150 if (!event_cpu.has_value()) {
151 return util::Status("Could not convert state");
152 }
153
154 TrackId track = context_->track_tracker->InternCpuCounterTrack(
155 cpuidle_name_id_, event_cpu.value());
156 context_->event_tracker->PushCounter(line.ts, new_state.value(), track);
157 } else if (line.event_name == "binder_transaction") {
158 auto id = base::StringToInt32(args["transaction"]);
159 auto dest_node = base::StringToInt32(args["dest_node"]);
160 auto dest_tgid = base::StringToUInt32(args["dest_proc"]);
161 auto dest_tid = base::StringToUInt32(args["dest_thread"]);
162 auto is_reply = base::StringToInt32(args["reply"]).value() == 1;
163 auto flags_str = args["flags"];
164 char* end;
165 uint32_t flags = static_cast<uint32_t>(strtol(flags_str.c_str(), &end, 16));
166 std::string code_str = args["code"] + " Java Layer Dependent";
167 StringId code = context_->storage->InternString(base::StringView(code_str));
168 if (!dest_tgid.has_value()) {
169 return util::Status("Could not convert dest_tgid");
170 }
171 if (!dest_tid.has_value()) {
172 return util::Status("Could not convert dest_tid");
173 }
174 if (!id.has_value()) {
175 return util::Status("Could not convert transaction id");
176 }
177 if (!dest_node.has_value()) {
178 return util::Status("Could not covert dest node");
179 }
180 BinderTracker::GetOrCreate(context_)->Transaction(
181 line.ts, line.pid, id.value(), dest_node.value(), dest_tgid.value(),
182 dest_tid.value(), is_reply, flags, code);
183 } else if (line.event_name == "binder_transaction_received") {
184 auto id = base::StringToInt32(args["transaction"]);
185 if (!id.has_value()) {
186 return util::Status("Could not convert transaction id");
187 }
188 BinderTracker::GetOrCreate(context_)->TransactionReceived(line.ts, line.pid,
189 id.value());
190 } else if (line.event_name == "binder_command") {
191 auto id = base::StringToUInt32(args["cmd"], 0);
192 if (!id.has_value()) {
193 return util::Status("Could not convert cmd ");
194 }
195 BinderTracker::GetOrCreate(context_)->CommandToKernel(line.ts, line.pid,
196 id.value());
197 } else if (line.event_name == "binder_return") {
198 auto id = base::StringToUInt32(args["cmd"], 0);
199 if (!id.has_value()) {
200 return util::Status("Could not convert cmd");
201 }
202 BinderTracker::GetOrCreate(context_)->ReturnFromKernel(line.ts, line.pid,
203 id.value());
204 } else if (line.event_name == "binder_lock") {
205 BinderTracker::GetOrCreate(context_)->Lock(line.ts, line.pid);
206 } else if (line.event_name == "binder_locked") {
207 BinderTracker::GetOrCreate(context_)->Locked(line.ts, line.pid);
208 } else if (line.event_name == "binder_unlock") {
209 BinderTracker::GetOrCreate(context_)->Unlock(line.ts, line.pid);
210 } else if (line.event_name == "binder_transaction_alloc_buf") {
211 auto data_size = base::StringToUInt64(args["data_size"]);
212 auto offsets_size = base::StringToUInt64(args["offsets_size"]);
213 if (!data_size.has_value()) {
214 return util::Status("Could not convert data size");
215 }
216 if (!offsets_size.has_value()) {
217 return util::Status("Could not convert offsets size");
218 }
219 BinderTracker::GetOrCreate(context_)->TransactionAllocBuf(
220 line.ts, line.pid, data_size.value(), offsets_size.value());
221 } else if (line.event_name == "clock_set_rate" ||
222 line.event_name == "clock_enable" ||
223 line.event_name == "clock_disable") {
224 std::string subtitle =
225 line.event_name == "clock_set_rate" ? " Frequency" : " State";
226 auto rate = base::StringToUInt32(args["state"]);
227 if (!rate.has_value()) {
228 return util::Status("Could not convert state");
229 }
230 std::string clock_name_str = args["name"] + subtitle;
231 StringId clock_name =
232 context_->storage->InternString(base::StringView(clock_name_str));
233 TrackId track = context_->track_tracker->InternGlobalCounterTrack(
234 TrackTracker::Group::kClockFrequency, clock_name);
235 context_->event_tracker->PushCounter(line.ts, rate.value(), track);
236 } else if (line.event_name == "workqueue_execute_start") {
237 auto split = base::SplitString(line.args_str, "function ");
238 StringId name_id =
239 context_->storage->InternString(base::StringView(split[1]));
240 TrackId track = context_->track_tracker->InternThreadTrack(utid);
241 context_->slice_tracker->Begin(line.ts, track, workqueue_name_id_, name_id);
242 } else if (line.event_name == "workqueue_execute_end") {
243 TrackId track = context_->track_tracker->InternThreadTrack(utid);
244 context_->slice_tracker->End(line.ts, track, workqueue_name_id_);
245 } else if (line.event_name == "thermal_temperature") {
246 std::string thermal_zone = args["thermal_zone"] + " Temperature";
247 StringId track_name =
248 context_->storage->InternString(base::StringView(thermal_zone));
249 TrackId track = context_->track_tracker->InternGlobalCounterTrack(
250 TrackTracker::Group::kThermals, track_name);
251 auto temp = base::StringToInt32(args["temp"]);
252 if (!temp.has_value()) {
253 return util::Status("Could not convert temp");
254 }
255 context_->event_tracker->PushCounter(line.ts, temp.value(), track);
256 } else if (line.event_name == "cdev_update") {
257 std::string type = args["type"] + " Cooling Device";
258 StringId track_name =
259 context_->storage->InternString(base::StringView(type));
260 TrackId track = context_->track_tracker->InternGlobalCounterTrack(
261 TrackTracker::Group::kThermals, track_name);
262 auto target = base::StringToDouble(args["target"]);
263 if (!target.has_value()) {
264 return util::Status("Could not convert target");
265 }
266 context_->event_tracker->PushCounter(line.ts, target.value(), track);
267 } else if (line.event_name == "sched_blocked_reason") {
268 auto wakee_pid = base::StringToUInt32(args["pid"]);
269 if (!wakee_pid.has_value()) {
270 return util::Status("sched_blocked_reason: could not parse wakee_pid");
271 }
272 auto wakee_utid = context_->process_tracker->GetOrCreateThread(*wakee_pid);
273 auto io_wait = base::StringToInt32(args["iowait"]);
274 if (!io_wait.has_value()) {
275 return util::Status("sched_blocked_reason: could not parse io_wait");
276 }
277 StringId blocked_function =
278 context_->storage->InternString(base::StringView(args["caller"]));
279 ThreadStateTracker::GetOrCreate(context_)->PushBlockedReason(
280 wakee_utid, static_cast<bool>(*io_wait), blocked_function);
281 } else if (line.event_name == "rss_stat") {
282 // Format: rss_stat: size=8437760 member=1 curr=1 mm_id=2824390453
283 auto size = base::StringToInt64(args["size"]);
284 auto member = base::StringToUInt32(args["member"]);
285 auto mm_id = base::StringToInt64(args["mm_id"]);
286 auto opt_curr = base::StringToUInt32(args["curr"]);
287 if (!size.has_value()) {
288 return util::Status("rss_stat: could not parse size");
289 }
290 if (!member.has_value()) {
291 return util::Status("rss_stat: could not parse member");
292 }
293 std::optional<bool> curr;
294 if (!opt_curr.has_value()) {
295 curr = std::make_optional(static_cast<bool>(*opt_curr));
296 }
297 rss_stat_tracker_.ParseRssStat(line.ts, line.pid, *size, *member, curr,
298 mm_id);
299 }
300
301 return util::OkStatus();
302 }
303
304 } // namespace trace_processor
305 } // namespace perfetto
306