Snap for 12359238 from 9f1867626b496717afba585a4525dd68b3b9aceb to android15-tests-release Change-Id: I38d1b4d79858f3b4ac2afaefb06208d398fcaa37
diff --git a/standalone/allocator_config.def b/standalone/allocator_config.def index dcd130a..ce37b1c 100644 --- a/standalone/allocator_config.def +++ b/standalone/allocator_config.def
@@ -56,16 +56,8 @@ // SizeClassMap to use with the Primary. PRIMARY_REQUIRED_TYPE(SizeClassMap) -// Defines the type and scale of a compact pointer. A compact pointer can -// be understood as the offset of a pointer within the region it belongs -// to, in increments of a power-of-2 scale. See `CompactPtrScale` also. -PRIMARY_REQUIRED_TYPE(CompactPtrT) - // PRIMARY_REQUIRED(TYPE, NAME) // -// The scale of a compact pointer. E.g., Ptr = Base + (CompactPtr << Scale). -PRIMARY_REQUIRED(const uptr, CompactPtrScale) - // Log2 of the size of a size class region, as used by the Primary. PRIMARY_REQUIRED(const uptr, RegionSizeLog) @@ -86,6 +78,9 @@ // PRIMARY_OPTIONAL(TYPE, NAME, DEFAULT) // +// The scale of a compact pointer. E.g., Ptr = Base + (CompactPtr << Scale). +PRIMARY_OPTIONAL(const uptr, CompactPtrScale, SCUDO_MIN_ALIGNMENT_LOG) + // Indicates support for offsetting the start of a region by a random number of // pages. This is only used if `EnableContiguousRegions` is enabled. PRIMARY_OPTIONAL(const bool, EnableRandomOffset, false) @@ -104,6 +99,11 @@ // guarantee a performance benefit. PRIMARY_OPTIONAL_TYPE(ConditionVariableT, ConditionVariableDummy) +// Defines the type and scale of a compact pointer. A compact pointer can +// be understood as the offset of a pointer within the region it belongs +// to, in increments of a power-of-2 scale. See `CompactPtrScale` also. +PRIMARY_OPTIONAL_TYPE(CompactPtrT, uptr) + // SECONDARY_REQUIRED_TEMPLATE_TYPE(NAME) // // Defines the type of Secondary Cache to use.
diff --git a/standalone/combined.h b/standalone/combined.h index f9ed365..fcf6565 100644 --- a/standalone/combined.h +++ b/standalone/combined.h
@@ -549,6 +549,19 @@ // header to reflect the size change. if (reinterpret_cast<uptr>(OldTaggedPtr) + NewSize <= BlockEnd) { if (NewSize > OldSize || (OldSize - NewSize) < getPageSizeCached()) { + // If we have reduced the size, set the extra bytes to the fill value + // so that we are ready to grow it again in the future. + if (NewSize < OldSize) { + const FillContentsMode FillContents = + TSDRegistry.getDisableMemInit() ? NoFill + : Options.getFillContentsMode(); + if (FillContents != NoFill) { + memset(reinterpret_cast<char *>(OldTaggedPtr) + NewSize, + FillContents == ZeroFill ? 0 : PatternFillByte, + OldSize - NewSize); + } + } + Header.SizeOrUnusedBytes = (ClassId ? NewSize : BlockEnd -
diff --git a/standalone/mem_map_fuchsia.cpp b/standalone/mem_map_fuchsia.cpp index fc793ab..9d6df2b 100644 --- a/standalone/mem_map_fuchsia.cpp +++ b/standalone/mem_map_fuchsia.cpp
@@ -91,12 +91,15 @@ return Status == ZX_ERR_NO_MEMORY || Status == ZX_ERR_NO_RESOURCES; } +// Note: this constructor is only called by ReservedMemoryFuchsia::dispatch. MemMapFuchsia::MemMapFuchsia(uptr Base, uptr Capacity) : MapAddr(Base), WindowBase(Base), WindowSize(Capacity) { // Create the VMO. zx_status_t Status = _zx_vmo_create(Capacity, 0, &Vmo); if (UNLIKELY(Status != ZX_OK)) dieOnError(Status, "zx_vmo_create", Capacity); + + setVmoName(Vmo, "scudo:dispatched"); } bool MemMapFuchsia::mapImpl(UNUSED uptr Addr, uptr Size, const char *Name,
diff --git a/standalone/secondary.h b/standalone/secondary.h index d8c9f5b..9a8e53b 100644 --- a/standalone/secondary.h +++ b/standalone/secondary.h
@@ -391,10 +391,11 @@ return true; } if (O == Option::MaxCacheEntriesCount) { - const u32 MaxCount = static_cast<u32>(Value); - if (MaxCount > Config::getEntriesArraySize()) + if (Value < 0) return false; - atomic_store_relaxed(&MaxEntriesCount, MaxCount); + atomic_store_relaxed( + &MaxEntriesCount, + Min<u32>(static_cast<u32>(Value), Config::getEntriesArraySize())); return true; } if (O == Option::MaxCacheEntrySize) {
diff --git a/standalone/tests/combined_test.cpp b/standalone/tests/combined_test.cpp index 1a36155..16b19e8 100644 --- a/standalone/tests/combined_test.cpp +++ b/standalone/tests/combined_test.cpp
@@ -447,19 +447,32 @@ // returns the same chunk. This requires that all the sizes we iterate on use // the same block size, but that should be the case for MaxSize - 64 with our // default class size maps. - constexpr scudo::uptr ReallocSize = + constexpr scudo::uptr InitialSize = TypeParam::Primary::SizeClassMap::MaxSize - 64; - void *P = Allocator->allocate(ReallocSize, Origin); const char Marker = 'A'; - memset(P, Marker, ReallocSize); + Allocator->setFillContents(scudo::PatternOrZeroFill); + + void *P = Allocator->allocate(InitialSize, Origin); + scudo::uptr CurrentSize = InitialSize; for (scudo::sptr Delta = -32; Delta < 32; Delta += 8) { + memset(P, Marker, CurrentSize); const scudo::uptr NewSize = - static_cast<scudo::uptr>(static_cast<scudo::sptr>(ReallocSize) + Delta); + static_cast<scudo::uptr>(static_cast<scudo::sptr>(InitialSize) + Delta); void *NewP = Allocator->reallocate(P, NewSize); EXPECT_EQ(NewP, P); - for (scudo::uptr I = 0; I < ReallocSize - 32; I++) + + // Verify that existing contents have been preserved. + for (scudo::uptr I = 0; I < scudo::Min(CurrentSize, NewSize); I++) EXPECT_EQ((reinterpret_cast<char *>(NewP))[I], Marker); + + // Verify that new bytes are set according to FillContentsMode. + for (scudo::uptr I = CurrentSize; I < NewSize; I++) { + unsigned char V = (reinterpret_cast<unsigned char *>(NewP))[I]; + EXPECT_TRUE(V == scudo::PatternFillByte || V == 0); + } + checkMemoryTaggingMaybe(Allocator, NewP, NewSize, 0); + CurrentSize = NewSize; } Allocator->deallocate(P, Origin); }
diff --git a/standalone/tests/memtag_test.cpp b/standalone/tests/memtag_test.cpp index 37a1885..0613847 100644 --- a/standalone/tests/memtag_test.cpp +++ b/standalone/tests/memtag_test.cpp
@@ -19,10 +19,10 @@ TEST(MemtagBasicDeathTest, Unsupported) { if (archSupportsMemoryTagging()) - GTEST_SKIP(); + TEST_SKIP("Memory tagging is not supported"); // Skip when running with HWASan. if (&__hwasan_init != 0) - GTEST_SKIP(); + TEST_SKIP("Incompatible with HWASan"); EXPECT_DEATH(archMemoryTagGranuleSize(), "not supported"); EXPECT_DEATH(untagPointer((uptr)0), "not supported"); @@ -48,7 +48,7 @@ protected: void SetUp() override { if (!archSupportsMemoryTagging() || !systemDetectsMemoryTagFaultsTestOnly()) - GTEST_SKIP() << "Memory tagging is not supported"; + TEST_SKIP("Memory tagging is not supported"); BufferSize = getPageSizeCached(); ASSERT_FALSE(MemMap.isAllocated());
diff --git a/standalone/tests/scudo_unit_test.h b/standalone/tests/scudo_unit_test.h index 4283416..f8b658c 100644 --- a/standalone/tests/scudo_unit_test.h +++ b/standalone/tests/scudo_unit_test.h
@@ -11,9 +11,14 @@ #if SCUDO_FUCHSIA #include <zxtest/zxtest.h> using Test = ::zxtest::Test; +#define TEST_SKIP(message) ZXTEST_SKIP(message) #else #include "gtest/gtest.h" using Test = ::testing::Test; +#define TEST_SKIP(message) \ + do { \ + GTEST_SKIP() << message; \ + } while (0) #endif // If EXPECT_DEATH isn't defined, make it a no-op.
diff --git a/standalone/tests/secondary_test.cpp b/standalone/tests/secondary_test.cpp index 8f0250e..5685a93 100644 --- a/standalone/tests/secondary_test.cpp +++ b/standalone/tests/secondary_test.cpp
@@ -190,29 +190,31 @@ Str.output(); } -TEST_F(MapAllocatorTest, SecondaryOptions) { +TEST_F(MapAllocatorTest, SecondaryCacheOptions) { + if (!Allocator->canCache(0U)) + TEST_SKIP("Secondary Cache disabled"); + // Attempt to set a maximum number of entries higher than the array size. - EXPECT_FALSE( - Allocator->setOption(scudo::Option::MaxCacheEntriesCount, 4096U)); - // A negative number will be cast to a scudo::u32, and fail. + EXPECT_TRUE(Allocator->setOption(scudo::Option::MaxCacheEntriesCount, 4096U)); + + // Attempt to set an invalid (negative) number of entries EXPECT_FALSE(Allocator->setOption(scudo::Option::MaxCacheEntriesCount, -1)); - if (Allocator->canCache(0U)) { - // Various valid combinations. - EXPECT_TRUE(Allocator->setOption(scudo::Option::MaxCacheEntriesCount, 4U)); - EXPECT_TRUE( - Allocator->setOption(scudo::Option::MaxCacheEntrySize, 1UL << 20)); - EXPECT_TRUE(Allocator->canCache(1UL << 18)); - EXPECT_TRUE( - Allocator->setOption(scudo::Option::MaxCacheEntrySize, 1UL << 17)); - EXPECT_FALSE(Allocator->canCache(1UL << 18)); - EXPECT_TRUE(Allocator->canCache(1UL << 16)); - EXPECT_TRUE(Allocator->setOption(scudo::Option::MaxCacheEntriesCount, 0U)); - EXPECT_FALSE(Allocator->canCache(1UL << 16)); - EXPECT_TRUE(Allocator->setOption(scudo::Option::MaxCacheEntriesCount, 4U)); - EXPECT_TRUE( - Allocator->setOption(scudo::Option::MaxCacheEntrySize, 1UL << 20)); - EXPECT_TRUE(Allocator->canCache(1UL << 16)); - } + + // Various valid combinations. + EXPECT_TRUE(Allocator->setOption(scudo::Option::MaxCacheEntriesCount, 4U)); + EXPECT_TRUE( + Allocator->setOption(scudo::Option::MaxCacheEntrySize, 1UL << 20)); + EXPECT_TRUE(Allocator->canCache(1UL << 18)); + EXPECT_TRUE( + Allocator->setOption(scudo::Option::MaxCacheEntrySize, 1UL << 17)); + EXPECT_FALSE(Allocator->canCache(1UL << 18)); + EXPECT_TRUE(Allocator->canCache(1UL << 16)); + EXPECT_TRUE(Allocator->setOption(scudo::Option::MaxCacheEntriesCount, 0U)); + EXPECT_FALSE(Allocator->canCache(1UL << 16)); + EXPECT_TRUE(Allocator->setOption(scudo::Option::MaxCacheEntriesCount, 4U)); + EXPECT_TRUE( + Allocator->setOption(scudo::Option::MaxCacheEntrySize, 1UL << 20)); + EXPECT_TRUE(Allocator->canCache(1UL << 16)); } struct MapAllocatorWithReleaseTest : public MapAllocatorTest {
diff --git a/standalone/tests/strings_test.cpp b/standalone/tests/strings_test.cpp index abb8180..2c0916d 100644 --- a/standalone/tests/strings_test.cpp +++ b/standalone/tests/strings_test.cpp
@@ -147,7 +147,7 @@ MAP_ALLOWNOMEM)) { MemMap.unmap(MemMap.getBase(), MemMap.getCapacity()); setrlimit(RLIMIT_AS, &Limit); - GTEST_SKIP() << "Limiting address space does not prevent mmap."; + TEST_SKIP("Limiting address space does not prevent mmap."); } // Test requires that the default length is at least 6 characters.
diff --git a/standalone/tests/timing_test.cpp b/standalone/tests/timing_test.cpp index 09a6c31..23f0a02 100644 --- a/standalone/tests/timing_test.cpp +++ b/standalone/tests/timing_test.cpp
@@ -10,6 +10,7 @@ #include "timing.h" +#include <cstdlib> #include <string> class ScudoTimingTest : public Test { @@ -33,41 +34,36 @@ void printAllTimersStats() { Manager.printAll(); } + void getAllTimersStats(scudo::ScopedString &Str) { Manager.getAll(Str); } + scudo::TimingManager &getTimingManager() { return Manager; } + void testCallTimers() { + scudo::ScopedTimer Outer(getTimingManager(), "Level1"); + { + scudo::ScopedTimer Inner1(getTimingManager(), Outer, "Level2"); + { scudo::ScopedTimer Inner2(getTimingManager(), Inner1, "Level3"); } + } + } + private: scudo::TimingManager Manager; }; -// Given that the output of statistics of timers are dumped through -// `scudo::Printf` which is platform dependent, so we don't have a reliable way -// to catch the output and verify the details. Now we only verify the number of -// invocations on linux. TEST_F(ScudoTimingTest, SimpleTimer) { -#if SCUDO_LINUX - testing::internal::LogToStderr(); - testing::internal::CaptureStderr(); -#endif - testIgnoredTimer(); testChainedCalls(); - printAllTimersStats(); + scudo::ScopedString Str; + getAllTimersStats(Str); -#if SCUDO_LINUX - std::string output = testing::internal::GetCapturedStderr(); - EXPECT_TRUE(output.find("testIgnoredTimer (1)") == std::string::npos); - EXPECT_TRUE(output.find("testChainedCalls (1)") != std::string::npos); - EXPECT_TRUE(output.find("testFunc2 (1)") != std::string::npos); - EXPECT_TRUE(output.find("testFunc1 (1)") != std::string::npos); -#endif + std::string Output(Str.data()); + EXPECT_TRUE(Output.find("testIgnoredTimer (1)") == std::string::npos); + EXPECT_TRUE(Output.find("testChainedCalls (1)") != std::string::npos); + EXPECT_TRUE(Output.find("testFunc2 (1)") != std::string::npos); + EXPECT_TRUE(Output.find("testFunc1 (1)") != std::string::npos); } TEST_F(ScudoTimingTest, NestedTimer) { -#if SCUDO_LINUX - testing::internal::LogToStderr(); - testing::internal::CaptureStderr(); -#endif - { scudo::ScopedTimer Outer(getTimingManager(), "Outer"); { @@ -75,12 +71,191 @@ { scudo::ScopedTimer Inner2(getTimingManager(), Inner1, "Inner2"); } } } - printAllTimersStats(); + scudo::ScopedString Str; + getAllTimersStats(Str); + + std::string Output(Str.data()); + EXPECT_TRUE(Output.find("Outer (1)") != std::string::npos); + EXPECT_TRUE(Output.find("Inner1 (1)") != std::string::npos); + EXPECT_TRUE(Output.find("Inner2 (1)") != std::string::npos); +} + +TEST_F(ScudoTimingTest, VerifyChainedTimerCalculations) { + { + scudo::ScopedTimer Outer(getTimingManager(), "Level1"); + sleep(1); + { + scudo::ScopedTimer Inner1(getTimingManager(), Outer, "Level2"); + sleep(2); + { + scudo::ScopedTimer Inner2(getTimingManager(), Inner1, "Level3"); + sleep(3); + } + } + } + scudo::ScopedString Str; + getAllTimersStats(Str); + std::string Output(Str.data()); + + // Get the individual timer values for the average and maximum, then + // verify that the timer values are being calculated properly. + Output = Output.substr(Output.find('\n') + 1); + char *end; + unsigned long long Level1AvgNs = std::strtoull(Output.c_str(), &end, 10); + ASSERT_TRUE(end != nullptr); + unsigned long long Level1MaxNs = std::strtoull(&end[6], &end, 10); + ASSERT_TRUE(end != nullptr); + EXPECT_EQ(Level1AvgNs, Level1MaxNs); + + Output = Output.substr(Output.find('\n') + 1); + unsigned long long Level2AvgNs = std::strtoull(Output.c_str(), &end, 10); + ASSERT_TRUE(end != nullptr); + unsigned long long Level2MaxNs = std::strtoull(&end[6], &end, 10); + ASSERT_TRUE(end != nullptr); + EXPECT_EQ(Level2AvgNs, Level2MaxNs); + + Output = Output.substr(Output.find('\n') + 1); + unsigned long long Level3AvgNs = std::strtoull(Output.c_str(), &end, 10); + ASSERT_TRUE(end != nullptr); + unsigned long long Level3MaxNs = std::strtoull(&end[6], &end, 10); + ASSERT_TRUE(end != nullptr); + EXPECT_EQ(Level3AvgNs, Level3MaxNs); + + EXPECT_GT(Level1AvgNs, Level2AvgNs); + EXPECT_GT(Level2AvgNs, Level3AvgNs); + + // The time for the first timer needs to be at least six seconds. + EXPECT_GT(Level1AvgNs, 6000000000U); + // The time for the second timer needs to be at least five seconds. + EXPECT_GT(Level2AvgNs, 5000000000U); + // The time for the third timer needs to be at least three seconds. + EXPECT_GT(Level3AvgNs, 3000000000U); + // The time between the first and second timer needs to be at least one + // second. + EXPECT_GT(Level1AvgNs - Level2AvgNs, 1000000000U); + // The time between the second and third timer needs to be at least two + // second. + EXPECT_GT(Level2AvgNs - Level3AvgNs, 2000000000U); +} + +TEST_F(ScudoTimingTest, VerifyMax) { + for (size_t i = 0; i < 3; i++) { + scudo::ScopedTimer Outer(getTimingManager(), "Level1"); + sleep(1); + } + scudo::ScopedString Str; + getAllTimersStats(Str); + std::string Output(Str.data()); + + Output = Output.substr(Output.find('\n') + 1); + char *end; + unsigned long long AvgNs = std::strtoull(Output.c_str(), &end, 10); + ASSERT_TRUE(end != nullptr); + unsigned long long MaxNs = std::strtoull(&end[6], &end, 10); + ASSERT_TRUE(end != nullptr); + + EXPECT_GT(MaxNs, AvgNs); +} + +TEST_F(ScudoTimingTest, VerifyMultipleTimerCalls) { + for (size_t i = 0; i < 5; i++) + testCallTimers(); + + scudo::ScopedString Str; + getAllTimersStats(Str); + std::string Output(Str.data()); + EXPECT_TRUE(Output.find("Level1 (5)") != std::string::npos); + EXPECT_TRUE(Output.find("Level2 (5)") != std::string::npos); + EXPECT_TRUE(Output.find("Level3 (5)") != std::string::npos); +} + +TEST_F(ScudoTimingTest, VerifyHeader) { + { scudo::ScopedTimer Outer(getTimingManager(), "Timer"); } + scudo::ScopedString Str; + getAllTimersStats(Str); + + std::string Output(Str.data()); + std::string Header(Output.substr(0, Output.find('\n'))); + EXPECT_EQ(Header, "-- Average Operation Time -- -- Maximum Operation Time -- " + "-- Name (# of Calls) --"); +} + +TEST_F(ScudoTimingTest, VerifyTimerFormat) { + testCallTimers(); + scudo::ScopedString Str; + getAllTimersStats(Str); + std::string Output(Str.data()); + + // Check the top level line, should look similar to: + // 11718.0(ns) 11718(ns) Level1 (1) + Output = Output.substr(Output.find('\n') + 1); + + // Verify that the Average Operation Time is in the correct location. + EXPECT_EQ(".0(ns) ", Output.substr(14, 7)); + + // Verify that the Maximum Operation Time is in the correct location. + EXPECT_EQ("(ns) ", Output.substr(45, 5)); + + // Verify that the first timer name is in the correct location. + EXPECT_EQ("Level1 (1)\n", Output.substr(61, 11)); + + // Check a chained timer, should look similar to: + // 5331.0(ns) 5331(ns) Level2 (1) + Output = Output.substr(Output.find('\n') + 1); + + // Verify that the Average Operation Time is in the correct location. + EXPECT_EQ(".0(ns) ", Output.substr(14, 7)); + + // Verify that the Maximum Operation Time is in the correct location. + EXPECT_EQ("(ns) ", Output.substr(45, 5)); + + // Verify that the first timer name is in the correct location. + EXPECT_EQ(" Level2 (1)\n", Output.substr(61, 13)); + + // Check a secondary chained timer, should look similar to: + // 814.0(ns) 814(ns) Level3 (1) + Output = Output.substr(Output.find('\n') + 1); + + // Verify that the Average Operation Time is in the correct location. + EXPECT_EQ(".0(ns) ", Output.substr(14, 7)); + + // Verify that the Maximum Operation Time is in the correct location. + EXPECT_EQ("(ns) ", Output.substr(45, 5)); + + // Verify that the first timer name is in the correct location. + EXPECT_EQ(" Level3 (1)\n", Output.substr(61, 15)); +} #if SCUDO_LINUX - std::string output = testing::internal::GetCapturedStderr(); - EXPECT_TRUE(output.find("Outer (1)") != std::string::npos); - EXPECT_TRUE(output.find("Inner1 (1)") != std::string::npos); - EXPECT_TRUE(output.find("Inner2 (1)") != std::string::npos); -#endif +TEST_F(ScudoTimingTest, VerifyPrintMatchesGet) { + testing::internal::LogToStderr(); + testing::internal::CaptureStderr(); + testCallTimers(); + + { scudo::ScopedTimer Outer(getTimingManager(), "Timer"); } + printAllTimersStats(); + std::string PrintOutput = testing::internal::GetCapturedStderr(); + EXPECT_TRUE(PrintOutput.size() != 0); + + scudo::ScopedString Str; + getAllTimersStats(Str); + std::string GetOutput(Str.data()); + EXPECT_TRUE(GetOutput.size() != 0); + + EXPECT_EQ(PrintOutput, GetOutput); } +#endif + +#if SCUDO_LINUX +TEST_F(ScudoTimingTest, VerifyReporting) { + testing::internal::LogToStderr(); + testing::internal::CaptureStderr(); + // Every 100 calls generates a report, but run a few extra to verify the + // report happened at call 100. + for (size_t i = 0; i < 110; i++) + scudo::ScopedTimer Outer(getTimingManager(), "VerifyReportTimer"); + + std::string Output = testing::internal::GetCapturedStderr(); + EXPECT_TRUE(Output.find("VerifyReportTimer (100)") != std::string::npos); +} +#endif
diff --git a/standalone/tests/vector_test.cpp b/standalone/tests/vector_test.cpp index b612676..1547824 100644 --- a/standalone/tests/vector_test.cpp +++ b/standalone/tests/vector_test.cpp
@@ -64,7 +64,7 @@ MAP_ALLOWNOMEM)) { MemMap.unmap(MemMap.getBase(), MemMap.getCapacity()); setrlimit(RLIMIT_AS, &Limit); - GTEST_SKIP() << "Limiting address space does not prevent mmap."; + TEST_SKIP("Limiting address space does not prevent mmap."); } V.resize(capacity);
diff --git a/standalone/timing.h b/standalone/timing.h index 84caa79..de741ed 100644 --- a/standalone/timing.h +++ b/standalone/timing.h
@@ -104,6 +104,7 @@ strncpy(Timers[NumAllocatedTimers].Name, Name, MaxLenOfTimerName); TimerRecords[NumAllocatedTimers].AccumulatedTime = 0; TimerRecords[NumAllocatedTimers].Occurrence = 0; + TimerRecords[NumAllocatedTimers].MaxTime = 0; return Timer(*this, NumAllocatedTimers++); } @@ -140,36 +141,47 @@ const u32 HandleId = T.HandleId; CHECK_LT(HandleId, MaxNumberOfTimers); - TimerRecords[HandleId].AccumulatedTime += T.getAccumulatedTime(); + u64 AccTime = T.getAccumulatedTime(); + TimerRecords[HandleId].AccumulatedTime += AccTime; + if (AccTime > TimerRecords[HandleId].MaxTime) { + TimerRecords[HandleId].MaxTime = AccTime; + } ++TimerRecords[HandleId].Occurrence; ++NumEventsReported; - if (NumEventsReported % PrintingInterval == 0) - printAllImpl(); + if (NumEventsReported % PrintingInterval == 0) { + ScopedString Str; + getAllImpl(Str); + Str.output(); + } } void printAll() EXCLUDES(Mutex) { + ScopedString Str; + getAll(Str); + Str.output(); + } + + void getAll(ScopedString &Str) EXCLUDES(Mutex) { ScopedLock L(Mutex); - printAllImpl(); + getAllImpl(Str); } private: - void printAllImpl() REQUIRES(Mutex) { - static char NameHeader[] = "-- Name (# of Calls) --"; + void getAllImpl(ScopedString &Str) REQUIRES(Mutex) { static char AvgHeader[] = "-- Average Operation Time --"; - ScopedString Str; - Str.append("%-15s %-15s\n", AvgHeader, NameHeader); + static char MaxHeader[] = "-- Maximum Operation Time --"; + static char NameHeader[] = "-- Name (# of Calls) --"; + Str.append("%-15s %-15s %-15s\n", AvgHeader, MaxHeader, NameHeader); for (u32 I = 0; I < NumAllocatedTimers; ++I) { if (Timers[I].Nesting != MaxNumberOfTimers) continue; - printImpl(Str, I); + getImpl(Str, I); } - - Str.output(); } - void printImpl(ScopedString &Str, const u32 HandleId, - const u32 ExtraIndent = 0) REQUIRES(Mutex) { + void getImpl(ScopedString &Str, const u32 HandleId, const u32 ExtraIndent = 0) + REQUIRES(Mutex) { const u64 AccumulatedTime = TimerRecords[HandleId].AccumulatedTime; const u64 Occurrence = TimerRecords[HandleId].Occurrence; const u64 Integral = Occurrence == 0 ? 0 : AccumulatedTime / Occurrence; @@ -179,15 +191,20 @@ Occurrence == 0 ? 0 : ((AccumulatedTime % Occurrence) * 10) / Occurrence; - Str.append("%14" PRId64 ".%" PRId64 "(ns) %-11s", Integral, Fraction, " "); + // Average time. + Str.append("%14" PRId64 ".%" PRId64 "(ns) %-8s", Integral, Fraction, " "); + // Maximum time. + Str.append("%16" PRId64 "(ns) %-11s", TimerRecords[HandleId].MaxTime, " "); + + // Name and num occurrences. for (u32 I = 0; I < ExtraIndent; ++I) Str.append("%s", " "); Str.append("%s (%" PRId64 ")\n", Timers[HandleId].Name, Occurrence); for (u32 I = 0; I < NumAllocatedTimers; ++I) if (Timers[I].Nesting == HandleId) - printImpl(Str, I, ExtraIndent + 1); + getImpl(Str, I, ExtraIndent + 1); } // Instead of maintaining pages for timer registration, a static buffer is @@ -199,6 +216,7 @@ struct Record { u64 AccumulatedTime = 0; u64 Occurrence = 0; + u64 MaxTime = 0; }; struct TimerInfo {