[MDEV-11093] FULLTEXT query crashes MariaDB 10.0.27 Created: 2016-10-20  Updated: 2016-11-17  Resolved: 2016-11-17

Status: Closed
Project: MariaDB Server
Component/s: Full-text Search, Storage Engine - InnoDB
Affects Version/s: 10.0.27
Fix Version/s: N/A

Type: Bug Priority: Critical
Reporter: Southparkfan Assignee: Unassigned
Resolution: Cannot Reproduce Votes: 0
Labels: None
Environment:

3GB OpenVZ VPS, 2.6.32-042stab094.8, Debian 8, MariaDB 10.0.27 as provided by Debian (10.0.27-MariaDB-0+deb8u1)



 Description   

Two days ago, a user of our site executed a search that triggered this SQL query:

SELECT page_id,page_namespace,page_title  FROM `page`,`searchindex`   WHERE (page_id=si_page) AND ( MATCH(si_text) AGAINST('+\"u8e7a791 u8e4b8be u8e4bc98 u8e7ad89 u8e7949f u8efbc8c u8e4b88d u8e5a682 u8e58d8a u8e9878e u8e4baba\" ' IN BOOLEAN MODE) ) AND page_namespace = '0'  

While that seems like a normal (FULLTEXT) query to me, MariaDB did not handle that properly and crashed:

