MariaDB crashes on startup

[Walter Heck]

I wanted to add skip-pbxt to the config of one of a pair of mariadb dual masters. I added it, tried a restart, failure. Removed it, restart, failure. I've since then been trying a bunch of things:

* error log was complaining about deprecated options, so I disabled those.
* kept disabling unnecessary things from the my.cnf until I got to the bare minimum it is at now (see log below)
* upgraded to the latest version of mariadb 5.2.6 (from 5.2.5 rpms from askmonty.org)
* tried using strace to see what that would come up with
* No results. strace output attached. Command line log:

[root@yomamma ~]# cat /etc/my.cnf

# Server settings.
[mysqld]
datadir = /mysql/data

log-bin = /mysql/blog/mysql-bin
log-error = /mysql/blog/error.log
general_log = 1
general_log_file = /mysql/blog/general.log
log-slave-updates

[root@yomamma ~]# mysqld_safe --safe-mode
110530 16:06:26 mysqld_safe Logging to '/mysql/blog/error.log'.
110530 16:06:26 mysqld_safe Starting mysqld daemon with databases from /mysql/data
110530 16:06:26 mysqld_safe mysqld from pid file /mysql/data/yomamma.dedi.someplace.co.uk.pid ended
[root@yomamma ~]# tail /mysql/blog/error.log -n100
110530 15:32:10 mysqld_safe mysqld from pid file /mysql/data/yomamma.dedi.someplace.co.uk.pid ended
110530 16:06:26 mysqld_safe Starting mysqld daemon with databases from /mysql/data
110530 16:06:26 [ERROR] mysqld got signal 11 ;
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=0
read_buffer_size=131072
max_used_connections=0
max_threads=153
threads_connected=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 334804 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x10154340
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 = 0x7fff9cb91890 thread_stack 0x48000
/usr/sbin/mysqld(my_print_stacktrace+0x2e) [0x9a0a5e]
/usr/sbin/mysqld(handle_segfault+0x385) [0x5ee155]
/lib64/libpthread.so.0 [0x3a2260eb10]
/usr/sbin/mysqld(ha_resolve_by_name(THD*, st_mysql_lex_string const*)+0x62) [0x6deba2]
/usr/sbin/mysqld(open_table_def(THD*, st_table_share*, unsigned int)+0x187e) [0x64afae]
/usr/sbin/mysqld(get_table_share(THD*, TABLE_LIST*, char*, unsigned int, unsigned int, int*)+0x1df) [0x63d1ff]
/usr/sbin/mysqld [0x63fa50]
/usr/sbin/mysqld(open_table(THD*, TABLE_LIST*, st_mem_root*, bool*, unsigned int)+0x708) [0x643b58]
/usr/sbin/mysqld(open_tables(THD*, TABLE_LIST**, unsigned int*, unsigned int)+0x3a6) [0x644606]
/usr/sbin/mysqld(open_and_lock_tables_derived(THD*, TABLE_LIST*, bool)+0x67) [0x6449e7]
/usr/sbin/mysqld(plugin_init(int*, char**, int)+0x665) [0x763505]
/usr/sbin/mysqld [0x5f059b]
/usr/sbin/mysqld(main+0x618) [0x5f1778]
/lib64/libc.so.6(__libc_start_main+0xf4) [0x3a21e1d994]
/usr/sbin/mysqld [0x52c1c9]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query ((nil)): is an invalid pointer
Connection ID (thread ID): 0
Status: NOT_KILLED

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.
110530 16:06:26 mysqld_safe mysqld from pid file /mysql/data/yomamma.dedi.someplace.co.uk.pid ended

[Guillaume Lefranc (tanj)]

Basically, I narrowed this bug to a manipulation error - the mysql.plugin table had been converted to InnoDB. Since InnoDB engine is not loaded at server start (it's a plugin), the table can't be read. Moving the .frm and .ibd file to another directory is a workaround.
I somewhat think that the system tables should be protected against any conversion to engines which aren't compiled-in - or at least, instead of crashing, write out a message to the error log and explain why the mysql.plugin table cannot be read.

[Sergey Petrunia (sergefp)]

For the record: the same problem can be observed with MySQL 5.5 :

psergey@pslp2:~/dev2/mysql-server-5.5/sql$ ./mysqld --defaults-file=~/my1-tmp.cnf
110616 21:40:46 [ERROR] An old style --language value with language specific part detected: /home/psergey/dev2/mysql-server-5.5/sql/share/english/
110616 21:40:46 [ERROR] Use --lc-messages-dir without language specific part instead.
110616 21:40:46 [Warning] You have enabled the binary log, but you haven't set server-id to a non-zero value: we force server id to 1; updates will be logged to the binary log, but connections from slaves will not be accepted.
110616 21:40:46 [Note] Plugin 'FEDERATED' is disabled.
Segmentation fault

[Sergey Petrunia (sergefp)]

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0xb7dbd6c0 (LWP 11726)]
0x0838e04d in ha_resolve_by_name (thd=0xbfd835e0, name=0xbfd82914)
    at /home/psergey/dev2/mysql-server-5.5/sql/handler.cc:149
149 if (!(hton->flags & HTON_NOT_USER_SELECTABLE))
(gdb) wher
#0 0x0838e04d in ha_resolve_by_name (thd=0xbfd835e0, name=0xbfd82914)
    at /home/psergey/dev2/mysql-server-5.5/sql/handler.cc:149
