diff --git a/shared/source/debug_settings/debug_variables_base.inl b/shared/source/debug_settings/debug_variables_base.inl index 0d1192f0bb..6f95384f02 100644 --- a/shared/source/debug_settings/debug_variables_base.inl +++ b/shared/source/debug_settings/debug_variables_base.inl @@ -334,6 +334,7 @@ DECLARE_DEBUG_VARIABLE(bool, LogAllocationType, false, "Logs allocation type to DECLARE_DEBUG_VARIABLE(bool, LogAllocationStdout, false, "Log allocations to stdout instead of file") DECLARE_DEBUG_VARIABLE(bool, LogMemoryObject, false, "Logs memory object ptrs, sizes and operations") DECLARE_DEBUG_VARIABLE(bool, LogWaitingForCompletion, false, "Logs waiting for completion") +DECLARE_DEBUG_VARIABLE(bool, LogUsmReuse, false, "Logs operations of usm reuse to csv file") DECLARE_DEBUG_VARIABLE(bool, ResidencyDebugEnable, false, "enables debug messages and checks for Residency Model") DECLARE_DEBUG_VARIABLE(bool, EventsDebugEnable, false, "enables debug messages for events, virtual events, blocked enqueues, events trees etc.") DECLARE_DEBUG_VARIABLE(bool, EventsTrackerEnable, false, "enables event graphs dumping") diff --git a/shared/source/memory_manager/unified_memory_manager.cpp b/shared/source/memory_manager/unified_memory_manager.cpp index 111f9fa665..dbebb70b5d 100644 --- a/shared/source/memory_manager/unified_memory_manager.cpp +++ b/shared/source/memory_manager/unified_memory_manager.cpp @@ -56,28 +56,42 @@ void SVMAllocsManager::MapBasedAllocationTracker::freeAllocations(NEO::MemoryMan } } +SVMAllocsManager::SvmAllocationCache::SvmAllocationCache() { + this->enablePerformanceLogging = NEO::debugManager.flags.LogUsmReuse.get(); +} + bool SVMAllocsManager::SvmAllocationCache::insert(size_t size, void *ptr, SvmAllocationData *svmData) { if (false == sizeAllowed(size)) { return false; } std::lock_guard lock(this->mtx); + bool isSuccess = true; if (auto device = svmData->device) { auto lock = device->obtainAllocationsReuseLock(); - const auto usedSize = device->getAllocationsSavedForReuseSize(); - if (size + usedSize > device->getMaxAllocationsSavedForReuseSize()) { - return false; + if (size + device->getAllocationsSavedForReuseSize() > device->getMaxAllocationsSavedForReuseSize()) { + isSuccess = false; + } else { + device->recordAllocationSaveForReuse(size); } - device->recordAllocationSaveForReuse(size); } else { auto lock = memoryManager->obtainHostAllocationsReuseLock(); - const auto usedSize = memoryManager->getHostAllocationsSavedForReuseSize(); - if (size + usedSize > this->maxSize) { - return false; + if (size + memoryManager->getHostAllocationsSavedForReuseSize() > this->maxSize) { + isSuccess = false; + } else { + memoryManager->recordHostAllocationSaveForReuse(size); } - memoryManager->recordHostAllocationSaveForReuse(size); } - allocations.emplace(std::lower_bound(allocations.begin(), allocations.end(), size), size, ptr); - return true; + if (isSuccess) { + allocations.emplace(std::lower_bound(allocations.begin(), allocations.end(), size), size, ptr); + } + if (enablePerformanceLogging) { + logCacheOperation({.allocationSize = size, + .timePoint = std::chrono::high_resolution_clock::now(), + .allocationType = svmData->memoryType, + .operationType = CacheOperationType::insert, + .isSuccess = isSuccess}); + } + return isSuccess; } bool SVMAllocsManager::SvmAllocationCache::allocUtilizationAllows(size_t requestedSize, size_t reuseCandidateSize) { @@ -125,11 +139,25 @@ void *SVMAllocsManager::SvmAllocationCache::get(size_t size, const UnifiedMemory auto lock = memoryManager->obtainHostAllocationsReuseLock(); memoryManager->recordHostAllocationGetFromReuse(allocationIter->allocationSize); } + if (enablePerformanceLogging) { + logCacheOperation({.allocationSize = allocationIter->allocationSize, + .timePoint = std::chrono::high_resolution_clock::now(), + .allocationType = svmData->memoryType, + .operationType = CacheOperationType::get, + .isSuccess = true}); + } allocations.erase(allocationIter); svmData->size = size; return allocationPtr; } } + if (enablePerformanceLogging) { + logCacheOperation({.allocationSize = size, + .timePoint = std::chrono::high_resolution_clock::now(), + .allocationType = unifiedMemoryProperties.memoryType, + .operationType = CacheOperationType::get, + .isSuccess = false}); + } return nullptr; } @@ -145,6 +173,13 @@ void SVMAllocsManager::SvmAllocationCache::trim() { auto lock = memoryManager->obtainHostAllocationsReuseLock(); memoryManager->recordHostAllocationGetFromReuse(cachedAllocationInfo.allocationSize); } + if (enablePerformanceLogging) { + logCacheOperation({.allocationSize = cachedAllocationInfo.allocationSize, + .timePoint = std::chrono::high_resolution_clock::now(), + .allocationType = svmData->memoryType, + .operationType = CacheOperationType::trim, + .isSuccess = true}); + } svmAllocsManager->freeSVMAllocImpl(cachedAllocationInfo.allocation, FreePolicyType::none, svmData); } this->allocations.clear(); @@ -159,27 +194,76 @@ void SVMAllocsManager::SvmAllocationCache::cleanup() { this->trim(); } +void SVMAllocsManager::SvmAllocationCache::logCacheOperation(const SvmAllocationCachePerfInfo &cachePerfEvent) const { + std::string allocationTypeString, operationTypeString, isSuccessString; + switch (cachePerfEvent.allocationType) { + case InternalMemoryType::deviceUnifiedMemory: + allocationTypeString = "device"; + break; + case InternalMemoryType::hostUnifiedMemory: + allocationTypeString = "host"; + break; + default: + allocationTypeString = "unknown"; + break; + } + + switch (cachePerfEvent.operationType) { + case CacheOperationType::get: + operationTypeString = "get"; + break; + case CacheOperationType::insert: + operationTypeString = "insert"; + break; + case CacheOperationType::trim: + operationTypeString = "trim"; + break; + case CacheOperationType::trimOld: + operationTypeString = "trim_old"; + break; + default: + operationTypeString = "unknown"; + break; + } + isSuccessString = cachePerfEvent.isSuccess ? "TRUE" : "FALSE"; + NEO::usmReusePerfLoggerInstance().log(true, ",", + cachePerfEvent.timePoint.time_since_epoch().count(), ",", + allocationTypeString, ",", + operationTypeString, ",", + cachePerfEvent.allocationSize, ",", + isSuccessString); +} + void SVMAllocsManager::SvmAllocationCache::trimOldAllocs(std::chrono::high_resolution_clock::time_point trimTimePoint) { + if (this->allocations.empty()) { + return; + } std::lock_guard lock(this->mtx); - for (auto allocationIter = allocations.begin(); - allocationIter != allocations.end();) { - if (allocationIter->saveTime > trimTimePoint) { - ++allocationIter; + for (auto allocCleanCandidate = allocations.begin(); allocCleanCandidate != allocations.end();) { + if (allocCleanCandidate->saveTime > trimTimePoint) { + ++allocCleanCandidate; continue; } - void *allocationPtr = allocationIter->allocation; + void *allocationPtr = allocCleanCandidate->allocation; SvmAllocationData *svmData = svmAllocsManager->getSVMAlloc(allocationPtr); UNRECOVERABLE_IF(nullptr == svmData); if (svmData->device) { auto lock = svmData->device->obtainAllocationsReuseLock(); - svmData->device->recordAllocationGetFromReuse(allocationIter->allocationSize); + svmData->device->recordAllocationGetFromReuse(allocCleanCandidate->allocationSize); } else { auto lock = memoryManager->obtainHostAllocationsReuseLock(); - memoryManager->recordHostAllocationGetFromReuse(allocationIter->allocationSize); + memoryManager->recordHostAllocationGetFromReuse(allocCleanCandidate->allocationSize); } - svmAllocsManager->freeSVMAllocImpl(allocationIter->allocation, FreePolicyType::defer, svmData); - allocationIter = allocations.erase(allocationIter); - return; + if (enablePerformanceLogging) { + logCacheOperation({.allocationSize = allocCleanCandidate->allocationSize, + .timePoint = std::chrono::high_resolution_clock::now(), + .allocationType = svmData->memoryType, + .operationType = CacheOperationType::trimOld, + .isSuccess = true}); + } + svmAllocsManager->freeSVMAllocImpl(allocCleanCandidate->allocation, FreePolicyType::defer, svmData); + allocations.erase(allocCleanCandidate); + break; } } diff --git a/shared/source/memory_manager/unified_memory_manager.h b/shared/source/memory_manager/unified_memory_manager.h index 35be1a7e10..ae217faa54 100644 --- a/shared/source/memory_manager/unified_memory_manager.h +++ b/shared/source/memory_manager/unified_memory_manager.h @@ -167,10 +167,27 @@ class SVMAllocsManager { }; struct SvmAllocationCache { + enum class CacheOperationType { + insert, + get, + trim, + trimOld + }; + + struct SvmAllocationCachePerfInfo { + uint64_t allocationSize; + std::chrono::high_resolution_clock::time_point timePoint; + InternalMemoryType allocationType; + CacheOperationType operationType; + bool isSuccess; + }; + static constexpr size_t maxServicedSize = 256 * MemoryConstants::megaByte; static constexpr size_t minimalSizeToCheckUtilization = 4 * MemoryConstants::pageSize64k; static constexpr double minimalAllocUtilization = 0.5; + SvmAllocationCache(); + static bool sizeAllowed(size_t size) { return size <= SvmAllocationCache::maxServicedSize; } bool insert(size_t size, void *ptr, SvmAllocationData *svmData); static bool allocUtilizationAllows(size_t requestedSize, size_t reuseCandidateSize); @@ -179,12 +196,15 @@ class SVMAllocsManager { void trim(); void trimOldAllocs(std::chrono::high_resolution_clock::time_point trimTimePoint); void cleanup(); + void logCacheOperation(const SvmAllocationCachePerfInfo &cachePerfEvent) const; std::vector allocations; + std::mutex mtx; size_t maxSize = 0; SVMAllocsManager *svmAllocsManager = nullptr; MemoryManager *memoryManager = nullptr; + bool enablePerformanceLogging = false; }; enum class FreePolicyType : uint32_t { diff --git a/shared/source/utilities/logger.cpp b/shared/source/utilities/logger.cpp index 0d5413bd85..579ed3e744 100644 --- a/shared/source/utilities/logger.cpp +++ b/shared/source/utilities/logger.cpp @@ -1,5 +1,5 @@ /* - * Copyright (C) 2019-2024 Intel Corporation + * Copyright (C) 2019-2025 Intel Corporation * * SPDX-License-Identifier: MIT * @@ -25,6 +25,11 @@ FileLogger &fileLoggerInstance() { return fileLoggerInstance; } +FileLogger &usmReusePerfLoggerInstance() { + static FileLogger usmReusePerfLoggerInstance(std::string("usm_reuse_perf.csv"), debugManager.flags); + return usmReusePerfLoggerInstance; +} + template FileLogger::FileLogger(std::string filename, const DebugVariables &flags) { logFileName = std::move(filename); diff --git a/shared/source/utilities/logger.h b/shared/source/utilities/logger.h index b5e96aa3a4..4d5e4a6a58 100644 --- a/shared/source/utilities/logger.h +++ b/shared/source/utilities/logger.h @@ -192,6 +192,7 @@ static_assert(NEO::NonCopyableAndNonMovable>); extern FileLogger &fileLoggerInstance(); +extern FileLogger &usmReusePerfLoggerInstance(); template class LoggerApiEnterWrapper { diff --git a/shared/test/common/common_main.cpp b/shared/test/common/common_main.cpp index 4a2c07b998..74e8fc85ea 100644 --- a/shared/test/common/common_main.cpp +++ b/shared/test/common/common_main.cpp @@ -139,6 +139,7 @@ void applyCommonWorkarounds() { // Create FileLogger to prevent false memory leaks { NEO::fileLoggerInstance(); + NEO::usmReusePerfLoggerInstance(); } } diff --git a/shared/test/common/test_files/igdrcl.config b/shared/test/common/test_files/igdrcl.config index 1f3dae337a..b63fdbb258 100644 --- a/shared/test/common/test_files/igdrcl.config +++ b/shared/test/common/test_files/igdrcl.config @@ -665,4 +665,5 @@ ExperimentalUSMAllocationReuseCleaner = -1 DummyPageBackingEnabled = 0 EnableDeferBacking = 0 GetSipBinaryFromExternalLib = -1 +LogUsmReuse = 0 # Please don't edit below this line diff --git a/shared/test/unit_test/debug_settings/debug_settings_manager_tests.cpp b/shared/test/unit_test/debug_settings/debug_settings_manager_tests.cpp index 8c58adb3eb..f8cdc49e6b 100644 --- a/shared/test/unit_test/debug_settings/debug_settings_manager_tests.cpp +++ b/shared/test/unit_test/debug_settings/debug_settings_manager_tests.cpp @@ -8,6 +8,7 @@ #include "shared/source/helpers/api_specific_config.h" #include "shared/source/memory_manager/graphics_allocation.h" #include "shared/source/memory_manager/memory_manager.h" +#include "shared/source/memory_manager/unified_memory_manager.h" #include "shared/source/utilities/debug_file_reader.h" #include "shared/source/utilities/logger.h" #include "shared/test/common/debug_settings/debug_settings_manager_fixture.h" @@ -439,6 +440,43 @@ TEST(DebugSettingsManager, GivenLogsDisabledAndDumpToFileWhenPrintDebuggerLogCal ASSERT_FALSE(logFileExists); } +TEST(DebugSettingsManager, GivenLogsEnabledWhenLogCacheOperationCalledThenStringPrintedToFile) { + if (!NEO::usmReusePerfLoggerInstance().enabled()) { + GTEST_SKIP(); + } + DebugManagerStateRestore restorer; + + auto logFile = NEO::usmReusePerfLoggerInstance().getLogFileName(); + std::remove(logFile); + + SVMAllocsManager::SvmAllocationCache svmAllocationCache; + auto timePoint = std::chrono::high_resolution_clock::now(); + svmAllocationCache.logCacheOperation({.allocationSize = 1024, + .timePoint = timePoint, + .allocationType = InternalMemoryType::deviceUnifiedMemory, + .operationType = SVMAllocsManager::SvmAllocationCache::CacheOperationType::trim, + .isSuccess = true}); + + auto logFileExists = fileExists(logFile); + EXPECT_TRUE(logFileExists); + + size_t retSize; + auto data = loadDataFromFile(logFile, retSize); + auto retString = std::string(data.get(), data.get() + retSize); + std::stringstream expectedString; + expectedString << timePoint.time_since_epoch().count() << " , " + << "device" + << " , " + << "trim" + << " , " + << "1024" + << " , " + << "TRUE"; + + EXPECT_NE(std::string::npos, retString.find(expectedString.str())); + std::remove(logFile); +} + TEST(DebugLog, WhenLogDebugStringCalledThenNothingIsPrintedToStdout) { ::testing::internal::CaptureStdout(); logDebugString("test log");