Bug #1277986 “MEMORY/MyISAM tables + binlogging OFF | Empty GRA...” : Series 5.6 : Bugs : MySQL patches by Codership

Revision history for this message

Paul Namuag (paul-namuag) wrote on 2014-02-11:

#1

Verified this as well in Centos.

Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 11
Server version: 5.6.15-56-log Percona XtraDB Cluster (GPL), Release 25.3, Revision 706, wsrep_25.3.r4034

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> select @@general_log;
+---------------+
| @@general_log |
+---------------+
| 1 |
+---------------+
1 row in set (0.00 sec)

mysql> use memtables;
Database changed
mysql> create table mem1(a int not null auto_increment primary key, b int null) engine=memory;
Query OK, 0 rows affected (0.00 sec)

mysql> insert into mem1(b) values(1),(2),(3);
Query OK, 3 rows affected (0.01 sec)
Records: 3 Duplicates: 0 Warnings: 0

mysql> quit
Bye

[root@node1 mysql]# ls -alth .
total 237M
drwxr-xr-x 6 mysql mysql 4.0K Feb 11 06:02 .
-rw-rw---- 1 root root 0 Feb 11 06:02 GRA_11_-1.log
-rw-r----- 1 root root 26K Feb 11 06:02 node1.err
-rw-rw---- 1 root root 6.5K Feb 11 06:02 node1.log
-rw-rw---- 1 root root 104 Feb 11 06:02 grastate.dat
drwx------ 2 root root 4.0K Feb 11 06:02 memtables
-rw------- 1 root root 129M Feb 11 06:02 galera.cache
-rw-rw---- 1 root root 3.6K Feb 11 05:52 innobackup.backup.log
-rw-rw---- 1 mysql mysql 48M Feb 11 05:45 ib_logfile0
-rw-rw---- 1 mysql mysql 12M Feb 11 05:45 ibdata1
-rw-rw---- 1 root root 5 Feb 11 05:45 node1.pid
srwxrwxrwx 1 root root 0 Feb 11 05:45 mysql.sock
-rw-rw---- 1 mysql mysql 56 Feb 11 03:49 auto.cnf
-rw-r--r-- 1 root root 120 Feb 11 03:49 RPM_UPGRADE_HISTORY
-rw-r--r-- 1 mysql mysql 120 Feb 11 03:49 RPM_UPGRADE_MARKER-LAST
drwx------ 2 mysql mysql 4.0K Feb 11 03:49 mysql
drwx------ 2 mysql mysql 4.0K Feb 11 03:49 performance_schema
-rw-rw---- 1 mysql mysql 48M Feb 11 03:49 ib_logfile1
drwx------ 2 mysql mysql 4.0K Feb 11 03:49 test
drwxr-xr-x. 25 root root 4.0K Feb 11 03:49 ..

[root@node1 mysql]# uname -a
Linux node1 2.6.32-358.el6.x86_64 #1 SMP Fri Feb 22 00:31:26 UTC 2013 x86_64 x86_64 x86_64 GNU/Linux

[root@node1 mysql]# lsb_release -a
LSB Version: :base-4.0-amd64:base-4.0-noarch:core-4.0-amd64:core-4.0-noarch
Distributor ID: CentOS
Description: CentOS release 6.4 (Final)
Release: 6.4
Codename: Final

Verified this as well in Centos.

Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 11
Server version: 5.6.15-56-log Percona XtraDB Cluster (GPL), Release 25.3, Revision 706, wsrep_25.3.r4034

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> select @@general_log;
+---------------+
| @@general_log |
+---------------+
|             1 |
+---------------+
1 row in set (0.00 sec)

mysql> use memtables;
Database changed
mysql>  create table mem1(a int not null auto_increment primary key, b int null) engine=memory;
Query OK, 0 rows affected (0.00 sec)

mysql> insert into mem1(b) values(1),(2),(3);
Query OK, 3 rows affected (0.01 sec)
Records: 3  Duplicates: 0  Warnings: 0

mysql> quit
Bye

[root@node1 mysql]# ls -alth .
total 237M
drwxr-xr-x   6 mysql mysql 4.0K Feb 11 06:02 .
-rw-rw----   1 root  root     0 Feb 11 06:02 GRA_11_-1.log
-rw-r-----   1 root  root   26K Feb 11 06:02 node1.err
-rw-rw----   1 root  root  6.5K Feb 11 06:02 node1.log
-rw-rw----   1 root  root   104 Feb 11 06:02 grastate.dat
drwx------   2 root  root  4.0K Feb 11 06:02 memtables
-rw-------   1 root  root  129M Feb 11 06:02 galera.cache
-rw-rw----   1 root  root  3.6K Feb 11 05:52 innobackup.backup.log
-rw-rw----   1 mysql mysql  48M Feb 11 05:45 ib_logfile0
-rw-rw----   1 mysql mysql  12M Feb 11 05:45 ibdata1
-rw-rw----   1 root  root     5 Feb 11 05:45 node1.pid
srwxrwxrwx   1 root  root     0 Feb 11 05:45 mysql.sock
-rw-rw----   1 mysql mysql   56 Feb 11 03:49 auto.cnf
-rw-r--r--   1 root  root   120 Feb 11 03:49 RPM_UPGRADE_HISTORY
-rw-r--r--   1 mysql mysql  120 Feb 11 03:49 RPM_UPGRADE_MARKER-LAST
drwx------   2 mysql mysql 4.0K Feb 11 03:49 mysql
drwx------   2 mysql mysql 4.0K Feb 11 03:49 performance_schema
-rw-rw----   1 mysql mysql  48M Feb 11 03:49 ib_logfile1
drwx------   2 mysql mysql 4.0K Feb 11 03:49 test
drwxr-xr-x. 25 root  root  4.0K Feb 11 03:49 ..

