Percona XtraDB Cluster 5.6 crash on ALTER TABLE / CREATE INDEX | InnoDB: Assertion failure in thread 140662130571008 in file lock0lock.cc line 6384 - Failing assertion: lock_table_has(trx, index->table, LOCK_IX) - UNIV_DEBUG | Failing assertion: table->n_rec_locks == 0 in Release Build

@i.Tuzhilkin ,

You seem to be using 5.6.15-25.3, can you test with 5.6.15-25.4 which was released today? (which has "Server version: 5.6.15-63.0-log Percona XtraDB Cluster (GPL), Release 25.4, wsrep_25.4.r4043")

Also,

Please provide cnf as well as error log (and general log if any).

In addition:

a) Can you provide structure of the table before the crash?

b) Also, if you have test data that can be loaded, please provide that

I tested with sbtest and it didn't crash:

====================
MySQL [sbtest]> show create table sbtest1;
+---------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Table | Create Table |
+---------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| sbtest1 | CREATE TABLE `sbtest1` (
  `id` int(10) unsigned NOT NULL AUTO_INCREMENT,
  `k` int(10) unsigned NOT NULL DEFAULT '0',
  `c` char(120) NOT NULL DEFAULT '',
  `pad` char(60) NOT NULL DEFAULT '',
  PRIMARY KEY (`id`),
  KEY `k_1` (`k`)
) ENGINE=InnoDB AUTO_INCREMENT=100001 DEFAULT CHARSET=utf8 MAX_ROWS=1000000 |
+---------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)

MySQL [sbtest]> alter table sbtest1 change c c varchar(200) NULL;
Query OK, 100000 rows affected (2.79 sec)
Records: 100000 Duplicates: 0 Warnings: 0

MySQL [sbtest]> show create table sbtest1;
+---------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Table | Create Table |
+---------+-----------------------------------------------------------------------------------------------------------------------------------------------------------...

> Please provide cnf as well as error log (and general log if any).

Sorry general log is disabled, error log I already attached.

> a) Can you provide structure of the table before the crash?

No I can't provide it now, maybe tommorow. Our programmer is offline now.

Maybe i'll try upgrade server to newer build.

my.cnf:
###############################
[client]
port = 3306
socket = /var/run/mysqld/mysqld.sock

[mysqld_safe]
wsrep_cluster_address=gcomm://
socket = /var/run/mysqld/mysqld.sock
nice = 0

[mysqld]
query_cache_size=0
binlog_format=ROW
default_storage_engine=InnoDB
innodb_autoinc_lock_mode=2
innodb_locks_unsafe_for_binlog=1
innodb_doublewrite=1
wsrep_provider=/usr/lib/libgalera_smm.so
wsrep_provider_options="gcache.size=4G; gcache.page_size=2G; socket.checksum =1"
wsrep_cluster_address=gcomm://1.2.3.6,1.2.3.5
wsrep_cluster_name=""My_Cluster""
wsrep_node_address="1.2.3.4"
wsrep_node_name="db1"
wsrep_sst_method=xtrabackup
wsrep_sst_auth="root:mypasswd"
wsrep_node_incoming_address=1.2.3.4
wsrep_sst_receive_address=1.2.3.4
wsrep_slave_threads=2

user = mysql
pid-file = /var/run/mysqld/mysqld.pid
socket = /var/run/mysqld/mysqld.sock
port = 3306
basedir = /usr
datadir = /var/lib/mysql
tmpdir = /tmp
lc_messages_dir = /usr/share/mysql
lc_messages = en_US
skip-external-locking
skip-name-resolve

character_set_server = utf8
collation_server = utf8_general_ci

bind-address = 0.0.0.0

max_connections = 100
connect_timeout = 65
wait_timeout = 65
max_allowed_packet = 16M
thread_cache_size = 100
sort_buffer_size = 1M
bulk_insert_buffer_size = 1M
tmp_table_size = 256M
max_heap_table_size = 256M
#net_buffer_length = 8K

myisam_recover = BACKUP
key_buffer_size = 16M
myisam_sort_buffer_size = 1M
concurrent_insert = 2

table_open_cache = 20000
table_definition_cache = 20000

read_buffer_size = 512K
read_rnd_buffer_size = 512K

join_buffer_size = 4M

#general_log_file = /var/log/mysql/mysql.log
#general_log = 1
#log_warnings = 2
log_error = /var/log/mysql/error.log

