From 6227c0c1ab3d262d6b2877e755a85883b4241778 Mon Sep 17 00:00:00 2001 From: Pierric Gimmig Date: Fri, 13 Oct 2023 08:44:44 -0700 Subject: [PATCH] Trace closing of tracing fds by type --- src/LinuxTracing/PerfEventProcessor.cpp | 4 ++ src/LinuxTracing/TracerImpl.cpp | 54 ++++++++++++++----------- src/LinuxTracing/TracerImpl.h | 2 +- 3 files changed, 36 insertions(+), 24 deletions(-) diff --git a/src/LinuxTracing/PerfEventProcessor.cpp b/src/LinuxTracing/PerfEventProcessor.cpp index 4b4e3227ea4..1aae3f6e9f8 100644 --- a/src/LinuxTracing/PerfEventProcessor.cpp +++ b/src/LinuxTracing/PerfEventProcessor.cpp @@ -6,6 +6,7 @@ #include +#include "Introspection/Introspection.h" #include "OrbitBase/Logging.h" #include "OrbitBase/Profiling.h" #include "PerfEvent.h" @@ -40,6 +41,7 @@ void PerfEventProcessor::AddEvent(PerfEvent&& event) { // DiscardedPerfEvents. std::optional PerfEventProcessor::HandleOutOfOrderEvent( uint64_t event_timestamp_ns) { + ORBIT_SCOPE("PerfEventProcessor::HandleOutOfOrderEvent"); const uint64_t discarded_begin = event_timestamp_ns; const uint64_t discarded_end = last_processed_timestamp_ns_; @@ -84,6 +86,7 @@ std::optional PerfEventProcessor::HandleOutOfOrderEvent( } void PerfEventProcessor::ProcessAllEvents() { + ORBIT_SCOPE("PerfEventProcessor::ProcessAllEvents"); ORBIT_CHECK(!visitors_.empty()); while (event_queue_.HasEvent()) { const PerfEvent& event = event_queue_.TopEvent(); @@ -99,6 +102,7 @@ void PerfEventProcessor::ProcessAllEvents() { } void PerfEventProcessor::ProcessOldEvents() { + ORBIT_SCOPE("PerfEventProcessor::ProcessOldEvents"); ORBIT_CHECK(!visitors_.empty()); const uint64_t current_timestamp_ns = orbit_base::CaptureTimestampNs(); diff --git a/src/LinuxTracing/TracerImpl.cpp b/src/LinuxTracing/TracerImpl.cpp index 2bdf3a3f8cc..9c2f845958e 100644 --- a/src/LinuxTracing/TracerImpl.cpp +++ b/src/LinuxTracing/TracerImpl.cpp @@ -299,7 +299,7 @@ void TracerImpl::AddUprobesFileDescriptors( } else { uprobes_ids_.insert(stream_id); } - tracing_fds_.push_back(fd); + tracing_fds_by_type_["uprobe"].push_back(fd); } } @@ -315,7 +315,7 @@ void TracerImpl::AddUretprobesFileDescriptors( } else { uretprobes_ids_.insert(stream_id); } - tracing_fds_.push_back(fd); + tracing_fds_by_type_["uretprobe"].push_back(fd); } } @@ -389,7 +389,7 @@ bool TracerImpl::OpenUprobesToRecordAdditionalStackOn(absl::Span for (const auto [cpu, fd] : uprobes_fds_per_cpu) { uint64_t stream_id = perf_event_get_id(fd); uprobes_with_stack_ids_.insert(stream_id); - tracing_fds_.push_back(fd); + tracing_fds_by_type_["uprobe_additional_stack"].push_back(fd); } OpenRingBuffersOrRedirectOnExisting(uprobes_fds_per_cpu, &fds_per_cpu_for_redirection, &ring_buffers_, kUprobesWithStackRingBufferSizeKb, @@ -418,7 +418,7 @@ bool TracerImpl::OpenMmapTask(absl::Span cpus) { } for (int fd : mmap_task_tracing_fds) { - tracing_fds_.push_back(fd); + tracing_fds_by_type_["mmap_task"].push_back(fd); } for (PerfEventRingBuffer& buffer : mmap_task_ring_buffers) { ring_buffers_.emplace_back(std::move(buffer)); @@ -465,7 +465,7 @@ bool TracerImpl::OpenSampling(absl::Span cpus) { } for (int fd : sampling_tracing_fds) { - tracing_fds_.push_back(fd); + tracing_fds_by_type_["sampling"].push_back(fd); uint64_t stream_id = perf_event_get_id(fd); if (unwinding_method_ == CaptureOptions::kDwarf) { stack_sampling_ids_.insert(stream_id); @@ -497,7 +497,8 @@ struct TracepointToOpen { static bool OpenFileDescriptorsAndRingBuffersForAllTracepoints( absl::Span tracepoints_to_open, absl::Span cpus, - std::vector* tracing_fds, uint64_t ring_buffer_size_kb, + absl::flat_hash_map>* tracing_fds_by_type, + uint64_t ring_buffer_size_kb, absl::flat_hash_map* tracepoint_ring_buffer_fds_per_cpu_for_redirection, std::vector* ring_buffers, uint32_t stack_dump_size = 0, const CaptureOptions::ThreadStateChangeCallStackCollection @@ -553,7 +554,7 @@ static bool OpenFileDescriptorsAndRingBuffersForAllTracepoints( tracepoints_to_open[tracepoint_index].tracepoint_stream_ids; for (const auto& cpu_and_fd : index_and_tracepoint_fds_per_cpu.second) { - tracing_fds->push_back(cpu_and_fd.second); + (*tracing_fds_by_type)["tracepoint"].push_back(cpu_and_fd.second); tracepoint_stream_ids->insert(perf_event_get_id(cpu_and_fd.second)); } } @@ -578,7 +579,7 @@ bool TracerImpl::OpenThreadNameTracepoints(absl::Span cpus) { absl::flat_hash_map thread_name_tracepoint_ring_buffer_fds_per_cpu; return OpenFileDescriptorsAndRingBuffersForAllTracepoints( {{"task", "task_newtask", &task_newtask_ids_}, {"task", "task_rename", &task_rename_ids_}}, - cpus, &tracing_fds_, kThreadNamesRingBufferSizeKb, + cpus, &tracing_fds_by_type_, kThreadNamesRingBufferSizeKb, &thread_name_tracepoint_ring_buffer_fds_per_cpu, &ring_buffers_); } @@ -635,7 +636,7 @@ bool TracerImpl::OpenContextSwitchAndThreadStateTracepoints(absl::Span cpus) { {{"amdgpu", "amdgpu_cs_ioctl", &amdgpu_cs_ioctl_ids_}, {"amdgpu", "amdgpu_sched_run_job", &amdgpu_sched_run_job_ids_}, {"dma_fence", "dma_fence_signaled", &dma_fence_signaled_ids_}}, - cpus, &tracing_fds_, kGpuTracingRingBufferSizeKb, &gpu_tracepoint_ring_buffer_fds_per_cpu, - &ring_buffers_); + cpus, &tracing_fds_by_type_, kGpuTracingRingBufferSizeKb, + &gpu_tracepoint_ring_buffer_fds_per_cpu, &ring_buffers_); } bool TracerImpl::OpenInstrumentedTracepoints(absl::Span cpus) { @@ -679,7 +680,7 @@ bool TracerImpl::OpenInstrumentedTracepoints(absl::Span cpus) { absl::flat_hash_set stream_ids; tracepoint_event_open_errors |= !OpenFileDescriptorsAndRingBuffersForAllTracepoints( {{selected_tracepoint.category().c_str(), selected_tracepoint.name().c_str(), &stream_ids}}, - cpus, &tracing_fds_, kInstrumentedTracepointsRingBufferSizeKb, + cpus, &tracing_fds_by_type_, kInstrumentedTracepointsRingBufferSizeKb, &tracepoint_ring_buffer_fds_per_cpu, &ring_buffers_); for (const auto& stream_id : stream_ids) { @@ -841,8 +842,10 @@ void TracerImpl::Startup() { } // Start recording events. - for (int fd : tracing_fds_) { - perf_event_enable(fd); + for (const auto& [unused_name, fds] : tracing_fds_by_type_) { + for (int fd : fds) { + perf_event_enable(fd); + } } effective_capture_start_timestamp_ns_ = orbit_base::CaptureTimestampNs(); @@ -906,8 +909,12 @@ void TracerImpl::Shutdown() { } // Stop recording. - for (int fd : tracing_fds_) { - perf_event_disable(fd); + size_t num_fds = 0; + for (const auto& [unused_fd_type, fds] : tracing_fds_by_type_) { + for (int fd : fds) { + perf_event_disable(fd); + ++num_fds; + } } // Close the ring buffers. @@ -917,12 +924,13 @@ void TracerImpl::Shutdown() { } // Close the file descriptors. - { - ORBIT_SCOPE_WITH_COLOR( - absl::StrFormat("Closing %d file descriptors", tracing_fds_.size()).c_str(), - kOrbitColorRed); - ORBIT_SCOPED_TIMED_LOG("Closing %d file descriptors", tracing_fds_.size()); - for (int fd : tracing_fds_) { + ORBIT_SCOPE_WITH_COLOR(absl::StrFormat("Closing %d file descriptors", num_fds).c_str(), + kOrbitColorRed); + for (auto& [fd_type, fds] : tracing_fds_by_type_) { + std::string msg = absl::StrFormat("Closing %d %s file descriptors", fds.size(), fd_type); + ORBIT_SCOPE(msg.c_str()); + ORBIT_SCOPED_TIMED_LOG("%s", msg); + for (int fd : fds) { ORBIT_SCOPE("Closing fd"); close(fd); } @@ -1568,7 +1576,7 @@ void TracerImpl::RetrieveInitialThreadStatesOfTarget() { void TracerImpl::Reset() { ORBIT_SCOPE_FUNCTION; - tracing_fds_.clear(); + tracing_fds_by_type_.clear(); ring_buffers_.clear(); fds_to_last_timestamp_ns_.clear(); diff --git a/src/LinuxTracing/TracerImpl.h b/src/LinuxTracing/TracerImpl.h index 00291f28d23..58f066e00a3 100644 --- a/src/LinuxTracing/TracerImpl.h +++ b/src/LinuxTracing/TracerImpl.h @@ -166,7 +166,7 @@ class TracerImpl : public Tracer { std::atomic stop_run_thread_ = true; std::thread run_thread_; - std::vector tracing_fds_; + absl::flat_hash_map> tracing_fds_by_type_; std::vector ring_buffers_; absl::flat_hash_map fds_to_last_timestamp_ns_;