[root@node1 mysql]# uname -a
Linux node1 2.6.32-358.el6.x86_64 #1 SMP Fri Feb 22 00:31:26 UTC 2013 x86_64 x86_64 x86_64 GNU/Linux

[root@node1 mysql]# lsb_release -a
LSB Version:	:base-4.0-amd64:base-4.0-noarch:core-4.0-amd64:core-4.0-noarch
Distributor ID:	CentOS
Description:	CentOS release 6.4 (Final)
Release:	6.4
Codename:	Final

Revision history for this message

Paul Namuag (paul-namuag) wrote on 2014-02-11:

#2

Verified that it creates an empty GRA_*.log files.

Changed in percona-xtradb-cluster:
status:	New → Confirmed

Revision history for this message

Raghavendra D Prabhu (raghavendra-prabhu) wrote on 2014-02-11:

#3

Download full text (5.0 KiB)

With PXC56 release binary, I could reproduce it.

With codership-5.6 UNIV_DEBUG binary I got

mysqld: /media/Tintin/Work/code/codership/codership-5.6/sql/binlog.cc:1181: int binlog_cache_data::finalize(THD*, Log_event*): Assertion `!flags.finalized' failed.
09:09:18 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=4
max_threads=151
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 = 68318 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x2a392f0
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 = 7f797c077e48 thread_stack 0x40000
/chip/bin/mysqld(my_print_stacktrace+0x2c)[0x936e5a]
/chip/bin/mysqld(handle_fatal_signal+0x2f7)[0x66da3f]
/usr/lib/libpthread.so.0(+0xf880)[0x7f79a928a880]
/usr/lib/libc.so.6(gsignal+0x39)[0x7f79a7822389]
/usr/lib/libc.so.6(abort+0x148)[0x7f79a7823788]
/usr/lib/libc.so.6(+0x2e4a6)[0x7f79a781b4a6]
/usr/lib/libc.so.6(+0x2e552)[0x7f79a781b552]
/chip/bin/mysqld(_ZN17binlog_cache_data8finalizeEP3THDP9Log_event+0xdd)[0x8ccb6d]
/chip/bin/mysqld(_ZN22binlog_stmt_cache_data8finalizeEP3THD+0x7a)[0x8ccd04]
/chip/bin/mysqld(_ZN13MYSQL_BIN_LOG6commitEP3THDb+0x385)[0x8dfce5]
/chip/bin/mysqld(_Z23wsrep_thd_binlog_commitP3THDb+0x4a)[0x8e035b]
/chip/bin/mysqld(_ZN12TC_LOG_DUMMY6commitEP3THDb+0xf)[0x65d68d]
/chip/bin/mysqld(_Z15ha_commit_transP3THDbb+0x4e5)[0x5a7dcf]
/chip/bin/mysqld(_Z17trans_commit_stmtP3THD+0x475)[0x79bde1]
/chip/bin/mysqld(_Z21mysql_execute_commandP3THD+0x76f1)[0x7007dd]
/chip/bin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x4e8)[0x701ddd]
/chip/bin/mysqld[0x702761]
/chip/bin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x132d)[0x704005]
/chip/bin/mysqld(_Z10do_commandP3THD+0x716)[0x7067a1]
/chip/bin/mysqld(_Z24do_handle_one_connectionP3THD+0x143)[0x6c9738]
/chip/bin/mysqld(handle_one_connection+0x40)[0x6c98c3]
/chip/bin/mysqld(pfs_spawn_thread+0x14e)[0xc22de8]
/usr/lib/libpthread.so.0(+0x80a2)[0x7f79a92830a2]
/usr/lib/libc.so.6(clone+0x6d)[0x7f79a78d2d1d]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7f7930004fd0): is an invalid pointer
Connection ID (thread ID): 5
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.

Config used:
[mysqld]
socket = /chip/datadir/pxc.sock
port = 40000
basedir=/chip
datadir=/chip/datadir

binlog_format = ROW
innodb_buffer_pool_size = 500M
innodb_flush_log_at_tr...

With PXC56 release binary, I could reproduce it.

With codership-5.6 UNIV_DEBUG binary I got

mysqld: /media/Tintin/Work/code/codership/codership-5.6/sql/binlog.cc:1181: int binlog_cache_data::finalize(THD*, Log_event*): Assertion `!flags.finalized' failed.
09:09:18 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=4
max_threads=151
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 = 68318 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x2a392f0
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 = 7f797c077e48 thread_stack 0x40000
/chip/bin/mysqld(my_print_stacktrace+0x2c)[0x936e5a]
/chip/bin/mysqld(handle_fatal_signal+0x2f7)[0x66da3f]
/usr/lib/libpthread.so.0(+0xf880)[0x7f79a928a880]
/usr/lib/libc.so.6(gsignal+0x39)[0x7f79a7822389]
/usr/lib/libc.so.6(abort+0x148)[0x7f79a7823788]
/usr/lib/libc.so.6(+0x2e4a6)[0x7f79a781b4a6]
/usr/lib/libc.so.6(+0x2e552)[0x7f79a781b552]
/chip/bin/mysqld(_ZN17binlog_cache_data8finalizeEP3THDP9Log_event+0xdd)[0x8ccb6d]
/chip/bin/mysqld(_ZN22binlog_stmt_cache_data8finalizeEP3THD+0x7a)[0x8ccd04]
/chip/bin/mysqld(_ZN13MYSQL_BIN_LOG6commitEP3THDb+0x385)[0x8dfce5]
/chip/bin/mysqld(_Z23wsrep_thd_binlog_commitP3THDb+0x4a)[0x8e035b]
/chip/bin/mysqld(_ZN12TC_LOG_DUMMY6commitEP3THDb+0xf)[0x65d68d]
/chip/bin/mysqld(_Z15ha_commit_transP3THDbb+0x4e5)[0x5a7dcf]
/chip/bin/mysqld(_Z17trans_commit_stmtP3THD+0x475)[0x79bde1]
/chip/bin/mysqld(_Z21mysql_execute_commandP3THD+0x76f1)[0x7007dd]
/chip/bin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x4e8)[0x701ddd]
/chip/bin/mysqld[0x702761]
/chip/bin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x132d)[0x704005]
/chip/bin/mysqld(_Z10do_commandP3THD+0x716)[0x7067a1]
/chip/bin/mysqld(_Z24do_handle_one_connectionP3THD+0x143)[0x6c9738]
/chip/bin/mysqld(handle_one_connection+0x40)[0x6c98c3]
/chip/bin/mysqld(pfs_spawn_thread+0x14e)[0xc22de8]
/usr/lib/libpthread.so.0(+0x80a2)[0x7f79a92830a2]
/usr/lib/libc.so.6(clone+0x6d)[0x7f79a78d2d1d]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7f7930004fd0): is an invalid pointer
Connection ID (thread ID): 5
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.

