Bug #77564 SIGABRT during resizing the InnoDB Buffer Pool Online with memory full condition
Submitted: 30 Jun 2015 11:49 Modified: 16 Jun 2016 6:32
Reporter: Shahriyar Rzayev (OCA) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S1 (Critical)
Version:5.7.7-rc, 5.7.8, 5.7.12 OS:CentOS (7)
Assigned to: CPU Architecture:Any

[30 Jun 2015 11:49] Shahriyar Rzayev
Description:
Testing resizing InnoDB Buffer Pool online with 5.7.7-rc.

Started as:

(gdb) run --defaults-file=/opt/mysql/my.cnf --basedir=/opt/mysql --datadir=/opt/mysql/datadir --plugin-dir=/opt/mysql/lib/plugin --user=mysql --log-error=/opt/mysql/datadir/centos7-1_vm.err --pid-file=/opt/mysql/datadir/mysqld-new.pid --socket=/opt/mysql/datadir/mysqld-new.sock --port=3306

Then tried to change buffer pool size several times:

mysql> SET @@GLOBAL.innodb_buffer_pool_size=9556544565345346;
Query OK, 0 rows affected, 2 warnings (0.00 sec)

After few attempts it will stuck with:

Program received signal SIGABRT, Aborted.
[Switching to Thread 0x7fffb77f6700 (LWP 17145)]
0x00007ffff61675d7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
56	  return INLINE_SYSCALL (tgkill, 3, pid, selftid, sig);

(gdb) bt
#0  0x00007ffff61675d7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#1  0x00007ffff6168cc8 in __GI_abort () at abort.c:90
#2  0x0000000001adbe0f in ut_dbg_assertion_failed (expr=0x0, file=0x21956d8 "/root/mysql-5.7.7-rc/storage/innobase/ut/ut0ut.cc", line=906)
    at /root/mysql-5.7.7-rc/storage/innobase/ut/ut0dbg.cc:67
#3  0x0000000001ae123e in ib::fatal::~fatal (this=0x7fffb77f49e0, __in_chrg=<optimized out>) at /root/mysql-5.7.7-rc/storage/innobase/ut/ut0ut.cc:906
#4  0x00000000018f18e8 in ut_allocator<unsigned char>::allocate (this=0x7fffb77f4ba0, n_elements=14238670808, hint=0x0, 
    file=0x21cbb10 "/root/mysql-5.7.7-rc/storage/innobase/ha/hash0hash.cc", set_to_zero=false, throw_on_error=false)
    at /root/mysql-5.7.7-rc/storage/innobase/include/ut0new.h:328
#5  0x0000000001bed775 in hash0_create (n=1756528640) at /root/mysql-5.7.7-rc/storage/innobase/ha/hash0hash.cc:284
#6  0x000000000194769d in lock_sys_resize (n_cells=1756528640) at /root/mysql-5.7.7-rc/storage/innobase/lock/lock0lock.cc:478
#7  0x0000000001b3dce1 in buf_pool_resize () at /root/mysql-5.7.7-rc/storage/innobase/buf/buf0buf.cc:2669
#8  0x0000000001b3e0f5 in buf_resize_thread (arg=0x0) at /root/mysql-5.7.7-rc/storage/innobase/buf/buf0buf.cc:2749
#9  0x00007ffff7bc6df5 in start_thread (arg=0x7fffb77f6700) at pthread_create.c:308
#10 0x00007ffff62281ad in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

(gdb) bt full
#0  0x00007ffff61675d7 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
        resultvar = 0
        pid = 17122
        selftid = 17145
#1  0x00007ffff6168cc8 in __GI_abort () at abort.c:90
        save_stage = 2
        act = {__sigaction_handler = {sa_handler = 0x2195701, sa_sigaction = 0x2195701}, sa_mask = {__val = {140736271960400, 61282656, 140737351975648, 
              140737325748672, 35212440, 404, 140737322325519, 140736271968000, 140737325748672, 1, 404, 0, 18446744073709551456, 0, 140737325754896, 
              140737325749248}}, sa_flags = -1216387328, sa_restorer = 0x2194c98}
        sigs = {__val = {32, 0 <repeats 15 times>}}
#2  0x0000000001adbe0f in ut_dbg_assertion_failed (expr=0x0, file=0x21956d8 "/root/mysql-5.7.7-rc/storage/innobase/ut/ut0ut.cc", line=906)
    at /root/mysql-5.7.7-rc/storage/innobase/ut/ut0dbg.cc:67
