Memory Limit Exceeded Analysis

SinceVersion 1.2.0

When the query or import error Memory limit exceeded is reported, the possible reasons are: the process memory exceeds the limit, the remaining available memory of the system is insufficient, and the memory limit for a single query execution is exceeded.

  1. ERROR 1105 (HY000): errCode = 2, detailMessage = Memory limit exceeded:<consuming tracker:<xxx>, xxx. backend 172.1.1.1 process memory used xxx GB, limit xxx GB. If query tracker exceeded, `set exec_mem_limit=8G ` to change limit, details mem usage see be. INFO.

The process memory exceeds the limit OR the remaining available memory of the system is insufficient

When the following error is returned, it means that the process memory exceeds the limit, or the remaining available memory of the system is insufficient. The specific reason depends on the memory statistics.

  1. ERROR 1105 (HY000): errCode = 2, detailMessage = Memory limit exceeded:<consuming tracker:<Query#Id=3c88608cf35c461d-95fe88969aa6fc30>, process memory used 2.68 GB exceed limit 2.47 GB or sys mem available 50.95 GB less than low water mark 3.20 GB, failed alloc size 2.00 MB>, executing msg:<execute:<ExecNode:VAGGREGATION_NODE (id=7)>>. backend 172.1.1.1 process memory used 2.68 GB, limit 2.47 GB. If query tracker exceeded, `set exec_mem_limit =8G` to change limit, details mem usage see be.INFO

Error message analysis

The error message is divided into three parts:

  1. Memory limit exceeded:<consuming tracker:<Query#Id=3c88608cf35c461d-95fe88969aa6fc30>: It is found that the memory limit is exceeded during the memory application process of query 3c88608cf35c461d-95fe88969aa6fc30.
  2. process memory used 2.68 GB exceed limit 2.47 GB or sys mem available 50.95 GB less than low water mark 3.20 GB, failed alloc size 2.00 MB: The reason for exceeding the limit is that the 2.68GB of memory used by the BE process exceeds the limit of 2.47GB limit, the value of limit comes from mem_limit * system MemTotal in be.conf, which is equal to 80% of the total memory of the operating system by default. The remaining available memory of the current operating system is 50.95 GB, which is still higher than the minimum water level of 3.2GB. This time, we are trying to apply for 2MB of memory.
  3. executing msg:<execute:<ExecNode:VAGGREGATION_NODE (id=7)>>, backend 172.24.47.117 process memory used 2.68 GB, limit 2.47 GB: The location of this memory application is ExecNode:VAGGREGATION_NODE (id= 7)>, the current IP of the BE node is 172.1.1.1, and print the memory statistics of the BE node again.

Log Analysis

