[MDEV-11233] CREATE FULLTEXT INDEX with a token longer than 127 bytes crashes server - Jira

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Critical
Resolution: Fixed
Affects Version/s: 10.1.17, 10.1.18
Fix Version/s: 10.0.30, 10.1.20, 10.2.3
Component/s: Data Definition - Alter Table, Storage Engine - InnoDB
Labels:
- index
- innodb
Environment:
Centos 6.5, Mariadb 10.1.18 and Mariadb 10.1.17 (and also on all older)
Linode virtual server 48GB RAM

Sprint:
10.1.20

Description

Adding fulltext index on bigger table crash server

2016-11-04 07:41:26 7f7149bfe700  InnoDB: Assertion failure in thread 140124545345280 in file row0merge.cc line 890

InnoDB: Failing assertion: b == &block[0] + buf->total_size + ROW_MERGE_RESERVE_SIZE

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.

161104  7:41:26 [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.1.17-MariaDB

key_buffer_size=134217728

read_buffer_size=131072

max_used_connections=54

max_threads=902

thread_count=8

It is possible that mysqld could use up to

key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 2112329 K  bytes of memory

Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x0x0

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 = 0x0 thread_stack 0x48400

2016-11-04 07:41:27 7f714a3ff700  InnoDB: Assertion failure in thread 140124553737984 in file row0merge.cc line 890

InnoDB: Failing assertion: b == &block[0] + buf->total_size + ROW_MERGE_RESERVE_SIZE

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.

161104 07:41:29 mysqld_safe Number of processes running now: 0

161104 07:41:29 mysqld_safe mysqld restarted

2016-11-04  7:41:29 140601780914208 [Note] /usr/sbin/mysqld (mysqld 10.1.17-MariaDB) starting as process 25262 ...

2016-11-04  7:41:29 140601780914208 [Warning] Although a path was specified for the --log-slow-queries option, log tables are used. To enable logging to files use the --log-output=file option.

2016-11-04  7:41:29 140601780914208 [Warning] option 'innodb-ft-cache-size': unsigned value 83886080 adjusted to 80000000

2016-11-04  7:41:29 140601780914208 [Note] InnoDB: Using mutexes to ref count buffer pool pages

2016-11-04  7:41:29 140601780914208 [Note] InnoDB: The InnoDB memory heap is disabled

2016-11-04  7:41:29 140601780914208 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins

2016-11-04  7:41:29 140601780914208 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier

2016-11-04  7:41:29 140601780914208 [Note] InnoDB: Compressed tables use zlib 1.2.3

2016-11-04  7:41:29 140601780914208 [Note] InnoDB: Using Linux native AIO

2016-11-04  7:41:29 140601780914208 [Note] InnoDB: Using SSE crc32 instructions

2016-11-04  7:41:29 140601780914208 [Note] InnoDB: Initializing buffer pool, size = 14.0G

2016-11-04  7:41:30 140601780914208 [Note] InnoDB: Completed initialization of buffer pool

2016-11-04  7:41:30 140601780914208 [Note] InnoDB: Highest supported file format is Barracuda.

2016-11-04  7:41:30 140601780914208 [Note] InnoDB: Log scan progressed past the checkpoint lsn 5089194166241

2016-11-04  7:41:30 140601780914208 [Note] InnoDB: Database was not shutdown normally!

2016-11-04  7:41:30 140601780914208 [Note] InnoDB: Starting crash recovery.

2016-11-04  7:41:30 140601780914208 [Note] InnoDB: Reading tablespace information from the .ibd files...

2016-11-04  7:41:46 140601780914208 [Note] InnoDB: Processed 81433 .ibd/.isl files

2016-11-04  7:42:02 140601780914208 [Note] InnoDB: Processed 165583 .ibd/.isl files

2016-11-04  7:42:18 140601780914208 [Note] InnoDB: Processed 248732 .ibd/.isl files

2016-11-04  7:42:34 140601780914208 [Note] InnoDB: Processed 331595 .ibd/.isl files

2016-11-04  7:42:50 140601780914208 [Note] InnoDB: Processed 410190 .ibd/.isl files

2016-11-04  7:43:06 140601780914208 [Note] InnoDB: Processed 490369 .ibd/.isl files

2016-11-04  7:43:22 140601780914208 [Note] InnoDB: Processed 571032 .ibd/.isl files

2016-11-04  7:43:38 140601780914208 [Note] InnoDB: Processed 653103 .ibd/.isl files

2016-11-04  7:43:54 140601780914208 [Note] InnoDB: Processed 733414 .ibd/.isl files

2016-11-04  7:44:10 140601780914208 [Note] InnoDB: Processed 811624 .ibd/.isl files

2016-11-04  7:44:26 140601780914208 [Note] InnoDB: Processed 891341 .ibd/.isl files

2016-11-04  7:44:42 140601780914208 [Note] InnoDB: Processed 969320 .ibd/.isl files

2016-11-04  7:44:58 140601780914208 [Note] InnoDB: Processed 1047838 .ibd/.isl files

2016-11-04  7:45:14 140601780914208 [Note] InnoDB: Processed 1123078 .ibd/.isl files

2016-11-04  7:45:25 140601780914208 [Note] InnoDB: Restoring possible half-written data pages

2016-11-04  7:45:25 140601780914208 [Note] InnoDB: from the doublewrite buffer...

InnoDB: Doing recovery: scanned up to log sequence number 5089199408640

InnoDB: Doing recovery: scanned up to log sequence number 5089204651520

InnoDB: Doing recovery: scanned up to log sequence number 5089209894400

InnoDB: Doing recovery: scanned up to log sequence number 5089215137280

InnoDB: Doing recovery: scanned up to log sequence number 5089220380160

InnoDB: Doing recovery: scanned up to log sequence number 5089225623040

InnoDB: Doing recovery: scanned up to log sequence number 5089230865920

.... etc

Problem was started by SQL:
ALTER TABLE `qu_la_contacts` ADD FULLTEXT `qu_la_contacts_ftidx` (`firstname` ,`lastname` ,`emails` ,`system_name`)

on table, which has about 200k rows

CREATE TABLE IF NOT EXISTS `qu_la_contacts` (

  `contactid` CHAR(8) NOT NULL,

  `parent_contactid` CHAR(8) NULL,

  `company` CHAR(1) NOT NULL DEFAULT 'N',

  `job_position` VARCHAR(255) NULL,

  `emails` TEXT NULL,

  `firstname` VARCHAR(100) NULL,

  `lastname` VARCHAR(100) NULL,

  `system_name` VARCHAR(100) NULL,

  `description` VARCHAR(255) NULL,

  `rtype` CHAR(1) NOT NULL,

  `status` CHAR(1) NOT NULL DEFAULT 'A' COMMENT 'A=Active, X=Deleted',

  `datecreated` DATETIME NULL,

  `avatar_url` TEXT NULL,

  `city` VARCHAR(255) NULL,

  `countrycode` VARCHAR(2) NULL,

  `note` TEXT NULL,

  `time_offset` INT NULL,

  `language` VARCHAR(10) NULL,

  `gender` CHAR(1) NOT NULL DEFAULT 'M',

  `levelid` CHAR(8) NULL,

  `ldap_id` VARCHAR(255) NULL,

  `groups` VARCHAR(255) NULL,

  `ip` VARCHAR(39) NULL,

  `useragent` TEXT NULL,

  `screen` VARCHAR(12) NULL,

  `latitude` FLOAT NULL,

  `longitude` FLOAT NULL,

  `last_action_type` CHAR(1) NULL,

  `last_action_date` DATETIME NULL,

  `last_action_meta` VARCHAR(80) NULL,

  PRIMARY KEY (`contactid`),

  INDEX `fk_qu_la_contacts_qu_la_levels1_idx` (`levelid` ASC),

  INDEX `fk_parent_contactid` (`parent_contactid` ASC),

  INDEX `qu_la_contacts_datecreated` (`datecreated` ASC),

  INDEX `qu_la_contacts_firstname` (`firstname` ASC),

  INDEX `qu_la_contacts_lastname` (`lastname` ASC),

  INDEX `qu_la_contacts_system_name` (`system_name` ASC),

  INDEX `qu_la_contacts_company` (`company`)

ENGINE = InnoDB;

Server settings:

[mysqld]

server-id=14

datadir=/opt/mysql/

socket=/var/lib/mysql/mysql.sock

tmpdir=/tmp/

log_bin=mysql-bin

expire_logs_days=6

wait_timeout=60

long_query_time=1

slow_query_log=1

slow_query_log_file=/opt/log/slow.log

log_output=TABLE

userstat = 1

user=root

symbolic-links=0

binlog_format=STATEMENT

default_storage_engine=InnoDB

slave_skip_errors=1062,1396,1690

innodb_autoinc_lock_mode=2

innodb_buffer_pool_size=14G

innodb_buffer_pool_instances=10

innodb_log_file_size=1G

innodb_log_buffer_size=196M

innodb_flush_log_at_trx_commit=1

innodb_thread_concurrency=24

innodb_file_per_table

innodb_write_io_threads=24

innodb_read_io_threads=24

innodb_sched_priority_cleaner=39

innodb_adaptive_flushing=1

innodb_purge_threads=5

#transaction-isolation=READ-COMMITTED

innodb_adaptive_hash_index_partitions=64

innodb_flush_neighbors=0

innodb_flush_method=O_DIRECT

innodb_io_capacity=5000

innodb_io_capacity_max=8000

innodb_lru_scan_depth=1024

innodb_sort_buffer_size=32M

innodb_ft_cache_size=80M

innodb_ft_total_cache_size=1G

slave_parallel_threads=10

log_slave_updates=on

performance_schema=off

skip-name-resolve

max_allowed_packet = 512M

query_cache_type=1

query_cache_size = 0

query_cache_limit = 1M

query_cache_min_res_unit=1K

max_connections = 900

table_open_cache=64K

innodb_open_files=64K

open_files_limit=1020000

collation-server = utf8_general_ci

character-set-server = utf8

log-error=/opt/log/error.log

[mysqld_safe]

log-error=/opt/log/error.log

pid-file=/var/run/mysqld/mysqld.pid

malloc-lib=/usr/lib64/libjemalloc.so.1

Exactly the same problem happen on another table when adding fulltext index (table size about 150MB) (reported in additional comments here: https://jira.mariadb.org/browse/MDEV-9129):

ALTER TABLE qu_g_mails ADD FULLTEXT ft_qu_g_mails1 (subject, body_text, body_html);

CREATE TABLE `qu_g_mails` (

  `mailid` int(10) unsigned NOT NULL AUTO_INCREMENT,

  `hdr_message_id` varchar(255) DEFAULT NULL,

  `unique_message_id` varchar(255) NOT NULL,

  `subject` text,

  `headers` text,

  `body_text` longtext,

  `body_html` longtext,

  `created` datetime NOT NULL,

  `delivered` datetime DEFAULT NULL,

  `from_mail` text,

  `to_recipients` text,

  `cc_recipients` text,

  `bcc_recipients` text,

  `accountuserid` char(8) DEFAULT NULL,

  `reply_to` text,

  PRIMARY KEY (`mailid`),

  KEY `IDX_qu_g_mails_1` (`accountuserid`)

) ENGINE=InnoDB  DEFAULT CHARSET=utf8 ROW_FORMAT=COMPRESSED;

Attachments

Issue Links

is duplicated by

MDEV-11918 CREATE FULLTEXT INDEX with a token longer than 127 bytes crashes server (10.0 version)

Closed

relates to

MDEV-11241 Certain combining marks cause MariaDB to crash when doing Full-Text searches

Closed

Activity

Ascending order - Click to sort in descending order

Viktor Zeman added a comment - 2016-11-04 14:14

After next investigation we think, that size of DB table doesn't play a role here.
It looks like the problem could be related to characters used in data.
If special characters are used, there is higher chance, that server crash.

e.g. we have about 800 databases on server with same structure, but only one DB crashed the server when changing qu_la_contacts table
(in db are special vietnamese characters)

On other hand adding fulltext index on qu_g_mails crash server nearly on every db we have on server. This table holds email sources, which contains special characters nearly in every db.

Our workaround was:
1. rename original table to table_backup
2. create empty table with correct structure (including fulltext index)
3. copy data from table_backup to empty table
In this way server doesn't crash.

Viktor Zeman added a comment - 2016-11-04 14:14 After next investigation we think, that size of DB table doesn't play a role here. It looks like the problem could be related to characters used in data. If special characters are used, there is higher chance, that server crash. e.g. we have about 800 databases on server with same structure, but only one DB crashed the server when changing qu_la_contacts table (in db are special vietnamese characters) On other hand adding fulltext index on qu_g_mails crash server nearly on every db we have on server. This table holds email sources, which contains special characters nearly in every db. Our workaround was: 1. rename original table to table_backup 2. create empty table with correct structure (including fulltext index) 3. copy data from table_backup to empty table In this way server doesn't crash.

Elena Stepanova added a comment - 2016-11-12 14:57

unitminer,

Is the problem reproducible if you reuse the tablespace instead of copying the data?

shutdown the server normally;
store the <crashing_table>.ibd file;
start the server;
create new empty table <new_table> with the same structure;
run ALTER TABLE <new_table> DISCARD TABLESPACE;
copy the stored ibd file to <new_table>.ibd in the corresponding database folder;
run ALTER TABLE <new_table> IMPORT TABLESPACE.

Does the server crash after that when you are using the new table?
If it does, would you be able to provide the example of such ibd file along with the exact structure of the <new_table> as SHOW CREATE TABLE shows?

Thanks.

Elena Stepanova added a comment - 2016-11-12 14:57 unitminer , Is the problem reproducible if you reuse the tablespace instead of copying the data? shutdown the server normally; store the <crashing_table>.ibd file; start the server; create new empty table <new_table> with the same structure; run ALTER TABLE <new_table> DISCARD TABLESPACE ; copy the stored ibd file to <new_table>.ibd in the corresponding database folder; run ALTER TABLE <new_table> IMPORT TABLESPACE . Does the server crash after that when you are using the new table? If it does, would you be able to provide the example of such ibd file along with the exact structure of the <new_table> as SHOW CREATE TABLE shows? Thanks.

Viktor Zeman added a comment - 2016-11-18 13:21

Elena, I don't understand your request with DISCARD TABLESPACE.
I'm not able to run such commands on live environment.

Viktor Zeman added a comment - 2016-11-18 13:21 Elena, I don't understand your request with DISCARD TABLESPACE. I'm not able to run such commands on live environment.

Marko Mäkelä added a comment - 2016-12-02 12:07

Someone on irc repeated the same problem. I suggested the following:

Use mysqldump or equivalent to copy the data.
Load the data to a new server.
The same CREATE FULLTEXT INDEX statement should still crash. (I am pretty sure about this; the input to the sort should be ordered by the clustered index (PRIMARY KEY).)
ALTER TABLE…DROP COLUMN to drop any irrelevant columns. We should only need the PRIMARY KEY columns and the column(s) that the fulltext index is being created on, and a possible FTS_DOC_ID column (if one has been created by the user).
The CREATE FULLTEXT INDEX should still crash.
DELETE half of the rows, and hope that the CREATE FULLTEXT INDEX still crashes. If not, restore the rows, delete rows by some other condition.
Repeat the last step until the data set is small enough.
Then (if needed) replace any confidential data while making sure that the CREATE FULLTEXT INDEX still crashes.
Send the mysqldump of the reduced table, and the CREATE FULLTEXT INDEX statement.
I am looking forward to get some data obtained by this method.

Marko Mäkelä added a comment - 2016-12-02 12:07 Someone on irc repeated the same problem. I suggested the following: Use mysqldump or equivalent to copy the data. Load the data to a new server. The same CREATE FULLTEXT INDEX statement should still crash. (I am pretty sure about this; the input to the sort should be ordered by the clustered index (PRIMARY KEY).) ALTER TABLE…DROP COLUMN to drop any irrelevant columns. We should only need the PRIMARY KEY columns and the column(s) that the fulltext index is being created on, and a possible FTS_DOC_ID column (if one has been created by the user). The CREATE FULLTEXT INDEX should still crash. DELETE half of the rows, and hope that the CREATE FULLTEXT INDEX still crashes. If not, restore the rows, delete rows by some other condition. Repeat the last step until the data set is small enough. Then (if needed) replace any confidential data while making sure that the CREATE FULLTEXT INDEX still crashes. Send the mysqldump of the reduced table, and the CREATE FULLTEXT INDEX statement. I am looking forward to get some data obtained by this method.

Waqar Khan added a comment - 2016-12-02 13:21 - edited

After some testing with Marko, we have an update for this and how to replicate:

CREATE TABLE t(t text CHARACTER SET utf8mb4 COLLATE utf8mb4_unicode_ci) ENGINE=InnoDB;

INSERT INTO t VALUES (0xD0B4E0B894E0B987E0B987E0B987E0B987E0B987E0B989E0B989E0B989E0B989E0B989E0B987E0B987E0B987E0B987E0B989E0B989E0B989E0B989E0B989E0B987E0B987E0B987E0B987E0B987E0B989E0B989E0B989E0B989E0B989E0B987E0B987E0B987E0B987E0B987E0B989E0B989E0B989E0B989E0B989E0B987E0B987E0B987E0B987E0B987E0B989E0B989E0B989E0B989E0B989);

CREATE FULLTEXT INDEX ft ON t(t);

DROP TABLE t;

Upon CREATE FULLTEXT INDEX ft ON t(t); the server with crash with the following snippet from the log file:

Dec 2 13:12:34 centos-mdb1 mysqld: 2016-12-02 13:12:34 7f4c2ebff700 InnoDB: Assertion failure in thread 139965178574592 in
file row0merge.cc line 897
Dec 2 13:12:34 centos-mdb1 mysqld: InnoDB: Failing assertion: b == &block[0] + buf->total_size + ROW_MERGE_RESERVE_SIZE

Waqar Khan added a comment - 2016-12-02 13:21 - edited After some testing with Marko, we have an update for this and how to replicate: CREATE TABLE t(t text CHARACTER SET utf8mb4 COLLATE utf8mb4_unicode_ci) ENGINE=InnoDB; INSERT INTO t VALUES (0xD0B4E0B894E0B987E0B987E0B987E0B987E0B987E0B989E0B989E0B989E0B989E0B989E0B987E0B987E0B987E0B987E0B989E0B989E0B989E0B989E0B989E0B987E0B987E0B987E0B987E0B987E0B989E0B989E0B989E0B989E0B989E0B987E0B987E0B987E0B987E0B987E0B989E0B989E0B989E0B989E0B989E0B987E0B987E0B987E0B987E0B987E0B989E0B989E0B989E0B989E0B989); CREATE FULLTEXT INDEX ft ON t(t); DROP TABLE t; Upon CREATE FULLTEXT INDEX ft ON t(t); the server with crash with the following snippet from the log file: Dec 2 13:12:34 centos-mdb1 mysqld: 2016-12-02 13:12:34 7f4c2ebff700 InnoDB: Assertion failure in thread 139965178574592 in file row0merge.cc line 897 Dec 2 13:12:34 centos-mdb1 mysqld: InnoDB: Failing assertion: b == &block [0] + buf->total_size + ROW_MERGE_RESERVE_SIZE

Marko Mäkelä added a comment - 2016-12-02 13:33

Also ~~MDEV-11241~~ is something about 4-byte UTF-8 and fulltext search, but outside InnoDB.

Marko Mäkelä added a comment - 2016-12-02 13:33 Also MDEV-11241 is something about 4-byte UTF-8 and fulltext search, but outside InnoDB.

Marko Mäkelä added a comment - 2016-12-05 11:18

This bug is related to the following bug that was fixed in MySQL 5.6.29, 5.7.11 and 8.0.0:
Bug#79475 Insert a token of 84 4-bytes chars into fts index causes server crash
This particular bug fix was not merged to MariaDB. But, a follow-up bug fix was merged, causing this very bug:

commit 052a8b8e324122d99d58f328cc90f3249fc76a3a

Author: Shaohua Wang <shaohua.wang@oracle.com>

Date:   Thu Apr 7 11:37:32 2016 +0800

    BUG#22963169 MYSQL CRASHES ON CREATE FULLTEXT INDEX

If I revert the change of the latter fix to row_merge_fts_doc_tokenize(), the test case will not crash. Note: I was able to crash by using 3-byte UTF-8:

CREATE TABLE t(t text CHARACTER SET utf8) ENGINE=InnoDB;

INSERT INTO t set t=repeat(concat(repeat(0xE0B987, 4), repeat(0xE0B989, 5)), 5);

CREATE FULLTEXT INDEX ft ON t(t);

DROP TABLE t;

It seems that the correct fix is to keep the 84-character token length limit even when using utf8mb4. This would increase the storage size in bytes to 336. The MariaDB bug fix has the option to keep using 84*3 = 254 bytes as the maximum word size for those indexes that use encodings with less than 4 bytes per character. This would save 1 byte for fulltext index entries that where the length of an indexed word is between 128 and 254 bytes (43 to 84 three-byte characters, or 64 to 127 two-byte characters).

Marko Mäkelä added a comment - 2016-12-05 11:18 This bug is related to the following bug that was fixed in MySQL 5.6.29, 5.7.11 and 8.0.0: Bug#79475 Insert a token of 84 4-bytes chars into fts index causes server crash This particular bug fix was not merged to MariaDB. But, a follow-up bug fix was merged, causing this very bug: commit 052a8b8e324122d99d58f328cc90f3249fc76a3a Author: Shaohua Wang <shaohua.wang@oracle.com> Date: Thu Apr 7 11:37:32 2016 +0800 BUG#22963169 MYSQL CRASHES ON CREATE FULLTEXT INDEX If I revert the change of the latter fix to row_merge_fts_doc_tokenize(), the test case will not crash. Note: I was able to crash by using 3-byte UTF-8: CREATE TABLE t(t text CHARACTER SET utf8) ENGINE=InnoDB; INSERT INTO t set t=repeat(concat(repeat(0xE0B987, 4), repeat(0xE0B989, 5)), 5); CREATE FULLTEXT INDEX ft ON t(t); DROP TABLE t; It seems that the correct fix is to keep the 84-character token length limit even when using utf8mb4. This would increase the storage size in bytes to 336. The MariaDB bug fix has the option to keep using 84*3 = 254 bytes as the maximum word size for those indexes that use encodings with less than 4 bytes per character. This would save 1 byte for fulltext index entries that where the length of an indexed word is between 128 and 254 bytes (43 to 84 three-byte characters, or 64 to 127 two-byte characters).

Jan Lindström (Inactive) added a comment - 2016-12-05 14:16

ok to push.

Jan Lindström (Inactive) added a comment - 2016-12-05 14:16 ok to push.

Elena Stepanova added a comment - 2016-12-10 17:16

Adding to make it searchable in JIRA
Not long before the fix, we had a buildbot failure on innodb_fts.innodb_fts_misc with somewhat similar appearance:
http://buildbot.askmonty.org/buildbot/builders/kvm-deb-yakkety-x86/builds/175/steps/test_5/logs/stdio

Elena Stepanova added a comment - 2016-12-10 17:16 Adding to make it searchable in JIRA Not long before the fix, we had a buildbot failure on innodb_fts.innodb_fts_misc with somewhat similar appearance: http://buildbot.askmonty.org/buildbot/builders/kvm-deb-yakkety-x86/builds/175/steps/test_5/logs/stdio

Marko Mäkelä added a comment - 2016-12-12 06:38

elenst, that failure looks different, possibly a failure to create a thread:

CURRENT_TEST: innodb_fts.innodb_fts_misc

mysqltest: At line 59: query 'CREATE FULLTEXT INDEX idx on t1 (a,b)' failed: 2013: Lost connection to MySQL server during query

…

2016-11-22  7:08:49 3067240256 [Note] InnoDB: Online DDL : End of reading clustered index of the table and create temporary files

161122  7:08:49 [ERROR] mysqld got signal 11 ;

…

Server version: 10.1.20-MariaDB-1~yakkety

…

/usr/sbin/mysqld(my_print_stacktrace+0x28)[0x809282e8]

/usr/sbin/mysqld(handle_fatal_signal+0x367)[0x80453647]

[0xb76fad10]

/lib/i386-linux-gnu/libpthread.so.0(pthread_create+0x435)[0xb7361a25]

/usr/lib/mysql/plugin/ha_innodb.so(+0x158531)[0xb12b2531]

/usr/lib/mysql/plugin/ha_innodb.so(+0x183eea)[0xb12ddeea]

/usr/lib/mysql/plugin/ha_innodb.so(+0x19bcd4)[0xb12f5cd4]

/usr/lib/mysql/plugin/ha_innodb.so(+0x108be0)[0xb1262be0]

/usr/sbin/mysqld(_Z17mysql_alter_tableP3THDPcS1_P14HA_CREATE_INFOP10TABLE_LISTP10Alter_infojP8st_orderb+0x2b46)[0x80348786]

There was no resolved stack trace with line numbers. The only place where ALTER TABLE is creating threads is for preprocessing data for fulltext indexes, the threads fts_parallel_tokenization (created by row_fts_start_psort()) and fts_parallel_merge (created by row_fts_start_parallel_merge()).
Neither of these places is checking whether the thread creation succeeded. It seems that the crash must have occurred while row_fts_start_parallel_merge() was being invoked by row_merge_build_indexes().
The problem appears to be that something inside pthread_create() fails. In InnoDB, pthread_create() is called by os_thread_create_func(), which invokes pthread_attr_init() on one argument without checking the return value of that function. However, according to the Linux man-pages version 4.8, pthread_attr_init() should always succeed on Linux.

The manual page for pthread_create() does not give hints why the pthread_create() might have crashed. Given that the platform is 32-bit (i386), one possibility could be exhaustion of the address space when trying to allocate stack for the thread. Maybe this could be repated by running the same tests on a single instance:

innodb.innodb_prefix_index_restart_server 'innodb_plugin' w1 [ pass ]   8513

innodb.innodb_stats 'innodb_plugin'      w1 [ pass ]    102

innodb.innodb_stats_create_on_corrupted 'innodb_plugin' w1 [ pass ]   2769

innodb.innodb_stats_create_table 'innodb_plugin' w1 [ pass ]     16

innodb.innodb_stats_drop_locked 'innodb_plugin' w1 [ pass ]   2206

innodb.innodb_stats_fetch 'innodb_plugin' w1 [ pass ]     34

innodb.innodb_stats_fetch_corrupted 'innodb_plugin' w1 [ pass ]   2792

innodb.innodb_stats_fetch_nonexistent 'innodb_plugin' w1 [ pass ]     23

innodb.innodb_stats_rename_table 'innodb_plugin' w1 [ pass ]      5

innodb.innodb_stats_rename_table_if_exists 'innodb_plugin' w1 [ pass ]    422

innodb.innodb_trx_weight 'innodb_plugin' w1 [ pass ]    135

innodb.mdev-117 'innodb_plugin'          w1 [ pass ]     17

innodb.row_lock 'innodb_plugin'          w1 [ pass ]    118

innodb.strict_mode 'innodb_plugin'       w1 [ pass ]     34

innodb.system_tables 'innodb_plugin'     w1 [ pass ]   2744

innodb.tmpdir 'innodb_plugin'            w1 [ pass ]    147

innodb.xa_recovery 'innodb_plugin'       w1 [ pass ]   5283

innodb_fts.fulltext 'innodb_plugin'      w1 [ pass ]   1162

innodb_fts.fulltext2 'innodb_plugin'     w1 [ pass ]   1120

innodb_fts.fulltext3 'innodb_plugin'     w1 [ pass ]     41

innodb_fts.fulltext_cache 'innodb_plugin' w1 [ pass ]     40

innodb_fts.fulltext_distinct 'innodb_plugin' w1 [ pass ]     57

innodb_fts.fulltext_left_join 'innodb_plugin' w1 [ pass ]    168

innodb_fts.fulltext_misc 'innodb_plugin' w1 [ pass ]    255

innodb_fts.fulltext_multi 'innodb_plugin' w1 [ pass ]     68

innodb_fts.fulltext_order_by 'innodb_plugin' w1 [ pass ]    182

innodb_fts.fulltext_update 'innodb_plugin' w1 [ pass ]     37

innodb_fts.fulltext_var 'innodb_plugin'  w1 [ pass ]     20

innodb_fts.innodb-fts-basic 'innodb_plugin' w1 [ pass ]     36

main.information_schema 'xtradb'         w4 [ pass ]   3770

main.progress_976225 'xtradb'            w4 [ pass ]     53

main.rowid_order_innodb 'xtradb'         w4 [ pass ]     46

innodb_fts.innodb-fts-ddl 'innodb_plugin' w1 [ pass ]   1020

innodb_fts.innodb-fts-fic 'innodb_plugin' w1 [ pass ]    545

innodb_fts.innodb_fts_large_records 'innodb_plugin' w1 [ pass ]   1056

innodb_fts.innodb_fts_misc 'innodb_plugin' w1 [ fail ]

Marko Mäkelä added a comment - 2016-12-12 06:38 elenst , that failure looks different, possibly a failure to create a thread: CURRENT_TEST: innodb_fts.innodb_fts_misc mysqltest: At line 59: query 'CREATE FULLTEXT INDEX idx on t1 (a,b)' failed: 2013: Lost connection to MySQL server during query … 2016-11-22 7:08:49 3067240256 [Note] InnoDB: Online DDL : End of reading clustered index of the table and create temporary files 161122 7:08:49 [ERROR] mysqld got signal 11 ; … Server version: 10.1.20-MariaDB-1~yakkety … /usr/sbin/mysqld(my_print_stacktrace+0x28)[0x809282e8] /usr/sbin/mysqld(handle_fatal_signal+0x367)[0x80453647] [0xb76fad10] /lib/i386-linux-gnu/libpthread.so.0(pthread_create+0x435)[0xb7361a25] /usr/lib/mysql/plugin/ha_innodb.so(+0x158531)[0xb12b2531] /usr/lib/mysql/plugin/ha_innodb.so(+0x183eea)[0xb12ddeea] /usr/lib/mysql/plugin/ha_innodb.so(+0x19bcd4)[0xb12f5cd4] /usr/lib/mysql/plugin/ha_innodb.so(+0x108be0)[0xb1262be0] /usr/sbin/mysqld(_Z17mysql_alter_tableP3THDPcS1_P14HA_CREATE_INFOP10TABLE_LISTP10Alter_infojP8st_orderb+0x2b46)[0x80348786] There was no resolved stack trace with line numbers. The only place where ALTER TABLE is creating threads is for preprocessing data for fulltext indexes, the threads fts_parallel_tokenization (created by row_fts_start_psort()) and fts_parallel_merge (created by row_fts_start_parallel_merge()). Neither of these places is checking whether the thread creation succeeded. It seems that the crash must have occurred while row_fts_start_parallel_merge() was being invoked by row_merge_build_indexes(). The problem appears to be that something inside pthread_create() fails. In InnoDB, pthread_create() is called by os_thread_create_func(), which invokes pthread_attr_init() on one argument without checking the return value of that function. However, according to the Linux man-pages version 4.8, pthread_attr_init() should always succeed on Linux. The manual page for pthread_create() does not give hints why the pthread_create() might have crashed. Given that the platform is 32-bit (i386), one possibility could be exhaustion of the address space when trying to allocate stack for the thread. Maybe this could be repated by running the same tests on a single instance: innodb.innodb_prefix_index_restart_server 'innodb_plugin' w1 [ pass ] 8513 innodb.innodb_stats 'innodb_plugin' w1 [ pass ] 102 innodb.innodb_stats_create_on_corrupted 'innodb_plugin' w1 [ pass ] 2769 innodb.innodb_stats_create_table 'innodb_plugin' w1 [ pass ] 16 innodb.innodb_stats_drop_locked 'innodb_plugin' w1 [ pass ] 2206 innodb.innodb_stats_fetch 'innodb_plugin' w1 [ pass ] 34 innodb.innodb_stats_fetch_corrupted 'innodb_plugin' w1 [ pass ] 2792 innodb.innodb_stats_fetch_nonexistent 'innodb_plugin' w1 [ pass ] 23 innodb.innodb_stats_rename_table 'innodb_plugin' w1 [ pass ] 5 innodb.innodb_stats_rename_table_if_exists 'innodb_plugin' w1 [ pass ] 422 innodb.innodb_trx_weight 'innodb_plugin' w1 [ pass ] 135 innodb.mdev-117 'innodb_plugin' w1 [ pass ] 17 innodb.row_lock 'innodb_plugin' w1 [ pass ] 118 innodb.strict_mode 'innodb_plugin' w1 [ pass ] 34 innodb.system_tables 'innodb_plugin' w1 [ pass ] 2744 innodb.tmpdir 'innodb_plugin' w1 [ pass ] 147 innodb.xa_recovery 'innodb_plugin' w1 [ pass ] 5283 innodb_fts.fulltext 'innodb_plugin' w1 [ pass ] 1162 innodb_fts.fulltext2 'innodb_plugin' w1 [ pass ] 1120 innodb_fts.fulltext3 'innodb_plugin' w1 [ pass ] 41 innodb_fts.fulltext_cache 'innodb_plugin' w1 [ pass ] 40 innodb_fts.fulltext_distinct 'innodb_plugin' w1 [ pass ] 57 innodb_fts.fulltext_left_join 'innodb_plugin' w1 [ pass ] 168 innodb_fts.fulltext_misc 'innodb_plugin' w1 [ pass ] 255 innodb_fts.fulltext_multi 'innodb_plugin' w1 [ pass ] 68 innodb_fts.fulltext_order_by 'innodb_plugin' w1 [ pass ] 182 innodb_fts.fulltext_update 'innodb_plugin' w1 [ pass ] 37 innodb_fts.fulltext_var 'innodb_plugin' w1 [ pass ] 20 innodb_fts.innodb-fts-basic 'innodb_plugin' w1 [ pass ] 36 main.information_schema 'xtradb' w4 [ pass ] 3770 main.progress_976225 'xtradb' w4 [ pass ] 53 main.rowid_order_innodb 'xtradb' w4 [ pass ] 46 innodb_fts.innodb-fts-ddl 'innodb_plugin' w1 [ pass ] 1020 innodb_fts.innodb-fts-fic 'innodb_plugin' w1 [ pass ] 545 innodb_fts.innodb_fts_large_records 'innodb_plugin' w1 [ pass ] 1056 innodb_fts.innodb_fts_misc 'innodb_plugin' w1 [ fail ]

Manuel Arostegui added a comment - 2017-01-26 17:04

Quick note: this seems to affect also 10.0.28 and 10.0.29 but not 10.0.23.

Manuel Arostegui added a comment - 2017-01-26 17:04 Quick note: this seems to affect also 10.0.28 and 10.0.29 but not 10.0.23.

Marko Mäkelä added a comment - 2017-01-27 08:06

Reopening for backporting the fix to 10.0.

Marko Mäkelä added a comment - 2017-01-27 08:06 Reopening for backporting the fix to 10.0.

Manuel Arostegui added a comment - 2017-01-27 08:29

Hey Marko - thanks.
Check this: https://jira.mariadb.org/browse/MDEV-11918 as there is a PR already requested there.

Manuel Arostegui added a comment - 2017-01-27 08:29 Hey Marko - thanks. Check this: https://jira.mariadb.org/browse/MDEV-11918 as there is a PR already requested there.

People

Assignee:: Marko Mäkelä

Reporter:: Viktor Zeman

Votes:: 0 Vote for this issue

Watchers:: 8 Start watching this issue

Dates

Created:: 2016-11-04 08:16

Updated:: 2017-01-27 08:29

Resolved:: 2017-01-27 08:20

Git Integration

Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.

MariaDB Server