[MDEV-9236] Dramatically overallocation of InnoDB buffer pool leads to crash Created: 2015-12-03  Updated: 2023-04-27

Status: Open
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.1.9
Fix Version/s: 10.6, 10.11

Type: Bug Priority: Major
Reporter: Oli Sennhauser Assignee: Marko Mäkelä
Resolution: Unresolved Votes: 0
Labels: memory_exhaustion
Environment:

Linux, Ubuntu 14.04


Issue Links:
Relates
relates to MDEV-29445 reorganise innodb buffer pool (and re... Stalled

 Description   

free
             total       used       free     shared    buffers     cached
Mem:      11989892   11562816     427076     468028     260304    4216848
-/+ buffers/cache:    7085664    4904228
Swap:     12261372     901968   11359404

my.cnf

innodb_buffer_pool_size        = 128G

2015-12-03 17:16:59 139995792902080 [Note] InnoDB: Initializing buffer pool, size = 128.0G
InnoDB: mmap(17716740096 bytes) failed; errno 12
2015-12-03 17:17:01 7f534f8187c0  InnoDB: Assertion failure in thread 139995792902080 in file buf0lru.cc line 2240
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
151203 17:17:01 [ERROR] mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
 
To report this bug, see http://kb.askmonty.org/en/reporting-bugs
 
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed,
something is definitely wrong and this may fail.
 
Server version: 10.1.9-MariaDB-log
key_buffer_size=8388608
read_buffer_size=131072
max_used_connections=0
max_threads=507
thread_count=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 1121757 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0x0 thread_stack 0x48000
(my_addr_resolve failure: fork)
/home/mysql/product/mariadb-10.1.9/bin/mysqld(my_print_stacktrace+0x2e) [0xbf822e]
/home/mysql/product/mariadb-10.1.9/bin/mysqld(handle_fatal_signal+0x464) [0x760e24]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x10340) [0x7f534f414340]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x39) [0x7f534dfe1cc9]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x148) [0x7f534dfe50d8]
/home/mysql/product/mariadb-10.1.9/bin/mysqld() [0xa42f7a]
/home/mysql/product/mariadb-10.1.9/bin/mysqld() [0x95552b]
/home/mysql/product/mariadb-10.1.9/bin/mysqld() [0xa307aa]
/home/mysql/product/mariadb-10.1.9/bin/mysqld() [0xa3094d]
/home/mysql/product/mariadb-10.1.9/bin/mysqld() [0x9d0a59]
/home/mysql/product/mariadb-10.1.9/bin/mysqld() [0x8fca10]
/home/mysql/product/mariadb-10.1.9/bin/mysqld(ha_initialize_handlerton(st_plugin_int*)+0x5e) [0x766eae]
/home/mysql/product/mariadb-10.1.9/bin/mysqld() [0x5c0a70]
/home/mysql/product/mariadb-10.1.9/bin/mysqld(plugin_init(int*, char**, int)+0xbd2) [0x5c27e2]
/home/mysql/product/mariadb-10.1.9/bin/mysqld() [0x51e5ae]
/home/mysql/product/mariadb-10.1.9/bin/mysqld(mysqld_main(int, char**)+0x864) [0x51f894]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf5) [0x7f534dfccec5]
/home/mysql/product/mariadb-10.1.9/bin/mysqld() [0x514879]
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
151203 17:17:01 mysqld_safe mysqld from pid file /home/mysql/data/mariadb-10.1.9/laptop4.pid ended



 Comments   
Comment by Elena Stepanova [ 2015-12-16 ]

Error 12 does indicate that the memory could not be allocated.
I suppose InnoDB could refuse to startup more nicely, although it's rather usual behavior for InnoDB to go down with assertion failures (not quite crash).
I'll leave it to jplindst to decide if it can and should be fixed somehow.

Comment by Jan Lindström (Inactive) [ 2015-12-16 ]

There is no way I can fix all possible memory allocation failures in GA product not to crash inside a InnoDB, but maybe this buffer pool over-allocation problem is feasible to be fixed. InnoDB has traditionally selected crashing when something goes wrong, not to shutdown cleanly, that change is also out of reach on GA product.

Comment by Jan Lindström (Inactive) [ 2015-12-17 ]

There is already error handling on buffer pool initialization and --innodb_buffer_pool_populate=ON would also help here.

Comment by Jan Lindström (Inactive) [ 2015-12-17 ]

Hi, Can you provide full error log and if possible use resolve_stack_dump for above addresses.

Comment by Marko Mäkelä [ 2023-04-11 ]

oli, this very old bug was just assigned to me. Can you please try to see what would happen in MariaDB Server 10.6 in this case? The buffer pool initialization was greatly simplified there. If there still is a problem, it would make a good test case for MDEV-29445.

Comment by Oli Sennhauser [ 2023-04-17 ]

Hi Marko

I tried:

  • 10.1.43: mysqld process exited properly and did NOT crash. So I consider this a good fix.
  • 10.3.20: My desktop (KDE) was completely frozen (b/c of swapping?). I would says is worse than before! No good fix.

...
2023-04-17 11:12:46 0 [Note] InnoDB: Initializing buffer pool, total size = 128G, instances = 1, chunk size = 128M
2023-04-17 11:12:50 0 [Note] InnoDB: Completed initialization of buffer pool
2023-04-17 11:14:12 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2023-04-17 11:14:36 0 [Note] InnoDB: Waiting for purge to start
2023-04-17 11:14:36 0 [Note] InnoDB: Waiting for purge to start
2023-04-17 11:14:36 0 [Note] InnoDB: Waiting for purge to start
...
2023-04-17 11:14:44 0 [Note] InnoDB: Waiting for purge to start
2023-04-17 11:14:44 0 [Note] InnoDB: Waiting for purge to start
2023-04-17 11:14:44 0 [Note] InnoDB: Waiting for purge to start
2023-04-17 11:14:44 0 [Note] InnoDB: 10.3.20 started; log sequence number 36441723646; transaction id 5124871
2023-04-17 11:14:44 0 [Note] InnoDB: Loading buffer pool(s) from /home/mysql/database/mariadb-103/data/ib_buffer_pool
2023-04-17 11:14:44 0 [Note] InnoDB: Buffer pool(s) load completed at 230417 11:14:44
...
2023-04-17 11:14:52 0 [Note] bin/mysqld: ready for connections.
Version: '10.3.20-MariaDB-log' socket: '/var/run/mysqld/mysql-3318.sock' port: 3318 MariaDB Server

  • 10.6.11: Started without any problem. No swapping, no freeze. I consider this a good solution. Long term effects of this solution I have no idea.

2023-04-17 11:29:08 0 [Note] InnoDB: Initializing buffer pool, total size = 137438953472, chunk size = 134217728
2023-04-17 11:29:09 0 [Note] InnoDB: Completed initialization of buffer pool

  • 10.11.2: Started without any problem. No swapping, no freeze. I consider this a good solution. Long term effects of this solution I have no idea.

2023-04-17 11:26:58 0 [Note] InnoDB: Initializing buffer pool, total size = 128.000GiB, chunk size = 2.000GiB
2023-04-17 11:26:58 0 [Note] InnoDB: Completed initialization of buffer pool

Thanks and Regards, Oli

Comment by Marko Mäkelä [ 2023-04-17 ]

Thank you, oli. It is possible that Linux would overcommit the memory and actually allocate it later as part of copy-on-write. That is, excessive swapping or an OOM kill could happen later when the memory is actually being used.

I will retain this ticket open for now, to be tested when we work on MDEV-29445.

Generated at Thu Feb 08 07:33:09 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.