#1 0x082ca0fa in open_binary_frm (thd=0xbfd835e0, share=0x9976bf8, head=0xbfd82dec "�\001\n\f\003", file=6)
    at /home/psergey/dev2/mysql-server-5.5/sql/table.cc:976
#2 0x082cd06a in open_table_def (thd=0xbfd835e0, share=0x9976bf8, db_flags=8192)
    at /home/psergey/dev2/mysql-server-5.5/sql/table.cc:701
#3 0x081cc5fc in get_table_share (thd=0xbfd835e0, table_list=0xbfd85398, key=0xbfd8317e "mysql", key_length=13,
    db_flags=8192, error=0xbfd82f64, hash_value=1324052888)
    at /home/psergey/dev2/mysql-server-5.5/sql/sql_base.cc:545
#4 0x081cd0bc in get_table_share_with_discover (thd=0xbfd835e0, table_list=0xbfd85398, key=0xbfd8317e "mysql",
    key_length=13, db_flags=8192, error=0xbfd82f64, hash_value=1324052888)
    at /home/psergey/dev2/mysql-server-5.5/sql/sql_base.cc:617
#5 0x081cde09 in open_table (thd=0xbfd835e0, table_list=0xbfd85398, mem_root=0xbfd833e0, ot_ctx=0xbfd83400)
    at /home/psergey/dev2/mysql-server-5.5/sql/sql_base.cc:2882
#6 0x081ceefc in open_and_process_table (thd=0xbfd835e0, lex=0xbfd8464c, tables=0xbfd85398, counter=0xbfd834a0,
    flags=2048, prelocking_strategy=0xbfd834dc, has_prelocking_list=false, ot_ctx=0xbfd83400,
    new_frm_mem=0xbfd833e0) at /home/psergey/dev2/mysql-server-5.5/sql/sql_base.cc:4381
#7 0x081cf65d in open_tables (thd=0xbfd835e0, start=0xbfd834b4, counter=0xbfd834a0, flags=2048,
    prelocking_strategy=0xbfd834dc) at /home/psergey/dev2/mysql-server-5.5/sql/sql_base.cc:4828
#8 0x081cfc53 in open_and_lock_tables (thd=0xbfd835e0, tables=0xbfd85398, derived=false, flags=2048,
    prelocking_strategy=0xbfd834dc) at /home/psergey/dev2/mysql-server-5.5/sql/sql_base.cc:5425
#9 0x081be13f in open_and_lock_tables (thd=0xbfd835e0, tables=0xbfd85398, derived=false, flags=2048)
    at /home/psergey/dev2/mysql-server-5.5/sql/sql_base.h:475
#10 0x0822ec5f in plugin_load (tmp_root=0xbfd857d8, argc=0x8b6535c, argv=0x994c360)
    at /home/psergey/dev2/mysql-server-5.5/sql/sql_plugin.cc:1447
#11 0x0822f663 in plugin_init (argc=0x8b6535c, argv=0x994c360, flags=0)
    at /home/psergey/dev2/mysql-server-5.5/sql/sql_plugin.cc:1333
#12 0x0817bcd0 in init_server_components () at /home/psergey/dev2/mysql-server-5.5/sql/mysqld.cc:3952
#13 0x0817cacc in mysqld_main (argc=9, argv=0x994c360) at /home/psergey/dev2/mysql-server-5.5/sql/mysqld.cc:4522
#14 0x08170573 in main (argc=89812, argv=0xb7fcf860) at /home/psergey/dev2/mysql-server-5.5/sql/main.cc:24
(gdb) p hton
$1 = (handlerton *) 0x0

[Sergey Petrunia (sergefp)]

.. And for MySQL 5.5, the problem happens even if innodb (the engine that I've changed mysql.plugin to) is compiled-in.

[Sergey Petrunia (sergefp)]

MariaDB 5.2 shows similar behaviour. I have xtradb built-in, and even there after doing "alter table mysql.plugin engine=innodb" the server will crash on startup.

The cause of the crash is that mysql.plugin table is read before plugins are initialized.

When mysqld tries to open mysql.plugin it will at some point call ha_resolve_by_name() . When it executes this part of that function:

  if ((plugin= my_plugin_lock_by_name(thd, name, MYSQL_STORAGE_ENGINE_PLUGIN)))
  {
    handlerton *hton= plugin_data(plugin, handlerton *);
    if (!(hton->flags & HTON_NOT_USER_SELECTABLE))
      return plugin;

it will have

(gdb) p plugin
  $42 = (plugin_ref) 0xa04f218
(gdb) p hton
  $43 = (handlerton *) 0x0
(gdb) p plugin->data
  $44 = (void *) 0x0

hton==NULL because ha_initialize_handlerton() haven't yet been called for xtradb.

[Sergey Petrunia (sergefp)]

I can think of this fix:

http://lists.askmonty.org/pipermail/commits/2011-June/001911.html

which makes the crash go away, and one gets this error instead:

110617 1:10:10 [ERROR] Attempt to use a built-in plugin InnoDB before it has been initialized
110617 1:10:10 [ERROR] Can't open the mysql.plugin table. Please run mysql_upgrade to create it.