No locals.
#3  0x0000000001ae123e in ib::fatal::~fatal (this=0x7fffb77f49e0, __in_chrg=<optimized out>) at /root/mysql-5.7.7-rc/storage/innobase/ut/ut0ut.cc:906
No locals.
#4  0x00000000018f18e8 in ut_allocator<unsigned char>::allocate (this=0x7fffb77f4ba0, n_elements=14238670808, hint=0x0, 
    file=0x21cbb10 "/root/mysql-5.7.7-rc/storage/innobase/ha/hash0hash.cc", set_to_zero=false, throw_on_error=false)
    at /root/mysql-5.7.7-rc/storage/innobase/include/ut0new.h:328
        ptr = 0x0
        total_bytes = 14238670824
        pfx = 0x38120d0
#5  0x0000000001bed775 in hash0_create (n=1756528640) at /root/mysql-5.7.7-rc/storage/innobase/ha/hash0hash.cc:284
        array = 0x198b73c <os_thread_get_curr_id()+9>
        prime = 1779833851
        table = 0x38120e0
#6  0x000000000194769d in lock_sys_resize (n_cells=1756528640) at /root/mysql-5.7.7-rc/storage/innobase/lock/lock0lock.cc:478
        old_hash = 0x3845e20
#7  0x0000000001b3dce1 in buf_pool_resize () at /root/mysql-5.7.7-rc/storage/innobase/buf/buf0buf.cc:2669
        retry_interval = 1
        should_retry_withdraw = false
        chunk_map_old = 0x2e12140
        buf_pool = 0x2e11ac0
        withdraw_started = 1435663352
        new_instance_size = 351305728
        warning = true
        btr_search_disabled = true
        message_interval = 60
        now = '\000' <repeats 31 times>
#8  0x0000000001b3e0f5 in buf_resize_thread (arg=0x0) at /root/mysql-5.7.7-rc/storage/innobase/buf/buf0buf.cc:2749
No locals.
---Type <return> to continue, or q <return> to quit---
#9  0x00007ffff7bc6df5 in start_thread (arg=0x7fffb77f6700) at pthread_create.c:308
        __res = <optimized out>
        pd = 0x7fffb77f6700
        now = <optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140736271968000, -1468125053445450988, 1, 140736271968704, 140736271968000, 0, 1467965621093815060, 
                1468106898156966676}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
        not_first_call = <optimized out>
        pagesize_m1 = <optimized out>
        sp = <optimized out>
        freesize = <optimized out>
#10 0x00007ffff62281ad in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113
No locals.

How to repeat:
1. Install MySQL 5.7.7-rc from source with debug enabled
2. Start MySQL
3. Create full disk condition
4. Try to resize innodb buffer pool size several times.

Suggested fix:
Preventing resizing innodb buffer pool size after getting disk full error.
[30 Jun 2015 13:12] Umesh Shastry
Hello Shahriyar,

Thank you for the report.

Thanks,
Umesh
[1 Jul 2015 5:54] Shane Bester
I think the reporter means "memory full condition" instead of disk full.
  

[Note] InnoDB: Resizing buffer pool from 134217728 to 9556544630816768. (unit=134217728)
[Note] InnoDB: disabled adaptive hash index.
[Note] InnoDB: VirtualAlloc(140771328 bytes) failed; Windows error 1455
[ERROR] InnoDB: buffer pool 0 : failed to allocate new memory.
[Note] InnoDB: buffer pool 0 : 745 chunks (6103040 blocks) were added.
[Note] InnoDB: buffer pool 0 : hash tables were resized.
[Note] InnoDB: page_cleaner: 1000ms intended loop took 200645ms. The settings might not be optimal. (flushed=0 and evicted=0, during the time.)
[ERROR] [FATAL] InnoDB: Cannot allocate 23640961911088 bytes of memory after 60 retries over 60 seconds. OS error: Not enough space (12). Check if you should increase the swap file or ulimits of your operating system. Note that on most 32-bit computers the process memory space is limited to 2 GB or 4 GB.
noDB: Assertion failure in thread 9288 in file ut0ut.cc line 908
ate a memory trap.

mysqld-debug.exe!my_sigabrt_handler()[my_thr_init.c:364]
mysqld-debug.exe!raise()[winsig.c:594]
mysqld-debug.exe!abort()[abort.c:82]
mysqld-debug.exe!ut_dbg_assertion_failed()[ut0dbg.cc:68]
mysqld-debug.exe!ib::fatal::~fatal()[ut0ut.cc:908]
mysqld-debug.exe!ut_allocator<unsigned char>::allocate()[ut0new.h:345]
mysqld-debug.exe!hash0_create()[hash0hash.cc:119]
mysqld-debug.exe!lock_sys_resize()[lock0lock.cc:480]
mysqld-debug.exe!buf_pool_resize()[buf0buf.cc:2272]
mysqld-debug.exe!buf_resize_thread()[buf0buf.cc:2349]
[1 Jul 2015 6:03] Shahriyar Rzayev
Thanks Shane Bester for correction.
[7 Aug 2015 12:30] Daniel Price
Posted by developer:
 