Config used:
 [mysqld]
 socket = /chip/datadir/pxc.sock
 port = 40000
 basedir=/chip
 datadir=/chip/datadir

binlog_format           = ROW
 innodb_buffer_pool_size         = 500M
 innodb_flush_log_at_trx_commit  = 0
 innodb_flush_method             = O_DIRECT
 wsrep_node_address=127.0.0.1
 innodb_log_files_in_group       = 2
 innodb_log_file_size            = 20M
 innodb_file_per_table           = 1

wsrep_sst_receive_address=127.0.0.1:40001
 wsrep_node_incoming_address=127.0.0.1
 wsrep_cluster_address='gcomm://127.0.0.1:50010,127.0.0.1:60010'
 wsrep_provider=/chip/lib/libgalera_smm.so
 wsrep_provider_options = "gmcast.listen_addr=tcp://127.0.0.1:40010"

wsrep_slave_threads=2
 wsrep_cluster_name=Chip56
 wsrep_sst_method=rsync
 #wsrep_sst_method=xtrabackup-v2

innodb_locks_unsafe_for_binlog=1
 innodb_autoinc_lock_mode=2

query_cache_type=0
 query_cache_size=0

[client]
 user=root
 password=test
 socket = /chip/datadir/pxc.sock

[xtrabackup]
 parallel=4
 compress

Started as:
sudo /chip/bin/mysqld --defaults-file=/chip/etc/my.cnf.local --basedir=/chip --user=mysql     --wsrep-debug --wsrep-new-cluster

>>mysql --defaults-file=/chip/etc/my.cnf.local -u root -ptest test
Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MySQL connection id is 5
Server version: 5.6.15-debug MySQL Community Server (GPL), wsrep_25.2.r4039

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

MySQL [test]> create table mem1(a int not null auto_increment primary key, b int null) engine=memory;
Query OK, 0 rows affected (0.01 sec)

MySQL [test]> insert into mem1(a) values (NULL);
Query OK, 1 row affected (0.00 sec)