slow_query_log = 1
slow_query_log_file = /var/log/mysql/mariadb-slow.log
long_query_time = 10
log_slow_rate_limit = 1000
#log_slow_verbosity = query_plan

log-queries-not-using-indexes
log_slow_admin_statements

log_bin = /var/log/mysql/mysql-bin
log_bin_index = /var/log/mysql/mysql-bin.index

sync_binlog = 1
expire_logs_days = 10
max_binlog_size = 32M

innodb_data_home_dir = /var/lib/mysql
innodb_log_group_home_dir = /var/lib/mysql
innodb_buffer_pool_size = 8096M
innodb_flush_log_at_trx_commit = 2
innodb_log_buffer_size = 64M
innodb_log_file_size = 256M
innodb_file_per_table = 1
innodb_open_files = 20000
innodb_io_capacity = 200
innodb_flush_method = O_DIRECT
innodb_thread_concurrency = 2
innodb_change_buffering = all
innodb_force_recovery = 0

[mysqldump]
quick
quote-names
max_allowed_packet = 200M

[isamchk]
key_buffer = 8M
###############################

[Expired for Percona XtraDB Cluster because there has been no activity for 60 days.]

It happens again, on fresh release. Same error.

After this:
"ALTER TABLE common_referal_payment CHANGE parent_payment_id parent_payment_id INTEGER(11) NOT NULL;"

Table structure:

