Testing MySQL 5.7.7-rc with memory and disc full conditions

With MySQL 5.7 there will be many improvements and changes. The most valuable ones are:

1. “General Tablespace” feature -> From now you can place tables to separate tablespaces. Prior, on our hands there were only “System TableSpace” and “InnoDB file per table” options.

Check for further reading: General Tablespaces Create statement: Create TableSpace

2. Resizing InnoDB Buffer Pool online -> for changing innodb_buffer_pool_size variable restart is required prior to MySQL 5.7, from now we can change buffer pool size without restart dynamically. Read Documentation -> innodb-buffer-pool-online-resize

To break this new things, we need to create some conditions where Memory or Disc will be full. Firstly let’s try to resize innodb buffer pool size without having sufficient memory.

Note: MySQL installation: debug enabled

Started MySQL 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 try to resize:

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 SIGABRT signal:

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

See Related verified BUG report -> #77564

How about creating “General Tablespace” if there is no free disk space? Again started with:

[root@centos7_vm ~]# gdb /opt/mysql/bin/mysqld
(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_vm.err --pid-file=/opt/mysql/datadir/mysqld-new.pid --socket=/opt/mysql/datadir/mysqld-new.sock --port=3306

Try to run create tablespace:

mysql> CREATE TABLESPACE `ts2` ADD DATAFILE 'ts2.ibd' Engine=InnoDB;

In error log there is some mention about full disk:

2015-06-30T05:34:41.379790Z 2 [ERROR] InnoDB: Encountered a problem with file ./ts2.ibd
2015-06-30T05:34:41.379865Z 2 [ERROR] InnoDB: Disk is full. Try to clean the disk to free space.
2015-06-30T05:34:41.379910Z 2 [ERROR] InnoDB: Operating system error number 28 in a file operation.
2015-06-30T05:34:41.379937Z 2 [ERROR] InnoDB: Error number 28 means 'No space left on device'.
2015-06-30T05:34:41.379952Z 2 [Note] InnoDB: Some operating system error numbers are described at http://dev.mysql.com/doc/refman/5.7/en/operating-system-error-codes.html
2015-06-30T05:34:41.393247Z 2 [ERROR] InnoDB: Cannot create file './ts2.ibd'

From GDB we will see SIGSEGV signal:

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7fffddf7e700 (LWP 2787)]
__strnlen_sse2 () at ../sysdeps/x86_64/strnlen.S:34
34      pcmpeqb (%rdi), %xmm2

    (gdb) bt
#0  __strnlen_sse2 () at ../sysdeps/x86_64/strnlen.S:34
#1  0x0000000001dc18f2 in process_str_arg (cs=0x2ba3ea0 <my_charset_utf8_general_ci>, to=0x7fffddf7bfdb "02", end=0x7fffddf7c1cf "", width=192, 
    par=0x1 <Address 0x1 out of bounds>, print_type=0) at /root/mysql-5.7.7-rc/strings/my_vsnprintf.c:194
#2  0x0000000001dc32e6 in my_vsnprintf_ex (cs=0x2ba3ea0 <my_charset_utf8_general_ci>, to=0x7fffddf7bfdb "02", n=512, fmt=0x2d32a12 "s' is full", 
    ap=0x7fffddf7c1d0) at /root/mysql-5.7.7-rc/strings/my_vsnprintf.c:607
#3  0x000000000189d0e9 in my_error (nr=135, MyFlags=0) at /root/mysql-5.7.7-rc/mysys/my_error.c:206
    #4  0x0000000001622428 in mysql_alter_tablespace (thd=0x7fffcc000e20, ts_info=0x7fffcc022080) at /root/mysql-5.7.7-rc/sql/sql_tablespace.cc:191
