Assertion failure in thread x in file fts0que.cc line 3659

Bug #1634932 reported by Przemek on 2016-10-19
18
This bug affects 2 people
Affects Status Importance Assigned to Milestone
MySQL Server
Unknown
Unknown
Percona Server moved to https://jira.percona.com/projects/PS
Status tracked in 5.7
5.5
Invalid
Undecided
Unassigned
5.6
Fix Released
High
Robert Golebiowski
5.7
Fix Released
High
Robert Golebiowski
Percona XtraDB Cluster moved to https://jira.percona.com/projects/PXC
Fix Released
Undecided
Unassigned

Bug Description

Seen occasionally on PXC 5.6.26-74.0-56 and 5.6.30-76.3-56

2016-10-19 11:26:05 7fc6502a6700 InnoDB: Assertion failure in thread 140489725208320 in file fts0que.cc line 3659
InnoDB: Failing assertion: !query->intersection
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.
11:26:05 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=16777216
read_buffer_size=131072
max_used_connections=101
max_threads=102
thread_count=51
connection_count=42
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 57007 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x1b49590
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 = 7fc6502a5d38 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x35)[0x906e45]
/usr/sbin/mysqld(handle_fatal_signal+0x4b4)[0x66ac44]
/lib64/libpthread.so.0(+0xf7e0)[0x7fc69c74b7e0]
/lib64/libc.so.6(gsignal+0x35)[0x7fc69a9855e5]
/lib64/libc.so.6(abort+0x175)[0x7fc69a986dc5]
/usr/sbin/mysqld[0xb4b0c3]
/usr/sbin/mysqld[0x9ab2d1]
/usr/sbin/mysqld(_ZN15Item_func_match11init_searchEb+0x167)[0x607e57]
/usr/sbin/mysqld(_Z12init_ftfuncsP3THDP13st_select_lexb+0x60)[0x69a510]
/usr/sbin/mysqld(_ZN4JOIN8optimizeEv+0x26d9)[0x86f829]
/usr/sbin/mysqld(_Z12mysql_selectP3THDP10TABLE_LISTjR4ListI4ItemEPS4_P10SQL_I_ListI8st_orderESB_S7_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x207)[0x71a8d7]
/usr/sbin/mysqld(_Z13handle_selectP3THDP13select_resultm+0x187)[0x71b1a7]
/usr/sbin/mysqld[0x6ef5ed]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x49a1)[0x6f5491]
/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x628)[0x6f7e18]
/usr/sbin/mysqld[0x6f7fb2]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1896)[0x6fa1e6]
/usr/sbin/mysqld(_Z10do_commandP3THD+0x22b)[0x6fba9b]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x17f)[0x6c216f]
/usr/sbin/mysqld(handle_one_connection+0x47)[0x6c2357]
/usr/sbin/mysqld(pfs_spawn_thread+0x12a)[0x994b6a]
/lib64/libpthread.so.0(+0x7aa1)[0x7fc69c743aa1]
/lib64/libc.so.6(clone+0x6d)[0x7fc69aa3baad]

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

Przemek (pmalkowski) wrote :

Attaching my.cnf from affected instance. The innodb_ft_result_cache_limit is now 256M, but it seems that with previous 128M the crashes were more frequent.

Krunal Bauskar (krunal-bauskar) wrote :

a. Can you please provide a test-case.

b. From the log it seems like server did hit an assert during normal select so likely that we should hit it with upstream (MySQL/PS) too.

Przemek (pmalkowski) wrote :
Download full text (6.5 KiB)

OK, I reproduced the same on Percona Server 5.6.33.
The test case:

On a sandbox instance, used these settings:
innodb_flush_log_at_trx_commit = 0
innodb_flush_method = O_DIRECT
innodb_buffer_pool_size = 1G
innodb_log_file_size = 1G
max_allowed_packet = 128M
innodb_ft_result_cache_limit = 16M

-- Created table:
mysql [localhost] {msandbox} (test) > CREATE TABLE `text_content` ( `text_content_id` int(11) NOT NULL AUTO_INCREMENT, `content_id` int(11) NOT NULL DEFAULT '0', `active` enum('Y','N') DEFAULT 'Y', `revision` smallint(6) NOT NULL DEFAULT '1', `page` smallint(6) NOT NULL DEFAULT '1', `text_content` mediumtext, `created_date` datetime NOT NULL DEFAULT '0000-00-00 00:00:00', PRIMARY KEY (`text_content_id`), KEY `key_content_active` (`content_id`,`active`), FULLTEXT KEY `text_content` (`text_content`) ) ENGINE=InnoDB DEFAULT CHARSET=utf8;
Query OK, 0 rows affected (0.13 sec)

