[MDEV-20407] mysqld got signal 11; rowid filter Created: 2019-08-22  Updated: 2019-11-27  Resolved: 2019-11-27

Status: Closed
Project: MariaDB Server
Component/s: Optimizer
Affects Version/s: 10.4.7, 10.4
Fix Version/s: 10.4.11

Type: Bug Priority: Critical
Reporter: Kieran Brahney Assignee: Igor Babaev
Resolution: Fixed Votes: 1
Labels: None
Environment:

docker

Issue Links:
Duplicate
is duplicated by MDEV-21040 InnoDB: fulltext search with ` in(...... Closed
Problem/Incident
is caused by MDEV-16188 Use in-memory PK filters built from r... Closed
Relates
relates to MDEV-21040 InnoDB: fulltext search with ` in(...... Closed
relates to MDEV-21047 Crash on UTF-8 Full text search Closed
relates to MDEV-21125 Crash with FTS query Closed

 Description   

Query

select count(0) AS `aggregate` from `ticket_message` where `ticket_message`.`ticket_id` = 15066 and (match `ticket_message`.`text` against ('+"Website design"' in boolean mode));

Explain

+------+-------------+----------------+-----------------+---------------------------------------+---------------------------------------+---------+------+--------+---------------------------------+
 
| id   | select_type | table          | type            | possible_keys                         | key                                   | key_len | ref  | rows   | Extra                           |
 
+------+-------------+----------------+-----------------+---------------------------------------+---------------------------------------+---------+------+--------+---------------------------------+
 
|    1 | SIMPLE      | ticket_message | fulltext|filter | ticket_message_ticket_id_foreign,text | text|ticket_message_ticket_id_foreign | 0|4     |      | 1 (0%) | Using where; Using rowid filter |
 
+------+-------------+----------------+-----------------+---------------------------------------+---------------------------------------+---------+------+--------+---------------------------------+
 
1 row in set (0.000 sec)

Result

ERROR 2013 (HY000): Lost connection to MySQL server during query

Logs

190822 14:32:29 [ERROR] mysqld got signal 11 ;
 
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.4.7-MariaDB-1:10.4.7+maria~bionic
 
key_buffer_size=134217728
 
read_buffer_size=2097152
 
max_used_connections=1
 
max_threads=102
 
thread_count=7
 
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 760243 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0x7f1068000f38
 
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 = 0x7f1080de7dd8 thread_stack 0x49000
 
mysqld(my_print_stacktrace+0x2e)[0x55dd4ed9ecee]
 
mysqld(handle_fatal_signal+0x515)[0x55dd4e816085]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x12890)[0x7f109011d890]
 
mysqld(+0xae5314)[0x55dd4eaa4314]
 
mysqld(+0x561d35)[0x55dd4e520d35]
 
mysqld(+0x561fe1)[0x55dd4e520fe1]
 
mysqld(+0xae7653)[0x55dd4eaa6653]
 
mysqld(+0xa011dd)[0x55dd4e9c01dd]
 
mysqld(+0x68bfb2)[0x55dd4e64afb2]
 
mysqld(_Z10sub_selectP4JOINP13st_join_tableb+0x163)[0x55dd4e640f63]
 
mysqld(_ZN4JOIN10exec_innerEv+0xa8b)[0x55dd4e6621fb]
 
mysqld(_ZN4JOIN4execEv+0x33)[0x55dd4e6625a3]
 
mysqld(_Z12mysql_selectP3THDP10TABLE_LISTjR4ListI4ItemEPS4_jP8st_orderS9_S7_S9_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x131)[0x55dd4e660961]
 
mysqld(_Z13handle_selectP3THDP3LEXP13select_resultm+0x141)[0x55dd4e661311]
 
mysqld(+0x63f291)[0x55dd4e5fe291]
 
mysqld(_Z21mysql_execute_commandP3THD+0x12ab)[0x55dd4e60653b]
 
mysqld(_Z11mysql_parseP3THDPcjP12Parser_statebb+0x22a)[0x55dd4e60dd4a]
 
mysqld(_Z16dispatch_command19enum_server_commandP3THDPcjbb+0x1689)[0x55dd4e610559]
 
mysqld(_Z10do_commandP3THD+0x148)[0x55dd4e611b48]
 
