Bug #80296 FTS query exceeds result cache limit
Submitted: 7 Feb 2016 15:38 Modified: 31 May 2016 4:58
Reporter: monty solomon Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S1 (Critical)
Version:5.6.29 OS:CentOS
Assigned to: CPU Architecture:Any

[7 Feb 2016 15:38] monty solomon
Description:
InnoDB full-text queries fail with error "ERROR 188 (HY000): FTS query exceeds result cache limit" using the maximum values of innodb_ft_result_cache_limit and innodb_ft_total_cache_size.

The failing queries executed properly when the engine was MyISAM.

How to repeat:
Convert a large MyISAM FTS table to InnoDB. Execute queries that work with the MyISAM table on the InnoDB table.

Get error message
ERROR 188 (HY000): FTS query exceeds result cache limit

ALTER TABLE eventDetails ENGINE = InnoDB ROW_FORMAT=COMPRESSED KEY_BLOCK_SIZE=8;
[7 Feb 2016 15:39] monty solomon
mysql> show global variables like 'innodb_ft%';
+---------------------------------+------------+
| Variable_name                   | Value      |
+---------------------------------+------------+
| innodb_ft_aux_table             |            |
| innodb_ft_cache_size            | 8000000    |
| innodb_ft_enable_diag_print     | OFF        |
| innodb_ft_enable_stopword       | ON         |
| innodb_ft_max_token_size        | 10         |
| innodb_ft_min_token_size        | 4          |
| innodb_ft_num_word_optimize     | 2000       |
| innodb_ft_result_cache_limit    | 4294967295 |
| innodb_ft_server_stopword_table |            |
| innodb_ft_sort_pll_degree       | 2          |
| innodb_ft_total_cache_size      | 1600000000 |
| innodb_ft_user_stopword_table   |            |
+---------------------------------+------------+
12 rows in set (0.25 sec)
[8 Feb 2016 13:03] MySQL Verification Team
Hello monty,

Thank you for the report.
Could you please provide exact table details(output of SHOW CREATE TABLE <table_name>\G) and also queries which are triggering this issue with Innodb tables?

Thanks,
Umesh
[8 Feb 2016 23:11] monty solomon
mysqld is sometimes killed during the InnoDB FTS query because it is using too much RAM.

ERROR 2013 (HY000): Lost connection to MySQL server during query
[11 Feb 2016 6:56] MySQL Verification Team
Thank you for providing the requested details.

Thanks,
Umesh
[11 Feb 2016 6:57] MySQL Verification Team
-- Not observed any crashes(may be bigger box that I have for tests)
-- 5.6.29

scripts/mysql_install_db --basedir=/export/umesh/server/binaries/mysql-5.6.29 --datadir=/export/umesh/server/binaries/mysql-5.6.29/80296
bin/mysqld --no-defaults --innodb_file_format=barracuda --basedir=/export/umesh/server/binaries/mysql-5.6.29 --datadir=/export/umesh/server/binaries/mysql-5.6.29/80296 --core-file --socket=/tmp/mysql_ushastry.sock  --port=15000 --log-error=/export/umesh/server/binaries/mysql-5.6.29/80296/log.err --innodb_buffer_pool_size=64G --innodb_ft_result_cache_limit=4294967295 --innodb_ft_total_cache_size=1600000000 2>&1 &

create database if not exists test;
use test;
drop table if exists eventDetails;