-- installed procedure from http://kedar.nitty-witty.com/blog/generate-random-test-data-for-mysql-using-routines:
mysql [localhost] {msandbox} (test) > source ../populate_dummy_data.sql
...
Query OK, 0 rows affected (0.00 sec)

-- populated 500k rows:
mysql [localhost] {msandbox} (test) > call populate('test','text_content',500000,'N');
+---------------------+
| Developed by |
+---------------------+
| Kedar Vaijanapurkar |
+---------------------+
1 row in set (2 min 5.20 sec)

-- updated most of the rows, the blob column with text file from mysqlsandbox installation:
mysql [localhost] {msandbox} (test) > update text_content set text_content=LOAD_FILE('/home/przemyslaw.malkowski/sandboxes/ps5.6.33/clear') where text_content_id>40000;
Query OK, 460500 rows affected (5 min 47.44 sec)
Rows matched: 460500 Changed: 460500 Warnings: 0

-- executed query:
mysql [localhost] {msandbox} (test) > select content_id,page from text_content where MATCH (text_content.text_content) AGAINST ('+databases +language +compliance +limitations ' IN BOOLEAN MODE) limit 300;
ERROR 2013 (HY000): Lost connection to MySQL server during query

-- crash trace:

Version: '5.6.33-79.0' socket: '/tmp/mysql_sandbox25633.sock' port: 25633 Percona Server (GPL), Release 79.0, Revision 2084bdb
2016-10-21 11:05:29 7f8460c42700 InnoDB: Assertion failure in thread 140206535878400 in file fts0que.cc line 3659
InnoDB: Failing assertion: !query->intersection
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.
15:05:29 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.
Ple...

Read more...

Changed in percona-server:
status: New → Confirmed

Is there an upstream bug report?

tags: added: innodb upstream
Przemek (pmalkowski) wrote :
Download full text (4.2 KiB)

Same crash reproduced on PS 5.7.14 and PS 5.7.15:

2016-10-27 07:18:21 0x7fb1fa7f9700 InnoDB: Assertion failure in thread 140402388604672 in file fts0que.cc line 3831
InnoDB: Failing assertion: !query->intersection
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.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
11:18:21 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.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might 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=152
thread_count=1
connection_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 68309 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7fb1cf816000
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 = 7fb1fa7f8df0 thread_stack 0x40000
/home/przemyslaw.malkowski/sandboxes/tarballs/percona5.7.15/bin/mysqld(my_print_stacktrace+0x2e)[0xfee3be]
/home/przemyslaw.malkowski/sandboxes/tarballs/percona5.7.15/bin/mysqld(handle_fatal_signal+0x4a1)[0x943d51]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x10330)[0x7fb1fa24a330]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x37)[0x7fb1f83e5c37]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x148)[0x7fb1f83e9028]
/home/przemyslaw.malkowski/sandboxes/tarballs/percona5.7.15/bin/mysqld[0x91458b]
/home/przemyslaw.malkowski/sandboxes/tarballs/percona5.7.15/bin/mysqld(_Z9fts_queryP5trx_tP12dict_index_tjPKhmPP12fts_result_ty+0x2371)[0x1320981]
/home/przemyslaw.malkowski/sandboxes/tarballs/percona5.7.15/bin/mysqld(_ZN11ha_innobase11ft_init_extEjjP6String+0x379)[0x1095929]
/home/przemyslaw.malkowski/sandboxes/tarballs/percona5.7.15/bin/mysqld(_ZN15Item_func_match11init_searchEP3THD+0x157)[0xa0a6c7]
/home/przemyslaw.malkowski/sandboxes/tarballs/percona5.7.15/bin/mysqld(_Z12init_ftfuncsP3THDP13st_select_lex+0x4c)[0xda86fc]
/home/przemyslaw.malkowski/sandboxes/tarballs/percona5.7.15/bin/mysqld(_ZN4JOIN8optimizeEv+0x23cc)[0xdf0c1c]
/home/przemyslaw.malkowski/sandboxes/tarballs/percona5.7.15/bin/mysqld(_ZN13st_select_lex8optimizeEP3THD+0x4a)[0xe2c92a]
/home/przemyslaw.malkowski/sandboxes/tarballs/percona5.7.15/bin/mysqld(_Z12handle_queryP3THDP3LEXP12Query_resultyy+0x165)[0xe2caf5]
/home/przemyslaw.malkowski/sandboxes/tarballs/percona5.7.15/bin/mysqld[0x90aeba]
/home/przemyslaw.malkowsk...

Read more...

Przemek (pmalkowski) wrote :

Also reproduced the same on upstream MySQL 5.7.16

Changed in percona-xtradb-cluster:
status: New → Fix Released

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

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

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers

Bug attachments

Remote bug watches

Bug watches keep track of this bug in other bug trackers.