Failing assertion: btr_pcur_restore_position(thr_get_trx(thr)->fake_changes ? BTR_SEARCH_TREE : BTR_MODIFY_TREE, pcur, mtr) [ in row_upd_clust_step / row_upd_clust_rec ]

121204 7:45:06 InnoDB: Assertion failure in thread 352803136 in file row0upd.c line 2023
InnoDB: Failing assertion: btr_pcur_restore_position(thr_get_trx(thr)->fake_changes ? BTR_SEARCH_TREE : BTR_MODIFY_TREE, pcur, mtr)
InnoDB: We intentionally generate a memory trap.

============= RQG script used:
$ cat cmd85
ps -ef | grep 'cmdrun_85' | grep -v grep | awk '{print $2}' | xargs sudo kill -9
rm -Rf /data/ssd/qa/105/cmdrun_85
mkdir /data/ssd/qa/105/cmdrun_85
cd /data/ssd/qa/105/randgen
bash -c "set -o pipefail; perl runall.pl --queries=100000000 --seed=1101 --duration=300 --querytimeout=60 --short_column_names --sqltrace --reporter=Shutdown,Backtrace,QueryTimeout,ErrorLog,ErrorLogAlarm --mysqld=--log-output=none --mysqld=--sql_mode=ONLY_FULL_GROUP_BY --grammar=conf/percona_qa/percona_qa.yy --gendata=conf/percona_qa/percona_qa.zz --basedir=/data/ssd/qa/105/Percona-Server-5.5.28-rel29.1-359.Linux.x86_64 --valgrind --reporter=ValgrindErrors --validator=MarkErrorLog --threads=1 --notnull --validator=Transformer --mysqld=--innodb_lazy_drop_table=1 --mysqld=--innodb_file_per_table=1 --mysqld=--innodb_file_format=barracuda --mtr-build-thread=781 --mask=8868 --vardir1=/data/ssd/qa/105/cmdrun_85 > /data/ssd/qa/105/cmdrun85.log 2>&1"

============= Versions:
PS: Percona-Server-5.5.28-rel29.1-359.Linux.x86_64
RQG: 794 <email address hidden>

Does not look related to fake changes. Looks like a locking bug, needs further testcase reduction. It should be possible to reduce it to workload involving only table100_innodb_compressed_int and any its views if it is updated through them. Might be timing-dependent though.

Just jotting down some notes. Bug confirmed reproducible using:

[roel@fusion1 102]$ cat cmd57
ps -ef | grep 'cmdrun_57' | grep -v grep | awk '{print $2}' | xargs sudo kill -9
rm -Rf /data/ssd/qa/102/cmdrun_57
mkdir /data/ssd/qa/102/cmdrun_57
cd /data/ssd/qa/102/randgen
bash -c "set -o pipefail; perl runall.pl --queries=100000000 --seed=24123 --duration=600 --querytimeout=60 --short_column_names --sqltrace --reporter=Shutdown,Backtrace,QueryTimeout,ErrorLog,ErrorLogAlarm --mysqld=--log-output=none --mysqld=--sql_mode=ONLY_FULL_GROUP_BY --grammar=conf/percona_qa/percona_qa.yy --gendata=conf/percona_qa/percona_qa.zz --basedir=/data/ssd/qa/102/Percona-Server-5.5.28-rel29.1-359.Linux.x86_64 --valgrind --reporter=ValgrindErrors --validator=MarkErrorLog --threads=1 --views --validator=Transformer --mysqld=--slow_query_log --mysqld=--innodb_lazy_drop_table=1 --mysqld=--innodb_file_per_table=1 --mtr-build-thread=757 --mask=57212 --vardir1=/data/ssd/qa/102/cmdrun_57 > /data/ssd/qa/102/cmdrun57.log 2>&1"[roel@fusion1 102]$ vi /data/ssd/qa/102/cmdrun57.log

RQG: 792 <email address hidden>

Possibly also using script in #2

This bug is seen quite often in RQG testing.

Refined the testcase down to about 10 seconds. Testcase result:

================== Error log:
130122 5:06:49 [Note] /ssd/qa/102/Percona-Server-5.5.28-rel29.1-359.Linux.x86_64/bin/mysqld: ready for connections.
Version: '5.5.28-rel29.1-log' socket: '/ssd/qa/102/vardir1_57/tmp/master.sock' port: 11139 Percona Server with XtraDB (GPL), Release rel29.1, Revision 359
InnoDB: Warning: hash index ref_count (1) is not zero after fil_discard_tablespace().
index: "c32" table: "test/table100_innodb_compressed"
InnoDB: Warning: hash index ref_count (1) is not zero after fil_discard_tablespace().
index: "PRIMARY" table: "test/table100_innodb_default_int"
InnoDB: Warning: hash index ref_count (1) is not zero after fil_discard_tablespace().
index: "c32" table: "test/table100_innodb_compressed"
130122 5:07:10 InnoDB: Assertion failure in thread 67819264 in file row0upd.c line 2023
InnoDB: Failing assertion: btr_pcur_restore_position(thr_get_trx(thr)->fake_changes ? BTR_SEARCH_TREE : BTR_MODIFY_TREE, pcur, mtr)
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.5/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
02:07:10 UTC - mysqld got signal 6 ;
==================

Note that both --innodb_file_per_table=1 and --innodb_lazy_drop_table=1 are required!

To execute the testcase:
1. Get PS (this was found on Percona-Server-5.5.28-rel29.1-359.Linux.x86_64)
2. Build with './build/build-binary.sh --debug ..', then untar
3. Set paths in start_mtr57 and test_mtr57 to the correct locations.
4. ./start_mtr57
5. time ./test_mtr57 # should complete in ~10 seconds. Crash data in vardir1_57

Sidenote; during testcase creation, I also saw the following happen at some point (note the 600 second timeout):

==================
InnoDB: Warning: hash index ref_count (1) is not zero after fil_discard_tablespace().
index: "PRIMARY" table: "test/table100_innodb_default_int"
InnoDB: Error: Waited for 5 secs for hash index ref_count (1) to drop to 0.
[...counts up to 600 seconds...]
InnoDB: Error: Waited for 600 secs for hash index ref_count (1) to drop to 0.
index: "PRIMARY" table: "test/table100_innodb_default_int"
130118 13:07:08 InnoDB: Assertion failure in thread 67819264 in file dict0dict.c line 1883
==================

Which in turn may relate to bug 1086227 / bug 897258 / bug 798371 (thanks AlexeyK)

Should be fixed by the lazy drop table removal. Marking this as "Incomplete", so that it can be reopened in the case the crash resurfaces without the lazy drop table.

[Expired for Percona Server 5.5 because there has been no activity for 60 days.]

Based on bug not showing anymore, set to fix released.

Note bug 1193138

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