At the same time, you can find the following log in log/be.INFO to confirm whether the memory usage of the current process meets expectations. The log is also divided into three parts:

  1. Process Memory Summary: process memory statistics.
  2. Alloc Stacktrace: The stack that triggers the memory overrun detection, which is not necessarily the location of the large memory application.
  3. Memory Tracker Summary: Process memory tracker statistics, refer to Memory Tracker to analyze the location of memory usage. Notice:
  4. The printing interval of the process memory overrun log is 1s. After the process memory exceeds the limit, the memory applications in most locations of BE will sense it, and try to make a predetermined callback method, and print the process memory overrun log, so if the log is If the value of Try Alloc is small, you don’t need to pay attention to Alloc Stacktrace, just analyze Memory Tracker Summary directly.
  5. When the process memory exceeds the limit, BE will trigger memory GC.
  1. W1127 17:23:16.372572 19896 mem_tracker_limiter.cpp:214] System Mem Exceed Limit Check Failed, Try Alloc: 1062688
  2. Process Memory Summary:
  3.     process memory used 2.68 GB limit 2.47 GB, sys mem available 50.95 GB min reserve 3.20 GB, tc/jemalloc allocator cache 51.97 MB
  4. Alloc Stacktrace:
  5.     @          0x50028e8  doris::MemTrackerLimiter::try_consume()
  6.     @          0x50027c1  doris::ThreadMemTrackerMgr::flush_untracked_mem<>()
  7.     @          0x595f234  malloc
  8.     @          0xb888c18  operator new()
  9.     @          0x8f316a2  google::LogMessage::Init()
  10.     @          0x5813fef  doris::FragmentExecState::coordinator_callback()
  11.     @          0x58383dc  doris::PlanFragmentExecutor::send_report()
  12.     @          0x5837ea8  doris::PlanFragmentExecutor::update_status()
  13.     @          0x58355b0  doris::PlanFragmentExecutor::open()
  14.     @          0x5815244  doris::FragmentExecState::execute()
  15.     @          0x5817965  doris::FragmentMgr::_exec_actual()
  16.     @          0x581fffb  std::_Function_handler<>::_M_invoke()
  17.     @          0x5a6f2c1  doris::ThreadPool::dispatch_thread()
  18.     @          0x5a6843f  doris::Thread::supervise_thread()
  19.     @     0x7feb54f931ca  start_thread
  20.     @     0x7feb5576add3  __GI___clone
  21.     @              (nil)  (unknown)
  23. Memory Tracker Summary:
  24.     Type=consistency, Used=0(0 B), Peak=0(0 B)
  25.     Type=batch_load, Used=0(0 B), Peak=0(0 B)
  26.     Type=clone, Used=0(0 B), Peak=0(0 B)
  27.     Type=schema_change, Used=0(0 B), Peak=0(0 B)
  28.     Type=compaction, Used=0(0 B), Peak=0(0 B)
  29.     Type=load, Used=0(0 B), Peak=0(0 B)
  30.     Type=query, Used=206.67 MB(216708729 B), Peak=565.26 MB(592723181 B)
  31.     Type=global, Used=930.42 MB(975614571 B), Peak=1017.42 MB(1066840223 B)
  32.     Type=tc/jemalloc_cache, Used=51.97 MB(54494616 B), Peak=-1.00 B(-1 B)
  33.     Type=process, Used=1.16 GB(1246817916 B), Peak=-1.00 B(-1 B)
  34.     MemTrackerLimiter Label=Orphan, Type=global, Limit=-1.00 B(-1 B), Used=474.20 MB(497233597 B), Peak=649.18 MB(680718208 B)
  35.     MemTracker Label=BufferAllocator, Parent Label=Orphan, Used=0(0 B), Peak=0(0 B)
  36.     MemTracker Label=LoadChannelMgr, Parent Label=Orphan, Used=0(0 B), Peak=0(0 B)
  37.     MemTracker Label=StorageEngine, Parent Label=Orphan, Used=320.56 MB(336132488 B), Peak=322.56 MB(338229824 B)
  38.     MemTracker Label=SegCompaction, Parent Label=Orphan, Used=0(0 B), Peak=0(0 B)
  39.     MemTracker Label=SegmentMeta, Parent Label=Orphan, Used=948.64 KB(971404 B), Peak=943.64 KB(966285 B)
  40.     MemTracker Label=TabletManager, Parent Label=Orphan, Used=0(0 B), Peak=0(0 B)
  41.     MemTrackerLimiter Label=DataPageCache, Type=global, Limit=-1.00 B(-1 B), Used=455.22 MB(477329882 B), Peak=454.18 MB(476244180 B)
  42.     MemTrackerLimiter Label=IndexPageCache, Type=global, Limit=-1.00 B(-1 B), Used=1.00 MB(1051092 B), Peak=0(0 B)
  43.     MemTrackerLimiter Label=SegmentCache, Type=global, Limit=-1.00 B(-1 B), Used=0(0 B), Peak=0(0 B)
  44.     MemTrackerLimiter Label=DiskIO, Type=global, Limit=2.47 GB(2655423201 B), Used=0(0 B), Peak=0(0 B)
  45.     MemTrackerLimiter Label=ChunkAllocator, Type=global, Limit=-1.00 B(-1 B), Used=0(0 B), Peak=0(0 B)
  46.     MemTrackerLimiter Label=LastestSuccessChannelCache, Type=global, Limit=-1.00 B(-1 B), Used=0(0 B), Peak=0(0 B)
  47.     MemTrackerLimiter Label=DeleteBitmap AggCache, Type=global, Limit=-1.00 B(-1 B), Used=0(0 B), Peak=0(0 B)