CREATE TABLE IF NOT EXISTS `common_referal_payment` (
  `id` int(11) NOT NULL,
  `child_id` int(11) NOT NULL,
  `parent_payment_id` int(11) NOT NULL,
  PRIMARY KEY (`id`),
  KEY `child_id` (`child_id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8;

ALTER TABLE `common_referal_payment`
  ADD CONSTRAINT `common_referal_payment_ibfk_1` FOREIGN KEY (`id`) REFERENCES `abstract_payment` (`id`) ON DELETE CASCADE,
  ADD CONSTRAINT `common_referal_payment_ibfk_2` FOREIGN KEY (`child_id`) REFERENCES `users` (`id`) ON DELETE CASCADE;

Hi,

same issue here.

ii percona-xtrabackup 2.2.3-4982-1.precise Open source backup tool for InnoDB and XtraDB
ii percona-xtradb-cluster-client 5.6.15-25.2-645.precise Percona Server database client
ii percona-xtradb-cluster-client-5.6 5.6.19-25.6-824.precise Percona XtraDB Cluster database client binaries
ii percona-xtradb-cluster-common-5.6 5.6.19-25.6-824.precise Percona XtraDB Cluster database common files (e.g. /etc/mysql/my.cnf)
ii percona-xtradb-cluster-galera-3.x 3.6.3190.precise Galera components of Percona XtraDB Cluster
ii percona-xtradb-cluster-server 5.6.15-25.2-645.precise Percona Server database server
ii percona-xtradb-cluster-server-5.6 5.6.19-25.6-824.precise Percona XtraDB Cluster database server binaries
root@tlsisxdb001l:~#

Note that we discovered that when doing the requests manually there is no problem, but when using python mysqldb, it crashes.

Same problem here but much much severe.
When running alter table the Master crashed. On restarting the Master 10,000 records of the table went missing. Repeated the same alter table twice more with the same result - each time 10,000 records were deleted.
The ALTER TABLE command was only modifying a column definition from NULL to NOT NULL.
My configuration is:
Percona-Server-shared-51.x86_64
                                        @percona
Percona-XtraDB-Cluster-client-56.x86_64
                                        @percona
Percona-XtraDB-Cluster-galera-3.x86_64
                        3.5-1.216.rhel6 @percona
Percona-XtraDB-Cluster-server-56.x86_64
                                        @percona
Percona-XtraDB-Cluster-shared-56.x86_64
                                        @percona
percona-xtrabackup.x86_64
                        2.1.9-744.rhel6 @percona

Server version: 5.6.15-56 Percona XtraDB Cluster (GPL), Release 25.5, Revision 759, wsrep_25.5.r4061

Some additional info:
Performed the following test: 1. CREATE TABLE xyz (id int auto_increment not null, sdate datetime null, primary key (id)); 2. INSERT INTO xyz VALUES(default, now()) - repeat 100000 times; 3. ALTER TABLE xyz MODIFY sdate datetime NOT NULL.

That will crash the server and delete 10000 records both using the mysql-python and the oracle mysql connecter for python.

More updates:
Tested with Galera 3.5 & MySQL 5.6 & Python - No Issues.
It is definitely a Percona bug!!!

Hit the bug yesterday with the ability to reproduce.

Server version: 5.6.20-68.0-56-log Percona XtraDB Cluster (GPL), Release 25.7, wsrep_25.7.r4126

@Alex, @Marc,

Thank you for reporting.

@Alex,

I tested with

"
1. CREATE TABLE xyz (id int auto_increment not null, sdate datetime null, primary key (id)); 2. INSERT INTO xyz VALUES(default, now()) - repeat 100000 times; 3. ALTER TABLE xyz MODIFY sdate datetime NOT NULL.

"

I was not able to reproduce with 5.6.21 (galera 3.8) which is in experimental
repo now.

Can you try with that and let me know.

The file used to create table for ALTER TABLE.

Also repeatable with codership binaries.

Crashes with UNIV_DEBUG as follows:

2015-01-24 20:01:15 7fffb01dc700 InnoDB: Assertion failure in thread 140736148129536 in file lock0lock.cc line 6384
InnoDB: Failing assertion: lock_table_has(trx, index->table, LOCK_IX)
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.

Program received signal SIGABRT, Aborted.
[Switching to Thread 0x7fffb01dc700 (LWP 30829)]
0x00007ffff5ed0a97 in raise () from /usr/lib/libc.so.6
(gdb) bt
#0 0x00007ffff5ed0a97 in raise () from /usr/lib/libc.so.6
#1 0x00007ffff5ed1e6a in abort () from /usr/lib/libc.so.6
#2 0x00000000009ff9cd in lock_rec_insert_check_and_lock (flags=flags@entry=0, rec=rec@entry=0x7fffd636ad6a "\200", block=0x7fffb841e930, index=index@entry=0x7fff7436edc8, thr=thr@entry=0x7fff74374d00,
    mtr=mtr@entry=0x7fffb01d7860, inherit=0x7fffb01d76b8) at /media/Oort/ncode/percona-xtradb-cluster/pxc56-test/storage/innobase/lock/lock0lock.cc:6384
#3 0x0000000000afce47 in btr_cur_ins_lock_and_undo (flags=flags@entry=0, cursor=cursor@entry=0x7fffb01d77e0, entry=entry@entry=0x7fff7436b8d8, thr=thr@entry=0x7fff74374d00, mtr=mtr@entry=0x7fffb01d7860,
    inherit=inherit@entry=0x7fffb01d76b8) at /media/Oort/ncode/percona-xtradb-cluster/pxc56-test/storage/innobase/btr/btr0cur.cc:1263
#4 0x0000000000b0830d in btr_cur_optimistic_insert (flags=flags@entry=0, cursor=cursor@entry=0x7fffb01d77e0, offsets=offsets@entry=0x7fffb01d77c0, heap=heap@entry=0x7fffb01d77d0,
    entry=entry@entry=0x7fff7436b8d8, rec=rec@entry=0x7fffb01d77d8, big_rec=0x7fffb01d77c8, n_ext=0, thr=0x7fff74374d00, mtr=0x7fffb01d7860)
    at /media/Oort/ncode/percona-xtradb-cluster/pxc56-test/storage/innobase/btr/btr0cur.cc:1501
#5 0x0000000000a689c5 in row_ins_clust_index_entry_low (flags=flags@entry=0, mode=<optimized out>, mode@entry=2, index=index@entry=0x7fff7436edc8, n_uniq=n_uniq@entry=1, entry=entry@entry=0x7fff7436b8d8,
    n_ext=n_ext@entry=0, thr=0x7fff74374d00) at /media/Oort/ncode/percona-xtradb-cluster/pxc56-test/storage/innobase/row/row0ins.cc:2520
#6 0x0000000000a6a72f in row_ins_clust_index_entry (index=0x7fff7436edc8, entry=0x7fff7436b8d8, thr=thr@entry=0x7fff74374d00, n_ext=n_ext@entry=0)
    at /media/Oort/ncode/percona-xtradb-cluster/pxc56-test/storage/innobase/row/row0ins.cc:2924
#7 0x0000000000a6a9d2 in row_ins_index_entry (index=<optimized out>, entry=<optimized out>, thr=thr@entry=0x7fff74374d00)
    at /media/Oort/ncode/percona-xtradb-cluster/pxc56-test/storage/innobase/row/row0ins.cc:3022
#8 0x0000000000a6aa58 in row_ins_index_entry_step (node=node@entry=0x7fff74373ed0, thr=thr@entry=0x7fff74374d00) at /media/Oort/ncode/percona-xtradb-cluster/pxc56-test/storage/innobase/row/row0ins.cc:3099
#9 0x0000000000a6ab3c in row_ins (node=node@entry=0x7fff74373ed0, thr=thr@entry=0x7fff74374d00) at /media/Oort/ncode/percona-xtradb-cluster/pxc56-test/storage/innobase/row/row0...

The build with fix is available in our apt/yum experimental repository and binaries are available from:
http://www.percona.com/downloads/TESTING/issue-50153/

The same has happened on
Ubuntu 14.04.1 LTS
+ percona-xtradb-cluster-client-5.6 5.6.21-25.8-938.trusty
+ percona-xtradb-cluster-common-5.6 5.6.21-25.8-938.trusty
+ percona-xtradb-cluster-galera-3.x 3.8.3390.trusty
+ percona-xtradb-cluster-server-5.6 5.6.21-25.8-938.trusty

The alter statement was
ALTER TABLE `db_name`.`table_name` ADD COLUMN `hostname` VARCHAR(255) NULL;
after, there were couple updates like...
UPDATE `db_name`.`table_name` SET `hostname`='localhost';
all of them were preserved in other nodes, while first node has collapsed and couldn't getup.

2015-01-29 09:09:45 5461 [ERROR] Transaction not registered for MySQL 2PC, but transaction is active
2015-01-29 09:09:45 7f20a485b700 InnoDB: Assertion failure in thread 139778175907584 in file row0mysql.cc line 4041
InnoDB: Failing assertion: table->n_rec_locks == 0
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
09:09:45 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=33554432
read_buffer_size=131072
max_used_connections=93
max_threads=202
thread_count=48
connection_count=46
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 113388 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x1ca6410
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 = 7f20a485ae20 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x2c)[0x923b1c]
/usr/sbin/mysqld(handle_fatal_signal+0x352)[0x67cac2]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x10340)[0x7f251d61c340]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x39)[0x7f251ca5cbb9]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x148)[0x7f251ca5ffc8]
/usr/sbin/mysqld[0x9ec969]
/usr/sbin/mysqld[0x949c77]
/usr/sbin/mysqld(_Z15ha_delete_tableP3THDP10handlertonPKcS4_S4_b+0x157)[0x5b26e7]
/usr/sbin/mysqld(_Z14quick_rm_tableP3THDP10handlertonPKcS4_j+0x1a2)[0x75c7b2]
/usr/sbin/mysqld(_Z17mysql_alter_tableP3THDPcS1_P24st_ha_create_informationP10TABLE_LISTP10Alter_infojP8st_orderb+0x2ccc)[0x766c1c]
/usr/sbin/mysqld(_ZN19Sql_cmd_alter_table7executeEP3TH...

Hi,

I have tested the 5.6.21-25.8-939.trusty binaries 3 times, so far they solve the problem for me.
When they will be moved to the main repository?

Hi,

Has this release been pushed to the official repo? I've just checked and still shows 938 only available.

# dpkg -l | grep percona | awk '{print $2}' | xargs apt-cache policy | grep 'Installed' -B1 -A1
percona-xtradb-cluster-client-5.6:
  Installed: 5.6.21-25.8-938.trusty
  Candidate: 5.6.21-25.8-938.trusty
--
percona-xtradb-cluster-common-5.6:
  Installed: 5.6.21-25.8-938.trusty
  Candidate: 5.6.21-25.8-938.trusty
--
percona-xtradb-cluster-galera-3.x:
  Installed: 3.8.3390.trusty
  Candidate: 3.8.3390.trusty
--
percona-xtradb-cluster-server-5.6:
  Installed: 5.6.21-25.8-938.trusty
  Candidate: 5.6.21-25.8-938.trusty

Its available in the experimental repo and working well from there. From what they've said it will be in the next release in the main repo (as a different version).

Thank you Matt, I know, I got it, but I need to update other environments too.
If anybody could answer this questions, I would be thankful.

1. Do we know how long we should wait?
2. Which version will be moved to the main repo
- the same as is now in the testing repo (939)
- higher than and including other fixes (so requires testing on my side again)?

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