Bug #94096 Setting the innodb-log-buffer-size to a big value leads to crash during startup
Submitted: 28 Jan 2019 10:47 Modified: 28 Jan 2019 10:59
Reporter: Hrvoje Matijakovic Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S3 (Non-critical)
Version:5.6.43 OS:Linux
Assigned to: CPU Architecture:x86

[28 Jan 2019 10:47] Hrvoje Matijakovic
Description:
error_log output:

2019-01-28 05:32:24 11860 [Note] Plugin 'FEDERATED' is disabled.
2019-01-28 05:32:24 11860 [Note] InnoDB: Using atomics to ref count buffer pool pages
2019-01-28 05:32:24 11860 [Note] InnoDB: The InnoDB memory heap is disabled
2019-01-28 05:32:24 11860 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2019-01-28 05:32:24 11860 [Note] InnoDB: Memory barrier is not used
2019-01-28 05:32:24 11860 [Note] InnoDB: Compressed tables use zlib 1.2.7
2019-01-28 05:32:24 11860 [Note] InnoDB: Using Linux native AIO
2019-01-28 05:32:24 11860 [Note] InnoDB: Using CPU crc32 instructions
2019-01-28 05:32:24 11860 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2019-01-28 05:32:24 11860 [Note] InnoDB: Completed initialization of buffer pool
2019-01-28 05:32:24 11860 [ERROR] InnoDB:  InnoDB: Unable to allocate memory of size 1125899906843240.

2019-01-28 05:32:24 7f50de2388c0  InnoDB: Assertion failure in thread 139985300981952 in file ha_innodb.cc line 17437
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.
10:32:24 UTC - 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.
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.

key_buffer_size=8388608
read_buffer_size=131072
max_used_connections=0
max_threads=151
thread_count=0
connection_count=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 68108 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x0
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 = 0 thread_stack 0x40000
/sdc/MS240119-mysql-5.6.43-linux-x86_64-opt/bin/mysqld(my_print_stacktrace+0x2c)[0x8c9f1c]
/sdc/MS240119-mysql-5.6.43-linux-x86_64-opt/bin/mysqld(handle_fatal_signal+0x491)[0x662821]
/lib64/libpthread.so.0(+0xf5d0)[0x7f50ddbee5d0]
/lib64/libc.so.6(gsignal+0x37)[0x7f50dbef7207]
/lib64/libc.so.6(abort+0x148)[0x7f50dbef88f8]
/sdc/MS240119-mysql-5.6.43-linux-x86_64-opt/bin/mysqld[0x980318]
/sdc/MS240119-mysql-5.6.43-linux-x86_64-opt/bin/mysqld[0x9b999f]
/sdc/MS240119-mysql-5.6.43-linux-x86_64-opt/bin/mysqld[0x9ae1e6]
/sdc/MS240119-mysql-5.6.43-linux-x86_64-opt/bin/mysqld[0xa2d6da]
/sdc/MS240119-mysql-5.6.43-linux-x86_64-opt/bin/mysqld[0x973198]
/sdc/MS240119-mysql-5.6.43-linux-x86_64-opt/bin/mysqld(_Z24ha_initialize_handlertonP13st_plugin_int+0x48)[0x5afc18]
/sdc/MS240119-mysql-5.6.43-linux-x86_64-opt/bin/mysqld[0x6e7291]
/sdc/MS240119-mysql-5.6.43-linux-x86_64-opt/bin/mysqld(_Z11plugin_initPiPPci+0x740)[0x6ed410]
/sdc/MS240119-mysql-5.6.43-linux-x86_64-opt/bin/mysqld[0x5a7c18]
/sdc/MS240119-mysql-5.6.43-linux-x86_64-opt/bin/mysqld(_Z11mysqld_mainiPPc+0x41b)[0x5a8b7b]
/lib64/libc.so.6(__libc_start_main+0xf5)[0x7f50dbee33d5]
/sdc/MS240119-mysql-5.6.43-linux-x86_64-opt/bin/mysqld[0x59c4d5]
"/dev/shm/1548670949/error.log.out" 63L, 3728C

I'm able to reproduce this with both debug and opt builds.

