Bug #76852 Segmentation fault while starting MySQL with binary log in disk full Linux
Submitted: 27 Apr 2015 12:18 Modified: 10 Nov 2016 17:26
Reporter: Shahriyar Rzayev Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server Severity:S6 (Debug Builds)
Version:5.6.24 OS:Linux (CentOS 6.5)
Assigned to: CPU Architecture:Any
Tags: debug

[27 Apr 2015 12:18] Shahriyar Rzayev
Description:
Dear experts,
while testing disk full conditions there is another issue related starting MySQL with binary log/gtid in environment where no space.
Because lacking information in error log:

/opt/mysql/bin/mysqld(my_print_stacktrace+0x35)[0xaf3925]
/opt/mysql/bin/mysqld(handle_fatal_signal+0x404)[0x7491a6]
/lib64/libpthread.so.0(+0xf710)[0x7f5ebfcd0710]

Here is output from GDB:

[root@localhost error_log_dir]# gdb /opt/mysql/bin/mysqld
(gdb) run --defaults-file=/home/error_log_dir/my.cnf --basedir=/opt/mysql --datadir=/opt/mysql/datadir --plugin-dir=/opt/mysql/lib/plugin --user=mysql --log-error=/home/error_log_dir/error.err --pid-file=/home/error_log_dir/mysqld-new.pid --socket=/opt/mysql/datadir/mysqld-new.sock --port=3307

Program received signal SIGSEGV, Segmentation fault.
0x0000000000000000 in ?? ()

(gdb) bt
#0  0x0000000000000000 in ?? ()
#1  0x0000000000ae6242 in my_printf_warning (format=0x1026f08 "Disk is full writing '%s' (Errcode: %d - %s). Waiting for someone to free space...")
    at /root/mysql-5.6.24/mysys/my_error.c:260
#2  0x0000000000ac9052 in wait_for_free_space (filename=0x1fe7ee0 "/opt/mysql/datadir/mysql-bin.~rec~", errors=0) at /root/mysql-5.6.24/mysys/errors.c:115
#3  0x0000000000af1ac7 in my_write (Filedes=19, Buffer=0x1964d00 "/opt/mysql/datadir/mysql-bin.000003\n", Count=36, MyFlags=52)
    at /root/mysql-5.6.24/mysys/my_write.c:89
#4  0x0000000000acd5ae in inline_mysql_file_write (src_file=0x1027708 "/root/mysql-5.6.24/mysys/mf_iocache.c", src_line=1788, file=19, 
    buffer=0x1964d00 "/opt/mysql/datadir/mysql-bin.000003\n", count=36, flags=52) at /root/mysql-5.6.24/include/mysql/psi/mysql_file.h:1141
#5  0x0000000000ad078c in my_b_flush_io_cache (info=0x183c1a8, need_append_buffer_lock=0) at /root/mysql-5.6.24/mysys/mf_iocache.c:1787
#6  0x0000000000a7132b in MYSQL_BIN_LOG::sync_purge_index_file (this=0x183b400) at /root/mysql-5.6.24/sql/binlog.cc:4420
#7  0x0000000000a6e206 in MYSQL_BIN_LOG::open_binlog (this=0x183b400, log_name=0x190d130 "/opt/mysql/datadir/mysql-bin", new_name=0x0, 
    io_cache_type_arg=WRITE_CACHE, max_size_arg=1073741824, null_created_arg=false, need_lock_index=true, need_sid_lock=true, extra_description_event=0x0)
    at /root/mysql-5.6.24/sql/binlog.cc:3146
#8  0x000000000063ad8e in init_server_components () at /root/mysql-5.6.24/sql/mysqld.cc:5012
#9  0x000000000063b6e7 in mysqld_main (argc=19, argv=0x186de68) at /root/mysql-5.6.24/sql/mysqld.cc:5455
#10 0x000000000062fc74 in main (argc=10, argv=0x7fffffffe3d8) at /root/mysql-5.6.24/sql/main.cc:25

How to repeat:
Try to start MySQL with enable gtid/binary log in disk full environment...

Suggested fix:
Prevent starting MySQL if it is no space left on disk.
[27 Apr 2015 12:19] Shahriyar Rzayev
bt full output from gdb

Attachment: bt_full.txt (text/plain), 6.09 KiB.

[27 Apr 2015 12:39] MySQL Verification Team
Thank you for the report.
Observed this with 5.6.24 debug build when partition was full and tried to start server.