#5  0x000000000158e104 in mysql_execute_command (thd=0x7fffcc000e20) at /root/mysql-5.7.7-rc/sql/sql_parse.cc:4432
#6  0x000000000158ff62 in mysql_parse (thd=0x7fffcc000e20, parser_state=0x7fffddf7d5a0) at /root/mysql-5.7.7-rc/sql/sql_parse.cc:5159
#7  0x0000000001585cf1 in dispatch_command (command=COM_QUERY, thd=0x7fffcc000e20, 
packet=0x7fffcc006f71 "CREATE TABLESPACE `ts2` ADD DATAFILE 'ts2.ibd' Engine=InnoDB", packet_length=60) at /root/mysql-5.7.7-rc/sql/sql_parse.cc:1249
#8  0x0000000001584b21 in do_command (thd=0x7fffcc000e20) at /root/mysql-5.7.7-rc/sql/sql_parse.cc:835
#9  0x00000000016adcff in handle_connection (arg=0x3c92060) at /root/mysql-5.7.7-rc/sql/conn_handler/connection_handler_per_thread.cc:298
#10 0x0000000001cd9905 in pfs_spawn_thread (arg=0x3b4dcd0) at /root/mysql-5.7.7-rc/storage/perfschema/pfs.cc:2147
#11 0x00007ffff7bc6df5 in start_thread (arg=0x7fffddf7e700) at pthread_create.c:308
#12 0x00007ffff62281ad in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

Related BUG report -> #77556

If you have you own test cases, please share it.

Audit MySQL? no just Crash it :)

Auditing maybe the main part of a corporate structure that wants to know everything. Searching for MySQL auditing plugins we come up to 3 known plugins: 1. MySQL Enterprise Audit (Official one from Oracle) – commercial 2. MariaDB audit plugin for MySQL (version 1.1.6) – free 3. McAfee MySQL audit plugin – free
With a great happiness tried to test this plugins. But wait i don’t want to crash my MySQL just want to install and use these plugins. Let’s begin with MariaDB audit plugin for MySQL — at this time the latest version is 1.1.6 With a great effort in SkySQL site they provide us with a tutorial of how to activate this plugin. Check it: SkySQL Tutorial about Plugin Followed all instructions from tutorial and got a crash of MySQL 5.6.17. So there was an error messages with 2 statement:

    INSTALL PLUGIN server_audit SONAME 'server_audit.so';
    ERROR 2013 (HY000): Lost connection to MySQL server during query 

And

    SET GLOBAL server_audit_logging=ON; 
    ERROR 2013 (HY000): Lost connection to MySQL server during query 

From Web APP side the error message is something more interesting:

    SQLSTATE[HY000] [2013] Lost connection to MySQL server at 'reading initial communication packet',

This is a same error message that we saw after Errcode: 28 – No space left on device.
Reported but still waiting as open 🙂 — 72437.

So The State of my server is very critical and actually i lost my lovely MySQL 😦 Killed all mysql processes. Restarted MySQL looked at error log and here you are:

Version: '5.6.17-log' socket: '/var/lib/mysql/mysql.sock' port: 3306 MySQL Community Server (GPL) 140430 11:21:52 server_audit: MariaDB Audit Plugin version 1.1.6 STARTED. 06:21:52 UTC - mysqld got signal 11 ; . . . Thread pointer: 0x18428270 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 = 7f63a0d78e18 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x35)[0x8d6475]
/usr/sbin/mysqld(handle_fatal_signal+0x4a4)[0x663084]
/lib64/libpthread.so.0[0x385780f500] /lib64/libc.so.6[0x3a2173259f]
/usr/sbin/mysqld[0xabdd60] /usr/sbin/mysqld[0xabe0a0]
/usr/lib64/mysql/plugin/server_audit.so(logger_open+0x10b)[0x7f639bdf806b]
/usr/lib64/mysql/plugin/server_audit.so(+0x4202)[0x7f639bdf8202]
/usr/lib64/mysql/plugin/server_audit.so(+0x5ccf)[0x7f639bdf9ccf]
/usr/sbin/mysqld(_Z23initialize_audit_pluginP13st_plugin_int+0x4d)[0x68f6ad]
/usr/sbin/mysqld[0x6ea481]
/usr/sbin/mysqld(_Z20mysql_install_pluginP3THDPK19st_mysql_lex_stringS3_+0x43f)[0x6eee7f] /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0xf04)[0x6deb14]
/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x32f)[0x6e2b3f]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x140b)[0x6e403b] 
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0xcf)[0x6b0f3f]
/usr/sbin/mysqld(handle_one_connection+0x47)[0x6b1067]
/usr/sbin/mysqld(pfs_spawn_thread+0x12a)[0xabd8da]
/lib64/libpthread.so.0[0x3857807851] /lib64/libc.so.6(clone+0x6d)[0x3a216e811d] . . . 
    2014-04-30 11:21:54 19033 [Note] InnoDB: Starting crash recovery.
    2014-04-30 11:21:54 19033 [Note] InnoDB: Reading tablespace information from the .ibd files... 
    2014-04-30 11:21:55 19033 [Note] InnoDB: Restoring possible half-written data pages 2014-04-30 11:21:55 19033 [Note] InnoDB: from the doublewrite buffer... InnoDB: Doing recovery: scanned up to log sequence number 69056068973 InnoDB: Transaction 246648984 was in the XA prepared state. InnoDB: 1 transaction(s) which must be rolled back or cleaned up InnoDB: in total 0 row operations to undo InnoDB: Trx id counter is 246649344 
    2014-04-30 11:21:55 19033 [Note] InnoDB: Starting an apply batch of log records to the database... InnoDB: Progress in percent: 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 InnoDB: Apply batch completed [/code] Result is was: MariaDB Audit Plugin Crashed my MySQL 5.6.17... Will i use it? Last step was: 140430 14:40:53 server_audit: STOPPED