mysqld(_Z24do_handle_one_connectionP7CONNECT+0x2c6)[0x55dd4e6ecca6]
 
mysqld(handle_one_connection+0x3d)[0x55dd4e6ecd9d]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x76db)[0x7f10901126db]
 
/lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7f108f51088f]
 
 
 
Trying to get some variables.
 
Some pointers may be invalid and cause the dump to abort.
 
Query (0x7f1068010210): select count(0) AS `aggregate` from `supportpal`.`ticket_message` where `supportpal`.`ticket_message`.`ticket_id` = 15066 and (match `supportpal`.`ticket_message`.`text` against ('+"Website design"' in boolean mode))
 
Connection ID (thread ID): 8
 
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=on,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on,condition_pushdown_for_subquery=on,rowid_filter=on,condition_pushdown_from_having=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.
 
Writing a core file...
 
Working directory at /var/lib/mysql
 
Resource Limits:
 
Limit                     Soft Limit           Hard Limit           Units     
Max cpu time              unlimited            unlimited            seconds   
Max file size             unlimited            unlimited            bytes     
Max data size             unlimited            unlimited            bytes     
Max stack size            8388608              unlimited            bytes     
Max core file size        unlimited            unlimited            bytes     
Max resident set          unlimited            unlimited            bytes     
Max processes             unlimited            unlimited            processes 
Max open files            1048576              1048576              files     
Max locked memory         16777216             16777216             bytes     
Max address space         unlimited            unlimited            bytes     
Max file locks            unlimited            unlimited            locks     
Max pending signals       7873                 7873                 signals   
Max msgqueue size         819200               819200               bytes     
Max nice priority         0                    0                    
Max realtime priority     0                    0                    
Max realtime timeout      unlimited            unlimited            us        
Core pattern: |/usr/share/apport/apport %p %s %c %d %P

Steps to replicate

curl -fsSL https://get.docker.com -o get-docker.sh && sh get-docker.sh
 
docker run --name mariadb -e MYSQL_ROOT_PASSWORD=my-secret-pw -d mariadb:10.4.7
 
docker exec -i mariadb sh -c 'exec mysql -uroot -p"my-secret-pw" supportpal' < db_supportPAL.sql

Fix

Turning off rowid_filter in the optimizer switch stops it from dieing.

 Comments   
Comment by Alice Sherepa [ 2019-08-23 ]

Could you please add the output of SHOW CREATE TABLE ticket_message;
and upload db_supportPAL.sql?

Comment by Kieran Brahney [ 2019-08-26 ]

Is there a secure way to share a dump without sharing publicly?

Comment by Alice Sherepa [ 2019-08-27 ]

please upload your test data to ftp.askmonty.org/private

Comment by Kieran Brahney [ 2019-08-27 ]

Uploaded db_supportPAL.zip

Comment by Kieran Brahney [ 2019-09-08 ]

Any update on this?

Comment by Manuel Schulze [ 2019-09-10 ]

I'm seeing the exact same problem and the workaround posted here also fixed it for me. But can't be 100 % sure that it's the same bug. I first noticed this bug when upgrading from 10.3.9 to 10.4.7. (and the default for rowid_filter was also changed between these versions)

For me it only happens under very specific circumstances within the web app that's making the query. Essentially the crash doesn't happen when it only has to query one record. When it has to query two or more it crashes.

Comment by Manuel Schulze [ 2019-09-10 ]

