jcs.org
Serenity Operating System
1/*
2 * Copyright (c) 2018-2021, Andreas Kling <kling@serenityos.org>
3 *
4 * SPDX-License-Identifier: BSD-2-Clause
5 */
6
7#include "Profile.h"
8#include "DisassemblyModel.h"
9#include "ProfileModel.h"
10#include "SamplesModel.h"
11#include "SourceModel.h"
12#include <AK/HashTable.h>
13#include <AK/LexicalPath.h>
14#include <AK/QuickSort.h>
15#include <AK/RefPtr.h>
16#include <AK/Try.h>
17#include <LibCore/MappedFile.h>
18#include <LibELF/Image.h>
19#include <LibSymbolication/Symbolication.h>
20#include <sys/stat.h>
21
22namespace Profiler {
23
24static void sort_profile_nodes(Vector<NonnullRefPtr<ProfileNode>>& nodes)
25{
26 quick_sort(nodes.begin(), nodes.end(), [](auto& a, auto& b) {
27 return a->event_count() >= b->event_count();
28 });
29
30 for (auto& child : nodes)
31 child->sort_children();
32}
33
34Profile::Profile(Vector<Process> processes, Vector<Event> events)
35 : m_processes(move(processes))
36 , m_events(move(events))
37 , m_file_event_nodes(FileEventNode::create(""))
38{
39 for (size_t i = 0; i < m_events.size(); ++i) {
40 if (m_events[i].data.has<Event::SignpostData>())
41 m_signpost_indices.append(i);
42 }
43
44 m_first_timestamp = m_events.first().timestamp;
45 m_last_timestamp = m_events.last().timestamp;
46
47 m_model = ProfileModel::create(*this);
48 m_samples_model = SamplesModel::create(*this);
49 m_signposts_model = SignpostsModel::create(*this);
50 m_file_event_model = FileEventModel::create(*this);
51
52 rebuild_tree();
53}
54
55GUI::Model& Profile::model()
56{
57 return *m_model;
58}
59
60GUI::Model& Profile::samples_model()
61{
62 return *m_samples_model;
63}
64
65GUI::Model& Profile::signposts_model()
66{
67 return *m_signposts_model;
68}
69
70void Profile::rebuild_tree()
71{
72 Vector<NonnullRefPtr<ProfileNode>> roots;
73
74 auto find_or_create_process_node = [this, &roots](pid_t pid, EventSerialNumber serial) -> ProfileNode& {
75 auto const* process = find_process(pid, serial);
76 if (!process) {
77 dbgln("Profile contains event for unknown process with pid={}, serial={}", pid, serial.to_number());
78 VERIFY_NOT_REACHED();
79 }
80 for (auto root : roots) {
81 if (&root->process() == process)
82 return root;
83 }
84 auto new_root = ProfileNode::create_process_node(*process);
85 roots.append(new_root);
86 return new_root;
87 };
88
89 HashTable<FlatPtr> live_allocations;
90
91 for_each_event_in_filter_range([&](Event const& event) {
92 event.data.visit(
93 [&](Event::MallocData const& data) {
94 live_allocations.set(data.ptr);
95 },
96 [&](Event::FreeData const& data) {
97 live_allocations.remove(data.ptr);
98 },
99 [&](auto&) {});
100 });
101
102 m_filtered_event_indices.clear();
103 m_filtered_signpost_indices.clear();
104 m_file_event_nodes->children().clear();
105
106 for (size_t event_index = 0; event_index < m_events.size(); ++event_index) {
107 auto& event = m_events.at(event_index);
108
109 if (has_timestamp_filter_range()) {
110 auto timestamp = event.timestamp;
111 if (timestamp < m_timestamp_filter_range_start || timestamp > m_timestamp_filter_range_end)
112 continue;
113 }
114
115 if (!process_filter_contains(event.pid, event.serial))
116 continue;
117
118 if (event.data.has<Event::SignpostData>()) {
119 m_filtered_signpost_indices.append(event_index);
120 continue;
121 }
122
123 m_filtered_event_indices.append(event_index);
124
125 if (auto* malloc_data = event.data.get_pointer<Event::MallocData>(); malloc_data && !live_allocations.contains(malloc_data->ptr))
126 continue;
127
128 if (event.data.has<Event::FreeData>())
129 continue;
130
131 auto for_each_frame = [&]<typename Callback>(Callback callback) {
132 if (!m_inverted) {
133 for (size_t i = 0; i < event.frames.size(); ++i) {
134 if (callback(event.frames.at(i), i == event.frames.size() - 1) == IterationDecision::Break)
135 break;
136 }
137 } else {
138 for (ssize_t i = event.frames.size() - 1; i >= 0; --i) {
139 if (callback(event.frames.at(i), static_cast<size_t>(i) == event.frames.size() - 1) == IterationDecision::Break)
140 break;
141 }
142 }
143 };
144
145 if (!m_show_top_functions) {
146 ProfileNode* node = nullptr;
147 auto& process_node = find_or_create_process_node(event.pid, event.serial);
148 process_node.increment_event_count();
149 for_each_frame([&](Frame const& frame, bool is_innermost_frame) {
150 auto const& object_name = frame.object_name;
151 auto const& symbol = frame.symbol;
152 auto const& address = frame.address;
153 auto const& offset = frame.offset;
154
155 if (symbol.is_empty())
156 return IterationDecision::Break;
157
158 // FIXME: More cheating with intentional mixing of TID/PID here:
159 if (!node)
160 node = &process_node;
161 node = &node->find_or_create_child(object_name, symbol, address, offset, event.timestamp, event.pid);
162
163 node->increment_event_count();
164 if (is_innermost_frame) {
165 node->add_event_address(address);
166 node->increment_self_count();
167 }
168 return IterationDecision::Continue;
169 });
170 } else {
171 auto& process_node = find_or_create_process_node(event.pid, event.serial);
172 process_node.increment_event_count();
173 for (size_t i = 0; i < event.frames.size(); ++i) {
174 ProfileNode* node = nullptr;
175 ProfileNode* root = nullptr;
176 for (size_t j = i; j < event.frames.size(); ++j) {
177 auto& frame = event.frames.at(j);
178 auto& object_name = frame.object_name;
179 auto& symbol = frame.symbol;
180 auto& address = frame.address;
181 auto& offset = frame.offset;
182 if (symbol.is_empty())
183 break;
184
185 // FIXME: More PID/TID mixing cheats here:
186 if (!node) {
187 node = &find_or_create_process_node(event.pid, event.serial);
188 node = &node->find_or_create_child(object_name, symbol, address, offset, event.timestamp, event.pid);
189 root = node;
190 root->will_track_seen_events(m_events.size());
191 } else {
192 node = &node->find_or_create_child(object_name, symbol, address, offset, event.timestamp, event.pid);
193 }
194
195 if (!root->has_seen_event(event_index)) {
196 root->did_see_event(event_index);
197 root->increment_event_count();
198 } else if (node != root) {
199 node->increment_event_count();
200 }
201
202 if (j == event.frames.size() - 1) {
203 node->add_event_address(address);
204 node->increment_self_count();
205 }
206 }
207 }
208 }
209
210 if (event.data.has<Event::ReadData>()) {
211 auto const& read_event = event.data.get<Event::ReadData>();
212 auto& event_node = m_file_event_nodes->find_or_create_node(read_event.path);
213
214 event_node.for_each_parent_node([&](FileEventNode& node) {
215 node.increment_count();
216
217 // Fixme: Currently events record 'timestamp' and 'start_timestamp' in ms resolution,
218 // which results in most durations equal to zero. Increasing the resolution should
219 // make the information more accurate.
220 auto const duration = event.timestamp - read_event.start_timestamp;
221 node.add_to_duration(duration);
222 });
223 }
224 }
225
226 sort_profile_nodes(roots);
227
228 m_roots = move(roots);
229 m_model->invalidate();
230}
231
232Optional<MappedObject> g_kernel_debuginfo_object;
233OwnPtr<Debug::DebugInfo> g_kernel_debug_info;
234
235ErrorOr<NonnullOwnPtr<Profile>> Profile::load_from_perfcore_file(StringView path)
236{
237 auto file = TRY(Core::File::open(path, Core::File::OpenMode::Read));
238
239 auto json = JsonValue::from_string(TRY(file->read_until_eof()));
240 if (json.is_error() || !json.value().is_object())
241 return Error::from_string_literal("Invalid perfcore format (not a JSON object)");
242
243 auto const& object = json.value().as_object();
244
245 if (!g_kernel_debuginfo_object.has_value()) {
246 auto debuginfo_file_or_error = Core::MappedFile::map("/boot/Kernel.debug"sv);
247 if (!debuginfo_file_or_error.is_error()) {
248 auto debuginfo_file = debuginfo_file_or_error.release_value();
249 auto debuginfo_image = ELF::Image(debuginfo_file->bytes());
250 g_kernel_debuginfo_object = { { debuginfo_file, move(debuginfo_image) } };
251 }
252 }
253
254 auto strings_value = object.get_array("strings"sv);
255 if (!strings_value.has_value())
256 return Error::from_string_literal("Malformed profile (strings is not an array)");
257 auto const& strings = strings_value.value();
258
259 HashMap<FlatPtr, DeprecatedString> profile_strings;
260 for (FlatPtr string_id = 0; string_id < strings.size(); ++string_id) {
261 auto const& value = strings.at(string_id);
262 profile_strings.set(string_id, value.to_deprecated_string());
263 }
264
265 auto events_value = object.get_array("events"sv);
266 if (!events_value.has_value())
267 return Error::from_string_literal("Malformed profile (events is not an array)");
268 auto const& perf_events = events_value.value();
269
270 Vector<NonnullOwnPtr<Process>> all_processes;
271 HashMap<pid_t, Process*> current_processes;
272 Vector<Event> events;
273 EventSerialNumber next_serial;
274
275 for (auto const& perf_event_value : perf_events.values()) {
276 auto const& perf_event = perf_event_value.as_object();
277
278 Event event;
279
280 event.serial = next_serial;
281 next_serial.increment();
282 event.timestamp = perf_event.get_u64("timestamp"sv).value_or(0);
283 event.lost_samples = perf_event.get_u32("lost_samples"sv).value_or(0);
284 event.pid = perf_event.get_i32("pid"sv).value_or(0);
285 event.tid = perf_event.get_i32("tid"sv).value_or(0);
286
287 auto type_string = perf_event.get_deprecated_string("type"sv).value_or({});
288
289 if (type_string == "sample"sv) {
290 event.data = Event::SampleData {};
291 } else if (type_string == "malloc"sv) {
292 event.data = Event::MallocData {
293 .ptr = perf_event.get_addr("ptr"sv).value_or(0),
294 .size = perf_event.get_integer<size_t>("size"sv).value_or(0),
295 };
296 } else if (type_string == "free"sv) {
297 event.data = Event::FreeData {
298 .ptr = perf_event.get_addr("ptr"sv).value_or(0),
299 };
300 } else if (type_string == "signpost"sv) {
301 auto string_id = perf_event.get_addr("arg1"sv).value_or(0);
302 event.data = Event::SignpostData {
303 .string = profile_strings.get(string_id).value_or(DeprecatedString::formatted("Signpost #{}", string_id)),
304 .arg = perf_event.get_addr("arg2"sv).value_or(0),
305 };
306 } else if (type_string == "mmap"sv) {
307 auto ptr = perf_event.get_addr("ptr"sv).value_or(0);
308 auto size = perf_event.get_integer<size_t>("size"sv).value_or(0);
309 auto name = perf_event.get_deprecated_string("name"sv).value_or({});
310
311 event.data = Event::MmapData {
312 .ptr = ptr,
313 .size = size,
314 .name = name,
315 };
316
317 auto it = current_processes.find(event.pid);
318 if (it != current_processes.end())
319 it->value->library_metadata.handle_mmap(ptr, size, name);
320 continue;
321 } else if (type_string == "munmap"sv) {
322 event.data = Event::MunmapData {
323 .ptr = perf_event.get_addr("ptr"sv).value_or(0),
324 .size = perf_event.get_integer<size_t>("size"sv).value_or(0),
325 };
326 continue;
327 } else if (type_string == "process_create"sv) {
328 auto parent_pid = perf_event.get_integer<pid_t>("parent_pid"sv).value_or(0);
329 auto executable = perf_event.get_deprecated_string("executable"sv).value_or({});
330 event.data = Event::ProcessCreateData {
331 .parent_pid = parent_pid,
332 .executable = executable,
333 };
334
335 auto sampled_process = TRY(adopt_nonnull_own_or_enomem(new (nothrow) Process {
336 .pid = event.pid,
337 .executable = executable,
338 .basename = LexicalPath::basename(executable),
339 .start_valid = event.serial,
340 .end_valid = {},
341 }));
342
343 current_processes.set(sampled_process->pid, sampled_process);
344 all_processes.append(move(sampled_process));
345 continue;
346 } else if (type_string == "process_exec"sv) {
347 auto executable = perf_event.get_deprecated_string("executable"sv).value_or({});
348 event.data = Event::ProcessExecData {
349 .executable = executable,
350 };
351
352 auto* old_process = current_processes.get(event.pid).value();
353 old_process->end_valid = event.serial;
354
355 current_processes.remove(event.pid);
356
357 auto sampled_process = TRY(adopt_nonnull_own_or_enomem(new (nothrow) Process {
358 .pid = event.pid,
359 .executable = executable,
360 .basename = LexicalPath::basename(executable),
361 .start_valid = event.serial,
362 .end_valid = {},
363 }));
364
365 current_processes.set(sampled_process->pid, sampled_process);
366 all_processes.append(move(sampled_process));
367 continue;
368 } else if (type_string == "process_exit"sv) {
369 auto* old_process = current_processes.get(event.pid).value();
370 old_process->end_valid = event.serial;
371
372 current_processes.remove(event.pid);
373 continue;
374 } else if (type_string == "thread_create"sv) {
375 auto parent_tid = perf_event.get_integer<pid_t>("parent_tid"sv).value_or(0);
376 event.data = Event::ThreadCreateData {
377 .parent_tid = parent_tid,
378 };
379 auto it = current_processes.find(event.pid);
380 if (it != current_processes.end())
381 it->value->handle_thread_create(event.tid, event.serial);
382 continue;
383 } else if (type_string == "thread_exit"sv) {
384 auto it = current_processes.find(event.pid);
385 if (it != current_processes.end())
386 it->value->handle_thread_exit(event.tid, event.serial);
387 continue;
388 } else if (type_string == "read"sv) {
389 auto const string_index = perf_event.get_addr("filename_index"sv).value_or(0);
390 event.data = Event::ReadData {
391 .fd = perf_event.get_integer<int>("fd"sv).value_or(0),
392 .size = perf_event.get_integer<size_t>("size"sv).value_or(0),
393 .path = profile_strings.get(string_index).value(),
394 .start_timestamp = perf_event.get_integer<size_t>("start_timestamp"sv).value_or(0),
395 .success = perf_event.get_bool("success"sv).value_or(false)
396 };
397 } else {
398 dbgln("Unknown event type '{}'", type_string);
399 VERIFY_NOT_REACHED();
400 }
401
402 auto maybe_kernel_base = Symbolication::kernel_base();
403
404 auto stack = perf_event.get_array("stack"sv);
405 VERIFY(stack.has_value());
406 auto const& stack_array = stack.value();
407 for (ssize_t i = stack_array.values().size() - 1; i >= 0; --i) {
408 auto const& frame = stack_array.at(i);
409 auto ptr = frame.to_number<u64>();
410 u32 offset = 0;
411 DeprecatedFlyString object_name;
412 DeprecatedString symbol;
413
414 if (maybe_kernel_base.has_value() && ptr >= maybe_kernel_base.value()) {
415 if (g_kernel_debuginfo_object.has_value()) {
416 symbol = g_kernel_debuginfo_object->elf.symbolicate(ptr - maybe_kernel_base.value(), &offset);
417 } else {
418 symbol = DeprecatedString::formatted("?? <{:p}>", ptr);
419 }
420 } else {
421 auto it = current_processes.find(event.pid);
422 // FIXME: This logic is kinda gnarly, find a way to clean it up.
423 LibraryMetadata* library_metadata {};
424 if (it != current_processes.end())
425 library_metadata = &it->value->library_metadata;
426 if (auto const* library = library_metadata ? library_metadata->library_containing(ptr) : nullptr) {
427 object_name = library->name;
428 symbol = library->symbolicate(ptr, &offset);
429 } else {
430 symbol = DeprecatedString::formatted("?? <{:p}>", ptr);
431 }
432 }
433
434 event.frames.append({ object_name, symbol, (FlatPtr)ptr, offset });
435 }
436
437 if (event.frames.size() < 2)
438 continue;
439
440 FlatPtr innermost_frame_address = event.frames.at(1).address;
441 event.in_kernel = maybe_kernel_base.has_value() && innermost_frame_address >= maybe_kernel_base.value();
442
443 events.append(move(event));
444 }
445
446 if (events.is_empty())
447 return Error::from_string_literal("No events captured (targeted process was never on CPU)");
448
449 quick_sort(all_processes, [](auto& a, auto& b) {
450 if (a->pid == b->pid)
451 return a->start_valid < b->start_valid;
452
453 return a->pid < b->pid;
454 });
455
456 Vector<Process> processes;
457 for (auto& it : all_processes)
458 processes.append(move(*it));
459
460 return adopt_nonnull_own_or_enomem(new (nothrow) Profile(move(processes), move(events)));
461}
462
463void ProfileNode::sort_children()
464{
465 sort_profile_nodes(m_children);
466}
467
468void Profile::set_timestamp_filter_range(u64 start, u64 end)
469{
470 if (m_has_timestamp_filter_range && m_timestamp_filter_range_start == start && m_timestamp_filter_range_end == end)
471 return;
472 m_has_timestamp_filter_range = true;
473
474 m_timestamp_filter_range_start = min(start, end);
475 m_timestamp_filter_range_end = max(start, end);
476
477 rebuild_tree();
478 m_samples_model->invalidate();
479 m_signposts_model->invalidate();
480}
481
482void Profile::clear_timestamp_filter_range()
483{
484 if (!m_has_timestamp_filter_range)
485 return;
486 m_has_timestamp_filter_range = false;
487 rebuild_tree();
488 m_samples_model->invalidate();
489 m_signposts_model->invalidate();
490}
491
492void Profile::add_process_filter(pid_t pid, EventSerialNumber start_valid, EventSerialNumber end_valid)
493{
494 auto filter = ProcessFilter { pid, start_valid, end_valid };
495 if (m_process_filters.contains_slow(filter))
496 return;
497 m_process_filters.append(move(filter));
498
499 rebuild_tree();
500 if (m_disassembly_model)
501 m_disassembly_model->invalidate();
502 m_samples_model->invalidate();
503 m_signposts_model->invalidate();
504}
505
506void Profile::remove_process_filter(pid_t pid, EventSerialNumber start_valid, EventSerialNumber end_valid)
507{
508 auto filter = ProcessFilter { pid, start_valid, end_valid };
509 if (!m_process_filters.contains_slow(filter))
510 return;
511 m_process_filters.remove_first_matching([&filter](ProcessFilter const& other_filter) {
512 return other_filter == filter;
513 });
514
515 rebuild_tree();
516 if (m_disassembly_model)
517 m_disassembly_model->invalidate();
518 m_samples_model->invalidate();
519 m_signposts_model->invalidate();
520}
521
522void Profile::clear_process_filter()
523{
524 if (m_process_filters.is_empty())
525 return;
526 m_process_filters.clear();
527 rebuild_tree();
528 if (m_disassembly_model)
529 m_disassembly_model->invalidate();
530 m_samples_model->invalidate();
531 m_signposts_model->invalidate();
532}
533
534bool Profile::process_filter_contains(pid_t pid, EventSerialNumber serial)
535{
536 if (!has_process_filter())
537 return true;
538
539 return AK::any_of(m_process_filters,
540 [&](auto const& process_filter) { return pid == process_filter.pid && serial >= process_filter.start_valid && serial <= process_filter.end_valid; });
541}
542
543void Profile::set_inverted(bool inverted)
544{
545 if (m_inverted == inverted)
546 return;
547 m_inverted = inverted;
548 rebuild_tree();
549}
550
551void Profile::set_show_top_functions(bool show)
552{
553 if (m_show_top_functions == show)
554 return;
555 m_show_top_functions = show;
556 rebuild_tree();
557}
558
559void Profile::set_show_percentages(bool show_percentages)
560{
561 if (m_show_percentages == show_percentages)
562 return;
563 m_show_percentages = show_percentages;
564}
565
566void Profile::set_disassembly_index(GUI::ModelIndex const& index)
567{
568 if (m_disassembly_index == index)
569 return;
570 m_disassembly_index = index;
571 auto* node = static_cast<ProfileNode*>(index.internal_data());
572 if (!node)
573 m_disassembly_model = nullptr;
574 else
575 m_disassembly_model = DisassemblyModel::create(*this, *node);
576}
577
578GUI::Model* Profile::disassembly_model()
579{
580 return m_disassembly_model;
581}
582
583void Profile::set_source_index(GUI::ModelIndex const& index)
584{
585 if (m_source_index == index)
586 return;
587 m_source_index = index;
588 auto* node = static_cast<ProfileNode*>(index.internal_data());
589 if (!node)
590 m_source_model = nullptr;
591 else
592 m_source_model = SourceModel::create(*this, *node);
593}
594
595GUI::Model* Profile::source_model()
596{
597 return m_source_model;
598}
599
600GUI::Model* Profile::file_event_model()
601{
602 return m_file_event_model;
603}
604
605ProfileNode::ProfileNode(Process const& process)
606 : m_root(true)
607 , m_process(process)
608{
609}
610
611ProfileNode::ProfileNode(Process const& process, DeprecatedFlyString const& object_name, DeprecatedString symbol, FlatPtr address, u32 offset, u64 timestamp, pid_t pid)
612 : m_process(process)
613 , m_symbol(move(symbol))
614 , m_pid(pid)
615 , m_address(address)
616 , m_offset(offset)
617 , m_timestamp(timestamp)
618{
619 DeprecatedString object;
620 if (object_name.ends_with(": .text"sv)) {
621 object = object_name.view().substring_view(0, object_name.length() - 7);
622 } else {
623 object = object_name;
624 }
625 m_object_name = LexicalPath::basename(object);
626}
627
628}