1 /*
2 * Copyright (C) 2023 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/proto/winscope/protolog_parser.h"
18
19 #include <cinttypes>
20 #include <cstddef>
21 #include <cstdint>
22 #include <optional>
23 #include <string>
24 #include <utility>
25 #include <vector>
26
27 #include "perfetto/ext/base/flat_hash_map.h"
28 #include "perfetto/ext/base/string_utils.h"
29 #include "perfetto/ext/base/string_view.h"
30 #include "perfetto/protozero/field.h"
31 #include "protos/perfetto/trace/android/protolog.pbzero.h"
32 #include "protos/perfetto/trace/interned_data/interned_data.pbzero.h"
33 #include "protos/perfetto/trace/profiling/profile_common.pbzero.h"
34 #include "protos/perfetto/trace/profiling/profile_packet.pbzero.h"
35 #include "src/trace_processor/containers/string_pool.h"
36 #include "src/trace_processor/importers/proto/packet_sequence_state_generation.h"
37 #include "src/trace_processor/importers/proto/winscope/protolog_messages_tracker.h"
38 #include "src/trace_processor/importers/proto/winscope/winscope.descriptor.h"
39 #include "src/trace_processor/storage/stats.h"
40 #include "src/trace_processor/storage/trace_storage.h"
41 #include "src/trace_processor/tables/winscope_tables_py.h"
42 #include "src/trace_processor/types/trace_processor_context.h"
43
44 namespace perfetto::trace_processor {
45
46 enum ProtoLogLevel : int32_t {
47 DEBUG = 1,
48 VERBOSE = 2,
49 INFO = 3,
50 WARN = 4,
51 ERROR = 5,
52 WTF = 6,
53 };
54
ProtoLogParser(TraceProcessorContext * context)55 ProtoLogParser::ProtoLogParser(TraceProcessorContext* context)
56 : context_(context),
57 args_parser_{pool_},
58 log_level_debug_string_id_(context->storage->InternString("DEBUG")),
59 log_level_verbose_string_id_(context->storage->InternString("VERBOSE")),
60 log_level_info_string_id_(context->storage->InternString("INFO")),
61 log_level_warn_string_id_(context->storage->InternString("WARN")),
62 log_level_error_string_id_(context->storage->InternString("ERROR")),
63 log_level_wtf_string_id_(context->storage->InternString("WTF")),
64 log_level_unknown_string_id_(context_->storage->InternString("UNKNOWN")) {
65 pool_.AddFromFileDescriptorSet(kWinscopeDescriptor.data(),
66 kWinscopeDescriptor.size());
67 }
68
ParseProtoLogMessage(PacketSequenceStateGeneration * sequence_state,protozero::ConstBytes blob,int64_t timestamp)69 void ProtoLogParser::ParseProtoLogMessage(
70 PacketSequenceStateGeneration* sequence_state,
71 protozero::ConstBytes blob,
72 int64_t timestamp) {
73 protos::pbzero::ProtoLogMessage::Decoder protolog_message(blob);
74
75 std::vector<int64_t> sint64_params;
76 for (auto it = protolog_message.sint64_params(); it; ++it) {
77 sint64_params.emplace_back(*it);
78 }
79
80 std::vector<double> double_params;
81 for (auto it = protolog_message.double_params(); it; ++it) {
82 double_params.emplace_back(*it);
83 }
84
85 std::vector<bool> boolean_params;
86 for (auto it = protolog_message.boolean_params(); it; ++it) {
87 boolean_params.emplace_back(*it);
88 }
89
90 std::vector<std::string> string_params;
91 if (protolog_message.has_str_param_iids()) {
92 for (auto it = protolog_message.str_param_iids(); it; ++it) {
93 auto* decoder = sequence_state->LookupInternedMessage<
94 protos::pbzero::InternedData::kProtologStringArgsFieldNumber,
95 protos::pbzero::InternedString>(it.field().as_uint32());
96 if (!decoder) {
97 // This shouldn't happen since we already checked the incremental
98 // state is valid.
99 string_params.emplace_back("<ERROR>");
100 context_->storage->IncrementStats(
101 stats::winscope_protolog_missing_interned_arg_parse_errors);
102 continue;
103 }
104 string_params.emplace_back(decoder->str().ToStdString());
105 }
106 }
107
108 std::optional<StringId> stacktrace = std::nullopt;
109 if (protolog_message.has_stacktrace_iid()) {
110 auto* stacktrace_decoder = sequence_state->LookupInternedMessage<
111 protos::pbzero::InternedData::kProtologStacktraceFieldNumber,
112 protos::pbzero::InternedString>(protolog_message.stacktrace_iid());
113
114 if (!stacktrace_decoder) {
115 // This shouldn't happen since we already checked the incremental
116 // state is valid.
117 string_params.emplace_back("<ERROR>");
118 context_->storage->IncrementStats(
119 stats::winscope_protolog_missing_interned_stacktrace_parse_errors);
120 } else {
121 stacktrace = context_->storage->InternString(
122 base::StringView(stacktrace_decoder->str().ToStdString()));
123 }
124 }
125
126 auto* protolog_table = context_->storage->mutable_protolog_table();
127
128 tables::ProtoLogTable::Row row;
129 auto row_id = protolog_table->Insert(row).id;
130
131 auto* protolog_message_tracker =
132 ProtoLogMessagesTracker::GetOrCreate(context_);
133 struct ProtoLogMessagesTracker::TrackedProtoLogMessage tracked_message = {
134 protolog_message.message_id(),
135 std::move(sint64_params),
136 std::move(double_params),
137 std::move(boolean_params),
138 std::move(string_params),
139 stacktrace,
140 row_id,
141 timestamp};
142 protolog_message_tracker->TrackMessage(std::move(tracked_message));
143 }
144
ParseProtoLogViewerConfig(protozero::ConstBytes blob)145 void ProtoLogParser::ParseProtoLogViewerConfig(protozero::ConstBytes blob) {
146 auto* protolog_table = context_->storage->mutable_protolog_table();
147
148 protos::pbzero::ProtoLogViewerConfig::Decoder protolog_viewer_config(blob);
149
150 base::FlatHashMap<uint32_t, std::string> group_tags;
151 for (auto it = protolog_viewer_config.groups(); it; ++it) {
152 protos::pbzero::ProtoLogViewerConfig::Group::Decoder group(*it);
153 group_tags.Insert(group.id(), group.tag().ToStdString());
154 }
155
156 auto* protolog_message_tracker =
157 ProtoLogMessagesTracker::GetOrCreate(context_);
158
159 for (auto it = protolog_viewer_config.messages(); it; ++it) {
160 protos::pbzero::ProtoLogViewerConfig::MessageData::Decoder message_data(
161 *it);
162
163 auto tracked_messages_opt =
164 protolog_message_tracker->GetTrackedMessagesByMessageId(
165 message_data.message_id());
166
167 if (tracked_messages_opt.has_value()) {
168 auto* group_tag = group_tags.Find(message_data.group_id());
169
170 for (const auto& tracked_message : *tracked_messages_opt.value()) {
171 auto formatted_message = FormatMessage(
172 message_data.message().ToStdString(), tracked_message.sint64_params,
173 tracked_message.double_params, tracked_message.boolean_params,
174 tracked_message.string_params);
175
176 auto row =
177 protolog_table->FindById(tracked_message.table_row_id).value();
178
179 row.set_ts(tracked_message.timestamp);
180
181 StringPool::Id level;
182 switch (message_data.level()) {
183 case ProtoLogLevel::DEBUG:
184 level = log_level_debug_string_id_;
185 break;
186 case ProtoLogLevel::VERBOSE:
187 level = log_level_verbose_string_id_;
188 break;
189 case ProtoLogLevel::INFO:
190 level = log_level_info_string_id_;
191 break;
192 case ProtoLogLevel::WARN:
193 level = log_level_warn_string_id_;
194 break;
195 case ProtoLogLevel::ERROR:
196 level = log_level_error_string_id_;
197 break;
198 case ProtoLogLevel::WTF:
199 level = log_level_wtf_string_id_;
200 break;
201 default:
202 level = log_level_unknown_string_id_;
203 break;
204 }
205 row.set_level(level);
206
207 auto tag =
208 context_->storage->InternString(base::StringView(*group_tag));
209 row.set_tag(tag);
210
211 auto message = context_->storage->InternString(
212 base::StringView(formatted_message));
213 row.set_message(message);
214
215 if (tracked_message.stacktrace.has_value()) {
216 row.set_stacktrace(tracked_message.stacktrace.value());
217 }
218 }
219 }
220 }
221 }
222
FormatMessage(const std::string & message,const std::vector<int64_t> & sint64_params,const std::vector<double> & double_params,const std::vector<bool> & boolean_params,const std::vector<std::string> & string_params)223 std::string ProtoLogParser::FormatMessage(
224 const std::string& message,
225 const std::vector<int64_t>& sint64_params,
226 const std::vector<double>& double_params,
227 const std::vector<bool>& boolean_params,
228 const std::vector<std::string>& string_params) {
229 std::string formatted_message;
230 formatted_message.reserve(message.size());
231
232 auto sint64_params_itr = sint64_params.begin();
233 auto double_params_itr = double_params.begin();
234 auto boolean_params_itr = boolean_params.begin();
235 auto str_params_itr = string_params.begin();
236
237 for (size_t i = 0; i < message.length();) {
238 if (message.at(i) == '%') {
239 switch (message.at(i + 1)) {
240 case '%':
241 break;
242 case 'd': {
243 base::StackString<32> param("%" PRId64, *sint64_params_itr);
244 formatted_message.append(param.c_str());
245 ++sint64_params_itr;
246 break;
247 }
248 case 'o': {
249 base::StackString<32> param("%" PRIo64, *sint64_params_itr);
250 formatted_message.append(param.c_str());
251 ++sint64_params_itr;
252 break;
253 }
254 case 'x': {
255 base::StackString<32> param("%" PRIx64, *sint64_params_itr);
256 formatted_message.append(param.c_str());
257 ++sint64_params_itr;
258 break;
259 }
260 case 'f': {
261 base::StackString<32> param("%f", *double_params_itr);
262 formatted_message.append(param.c_str());
263 ++double_params_itr;
264 break;
265 }
266 case 'e': {
267 base::StackString<32> param("%e", *double_params_itr);
268 formatted_message.append(param.c_str());
269 ++double_params_itr;
270 break;
271 }
272 case 'g': {
273 base::StackString<32> param("%g", *double_params_itr);
274 formatted_message.append(param.c_str());
275 ++double_params_itr;
276 break;
277 }
278 case 's': {
279 formatted_message.append(*str_params_itr);
280 ++str_params_itr;
281 break;
282 }
283 case 'b': {
284 formatted_message.append(*boolean_params_itr ? "true" : "false");
285 ++boolean_params_itr;
286 break;
287 }
288 default:
289 // Should never happen
290 context_->storage->IncrementStats(
291 stats::winscope_protolog_invalid_interpolation_parse_errors);
292 }
293
294 i += 2;
295 } else {
296 formatted_message.push_back(message[i]);
297 i += 1;
298 }
299 }
300
301 return formatted_message;
302 }
303
304 } // namespace perfetto::trace_processor
305