From 5b2e2c9023b38b6e545c2e2933cf980252e39021 Mon Sep 17 00:00:00 2001 From: TCMalloc Team Date: Thu, 9 Jul 2026 11:37:57 -0700 Subject: [PATCH] Deallocation tracing. PiperOrigin-RevId: 945230975 --- tcmalloc/deallocation_profiler.cc | 146 +++++++++-- tcmalloc/deallocation_profiler.h | 10 +- tcmalloc/internal/parameter_accessors.h | 2 + tcmalloc/internal/profile_builder.cc | 56 +++- tcmalloc/internal/profile_builder_test.cc | 244 ++++++++++++++++++ tcmalloc/internal_malloc_extension.h | 2 + tcmalloc/malloc_extension.cc | 14 + tcmalloc/malloc_extension.h | 19 ++ tcmalloc/parameters.cc | 10 + tcmalloc/parameters.h | 10 + tcmalloc/tcmalloc.cc | 8 +- tcmalloc/testing/BUILD | 1 + .../testing/deallocation_profiler_test.cc | 208 +++++++++++++++ tcmalloc/testing/profile_test.cc | 120 +++++++++ 14 files changed, 812 insertions(+), 38 deletions(-) diff --git a/tcmalloc/deallocation_profiler.cc b/tcmalloc/deallocation_profiler.cc index c7ec67693..97e3210eb 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, @@ -628,8 +688,50 @@ void DeallocationProfiler::DeallocationStackTraceTable::AddTrace( v.counts[index]++; } +namespace { + +Profile::Sample ToSample(const tcmalloc_internal::StackTrace& stack_trace) { + Profile::Sample sample = {}; + sample.requested_size = stack_trace.requested_size; + sample.requested_alignment = stack_trace.requested_alignment; + sample.allocated_size = stack_trace.allocated_size; + sample.requested_size_returning = stack_trace.requested_size_returning; + sample.access_hint = static_cast(stack_trace.access_hint); + sample.access_allocated = stack_trace.cold_allocated + ? Profile::Sample::Access::Cold + : Profile::Sample::Access::Hot; + sample.token_id = stack_trace.token_id; + sample.guarded_status = stack_trace.guarded_status; + sample.type = stack_trace.allocation_type; + return sample; +} + +} // namespace + void DeallocationProfiler::DeallocationStackTraceTable::Iterate( absl::FunctionRef func) const { + if (mode_ == Mode::kEventTrace) { + for (const auto& r : events_) { + tcmalloc::Profile::Sample s = ToSample(r.stack_trace); + // 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.sum = r.stack_trace.allocated_size; + s.allocation_time = r.stack_trace.allocation_time; + s.alloc_handle = r.stack_trace.sampled_alloc_handle; + 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_) { @@ -665,22 +767,9 @@ void DeallocationProfiler::DeallocationStackTraceTable::Iterate( static_cast((v.counts[index])))); const auto bucketize = internal::LifetimeNsToBucketedDuration; - Profile::Sample sample; + Profile::Sample sample = ToSample(k.alloc.stack_trace); sample.sum = sum; - sample.requested_size = k.alloc.stack_trace.requested_size; - sample.requested_alignment = k.alloc.stack_trace.requested_alignment; - sample.allocated_size = allocated_size; sample.profile_id = pair_id++; - sample.requested_size_returning = - k.alloc.stack_trace.requested_size_returning; - sample.access_hint = - static_cast(k.alloc.stack_trace.access_hint); - sample.access_allocated = k.alloc.stack_trace.cold_allocated - ? Profile::Sample::Access::Cold - : Profile::Sample::Access::Hot; - sample.token_id = k.alloc.stack_trace.token_id; - sample.guarded_status = k.alloc.stack_trace.guarded_status; - sample.type = k.alloc.stack_trace.allocation_type; // Set the is_censored flag so that when we create a proto // sample later we can treat the *_lifetime accordingly. sample.is_censored = (k.dealloc.stack_trace.depth == 0); @@ -731,8 +820,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..f9ab116b7 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,21 @@ 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)); + 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 +856,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/profile_builder_test.cc b/tcmalloc/internal/profile_builder_test.cc index df6981103..699578909 100644 --- a/tcmalloc/internal/profile_builder_test.cc +++ b/tcmalloc/internal/profile_builder_test.cc @@ -1007,6 +1007,233 @@ TEST(ProfileBuilderTest, LifetimeProfile) { EXPECT_EQ(converted.period(), 0); } +perftools::profiles::Profile MakeTestEventTraceProfile( + absl::Time start_time, absl::Duration duration) { + auto fake_profile = std::make_unique(); + fake_profile->SetType(ProfileType::kEventTrace); + fake_profile->SetDuration(duration); + fake_profile->SetStartTime(start_time); + + std::vector samples; + { + // The allocation sample. + Profile::Sample alloc{ + .sum = 123, + .count = 2, + // Common information we retain in the event trace profile. + .requested_size = 2, + .requested_alignment = std::align_val_t{4}, + .allocated_size = 16, + .alloc_handle = MallocHook::AllocHandle{0xbeef}, + .requested_size_returning = true, + // Lifetime specific information in each sample. + .profile_id = 33, + .allocation_time = start_time + absl::Milliseconds(10), + .avg_lifetime = absl::Nanoseconds(77), + .stddev_lifetime = absl::Nanoseconds(22), + .min_lifetime = absl::Nanoseconds(55), + .max_lifetime = absl::Nanoseconds(99), + .allocator_deallocator_physical_cpu_matched = true, + .allocator_deallocator_virtual_cpu_matched = true, + .allocator_deallocator_l3_matched = true, + .allocator_deallocator_numa_matched = true, + .allocator_deallocator_thread_matched = false, + }; + // This stack is mostly artificial, but we include a couple of real symbols + // from the binary to confirm that the locations are indexed into the + // mappings. + alloc.depth = 6; + alloc.stack[0] = absl::bit_cast(uintptr_t{0x12345}); + alloc.stack[1] = absl::bit_cast(uintptr_t{0x23451}); + alloc.stack[2] = absl::bit_cast(uintptr_t{0x34512}); + alloc.stack[3] = absl::bit_cast(uintptr_t{0x45123}); + alloc.stack[4] = reinterpret_cast(&ProfileAccessor::MakeProfile); + alloc.stack[5] = reinterpret_cast(&RealPath); + + samples.push_back(alloc); + + // The deallocation sample contains the same information with a negative + // count to denote deallocation. + Profile::Sample dealloc = alloc; + dealloc.count = -dealloc.count; + dealloc.allocation_time = start_time + absl::Milliseconds(20); + samples.push_back(dealloc); + + // Right-censored sample (allocation with unobserved deallocation). + Profile::Sample right_censored_alloc = alloc; + right_censored_alloc.alloc_handle = MallocHook::AllocHandle{0xcafe}; + right_censored_alloc.profile_id = 34; + right_censored_alloc.allocation_time = start_time + absl::Milliseconds(15); + right_censored_alloc.allocator_deallocator_physical_cpu_matched = + std::nullopt; + right_censored_alloc.allocator_deallocator_virtual_cpu_matched = + std::nullopt; + right_censored_alloc.allocator_deallocator_l3_matched = std::nullopt; + right_censored_alloc.allocator_deallocator_numa_matched = std::nullopt; + right_censored_alloc.allocator_deallocator_thread_matched = std::nullopt; + samples.push_back(right_censored_alloc); + + // Left-censored sample (deallocation with unobserved allocation). + Profile::Sample left_censored_dealloc = dealloc; + left_censored_dealloc.alloc_handle = MallocHook::AllocHandle{0xdead}; + left_censored_dealloc.profile_id = 35; + left_censored_dealloc.allocation_time = start_time + absl::Milliseconds(25); + left_censored_dealloc.allocator_deallocator_physical_cpu_matched = + std::nullopt; + left_censored_dealloc.allocator_deallocator_virtual_cpu_matched = + std::nullopt; + left_censored_dealloc.allocator_deallocator_l3_matched = std::nullopt; + left_censored_dealloc.allocator_deallocator_numa_matched = std::nullopt; + left_censored_dealloc.allocator_deallocator_thread_matched = std::nullopt; + samples.push_back(left_censored_dealloc); + } + + fake_profile->SetSamples(std::move(samples)); + Profile profile = ProfileAccessor::MakeProfile(std::move(fake_profile)); + auto converted_or = MakeProfileProto(profile); + CHECK_OK(converted_or.status()); + return **converted_or; +} + +TEST(ProfileBuilderTest, EventTraceProfile) { + const absl::Time start_time = absl::Now(); + constexpr absl::Duration kDuration = absl::Milliseconds(1500); + const auto converted = MakeTestEventTraceProfile(start_time, kDuration); + const auto& string_table = converted.string_table(); + + // Checks for event trace (and lifetime) profile specific fields. + ASSERT_EQ(converted.sample_type_size(), 6); + EXPECT_EQ(string_table.at(converted.sample_type(0).type()), + "allocated_objects"); + EXPECT_EQ(string_table.at(converted.sample_type(1).type()), + "allocated_space"); + EXPECT_EQ(string_table.at(converted.sample_type(2).type()), + "deallocated_objects"); + EXPECT_EQ(string_table.at(converted.sample_type(3).type()), + "deallocated_space"); + EXPECT_EQ(string_table.at(converted.sample_type(4).type()), + "censored_allocated_objects"); + EXPECT_EQ(string_table.at(converted.sample_type(5).type()), + "censored_allocated_space"); + + ASSERT_EQ(converted.sample_size(), 4); + // For the alloc sample, the values are in indices 0, 1. + EXPECT_EQ(converted.sample(0).value(0), 2); + EXPECT_EQ(converted.sample(0).value(1), 123); + EXPECT_EQ(converted.sample(0).value(2), 0); + EXPECT_EQ(converted.sample(0).value(3), 0); + EXPECT_EQ(converted.sample(0).value(4), 0); + EXPECT_EQ(converted.sample(0).value(5), 0); + // For the dealloc sample, the values are in indices 2, 3. + EXPECT_EQ(converted.sample(1).value(0), 0); + EXPECT_EQ(converted.sample(1).value(1), 0); + EXPECT_EQ(converted.sample(1).value(2), 2); + EXPECT_EQ(converted.sample(1).value(3), 123); + EXPECT_EQ(converted.sample(1).value(4), 0); + EXPECT_EQ(converted.sample(1).value(5), 0); + // For the right-censored alloc sample, the values are in indices 0, 1. + EXPECT_EQ(converted.sample(2).value(0), 2); + EXPECT_EQ(converted.sample(2).value(1), 123); + EXPECT_EQ(converted.sample(2).value(2), 0); + EXPECT_EQ(converted.sample(2).value(3), 0); + EXPECT_EQ(converted.sample(2).value(4), 0); + EXPECT_EQ(converted.sample(2).value(5), 0); + // For the left-censored dealloc sample, the values are in indices 2, 3. + EXPECT_EQ(converted.sample(3).value(0), 0); + EXPECT_EQ(converted.sample(3).value(1), 0); + EXPECT_EQ(converted.sample(3).value(2), 2); + EXPECT_EQ(converted.sample(3).value(3), 123); + EXPECT_EQ(converted.sample(3).value(4), 0); + EXPECT_EQ(converted.sample(3).value(5), 0); + + // Check the location and mapping fields and extract sample, label pairs. + SampleLabels extracted; + { + SCOPED_TRACE("EventTraceProfile"); + ASSERT_NO_FATAL_FAILURE(CheckAndExtractSampleLabels(converted, extracted)); + } + + EXPECT_THAT( + extracted, + UnorderedElementsAre( + UnorderedElementsAre( + Pair("bytes", 16), Pair("request", 2), Pair("alignment", 4), + Pair("callstack-pair-id", 33), Pair("avg_lifetime", 77), + Pair("stddev_lifetime", 22), Pair("min_lifetime", 55), + Pair("max_lifetime", 99), Pair("active CPU", "same"), + Pair("active vCPU", "same"), Pair("active L3", "same"), + Pair("active NUMA", "same"), Pair("active thread", "different"), + Pair("size_returning", 1), Pair("allocation type", "new"), + Pair("guarded_status", "NotAttempted"), Pair("token_id", 0), + Pair("access_hint", 0), Pair("access_allocated", "hot"), + Pair("alloc_handle", 0xbeef), + Pair("allocation_time", + static_cast( + absl::ToUnixNanos(start_time + absl::Milliseconds(10)))), + Pair("requested_size", 2)), + UnorderedElementsAre( + Pair("bytes", 16), Pair("request", 2), Pair("alignment", 4), + Pair("callstack-pair-id", 33), Pair("avg_lifetime", 77), + Pair("stddev_lifetime", 22), Pair("min_lifetime", 55), + Pair("max_lifetime", 99), Pair("active CPU", "same"), + Pair("active vCPU", "same"), Pair("active L3", "same"), + Pair("active NUMA", "same"), Pair("active thread", "different"), + Pair("size_returning", 1), Pair("allocation type", "new"), + Pair("guarded_status", "NotAttempted"), Pair("token_id", 0), + Pair("access_hint", 0), Pair("access_allocated", "hot"), + Pair("alloc_handle", 0xbeef), + Pair("deallocation_time", + static_cast(absl::ToUnixNanos( + start_time + absl::Milliseconds(20))))), + // Check the contents of the right-censored sample. + UnorderedElementsAre( + Pair("bytes", 16), Pair("request", 2), Pair("alignment", 4), + Pair("callstack-pair-id", 34), Pair("avg_lifetime", 77), + Pair("stddev_lifetime", 22), Pair("min_lifetime", 55), + Pair("max_lifetime", 99), Pair("active CPU", "none"), + Pair("active vCPU", "none"), Pair("active L3", "none"), + Pair("active NUMA", "none"), Pair("active thread", "none"), + Pair("size_returning", 1), Pair("allocation type", "new"), + Pair("guarded_status", "NotAttempted"), Pair("token_id", 0), + Pair("access_hint", 0), Pair("access_allocated", "hot"), + Pair("alloc_handle", 0xcafe), + Pair("allocation_time", + static_cast( + absl::ToUnixNanos(start_time + absl::Milliseconds(15)))), + Pair("requested_size", 2)), + // Check the contents of the left-censored sample. + UnorderedElementsAre( + Pair("bytes", 16), Pair("request", 2), Pair("alignment", 4), + Pair("callstack-pair-id", 35), Pair("avg_lifetime", 77), + Pair("stddev_lifetime", 22), Pair("min_lifetime", 55), + Pair("max_lifetime", 99), Pair("active CPU", "none"), + Pair("active vCPU", "none"), Pair("active L3", "none"), + Pair("active NUMA", "none"), Pair("active thread", "none"), + Pair("size_returning", 1), Pair("allocation type", "new"), + Pair("guarded_status", "NotAttempted"), Pair("token_id", 0), + Pair("access_hint", 0), Pair("access_allocated", "hot"), + Pair("alloc_handle", 0xdead), + Pair("deallocation_time", + static_cast(absl::ToUnixNanos( + start_time + absl::Milliseconds(25))))))); + + // Checks for common fields. + EXPECT_TRUE(RE2::FullMatch("TCMallocInternalNew", + converted.string_table(converted.drop_frames()))); + // No keep frames. + EXPECT_EQ(converted.string_table(converted.keep_frames()), ""); + + EXPECT_EQ(converted.duration_nanos(), absl::ToInt64Nanoseconds(kDuration)); + EXPECT_EQ(converted.time_nanos(), absl::ToUnixNanos(start_time)); + + // Period type [space, bytes] + EXPECT_EQ(converted.string_table(converted.period_type().type()), "space"); + EXPECT_EQ(converted.string_table(converted.period_type().unit()), "bytes"); + + // Period not set + EXPECT_EQ(converted.period(), 0); +} + TEST(ProfileBuilderTest, SameTags) { const absl::Time start_time = absl::Now(); constexpr absl::Duration kDuration = absl::Milliseconds(1500); @@ -1018,6 +1245,7 @@ TEST(ProfileBuilderTest, SameTags) { const auto allocation = MakeTestProfile(start_time, kDuration, ProfileType::kAllocations); const auto lifetime = MakeTestLifetimeProfile(start_time, kDuration); + const auto event_trace = MakeTestEventTraceProfile(start_time, kDuration); auto ExtractTags = [&](const perftools::profiles::Profile& proto) { absl::flat_hash_set tags; @@ -1047,6 +1275,22 @@ TEST(ProfileBuilderTest, SameTags) { auto lifetime_tags = ExtractTags(lifetime); EXPECT_THAT(lifetime_tags, testing::IsSupersetOf(lifetime_only_tags)); + + const absl::flat_hash_set event_trace_only_tags = { + "alloc_handle", + "allocation_time", + "deallocation_time", + "requested_size", + }; + + auto event_trace_tags = ExtractTags(event_trace); + EXPECT_THAT(event_trace_tags, testing::IsSupersetOf(event_trace_only_tags)); + for (const auto tag : event_trace_only_tags) { + event_trace_tags.erase(tag); + } + + EXPECT_THAT(lifetime_tags, testing::ContainerEq(event_trace_tags)); + for (const auto tag : lifetime_only_tags) { lifetime_tags.erase(tag); } 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