Details
-
Bug
-
Status: Open (View Workflow)
-
Minor
-
Resolution: Unresolved
-
10.2(EOL), 10.3(EOL), 10.4(EOL), 10.5, 10.6
Description
When certain strings of a considerable length are inserted into an InnoDB table with fulltext index (or existing values are updated to such strings), on a debug server it takes very long time.
I fully realize that debug server is bound to be slower, but I think it's worth checking, when/if priorities permit, whether it should be that much slower.
It doesn't happen with any string. If the file contents is replaced with REPEAT of a similar length, the execution is very quick. An example of a file which causes a problem is attached. It is a part of a real-life JSON document from an official public source.
Please note that to run the test below, you need to download the attached file and put it into the location which LOAD_FILE points at.
Also, if you are running the test via MTR, it needs to be run with --mysqld=--secure-file-priv='', otherwise it will quietly refuse to read the file. It will only be noticeable in the LENGTH output.
--source include/have_innodb.inc
|
|
|
CREATE TABLE t (f MEDIUMTEXT, FULLTEXT KEY (f)) ENGINE=InnoDB; |
|
|
SET @a= LOAD_FILE('/dev/shm/01.json'); |
SELECT LENGTH(@a); |
INSERT INTO t VALUES (@a),(@a); |
|
|
# Cleanup
|
DROP TABLE t; |
MariaDB [test]> SELECT LENGTH(@a); |
+------------+ |
| LENGTH(@a) |
|
+------------+ |
| 1315965 |
|
+------------+ |
1 row in set (0.000 sec) |
|
10.6 1bd41158 -DCMAKE_BUILD_TYPE=Debug |
MariaDB [test]> INSERT INTO t VALUES (@a),(@a); |
Query OK, 2 rows affected (53.350 sec) |
|
10.6 1bd41158 -DCMAKE_BUILD_TYPE=Debug optimized, with -O2 |
MariaDB [test]> INSERT INTO t VALUES (@a),(@a); |
Query OK, 2 rows affected (33.993 sec) |
|
10.6 1bd41158 -DBUILD_CONFIG=mysql_release |
MariaDB [test]> INSERT INTO t VALUES (@a),(@a); |
Query OK, 2 rows affected (0.673 sec) |
While running INSERT, the stack trace mainly alternates between these two patterns:
|
10.6 1bd41158 Debug |
Thread 13 (Thread 0x7f96b8697700 (LWP 1895922)):
|
#0 0x0000560f3888638a in rbt_count_black_nodes (tree=0x7f967119d8b8, node=0x7f967119d918) at /data/src/10.6/storage/innobase/ut/ut0rbt.cc:105
|
#1 0x0000560f388863d9 in rbt_count_black_nodes (tree=0x7f967119d8b8, node=0x7f9671022868) at /data/src/10.6/storage/innobase/ut/ut0rbt.cc:111
|
#2 0x0000560f388863be in rbt_count_black_nodes (tree=0x7f967119d8b8, node=0x7f9670a67878) at /data/src/10.6/storage/innobase/ut/ut0rbt.cc:109
|
#3 0x0000560f388863be in rbt_count_black_nodes (tree=0x7f967119d8b8, node=0x7f967102a408) at /data/src/10.6/storage/innobase/ut/ut0rbt.cc:109
|
#4 0x0000560f388863d9 in rbt_count_black_nodes (tree=0x7f967119d8b8, node=0x7f9670fe0dc8) at /data/src/10.6/storage/innobase/ut/ut0rbt.cc:111
|
#5 0x0000560f388863d9 in rbt_count_black_nodes (tree=0x7f967119d8b8, node=0x7f967114ab28) at /data/src/10.6/storage/innobase/ut/ut0rbt.cc:111
|
#6 0x0000560f388863be in rbt_count_black_nodes (tree=0x7f967119d8b8, node=0x7f967114dc88) at /data/src/10.6/storage/innobase/ut/ut0rbt.cc:109
|
#7 0x0000560f388863d9 in rbt_count_black_nodes (tree=0x7f967119d8b8, node=0x7f96711621f8) at /data/src/10.6/storage/innobase/ut/ut0rbt.cc:111
|
#8 0x0000560f388863d9 in rbt_count_black_nodes (tree=0x7f967119d8b8, node=0x7f967118e378) at /data/src/10.6/storage/innobase/ut/ut0rbt.cc:111
|
#9 0x0000560f388863d9 in rbt_count_black_nodes (tree=0x7f967119d8b8, node=0x7f967118df18) at /data/src/10.6/storage/innobase/ut/ut0rbt.cc:111
|
#10 0x0000560f388863d9 in rbt_count_black_nodes (tree=0x7f967119d8b8, node=0x7f967119af78) at /data/src/10.6/storage/innobase/ut/ut0rbt.cc:111
|
#11 0x0000560f388863d9 in rbt_count_black_nodes (tree=0x7f967119d8b8, node=0x7f96711960d8) at /data/src/10.6/storage/innobase/ut/ut0rbt.cc:111
|
#12 0x0000560f388863be in rbt_count_black_nodes (tree=0x7f967119d8b8, node=0x7f967119da98) at /data/src/10.6/storage/innobase/ut/ut0rbt.cc:109
|
#13 0x0000560f388863d9 in rbt_count_black_nodes (tree=0x7f967119d8b8, node=0x7f967119dbe8) at /data/src/10.6/storage/innobase/ut/ut0rbt.cc:111
|
#14 0x0000560f388863be in rbt_count_black_nodes (tree=0x7f967119d8b8, node=0x7f9671199ae8) at /data/src/10.6/storage/innobase/ut/ut0rbt.cc:109
|
#15 0x0000560f38887e71 in rbt_validate (tree=0x7f967119d8b8) at /data/src/10.6/storage/innobase/ut/ut0rbt.cc:1136
|
#16 0x0000560f389c27ae in fts_add_token (result_doc=0x7f96b86944d0, str=..., position=1043775) at /data/src/10.6/storage/innobase/fts/fts0fts.cc:4447
|
#17 0x0000560f389c2963 in fts_process_token (doc=0x7f96b86944d0, result=0x0, start_pos=1043774, add_pos=0) at /data/src/10.6/storage/innobase/fts/fts0fts.cc:4490
|
#18 0x0000560f389c2ece in fts_tokenize_document (doc=0x7f96b86944d0, result=0x0, parser=0x0) at /data/src/10.6/storage/innobase/fts/fts0fts.cc:4675
|
#19 0x0000560f389bf4ec in fts_fetch_doc_from_rec (get_doc=0x7f967003d038, clust_index=0x7f9670024918, pcur=0x7f96b8694620, offsets=0x7f967002b268, doc=0x7f96b86944d0) at /data/src/10.6/storage/innobase/fts/fts0fts.cc:3217
|
#20 0x0000560f389c00d4 in fts_add_doc_by_id (ftt=0x7f967008f4e8, doc_id=2, fts_indexes=0x0) at /data/src/10.6/storage/innobase/fts/fts0fts.cc:3489
|
#21 0x0000560f389be6b7 in fts_add (ftt=0x7f967008f4e8, row=0x7f967001be28) at /data/src/10.6/storage/innobase/fts/fts0fts.cc:2807
|
#22 0x0000560f389bee37 in fts_commit_table (ftt=0x7f967008f4e8) at /data/src/10.6/storage/innobase/fts/fts0fts.cc:2979
|
#23 0x0000560f389bef2e in fts_commit (trx=0x7f96b8f51168) at /data/src/10.6/storage/innobase/fts/fts0fts.cc:3028
|
#24 0x0000560f388744a8 in trx_t::commit_low (this=0x7f96b8f51168, mtr=0x7f96b8694d30) at /data/src/10.6/storage/innobase/trx/trx0trx.cc:1470
|
#25 0x0000560f38874621 in trx_t::commit (this=0x7f96b8f51168) at /data/src/10.6/storage/innobase/trx/trx0trx.cc:1522
|
#26 0x0000560f38874a26 in trx_commit_for_mysql (trx=0x7f96b8f51168) at /data/src/10.6/storage/innobase/trx/trx0trx.cc:1639
|
#27 0x0000560f38600c82 in innobase_commit_low (trx=0x7f96b8f51168) at /data/src/10.6/storage/innobase/handler/ha_innodb.cc:3888
|
#28 0x0000560f38600fbd in innobase_commit_ordered_2 (trx=0x7f96b8f51168, thd=0x7f9670000db8) at /data/src/10.6/storage/innobase/handler/ha_innodb.cc:3994
|
#29 0x0000560f38601535 in innobase_commit (hton=0x560f3af28bf8, thd=0x7f9670000db8, commit_trx=false) at /data/src/10.6/storage/innobase/handler/ha_innodb.cc:4098
|
#30 0x0000560f3818aed4 in commit_one_phase_2 (thd=0x7f9670000db8, all=false, trans=0x7f9670004578, is_real_trans=true) at /data/src/10.6/sql/handler.cc:1942
|
#31 0x0000560f3818adc3 in ha_commit_one_phase (thd=0x7f9670000db8, all=false) at /data/src/10.6/sql/handler.cc:1921
|
#32 0x0000560f38189eff in ha_commit_trans (thd=0x7f9670000db8, all=false) at /data/src/10.6/sql/handler.cc:1715
|
#33 0x0000560f37fdfd74 in trans_commit_stmt (thd=0x7f9670000db8) at /data/src/10.6/sql/transaction.cc:472
|
#34 0x0000560f37e24c0c in mysql_execute_command (thd=0x7f9670000db8) at /data/src/10.6/sql/sql_parse.cc:6033
|
#35 0x0000560f37e2a746 in mysql_parse (thd=0x7f9670000db8, rawbuf=0x7f9670013d40 "INSERT INTO t VALUES (@a),(@a)", length=30, parser_state=0x7f96b8696510) at /data/src/10.6/sql/sql_parse.cc:8004
|
#36 0x0000560f37e16b6c in dispatch_command (command=COM_QUERY, thd=0x7f9670000db8, packet=0x7f967000b359 "INSERT INTO t VALUES (@a),(@a)", packet_length=30, blocking=true) at /data/src/10.6/sql/sql_parse.cc:1888
|
#37 0x0000560f37e15513 in do_command (thd=0x7f9670000db8, blocking=true) at /data/src/10.6/sql/sql_parse.cc:1399
|
#38 0x0000560f37fc3e7a in do_handle_one_connection (connect=0x560f3b3f7648, put_in_cache=true) at /data/src/10.6/sql/sql_connect.cc:1410
|
#39 0x0000560f37fc3bd6 in handle_one_connection (arg=0x560f3b410e78) at /data/src/10.6/sql/sql_connect.cc:1312
|
#40 0x0000560f385241ff in pfs_spawn_thread (arg=0x560f3b3065d8) at /data/src/10.6/storage/perfschema/pfs.cc:2201
|
#41 0x00007f96c2a82609 in start_thread (arg=<optimized out>) at pthread_create.c:477
|
#42 0x00007f96c2656293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|
and
Thread 13 (Thread 0x7f96b8697700 (LWP 1895922)):
|
#0 0x0000560f38886988 in rbt_find_successor (tree=0x7f967119d8b8, current=0x7f967114f5d8) at /data/src/10.6/storage/innobase/ut/ut0rbt.cc:391
|
#1 0x0000560f38887d52 in rbt_next (tree=0x7f967119d8b8, current=0x7f967114f5d8) at /data/src/10.6/storage/innobase/ut/ut0rbt.cc:1083
|
#2 0x0000560f38886372 in rbt_check_ordering (tree=0x7f967119d8b8) at /data/src/10.6/storage/innobase/ut/ut0rbt.cc:70
|
#3 0x0000560f38887e87 in rbt_validate (tree=0x7f967119d8b8) at /data/src/10.6/storage/innobase/ut/ut0rbt.cc:1137
|
#4 0x0000560f38887861 in rbt_add_node (tree=0x7f967119d8b8, parent=0x7f96b86940d0, value=0x7f96b8694100) at /data/src/10.6/storage/innobase/ut/ut0rbt.cc:867
|
#5 0x0000560f389c279a in fts_add_token (result_doc=0x7f96b86944d0, str=..., position=763642) at /data/src/10.6/storage/innobase/fts/fts0fts.cc:4444
|
#6 0x0000560f389c2963 in fts_process_token (doc=0x7f96b86944d0, result=0x0, start_pos=763641, add_pos=0) at /data/src/10.6/storage/innobase/fts/fts0fts.cc:4490
|
#7 0x0000560f389c2ece in fts_tokenize_document (doc=0x7f96b86944d0, result=0x0, parser=0x0) at /data/src/10.6/storage/innobase/fts/fts0fts.cc:4675
|
#8 0x0000560f389bf4ec in fts_fetch_doc_from_rec (get_doc=0x7f967003d038, clust_index=0x7f9670024918, pcur=0x7f96b8694620, offsets=0x7f967002b268, doc=0x7f96b86944d0) at /data/src/10.6/storage/innobase/fts/fts0fts.cc:3217
|
#9 0x0000560f389c00d4 in fts_add_doc_by_id (ftt=0x7f967008f4e8, doc_id=2, fts_indexes=0x0) at /data/src/10.6/storage/innobase/fts/fts0fts.cc:3489
|
#10 0x0000560f389be6b7 in fts_add (ftt=0x7f967008f4e8, row=0x7f967001be28) at /data/src/10.6/storage/innobase/fts/fts0fts.cc:2807
|
#11 0x0000560f389bee37 in fts_commit_table (ftt=0x7f967008f4e8) at /data/src/10.6/storage/innobase/fts/fts0fts.cc:2979
|
#12 0x0000560f389bef2e in fts_commit (trx=0x7f96b8f51168) at /data/src/10.6/storage/innobase/fts/fts0fts.cc:3028
|
#13 0x0000560f388744a8 in trx_t::commit_low (this=0x7f96b8f51168, mtr=0x7f96b8694d30) at /data/src/10.6/storage/innobase/trx/trx0trx.cc:1470
|
#14 0x0000560f38874621 in trx_t::commit (this=0x7f96b8f51168) at /data/src/10.6/storage/innobase/trx/trx0trx.cc:1522
|
#15 0x0000560f38874a26 in trx_commit_for_mysql (trx=0x7f96b8f51168) at /data/src/10.6/storage/innobase/trx/trx0trx.cc:1639
|
#16 0x0000560f38600c82 in innobase_commit_low (trx=0x7f96b8f51168) at /data/src/10.6/storage/innobase/handler/ha_innodb.cc:3888
|
#17 0x0000560f38600fbd in innobase_commit_ordered_2 (trx=0x7f96b8f51168, thd=0x7f9670000db8) at /data/src/10.6/storage/innobase/handler/ha_innodb.cc:3994
|
#18 0x0000560f38601535 in innobase_commit (hton=0x560f3af28bf8, thd=0x7f9670000db8, commit_trx=false) at /data/src/10.6/storage/innobase/handler/ha_innodb.cc:4098
|
#19 0x0000560f3818aed4 in commit_one_phase_2 (thd=0x7f9670000db8, all=false, trans=0x7f9670004578, is_real_trans=true) at /data/src/10.6/sql/handler.cc:1942
|
#20 0x0000560f3818adc3 in ha_commit_one_phase (thd=0x7f9670000db8, all=false) at /data/src/10.6/sql/handler.cc:1921
|
#21 0x0000560f38189eff in ha_commit_trans (thd=0x7f9670000db8, all=false) at /data/src/10.6/sql/handler.cc:1715
|
#22 0x0000560f37fdfd74 in trans_commit_stmt (thd=0x7f9670000db8) at /data/src/10.6/sql/transaction.cc:472
|
#23 0x0000560f37e24c0c in mysql_execute_command (thd=0x7f9670000db8) at /data/src/10.6/sql/sql_parse.cc:6033
|
#24 0x0000560f37e2a746 in mysql_parse (thd=0x7f9670000db8, rawbuf=0x7f9670013d40 "INSERT INTO t VALUES (@a),(@a)", length=30, parser_state=0x7f96b8696510) at /data/src/10.6/sql/sql_parse.cc:8004
|
#25 0x0000560f37e16b6c in dispatch_command (command=COM_QUERY, thd=0x7f9670000db8, packet=0x7f967000b359 "INSERT INTO t VALUES (@a),(@a)", packet_length=30, blocking=true) at /data/src/10.6/sql/sql_parse.cc:1888
|
#26 0x0000560f37e15513 in do_command (thd=0x7f9670000db8, blocking=true) at /data/src/10.6/sql/sql_parse.cc:1399
|
#27 0x0000560f37fc3e7a in do_handle_one_connection (connect=0x560f3b3f7648, put_in_cache=true) at /data/src/10.6/sql/sql_connect.cc:1410
|
#28 0x0000560f37fc3bd6 in handle_one_connection (arg=0x560f3b410e78) at /data/src/10.6/sql/sql_connect.cc:1312
|
#29 0x0000560f385241ff in pfs_spawn_thread (arg=0x560f3b3065d8) at /data/src/10.6/storage/perfschema/pfs.cc:2201
|
#30 0x00007f96c2a82609 in start_thread (arg=<optimized out>) at pthread_create.c:477
|
#31 0x00007f96c2656293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
|