Fixed as of the upcoming 5.7.9, 5.8.0 releases, and here's the changelog entry:

Resizing the buffer pool online raised an assertion due to a memory full
condition. 

Thank you for the bug report.
[27 May 2016 10:47] Shahriyar Rzayev
Reproducible with MySQL 5.7.12.
Reopening report with following assertion:

mysql> set global innodb_buffer_pool_size = 107374182400;
Query OK, 0 rows affected (0.01 sec)

2016-05-27T10:40:04.591868Z 4 [Note] InnoDB: Requested to resize buffer pool. (new size: 107374182400 bytes)
2016-05-27T10:40:04.592028Z 0 [Note] InnoDB: Resizing buffer pool from 134217728 to 107374182400 (unit=134217728).
2016-05-27T10:40:04.592040Z 0 [Note] InnoDB: Disabling adaptive hash index.
2016-05-27T10:40:04.592292Z 0 [Note] InnoDB: disabled adaptive hash index.
2016-05-27T10:40:04.592300Z 0 [Note] InnoDB: Withdrawing blocks to be shrunken.
2016-05-27T10:40:04.592305Z 0 [Note] InnoDB: Latching whole of buffer pool.
2016-05-27T10:40:04.592314Z 0 [Note] InnoDB: buffer pool 0 : resizing with chunks 1 to 800.
2016-05-27T10:40:06.117508Z 0 [Note] InnoDB: buffer pool 0 : 799 chunks (1636352 blocks) were added.
2016-05-27T10:40:06.124857Z 0 [Note] InnoDB: Resizing hash tables.
2016-05-27T10:40:06.351233Z 0 [Note] InnoDB: buffer pool 0 : hash tables were resized.
2016-05-27T10:40:06.416695Z 0 [Note] InnoDB: Resizing also other hash tables.
2016-05-27T10:41:09.861017Z 0 [ERROR] InnoDB: Cannot allocate 212498768 bytes of memory after 60 retries over 60 seconds. OS error: Cannot allocate memory (12). Check if you should increase the swap file or ulimits of your operating system. Note that on most 32-bit computers the process memory space is limited to 2 GB or 4 GB.
2016-05-27 14:41:09 0x7f75927fc700  InnoDB: Assertion failure in thread 140142945748736 in file ut0ut.cc line 935
InnoDB: Failing assertion: !m_fatal
InnoDB: We intentionally generate a memory trap.

/usr/sbin/mysqld(my_print_stacktrace+0x3b)[0xef0a4b]
/usr/sbin/mysqld(handle_fatal_signal+0x461)[0x7aef91]
/lib64/libpthread.so.0(+0xf100)[0x7f75f1ada100]
/lib64/libc.so.6(gsignal+0x37)[0x7f75f04ce5f7]
/lib64/libc.so.6(abort+0x148)[0x7f75f04cfce8]
/usr/sbin/mysqld[0x77f3ee]
/usr/sbin/mysqld(ib::fatal_or_error::~fatal_or_error()+0x2f8)[0x10c5ba8]
/usr/sbin/mysqld[0x11b1e46]
/usr/sbin/mysqld(hash0_create(unsigned long)+0x63)[0x11b2f73]
/usr/sbin/mysqld(ib_create(unsigned long, latch_id_t, unsigned long, unsigned long)+0x41)[0x11b0411]
/usr/sbin/mysqld(btr_search_sys_resize(unsigned long)+0x1d1)[0x10f0ec1]
/usr/sbin/mysqld(buf_pool_resize()+0xcfc)[0x110ccfc]
/usr/sbin/mysqld(buf_resize_thread+0x197)[0x110e5a7]
/lib64/libpthread.so.0(+0x7dc5)[0x7f75f1ad2dc5]
/lib64/libc.so.6(clone+0x6d)[0x7f75f058f28d]
[16 Jun 2016 6:32] Erlend Dahl
Shahriyar,

please file a new bug. It's usually not advisable to latch on to an old report that has been closed, since it won't get proper attention.

Regards,

Erlend Dahl
Release Manager MySQL Server 8.0
[7 Jul 2016 22:03] Roel Van de Paar
See http://bugs.mysql.com/bug.php?id=81654
[21 Jul 2016 3:15] Roel Van de Paar
http://bugs.mysql.com/bug.php?id=82301