I have a report from another user of the same web app and he's not seeing this issue, but he's running MariaDB 10.4.7 on Windows 10 (I'm on Ubuntu 18.04)

Comment by Alice Sherepa [ 2019-09-10 ]

Thanks a lot!
Reproducible on 10.4 with optimizer_switch='rowid_filter=on':

--source include/have_innodb.inc
 
set optimizer_switch='rowid_filter=on';
 
create table t1(id int, s text, key (id), fulltext key (s)) engine=innodb;
 
 
 
insert into t1 values (1119,'t'),(1134,'t'),(1134,'t'),(1143,'t'),(1143,'t'),(1187,'t'),(1187,'t'),(1187,'t'),(1187,'t'),(1187,'t'),(1187,'t'),(1187,'t'),(1187,'t'),(1187,'t'),(1187,'t'),(1210,'t'),(1210,'t'),(1210,'t'),(1210,'t'),(1210,'t'),(1210,'t'),(1214,'t'),(1214,'t'),(1215,'t'),(1215,'t'),(1215,'t'),(1216,'t'),(1218,'t'),(1220,'t'),(1220,'t'),(1220,'t'),(1222,'t'),(1223,'t'),(1223,'t'),(1224,'t'),(1225,'t'),(1225,'t'),(1226,'t'),(1226,'t'),(1227,'t'),(1227,'t'),(1228,'t'),(1229,'t'),(1230,'t'),(1230,'t'),(1231,'t'),(1231,'t'),(1232,'t'),(1232,'t'),(1232,'t'),(1232,'t'),(1233,'t'),(1241,'t'),(1245,'t'),(1247,'t'),(1247,'t'),(1247,'t'),(1247,'t'),(1247,'t'),(1247,'t'),(1248,'like fttest');
 
 
 
select count(0) from t1
 
 where id=15066 and (match s against ('+"fttest"' in boolean mode));


MariaDB [test1]> explain extended
 
    -> select count(0) from t1
 
    ->  where id=15066 and (match s against ('+"fttest"' in boolean mode));
 
+------+-------------+-------+-----------------+---------------+------+---------+------+--------+----------+---------------------------------+
 
| id   | select_type | table | type            | possible_keys | key  | key_len | ref  | rows   | filtered | Extra                           |
 
+------+-------------+-------+-----------------+---------------+------+---------+------+--------+----------+---------------------------------+
 
|    1 | SIMPLE      | t1    | fulltext|filter | id,s          | s|id | 0|5     |      | 1 (2%) |     1.64 | Using where; Using rowid filter |
 
+------+-------------+-------+-----------------+---------------+------+---------+------+--------+----------+---------------------------------+
 
1 row in set, 1 warning (0.000 sec)

10.4 e980cf91cd01313edb659b128

 
mysqld: /10.4/storage/innobase/include/rem0rec.h:665: ulint rec_offs_nth_flag(const ulint*, ulint, ulint): Assertion `n < rec_offs_n_fields(offsets)' failed.
 
190910 19:51:08 [ERROR] mysqld got signal 6 ;
 
 
 
Server version: 10.4.8-MariaDB-debug-log
 
 
 
assert/assert.c:92(__assert_fail_base)[0x7f00247e8bd7]
 
/lib/x86_64-linux-gnu/libc.so.6(+0x2dc82)[0x7f00247e8c82]
 
include/rem0rec.h:665(rec_offs_nth_flag(unsigned long const*, unsigned long, unsigned long))[0x563396aa844f]
 
include/rem0rec.h:708(rec_offs_nth_extern(unsigned long const*, unsigned long))[0x563396aa862d]
 
row/row0sel.cc:2908(row_sel_store_mysql_field(unsigned char*, row_prebuilt_t*, unsigned char const*, dict_index_t const*, unsigned long const*, unsigned long, mysql_row_templ_t const*))[0x563396c4963b]
 
row/row0sel.cc:3921(row_search_idx_cond_check(unsigned char*, row_prebuilt_t*, unsigned char const*, unsigned long const*))[0x563396c4c2b8]
 
row/row0sel.cc:5257(row_search_mvcc(unsigned char*, page_cur_mode_t, row_prebuilt_t*, unsigned long, unsigned long))[0x563396c506cd]
 
include/row0sel.ic:138(row_search_for_mysql(unsigned char*, page_cur_mode_t, row_prebuilt_t*, unsigned long, unsigned long))[0x563396a423ee]
 
handler/ha_innodb.cc:10091(ha_innobase::ft_read(unsigned char*))[0x563396a575a1]
 
sql/sql_class.h:6557(handler::ha_ft_read(unsigned char*))[0x5633963e63bc]
 
sql/sql_select.cc:21231(join_ft_read_first(st_join_table*))[0x5633963cd5ab]
 
sql/sql_select.cc:20154(sub_select(JOIN*, st_join_table*, bool))[0x5633963ca825]
 
sql/sql_select.cc:19695(do_select(JOIN*, Procedure*))[0x5633963c9cf7]
 
sql/sql_select.cc:4391(JOIN::exec_inner())[0x56339639eaa1]
 
sql/sql_select.cc:4174(JOIN::exec())[0x56339639dbd0]
 
sql/sql_select.cc:4607(mysql_select(THD*, TABLE_LIST*, unsigned int, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*))[0x56339639f2f3]
 
sql/sql_select.cc:425(handle_select(THD*, LEX*, select_result*, unsigned long))[0x56339638f0ab]
 
sql/sql_parse.cc:6357(execute_sqlcom_select(THD*, TABLE_LIST*))[0x563396355123]
 
sql/sql_parse.cc:3899(mysql_execute_command(THD*))[0x56339634a6d4]
 
sql/sql_parse.cc:7909(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x5633963592b1]
 
sql/sql_parse.cc:1845(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool))[0x563396344278]
 
sql/sql_parse.cc:1360(do_command(THD*))[0x563396342896]
 
sql/sql_connect.cc:1412(do_handle_one_connection(CONNECT*))[0x5633964cd39d]
 
sql/sql_connect.cc:1317(handle_one_connection)[0x5633964cd0c6]
 
perfschema/pfs.cc:1864(pfs_spawn_thread)[0x563396f0453f]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x76ba)[0x7f0025cdf6ba]
 
x86_64/clone.S:111(clone)[0x7f00248c241d]
 
 
 
Query (0x7effd4013118): select count(0) from t1 where id=15066 and (match s against ('+"fttest"' in boolean mode))

on non-debug:

 
190910 20:27:26 [ERROR] mysqld got signal 11 ;
 
Server version: 10.4.8-MariaDB-log
 
row/row0sel.cc:2864(row_sel_field_store_in_mysql_format_func(unsigned char*, mysql_row_templ_t const*, unsigned char const*, unsigned long))[0x560f2a8d2a97]
 
row/row0sel.cc:3011(row_sel_store_mysql_field(unsigned char*, row_prebuilt_t*, unsigned char const*, dict_index_t const*, unsigned long const*, unsigned long, mysql_row_templ_t const*))[0x560f2a2fe30c]
 
row/row0sel.cc:3921(row_search_idx_cond_check(unsigned char*, row_prebuilt_t*, unsigned char const*, unsigned long const*))[0x560f2a2fe5ae]
 
row/row0sel.cc:5257(row_search_mvcc(unsigned char*, page_cur_mode_t, row_prebuilt_t*, unsigned long, unsigned long))[0x560f2a8d460e]
 
handler/ha_innodb.cc:10093(ha_innobase::ft_read(unsigned char*))[0x560f2a8046e4]
 
sql/sql_class.h:6558(handler::ha_ft_read(unsigned char*))[0x560f2a419066]
 
sql/sql_select.cc:20155(sub_select(JOIN*, st_join_table*, bool))[0x560f2a40f34d]
 
sql/sql_select.cc:19696(do_select)[0x560f2a42f169]
 
sql/sql_select.cc:4174(JOIN::exec())[0x560f2a42f3c4]
 
sql/sql_select.cc:4607(mysql_select(THD*, TABLE_LIST*, unsigned int, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*))[0x560f2a42d730]
 
sql/sql_select.cc:425(handle_select(THD*, LEX*, select_result*, unsigned long))[0x560f2a42e09e]
 
sql/sql_parse.cc:6359(execute_sqlcom_select(THD*, TABLE_LIST*) [clone .constprop.288])[0x560f2a2f0dd7]
 
sql/sql_parse.cc:3899(mysql_execute_command(THD*))[0x560f2a3ddc9a]
 
sql/sql_parse.cc:7909(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x560f2a3df3f9]
 
sql/sql_parse.cc:1907(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool))[0x560f2a3e133c]
 
sql/sql_parse.cc:1360(do_command(THD*))[0x560f2a3e2ff9]
 
sql/sql_connect.cc:1412(do_handle_one_connection(CONNECT*))[0x560f2a4b23d4]
 
sql/sql_connect.cc:1318(handle_one_connection)[0x560f2a4b2484]
 
perfschema/pfs.cc:1865(pfs_spawn_thread)[0x560f2aa534d4]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x76ba)[0x7f4cc23206ba]
 
x86_64/clone.S:111(clone)[0x7f4cc0f0341d]

Comment by Igor Babaev [ 2019-11-27 ]

This bug was fixed by the patch for MDEV-20056

Generated at Thu Feb 08 08:59:14 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.