MySQL [test]> insert into mem1(a) values (NULL);
ERROR 2013 (HY000): Lost connection to MySQL server during query
MySQL [test]> insert into mem1(a) values (NULL);
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...
ERROR 2002 (HY000): Can't connect to local MySQL server through socket '/chip/datadir/pxc.sock' (111)
ERROR: Can't connect to the server

Revision history for this message

Raghavendra D Prabhu (raghavendra-prabhu) wrote on 2014-02-11:

#4

Can reproduce the same crash with UNIV_DEBUG binary of PXC:

mysqld-debug: /media/Tintin/Work/code/percona-xtradb-cluster/pxc56/Percona-Server/sql/binlog.cc:1187: int binlog_cache_data::finalize(THD*, Log_event*): Assertion `!flags.finalized' failed.
09:22:22 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.
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=4
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: 0x3338c60
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 = 7f2bb4053e98 thread_stack 0x40000
/pxc56/bin/mysqld-debug(my_print_stacktrace+0x2c)[0x97c6dc]
/pxc56/bin/mysqld-debug(handle_fatal_signal+0x489)[0x6f4179]
/usr/lib/libpthread.so.0(+0xf880)[0x7f2be0c34880]
/usr/lib/libc.so.6(gsignal+0x39)[0x7f2bdefc4389]
/usr/lib/libc.so.6(abort+0x148)[0x7f2bdefc5788]
/usr/lib/libc.so.6(+0x2e4a6)[0x7f2bdefbd4a6]
/usr/lib/libc.so.6(+0x2e552)[0x7f2bdefbd552]
/pxc56/bin/mysqld-debug[0x91bd07]
/pxc56/bin/mysqld-debug(_ZN22binlog_stmt_cache_data8finalizeEP3THD+0x7e)[0x91bd8e]
/pxc56/bin/mysqld-debug(_ZN13MYSQL_BIN_LOG6commitEP3THDb+0x43f)[0x92aa4f]
/pxc56/bin/mysqld-debug(_Z15ha_commit_transP3THDbb+0x143)[0x64de53]
/pxc56/bin/mysqld-debug(_Z17trans_commit_stmtP3THD+0xb8)[0x8076d8]
/pxc56/bin/mysqld-debug(_Z21mysql_execute_commandP3THD+0x3268)[0x77cfa8]
/pxc56/bin/mysqld-debug(_Z11mysql_parseP3THDPcjP12Parser_state+0x6e8)[0x780f28]
/pxc56/bin/mysqld-debug[0x7815dc]
/pxc56/bin/mysqld-debug(_Z16dispatch_command19enum_server_commandP3THDPcj+0x15d9)[0x783059]
/pxc56/bin/mysqld-debug(_Z10do_commandP3THD+0x1b3)[0x7837f3]
/pxc56/bin/mysqld-debug(_Z24do_handle_one_connectionP3THD+0x142)[0x74e3a2]
/pxc56/bin/mysqld-debug(handle_one_connection+0x20)[0x74e4e0]
/pxc56/bin/mysqld-debug(pfs_spawn_thread+0x143)[0xbf5323]
/usr/lib/libpthread.so.0(+0x80a2)[0x7f2be0c2d0a2]
/usr/lib/libc.so.6(clone+0x6d)[0x7f2bdf074d1d]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7f2b50005020): is an invalid pointer
Connection ID (thread ID): 4
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.

Can reproduce the same crash with UNIV_DEBUG binary of PXC:

mysqld-debug: /media/Tintin/Work/code/percona-xtradb-cluster/pxc56/Percona-Server/sql/binlog.cc:1187: int binlog_cache_data::finalize(THD*, Log_event*): Assertion `!flags.finalized' failed.
09:22:22 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.
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=4
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: 0x3338c60
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 = 7f2bb4053e98 thread_stack 0x40000
/pxc56/bin/mysqld-debug(my_print_stacktrace+0x2c)[0x97c6dc]
/pxc56/bin/mysqld-debug(handle_fatal_signal+0x489)[0x6f4179]
/usr/lib/libpthread.so.0(+0xf880)[0x7f2be0c34880]
/usr/lib/libc.so.6(gsignal+0x39)[0x7f2bdefc4389]
/usr/lib/libc.so.6(abort+0x148)[0x7f2bdefc5788]
/usr/lib/libc.so.6(+0x2e4a6)[0x7f2bdefbd4a6]
/usr/lib/libc.so.6(+0x2e552)[0x7f2bdefbd552]
/pxc56/bin/mysqld-debug[0x91bd07]
/pxc56/bin/mysqld-debug(_ZN22binlog_stmt_cache_data8finalizeEP3THD+0x7e)[0x91bd8e]
/pxc56/bin/mysqld-debug(_ZN13MYSQL_BIN_LOG6commitEP3THDb+0x43f)[0x92aa4f]
/pxc56/bin/mysqld-debug(_Z15ha_commit_transP3THDbb+0x143)[0x64de53]
/pxc56/bin/mysqld-debug(_Z17trans_commit_stmtP3THD+0xb8)[0x8076d8]
/pxc56/bin/mysqld-debug(_Z21mysql_execute_commandP3THD+0x3268)[0x77cfa8]
/pxc56/bin/mysqld-debug(_Z11mysql_parseP3THDPcjP12Parser_state+0x6e8)[0x780f28]
/pxc56/bin/mysqld-debug[0x7815dc]
/pxc56/bin/mysqld-debug(_Z16dispatch_command19enum_server_commandP3THDPcj+0x15d9)[0x783059]
/pxc56/bin/mysqld-debug(_Z10do_commandP3THD+0x1b3)[0x7837f3]
/pxc56/bin/mysqld-debug(_Z24do_handle_one_connectionP3THD+0x142)[0x74e3a2]
/pxc56/bin/mysqld-debug(handle_one_connection+0x20)[0x74e4e0]
/pxc56/bin/mysqld-debug(pfs_spawn_thread+0x143)[0xbf5323]
/usr/lib/libpthread.so.0(+0x80a2)[0x7f2be0c2d0a2]
/usr/lib/libc.so.6(clone+0x6d)[0x7f2bdf074d1d]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7f2b50005020): is an invalid pointer
Connection ID (thread ID): 4
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.

