signal 8 | SIGFPE crash in find_mpvio_user if mysql.user table is empty

[Erik Lundin]

31211 7:53:26 [Note] WSREP: Synchronized with group, ready for connections
131211 7:53:26 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
131211 7:53:26 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.5.34-55-log' socket: '/var/lib/mysql/mysql.sock' port: 3306 Percona XtraDB Cluster (GPL), wsrep_25.9.r3928
06:55:30 UTC - mysqld got signal 8 ;
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.
Please help us make Percona XtraDB Cluster better by reporting any
bugs at https://bugs.launchpad.net/percona-xtradb-cluster

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

Thread pointer: 0x4d23f70
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 = 7ffcf40b8d58 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x35)[0x7dc685]
/usr/sbin/mysqld(handle_fatal_signal+0x4b4)[0x6b4924]
/lib64/libpthread.so.0(+0xf710)[0x7ffcf77b4710]
/usr/sbin/mysqld[0x547b57]
/usr/sbin/mysqld[0x5481a0]
/usr/sbin/mysqld[0x548436]
/usr/sbin/mysqld[0x53ff79]
/usr/sbin/mysqld(_Z16acl_authenticateP3THDjj+0x8f0)[0x54f3a0]
/usr/sbin/mysqld[0x63fbf1]
/usr/sbin/mysqld(_Z16login_connectionP3THD+0x50)[0x63fe20]
/usr/sbin/mysqld(_Z22thd_prepare_connectionP3THD+0x24)[0x640044]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x12b)[0x64111b]
/usr/sbin/mysqld(handle_one_connection+0x51)[0x641321]
/usr/sbin/mysqld(pfs_spawn_thread+0x59)[0x7f5c99]
/lib64/libpthread.so.0(+0x79d1)[0x7ffcf77ac9d1]
/lib64/libc.so.6(clone+0x6d)[0x7ffcf63e7b6d]

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): 5
Status: NOT_KILLED

You may download the Percona XtraDB Cluster operations manual by visiting
http://www.percona.com/software/percona-xtradb-cluster/. You may find information
in the manual which will help you identify the cause of the crash.
131211 07:55:30 mysqld_safe Number of processes running now: 0
131211 07:55:30 mysqld_safe WSREP: not restarting wsrep node automatically
131211 07:55:30 mysqld_safe mysqld from pid file /var/lib/mysql/xxx.pid ended

[Raghavendra D Prabhu (raghavendra-prabhu)]

a) The crash seems to be right after startup. (Also, can you
translate 06:55:30 UTC to your local TZ), about 2 minutes after
startup.

b) Have you had this crash before and/or is it reproduceable?

c) Would be better if you can install debuginfo of mysqld and
galera and resolve the backtrace. You can use https://dev.mysql.com/doc/refman/5.5/en/using-stack-trace.html as the guide for that.

d) Only reported instance of a SIGFPE on acl_authenticate seems
to be - https://mariadb.atlassian.net/browse/MDEV-4462 which was
caused by empty mysql.user table (which may be due to various
factors including but not limited to corruption). Can you check
this?

[Erik Lundin (e-erik)]

2014-01-21 10:34:27 9957 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.6.15-56-debug-log' socket: '/var/lib/mysql/mysql.sock' port: 3306 Percona XtraDB Cluster - Debug (GPL), Release 25.2, Revision 645, wsrep_25.2.r4027
00:00:01 UTC - mysqld got signal 8 ;
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.
Please help us make Percona XtraDB Cluster better by reporting any
bugs at https://bugs.launchpad.net/percona-xtradb-cluster

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

Thread pointer: 0x576fbc0
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 = 7fa128131d20 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x35)[0xaecd40]
/usr/sbin/mysqld(handle_fatal_signal+0x42e)[0x7542b2]
/lib64/libpthread.so.0(+0xf710)[0x7fa12d590710]
/usr/sbin/mysqld[0x78824e]
/usr/sbin/mysqld[0x789b38]
/usr/sbin/mysqld[0x78a1c0]
/usr/sbin/mysqld[0x78be5c]
/usr/sbin/mysqld[0x78a887]
/usr/sbin/mysqld(_Z16acl_authenticateP3THDj+0x1f5)[0x78ae32]
/usr/sbin/mysqld[0x7cc475]
/usr/sbin/mysqld(_Z16login_connectionP3THD+0xc5)[0x7cc615]
/usr/sbin/mysqld(_Z22thd_prepare_connectionP3THD+0x30)[0x7cce77]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x1aa)[0x7cd32f]
/usr/sbin/mysqld(handle_one_connection+0x33)[0x7cce40]
/usr/sbin/mysqld(pfs_spawn_thread+0x159)[0xb39c9b]
/lib64/libpthread.so.0(+0x79d1)[0x7fa12d5889d1]
/lib64/libc.so.6(clone+0x6d)[0x7fa12bca6b6d]

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): 614
Status: NOT_KILLED