Core was generated by `bin/mysqld-debug --no-defaults --basedir=/data/ushastry/server/mysql-5.6.24 --d'.
Program terminated with signal 11, Segmentation fault.
#0  0x0000003d5a80c8ac in pthread_kill () from /lib64/libpthread.so.0
Missing separate debuginfos, use: debuginfo-install glibc-2.12-1.149.el6_6.5.x86_64 libaio-0.3.107-10.el6.x86_64 libgcc-4.4.7-11.el6.x86_64 libstdc++-4.4.7-11.el6.x86_64 nss-softokn-freebl-3.14.3-22.el6_6.x86_64
(gdb) bt
#0  0x0000003d5a80c8ac in pthread_kill () from /lib64/libpthread.so.0
#1  0x0000000000b01fd3 in my_write_core (sig=11) at /pb2/build/sb_0-14307455-1422989245.13/mysqlcom-pro-5.6.24/mysys/stacktrace.c:422
#2  0x0000000000780070 in handle_fatal_signal (sig=11) at /pb2/build/sb_0-14307455-1422989245.13/mysqlcom-pro-5.6.24/sql/signal_handler.cc:230
#3  <signal handler called>
#4  0x0000000000000000 in ?? ()
#5  0x0000000000af91a0 in my_printf_warning (format=0x10f9c68 "Disk is full writing '%s' (Errcode: %d - %s). Waiting for someone to free space...")
    at /pb2/build/sb_0-14307455-1422989245.13/mysqlcom-pro-5.6.24/mysys/my_error.c:260
#6  0x0000000000ae0f7c in wait_for_free_space (filename=0x28f7130 "./binlog.~rec~", errors=0) at /pb2/build/sb_0-14307455-1422989245.13/mysqlcom-pro-5.6.24/mysys/errors.c:115
#7  0x0000000000b005f1 in my_write (Filedes=14, Buffer=0x2fc3b40 "./binlog.000005\n0;\374\002", Count=16, MyFlags=52)
    at /pb2/build/sb_0-14307455-1422989245.13/mysqlcom-pro-5.6.24/mysys/my_write.c:89
#8  0x0000000000ae4075 in inline_mysql_file_write (src_file=0x10fa520 "/pb2/build/sb_0-14307455-1422989245.13/mysqlcom-pro-5.6.24/mysys/mf_iocache.c", src_line=1788, file=14,
    buffer=0x2fc3b40 "./binlog.000005\n0;\374\002", count=16, flags=52) at /pb2/build/sb_0-14307455-1422989245.13/mysqlcom-pro-5.6.24/include/mysql/psi/mysql_file.h:1141
#9  0x0000000000ae713f in my_b_flush_io_cache (info=0x19a10a8, need_append_buffer_lock=0) at /pb2/build/sb_0-14307455-1422989245.13/mysqlcom-pro-5.6.24/mysys/mf_iocache.c:1787
#10 0x0000000000a8eaa9 in MYSQL_BIN_LOG::sync_purge_index_file (this=0x19a0500) at /pb2/build/sb_0-14307455-1422989245.13/mysqlcom-pro-5.6.24/sql/binlog.cc:4420
#11 0x0000000000a8bb9b in MYSQL_BIN_LOG::open_binlog (this=0x19a0500, log_name=0x28a7700 "binlog", new_name=0x0, io_cache_type_arg=WRITE_CACHE, max_size_arg=1073741824, null_created_arg=false,
    need_lock_index=true, need_sid_lock=true, extra_description_event=0x0) at /pb2/build/sb_0-14307455-1422989245.13/mysqlcom-pro-5.6.24/sql/binlog.cc:3146
#12 0x000000000067757d in init_server_components () at /pb2/build/sb_0-14307455-1422989245.13/mysqlcom-pro-5.6.24/sql/mysqld.cc:5008
#13 0x0000000000677ebd in mysqld_main (argc=40, argv=0x2808fd8) at /pb2/build/sb_0-14307455-1422989245.13/mysqlcom-pro-5.6.24/sql/mysqld.cc:5449
#14 0x000000000066cf74 in main (argc=40, argv=0x7fff0572d5d8) at /pb2/build/sb_0-14307455-1422989245.13/mysqlcom-pro-5.6.24/sql/main.cc:25
(gdb)
[18 Jan 2016 7:41] Shahriyar Rzayev
Changed Category
[9 Nov 2016 17:54] OCA Admin
Contribution submitted via Github - Bug #76852 - Segmentation fault while starting MySQL with binary log in disk ful 
(*) Contribution by Shahriyar Rzayev (Github ShahriyarR, mysql-server/pull/109#issuecomment-259478172): I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it.

Contribution: git_patch_92908928.txt (text/plain), 6.96 KiB.

[10 Nov 2016 17:26] Shahriyar Rzayev
By mistake my IDE added new lines or did something wrong and there are too many changes appeared on patch.
Exact changes:

@@ -4663,6 +4663,8 @@ static int init_server_components()
     We need to call each of these following functions to ensure that
     all things are initialized so that unireg_abort() doesn't fail
   */
+  sql_print_warning_hook = sql_print_warning;
+
   mdl_init();
   if (table_def_init() | hostname_cache_init(host_cache_size))
     unireg_abort(1);
@@ -5486,7 +5488,7 @@ int mysqld_main(int argc, char **argv)
 #endif
   }
 
-  /* 
+  /*
    The subsequent calls may take a long time : e.g. innodb log read.
    Thus set the long running service control manager timeout
   */
@@ -5596,7 +5598,7 @@ int mysqld_main(int argc, char **argv)
   */
   error_handler_hook= my_message_sql;
   start_signal_handler();       // Creates pidfile
-  sql_print_warning_hook = sql_print_warning;
+

diff --git a/mysys/my_error.c b/mysys/my_error.c
index b1f57ba..4441228 100644
--- a/mysys/my_error.c
+++ b/mysys/my_error.c
@@ -257,7 +257,14 @@ void my_printf_warning(const char *format, ...)
   va_start(args,format);
   (void) my_vsnprintf (wbuff, sizeof(wbuff), format, args);
   va_end(args);
-  (*sql_print_warning_hook)(wbuff);
+  if(sql_print_warning_hook)
+  {
+    (*sql_print_warning_hook)(wbuff);
+  }
+  else
+  {
+    fprintf(stderr, "%s\n", wbuff);
+  }
   DBUG_VOID_RETURN;
 }
[29 Sep 2017 8:02] Ståle Deraas
Thank you for the contribution Shahriyar. Since there has been quite a lot of code changes in the area in newer releases, we will work a bit more on your contribution, before pushing it.