Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Duplicate
-
10.1(EOL), 10.2(EOL)
-
None
-
10.1.24, 10.2.10, 10.2.11
Description
Might be related to MDEV-5518 / https://bugs.mysql.com/bug.php?id=73819
innodb_fts.fulltext_misc 'innodb_plugin' w1 [ fail ] Found warnings/errors in server log file!
|
Test ended at 2017-04-27 13:05:34
|
line
|
==1037== Thread 22:
|
==1037== Syscall param write(buf) points to uninitialised byte(s)
|
==1037== at 0x4E42B1D: ??? (in /lib64/libpthread-2.18.so)
|
==1037== by 0xF1EB0B: my_write (my_write.c:49)
|
==1037== by 0xEF31ED: inline_mysql_file_write (mysql_file.h:1131)
|
==1037== by 0xEF5E79: _my_b_cache_write (mf_iocache.c:1643)
|
==1037== by 0xEF66D4: my_b_flush_io_cache (mf_iocache.c:1843)
|
==1037== by 0xEF68C2: end_io_cache (mf_iocache.c:1902)
|
==1037== by 0xA8A5A5: maria_extra (ma_extra.c:164)
|
==1037== by 0xA4547A: ha_maria::extra(ha_extra_function) (ha_maria.cc:2583)
|
==1037== by 0x6F5367: select_union::flush() (sql_union.cc:111)
|
==1037== by 0x6F7C07: st_select_lex_unit::exec() (sql_union.cc:849)
|
==1037== by 0x6F5045: mysql_union(THD*, LEX*, select_result*, st_select_lex_unit*, unsigned long) (sql_union.cc:39)
|
==1037== by 0x658035: handle_select(THD*, LEX*, select_result*, unsigned long) (sql_select.cc:362)
|
==1037== Address 0x183197eb is 11 bytes inside a block of size 131,080 alloc'd
|
==1037== at 0x4C280F3: malloc (vg_replace_malloc.c:299)
|
==1037== by 0xF178DA: my_malloc (my_malloc.c:101)
|
==1037== by 0xEF3B76: init_io_cache (mf_iocache.c:272)
|
==1037== by 0xA8A512: maria_extra (ma_extra.c:145)
|
==1037== by 0xA4547A: ha_maria::extra(ha_extra_function) (ha_maria.cc:2583)
|
==1037== by 0x6F5590: select_union::create_result_table(THD*, List<Item>*, bool, unsigned long long, char const*, bool, bool, bool) (sql_union.cc:168)
|
==1037== by 0x6F6AFE: st_select_lex_unit::prepare(THD*, select_result*, unsigned long) (sql_union.cc:585)
|
==1037== by 0x6F502B: mysql_union(THD*, LEX*, select_result*, st_select_lex_unit*, unsigned long) (sql_union.cc:37)
|
==1037== by 0x658035: handle_select(THD*, LEX*, select_result*, unsigned long) (sql_select.cc:362)
|
==1037== by 0x627253: execute_sqlcom_select(THD*, TABLE_LIST*) (sql_parse.cc:5920)
|
==1037== by 0x61D721: mysql_execute_command(THD*) (sql_parse.cc:2979)
|
==1037== by 0x62A952: mysql_parse(THD*, char*, unsigned int, Parser_state*) (sql_parse.cc:7343)
|
Attachments
Issue Links
- relates to
-
-
- Closed
-
-
-
- Closed
-
Activity
| Field | Original Value | New Value |
|---|---|---|
| Link |
This issue relates to |
| Link |
This issue relates to |
| Sprint | 10.1.24 [ 161 ] |
| Fix Version/s | 10.2 [ 14601 ] | |
| Affects Version/s | 10.2 [ 14601 ] |
Reproducible locally (Jessie 8.8 64-bit, valgrind-3.12.0.SVN, gcc (Debian 4.9.2-10) 4.9.2) on the current 10.1 tree:
|
10.1 535910ae5f20e36405631030e9c0eb22fe40a7c4 |
$ perl ./mtr innodb_fts.fulltext_misc --valgrind --mem
|
|
|
innodb_fts.fulltext_misc 'innodb_plugin' [ fail ] Found warnings/errors in server log file!
|
Test ended at 2017-08-10 13:24:26
|
line
|
==18242== Thread 22:
|
==18242== Syscall param write(buf) points to uninitialised byte(s)
|
==18242== at 0x4E481AD: ??? (syscall-template.S:84)
|
==18242== by 0xEDA948: my_write (my_write.c:49)
|
==18242== by 0xEAF5DF: inline_mysql_file_write (mysql_file.h:1131)
|
==18242== by 0xEB2266: _my_b_cache_write (mf_iocache.c:1643)
|
==18242== by 0xEB2ACB: my_b_flush_io_cache (mf_iocache.c:1843)
|
==18242== by 0xEB2CB9: end_io_cache (mf_iocache.c:1902)
|
==18242== by 0xA38CAA: maria_extra (ma_extra.c:165)
|
==18242== by 0x9F3C94: ha_maria::extra(ha_extra_function) (ha_maria.cc:2583)
|
==18242== by 0x6B4BFB: select_union::flush() (sql_union.cc:111)
|
==18242== by 0x6B7534: st_select_lex_unit::exec() (sql_union.cc:864)
|
==18242== by 0x6B48D3: mysql_union(THD*, LEX*, select_result*, st_select_lex_unit*, unsigned long) (sql_union.cc:39)
|
==18242== by 0x616AD8: handle_select(THD*, LEX*, select_result*, unsigned long) (sql_select.cc:362)
|
==18242== by 0x5E5EFA: execute_sqlcom_select(THD*, TABLE_LIST*) (sql_parse.cc:5924)
|
==18242== by 0x5DC3CB: mysql_execute_command(THD*) (sql_parse.cc:2981)
|
==18242== by 0x5E9608: mysql_parse(THD*, char*, unsigned int, Parser_state*) (sql_parse.cc:7344)
|
==18242== by 0x5D8565: dispatch_command(enum_server_command, THD*, char*, unsigned int) (sql_parse.cc:1484)
|
==18242== Address 0x1873704b is 11 bytes inside a block of size 131,080 alloc'd
|
==18242== at 0x4C2BBAF: malloc (vg_replace_malloc.c:299)
|
==18242== by 0xED3927: my_malloc (my_malloc.c:101)
|
==18242== by 0xEAFF5C: init_io_cache (mf_iocache.c:272)
|
==18242== by 0xA38C13: maria_extra (ma_extra.c:145)
|
==18242== by 0x9F3C94: ha_maria::extra(ha_extra_function) (ha_maria.cc:2583)
|
==18242== by 0x6B4E17: select_union::create_result_table(THD*, List<Item>*, bool, unsigned long long, char const*, bool, bool, bool) (sql_union.cc:168)
|
==18242== by 0x6B6426: st_select_lex_unit::prepare(THD*, select_result*, unsigned long) (sql_union.cc:598)
|
==18242== by 0x6B48B9: mysql_union(THD*, LEX*, select_result*, st_select_lex_unit*, unsigned long) (sql_union.cc:37)
|
==18242== by 0x616AD8: handle_select(THD*, LEX*, select_result*, unsigned long) (sql_select.cc:362)
|
==18242== by 0x5E5EFA: execute_sqlcom_select(THD*, TABLE_LIST*) (sql_parse.cc:5924)
|
==18242== by 0x5DC3CB: mysql_execute_command(THD*) (sql_parse.cc:2981)
|
==18242== by 0x5E9608: mysql_parse(THD*, char*, unsigned int, Parser_state*) (sql_parse.cc:7344)
|
==18242== by 0x5D8565: dispatch_command(enum_server_command, THD*, char*, unsigned int) (sql_parse.cc:1484)
|
==18242== by 0x5D7302: do_command(THD*) (sql_parse.cc:1106)
|
==18242== by 0x714C78: do_handle_one_connection(THD*) (sql_connect.cc:1349)
|
==18242== by 0x7149DC: handle_one_connection (sql_connect.cc:1261)
|
^ Found warnings in /data/bld/10.1-valgrind/mysql-test/var/log/mysqld.1.err
|
ok
|
With vgdb, I got the following stack trace with parameter values:
#0 0x0000000004e481ad in write () at ../sysdeps/unix/syscall-template.S:84
|
#1 0x00000000010ff470 in my_write (Filedes=65,
|
Buffer=0x10f28f98 "\375\001\061", Count=24, MyFlags=36)
|
at /mariadb/10.2/mysys/my_write.c:49
|
#2 0x00000000010d38be in inline_mysql_file_write (
|
src_file=0x147d610 "/mariadb/10.2/mysys/mf_iocache.c", src_line=1733,
|
file=65, buffer=0x10f28f98 "\375\001\061", count=24, flags=36)
|
at /mariadb/10.2/include/mysql/psi/mysql_file.h:1131
|
#3 0x00000000010d68c3 in _my_b_cache_write (info=0x10ce2108,
|
Buffer=0x10f28f98 "\375\001\061", Count=24)
|
at /mariadb/10.2/mysys/mf_iocache.c:1733
|
#4 0x00000000010d7133 in my_b_flush_io_cache (info=0x10ce2108,
|
need_append_buffer_lock=0) at /mariadb/10.2/mysys/mf_iocache.c:1933
|
#5 0x00000000010d7325 in end_io_cache (info=0x10ce2108)
|
at /mariadb/10.2/mysys/mf_iocache.c:1992
|
#6 0x0000000000f70e08 in maria_extra (info=0x10ce1ca8,
|
function=HA_EXTRA_NO_CACHE, extra_arg=0x0)
|
at /mariadb/10.2/storage/maria/ma_extra.c:165
|
---Type <return> to continue, or q <return> to quit---
|
#7 0x0000000000f2bee8 in ha_maria::extra (this=0x1ca9fe80,
|
operation=HA_EXTRA_NO_CACHE)
|
at /mariadb/10.2/storage/maria/ha_maria.cc:2597
|
#8 0x00000000007a212c in select_union::flush (this=0x1caa3950)
|
at /mariadb/10.2/sql/sql_union.cc:135
|
#9 0x00000000007a5390 in st_select_lex_unit::exec (this=0x13b7c040)
|
at /mariadb/10.2/sql/sql_union.cc:1009
|
#10 0x00000000007a1d1a in mysql_union (thd=0x13b78558, lex=0x13b7bf78,
|
result=0x1ca9a300, unit=0x13b7c040, setup_tables_done_option=0)
|
at /mariadb/10.2/sql/sql_union.cc:41
|
#11 0x00000000006fcb9a in handle_select (thd=0x13b78558, lex=0x13b7bf78,
|
result=0x1ca9a300, setup_tables_done_option=0)
|
at /mariadb/10.2/sql/sql_select.cc:351
|
#12 0x00000000006c8007 in execute_sqlcom_select (thd=0x13b78558,
|
all_tables=0xc995920) at /mariadb/10.2/sql/sql_parse.cc:6444
|
#13 0x00000000006bdd23 in mysql_execute_command (thd=0x13b78558)
|
at /mariadb/10.2/sql/sql_parse.cc:3458
|
#14 0x00000000006cb9b3 in mysql_parse (thd=0x13b78558,
|
rawbuf=0x10d9f250 "SELECT * FROM t1 UNION SELECT * FROM t1\nORDER BY MATCH(a) AGAINST ('+abc' IN BOOLEAN MODE)", length=90, parser_state=0x412e1f0,
|
is_com_multi=false, is_next_command=false)
|
at /mariadb/10.2/sql/sql_parse.cc:7880
|
After killing the server at this spot, I will get:
CURRENT_TEST: innodb_fts.fulltext_misc
|
mysqltest: At line 186: query 'SELECT * FROM t1 UNION SELECT * FROM t1
|
ORDER BY MATCH(a) AGAINST ('+abc' IN BOOLEAN MODE)' failed: 2013: Lost connection to MySQL server during query
|
With the attached patch, the test completes without any Valgrind or server error whatsoever (not even on shutdown):
diff --git a/mysql-test/suite/innodb_fts/t/fulltext_misc.test b/mysql-test/suite/innodb_fts/t/fulltext_misc.test
|
index 25690ddc1d9..bc84143c30c 100644
|
--- a/mysql-test/suite/innodb_fts/t/fulltext_misc.test
|
+++ b/mysql-test/suite/innodb_fts/t/fulltext_misc.test
|
@@ -183,7 +183,7 @@ SELECT * FROM t1 UNION SELECT * FROM t1
|
|
--echo # Should not crash
|
--sorted_result
|
-SELECT * FROM t1 UNION SELECT * FROM t1
|
+SELECT * FROM t1
|
ORDER BY MATCH(a) AGAINST ('+abc' IN BOOLEAN MODE);
|
|
# FIXME: Valgrind in MySQL code _MI_WRITE_BLOB_RECORD, bug #13389854 |
I suppose that also the result to the client would be written to write() and instrumented by Valgrind, so InnoDB cannot be the culprit here.
The problem seems to be in the UNION execution instead. Whoever fixes this should also uncomment the following statement in the test:
# FIXME: Valgrind in MySQL code _MI_WRITE_BLOB_RECORD, bug #13389854 |
#--echo # Should not crash |
#(SELECT * FROM t1) UNION (SELECT * FROM t1) |
# ORDER BY MATCH(a) AGAINST ('+abc' IN BOOLEAN MODE); |
| Component/s | Optimizer [ 10200 ] | |
| Component/s | Storage Engine - Aria [ 10126 ] | |
| Component/s | Storage Engine - InnoDB [ 10129 ] |
| Status | Open [ 1 ] | Confirmed [ 10101 ] |
| Assignee | Marko Mäkelä [ marko ] | Oleksandr Byelkin [ sanja ] |
Reduced test case:
--source include/have_innodb.inc
|
CREATE TABLE t1 (a VARCHAR(10), FULLTEXT KEY a (a)) ENGINE = InnoDB; |
INSERT INTO t1 VALUES (1),(2); |
SELECT * FROM t1 UNION SELECT * FROM t1 |
ORDER BY MATCH(a) AGAINST ('+abc' IN BOOLEAN MODE); |
DROP TABLE t1; |
Relevant configuration: cmake -DWITH_VALGRIND=ON -DWITH_ASAN=OFF -DCMAKE_BUILD_TYPE=Debug
With MyISAM instead of InnoDB, it does not fail, but that could be because MyISAM is not calling VALGRIND_MAKE_MEM_UNDEFINED.
My guess: The optimizer could be writing a garbage part of a record to an internal temporary table.
Please debug with vgdb use monitor get_vbits to find out which bytes are flagged as uninitialized.
The problem seems to be the UNION. A plain SELECT with or without the ORDER BY will execute just fine.
It would seem to me that the issue is that the uninitialized tail of VARCHAR columns is being written to a temporary table. With CHAR(10) instead of VARCHAR(10), the test passes just fine.
Please refer to Bug#12835650 VARCHAR maximum length performance impact.
It seems that in MySQL, the Valgrind warnings were suppressed, instead of fixing the problem. For example: Bug#12856915 VALGRIND FAILURE IN FILESORT/CREATE_SORT_INDEX
| Summary | Syscall param write(buf) points to uninitialised byte(s) in my_write, innodb_fts.fulltext_misc fails in buildbot with valgrind | SELECT UNION writes garbage tail of VARCHAR column into internal temporary table |
| Status | Confirmed [ 10101 ] | In Progress [ 3 ] |
| Status | In Progress [ 3 ] | Stalled [ 10000 ] |
| Status | Stalled [ 10000 ] | In Progress [ 3 ] |
Does the test case really require FULLTEXT INDEX? Note that 10.0 should support FULLTEXT INDEX for InnoDB tables. 5.5 does not, but the problem should be repeatable there with a different type of query if you define UNIV_DEBUG_VALGRIND inside InnoDB.
Note: if the UNION is not optimized away in the following (I did not test), it should repeat also with that:
--source include/have_innodb.inc
|
CREATE TABLE t1 (a VARCHAR(10)) ENGINE = InnoDB; |
INSERT INTO t1 VALUES (1),(2); |
SELECT * FROM t1 UNION SELECT * FROM t1; |
| Sprint | 10.1.24 [ 161 ] | 10.1.24, 10.2.10 [ 161, 183 ] |
| Status | In Progress [ 3 ] | Stalled [ 10000 ] |
| Status | Stalled [ 10000 ] | In Progress [ 3 ] |
in 10.0 FT expressions prohibited in last "union branch" (whatever does mean in the comment) so it is also not repeatable.
| Status | In Progress [ 3 ] | Stalled [ 10000 ] |
| Status | Stalled [ 10000 ] | In Progress [ 3 ] |
| Sprint | 10.1.24, 10.2.10 [ 161, 183 ] | 10.1.24, 10.2.10, 10.1.29 [ 161, 183, 202 ] |
If remove "binary mode" it return error that can not find fulltext index and it looks correct, why it do not need index in binary mode.
it appeared that boolean mode allow absence of index.
internal temporary table table is aria, returned value of match is the same independent of original type of the table, but bug reproduceble only with innodb as t1 table.
It is 2 SELECTs with number 3, probably again problem of reset counter of SELECTs because of the error
| Comment |
[ Actually each function is building in query, so it is OK.
Repeating fix for the procedure fixed the functions. ] |
| Status | In Progress [ 3 ] | Stalled [ 10000 ] |
| Sprint | 10.1.24, 10.2.10, 10.1.29 [ 161, 183, 202 ] | 10.1.24, 10.2.10, 10.2.11 [ 161, 183, 203 ] |
| Status | Stalled [ 10000 ] | In Progress [ 3 ] |
| Comment |
[ According to review
- make test case with triggers - move action into execute ] |
The problem is fixed. the fact that bisect can't find normally the commit which fixed it it came form merge.
Also query in one of the test proposed here start return incorrect usage of FT and also the fact that it was not repeatable without FT and binary patch in particular makes me think that problem was there.
So I will just uncomment commented out test in fulltext_misc
OK, bisect was done incorrectly.
here is patch which fixed the problem:
HEAD ist jetzt bei b20f821e072 Fix Innodb ASAN error on init
b20f821e0723c27d6ce121aafb2eb6c6d89bcd57 is the first bad commit
commit b20f821e0723c27d6ce121aafb2eb6c6d89bcd57
Author: Vicențiu Ciorbaru <vicentiu@mariadb.org>
Date: Wed Jan 24 15:18:36 2018 +0200
Fix Innodb ASAN error on init
Backport 7c03edf2fe66855a8ce8f2575c3aaf66af975377 from xtradb to innodb
| Status | In Progress [ 3 ] | Stalled [ 10000 ] |
| Fix Version/s | 10.2.15 [ 23006 ] | |
| Fix Version/s | 10.1.33 [ 22909 ] | |
| Fix Version/s | 10.2 [ 14601 ] | |
| Fix Version/s | 10.1 [ 16100 ] | |
| Resolution | Duplicate [ 3 ] | |
| Status | Stalled [ 10000 ] | Closed [ 6 ] |
| Workflow | MariaDB v3 [ 80537 ] | MariaDB v4 [ 152052 ] |
This could have a common root cause with
MDEV-11649.