Revision history for this message

Raghavendra D Prabhu (raghavendra-prabhu) wrote on 2014-02-11:

#5

With binlog disabled, it crashes as above in UNIV_DEBUG build, however, with it enabled, it doesn't crash nor does it leave any GRA files behind. (so that is also a workaround)

Revision history for this message

Raghavendra D Prabhu (raghavendra-prabhu) wrote on 2014-02-11:

#6

Download full text (3.3 KiB)

Demangled backtrace for codership-5.6 binary:

#0 0x00007ffff6166389 in raise () from /usr/lib/libc.so.6
#1 0x00007ffff6167788 in abort () from /usr/lib/libc.so.6
#2 0x00007ffff615f4a6 in __assert_fail_base () from /usr/lib/libc.so.6
#3 0x00007ffff615f552 in __assert_fail () from /usr/lib/libc.so.6
#4 0x00000000008ccb6d in binlog_cache_data::finalize (this=this@entry=0x7fff8000f720, thd=thd@entry=0x2438e20, end_event=end_event@entry=0x7fffcc1b6240)
    at /media/Tintin/Work/code/codership/codership-5.6/sql/binlog.cc:1181
#5 0x00000000008ccd04 in binlog_stmt_cache_data::finalize (this=this@entry=0x7fff8000f720, thd=thd@entry=0x2438e20) at /media/Tintin/Work/code/codership/codership-5.6/sql/binlog.cc:601
#6 0x00000000008dfce5 in MYSQL_BIN_LOG::commit (this=this@entry=0x147bdc0 <mysql_bin_log>, thd=0x2438e20, all=<optimized out>) at /media/Tintin/Work/code/codership/codership-5.6/sql/binlog.cc:6287
#7 0x00000000008e035b in wsrep_thd_binlog_commit (thd=<optimized out>, all=<optimized out>) at /media/Tintin/Work/code/codership/codership-5.6/sql/binlog.cc:8985
#8 0x000000000065d68d in TC_LOG_DUMMY::commit (this=<optimized out>, thd=<optimized out>, all=<optimized out>) at /media/Tintin/Work/code/codership/codership-5.6/sql/log.h:124
#9 0x00000000005a7dcf in ha_commit_trans (thd=thd@entry=0x2438e20, all=all@entry=false, ignore_global_read_lock=ignore_global_read_lock@entry=false)
    at /media/Tintin/Work/code/codership/codership-5.6/sql/handler.cc:1458
#10 0x000000000079bde1 in trans_commit_stmt (thd=thd@entry=0x2438e20) at /media/Tintin/Work/code/codership/codership-5.6/sql/transaction.cc:473
#11 0x00000000007007dd in mysql_execute_command (thd=thd@entry=0x2438e20) at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_parse.cc:5405
#12 0x0000000000701ddd in mysql_parse (thd=thd@entry=0x2438e20, rawbuf=rawbuf@entry=0x7fff80005020 "insert into mem1(a) values (NULL)", length=length@entry=33, parser_state=parser_state@entry=0x7fffcc1b9610)
    at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_parse.cc:6775
#13 0x0000000000702761 in wsrep_mysql_parse (thd=thd@entry=0x2438e20, rawbuf=0x7fff80005020 "insert into mem1(a) values (NULL)", length=33, parser_state=parser_state@entry=0x7fffcc1b9610)
    at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_parse.cc:6555
#14 0x0000000000704005 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x2438e20, packet=packet@entry=0x2548491 "insert into mem1(a) values (NULL)", packet_length=packet_length@entry=33)
    at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_parse.cc:1526