System remaining available memory calculation

When the available memory of the system in the error message is less than the low water mark, it is also treated as a process memory limit. The value of the available memory of the system comes from MemAvailable in /proc/meminfo. When MemAvailable is insufficient, continue to use the memory The application may return std::bad_alloc or cause OOM of the BE process. Because both refreshing process memory statistics and BE memory GC have a certain lag, a small part of the memory buffer is reserved as a low water mark to avoid OOM as much as possible.

Among them, MemAvailable is the total amount of memory that the operating system can provide to the user process without triggering swap as much as possible given by the operating system considering the current free memory, buffer, cache, memory fragmentation and other factors. A simple calculation Formula: MemAvailable = MemFree - LowWaterMark + (PageCache - min(PageCache / 2, LowWaterMark)), which is the same as the available value seen by cmd free, for details, please refer to: https://serverfault.com/questions/940196/why-is-memaavailable-a-lot-less-than-memfreebufferscached https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=34e431b0ae398fc54ea69ff85ec700722c9da773

The low water mark defaults to a maximum of 1.6G, calculated based on MemTotal, vm/min_free_kbytes, confg::mem_limit, config::max_sys_mem_available_low_water_mark_bytes, and avoid wasting too much memory. Among them, MemTotal is the total memory of the system, and the value also comes from /proc/meminfo; vm/min_free_kbytes is the buffer reserved by the operating system for the memory GC process, and the value is usually between 0.4% and 5%. vm/min_free_kbytes may be 5% on some cloud servers, which will lead to visually that the available memory of the system is less than the real value; increasing config::max_sys_mem_available_low_water_mark_bytes will reserve more for Full GC on machines with more than 16G memory If there are more memory buffers, otherwise, the memory will be fully used as much as possible.

Query or import a single execution memory limit

When the following error is returned, it means that the memory limit of a single execution has been exceeded.

  1. ERROR 1105 (HY000): errCode = 2, detailMessage = Memory limit exceeded:<consuming tracker:<Query#Id=f78208b15e064527-a84c5c0b04c04fcf>, failed alloc size 1.03 MB, exceeded tracker:<Query#Id=f78208b15e064527-a84c5c0b04c04fcf>, limit 100.00 MB, peak used 99.29 MB, current used 99.25 MB>, executing msg:<execute:<ExecNode:VHASH_JOIN_NODE (id=4)>>. backend 172.24.47.117 process memory used 1.13 GB, limit 98.92 GB. If query tracker exceed, `set exec_mem_limit=8G` to change limit, details mem usage see log/be.INFO

Error message analysis

The error message is divided into three parts:

  1. Memory limit exceeded:<consuming tracker:<Query#Id=f78208b15e064527-a84c5c0b04c04fcf>: It is found that the memory limit is exceeded during the memory application process of query f78208b15e064527-a84c5c0b04c04fcf.
  2. failed alloc size 1.03 MB, exceeded tracker:<Query#Id=f78208b15e064527-a84c5c0b04c04fcf>, limit 100.00 MB, peak used 99.29 MB, current used 99.25 MB: The memory requested this time is 1.03 MB The current consumption of f78208b15e064527-a84c5c0b04c04fcf memory tracker is 99.28MB plus 1.03MB, which exceeds the limit of 100MB. The value of limit comes from exec_mem_limit in session variables, and the default is 4G.
  3. executing msg:<execute:<ExecNode:VHASH_JOIN_NODE (id=4)>>. backend 172.24.47.117 process memory used 1.13 GB, limit 98.92 GB. If query tracker exceeds, set exec_mem_limit=8G to change limit, details mem usage see be.INFO.: The location of this memory application is VHASH_JOIN_NODE (id=4), and it prompts that set exec_mem_limit can be used to increase the memory limit of a single query.