gdb output from the debug build:
(gdb) bt
+bt
#0  0x00007f8122e3e9d1 in __pthread_kill (threadid=<optimized out>, signo=6) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:59
#1  0x0000000000aabb5a in my_write_core (sig=6) at /home/hrvoje/worktable/MS-5.6.43_dbg/mysys/stacktrace.c:424
#2  0x000000000073b7da in handle_fatal_signal (sig=6) at /home/hrvoje/worktable/MS-5.6.43_dbg/sql/signal_handler.cc:230
#3  <signal handler called>
#4  0x00007f812114a207 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:55
#5  0x00007f812114b8f8 in __GI_abort () at abort.c:90
#6  0x0000000000b9f7cf in ib_logf (level=IB_LOG_LEVEL_FATAL, format=0xfb6240 " InnoDB: Unable to allocate memory of size %lu.\n") at /home/hrvoje/worktable/MS-5.6.43_dbg/storage/innobase/handler/ha_innodb.cc:17437
#7  0x0000000000bfd566 in mem_heap_create_block_func (heap=0x0, n=1125899906843136, file_name=0xfb29a8 "/home/hrvoje/worktable/MS-5.6.43_dbg/storage/innobase/log/log0log.cc", line=861, type=0) at /home/hrvoje/worktable/MS-5.6.43_dbg/storage/innobase/mem/mem0mem.cc:362
#8  0x0000000000bed2c5 in mem_heap_create_func (n=1125899906843136, file_name=0xfb29a8 "/home/hrvoje/worktable/MS-5.6.43_dbg/storage/innobase/log/log0log.cc", line=861, type=0) at /home/hrvoje/worktable/MS-5.6.43_dbg/storage/innobase/include/mem0mem.ic:449
#9  0x0000000000bed3ee in mem_alloc_func (n=1125899906843136, file_name=0xfb29a8 "/home/hrvoje/worktable/MS-5.6.43_dbg/storage/innobase/log/log0log.cc", line=861, size=0x0) at /home/hrvoje/worktable/MS-5.6.43_dbg/storage/innobase/include/mem0mem.ic:537
#10 0x0000000000beea17 in log_init () at /home/hrvoje/worktable/MS-5.6.43_dbg/storage/innobase/log/log0log.cc:861
#11 0x0000000000ccb3f9 in innobase_start_or_create_for_mysql () at /home/hrvoje/worktable/MS-5.6.43_dbg/storage/innobase/srv/srv0start.cc:2035
#12 0x0000000000b8a0be in innobase_init (p=0x7f81067d4f00) at /home/hrvoje/worktable/MS-5.6.43_dbg/storage/innobase/handler/ha_innodb.cc:3445
#13 0x000000000064cbc0 in ha_initialize_handlerton (plugin=0x7f81067eee78) at /home/hrvoje/worktable/MS-5.6.43_dbg/sql/handler.cc:662
#14 0x00000000007f995c in plugin_initialize (plugin=0x7f81067eee78) at /home/hrvoje/worktable/MS-5.6.43_dbg/sql/sql_plugin.cc:1138
#15 0x00000000007fa3b6 in plugin_init (argc=0x174a528 <remaining_argc>, argv=0x7f811f01c8c0, flags=0) at /home/hrvoje/worktable/MS-5.6.43_dbg/sql/sql_plugin.cc:1432
#16 0x00000000006367d3 in init_server_components () at /home/hrvoje/worktable/MS-5.6.43_dbg/sql/mysqld.cc:4886
#17 0x00000000006376ac in mysqld_main (argc=11, argv=0x7f811f01c8c0) at /home/hrvoje/worktable/MS-5.6.43_dbg/sql/mysqld.cc:5487
#18 0x000000000062cb26 in main (argc=11, argv=0x7ffdd29410d8) at /home/hrvoje/worktable/MS-5.6.43_dbg/sql/main.cc:25

How to repeat:
Start the service with:  --innodb-log-buffer-size=1125899906842624
[28 Jan 2019 10:59] Umesh Shastry
Hello Hrvoje,

Thank you for the report.
Imho this is duplicate of Bug #91956, please see Bug #91956

regards,
Umesh