with all necessary steps that stated here: McAfee Audit Plugin So no more words and just pasting error log portion:

2014-04-30 19:00:48 14571 [Note] Audit Plugin: starting up. Version: 1.0.4 , Revision: 459 (64bit). AUDIT plugin interface version: 769 (0x301). 
2014-04-30 19:00:48 14571 [Note] Audit Plugin: hot patch for: open_tables (0x69bd00) complete. Audit func: 0x7fb366fcad30, Trampoline address: 0x7fb366fcc060 size: 15.
2014-04-30 19:00:48 14571 [Note] Audit Plugin: Done initializing sql command names. status_vars_index: [141], com_status_vars: [0x1215400]. 
2014-04-30 19:00:48 14571 [Note] Audit Plugin: Init completed successfully. 2014-04-30 19:00:48 14571 [Note] Recovering after a crash using /var/lib/mysql/data/mysql-bin 
2014-04-30 19:00:48 14571 [Note] Starting crash recovery... 
2014-04-30 19:00:48 14571 [Note] Crash recovery finished. 
2014-04-30 19:00:48 14571 [Note] Server hostname (bind-address): '*'; port: 3306 2014-04-30 19:00:48 14571 [Note] IPv6 is available. 
2014-04-30 19:00:48 14571 [Note] - '::' resolves to '::'; 
2014-04-30 19:00:48 14571 [Note] Server socket created on IP: '::'. 14:00:48 UTC - mysqld got signal 11 ; Thread pointer: 0x26e2b70 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 = 7fff90422a78 thread_stack 0x40000 /usr/sbin/mysqld(my_print_stacktrace+0x35)[0x8d6475]
/usr/sbin/mysqld(handle_fatal_signal+0x4a4)[0x663084]
/lib64/libpthread.so.0[0x35b6e0f710]
/usr/sbin/mysqld(_Z11open_tablesP3THDPP10TABLE_LISTPjjP19Prelocking_strategy+0x0)[0x69bd00] 
/usr/sbin/mysqld(_Z20open_and_lock_tablesP3THDP10TABLE_LISTbjP19Prelocking_strategy+0x44)[0x69cb74] /usr/sbin/mysqld(_Z10acl_reloadP3THD+0x28f)[0x67c9cf]
/usr/sbin/mysqld(_Z8acl_initb+0x120)[0x67e9d0]
/usr/sbin/mysqld(_Z11mysqld_mainiPPc+0xa26)[0x59fc96]
/lib64/libc.so.6(__libc_start_main+0xfd)[0x35b6a1ed1d] /usr/sbin/mysqld[0x591949] Trying to get some variables. Some pointers may be invalid and cause the dump to abort. Query (0): is an invalid pointer Connection ID (thread ID): 0 Status: NOT_KILLED

Conclusion: 2 of 3 Audit Plugins crashed MySQL 5.6.17. And now Triggers will make us happy or Purchase a commercial product