diff --git a/tcmalloc/deallocation_profiler.cc b/tcmalloc/deallocation_profiler.cc index c7ec67693..5e10e030a 100644 --- a/tcmalloc/deallocation_profiler.cc +++ b/tcmalloc/deallocation_profiler.cc @@ -23,17 +23,16 @@ #include #include #include -#include #include #include #include +#include #include "absl/base/attributes.h" -#include "absl/base/const_init.h" #include "absl/base/internal/low_level_alloc.h" #include "absl/base/internal/spinlock.h" #include "absl/base/internal/sysinfo.h" -#include "absl/base/macros.h" +#include "absl/base/nullability.h" #include "absl/container/flat_hash_map.h" #include "absl/debugging/stacktrace.h" // for GetStackTrace #include "absl/functional/function_ref.h" @@ -48,6 +47,7 @@ #include "tcmalloc/internal/sampled_allocation.h" #include "tcmalloc/internal_malloc_extension.h" #include "tcmalloc/malloc_extension.h" +#include "tcmalloc/parameters.h" #include "tcmalloc/sampler.h" #include "tcmalloc/static_vars.h" @@ -380,8 +380,23 @@ class DeallocationProfiler { class DeallocationStackTraceTable final : public tcmalloc_internal::ProfileBase { public: + explicit DeallocationStackTraceTable(Mode mode) + : mode_(mode), + max_events_( + mode == Mode::kEventTrace + ? std::max(0, static_cast( + tcmalloc_internal::Parameters:: + event_trace_memory_limit() / + sizeof(DeallocationSampleRecord))) + : 0) { + if (mode_ == Mode::kEventTrace) { + events_.reserve(max_events_); + } + } + // We define the dtor to ensure it is placed in the desired text section. ~DeallocationStackTraceTable() override = default; + void AddTrace(const DeallocationSampleRecord& alloc_trace, const DeallocationSampleRecord& dealloc_trace); @@ -389,7 +404,12 @@ class DeallocationProfiler { absl::FunctionRef func) const override; ProfileType Type() const override { - return tcmalloc::ProfileType::kLifetimes; + switch (mode_) { + case Mode::kLifetimes: + return tcmalloc::ProfileType::kLifetimes; + case Mode::kEventTrace: + return tcmalloc::ProfileType::kEventTrace; + } } std::optional StartTime() const override { return start_time_; } @@ -441,12 +461,22 @@ class DeallocationProfiler { } }; + Mode mode_; + + // Used in kLifetimes mode. absl::flat_hash_map, std::equal_to, AllocAdaptor, MyAllocator>> table_; + // Used in kEventTrace mode. + // This is technically a fixed-size container -- we ::reserve capacity at + // construction time and truncate traces after reaching max_events_, hence + // the lack of low-level allocator. + int32_t max_events_ = 0; + std::vector events_; + absl::Time start_time_ = absl::Now(); - absl::Time stop_time_; + absl::Time stop_time_ = absl::InfiniteFuture(); }; // Keep track of allocations that are in flight @@ -456,8 +486,9 @@ class DeallocationProfiler { std::unique_ptr reports_ = nullptr; public: - explicit DeallocationProfiler(DeallocationProfilerList* list) : list_(list) { - reports_ = std::make_unique(); + explicit DeallocationProfiler(DeallocationProfilerList* list, Mode mode) + : list_(list) { + reports_ = std::make_unique(mode); list_->Add(this); } @@ -495,15 +526,20 @@ class DeallocationProfiler { void ReportFree(tcmalloc_internal::AllocHandle handle) { auto it = allocs_.find(handle); + DeallocationSampleRecord sample; - // Handle the case that we observed the deallocation but not the allocation + // Handle the (left-censored) case that we observed the deallocation but not + // the allocation. Since we only get the handle here, left-censored + // deallocations necessarily have depth = 0 and allocated_size = 0. if (it == allocs_.end()) { - return; + sample = {}; + sample.stack_trace.sampled_alloc_handle = handle; + sample.stack_trace.depth = 0; + } else { + sample = it->second; + allocs_.erase(it); } - DeallocationSampleRecord sample = it->second; - allocs_.erase(it); - DeallocationSampleRecord deallocation; deallocation.stack_trace = sample.stack_trace; deallocation.stack_trace.allocation_time = absl::Now(); @@ -592,6 +628,30 @@ void DeallocationProfiler::DeallocationStackTraceTable::StopAndRecord( void DeallocationProfiler::DeallocationStackTraceTable::AddTrace( const DeallocationSampleRecord& alloc_trace, const DeallocationSampleRecord& dealloc_trace) { + if (mode_ == Mode::kEventTrace) { + // Ensure we can fit up to 2 records (alloc + dealloc) without exceeding + // capacity; otherwise silently truncate the trace. + if (events_.size() + 2 <= max_events_) { + if (alloc_trace.stack_trace.depth > 0) { + events_.push_back(alloc_trace); + } + if (dealloc_trace.stack_trace.depth > 0) { + events_.push_back(dealloc_trace); + // In-band signal to Iterate() that this is a deallocation event. We can + // do this because: + // - Matched events propagate the allocated_size via the + // alloc_trace (and the pair can be associated downstream). + // - Left-censored events are only passed to ReportFree as + // alloc_handle-s, i.e. we can't know the allocated_size. + events_.back().stack_trace.allocated_size = 0; + } + } + return; + } + + // Left-censored samples cannot be aggregated with lifetimes + if (alloc_trace.stack_trace.depth == 0) return; + CpuThreadMatchingStatus status = CpuThreadMatchingStatus(alloc_trace.cpu_id == dealloc_trace.cpu_id, alloc_trace.vcpu_id == dealloc_trace.vcpu_id, @@ -630,6 +690,29 @@ void DeallocationProfiler::DeallocationStackTraceTable::AddTrace( void DeallocationProfiler::DeallocationStackTraceTable::Iterate( absl::FunctionRef func) const { + if (mode_ == Mode::kEventTrace) { + for (const auto& r : events_) { + tcmalloc::Profile::Sample s = {}; + // Allocations have allocated_size > 0; + // Deallocations (matched and left-censored) have allocated_size == 0. + s.count = r.stack_trace.allocated_size > 0 ? 1 : -1; + s.allocation_time = r.stack_trace.allocation_time; + s.alloc_handle = r.stack_trace.sampled_alloc_handle; + s.allocated_size = r.stack_trace.allocated_size; + s.requested_size = r.stack_trace.requested_size; + s.cpu_id = r.cpu_id; + s.vcpu_id = r.vcpu_id; + s.l3_id = r.l3_id; + s.numa_id = r.numa_id; + s.thread_id = r.thread_id; + s.depth = std::min(r.stack_trace.depth, + tcmalloc::Profile::Sample::kMaxStackDepth); + std::copy(r.stack_trace.stack, r.stack_trace.stack + s.depth, s.stack); + func(s); + } + return; + } + uint64_t pair_id = 1; for (auto& it : table_) { @@ -731,8 +814,9 @@ void DeallocationProfiler::DeallocationStackTraceTable::Iterate( } } -DeallocationSample::DeallocationSample(DeallocationProfilerList* list) { - profiler_ = std::make_unique(list); +DeallocationSample::DeallocationSample( + DeallocationProfilerList* absl_nonnull list, Mode mode) { + profiler_ = std::make_unique(list, mode); } DeallocationSample::~DeallocationSample() = default; diff --git a/tcmalloc/deallocation_profiler.h b/tcmalloc/deallocation_profiler.h index 40e21acf6..1c9322205 100644 --- a/tcmalloc/deallocation_profiler.h +++ b/tcmalloc/deallocation_profiler.h @@ -17,8 +17,8 @@ #include -#include "absl/base/const_init.h" #include "absl/base/internal/spinlock.h" +#include "absl/base/nullability.h" #include "absl/time/time.h" #include "tcmalloc/internal/config.h" #include "tcmalloc/internal/logging.h" @@ -46,10 +46,16 @@ class DeallocationProfilerList { absl::base_internal::SCHEDULE_KERNEL_ONLY}; }; +// Lifetime profiling is essentially a time-aggregated view of an event trace, +// so we share the majority of the implementation and switch internally in the +// cases where the implementations must diverge. +enum class Mode { kLifetimes, kEventTrace }; + class DeallocationSample final : public tcmalloc_internal::AllocationProfilingTokenBase { public: - explicit DeallocationSample(DeallocationProfilerList* absl_nonnull list); + explicit DeallocationSample(DeallocationProfilerList* absl_nonnull list, + Mode mode); // We define the dtor to ensure it is placed in the desired text section. ~DeallocationSample() override; diff --git a/tcmalloc/internal/parameter_accessors.h b/tcmalloc/internal/parameter_accessors.h index 8d93888cd..34847329d 100644 --- a/tcmalloc/internal/parameter_accessors.h +++ b/tcmalloc/internal/parameter_accessors.h @@ -88,6 +88,8 @@ TCMalloc_Internal_SetHugePageFillerSkipSubreleaseLongInterval(absl::Duration v); ABSL_ATTRIBUTE_WEAK bool TCMalloc_Internal_GetMadviseColdRegionsNoHugepage(); ABSL_ATTRIBUTE_WEAK void TCMalloc_Internal_SetMadviseColdRegionsNoHugepage( bool v); +ABSL_ATTRIBUTE_WEAK int64_t TCMalloc_Internal_GetEventTraceMemoryLimit(); +ABSL_ATTRIBUTE_WEAK void TCMalloc_Internal_SetEventTraceMemoryLimit(int64_t v); ABSL_ATTRIBUTE_WEAK uint8_t TCMalloc_Internal_GetMinHotAccessHint(); ABSL_ATTRIBUTE_WEAK void TCMalloc_Internal_SetMinHotAccessHint(uint8_t v); [[maybe_unused]] ABSL_ATTRIBUTE_WEAK bool TCMalloc_Internal_PossiblyCold( diff --git a/tcmalloc/internal/profile_builder.cc b/tcmalloc/internal/profile_builder.cc index 3b0d87c8a..f0db12893 100644 --- a/tcmalloc/internal/profile_builder.cc +++ b/tcmalloc/internal/profile_builder.cc @@ -684,19 +684,33 @@ static absl::Status MakeLifetimeProfileProto(const tcmalloc::Profile& profile, // Common intern string ids which are going to be used for each sample. const int count_id = builder->InternString("count"); const int nanoseconds_id = builder->InternString("nanoseconds"); - const int avg_lifetime_id = builder->InternString("avg_lifetime"); - const int stddev_lifetime_id = builder->InternString("stddev_lifetime"); - const int min_lifetime_id = builder->InternString("min_lifetime"); - const int max_lifetime_id = builder->InternString("max_lifetime"); + const int cpu_raw_id = builder->InternString("cpu_id"); const int active_cpu_id = builder->InternString("active CPU"); + const int vcpu_raw_id = builder->InternString("vcpu_id"); const int active_vcpu_id = builder->InternString("active vCPU"); + const int l3_raw_id = builder->InternString("l3_id"); const int active_l3_id = builder->InternString("active L3"); + const int numa_raw_id = builder->InternString("numa_id"); const int active_numa_id = builder->InternString("active NUMA"); + const int thread_raw_id = builder->InternString("thread_id"); + const int active_thread_id = builder->InternString("active thread"); + + // Lifetime profiling. + const int avg_lifetime_id = builder->InternString("avg_lifetime"); + const int stddev_lifetime_id = builder->InternString("stddev_lifetime"); + const int min_lifetime_id = builder->InternString("min_lifetime"); + const int max_lifetime_id = builder->InternString("max_lifetime"); const int same_id = builder->InternString("same"); const int different_id = builder->InternString("different"); - const int active_thread_id = builder->InternString("active thread"); - const int callstack_pair_id = builder->InternString("callstack-pair-id"); const int none_id = builder->InternString("none"); + const int callstack_pair_id = builder->InternString("callstack-pair-id"); + + // Event tracing. + const int bytes_id = builder->InternString("bytes"); + const int alloc_handle_id = builder->InternString("alloc_handle"); + const int allocation_time_id = builder->InternString("allocation_time"); + const int deallocation_time_id = builder->InternString("deallocation_time"); + const int requested_size_id = builder->InternString("requested_size"); profile.Iterate([&](const tcmalloc::Profile::Sample& entry) { perftools::profiles::Sample& sample = *converted.add_sample(); @@ -716,6 +730,13 @@ static absl::Status MakeLifetimeProfileProto(const tcmalloc::Profile& profile, add_label(key, unit, value); }; + auto add_optional_int_label = [&](int key, int unit, + std::optional opt_value) { + if (opt_value.has_value()) { + add_label(key, unit, static_cast(opt_value.value())); + } + }; + auto add_optional_string_label = [&](int key, const std::optional& optional_result, int result1, int result2) { @@ -744,18 +765,23 @@ static absl::Status MakeLifetimeProfileProto(const tcmalloc::Profile& profile, add_positive_label(max_lifetime_id, nanoseconds_id, absl::ToInt64Nanoseconds(entry.max_lifetime)); + add_optional_int_label(cpu_raw_id, 0, entry.cpu_id); add_optional_string_label(active_cpu_id, entry.allocator_deallocator_physical_cpu_matched, same_id, different_id); + add_optional_int_label(vcpu_raw_id, 0, entry.vcpu_id); add_optional_string_label(active_vcpu_id, entry.allocator_deallocator_virtual_cpu_matched, same_id, different_id); + add_optional_int_label(l3_raw_id, 0, entry.l3_id); add_optional_string_label(active_l3_id, entry.allocator_deallocator_l3_matched, same_id, different_id); + add_optional_int_label(numa_raw_id, 0, entry.numa_id); add_optional_string_label(active_numa_id, entry.allocator_deallocator_numa_matched, same_id, different_id); + add_optional_int_label(thread_raw_id, 0, entry.thread_id); add_optional_string_label(active_thread_id, entry.allocator_deallocator_thread_matched, same_id, different_id); @@ -763,6 +789,23 @@ static absl::Status MakeLifetimeProfileProto(const tcmalloc::Profile& profile, int64_t count = abs(entry.count); int64_t weight = entry.sum; + if (auto handle = static_cast(entry.alloc_handle); handle != 0) { + add_label(alloc_handle_id, count_id, handle); + } + // Set during event tracing, unset (epoch) during lifetime profiling. + if (entry.allocation_time > absl::UnixEpoch()) { + if (entry.count < 0) { // Deallocation event + add_label(deallocation_time_id, nanoseconds_id, + absl::ToUnixNanos(entry.allocation_time)); + } else { // Allocation event or censored allocation + add_label(allocation_time_id, nanoseconds_id, + absl::ToUnixNanos(entry.allocation_time)); + } + } + if (entry.count > 0) { // Allocation event + add_label(requested_size_id, bytes_id, entry.requested_size); + } + // Handle censored allocations first since we distinguish // the samples based on the is_censored flag. if (entry.is_censored) { @@ -815,7 +858,8 @@ absl::StatusOr> MakeProfileProto( ProfileBuilder builder; builder.AddCurrentMappings(); - if (profile.Type() == ProfileType::kLifetimes) { + if (profile.Type() == ProfileType::kLifetimes || + profile.Type() == ProfileType::kEventTrace) { absl::Status error = MakeLifetimeProfileProto(profile, &builder); if (!error.ok()) { return error; diff --git a/tcmalloc/internal_malloc_extension.h b/tcmalloc/internal_malloc_extension.h index 67f6cdf1f..6399e3e75 100644 --- a/tcmalloc/internal_malloc_extension.h +++ b/tcmalloc/internal_malloc_extension.h @@ -73,6 +73,8 @@ ABSL_ATTRIBUTE_WEAK tcmalloc::tcmalloc_internal::AllocationProfilingTokenBase* MallocExtension_Internal_StartAllocationProfiling(); ABSL_ATTRIBUTE_WEAK tcmalloc::tcmalloc_internal::AllocationProfilingTokenBase* MallocExtension_Internal_StartLifetimeProfiling(); +ABSL_ATTRIBUTE_WEAK tcmalloc::tcmalloc_internal::AllocationProfilingTokenBase* +MallocExtension_Internal_StartEventTracing(); ABSL_ATTRIBUTE_WEAK void MallocExtension_Internal_ActivateGuardedSampling(); ABSL_ATTRIBUTE_WEAK tcmalloc::MallocExtension::Ownership diff --git a/tcmalloc/malloc_extension.cc b/tcmalloc/malloc_extension.cc index b9965c841..4d4745eeb 100644 --- a/tcmalloc/malloc_extension.cc +++ b/tcmalloc/malloc_extension.cc @@ -305,6 +305,20 @@ MallocExtension::StartLifetimeProfiling() { #endif } +MallocExtension::AllocationProfilingToken MallocExtension::StartEventTracing() { +#if ABSL_INTERNAL_HAVE_WEAK_MALLOCEXTENSION_STUBS + if (&MallocExtension_Internal_StartEventTracing == nullptr) { + return {}; + } + + return tcmalloc_internal::AllocationProfilingTokenAccessor::MakeToken( + std::unique_ptr( + MallocExtension_Internal_StartEventTracing())); +#else + return {}; +#endif +} + void MallocExtension::MarkThreadIdle() { #if ABSL_INTERNAL_HAVE_WEAK_MALLOCEXTENSION_STUBS if (&MallocExtension_Internal_MarkThreadIdle == nullptr) { diff --git a/tcmalloc/malloc_extension.h b/tcmalloc/malloc_extension.h index 06f954a30..b9f8674e4 100644 --- a/tcmalloc/malloc_extension.h +++ b/tcmalloc/malloc_extension.h @@ -165,6 +165,16 @@ enum class ProfileType { // Lifetimes of sampled objects that are live during the profiling session. kLifetimes, + // Temporal trace of alloc/dealloc events. + // + // This is a deallocation profiler in sprit, hence its position under + // kLifetimes -- use that if you seek a time-aggregated view of the same data. + // + // Note that the memory overhead of this profile is necessarily larger than + // that of typical profiles; as a result, event traces are truncated after + // reaching TCMalloc_Internal_GetEventTraceMemoryLimit. + kEventTrace, + // Only present to prevent switch statements without a default clause so that // we can extend this enumeration without breaking code. kDoNotUse, @@ -289,10 +299,15 @@ class Profile final { // For the *_matched vars below we use true = "same", false = "different". // When the value is unavailable the profile contains "none". For // right-censored observations, CPU and thread matched values are "none". + std::optional cpu_id; std::optional allocator_deallocator_physical_cpu_matched; + std::optional vcpu_id; std::optional allocator_deallocator_virtual_cpu_matched; + std::optional l3_id; std::optional allocator_deallocator_l3_matched; + std::optional numa_id; std::optional allocator_deallocator_numa_matched; + std::optional thread_id; std::optional allocator_deallocator_thread_matched; // The start address of the sampled allocation, used to calculate the @@ -674,6 +689,10 @@ class MallocExtension final { // session. Returns null if the implementation does not support profiling. [[nodiscard]] static AllocationProfilingToken StartLifetimeProfiling(); + // Start recording a temporal trace of alloc/free events. + // Returns null if the implementation does not support profiling. + [[nodiscard]] static AllocationProfilingToken StartEventTracing(); + // Runs housekeeping actions for the allocator off of the main allocation path // of new/delete. As of 2020, this includes: // * Inspecting the current CPU mask and releasing memory from inaccessible diff --git a/tcmalloc/parameters.cc b/tcmalloc/parameters.cc index bc5145e64..85a460ba1 100644 --- a/tcmalloc/parameters.cc +++ b/tcmalloc/parameters.cc @@ -231,6 +231,8 @@ ABSL_CONST_INIT std::atomic Parameters::back_size_threshold_bytes_( ABSL_CONST_INIT std::atomic Parameters::enable_unfiltered_collapse_( false); ABSL_CONST_INIT std::atomic Parameters::release_max_cold_pages_(false); +ABSL_CONST_INIT std::atomic Parameters::event_trace_memory_limit_( + 16 << 20); static std::atomic& madvise_cold_regions_nohugepage_enabled() { ABSL_CONST_INIT static absl::once_flag flag; @@ -660,6 +662,14 @@ void TCMalloc_Internal_SetMadviseColdRegionsNoHugepage(bool v) { std::memory_order_relaxed); } +int64_t TCMalloc_Internal_GetEventTraceMemoryLimit() { + return Parameters::event_trace_memory_limit(); +} + +void TCMalloc_Internal_SetEventTraceMemoryLimit(int64_t v) { + Parameters::event_trace_memory_limit_.store(v, std::memory_order_relaxed); +} + } // extern "C" GOOGLE_MALLOC_SECTION_END diff --git a/tcmalloc/parameters.h b/tcmalloc/parameters.h index 6ccb0f989..55e0c672d 100644 --- a/tcmalloc/parameters.h +++ b/tcmalloc/parameters.h @@ -148,6 +148,14 @@ class Parameters { TCMalloc_Internal_SetMadviseColdRegionsNoHugepage(value); } + static int64_t event_trace_memory_limit() { + return event_trace_memory_limit_.load(std::memory_order_relaxed); + } + + static void set_event_trace_memory_limit(int64_t value) { + TCMalloc_Internal_SetEventTraceMemoryLimit(value); + } + static void set_per_cpu_caches(bool value) { #if !defined(TCMALLOC_DEPRECATED_PERTHREAD) if (!value) { @@ -241,6 +249,7 @@ class Parameters { friend void ::TCMalloc_Internal_SetEnableUnfilteredCollapse(bool v); friend void ::TCMalloc_Internal_SetHugeRegionAdaptiveReleaseEnabled(bool v); friend void ::TCMalloc_Internal_SetReleaseMaxColdPages(bool v); + friend void ::TCMalloc_Internal_SetEventTraceMemoryLimit(int64_t v); static std::atomic guarded_sampling_interval_; static std::atomic max_per_cpu_cache_size_; @@ -261,6 +270,7 @@ class Parameters { static std::atomic back_size_threshold_bytes_; static std::atomic enable_unfiltered_collapse_; static std::atomic release_max_cold_pages_; + static std::atomic event_trace_memory_limit_; }; } // namespace tcmalloc_internal diff --git a/tcmalloc/tcmalloc.cc b/tcmalloc/tcmalloc.cc index f392b9d6d..375e59cf2 100644 --- a/tcmalloc/tcmalloc.cc +++ b/tcmalloc/tcmalloc.cc @@ -293,8 +293,14 @@ MallocExtension_Internal_StartAllocationProfiling() { extern "C" tcmalloc_internal::AllocationProfilingTokenBase* MallocExtension_Internal_StartLifetimeProfiling() { + return new deallocationz::DeallocationSample(&tc_globals.deallocation_samples, + deallocationz::Mode::kLifetimes); +} + +extern "C" tcmalloc_internal::AllocationProfilingTokenBase* +MallocExtension_Internal_StartEventTracing() { return new deallocationz::DeallocationSample( - &tc_globals.deallocation_samples); + &tc_globals.deallocation_samples, deallocationz::Mode::kEventTrace); } MallocExtension::Ownership GetOwnership(const void* ptr) { diff --git a/tcmalloc/testing/BUILD b/tcmalloc/testing/BUILD index 3ac274849..78aea02c9 100644 --- a/tcmalloc/testing/BUILD +++ b/tcmalloc/testing/BUILD @@ -833,6 +833,7 @@ create_tcmalloc_testsuite( "//tcmalloc:malloc_extension", "//tcmalloc:profile_marshaler", "//tcmalloc/internal:linked_list", + "//tcmalloc/internal:parameter_accessors", "//tcmalloc/internal:profile_cc_proto", "@com_github_google_benchmark//:benchmark", "@com_google_absl//absl/base:core_headers", diff --git a/tcmalloc/testing/deallocation_profiler_test.cc b/tcmalloc/testing/deallocation_profiler_test.cc index ddd70ff6e..34e20176a 100644 --- a/tcmalloc/testing/deallocation_profiler_test.cc +++ b/tcmalloc/testing/deallocation_profiler_test.cc @@ -21,10 +21,12 @@ #include #include #include +#include #include // NOLINT(build/c++11) #include #include +#include "gmock/gmock.h" #include "gtest/gtest.h" #include "absl/base/attributes.h" #include "absl/debugging/symbolize.h" @@ -738,4 +740,210 @@ TEST(LifetimeProfiler, LifetimeBucketing) { EXPECT_EQ(absl::Nanoseconds(34000000), BucketizeDuration(34200040)); } +enum class EventType { kAlloc, kDealloc }; + +class ContainsEventMatcher { + public: + using is_gtest_matcher = void; + + ContainsEventMatcher(size_t size, EventType type) + : size_(size), type_(type) {} + + bool MatchAndExplain(const tcmalloc::Profile& profile, + testing::MatchResultListener* listener) const { + const int expected_count = (type_ == EventType::kAlloc) ? 1 : -1; + bool found = false; + profile.Iterate([&](const tcmalloc::Profile::Sample& s) { + if (s.requested_size == size_ && s.count == expected_count) { + if ((type_ == EventType::kAlloc && s.allocated_size > 0) || + (type_ == EventType::kDealloc && s.allocated_size == 0)) { + found = true; + } + } + }); + return found; + } + + void DescribeTo(std::ostream* os) const { + *os << "contains " + << (type_ == EventType::kAlloc ? "an allocation" : "a deallocation") + << " event for " << size_ << " bytes"; + } + + void DescribeNegationTo(std::ostream* os) const { + *os << "does not contain " + << (type_ == EventType::kAlloc ? "an allocation" : "a deallocation") + << " event for " << size_ << " bytes"; + } + + private: + size_t size_; + EventType type_; +}; + +inline auto ContainsAlloc(size_t size) { + return ContainsEventMatcher(size, EventType::kAlloc); +} + +inline auto ContainsDealloc(size_t size) { + return ContainsEventMatcher(size, EventType::kDealloc); +} + +inline auto ContainsAllocAndDealloc(size_t size) { + return testing::AllOf(ContainsAlloc(size), ContainsDealloc(size)); +} + +MATCHER_P(HasEventCount, count_matcher, "") { + int total = 0; + arg.Iterate([&](const tcmalloc::Profile::Sample& s) { ++total; }); + return testing::ExplainMatchResult(count_matcher, total, result_listener); +} + +TEST(EventTracingTest, BasicAllocationAndDeallocation) { + if (CheckerIsActive()) { + return; + } + + tcmalloc::ScopedProfileSamplingInterval test_sample_interval(1); + constexpr size_t kSize = 1024 * 1024; + + auto token = tcmalloc::MallocExtension::StartEventTracing(); + + void* ptr = SingleAlloc(2, kSize); + absl::SleepFor(absl::Milliseconds(10)); + SingleDealloc(2, ptr); + + const tcmalloc::Profile profile = std::move(token).Stop(); + EXPECT_THAT(profile.Type(), testing::Eq(tcmalloc::ProfileType::kEventTrace)); + EXPECT_THAT(profile, ContainsAllocAndDealloc(kSize)); +} + +TEST(EventTracingTest, CensoredEvents) { + if (CheckerIsActive()) { + return; + } + + tcmalloc::ScopedProfileSamplingInterval test_sample_interval(1); + constexpr size_t kSize1 = 2 * 1024 * 1024; + constexpr size_t kSize2 = 3 * 1024 * 1024; + + // Allocated before tracing begins (left-censored when freed during tracing) + void* ptr1 = SingleAlloc(2, kSize1); + + auto token = tcmalloc::MallocExtension::StartEventTracing(); + + // Allocated during tracing (right-censored when freed after tracing) + void* ptr2 = SingleAlloc(2, kSize2); + + // Deallocate ptr1 during tracing (should produce a free event) + SingleDealloc(2, ptr1); + + const tcmalloc::Profile profile = std::move(token).Stop(); + EXPECT_THAT(profile.Type(), testing::Eq(tcmalloc::ProfileType::kEventTrace)); + + // Deallocate ptr2 after tracing has stopped + SingleDealloc(2, ptr2); + + EXPECT_THAT(profile, ContainsAllocAndDealloc(kSize1)) + << "Inflight allocs are seeded when sampling starts."; + + EXPECT_THAT(profile, ContainsAlloc(kSize2)); + EXPECT_THAT(profile, testing::Not(ContainsDealloc(kSize2))) + << "Deallocations which happened after the trace ended are unknowable."; +} + +TEST(EventTracingTest, MultipleAllocations) { + if (CheckerIsActive()) { + return; + } + + tcmalloc::ScopedProfileSamplingInterval test_sample_interval(1); + + // Unusual sizes, should not correspond to other naturally-occurring allocs. + const std::vector kSizes = {1009, 2003, 4001, 8009}; + + auto token = tcmalloc::MallocExtension::StartEventTracing(); + + for (size_t size : kSizes) { + void* p = SingleAlloc(2, size); + SingleDealloc(2, p); + } + + const tcmalloc::Profile profile = std::move(token).Stop(); + EXPECT_THAT(profile.Type(), testing::Eq(tcmalloc::ProfileType::kEventTrace)); + EXPECT_THAT(profile.Duration(), testing::Gt(absl::ZeroDuration())); + EXPECT_THAT(profile.StartTime(), testing::Ne(std::nullopt)); + + for (size_t size : kSizes) { + EXPECT_THAT(profile, ContainsAllocAndDealloc(size)); + } +} + +TEST(EventTracingTest, ConcurrentEventTracing) { + if (CheckerIsActive()) { + return; + } + + tcmalloc::ScopedProfileSamplingInterval test_sample_interval(1); + constexpr int kThreads = 4; + constexpr int kAllocsPerThread = 50; + + auto token = tcmalloc::MallocExtension::StartEventTracing(); + + std::vector threads; + threads.reserve(kThreads); + for (int t = 0; t < kThreads; ++t) { + threads.emplace_back([t]() { + for (int i = 0; i < kAllocsPerThread; ++i) { + void* p = SingleAlloc(1, ((t * 100 + i) + 1) * 256); + SingleDealloc(1, p); + } + }); + } + + for (auto& t : threads) { + t.join(); + } + + const tcmalloc::Profile profile = std::move(token).Stop(); + EXPECT_THAT(profile.Type(), testing::Eq(tcmalloc::ProfileType::kEventTrace)); + EXPECT_THAT(profile, + HasEventCount(testing::Ge(kThreads * kAllocsPerThread * 2))); +} + +TEST(EventTracingTest, DefaultMemoryLimitTruncation) { + if (CheckerIsActive()) { + return; + } + + tcmalloc::ScopedProfileSamplingInterval test_sample_interval(1); + constexpr size_t kEarlySize = 1009; + constexpr size_t kFillerSize = 2003; + constexpr size_t kLateSize = 8009; + + auto token = tcmalloc::MallocExtension::StartEventTracing(); + + // Alloc-ed within the trace lifetime. + void* early_ptr = SingleAlloc(1, kEarlySize); + SingleDealloc(1, early_ptr); + + // An event is ~600B, so 50k allocs will produce 100k samples i.e. ~60 MiB, + // which is far above the default 16 MiB limit. + constexpr int kNumFillerAllocs = 50000; + for (int i = 0; i < kNumFillerAllocs; ++i) { + void* p = SingleAlloc(1, kFillerSize); + SingleDealloc(1, p); + } + + // Doesn't make it into the trace. + void* late_ptr = SingleAlloc(1, kLateSize); + SingleDealloc(1, late_ptr); + + const tcmalloc::Profile profile = std::move(token).Stop(); + EXPECT_THAT(profile.Type(), testing::Eq(tcmalloc::ProfileType::kEventTrace)); + + EXPECT_THAT(profile, ContainsAlloc(kEarlySize)); + EXPECT_THAT(profile, testing::Not(ContainsAlloc(kLateSize))); +} + } // namespace diff --git a/tcmalloc/testing/profile_test.cc b/tcmalloc/testing/profile_test.cc index 124a61b25..631eda9cc 100644 --- a/tcmalloc/testing/profile_test.cc +++ b/tcmalloc/testing/profile_test.cc @@ -44,6 +44,7 @@ #include "google/protobuf/io/gzip_stream.h" #include "google/protobuf/io/zero_copy_stream_impl_lite.h" #include "tcmalloc/internal/linked_list.h" +#include "tcmalloc/internal/parameter_accessors.h" #include "tcmalloc/malloc_extension.h" #include "tcmalloc/profile_marshaler.h" #include "tcmalloc/testing/testutil.h" @@ -511,5 +512,124 @@ TEST(ProfileTest, HeapProfile) { } } +class ScopedEventTraceMemoryLimit { + public: + explicit ScopedEventTraceMemoryLimit(int64_t limit) + : previous_(TCMalloc_Internal_GetEventTraceMemoryLimit()) { + TCMalloc_Internal_SetEventTraceMemoryLimit(limit); + } + + ~ScopedEventTraceMemoryLimit() { + TCMalloc_Internal_SetEventTraceMemoryLimit(previous_); + } + + private: + int64_t previous_; +}; + +TEST(ProfileTest, EventTraceTruncation) { +#if ABSL_HAVE_ADDRESS_SANITIZER || ABSL_HAVE_HWADDRESS_SANITIZER || \ + ABSL_HAVE_MEMORY_SANITIZER || ABSL_HAVE_THREAD_SANITIZER + GTEST_SKIP() << "Skipping event trace test under sanitizers."; +#endif + + // Sample every allocation to make the test deterministic. + ScopedProfileSamplingInterval sample_interval(1); + + // Set a small memory limit to force truncation. + // Note: A single matched allocation produces 2 records (alloc + dealloc), + // each ~600B, requiring at least ~1.3kB to *admit* the first pair. + constexpr int64_t kEventTraceMemoryLimit = 2048; + constexpr size_t kApproximateDeallocationSampleRecordSize = 600; + constexpr int kExpectedSampleCount = + kEventTraceMemoryLimit / kApproximateDeallocationSampleRecordSize; + ASSERT_GT(kExpectedSampleCount, 0) << "Event tracing requires more headroom."; + + ScopedEventTraceMemoryLimit limit(kEventTraceMemoryLimit); + + constexpr size_t kEarlySize = 1009; + constexpr size_t kFillerSize = 2003; + constexpr size_t kLateSize = 8009; + + const absl::Time test_start = absl::Now(); + auto token = MallocExtension::StartEventTracing(); + + // Sleep slightly to guarantee a non-zero, measurable duration. + absl::SleepFor(absl::Milliseconds(20)); + + // Early allocations (should be captured in the trace). + void* early_ptr = ::operator new(kEarlySize); + ::operator delete(early_ptr); + + // Trigger enough allocations to exceed the memory limit. + constexpr int kNumFillerAllocs = 50; + for (int i = 0; i < kNumFillerAllocs; ++i) { + void* p = ::operator new(kFillerSize); + ::operator delete(p); + } + + absl::SleepFor(absl::Milliseconds(20)); + + // Late allocations (should be truncated / dropped due to memory limit). + void* late_ptr = ::operator new(kLateSize); + ::operator delete(late_ptr); + + Profile profile = std::move(token).Stop(); + const absl::Time test_stop = absl::Now(); + + EXPECT_EQ(profile.Type(), ProfileType::kEventTrace); + EXPECT_GE(profile.Duration(), absl::Milliseconds(40)); + EXPECT_LE(profile.Duration(), test_stop - test_start + absl::Seconds(1)); + ASSERT_TRUE(profile.StartTime().has_value()); + EXPECT_GE(*profile.StartTime(), test_start); + EXPECT_LE(*profile.StartTime(), test_stop); + + absl::StatusOr encoded_or = Marshal(profile); + ASSERT_TRUE(encoded_or.ok()); + + // NOLINTNEXTLINE - clang-tidy can't associate ASSERT_TRUE as checked access. + const absl::string_view encoded = *encoded_or; + google::protobuf::io::ArrayInputStream stream(encoded.data(), encoded.size()); + google::protobuf::io::GzipInputStream gzip_stream(&stream); + google::protobuf::io::CodedInputStream coded(&gzip_stream); + + perftools::profiles::Profile converted; + ASSERT_TRUE(converted.ParseFromCodedStream(&coded)); + + EXPECT_EQ(converted.duration_nanos(), + absl::ToInt64Nanoseconds(profile.Duration())); + EXPECT_EQ(converted.time_nanos(), absl::ToUnixNanos(*profile.StartTime())); + + std::optional requested_size_id; + for (int i = 0, n = converted.string_table().size(); i < n; ++i) { + if (converted.string_table(i) == "requested_size") { + requested_size_id = i; + break; + } + } + EXPECT_TRUE(requested_size_id.has_value()); + + int sample_count = 0; + bool contains_early = false; + bool contains_late = false; + for (const auto& sample : converted.sample()) { + sample_count++; + for (const auto& label : sample.label()) { + if (label.key() == requested_size_id) { + if (label.num() == kEarlySize) { + contains_early = true; + } else if (label.num() == kLateSize) { + contains_late = true; + } + } + } + } + + EXPECT_LE(sample_count, kExpectedSampleCount) + << "Profile should be truncated."; + EXPECT_TRUE(contains_early); + EXPECT_FALSE(contains_late); +} + } // namespace } // namespace tcmalloc::tcmalloc_internal