diff --git a/Kernel/API/POSIX/serenity.h b/Kernel/API/POSIX/serenity.h index 1f9b46ad29..4bc2939846 100644 --- a/Kernel/API/POSIX/serenity.h +++ b/Kernel/API/POSIX/serenity.h @@ -32,7 +32,7 @@ enum { PERF_EVENT_PAGE_FAULT = 8192, PERF_EVENT_SYSCALL = 16384, PERF_EVENT_SIGNPOST = 32768, - PERF_EVENT_READ = 65536, + PERF_EVENT_FILESYSTEM = 65536, }; #define PERF_EVENT_MASK_ALL (~0ull) diff --git a/Kernel/CMakeLists.txt b/Kernel/CMakeLists.txt index 17d0ca76ca..5dce82bcd0 100644 --- a/Kernel/CMakeLists.txt +++ b/Kernel/CMakeLists.txt @@ -309,6 +309,7 @@ set(KERNEL_SOURCES Syscalls/prctl.cpp Syscalls/process.cpp Syscalls/profiling.cpp + Syscalls/profiled_syscalls.cpp Syscalls/ptrace.cpp Syscalls/purge.cpp Syscalls/read.cpp diff --git a/Kernel/Syscalls/open.cpp b/Kernel/Syscalls/open.cpp index b1386e6d95..f67fd30423 100644 --- a/Kernel/Syscalls/open.cpp +++ b/Kernel/Syscalls/open.cpp @@ -14,7 +14,7 @@ namespace Kernel { -ErrorOr Process::sys$open(Userspace user_params) +ErrorOr Process::open_impl(Userspace user_params) { VERIFY_NO_PROCESS_BIG_LOCK(this); auto params = TRY(copy_typed_from_user(user_params)); @@ -68,7 +68,7 @@ ErrorOr Process::sys$open(Userspace use }); } -ErrorOr Process::sys$close(int fd) +ErrorOr Process::close_impl(int fd) { VERIFY_NO_PROCESS_BIG_LOCK(this); TRY(require_promise(Pledge::stdio)); diff --git a/Kernel/Syscalls/profiled_syscalls.cpp b/Kernel/Syscalls/profiled_syscalls.cpp new file mode 100644 index 0000000000..1e6b411f61 --- /dev/null +++ b/Kernel/Syscalls/profiled_syscalls.cpp @@ -0,0 +1,274 @@ +/* + * Copyright (c) 2022-2023, Jakub Berkop + * + * SPDX-License-Identifier: BSD-2-Clause + */ + +#include +#include +#include + +namespace Kernel { + +ErrorOr> open_readable_file_description(auto& fds, int fd); + +static ErrorOr get_path_index(auto& fds, int fd, PerformanceEventBuffer* event_buffer) +{ + auto description = TRY(open_readable_file_description(fds, fd)); + + if (auto path = description->original_absolute_path(); !path.is_error()) { + return TRY(event_buffer->register_string(move(path.value()))); + } else if (auto pseudo_path = description->pseudo_path(); !pseudo_path.is_error()) { + return TRY(event_buffer->register_string(move(pseudo_path.value()))); + } else { + auto invalid_path_string = TRY(KString::try_create(""sv)); // TODO: Performance, unecessary allocations. + return TRY(event_buffer->register_string(move(invalid_path_string))); + } +} + +// FIXME: Following functions are very similar, and could be refactored into a more generic solution. +// However, it's not clear how to do it in a way that would be easy to read and understand. +ErrorOr Process::sys$open(Userspace user_params) +{ + Optional start_timestamp = {}; + + // We have to check whether profiling is enabled at before going into the syscall implementation + // so that we can measure the time it took to execute the syscall. + // This approach ensures that we don't have a race condition in case profiling was enabled during + // the execution of the syscall. + // If profiling is disabled at the beginning, we don't want to call TimeManagement::the().monotonic_time() + // because of the overhead it would introduce for every syscall. + bool const profiling_enabled_at_entry = !Thread::current()->is_profiling_suppressed(); + if (profiling_enabled_at_entry) { + start_timestamp = TimeManagement::the().monotonic_time(TimePrecision::Precise); + } + + auto const params = TRY(copy_typed_from_user(user_params)); + auto result = open_impl(user_params); + + if (!profiling_enabled_at_entry || Thread::current()->is_profiling_suppressed()) + return result; + + auto* event_buffer = current_perf_events_buffer(); + if (event_buffer == nullptr) + return result; + + auto const end_timestamp = TimeManagement::the().monotonic_time(TimePrecision::Precise); + auto const duration = end_timestamp - start_timestamp.value(); + + FilesystemEvent data; + data.type = FilesystemEventType::Open; + data.durationNs = static_cast(duration.to_nanoseconds()); + + if (result.is_error()) { + data.result.is_error = true; + data.result.value = result.error().code(); + } else { + data.result.is_error = false; + data.result.value = 0; + } + + auto path = get_syscall_path_argument(params.path); + if (!path.is_error()) { + auto value = event_buffer->register_string(move(path.value())); + data.data.open.filename_index = value.value(); + } + + data.data.open.dirfd = params.dirfd; + data.data.open.options = params.options; + data.data.open.mode = params.mode; + + (void)event_buffer->append(PERF_EVENT_FILESYSTEM, 0, 0, {}, Thread::current(), data); + + return result; +} + +ErrorOr Process::sys$close(int fd) +{ + Optional start_timestamp = {}; + + bool const profiling_enabled_at_entry = !Thread::current()->is_profiling_suppressed(); + if (profiling_enabled_at_entry) { + start_timestamp = TimeManagement::the().monotonic_time(TimePrecision::Precise); + } + + auto result = close_impl(fd); + if (Thread::current()->is_profiling_suppressed()) + return result; + + if (!profiling_enabled_at_entry || Thread::current()->is_profiling_suppressed()) + return result; + + auto* event_buffer = current_perf_events_buffer(); + if (event_buffer == nullptr) + return result; + + auto const end_timestamp = TimeManagement::the().monotonic_time(TimePrecision::Precise); + auto const duration = end_timestamp - start_timestamp.value(); + + FilesystemEvent data; + data.type = FilesystemEventType::Close; + data.durationNs = static_cast(duration.to_nanoseconds()); + data.data.close.fd = fd; + + if (result.is_error()) { + data.result.is_error = true; + data.result.value = result.error().code(); + } else { + data.result.is_error = false; + data.result.value = 0; + } + + auto maybe_path_index = get_path_index(fds(), fd, event_buffer); + if (maybe_path_index.is_error()) + return result; + + data.data.close.filename_index = maybe_path_index.value(); + + (void)event_buffer->append(PERF_EVENT_FILESYSTEM, 0, 0, {}, Thread::current(), data); + + return result; +} + +ErrorOr Process::sys$readv(int fd, Userspace iov, int iov_count) +{ + Optional start_timestamp = {}; + + bool const profiling_enabled_at_entry = !Thread::current()->is_profiling_suppressed(); + if (profiling_enabled_at_entry) { + start_timestamp = TimeManagement::the().monotonic_time(TimePrecision::Precise); + } + + auto result = readv_impl(fd, iov, iov_count); + + if (!profiling_enabled_at_entry || Thread::current()->is_profiling_suppressed()) + return result; + + if (Thread::current()->is_profiling_suppressed()) + return result; + + auto* event_buffer = current_perf_events_buffer(); + if (event_buffer == nullptr) + return result; + + auto const end_timestamp = TimeManagement::the().monotonic_time(TimePrecision::Precise); + auto const duration = end_timestamp - start_timestamp.value(); + + FilesystemEvent data; + data.type = FilesystemEventType::Readv; + data.durationNs = static_cast(duration.to_nanoseconds()); + data.data.readv.fd = fd; + + if (result.is_error()) { + data.result.is_error = true; + data.result.value = result.error().code(); + } else { + data.result.is_error = false; + data.result.value = 0; + } + + auto maybe_path_index = get_path_index(fds(), fd, event_buffer); + if (maybe_path_index.is_error()) + return result; + + data.data.readv.filename_index = maybe_path_index.value(); + + (void)event_buffer->append(PERF_EVENT_FILESYSTEM, 0, 0, {}, Thread::current(), data); + + return result; +} + +ErrorOr Process::sys$read(int fd, Userspace buffer, size_t size) +{ + Optional start_timestamp = {}; + + bool const profiling_enabled_at_entry = !Thread::current()->is_profiling_suppressed(); + if (profiling_enabled_at_entry) { + start_timestamp = TimeManagement::the().monotonic_time(TimePrecision::Precise); + } + + auto result = read_impl(fd, buffer, size); + + if (!profiling_enabled_at_entry || Thread::current()->is_profiling_suppressed()) + return result; + + auto* event_buffer = current_perf_events_buffer(); + if (event_buffer == nullptr) + return result; + + auto const end_timestamp = TimeManagement::the().monotonic_time(TimePrecision::Precise); + auto const duration = end_timestamp - start_timestamp.value(); + + FilesystemEvent data; + data.type = FilesystemEventType::Read; + data.durationNs = static_cast(duration.to_nanoseconds()); + data.data.read.fd = fd; + + if (result.is_error()) { + data.result.is_error = true; + data.result.value = result.error().code(); + } else { + data.result.is_error = false; + data.result.value = 0; + } + + auto maybe_path_index = get_path_index(fds(), fd, event_buffer); + if (maybe_path_index.is_error()) + return result; + + data.data.read.filename_index = maybe_path_index.value(); + + (void)event_buffer->append(PERF_EVENT_FILESYSTEM, 0, 0, {}, Thread::current(), data); + + return result; +} + +ErrorOr Process::sys$pread(int fd, Userspace buffer, size_t size, off_t userspace_offset) +{ + Optional start_timestamp = {}; + + bool const profiling_enabled_at_entry = !Thread::current()->is_profiling_suppressed(); + if (profiling_enabled_at_entry) { + start_timestamp = TimeManagement::the().monotonic_time(TimePrecision::Precise); + } + + auto result = pread_impl(fd, buffer, size, userspace_offset); + + if (!profiling_enabled_at_entry || Thread::current()->is_profiling_suppressed()) + return result; + + auto* event_buffer = current_perf_events_buffer(); + if (event_buffer == nullptr) + return result; + + auto const end_timestamp = TimeManagement::the().monotonic_time(TimePrecision::Precise); + auto const duration = end_timestamp - start_timestamp.value(); + + FilesystemEvent data; + data.type = FilesystemEventType::Pread; + data.durationNs = static_cast(duration.to_nanoseconds()); + data.data.pread.fd = fd; + data.data.pread.buffer_ptr = buffer.ptr(); + data.data.pread.size = size; + data.data.pread.offset = userspace_offset; + + if (result.is_error()) { + data.result.is_error = true; + data.result.value = result.error().code(); + } else { + data.result.is_error = false; + data.result.value = 0; + } + + auto maybe_path_index = get_path_index(fds(), fd, event_buffer); + if (maybe_path_index.is_error()) + return result; + + data.data.pread.filename_index = maybe_path_index.value(); + + (void)event_buffer->append(PERF_EVENT_FILESYSTEM, 0, 0, {}, Thread::current(), data); + + return result; +} + +} diff --git a/Kernel/Syscalls/read.cpp b/Kernel/Syscalls/read.cpp index 7f8f928f89..de602c9d90 100644 --- a/Kernel/Syscalls/read.cpp +++ b/Kernel/Syscalls/read.cpp @@ -13,7 +13,7 @@ namespace Kernel { using BlockFlags = Thread::FileBlocker::BlockFlags; -static ErrorOr> open_readable_file_description(auto& fds, int fd) +ErrorOr> open_readable_file_description(auto& fds, int fd) { auto description = TRY(fds.with_shared([&](auto& fds) { return fds.open_file_description(fd); })); if (!description->is_readable()) @@ -38,7 +38,7 @@ static ErrorOr check_blocked_read(OpenFileDescription* description) return {}; } -ErrorOr Process::sys$readv(int fd, Userspace iov, int iov_count) +ErrorOr Process::readv_impl(int fd, Userspace iov, int iov_count) { VERIFY_PROCESS_BIG_LOCK_ACQUIRED(this); TRY(require_promise(Pledge::stdio)); @@ -71,20 +71,6 @@ ErrorOr Process::sys$readv(int fd, Userspace iov, return nread; } -ErrorOr Process::sys$read(int fd, Userspace buffer, size_t size) -{ - auto const start_timestamp = TimeManagement::the().uptime_ms(); - auto result = read_impl(fd, buffer, size); - - if (Thread::current()->is_profiling_suppressed()) - return result; - - auto description = TRY(open_readable_file_description(fds(), fd)); - PerformanceManager::add_read_event(*Thread::current(), fd, size, description, start_timestamp, result); - - return result; -} - ErrorOr Process::read_impl(int fd, Userspace buffer, size_t size) { VERIFY_PROCESS_BIG_LOCK_ACQUIRED(this); @@ -101,7 +87,7 @@ ErrorOr Process::read_impl(int fd, Userspace buffer, size_t size) return TRY(description->read(user_buffer, size)); } -ErrorOr Process::sys$pread(int fd, Userspace buffer, size_t size, off_t offset) +ErrorOr Process::pread_impl(int fd, Userspace buffer, size_t size, off_t offset) { VERIFY_PROCESS_BIG_LOCK_ACQUIRED(this); TRY(require_promise(Pledge::stdio)); diff --git a/Kernel/Tasks/PerformanceEventBuffer.cpp b/Kernel/Tasks/PerformanceEventBuffer.cpp index 12d0bdafcf..690d25660a 100644 --- a/Kernel/Tasks/PerformanceEventBuffer.cpp +++ b/Kernel/Tasks/PerformanceEventBuffer.cpp @@ -24,10 +24,10 @@ PerformanceEventBuffer::PerformanceEventBuffer(NonnullOwnPtr buffer) { } -NEVER_INLINE ErrorOr PerformanceEventBuffer::append(int type, FlatPtr arg1, FlatPtr arg2, StringView arg3, Thread* current_thread, FlatPtr arg4, u64 arg5, ErrorOr const& arg6) +NEVER_INLINE ErrorOr PerformanceEventBuffer::append(int type, FlatPtr arg1, FlatPtr arg2, StringView arg3, Thread* current_thread, FilesystemEvent filesystem_event) { FlatPtr base_pointer = (FlatPtr)__builtin_frame_address(0); - return append_with_ip_and_bp(current_thread->pid(), current_thread->tid(), 0, base_pointer, type, 0, arg1, arg2, arg3, arg4, arg5, arg6); + return append_with_ip_and_bp(current_thread->pid(), current_thread->tid(), 0, base_pointer, type, 0, arg1, arg2, arg3, filesystem_event); } static Vector raw_backtrace(FlatPtr bp, FlatPtr ip) @@ -68,13 +68,13 @@ static Vector raw_backtrace(Fl } ErrorOr PerformanceEventBuffer::append_with_ip_and_bp(ProcessID pid, ThreadID tid, RegisterState const& regs, - int type, u32 lost_samples, FlatPtr arg1, FlatPtr arg2, StringView arg3, FlatPtr arg4, u64 arg5, ErrorOr const& arg6) + int type, u32 lost_samples, FlatPtr arg1, FlatPtr arg2, StringView arg3, FilesystemEvent filesystem_event) { - return append_with_ip_and_bp(pid, tid, regs.ip(), regs.bp(), type, lost_samples, arg1, arg2, arg3, arg4, arg5, arg6); + return append_with_ip_and_bp(pid, tid, regs.ip(), regs.bp(), type, lost_samples, arg1, arg2, arg3, filesystem_event); } ErrorOr PerformanceEventBuffer::append_with_ip_and_bp(ProcessID pid, ThreadID tid, - FlatPtr ip, FlatPtr bp, int type, u32 lost_samples, FlatPtr arg1, FlatPtr arg2, StringView arg3, FlatPtr arg4, u64 arg5, ErrorOr const& arg6) + FlatPtr ip, FlatPtr bp, int type, u32 lost_samples, FlatPtr arg1, FlatPtr arg2, StringView arg3, FilesystemEvent filesystem_event) { if (count() >= capacity()) return ENOBUFS; @@ -160,12 +160,8 @@ ErrorOr PerformanceEventBuffer::append_with_ip_and_bp(ProcessID pid, Threa event.data.signpost.arg1 = arg1; event.data.signpost.arg2 = arg2; break; - case PERF_EVENT_READ: - event.data.read.fd = arg1; - event.data.read.size = arg2; - event.data.read.filename_index = arg4; - event.data.read.start_timestamp = arg5; - event.data.read.success = !arg6.is_error(); + case PERF_EVENT_FILESYSTEM: + event.data.filesystem = filesystem_event; break; default: return EINVAL; @@ -295,13 +291,51 @@ ErrorOr PerformanceEventBuffer::to_json_impl(Serializer& object) const TRY(event_object.add("arg1"sv, event.data.signpost.arg1)); TRY(event_object.add("arg2"sv, event.data.signpost.arg2)); break; - case PERF_EVENT_READ: - TRY(event_object.add("type"sv, "read")); - TRY(event_object.add("fd"sv, event.data.read.fd)); - TRY(event_object.add("size"sv, event.data.read.size)); - TRY(event_object.add("filename_index"sv, event.data.read.filename_index)); - TRY(event_object.add("start_timestamp"sv, event.data.read.start_timestamp)); - TRY(event_object.add("success"sv, event.data.read.success)); + case PERF_EVENT_FILESYSTEM: + TRY(event_object.add("type"sv, "filesystem"sv)); + TRY(event_object.add("durationNs"sv, event.data.filesystem.durationNs)); + switch (event.data.filesystem.type) { + case FilesystemEventType::Open: { + auto const& open = event.data.filesystem.data.open; + TRY(event_object.add("fs_event_type"sv, "open"sv)); + TRY(event_object.add("dirfd"sv, open.dirfd)); + TRY(event_object.add("filename_index"sv, open.filename_index)); + TRY(event_object.add("options"sv, open.options)); + TRY(event_object.add("mode"sv, open.mode)); + break; + } + case FilesystemEventType::Close: { + auto const& close = event.data.filesystem.data.close; + TRY(event_object.add("fs_event_type"sv, "close"sv)); + TRY(event_object.add("fd"sv, close.fd)); + TRY(event_object.add("filename_index"sv, close.filename_index)); + break; + } + case FilesystemEventType::Readv: { + auto const& readv = event.data.filesystem.data.readv; + TRY(event_object.add("fs_event_type"sv, "readv"sv)); + TRY(event_object.add("fd"sv, readv.fd)); + TRY(event_object.add("filename_index"sv, readv.filename_index)); + break; + } + case FilesystemEventType::Read: { + auto const& read = event.data.filesystem.data.read; + TRY(event_object.add("fs_event_type"sv, "read"sv)); + TRY(event_object.add("fd"sv, read.fd)); + TRY(event_object.add("filename_index"sv, read.filename_index)); + break; + } + case FilesystemEventType::Pread: { + auto const& pread = event.data.filesystem.data.pread; + TRY(event_object.add("fs_event_type"sv, "pread"sv)); + TRY(event_object.add("fd"sv, pread.fd)); + TRY(event_object.add("filename_index"sv, pread.filename_index)); + TRY(event_object.add("buffer_ptr"sv, pread.buffer_ptr)); + TRY(event_object.add("size"sv, pread.size)); + TRY(event_object.add("offset"sv, pread.offset)); + break; + } + } break; } TRY(event_object.add("pid"sv, event.pid)); diff --git a/Kernel/Tasks/PerformanceEventBuffer.h b/Kernel/Tasks/PerformanceEventBuffer.h index 53eaaf4ee0..e7fb5962f5 100644 --- a/Kernel/Tasks/PerformanceEventBuffer.h +++ b/Kernel/Tasks/PerformanceEventBuffer.h @@ -77,6 +77,66 @@ struct [[gnu::packed]] ReadPerformanceEvent { bool success; }; +enum class FilesystemEventType : u8 { + Open, + Close, + Readv, + Read, + Pread +}; + +struct [[gnu::packed]] OpenEventData { + int dirfd; + size_t filename_index; + int options; + u64 mode; +}; + +struct [[gnu::packed]] CloseEventData { + int fd; + size_t filename_index; +}; + +struct [[gnu::packed]] ReadvEventData { + int fd; + size_t filename_index; + // struct iovec* iov; // TODO: Implement + // int iov_count; // TODO: Implement +}; + +struct [[gnu::packed]] ReadEventData { + int fd; + size_t filename_index; +}; + +struct [[gnu::packed]] PreadEventData { + int fd; + size_t filename_index; + FlatPtr buffer_ptr; + size_t size; + off_t offset; +}; + +// FIXME: This is a hack to make the compiler pack this struct correctly. +struct [[gnu::packed]] PackedErrorOr { + bool is_error; + FlatPtr value; +}; + +struct [[gnu::packed]] FilesystemEvent { + FilesystemEventType type; + u64 durationNs; + PackedErrorOr result; + + union { + OpenEventData open; + CloseEventData close; + ReadvEventData readv; + ReadEventData read; + PreadEventData pread; + } data; +}; + struct [[gnu::packed]] PerformanceEvent { u32 type { 0 }; u8 stack_size { 0 }; @@ -96,7 +156,7 @@ struct [[gnu::packed]] PerformanceEvent { KMallocPerformanceEvent kmalloc; KFreePerformanceEvent kfree; SignpostPerformanceEvent signpost; - ReadPerformanceEvent read; + FilesystemEvent filesystem; } data; static constexpr size_t max_stack_frame_count = 64; FlatPtr stack[max_stack_frame_count]; @@ -111,11 +171,11 @@ class PerformanceEventBuffer { public: static OwnPtr try_create_with_size(size_t buffer_size); - ErrorOr append(int type, FlatPtr arg1, FlatPtr arg2, StringView arg3, Thread* current_thread = Thread::current(), FlatPtr arg4 = 0, u64 arg5 = 0, ErrorOr const& arg6 = 0); + ErrorOr append(int type, FlatPtr arg1, FlatPtr arg2, StringView arg3, Thread* current_thread = Thread::current(), FilesystemEvent filesystem_event = {}); ErrorOr append_with_ip_and_bp(ProcessID pid, ThreadID tid, FlatPtr eip, FlatPtr ebp, - int type, u32 lost_samples, FlatPtr arg1, FlatPtr arg2, StringView arg3, FlatPtr arg4 = 0, u64 arg5 = {}, ErrorOr const& arg6 = 0); + int type, u32 lost_samples, FlatPtr arg1, FlatPtr arg2, StringView arg3, FilesystemEvent filesystem_event = {}); ErrorOr append_with_ip_and_bp(ProcessID pid, ThreadID tid, RegisterState const& regs, - int type, u32 lost_samples, FlatPtr arg1, FlatPtr arg2, StringView arg3, FlatPtr arg4 = 0, u64 arg5 = {}, ErrorOr const& arg6 = 0); + int type, u32 lost_samples, FlatPtr arg1, FlatPtr arg2, StringView arg3, FilesystemEvent filesystem_event = {}); void clear() { diff --git a/Kernel/Tasks/PerformanceManager.h b/Kernel/Tasks/PerformanceManager.h index 14a73f5d17..ce30a206a8 100644 --- a/Kernel/Tasks/PerformanceManager.h +++ b/Kernel/Tasks/PerformanceManager.h @@ -1,5 +1,6 @@ /* * Copyright (c) 2021, Brian Gianforcaro + * Copyright (c) 2023, Jakub Berkop * * SPDX-License-Identifier: BSD-2-Clause */ @@ -128,40 +129,6 @@ public: } } - static void add_read_event(Thread& thread, int fd, size_t size, OpenFileDescription const& file_description, u64 start_timestamp, ErrorOr const& result) - { - if (thread.is_profiling_suppressed()) - return; - - auto* event_buffer = thread.process().current_perf_events_buffer(); - if (event_buffer == nullptr) - return; - - size_t filepath_string_index; - - if (auto path = file_description.original_absolute_path(); !path.is_error()) { - auto registered_result = event_buffer->register_string(move(path.value())); - if (registered_result.is_error()) - return; - filepath_string_index = registered_result.value(); - } else if (auto pseudo_path = file_description.pseudo_path(); !pseudo_path.is_error()) { - auto registered_result = event_buffer->register_string(move(pseudo_path.value())); - if (registered_result.is_error()) - return; - filepath_string_index = registered_result.value(); - } else { - auto invalid_path_string = KString::try_create(""sv); // TODO: Performance, unnecessary allocations. - if (invalid_path_string.is_error()) - return; - auto registered_result = event_buffer->register_string(move(invalid_path_string.value())); - if (registered_result.is_error()) - return; - filepath_string_index = registered_result.value(); - } - - [[maybe_unused]] auto rc = event_buffer->append(PERF_EVENT_READ, fd, size, {}, &thread, filepath_string_index, start_timestamp, result); // wrong arguments - } - static void timer_tick(RegisterState const& regs) { static UnixDateTime last_wakeup; diff --git a/Kernel/Tasks/Process.h b/Kernel/Tasks/Process.h index 02c6883351..4915fb6649 100644 --- a/Kernel/Tasks/Process.h +++ b/Kernel/Tasks/Process.h @@ -690,7 +690,11 @@ private: ErrorOr remap_range_as_stack(FlatPtr address, size_t size); + ErrorOr open_impl(Userspace); + ErrorOr close_impl(int fd); ErrorOr read_impl(int fd, Userspace buffer, size_t size); + ErrorOr pread_impl(int fd, Userspace, size_t, off_t); + ErrorOr readv_impl(int fd, Userspace iov, int iov_count); public: ErrorOr traverse_as_directory(FileSystemID, Function(FileSystem::DirectoryEntryView const&)> callback) const; diff --git a/Userland/DevTools/Profiler/FilesystemEventModel.cpp b/Userland/DevTools/Profiler/FilesystemEventModel.cpp index 906f2590cf..8e9d947650 100644 --- a/Userland/DevTools/Profiler/FilesystemEventModel.cpp +++ b/Userland/DevTools/Profiler/FilesystemEventModel.cpp @@ -1,5 +1,5 @@ /* - * Copyright (c) 2022, Jakub Berkop + * Copyright (c) 2022-2023, Jakub Berkop * * SPDX-License-Identifier: BSD-2-Clause */ @@ -22,11 +22,20 @@ FileEventModel::~FileEventModel() { } +u64 FileEventNode::total_count() const +{ + return m_open.count + m_close.count + m_readv.count + m_read.count + m_pread.count; +} + +Duration FileEventNode::total_duration() const +{ + return m_open.duration + m_close.duration + m_readv.duration + m_read.duration + m_pread.duration; +} + FileEventNode& FileEventNode::find_or_create_node(DeprecatedString const& searched_path) { // TODO: Optimize this function. - - if (searched_path == ""sv) { + if (searched_path == ""sv || searched_path == "/"sv) { return *this; } @@ -67,7 +76,7 @@ FileEventNode& FileEventNode::create_recursively(DeprecatedString new_path) auto parts = lex_path.parts(); if (parts.size() == 1) { - auto new_node = FileEventNode::create(new_path, this); + auto new_node = FileEventNode::create(parts.take_first(), this); m_children.append(new_node); return *new_node.ptr(); } else { @@ -147,10 +156,30 @@ ErrorOr FileEventModel::column_name(int column) const switch (column) { case Column::Path: return "Path"_string; - case Column::Count: - return "Event Count"_string; - case Column::Duration: - return "Duration [ms]"_string; + case Column::TotalCount: + return "Total Count"_string; + case Column::TotalDuration: + return "Total Duration [ms]"_string; + case Column::OpenCount: + return "Open Count"_string; + case Column::OpenDuration: + return "Open Duration [ms]"_string; + case Column::CloseCount: + return "Close Count"_string; + case Column::CloseDuration: + return "Close Duration [ms]"_string; + case Column::ReadvCount: + return "Readv Count"_string; + case Column::ReadvDuration: + return "Readv Duration [ms]"_string; + case Column::ReadCount: + return "Read Count"_string; + case Column::ReadDuration: + return "Read Duration [ms]"_string; + case Column::PreadCount: + return "Pread Count"_string; + case Column::PreadDuration: + return "Pread Duration [ms]"_string; default: VERIFY_NOT_REACHED(); } @@ -167,19 +196,36 @@ GUI::Variant FileEventModel::data(GUI::ModelIndex const& index, GUI::ModelRole r auto* node = static_cast(index.internal_data()); if (role == GUI::ModelRole::Display) { - if (index.column() == Column::Count) { - return node->count(); - } - - if (index.column() == Column::Path) { + switch (index.column()) { + case Column::Path: return node->path(); + case Column::TotalCount: + return node->total_count(); + case Column::TotalDuration: + return static_cast(node->total_duration().to_nanoseconds()) / 1'000'000; + case Column::OpenCount: + return node->open().count; + case Column::OpenDuration: + return static_cast(node->open().duration.to_nanoseconds()) / 1'000'000; + case Column::CloseCount: + return node->close().count; + case Column::CloseDuration: + return static_cast(node->close().duration.to_nanoseconds()) / 1'000'000; + case Column::ReadvCount: + return node->readv().count; + case Column::ReadvDuration: + return static_cast(node->readv().duration.to_nanoseconds()) / 1'000'000; + case Column::ReadCount: + return node->read().count; + case Column::ReadDuration: + return static_cast(node->read().duration.to_nanoseconds()) / 1'000'000; + case Column::PreadCount: + return node->pread().count; + case Column::PreadDuration: + return static_cast(node->pread().duration.to_nanoseconds()) / 1'000'000; + default: + return {}; } - - if (index.column() == Column::Duration) { - return node->duration(); - } - - return {}; } return {}; diff --git a/Userland/DevTools/Profiler/FilesystemEventModel.h b/Userland/DevTools/Profiler/FilesystemEventModel.h index 68963ebf9d..c80b307029 100644 --- a/Userland/DevTools/Profiler/FilesystemEventModel.h +++ b/Userland/DevTools/Profiler/FilesystemEventModel.h @@ -1,5 +1,5 @@ /* - * Copyright (c) 2022, Jakub Berkop + * Copyright (c) 2022-2023, Jakub Berkop * * SPDX-License-Identifier: BSD-2-Clause */ @@ -9,6 +9,7 @@ #include #include #include +#include #include namespace Profiler { @@ -35,22 +36,32 @@ public: DeprecatedString const& path() const { return m_path; } - void increment_count() { m_count++; } - u64 count() const { return m_count; } + u64 total_count() const; + Duration total_duration() const; - void add_to_duration(u64 duration) { duration += duration; } - u64 duration() const { return m_duration; } + struct FileEventType { + u64 count = 0; + Duration duration = {}; + }; + + FileEventType& open() { return m_open; } + FileEventType& close() { return m_close; } + FileEventType& readv() { return m_readv; } + FileEventType& read() { return m_read; } + FileEventType& pread() { return m_pread; } private: FileEventNode(DeprecatedString const& path, FileEventNode* parent = nullptr) : m_path(path) - , m_count(0) - , m_duration(0) , m_parent(parent) {}; DeprecatedString m_path; - u64 m_count; - u64 m_duration; + + FileEventType m_open; + FileEventType m_close; + FileEventType m_readv; + FileEventType m_read; + FileEventType m_pread; Vector> m_children; FileEventNode* m_parent = nullptr; @@ -65,8 +76,18 @@ public: enum Column { Path, - Count, - Duration, + TotalCount, + TotalDuration, + OpenCount, + OpenDuration, + CloseCount, + CloseDuration, + ReadvCount, + ReadvDuration, + ReadCount, + ReadDuration, + PreadCount, + PreadDuration, __Count }; diff --git a/Userland/DevTools/Profiler/Profile.cpp b/Userland/DevTools/Profiler/Profile.cpp index 413bdbec6f..5fddf4abd3 100644 --- a/Userland/DevTools/Profiler/Profile.cpp +++ b/Userland/DevTools/Profiler/Profile.cpp @@ -1,5 +1,6 @@ /* * Copyright (c) 2018-2021, Andreas Kling + * Copyright (c) 2023, Jakub Berkop * * SPDX-License-Identifier: BSD-2-Clause */ @@ -206,19 +207,51 @@ void Profile::rebuild_tree() } } } + if (event.data.has()) { + auto const& filesystem_event = event.data.get(); + auto const& path = filesystem_event.data.visit( + [&](Event::OpenEventData const& data) { + return data.path; + }, + [&](Event::CloseEventData const& data) { + return data.path; + }, + [&](Event::ReadvEventData const& data) { + return data.path; + }, + [&](Event::ReadEventData const& data) { + return data.path; + }, + [&](Event::PreadEventData const& data) { + return data.path; + }); - if (event.data.has()) { - auto const& read_event = event.data.get(); - auto& event_node = m_file_event_nodes->find_or_create_node(read_event.path); + auto& event_node = m_file_event_nodes->find_or_create_node(path); event_node.for_each_parent_node([&](FileEventNode& node) { - node.increment_count(); + auto const duration = filesystem_event.duration; - // Fixme: Currently events record 'timestamp' and 'start_timestamp' in ms resolution, - // which results in most durations equal to zero. Increasing the resolution should - // make the information more accurate. - auto const duration = event.timestamp - read_event.start_timestamp; - node.add_to_duration(duration); + filesystem_event.data.visit( + [&](Event::OpenEventData const&) { + node.open().duration += duration; + node.open().count++; + }, + [&](Event::CloseEventData const&) { + node.close().duration += duration; + node.close().count++; + }, + [&](Event::ReadvEventData const&) { + node.readv().duration += duration; + node.readv().count++; + }, + [&](Event::ReadEventData const&) { + node.read().duration += duration; + node.read().count++; + }, + [&](Event::PreadEventData const&) { + node.pread().duration += duration; + node.pread().count++; + }); }); } } @@ -385,15 +418,55 @@ ErrorOr> Profile::load_from_perfcore_file(StringView path if (it != current_processes.end()) it->value->handle_thread_exit(event.tid, event.serial); continue; - } else if (type_string == "read"sv) { - auto const string_index = perf_event.get_addr("filename_index"sv).value_or(0); - event.data = Event::ReadData { - .fd = perf_event.get_integer("fd"sv).value_or(0), - .size = perf_event.get_integer("size"sv).value_or(0), - .path = profile_strings.get(string_index).value(), - .start_timestamp = perf_event.get_integer("start_timestamp"sv).value_or(0), - .success = perf_event.get_bool("success"sv).value_or(false) + } else if (type_string == "filesystem"sv) { + Event::FilesystemEventData fsdata { + .duration = Duration::from_nanoseconds(perf_event.get_integer("durationNs"sv).value_or(0)), + .data = Event::OpenEventData {}, }; + auto const filesystem_event_type = perf_event.get("fs_event_type"sv).value_or("").as_string(); + if (filesystem_event_type == "open"sv) { + auto const string_index = perf_event.get_addr("filename_index"sv).value_or(0); + auto const filename = profile_strings.get(string_index).value_or("").view(); + fsdata.data = Event::OpenEventData { + .dirfd = perf_event.get_integer("dirfd"sv).value_or(0), + .path = filename, + .options = perf_event.get_integer("options"sv).value_or(0), + .mode = perf_event.get_integer("mode"sv).value_or(0), + }; + } else if (filesystem_event_type == "close"sv) { + auto const string_index = perf_event.get_addr("filename_index"sv).value_or(0); + auto const filename = profile_strings.get(string_index).value_or("").view(); + fsdata.data = Event::CloseEventData { + .fd = perf_event.get_integer("fd"sv).value_or(0), + .path = filename, + }; + } else if (filesystem_event_type == "readv"sv) { + auto const string_index = perf_event.get_addr("filename_index"sv).value_or(0); + auto const filename = profile_strings.get(string_index).value().view(); + fsdata.data = Event::ReadvEventData { + .fd = perf_event.get_integer("fd"sv).value_or(0), + .path = filename, + }; + } else if (filesystem_event_type == "read"sv) { + auto const string_index = perf_event.get_addr("filename_index"sv).value_or(0); + auto const filename = profile_strings.get(string_index).value().view(); + fsdata.data = Event::ReadEventData { + .fd = perf_event.get_integer("fd"sv).value_or(0), + .path = filename, + }; + } else if (filesystem_event_type == "pread"sv) { + auto const string_index = perf_event.get_addr("filename_index"sv).value_or(0); + auto const filename = profile_strings.get(string_index).value().view(); + fsdata.data = Event::PreadEventData { + .fd = perf_event.get_integer("fd"sv).value_or(0), + .path = filename, + .buffer_ptr = perf_event.get_integer("buffer_ptr"sv).value_or(0), + .size = perf_event.get_integer("size"sv).value_or(0), + .offset = perf_event.get_integer("offset"sv).value_or(0), + }; + } + + event.data = fsdata; } else { dbgln("Unknown event type '{}'", type_string); VERIFY_NOT_REACHED(); diff --git a/Userland/DevTools/Profiler/Profile.h b/Userland/DevTools/Profiler/Profile.h index 433d1a2668..74aa0f53f4 100644 --- a/Userland/DevTools/Profiler/Profile.h +++ b/Userland/DevTools/Profiler/Profile.h @@ -1,5 +1,6 @@ /* * Copyright (c) 2018-2021, Andreas Kling + * Copyright (c) 2023, Jakub Berkop * * SPDX-License-Identifier: BSD-2-Clause */ @@ -20,6 +21,7 @@ #include #include #include +#include #include #include #include @@ -222,15 +224,45 @@ public: pid_t parent_tid {}; }; - struct ReadData { - int fd; - size_t size; + // Based on Syscall::SC_open_params + struct OpenEventData { + int dirfd; DeprecatedString path; - size_t start_timestamp; - bool success; + int options; + u64 mode; }; - Variant data { nullptr }; + struct CloseEventData { + int fd; + DeprecatedString path; + }; + + struct ReadvEventData { + int fd; + DeprecatedString path; + // struct iovec* iov; // TODO: Implement + // int iov_count; // TODO: Implement + }; + + struct ReadEventData { + int fd; + DeprecatedString path; + }; + + struct PreadEventData { + int fd; + DeprecatedString path; + FlatPtr buffer_ptr; + size_t size; + off_t offset; + }; + + struct FilesystemEventData { + Duration duration; + Variant data; + }; + + Variant data { nullptr }; }; Vector const& events() const { return m_events; } diff --git a/Userland/DevTools/Profiler/SamplesModel.cpp b/Userland/DevTools/Profiler/SamplesModel.cpp index a6a0084b48..7c0af2f61c 100644 --- a/Userland/DevTools/Profiler/SamplesModel.cpp +++ b/Userland/DevTools/Profiler/SamplesModel.cpp @@ -1,6 +1,7 @@ /* * Copyright (c) 2018-2021, Andreas Kling * Copyright (c) 2022, the SerenityOS developers. + * Copyright (c) 2023, Jakub Berkop * * SPDX-License-Identifier: BSD-2-Clause */ @@ -90,9 +91,24 @@ GUI::Variant SamplesModel::data(GUI::ModelIndex const& index, GUI::ModelRole rol } if (index.column() == Column::Path) { - if (!event.data.has()) - return ""; - return event.data.get().path; + if (event.data.has()) { + return event.data.get().data.visit( + [&](Profile::Event::OpenEventData const& data) { + return data.path; + }, + [&](Profile::Event::CloseEventData const& data) { + return data.path; + }, + [&](Profile::Event::ReadvEventData const& data) { + return data.path; + }, + [&](Profile::Event::ReadEventData const& data) { + return data.path; + }, + [&](Profile::Event::PreadEventData const& data) { + return data.path; + }); + } } return {}; diff --git a/Userland/DevTools/Profiler/main.cpp b/Userland/DevTools/Profiler/main.cpp index a72677f105..3a0d886355 100644 --- a/Userland/DevTools/Profiler/main.cpp +++ b/Userland/DevTools/Profiler/main.cpp @@ -2,6 +2,7 @@ * Copyright (c) 2018-2021, Andreas Kling * Copyright (c) 2021, Julius Heijmen * Copyright (c) 2023, Jelle Raaijmakers + * Copyright (c) 2023, Jakub Berkop * * SPDX-License-Identifier: BSD-2-Clause */ @@ -264,6 +265,11 @@ ErrorOr serenity_main(Main::Arguments arguments) filesystem_events_tree_view->set_column_headers_visible(true); filesystem_events_tree_view->set_selection_behavior(GUI::TreeView::SelectionBehavior::SelectRows); filesystem_events_tree_view->set_model(profile->file_event_model()); + filesystem_events_tree_view->set_column_visible(FileEventModel::Column::OpenDuration, false); + filesystem_events_tree_view->set_column_visible(FileEventModel::Column::CloseDuration, false); + filesystem_events_tree_view->set_column_visible(FileEventModel::Column::ReadvDuration, false); + filesystem_events_tree_view->set_column_visible(FileEventModel::Column::ReadDuration, false); + filesystem_events_tree_view->set_column_visible(FileEventModel::Column::PreadDuration, false); auto file_menu = window->add_menu("&File"_string); file_menu->add_action(GUI::CommonActions::make_quit_action([&](auto&) { app->quit(); })); diff --git a/Userland/Utilities/profile.cpp b/Userland/Utilities/profile.cpp index ddab9d6d3d..0d16870390 100644 --- a/Userland/Utilities/profile.cpp +++ b/Userland/Utilities/profile.cpp @@ -52,8 +52,8 @@ ErrorOr serenity_main(Main::Arguments arguments) event_mask |= PERF_EVENT_PAGE_FAULT; else if (event_type == "syscall") event_mask |= PERF_EVENT_SYSCALL; - else if (event_type == "read") - event_mask |= PERF_EVENT_READ; + else if (event_type == "filesystem") + event_mask |= PERF_EVENT_FILESYSTEM; else { warnln("Unknown event type '{}' specified.", event_type); exit(1); @@ -65,7 +65,7 @@ ErrorOr serenity_main(Main::Arguments arguments) auto print_types = [] { outln(); - outln("Event type can be one of: sample, context_switch, page_fault, syscall, read, kmalloc and kfree."); + outln("Event type can be one of: sample, context_switch, page_fault, syscall, filesystem, kmalloc and kfree."); }; if (!args_parser.parse(arguments, Core::ArgsParser::FailureBehavior::PrintUsage)) {