From 51d11e971c7ae8426c21355b15315af4557d227f Mon Sep 17 00:00:00 2001 From: mohsaka <135669458+mohsaka@users.noreply.github.com> Date: Wed, 17 Apr 2024 08:54:28 -0700 Subject: [PATCH] Add Mmap allocator information to error message when failing with MMap failed (#9455) Summary: We currently have a lack of information on the current status of the MMap allocator when we fail in the logging. Here is an example of what we see. ``` E20240410 00:12:53.207183 21387 MmapAllocator.cpp:344] [MEM] Mmap failed with 4194304 pages use MmapArena false E20240410 00:12:53.218799 21387 MmapAllocator.cpp:344] [MEM] Mmap failed with 4194304 pages use MmapArena false E20240410 00:12:53.228353 21387 MmapAllocator.cpp:344] [MEM] Mmap failed with 4194304 pages use MmapArena false E20240410 00:12:53.239408 21387 MmapAllocator.cpp:344] [MEM] Mmap failed with 4194304 pages use MmapArena false E20240410 00:12:53.250753 21387 MmapAllocator.cpp:344] [MEM] Mmap failed with 4194304 pages use MmapArena false E20240410 00:12:53.259156 21387 MmapAllocator.cpp:344] [MEM] Mmap failed with 4194304 pages use MmapArena false E20240410 00:12:53.266788 21387 MmapAllocator.cpp:344] [MEM] Mmap failed with 4194304 pages use MmapArena false E20240410 00:12:53.274092 21387 MmapAllocator.cpp:344] [MEM] Mmap failed with 4194304 pages use MmapArena false E20240410 00:12:53.287583 21387 MmapAllocator.cpp:344] [MEM] Mmap failed with 4194304 pages use MmapArena false E20240410 00:12:53.296489 21387 MmapAllocator.cpp:344] [MEM] Mmap failed with 4194304 pages use MmapArena false I20240410 00:12:53.296515 21387 AsyncDataCache.cpp:799] [CACHE] Backoff in allocation contention for 23.67ms E20240410 00:12:53.327771 21387 MmapAllocator.cpp:344] [MEM] Mmap failed with 4194304 pages use MmapArena false E20240410 00:12:53.342656 21387 MmapAllocator.cpp:344] [MEM] Mmap failed with 4194304 pages use MmapArena false E20240410 00:12:53.387915 21387 MmapAllocator.cpp:344] [MEM] Mmap failed with 4194304 pages use MmapArena false E20240410 00:12:53.413861 21387 MmapAllocator.cpp:344] [MEM] Mmap failed with 4194304 pages use MmapArena false E20240410 00:12:53.463887 21387 MmapAllocator.cpp:344] [MEM] Mmap failed with 4194304 pages use MmapArena false E20240410 00:12:53.501030 21387 MmapAllocator.cpp:344] [MEM] Mmap failed with 4194304 pages use MmapArena false E20240410 00:12:53.521816 21387 Exceptions.h:69] Line: /app/presto-native-execution/velox/velox/common/memory/MemoryPool.cpp:1198, Function:handleAllocationFailure, Expression: allocateContiguous failed with 4194304 pages from Memory Pool[op.2149.4.63.HashBuild LEAF root[20240410_001004_00013_5sjzc_123] parent[node.2149] MMAP track-usage thread-safe] Mmap failed with 4194304 pages use MmapArena false Failed to evict from cache state: AsyncDataCache: Cache size: 57.10GB tinySize: 228.15KB large size: 57.09GB Cache entries: 15536 read pins: 128 write pins: 0 pinned shared: 126.07MB pinned exclusive: 0B num write wait: 19610 empty entries: 112530 Cache access miss: 235115 hit: 974160 hit bytes: 2.51TB eviction: 219579 eviction checks: 296298 aged out: 0 Prefetch entries: 2 bytes: 890.92KB Alloc Megaclocks 610291 Allocated pages: 32586619 cached pages: 14967066 , Source: RUNTIME, ErrorCode: MEM_ALLOC_ERROR ``` By adding toString(), we will be able to see output like ``` Memory Allocator[MMAP total capacity 461.00GB free capacity 66.99GB allocated pages 103287293 mapped pages 104333972 external mapped pages 7670401 [size 1: 33382(130MB) allocated 60831 mapped] [size 2: 43805(342MB) allocated 343492 mapped] [size 4: 34963(546MB) allocated 47499 mapped] [size 8: 28204(881MB) allocated 38870 mapped] [size 16: 35949(2246MB) allocated 47261 mapped] [size 32: 47909(5988MB) allocated 51124 mapped] [size 64: 36067(9016MB) allocated 36067 mapped] [size 128: 45642(22821MB) allocated 45642 mapped] [size 256: 331530(331530MB) allocated 331532 mapped] ] ``` Pull Request resolved: https://github.com/facebookincubator/velox/pull/9455 Reviewed By: amitkdutta Differential Revision: D56230522 Pulled By: xiaoxmeng fbshipit-source-id: f56832115468c0354680381c27f5f175580184ac --- velox/common/memory/MmapAllocator.cpp | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/velox/common/memory/MmapAllocator.cpp b/velox/common/memory/MmapAllocator.cpp index 88839e6b26622..2a4f26174ab2f 100644 --- a/velox/common/memory/MmapAllocator.cpp +++ b/velox/common/memory/MmapAllocator.cpp @@ -340,10 +340,11 @@ bool MmapAllocator::allocateContiguousImpl( } if (data == nullptr || data == MAP_FAILED) { const std::string errorMsg = fmt::format( - "Mmap failed with {} pages use MmapArena {}, errno {}", + "Mmap failed with {} pages use MmapArena {}, errno {}, Mmap Allocator: {}", numPages, (useMmapArena_ ? "true" : "false"), - folly::errnoStr(errno)); + folly::errnoStr(errno), + toString()); VELOX_MEM_LOG(ERROR) << errorMsg; setAllocatorFailureMessage(errorMsg); // If the mmap failed, we have unmapped former 'allocation' and the extra to