CREATE TABLE `eventDetails` (
  `domain` varchar(50) NOT NULL,
  `portalId` bigint(10) NOT NULL,
  `emailCampaignId` bigint(20) NOT NULL,
  `email` varchar(50) NOT NULL,
  `emailAccountId` bigint(10) NOT NULL,
  `eventType` varchar(30) NOT NULL,
  `status` varchar(20) NOT NULL,
  `reason` varchar(500) NOT NULL,
  `date` bigint(20) NOT NULL,
  `id` varchar(36) NOT NULL,
  `category` varchar(30) DEFAULT NULL,
  PRIMARY KEY (`id`),
  KEY `idx_event_detail_date` (`date`),
  KEY `idx_eventType_date` (`eventType`,`date`),
  KEY `idx_domain_eventType_date` (`domain`,`eventType`,`date`),
  KEY `idx_status_eventType_date` (`status`,`eventType`,`date`),
  KEY `idx_portalId_eventType_date` (`portalId`,`eventType`,`date`),
  KEY `idx_emailCampaignId_eventType_date` (`emailCampaignId`,`eventType`,`date`),
  KEY `idx_category` (`category`),
  FULLTEXT KEY `idx_event_details_fulltext_reason` (`reason`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8 ROW_FORMAT=COMPRESSED KEY_BLOCK_SIZE=8;

 set @id:=0;

-- dummy data
 insert into `eventDetails` SELECT CONCAT('MySQL',@id:=@id+1,'.COM'),@id:=@id+1,@id:=@id+1,CONCAT('MySQL',@id:=@id+1,'@MySQL.COM'),@id:=@id+1,'SENGRID_BOUNCE','YES|NO',CONCAT('address rejected',' ',md5(rand()*1000000)),UNIX_TIMESTAMP(DATE_ADD("1970-01-01 10:00:00", INTERVAL @id:=@id+6 SECOND)),@id:=@id+6,NULL;
 insert into `eventDetails` SELECT CONCAT('MySQL',@id:=@id+1,'.COM'),@id:=@id+1,@id:=@id+1,CONCAT('MySQL',@id:=@id+1,'@MySQL.COM'),@id:=@id+1,'SENGRID_BOUNCE','YES|NO',CONCAT('address rejected',' ',md5(rand()*1000000)),UNIX_TIMESTAMP(DATE_ADD("1970-01-01 10:00:00", INTERVAL @id:=@id+1 SECOND)),@id:=@id+1,NULL;
 insert into `eventDetails` SELECT CONCAT('MySQL',@id:=@id+1,'.COM'),@id:=@id+1,@id:=@id+1,CONCAT('MySQL',@id:=@id+1,'@MySQL.COM'),@id:=@id+1,'SENGRID_BOUNCE','YES|NO',CONCAT('address rejected',' ',md5(rand()*1000000)),UNIX_TIMESTAMP(DATE_ADD("1970-01-01 10:00:00", INTERVAL @id:=@id+1 SECOND)),@id:=@id+1,NULL;
 insert into `eventDetails` SELECT CONCAT('MySQL',@id:=@id+1,'.COM'),@id:=@id+1,@id:=@id+1,CONCAT('MySQL',@id:=@id+1,'@MySQL.COM'),@id:=@id+1,'SENGRID_BOUNCE','YES|NO',CONCAT('address rejected',' ',md5(rand()*1000000)),UNIX_TIMESTAMP(DATE_ADD("1970-01-01 10:00:00", INTERVAL @id:=@id+1 SECOND)),@id:=@id+1,NULL;

 insert into `eventDetails`(`domain`,`portalId`,`emailCampaignId`,`email`,`emailAccountId`,`eventType`,`status`,`reason`,`date`,`id`,`category`) SELECT CONCAT('MySQL',@id:=@id+1,'.COM'),@id:=@id+1,@id:=@id+1,CONCAT('MySQL',@id:=@id+1,'@MySQL.COM'),@id:=@id+1,'SENGRID_BOUNCE','YES|NO',CONCAT('address rejected',' ',md5(rand()*1000000)),UNIX_TIMESTAMP(DATE_ADD("1970-01-01 10:00:00", INTERVAL @id:=@id+1 SECOND)),@id:=@id+1,NULL  from `eventDetails` k1, `eventDetails` k2, `eventDetails` k3, `eventDetails` k4,`eventDetails` k5,`eventDetails` k6, `eventDetails` k7, `eventDetails` k8, `eventDetails` k9,`eventDetails` k0,`eventDetails` ka, `eventDetails` kb, `eventDetails` kc, `eventDetails` kd limit  125346490;  
 
 ^^ Above took close to 5hr+ to load ( I didn't use but may be you can speed up a bit by turning on/off few things e.g --no-defaults --skip-gr --skip-na --innodb-flush-log-at-trx-commit=0 --innodb-support-xa=0 --innodb-checksums=0 --innodb-doublewrite=0 and bit bigger --innodb-log-file-size)

-- disk usage

mysql> \! ls -lh 80296/test
total 58G
-rw-rw---- 1 umshastr common  13K Feb 10 12:56 eventDetails.frm
-rw-rw---- 1 umshastr common  40G Feb 10 17:25 eventDetails.ibd
-rw-rw---- 1 umshastr common  11G Feb 11 05:38 FTS_0000000000000044_0000000000000064_INDEX_1.ibd
-rw-rw---- 1 umshastr common 5.9G Feb 11 05:38 FTS_0000000000000044_0000000000000064_INDEX_2.ibd
-rw-rw---- 1 umshastr common 1.1G Feb 11 05:38 FTS_0000000000000044_0000000000000064_INDEX_3.ibd
-rw-rw---- 1 umshastr common  96K Feb 10 12:56 FTS_0000000000000044_0000000000000064_INDEX_4.ibd
-rw-rw---- 1 umshastr common 480M Feb 11 05:38 FTS_0000000000000044_0000000000000064_INDEX_5.ibd
-rw-rw---- 1 umshastr common  96K Feb 10 12:56 FTS_0000000000000044_0000000000000064_INDEX_6.ibd
-rw-rw---- 1 umshastr common  96K Feb 10 12:56 FTS_0000000000000044_BEING_DELETED_CACHE.ibd
-rw-rw---- 1 umshastr common  96K Feb 10 12:56 FTS_0000000000000044_BEING_DELETED.ibd
-rw-rw---- 1 umshastr common  96K Feb 11 05:38 FTS_0000000000000044_CONFIG.ibd
-rw-rw---- 1 umshastr common  96K Feb 10 12:56 FTS_0000000000000044_DELETED_CACHE.ibd
-rw-rw---- 1 umshastr common  96K Feb 10 12:56 FTS_0000000000000044_DELETED.ibd
mysql>

 
[umshastr@hod03]/export/umesh/server/binaries/mysql-5.6.29: bin/mysql -uroot -S /tmp/mysql_ushastry.sock
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 2
Server version: 5.6.29 MySQL Community Server (GPL)

Copyright (c) 2000, 2016, Oracle and/or its affiliates. All rights reserved.

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> show global variables like 'innodb_ft%';
+---------------------------------+------------+
| Variable_name                   | Value      |
+---------------------------------+------------+
| innodb_ft_aux_table             |            |
| innodb_ft_cache_size            | 8000000    |
| innodb_ft_enable_diag_print     | OFF        |
| innodb_ft_enable_stopword       | ON         |
| innodb_ft_max_token_size        | 84         |
| innodb_ft_min_token_size        | 3          |
| innodb_ft_num_word_optimize     | 2000       |
| innodb_ft_result_cache_limit    | 4294967295 | <-- max value set
| innodb_ft_server_stopword_table |            |
| innodb_ft_sort_pll_degree       | 2          |
| innodb_ft_total_cache_size      | 1600000000 | <-- max value set
| innodb_ft_user_stopword_table   |            |
+---------------------------------+------------+
12 rows in set (0.00 sec)

mysql> use test
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
mysql> show table status like 'eventDetails'\G
*************************** 1. row ***************************
           Name: eventDetails
         Engine: InnoDB
        Version: 10
     Row_format: Compressed
           Rows: 121672265
 Avg_row_length: 143
    Data_length: 17474338816
Max_data_length: 0
   Index_length: 20945666048
      Data_free: 4194304
 Auto_increment: NULL
    Create_time: 2016-02-10 12:56:37
    Update_time: NULL
     Check_time: NULL
      Collation: utf8_general_ci
       Checksum: NULL
 Create_options: row_format=COMPRESSED KEY_BLOCK_SIZE=8
        Comment:
1 row in set (0.44 sec)

mysql> SELECT id, domain, portalId, emailCampaignId, email, emailAccountId, eventType, status, reason, date, category FROM eventDetails  WHERE date <= 1453784399999  AND match(reason) against('address rejected' in boolean mode)  AND date >= 1453698000000  AND eventType = 'SENGRID_BOUNCE'  LIMIT 15 OFFSET 0;
ERROR 188 (HY000): FTS query exceeds result cache limit
mysql>
mysql> SELECT id, domain, portalId, emailCampaignId, email, emailAccountId, eventType, status, reason, date, category FROM eventDetails  WHERE match(reason) against('address rejected' in boolean mode) LIMIT 15 OFFSET 0;
ERROR 188 (HY000): FTS query exceeds result cache limit
mysql>
[9 Mar 2016 22:25] monty solomon
Since the InnoDB FTS is not working we are going to shut down the server. Do you need anything else before I shut down the server?
[13 May 2016 4:50] Jervin R
In some cases if you have a long text like:

AGAINST('+the +quick +brown +fox +jumps +over +the +lazy* +dog*')

can easily crash the server.
[27 May 2016 17:50] Daniel Price
Posted by developer:
 
Fixed as of the upcoming 5.7.14 release, and here's the changelog entry:

A full-text query that involved a large number of records exceeded the
result cache limit and caused a server exit. 

Thank you for the bug report.
[31 May 2016 4:58] monty solomon
Daniel,

Will the bug be patched in 5.6?

Thanks.
[8 Feb 2017 12:25] Craig Carnell
This bug still occurs in 5.7.17
[24 Mar 2017 8:54] Cédric Bruderer
This bug appears to break the full text search in MySQL 5.6.35 completely. I cannot search anything without getting the error "ERROR 188 (HY000): FTS query exceeds result cache limit". Sometimes MySQL is even killed, because there is no more memory available on the server.

Server Specifications:
Ubuntu 16.04.2 (Virtualized)
1 CPU core
4GB of RAM

Is there going to be a fix for this issue?

===

mysql@myenv:~/data/mysql-56 [mysql-56, 3307]> cat my.cnf
[client]
port                           = 3307
socket                         = /var/run/mysqld/mysql-mysql-56.sock

[mysql]
no_auto_rehash
prompt                         = '\u@\h [\d]> '
default_character_set          = utf8

[mysqld_safe]
user                           = mysql
log-error                      = myenv_error.log

[mysqld]
# Connection and Thread variables
port                           = 3307
socket                         = /var/run/mysqld/mysql-mysql-56.sock
basedir                        = /home/mysql/product/mysql-5.6.35-linux-glibc2.5-x86_64
datadir                        = /home/mysql/data/mysql-56
default_storage_engine         = InnoDB
# MySQL error log
log_error                      = myenv_mysql-56_error.log
log_warnings                   = 2

mysql@myenv:~/data/mysql-56 [mysql-56, 3307]> mysql
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 5
Server version: 5.6.35 MySQL Community Server (GPL)

Copyright (c) 2000, 2016, Oracle and/or its affiliates. All rights reserved.

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.

wookie@localhost [(none)]> use test;
Database changed

wookie@localhost [test]> show create table test\G
*************************** 1. row ***************************
       Table: test
Create Table: CREATE TABLE `test` (
  `id` int(11) NOT NULL AUTO_INCREMENT,
  `text` varchar(50) NOT NULL,
  `mail` varchar(50) DEFAULT NULL,
  `combined` text,
  PRIMARY KEY (`id`),
  FULLTEXT KEY `text` (`text`,`mail`,`combined`)
) ENGINE=InnoDB AUTO_INCREMENT=2097284 DEFAULT CHARSET=latin1
1 row in set (0.00 sec)

wookie@localhost [test]> select count(*) from test;
+----------+
| count(*) |
+----------+
|   747898 |
+----------+
1 row in set (0.50 sec)

wookie@localhost [test]> SELECT * FROM test WHERE MATCH(text, mail, combined) AGAINST (_utf8'\"7c.833@test.ch\"' IN BOOLEAN MODE) LIMIT 10;
ERROR 2013 (HY000): Lost connection to MySQL server during query

wookie@localhost [test]> SELECT * FROM test WHERE MATCH(text, mail, combined) AGAINST (_utf8'\"7c.833@test.ch\"' IN BOOLEAN MODE) LIMIT 10;
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...
Connection id:    2
Current database: test

ERROR 188 (HY000): FTS query exceeds result cache limit
wookie@localhost [test]> select * from test limit 10;
+----+--------------------------------------+----------------------+---------------------------------------------------+
| id | text                                 | mail                 | combined                                          |
+----+--------------------------------------+----------------------+---------------------------------------------------+
|  1 | 78b1469d.0a30.11e7.b704.000c29c2c0c8 | 78b1469d.1@test.ch   | CN=78b1469d.0a30.11e7.b704 OU=78b1469d.1@test.ch  |
|  2 | 794abbd3.0a30.11e7.b704.000c29c2c0c8 | 794abbd3.2@test.com  | CN=794abbd3.0a30.11e7.b704 OU=794abbd3.2@test.ch  |
|  7 | 7de388d2.0a30.11e7.b704.000c29c2c0c8 | 7de388d2.7@test.ch   | CN=7de388d2.0a30.11e7.b704 OU=7de388d2.7@test.ch  |
| 13 | 88bf3180.0a30.11e7.b704.000c29c2c0c8 | 88bf3180.13@test.ch  | CN=88bf3180.0a30.11e7.b704 OU=88bf3180.13@test.ch |
| 14 | 927c1a5d.0a30.11e7.b704.000c29c2c0c8 | 927c1a5d.14@test.com | CN=927c1a5d.0a30.11e7.b704 OU=927c1a5d.14@test.ch |
| 17 | 970d657c.0a30.11e7.b704.000c29c2c0c8 | 970d657c.17@test.ch  | CN=970d657c.0a30.11e7.b704 OU=970d657c.17@test.ch |
| 19 | a9259d61.0a30.11e7.b704.000c29c2c0c8 | a9259d61.19@test.ch  | CN=a9259d61.0a30.11e7.b704 OU=a9259d61.19@test.ch |
| 23 | 099a0b91.0a31.11e7.b704.000c29c2c0c8 | 099a0b91.23@test.ch  | CN=099a0b91.0a31.11e7.b704 OU=099a0b91.23@test.ch |
| 26 | 0b675993.0a31.11e7.b704.000c29c2c0c8 | 0b675993.26@test.com | CN=0b675993.0a31.11e7.b704 OU=0b675993.26@test.ch |
| 29 | 0d353b8e.0a31.11e7.b704.000c29c2c0c8 | 0d353b8e.29@test.ch  | CN=0d353b8e.0a31.11e7.b704 OU=0d353b8e.29@test.ch |
+----+--------------------------------------+----------------------+---------------------------------------------------+
10 rows in set (0.00 sec)

wookie@localhost [(none)]> show global variables like 'innodb_ft%';
+---------------------------------+------------+
| Variable_name                   | Value      |
+---------------------------------+------------+
| innodb_ft_aux_table             |            |
| innodb_ft_cache_size            | 8000000    |
| innodb_ft_enable_diag_print     | OFF        |
| innodb_ft_enable_stopword       | ON         |
| innodb_ft_max_token_size        | 84         |
| innodb_ft_min_token_size        | 3          |
| innodb_ft_num_word_optimize     | 2000       |
| innodb_ft_result_cache_limit    | 2000000000 |
| innodb_ft_server_stopword_table |            |
| innodb_ft_sort_pll_degree       | 2          |
| innodb_ft_total_cache_size      | 640000000  |
| innodb_ft_user_stopword_table   |            |
+---------------------------------+------------+
12 rows in set (0.03 sec)