#15 0x00000000007067a1 in do_command (thd=0x2438e20) at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_parse.cc:1118
#16 0x00000000006c9738 in do_handle_one_connection (thd_arg=thd_arg@entry=0x2438e20) at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_connect.cc:1007
#17 0x00000000006c98c3 in handle_one_connection (arg=arg@entry=0x2438e20) at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_connect.cc:916
#18 0x0000000000c22de8 in pfs_spawn_thread (arg=0x24c0390) at /media/Tintin/Work/code/codership/codership-5.6/storage/perfschema/pfs.cc:1858
#19 0x00007ffff7bc7...

Demangled backtrace for codership-5.6 binary:

#0  0x00007ffff6166389 in raise () from /usr/lib/libc.so.6
#1  0x00007ffff6167788 in abort () from /usr/lib/libc.so.6
#2  0x00007ffff615f4a6 in __assert_fail_base () from /usr/lib/libc.so.6
#3  0x00007ffff615f552 in __assert_fail () from /usr/lib/libc.so.6
#4  0x00000000008ccb6d in binlog_cache_data::finalize (this=this@entry=0x7fff8000f720, thd=thd@entry=0x2438e20, end_event=end_event@entry=0x7fffcc1b6240)
    at /media/Tintin/Work/code/codership/codership-5.6/sql/binlog.cc:1181
#5  0x00000000008ccd04 in binlog_stmt_cache_data::finalize (this=this@entry=0x7fff8000f720, thd=thd@entry=0x2438e20) at /media/Tintin/Work/code/codership/codership-5.6/sql/binlog.cc:601
#6  0x00000000008dfce5 in MYSQL_BIN_LOG::commit (this=this@entry=0x147bdc0 <mysql_bin_log>, thd=0x2438e20, all=<optimized out>) at /media/Tintin/Work/code/codership/codership-5.6/sql/binlog.cc:6287
#7  0x00000000008e035b in wsrep_thd_binlog_commit (thd=<optimized out>, all=<optimized out>) at /media/Tintin/Work/code/codership/codership-5.6/sql/binlog.cc:8985
#8  0x000000000065d68d in TC_LOG_DUMMY::commit (this=<optimized out>, thd=<optimized out>, all=<optimized out>) at /media/Tintin/Work/code/codership/codership-5.6/sql/log.h:124
#9  0x00000000005a7dcf in ha_commit_trans (thd=thd@entry=0x2438e20, all=all@entry=false, ignore_global_read_lock=ignore_global_read_lock@entry=false)
    at /media/Tintin/Work/code/codership/codership-5.6/sql/handler.cc:1458
#10 0x000000000079bde1 in trans_commit_stmt (thd=thd@entry=0x2438e20) at /media/Tintin/Work/code/codership/codership-5.6/sql/transaction.cc:473
#11 0x00000000007007dd in mysql_execute_command (thd=thd@entry=0x2438e20) at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_parse.cc:5405
#12 0x0000000000701ddd in mysql_parse (thd=thd@entry=0x2438e20, rawbuf=rawbuf@entry=0x7fff80005020 "insert into mem1(a) values (NULL)", length=length@entry=33, parser_state=parser_state@entry=0x7fffcc1b9610)
    at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_parse.cc:6775
#13 0x0000000000702761 in wsrep_mysql_parse (thd=thd@entry=0x2438e20, rawbuf=0x7fff80005020 "insert into mem1(a) values (NULL)", length=33, parser_state=parser_state@entry=0x7fffcc1b9610)
    at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_parse.cc:6555
#14 0x0000000000704005 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x2438e20, packet=packet@entry=0x2548491 "insert into mem1(a) values (NULL)", packet_length=packet_length@entry=33)
    at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_parse.cc:1526
#15 0x00000000007067a1 in do_command (thd=0x2438e20) at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_parse.cc:1118
#16 0x00000000006c9738 in do_handle_one_connection (thd_arg=thd_arg@entry=0x2438e20) at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_connect.cc:1007
#17 0x00000000006c98c3 in handle_one_connection (arg=arg@entry=0x2438e20) at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_connect.cc:916
#18 0x0000000000c22de8 in pfs_spawn_thread (arg=0x24c0390) at /media/Tintin/Work/code/codership/codership-5.6/storage/perfschema/pfs.cc:1858
#19 0x00007ffff7bc70a2 in start_thread () from /usr/lib/libpthread.so.0
#20 0x00007ffff6216d1d in clone () from /usr/lib/libc.so.6

(Will attach full bt).

Revision history for this message

Raghavendra D Prabhu (raghavendra-prabhu) wrote on 2014-02-11:

#7

gdb.txt Edit (25.2 KiB, text/plain)

Full backtrace of the crash - 'bt full'

Revision history for this message

Raghavendra D Prabhu (raghavendra-prabhu) wrote on 2014-02-11:

#8

This (the crash) happens with MyISAM too as reported here https://groups.google.com/d/topic/codership-team/3GPGWt8UwhM

summary:

