Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-9236

Dramatically overallocation of InnoDB buffer pool leads to crash

Details

    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

      Attachments

        Issue Links

          Activity

            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.

            elenst Elena Stepanova added a comment - 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.

            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.

            jplindst Jan Lindström (Inactive) added a comment - 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.

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

            jplindst Jan Lindström (Inactive) added a comment - There is already error handling on buffer pool initialization and --innodb_buffer_pool_populate=ON would also help here.

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

            jplindst Jan Lindström (Inactive) added a comment - Hi, Can you provide full error log and if possible use resolve_stack_dump for above addresses.

            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.

            marko Marko Mäkelä added a comment - 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 .

            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

            oli Oli Sennhauser added a comment - 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

            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.

            marko Marko Mäkelä added a comment - 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 .

            People

              marko Marko Mäkelä
              oli Oli Sennhauser
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

              Dates

                Created:
                Updated:

                Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.