Log Analysis

After set global enable_profile=true, you can print a log in log/be.INFO when a single query memory exceeds the limit, to confirm whether the current query memory usage meets expectations. At the same time, you can find the following logs in log/be.INFO to confirm whether the current query memory usage meets expectations. The logs are also divided into three parts:

  1. Process Memory Summary: process memory statistics.
  2. Alloc Stacktrace: The stack that triggers the memory overrun detection, which is not necessarily the location of the large memory application.
  3. Memory Tracker Summary: The memory tracker statistics of the current query, you can see the memory and peak value currently used by each operator. For details, please refer to [Memory Tracker](../admin-manual/memory-management/memory -tracker.md). Note: A query will only print the log once after the memory exceeds the limit. At this time, multiple threads of the query will sense it and try to wait for the memory to be released, or cancel the current query. If the value of Try Alloc in the log is small, there is no need to pay attention Alloc Stacktrace, just analyze Memory Tracker Summary directly.
  1. W1128 01:34:11.016165 357796 mem_tracker_limiter.cpp:191] Memory limit exceeded:<consuming tracker:<Query#Id=78208b15e064527-a84c5c0b04c04fcf>, failed alloc size 4.00 MB, exceeded tracker:<Query#Id=78208b15e064527-a84c5c0b04c04fcf>, limit 100.00 MB, peak used 98.59 MB,
  2. current used 96.88 MB>, executing msg:<execute:<ExecNode:VHASH_JOIN_NODE (id=2)>>. backend 172.24.47.117 process memory used 1.13 GB, limit 98.92 GB. If query tracker exceed, `set exec_mem_limit=8G` to change limit, details mem usage see be.INFO.
  3. Process Memory Summary:    
  4.     process memory used 1.13 GB limit 98.92 GB, sys mem available 45.15 GB min reserve 3.20 GB, tc/jemalloc allocator cache 27.62 MB
  5. Alloc Stacktrace:    
  6.     @          0x66cf73a  doris::vectorized::HashJoinNode::_materialize_build_side()
  7.     @          0x69cb1ee  doris::vectorized::VJoinNodeBase::open()
  8.     @          0x66ce27a  doris::vectorized::HashJoinNode::open()
  9.     @          0x5835dad  doris::PlanFragmentExecutor::open_vectorized_internal()
  10.     @          0x58351d2  doris::PlanFragmentExecutor::open()
  11.     @          0x5815244  doris::FragmentExecState::execute()
  12.     @          0x5817965  doris::FragmentMgr::_exec_actual()
  13.     @          0x581fffb  std::_Function_handler<>::_M_invoke()
  14.     @          0x5a6f2c1  doris::ThreadPool::dispatch_thread()
  15.     @          0x5a6843f  doris::Thread::supervise_thread()
  16.     @     0x7f6faa94a1ca  start_thread
  17.     @     0x7f6fab121dd3  __GI___clone
  18.     @              (nil)  (unknown)
  20. Memory Tracker Summary:
  21.     MemTrackerLimiter Label=Query#Id=78208b15e064527-a84c5c0b04c04fcf, Type=query, Limit=100.00 MB(104857600 B), Used=64.75 MB(67891182 B), Peak=104.70 MB(109786406 B)
  22.     MemTracker Label=Scanner#QueryId=78208b15e064527-a84c5c0b04c04fcf, Parent Label=Query#Id=78208b15e064527-a84c5c0b04c04fcf, Used=0(0 B), Peak=0(0 B)
  23.     MemTracker Label=RuntimeFilterMgr, Parent Label=Query#Id=78208b15e064527-a84c5c0b04c04fcf, Used=2.09 KB(2144 B), Peak=0(0 B)
  24.     MemTracker Label=BufferedBlockMgr2, Parent Label=Query#Id=78208b15e064527-a84c5c0b04c04fcf, Used=0(0 B), Peak=0(0 B)
  25.     MemTracker Label=ExecNode:VHASH_JOIN_NODE (id=2), Parent Label=Query#Id=78208b15e064527-a84c5c0b04c04fcf, Used=-61.44 MB(-64426656 B), Peak=290.33 KB(297296 B)
  26.     MemTracker Label=ExecNode:VEXCHANGE_NODE (id=9), Parent Label=Query#Id=78208b15e064527-a84c5c0b04c04fcf, Used=6.12 KB(6264 B), Peak=5.84 KB(5976 B)
  27.     MemTracker Label=VDataStreamRecvr:78208b15e064527-a84c5c0b04c04fd2, Parent Label=Query#Id=78208b15e064527-a84c5c0b04c04fcf, Used=6.12 KB(6264 B), Peak=5.84 KB(5976 B)
  28.     MemTracker Label=ExecNode:VEXCHANGE_NODE (id=10), Parent Label=Query#Id=78208b15e064527-a84c5c0b04c04fcf, Used=-41.20 MB(-43198024 B), Peak=1.46 MB(1535656 B)
  29.     MemTracker Label=VDataStreamRecvr:78208b15e064527-a84c5c0b04c04fd2, Parent Label=Query#Id=78208b15e064527-a84c5c0b04c04fcf, Used=-41.20 MB(-43198024 B), Peak=1.46 MB(1535656 B)
  30.     MemTracker Label=VDataStreamSender:78208b15e064527-a84c5c0b04c04fd2, Parent Label=Query#Id=78208b15e064527-a84c5c0b04c04fcf, Used=2.34 KB(2400 B), Peak=0(0 B)
  31.     MemTracker Label=Scanner#QueryId=78208b15e064527-a84c5c0b04c04fcf, Parent Label=Query#Id=78208b15e064527-a84c5c0b04c04fcf, Used=58.12 MB(60942224 B), Peak=57.41 MB(60202848 B)
  32.     MemTracker Label=RuntimeFilterMgr, Parent Label=Query#Id=78208b15e064527-a84c5c0b04c04fcf, Used=0(0 B), Peak=0(0 B)
  33.     MemTracker Label=BufferedBlockMgr2, Parent Label=Query#Id=78208b15e064527-a84c5c0b04c04fcf, Used=0(0 B), Peak=0(0 B)
  34.     MemTracker Label=ExecNode:VNewOlapScanNode(customer) (id=1), Parent Label=Query#Id=78208b15e064527-a84c5c0b04c04fcf, Used=9.55 MB(10013424 B), Peak=10.20 MB(10697136 B)
  35.     MemTracker Label=VDataStreamSender:78208b15e064527-a84c5c0b04c04fd1, Parent Label=Query#Id=78208b15e064527-a84c5c0b04c04fcf, Used=59.80 MB(62701880 B), Peak=59.16 MB(62033048 B)
  36.     MemTracker Label=Scanner#QueryId=78208b15e064527-a84c5c0b04c04fcf, Parent Label=Query#Id=78208b15e064527-a84c5c0b04c04fcf, Used=0(0 B), Peak=0(0 B)
  37.     MemTracker Label=RuntimeFilterMgr, Parent Label=Query#Id=78208b15e064527-a84c5c0b04c04fcf, Used=13.62 KB(13952 B), Peak=0(0 B)
  38.     MemTracker Label=BufferedBlockMgr2, Parent Label=Query#Id=78208b15e064527-a84c5c0b04c04fcf, Used=0(0 B), Peak=0(0 B)
  39.     MemTracker Label=ExecNode:VNewOlapScanNode(lineorder) (id=0), Parent Label=Query#Id=78208b15e064527-a84c5c0b04c04fcf, Used=6.03 MB(6318064 B), Peak=4.02 MB(4217664 B)
  40.     MemTracker Label=VDataStreamSender:78208b15e064527-a84c5c0b04c04fd0, Parent Label=Query#Id=78208b15e064527-a84c5c0b04c04fcf, Used=2.34 KB(2400 B), Peak=0(0 B)