Empty GRA_*_*.log file generated after closing a MySQL session that was
- used to insert rows on a MEMORY table
+ used to insert rows on a MEMORY/MyISAM with binlogging OFF.

Revision history for this message

Raghavendra D Prabhu (raghavendra-prabhu) wrote on 2014-02-11: Re: Empty GRA_*_*.log file generated after closing a MySQL session that was used to insert rows on a MEMORY/MyISAM with binlogging OFF.

#9

To trigger this crash/issue: you need to do an insert to a non-innodb table followed by anything that touches binlog logic - ie. another insert to any table (an innodb), it will crash. This seems to be due to lack of cleanup in binlog_cache_data::reset() (called from thd_binlog_trx_reset):

#0 thd_binlog_trx_reset (thd=thd@entry=0x2444170) at /media/Tintin/Work/code/codership/codership-5.6/sql/binlog.cc:8976
#1 0x00000000007b5566 in wsrep_cleanup_transaction (thd=thd@entry=0x2444170) at /media/Tintin/Work/code/codership/codership-5.6/sql/wsrep_hton.cc:39
#2 0x00000000007b5da9 in wsrep_post_commit (thd=thd@entry=0x2444170, all=all@entry=false) at /media/Tintin/Work/code/codership/codership-5.6/sql/wsrep_hton.cc:110
#3 0x000000000079be15 in trans_commit_stmt (thd=thd@entry=0x2444170) at /media/Tintin/Work/code/codership/codership-5.6/sql/transaction.cc:481
#4 0x00000000007007dd in mysql_execute_command (thd=thd@entry=0x2444170) at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_parse.cc:5405
#5 0x0000000000701ddd in mysql_parse (thd=thd@entry=0x2444170, rawbuf=rawbuf@entry=0x7fff74005020 "insert into i1(a) values (NULL)", length=length@entry=31, parser_state=parser_state@entry=0x7fffcc1b9610)
    at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_parse.cc:6775
#6 0x0000000000702761 in wsrep_mysql_parse (thd=thd@entry=0x2444170, rawbuf=0x7fff74005020 "insert into i1(a) values (NULL)", length=31, parser_state=parser_state@entry=0x7fffcc1b9610)
    at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_parse.cc:6555
#7 0x0000000000704005 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x2444170, packet=packet@entry=0x2552f91 "insert into i1(a) values (NULL)", packet_length=packet_length@entry=31)
    at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_parse.cc:1526
#8 0x00000000007067a1 in do_command (thd=0x2444170) at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_parse.cc:1118
#9 0x00000000006c9738 in do_handle_one_connection (thd_arg=thd_arg@entry=0x2444170) at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_connect.cc:1007
#10 0x00000000006c98c3 in handle_one_connection (arg=arg@entry=0x2444170) at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_connect.cc:916
#11 0x0000000000c22de8 in pfs_spawn_thread (arg=0x24cae90) at /media/Tintin/Work/code/codership/codership-5.6/storage/perfschema/pfs.cc:1858
#12 0x00007ffff7bc70a2 in start_thread () from /usr/lib/libpthread.so.0
#13 0x00007ffff6216d1d in clone () from /usr/lib/libc.so.6

(i1 is an innodb table).

This cleanup is not called for non-innodb - memory/myisam tables.

To trigger this crash/issue: you need to do an insert to a non-innodb table followed by anything that touches binlog logic - ie. another insert to any table (an innodb), it will crash. This seems to be due to lack of cleanup  in binlog_cache_data::reset() (called from thd_binlog_trx_reset):

#0  thd_binlog_trx_reset (thd=thd@entry=0x2444170) at /media/Tintin/Work/code/codership/codership-5.6/sql/binlog.cc:8976
#1  0x00000000007b5566 in wsrep_cleanup_transaction (thd=thd@entry=0x2444170) at /media/Tintin/Work/code/codership/codership-5.6/sql/wsrep_hton.cc:39
#2  0x00000000007b5da9 in wsrep_post_commit (thd=thd@entry=0x2444170, all=all@entry=false) at /media/Tintin/Work/code/codership/codership-5.6/sql/wsrep_hton.cc:110
#3  0x000000000079be15 in trans_commit_stmt (thd=thd@entry=0x2444170) at /media/Tintin/Work/code/codership/codership-5.6/sql/transaction.cc:481
#4  0x00000000007007dd in mysql_execute_command (thd=thd@entry=0x2444170) at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_parse.cc:5405
#5  0x0000000000701ddd in mysql_parse (thd=thd@entry=0x2444170, rawbuf=rawbuf@entry=0x7fff74005020 "insert into i1(a) values (NULL)", length=length@entry=31, parser_state=parser_state@entry=0x7fffcc1b9610)
    at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_parse.cc:6775
#6  0x0000000000702761 in wsrep_mysql_parse (thd=thd@entry=0x2444170, rawbuf=0x7fff74005020 "insert into i1(a) values (NULL)", length=31, parser_state=parser_state@entry=0x7fffcc1b9610)
    at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_parse.cc:6555