You may download the Percona XtraDB Cluster operations manual by visiting
http://www.percona.com/software/percona-xtradb-cluster/. You may find information
in the manual which will help you identify the cause of the crash.
140122 01:00:02 mysqld_safe Number of processes running now: 0
140122 01:00:02 mysqld_safe WSREP: not restarting wsrep node automatically
140122 01:00:02 mysqld_safe mysqld from pid file /var/lib/mysql/db211

---------------------------------------
Translated stacktrace:
0x78824e _Z23set_default_auth_pluginPci + 3848
0x789b38 _Z23set_default_auth_pluginPci + 10226
0x78a1c0 _Z23set_default_auth_pluginPci + 11898
0x78be5c _Z16acl_authenticateP3THDj + 4639
0x78a887 _Z23set_default_auth_pluginPci + 13633

00:00:01 UTC = 01:00:01 (UTC+1)

[David Busby (d-busby)]

Encountered same issue:

---
08:37:12 UTC - mysqld got signal 8 ;
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.
Please help us make Percona Server better by reporting any
bugs at http://bugs.percona.com/

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

Thread pointer: 0xa35176b0
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 = 7f11a771bd78 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x35)[0x7c9c65]
/usr/sbin/mysqld(handle_fatal_signal+0x4b4)[0x69eac4]
/lib64/libpthread.so.0(+0xf710)[0x7f2a979c3710]
/usr/sbin/mysqld[0x541cd7]
/usr/sbin/mysqld[0x5423b0]
/usr/sbin/mysqld[0x542666]
/usr/sbin/mysqld[0x539ec9]
/usr/sbin/mysqld(_Z16acl_authenticateP3THDjj+0x930)[0x549770]
/usr/sbin/mysqld[0x639dd4]
/usr/sbin/mysqld(_Z16login_connectionP3THD+0x50)[0x63a020]
/usr/sbin/mysqld(_Z22thd_prepare_connectionP3THD+0x24)[0x63a244]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x11a)[0x63b68a]
/usr/sbin/mysqld(handle_one_connection+0x51)[0x63b791]
/lib64/libpthread.so.0(+0x79d1)[0x7f2a979bb9d1]
/lib64/libc.so.6(clone+0x6d)[0x7f2a962eeb5d]

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): 42
Status: NOT_KILLED

You may download the Percona Server operations manual by visiting
...

Resolution:

mysql/users.MYD was 0 bytes in size, as this was a new install, removal of datadir contents and re-running of mysql_install_db (after fixing selinux contexts on the non standard datadir location) all was well.

Bug here imho is the poor handling of the empty users table; crashing instead of throwing an error.

[Valerii Kravchuk (valerii-kravchuk)]

This is easy to confirm with code review of current Percona Server 5.5 and 5.6. In the find_mpvio_user() function in sql/sql_acl.cc we have something like this (code is from 5.6):

  10236 if (!mpvio->acl_user)
  10237 {
  10238 /*
  10239 A matching user was not found. Fake it. Take any user, make the
  10240 authentication fail later.
  10241 This way we get a realistically looking failure, with occasional
  10242 "change auth plugin" requests even for nonexistent users. The ratio
  10243 of "change auth plugin" request will be the same for real and
  10244 nonexistent users.
  10245 Note, that we cannot pick any user at random, it must always be
  10246 the same user account for the incoming sctx->user name.
  10247 */
  10248 ulong nr1=1, nr2=4;
  10249 CHARSET_INFO *cs= &my_charset_latin1;
  10250 cs->coll->hash_sort(cs, (uchar*) mpvio->auth_info.user_name,
  10251 mpvio->auth_info.user_name_length, &nr1, &nr2);
  10252
  10253 mysql_mutex_lock(&acl_cache->lock);
  10254 uint i= nr1 % acl_users.elements;
...

So, we may get that signal when acl_users.elements = 0 (there is not check of any kind in the code above) theoretically.

In upstream MySQL 5.5 and 5.6 this part of code is simple:

   9930 if (!mpvio->acl_user)
   9931 {
   9932 login_failed_error(mpvio, mpvio->auth_info.password_used);
   9933 DBUG_RETURN (1);
   9934 }

So, maybe we have to check and use that fix from https://mariadb.atlassian.net/browse/MDEV-4462 or use the approach from upstream MySQL?

[Valerii Kravchuk (valerii-kravchuk)]

Confirmed for PXC as well, as corresponding code there is inherited from Percona Server.

[Raghavendra D Prabhu (raghavendra-prabhu)]

Also, been reported here https://mariadb.atlassian.net/browse/MDEV-4462 (and fixed there).

[Laurynas Biveinis (laurynas-biveinis)]

The fix is in sql_acl.cc bits of lp:maria/10.0 rev 3758