2016-10-18 17:17:18 7fc84e16c700  InnoDB: Assertion failure in thread 140498280302336 in file fts0que.cc line 3391
InnoDB: Failing assertion: ret == 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.
""""""""""""""""161018 17:17:18 [ERROR] 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.
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
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.
 
Server version: 10.0.27-MariaDB-0+deb8u1
key_buffer_size=33554432
read_buffer_size=131072
max_used_connections=76
max_threads=77
thread_count=18
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 201826 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x0x7fc802837008
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 = 0x7fc84e16be88 thread_stack 0x48000
/usr/sbin/mysqld(my_print_stacktrace+0x2e)[0xbfff4e]
/usr/sbin/mysqld(handle_fatal_signal+0x3af)[0x7344af]
/lib/x86_64-linux-gnu/libpthread.so.0(+0xf8d0)[0x7fc8b043b8d0]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x37)[0x7fc8aefe4067]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x148)[0x7fc8aefe5448]
/usr/sbin/mysqld[0xa54a79]
/usr/sbin/mysqld[0x8ad0e5]
/usr/sbin/mysqld(_ZN15Item_func_match11init_searchEb+0x3f3)[0x79a0d3]
/usr/sbin/mysqld(_Z12init_ftfuncsP3THDP13st_select_lexb+0x30)[0x57cb90]
/usr/sbin/mysqld[0x615b00]
/usr/sbin/mysqld(_ZN4JOIN8optimizeEv+0x11b)[0x616fdb]
/usr/sbin/mysqld(_Z13handle_selectP3THDP3LEXP13select_resultm+0xa47)[0x61af57]
/usr/sbin/mysqld[0x5b7beb]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x4c64)[0x5c3574]
/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x1ca)[0x5c523a]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1531)[0x5c6d01]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x25b)[0x69543b]
/usr/sbin/mysqld(handle_one_connection+0x39)[0x695489]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x80a4)[0x7fc8b04340a4]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7fc8af09762d]
 
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x7fc8068af020): is an invalid pointer
Connection ID (thread ID): 10364277
Status: NOT_KILLED
 
Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on
 
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.

We think the query pointer is invalid, but we will try to print it anyway.
Query: SELECT page_id,page_namespace,page_title  FROM `page`,`searchindex`   WHERE (page_id=si_page) AND ( MATCH(si_text) AGAINST('+\"u8e7a791 u8e4b8be u8e4bc98 u8e7ad89 u8e7949f u8efbc8c u8e4b88d u8e5a682 u8e58d8a u8e9878e u8e4baba\" ' IN BOOLEAN MODE) ) AND page_namespace = '0'  LIMIT 20

We immediately tried to restart MariaDB, but without success, we think InnoDB data corruption occurred, thus we ended up restarting MariaDB with innodb-force-recovery = 6, dumping all our databases and importing them on a fresh MariaDB installation.

https://github.com/MariaDB/server/blob/10.0/storage/innobase/fts/fts0que.cc#L3391 is the failing assertion. A "show create table" of searchindex:

+-------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Table       | Create Table                                                                                                                                                                                                                                                                                              |
+-------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| searchindex | CREATE TABLE `searchindex` (
  `si_page` int(10) unsigned NOT NULL,
  `si_title` varchar(255) NOT NULL DEFAULT '',
  `si_text` mediumtext NOT NULL,
  UNIQUE KEY `si_page` (`si_page`),
  FULLTEXT KEY `si_title` (`si_title`),
  FULLTEXT KEY `si_text` (`si_text`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8 |
+-------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+

The table is filled with 54k rows.



 Comments   
Comment by Elena Stepanova [ 2016-10-21 ]

It's doubtful that SELECT itself corrupted the data, it's more likely that it got corrupted before by something else, and it caused both the assertion failure and the following recovery problems.

Could you please also paste the output of SHOW CREATE TABLE page, and attach the full error log (at least from the beginning of the session preceding the reported assertion failure, including the failure itself and the following restart which failed to happen), and your cnf files?
Thanks.

Comment by Southparkfan [ 2016-10-21 ]

Hi, this is the page table:

+-------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Table | Create Table                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                          |
+-------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| page  | CREATE TABLE `page` (
  `page_id` int(10) unsigned NOT NULL AUTO_INCREMENT,
  `page_namespace` int(11) NOT NULL,
  `page_title` varchar(255) CHARACTER SET latin1 COLLATE latin1_bin NOT NULL,
  `page_restrictions` tinyblob NOT NULL,
  `page_is_redirect` tinyint(3) unsigned NOT NULL DEFAULT '0',
  `page_is_new` tinyint(3) unsigned NOT NULL DEFAULT '0',
  `page_random` double unsigned NOT NULL,
  `page_touched` binary(14) NOT NULL DEFAULT '\0\0\0\0\0\0\0\0\0\0\0\0\0\0',
  `page_links_updated` varbinary(14) DEFAULT NULL,
  `page_latest` int(10) unsigned NOT NULL,
  `page_len` int(10) unsigned NOT NULL,
  `page_content_model` varbinary(32) DEFAULT NULL,
  `page_lang` varbinary(35) DEFAULT NULL,
  PRIMARY KEY (`page_id`),
  UNIQUE KEY `name_title` (`page_namespace`,`page_title`),
  KEY `page_random` (`page_random`),
  KEY `page_len` (`page_len`),
  KEY `page_redirect_namespace_len` (`page_is_redirect`,`page_namespace`,`page_len`)
) ENGINE=InnoDB AUTO_INCREMENT=54298 DEFAULT CHARSET=latin1 |
+-------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+

Configuration (when it crashed):

[client]
ssl-ca=/etc/ssl/certs/GlobalSign.crt
 
[mysql]
port                           = 3306
socket                         = /var/run/mysqld/mysqld.sock
 
[mysqld]
user                           = mysql
port                           = 3306
default-storage-engine         = InnoDB
socket                         = /var/run/mysqld/mysqld.sock
pid-file                       = /var/run/mysqld/mysqld.pid
skip-name-resolve
key-buffer-size                = 32M
myisam-recover                 = FORCE,BACKUP
 
max-allowed-packet             = 16M
max-connect-errors             = 1000000
sql-mode                       = STRICT_TRANS_TABLES,ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_AUTO_VALUE_ON_ZERO,NO_ENGINE_SUBSTITUTION,NO_ZERO_DATE,NO_ZERO_IN_DATE
sysdate-is-now                 = 1
innodb                         = FORCE
 
datadir                        = /srv/mariadb
 
transaction-isolation          = READ-COMMITTED
binlog_format                  = ROW
 
log-bin                        = /srv/mariadb/mysql-bin
expire-logs-days               = 14
sync-binlog                    = 1
 
tmp-table-size                 = 12M
max-heap-table-size            = 12M
query-cache-type               = 0
query-cache-size               = 0
max-connections                = 75
thread-cache-size              = 50
open-files-limit               = 65535
table-definition-cache         = 700
table-open-cache               = 700
 
innodb-flush-method            = O_DIRECT
innodb-log-files-in-group      = 2
innodb-log-file-size           = 64M
innodb-flush-log-at-trx-commit = 1
innodb-file-per-table          = 1
innodb-buffer-pool-size        = 1024M
innodb-buffer-pool-instances   = 1
innodb_lock_wait_timeout       = 120
innodb-stats-on-metadata       = OFF
 
performance_schema = off
 
log-error                      = /var/log/mysql/mysql-error.log
log-queries-not-using-indexes  = 1
slow-query-log                 = 1
slow-query-log-file            = /var/log/mysql/mysql-slow.log
 
ssl
ssl-ca                         = /etc/ssl/certs/GlobalSign.crt
ssl-cert                       = /etc/ssl/certs/oursite.crt
ssl-key                        = /etc/ssl/private/oursite-nopass.key

Unfortunately, the log files were lost in a reinstall of the affected database server (a colleague actually asked us to create a backup of it, but it didn't happen).

Also, noteworthy: I ran the query on our production db server and another db server, and it ran without errors in 9.10sec. I believe you are right about the corruption (and causing this), reproducing it seems impossible. I wonder when/how the corruption started, but the corrupted data is gone, so figuring that out will be a hard task. Thank you for your assistance.

Comment by Elena Stepanova [ 2016-10-21 ]

I wonder when/how the corruption started, but the corrupted data is gone, so figuring that out will be a hard task

Yes, that's why we needed the error log, it could have shown when the corruption occurred. It could be a previous crash, or a DDL that went very wrong, or something else.
Without the error log, it will be indeed difficult to figure out.

Comment by Ian Gilfillan [ 2016-11-17 ]

Don't think there's much hope of this bug being resolved as is, the corruption was probably elsewhere, with no way to retrace.

Generated at Thu Feb 08 07:47:15 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.