#7  0x0000000000704005 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x2444170, packet=packet@entry=0x2552f91 "insert into i1(a) values (NULL)", packet_length=packet_length@entry=31)
    at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_parse.cc:1526
#8  0x00000000007067a1 in do_command (thd=0x2444170) at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_parse.cc:1118
#9  0x00000000006c9738 in do_handle_one_connection (thd_arg=thd_arg@entry=0x2444170) at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_connect.cc:1007
#10 0x00000000006c98c3 in handle_one_connection (arg=arg@entry=0x2444170) at /media/Tintin/Work/code/codership/codership-5.6/sql/sql_connect.cc:916
#11 0x0000000000c22de8 in pfs_spawn_thread (arg=0x24cae90) at /media/Tintin/Work/code/codership/codership-5.6/storage/perfschema/pfs.cc:1858
#12 0x00007ffff7bc70a2 in start_thread () from /usr/lib/libpthread.so.0
#13 0x00007ffff6216d1d in clone () from /usr/lib/libc.so.6

(i1 is an innodb table).

This cleanup is not called for non-innodb - memory/myisam tables.

Raghavendra D Prabhu (raghavendra-prabhu) on 2014-02-11

summary:

- Empty GRA_*_*.log file generated after closing a MySQL session that was
- used to insert rows on a MEMORY/MyISAM with binlogging OFF.
+ Empty GRA_*_*.log file with MEMORY/MyISAM tables + binlogging OFF in
+ Release | Assertion failure binlog_cache_data::finalize(THD*,
+ Log_event*): Assertion `!flags.finalized' failed in UNIV_DEBUG build.

Raghavendra D Prabhu (raghavendra-prabhu) on 2014-02-11

summary:

- Empty GRA_*_*.log file with MEMORY/MyISAM tables + binlogging OFF in
- Release | Assertion failure binlog_cache_data::finalize(THD*,
+ MEMORY/MyISAM tables + binlogging OFF | Empty GRA_*_*.log file(s) with
+ Release build | Assertion failure binlog_cache_data::finalize(THD*,
Log_event*): Assertion `!flags.finalized' failed in UNIV_DEBUG build.

Revision history for this message

Seppo Jaakola (seppo-jaakola) wrote on 2014-02-12:

#10

This problem happens when binlog is not enabled and there are statements for non InnoDB tables. Then, binlog events will be created for these statements, but they are never cleaned from transaction cache.

A simple fix is to prevent creating of binlog events for non-InnoDB tables. With this fix MEMORY tables will always remain node local.

Note that MyISAM replication (if wanted by wsrep_replicate_myisam), will still work through TOI replication, these binlog events would not be needed for that.

Revision history for this message

Seppo Jaakola (seppo-jaakola) wrote on 2014-02-12:

#11

Potential fix pushed in revision: http://bazaar.launchpad.net/~codership/codership-mysql/5.6/revision/4040

Revision history for this message

Seppo Jaakola (seppo-jaakola) wrote on 2014-02-13:

#12

Merged the fix also to wsrep-5.5 in revision: http://bazaar.launchpad.net/~codership/codership-mysql/wsrep-5.5/revision/3949
Removed the debug message, which was too chatty, all temporary table access was reported

Revision history for this message

Shahriyar Rzayev (rzayev-sehriyar) wrote on 2018-01-18:

#13

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PXC-1611

	Status	Importance	Assigned to	Milestone
MySQL patches by Codership	Status tracked in 5.6
5.6	Fix Committed	High	Seppo Jaakola
Percona XtraDB Cluster moved to https://jira.percona.com/projects/PXC	Status tracked in 5.6
5.5	Fix Released	Undecided	Unassigned	Percona XtraDB Cluster moved to https://jira.percona.com/projects/PXC 5.5.37-25.10
5.6	Fix Released	High	Unassigned	Percona XtraDB Cluster moved to https://jira.percona.com/projects/PXC 5.6.15-25.4

MySQL patches by Codership

MEMORY/MyISAM tables + binlogging OFF | Empty GRA__.log file(s) with Release build | Assertion failure binlog_cache_data::finalize(THD, Log_event): Assertion `!flags.finalized' failed in UNIV_DEBUG build.

Bug Description

Other bug subscribers

Bug attachments

Remote bug watches

MySQL patches by Codership

MEMORY/MyISAM tables + binlogging OFF | Empty GRA_*_*.log file(s) with Release build | Assertion failure binlog_cache_data::finalize(THD*, Log_event*): Assertion `!flags.finalized' failed in UNIV_DEBUG build.

Bug Description

Other bug subscribers

Bug attachments

Remote bug watches

MEMORY/MyISAM tables + binlogging OFF | Empty GRA__.log file(s) with Release build | Assertion failure binlog_cache_data::finalize(THD, Log_event): Assertion `!flags.finalized' failed in UNIV_DEBUG build.