[MDEV-30528] Assertion `!mbmaxlen || !(prefix_len % mbmaxlen)' failed in dtype_get_at_most_n_mbchars Created: 2023-01-31  Updated: 2024-02-01

Status: Stalled
Project: MariaDB Server
Component/s: Storage Engine - InnoDB, Versioned Tables
Affects Version/s: 10.3, 10.4, 10.5, 10.6, 10.7, 10.8, 10.9, 10.10
Fix Version/s: 10.4, 10.5, 10.6, 10.11, 11.0, 11.1, 11.2

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Marko Mäkelä
Resolution: Unresolved Votes: 0
Labels: fulltext, regression

Attachments: File breaks.gdb    
Issue Links:
Problem/Incident
is caused by MDEV-25004 Missing row in FTS_DOC_ID_INDEX durin... Closed
Relates
relates to MDEV-23644 Assertion on evaluating foreign refer... Closed

 Description    

--source include/have_innodb.inc
 
 
 
CREATE TABLE t (f TEXT) WITH SYSTEM VERSIONING CHARACTER SET utf8 ENGINE=InnoDB;
 
INSERT INTO t VALUES ('foo');
 
DELETE FROM t;
 
ALTER TABLE t ADD FULLTEXT (f);
 
 
 
# Cleanup
 
DROP TABLE t;

10.3 7a98d232

 
/src/storage/innobase/data/data0type.cc:63: ulint dtype_get_at_most_n_mbchars(ulint, ulint, ulint, ulint, ulint, const char*): Assertion `!mbmaxlen || !(prefix_len % mbmaxlen)' failed
 
 
 
#7  0x00007f3e7237b662 in __GI___assert_fail (assertion=0x564011d04300 "!mbmaxlen || !(prefix_len % mbmaxlen)", file=0x564011d04240 "/src/storage/innobase/data/data0type.cc", line=63, function=0x564011d04360 "ulint dtype_get_at_most_n_mbchars(ulint, ulint, ulint, ulint, ulint, const char*)") at assert.c:101
 
#8  0x0000564010d00461 in dtype_get_at_most_n_mbchars (prtype=2212092, mbminlen=1, mbmaxlen=3, prefix_len=1, data_len=3, str=0x7f3e683ec092 "fooc\331T{\bwUc\331T{\b}\277") at /src/storage/innobase/data/data0type.cc:63
 
#9  0x000056401099bdda in row_merge_buf_add (buf=0x615000044d08, fts_index=0x618000049d08, old_table=0x6190000d4e08, new_table=0x6190000d9408, psort_info=0x6190000e5b80, row=0x63100008c8b8, ext=0x0, history_fts=true, doc_id=0x7f3e5bb42b10, conv_heap=0x0, err=0x7f3e5bb42ab0, v_heap=0x7f3e5bb42af0, my_table=0x61f000043688, trx=0x7f3e687898b8) at /src/storage/innobase/row/row0merge.cc:725
 
#10 0x00005640109a8515 in row_merge_read_clustered_index (trx=0x7f3e687898b8, table=0x61f000043688, old_table=0x6190000d4e08, new_table=0x6190000d9408, online=false, index=0x6190000d91b0, fts_sort_idx=0x618000055908, psort_info=0x6190000e5b80, files=0x60800000c2a0, key_numbers=0x6190000d91d0, n_index=3, defaults=0x0, add_v=0x0, col_map=0x61d0001f9108, add_autoinc=18446744073709551615, sequence=..., block=0x7f3e5b5e5000 "", skip_pk_sort=true, tmpfd=0x7f3e5bb43920, stage=0x60700001cd40, pct_cost=25, crypt_block=0x0, eval_table=0x61f000043688, allow_not_null=false) at /src/storage/innobase/row/row0merge.cc:2329
 
#11 0x00005640109b854d in row_merge_build_indexes (trx=0x7f3e687898b8, old_table=0x6190000d4e08, new_table=0x6190000d9408, online=false, indexes=0x6190000d91b0, key_numbers=0x6190000d91d0, n_indexes=3, table=0x61f000043688, defaults=0x0, col_map=0x61d0001f9108, add_autoinc=18446744073709551615, sequence=..., skip_pk_sort=true, stage=0x60700001cd40, add_v=0x0, eval_table=0x61f000043688, allow_not_null=false) at /src/storage/innobase/row/row0merge.cc:4707
 
#12 0x000056401074d9bf in ha_innobase::inplace_alter_table (this=0x61c0000610a8, altered_table=0x61f000043688, ha_alter_info=0x7f3e5bb44df0) at /src/storage/innobase/handler/handler0alter.cc:7241
 
#13 0x000056400fc34e82 in handler::ha_inplace_alter_table (this=0x61c0000610a8, altered_table=0x61f000043688, ha_alter_info=0x7f3e5bb44df0) at /src/sql/handler.h:4153
 
#14 0x000056400fc17c08 in mysql_inplace_alter_table (thd=0x62a0000ba208, table_list=0x62b000000338, table=0x61f000042888, altered_table=0x61f000043688, ha_alter_info=0x7f3e5bb44df0, target_mdl_request=0x7f3e5bb44fd0, alter_ctx=0x7f3e5bb45830) at /src/sql/sql_table.cc:7778
 
#15 0x000056400fc29141 in mysql_alter_table (thd=0x62a0000ba208, new_db=0x62a0000be918, new_name=0x62a0000bed00, create_info=0x7f3e5bb46550, table_list=0x62b000000338, alter_info=0x7f3e5bb46450, order_num=0, order=0x0, ignore=false) at /src/sql/sql_table.cc:10166
 
#16 0x000056400fd9287c in Sql_cmd_alter_table::execute (this=0x62b000000ac8, thd=0x62a0000ba208) at /src/sql/sql_alter.cc:512
 
#17 0x000056400f9de0bf in mysql_execute_command (thd=0x62a0000ba208) at /src/sql/sql_parse.cc:6076
 
#18 0x000056400f9e9ef0 in mysql_parse (thd=0x62a0000ba208, rawbuf=0x62b000000228 "ALTER TABLE t ADD FULLTEXT (f)", length=30, parser_state=0x7f3e5bb48950, is_com_multi=false, is_next_command=false) at /src/sql/sql_parse.cc:7855
 
#19 0x000056400f9c1580 in dispatch_command (command=COM_QUERY, thd=0x62a0000ba208, packet=0x629000136209 "ALTER TABLE t ADD FULLTEXT (f)", packet_length=30, is_com_multi=false, is_next_command=false) at /src/sql/sql_parse.cc:1852
 
#20 0x000056400f9be138 in do_command (thd=0x62a0000ba208) at /src/sql/sql_parse.cc:1398
 
#21 0x000056400fd82166 in do_handle_one_connection (connect=0x608000000ea8) at /src/sql/sql_connect.cc:1404
 
#22 0x000056400fd81a62 in handle_one_connection (arg=0x608000000ea8) at /src/sql/sql_connect.cc:1309
 
#23 0x0000564011333775 in pfs_spawn_thread (arg=0x615000007608) at /src/storage/perfschema/pfs.cc:1869
 
#24 0x00007f3e72526ea7 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#25 0x00007f3e72446aef in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

The failure started happening on 10.3 after this commit:

commit e056efdd6cfa62cc4c978fce5730af0b8d4c3c6b
 
Author: Aleksey Midenkov
 
Date:   Tue Dec 27 00:02:02 2022 +0300
 
 
 
    MDEV-25004 Missing row in FTS_DOC_ID_INDEX during DELETE HISTORY

On higher versions the assertion is a bit different. The test case is the same.

10.11

 
ulint dtype_get_at_most_n_mbchars(ulint, ulint, ulint, ulint, ulint, const char*): Assertion `!mbmaxlen || !(prefix_len % mbmaxlen) || !(prefix_len % 4)' failed

Non-debug builds also fail, with a non-debug version of the assertion

10.3 f812f8e1

 
2023-01-31 20:16:07 0x7f91e3287700  InnoDB: Assertion failure in file /data/src/10.3/storage/innobase/data/data0type.cc line 66
 
InnoDB: Failing assertion: !(prefix_len % mbmaxlen)



 Comments   
Comment by Aleksey Midenkov [ 2023-07-10 ]

Please review bb-10.4-midenok

Comment by Aleksey Midenkov [ 2023-07-20 ]

10.4.31 10.5.22 10.6.15 10.9.8 10.10.6 10.11.5 11.0.3 11.1.2 11.2.1

Comment by Marko Mäkelä [ 2023-07-31 ]

This had been pushed without my review. I am wondering why the scope of one variable was widened, potentially allowing a result from an earlier loop iteration to be reused. I tried narrowing as follows:

diff --git a/storage/innobase/row/row0merge.cc b/storage/innobase/row/row0merge.cc
 
index e78f05fcc53..5a6a145498f 100644
 
--- a/storage/innobase/row/row0merge.cc
 
+++ b/storage/innobase/row/row0merge.cc
 
@@ -1874,7 +1874,6 @@ row_merge_read_clustered_index(
 
 	mach_write_to_8(new_sys_trx_start, trx->id);
 
 	mach_write_to_8(new_sys_trx_end, TRX_ID_MAX);
 
 	uint64_t	n_rows = 0;
 
-	bool history_row = false;
 
 
 	/* Scan the clustered index. */
 
 	for (;;) {
 
@@ -1891,7 +1890,7 @@ row_merge_read_clustered_index(
 
 		dtuple_t*	row;
 
 		row_ext_t*	ext;
 
 		page_cur_t*	cur	= btr_pcur_get_page_cur(&pcur);
 
-		bool history_fts = false;
 
+		bool history_row = false, history_fts = false;
 
 
 		page_cur_move_to_next(cur);

Then, the test would fail like this:

10.5 055f2e308bf1dd4026df65093a1166526ac35d9b with the above patch

 
CURRENT_TEST: innodb_fts.innodb_fts_misc
 
mysqltest: At line 1357: query 'alter table t add fulltext (f)' failed: 1062: Duplicate entry '' for key '*UNKNOWN*'

It is failing on the hidden index on a hidden column FTS_DOC_ID_INDEX(FTS_DOC_ID). At the time of the report, that index page in the buffer pool is empty. The duplicate was reported during merge sorting: row_merge_tuple_cmp() invoked row_merge_dup_report(). In the ./mtr --rr trace that I debugged, the last (FTS_DOC_ID,row_end,DB_ROW_ID) tuples that were being compared were a=(0,0x64c78f980c42f2,0x313) and b=(0,0x64c78f980c42f2,0x317). The first comparison was between similar tuples, but the DB_ROW_ID were 0x317 and 0x318.
The first two fields are supposed to be unique. The FTS_DOC_ID=0 makes sense to me, but the row_end values need to be explained in detail. At the time of detecting the duplicate key, the clustered index contains the following (DB_ROW_ID,f) values:
(0x313,'mysql from tutorial dbms stands for database ...'),
(0x314,'when to use mysql well after that you went through a ...'),
(0x315,'where will optimizing mysql in what tutorial we will show ...'),
(0x316,'1001 mysql tricks 1. never run mysqld as root. 2. ...'),
(0x317,'mysql vs. yoursql in the following database comparison ...'),
(0x318,'mysql security when configured properly, mysql ...')

As you can see, the problematic DB_ROW_ID values 0x313, 0x317, 0x318 correspond to the statement

delete from t where f like 'mysql%';

I think that this scenario needs to be fully understood and described and until then, the fix needs to be reverted.

Comment by Marko Mäkelä [ 2023-07-31 ]

My common sense tells me that it should not matter at which point between the creation of the table and the last DML statement any (non-unique) secondary indexes were created.

With the current patch, it appears that the contents of the internal index on FTS_DOC_ID depends on the order in which the following statements were executed:

delete from t where f like 'mysql%';
 
alter table t add fulltext (f);

Whether that is an actual problem, I do not know. It could be if fulltext search can be combined with system versioning during queries.

Comment by Aleksey Midenkov [ 2023-07-31 ]

FTS_DOC_ID_INDEX must skip duplicates for history rows (DOC_ID == 0). But the problem is row_merge_buf_add() cannot do that. So we can skip such duplicates for history rows in row_merge_buf_sort().

Please confirm the following changes:

1. Refactor UT_SORT_FUNCTION_BODY as timeplate function mergesort();
2. When row_merge_tuple_cmp() sees history row (row_end < row_end_max) instead of reporting it tells mergesort() to not add this tuple to merge buffer.
3. mergesort() algorithm upgraded to support duplicate skipping.

Comment by Marko Mäkelä [ 2023-08-16 ]

Please, show the internal contents of the table in the case that the FULLTEXT INDEX is created before the INSERT and DELETE statements are executed on this table. This should include the contents of the hidden FTS_DOC_ID column as well as the hidden system versioned columns.

I think that the contents of a table must be equivalent, no matter at which point of time the fulltext index is created. Note: I say equivalent, not equal. Some discrepancy with respect to the FTS_DOC_ID column may be allowed, provided that CHECK TABLE does not report any inconsistency.

Comment by Elena Stepanova [ 2023-09-05 ]

More debug and non-debug effects on test variations of the same category. I don't see much point in filing them separately if nobody wants to fix these anyway; but I need them to be findable in JIRA.

--source include/have_innodb.inc
 
 
 
CREATE TABLE t (a CHAR(8) NOT NULL DEFAULT '', b VARCHAR(8), c INT, d INT, e CHAR(16), f TIMESTAMP, vf TIMESTAMP AS (f), vb VARCHAR(8) AS (b), KEY(d), FULLTEXT(e)) ENGINE=InnoDB WITH SYSTEM VERSIONING;
 
INSERT INTO t (c) VALUES (1);
 
SET STATEMENT SYSTEM_VERSIONING_ALTER_HISTORY=KEEP FOR ALTER TABLE t ADD UNIQUE(a);
 
UPDATE t SET d = 2;
 
 
 
# Cleanup
 
DROP TABLE t;

10.4 900c4d69

 
mysqld: /data/src/10.4/storage/innobase/trx/trx0rec.cc:1284: ulint trx_undo_page_report_modify(buf_block_t*, trx_t*, dict_index_t*, const rec_t*, const rec_offs*, const upd_t*, ulint, const dtuple_t*, mtr_t*): Assertion `pos != ((ulint)(-1))' failed.
 
230906  1:10:09 [ERROR] mysqld got signal 6 ;
 
 
 
#9  0x00007fe895853df2 in __GI___assert_fail (assertion=0x55a61b855860 "pos != ((ulint)(-1))", file=0x55a61b854340 "/data/src/10.4/storage/innobase/trx/trx0rec.cc", line=1284, function=0x55a61b854fa0 "ulint trx_undo_page_report_modify(buf_block_t*, trx_t*, dict_index_t*, const rec_t*, const rec_offs*, const upd_t*, ulint, const dtuple_t*, mtr_t*)") at ./assert/assert.c:101
 
#10 0x000055a61a663627 in trx_undo_page_report_modify (undo_block=0x7fe88d02c070, trx=0x7fe88d859908, index=0x61700004a008, rec=0x7fe88d5e807e "        \177\377\377\377\017B?", offsets=0x619000104770, update=0x622000035468, cmpl_info=0, row=0x0, mtr=0x7fe880c82bf0) at /data/src/10.4/storage/innobase/trx/trx0rec.cc:1284
 
#11 0x000055a61a668181 in trx_undo_report_row_operation (thr=0x622000035808, index=0x61700004a008, clust_entry=0x0, update=0x622000035468, cmpl_info=0, rec=0x7fe88d5e807e "        \177\377\377\377\017B?", offsets=0x619000104770, roll_ptr=0x7fe880c83300) at /data/src/10.4/storage/innobase/trx/trx0rec.cc:1955
 
#12 0x000055a61a724c9d in btr_cur_upd_lock_and_undo (flags=10, cursor=0x6110000d5ec0, offsets=0x619000104770, update=0x622000035468, cmpl_info=0, thr=0x622000035808, mtr=0x7fe880c83860, roll_ptr=0x7fe880c83300) at /data/src/10.4/storage/innobase/btr/btr0cur.cc:3936
 
#13 0x000055a61a72d9b4 in btr_cur_pessimistic_update (flags=10, cursor=0x6110000d5ec0, offsets=0x7fe880c83480, offsets_heap=0x7fe880c83560, entry_heap=0x619000104a80, big_rec=0x7fe880c83460, update=0x622000035468, cmpl_info=0, thr=0x622000035808, trx_id=88, mtr=0x7fe880c83860) at /data/src/10.4/storage/innobase/btr/btr0cur.cc:5089
 
#14 0x000055a61a5bb5aa in row_upd_clust_rec (flags=0, node=0x622000035338, index=0x61700004a008, offsets=0x619000104770, offsets_heap=0x7fe880c83560, thr=0x622000035808, mtr=0x7fe880c83860) at /data/src/10.4/storage/innobase/row/row0upd.cc:2966
 
#15 0x000055a61a5bd0f5 in row_upd_clust_step (node=0x622000035338, thr=0x622000035808) at /data/src/10.4/storage/innobase/row/row0upd.cc:3269
 
#16 0x000055a61a5bd92d in row_upd (node=0x622000035338, thr=0x622000035808) at /data/src/10.4/storage/innobase/row/row0upd.cc:3332
 
#17 0x000055a61a5be903 in row_upd_step (thr=0x622000035808) at /data/src/10.4/storage/innobase/row/row0upd.cc:3476
 
#18 0x000055a61a4fddf3 in row_update_for_mysql (prebuilt=0x622000034988) at /data/src/10.4/storage/innobase/row/row0mysql.cc:1802
 
#19 0x000055a61a18d301 in ha_innobase::update_row (this=0x61d0002738a8, old_row=0x619000102308 "\355        ", new_row=0x6190001022b8 "\351        ") at /data/src/10.4/storage/innobase/handler/ha_innodb.cc:8952
 
#20 0x000055a6197f73b7 in handler::ha_update_row (this=0x61d0002738a8, old_data=0x619000102308 "\355        ", new_data=0x6190001022b8 "\351        ") at /data/src/10.4/sql/handler.cc:6905
 
#21 0x000055a6192f40b3 in mysql_update (thd=0x62b00009a208, table_list=0x62b0000a1328, fields=..., values=..., conds=0x62b0000a21d0, order_num=0, order=0x0, limit=18446744073709551615, ignore=false, found_return=0x7fe880c84e80, updated_return=0x7fe880c84ea0) at /data/src/10.4/sql/sql_update.cc:1087
 
#22 0x000055a619025ab4 in mysql_execute_command (thd=0x62b00009a208) at /data/src/10.4/sql/sql_parse.cc:4449
 
#23 0x000055a61903ea77 in mysql_parse (thd=0x62b00009a208, rawbuf=0x62b0000a1228 "UPDATE t SET d = 2", length=18, parser_state=0x7fe880c86860, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:8010
 
#24 0x000055a619014d42 in dispatch_command (command=COM_QUERY, thd=0x62b00009a208, packet=0x62900029e209 "UPDATE t SET d = 2", packet_length=18, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1857
 
#25 0x000055a6190118b1 in do_command (thd=0x62b00009a208) at /data/src/10.4/sql/sql_parse.cc:1378
 
#26 0x000055a619410e10 in do_handle_one_connection (connect=0x608000000ba8) at /data/src/10.4/sql/sql_connect.cc:1420
 
#27 0x000055a619410727 in handle_one_connection (arg=0x608000000ba8) at /data/src/10.4/sql/sql_connect.cc:1324
 
#28 0x000055a61a080e20 in pfs_spawn_thread (arg=0x615000006208) at /data/src/10.4/storage/perfschema/pfs.cc:1869
 
#29 0x00007fe8958a7fd4 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
 
#30 0x00007fe8959285bc in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81


--source include/have_innodb.inc
 
 
 
CREATE TABLE t (a SET('','a','b') NOT NULL DEFAULT '', b VARCHAR(8), c INT, d INT, e CHAR(16), vb VARCHAR(8) AS (b), KEY(d), FULLTEXT(e)) ENGINE=InnoDB WITH SYSTEM VERSIONING;
 
INSERT INTO t (c) VALUES (1);
 
SET STATEMENT SYSTEM_VERSIONING_ALTER_HISTORY=KEEP FOR ALTER TABLE t ADD UNIQUE(a);
 
UPDATE t SET d = 2;
 
 
 
# Cleanup
 
DROP TABLE t;


mysqltest: At line 5: query 'SET STATEMENT SYSTEM_VERSIONING_ALTER_HISTORY=KEEP FOR ALTER TABLE t ADD UNIQUE(a)' failed: 1034: Index for table 't' is corrupt; try to repair it


2023-09-06  1:11:22 9 [ERROR] InnoDB: No matching column for `FTS_DOC_ID` in index `FTS_DOC_ID_INDEX` of table `test`.`#sql-ea780_9`


--source include/have_innodb.inc
 
 
 
CREATE TABLE t (a CHAR(8), b VARCHAR(8), c INT AUTO_INCREMENT, d TIMESTAMP, e CHAR(16), vd TIMESTAMP AS (d), vb VARCHAR(8) AS (b), UNIQUE(c), FULLTEXT(e)) ENGINE=InnoDB WITH SYSTEM VERSIONING;
 
INSERT INTO t (a) VALUES ('');
 
SET STATEMENT SYSTEM_VERSIONING_ALTER_HISTORY=KEEP FOR ALTER TABLE t ADD PRIMARY KEY(a);
 
 
 
# Cleanup
 
DROP TABLE t;

10.4 900c4d69 non-debug

 
#2  <signal handler called>
 
#3  __memcpy_avx_unaligned () at ../sysdeps/x86_64/multiarch/memmove-vec-unaligned-erms.S:228
 
#4  0x0000560b80f7a595 in memcpy (__len=4294967295, __src=<optimized out>, __dest=<optimized out>) at /usr/include/x86_64-linux-gnu/bits/string_fortified.h:29
 
#5  rec_convert_dtuple_to_rec_comp<> (temp=false, status=<optimized out>, n_fields=<optimized out>, field=<optimized out>, index=<optimized out>, rec=<optimized out>) at /data/src/10.4/storage/innobase/rem/rem0rec.cc:1696
 
#6  rec_convert_dtuple_to_rec_new (dtuple=0x7fd9201861b7, index=0x2, buf=0x7fd9201861bd "") at /data/src/10.4/storage/innobase/rem/rem0rec.cc:1742
 
#7  rec_convert_dtuple_to_rec (buf=<optimized out>, index=index@entry=0x7fd92005e938, dtuple=dtuple@entry=0x7fd91428d4a8, n_ext=<optimized out>) at /data/src/10.4/storage/innobase/rem/rem0rec.cc:1774
 
#8  0x0000560b8101cf36 in BtrBulk::insert (this=this@entry=0x7fd966a61080, tuple=tuple@entry=0x7fd91428d4a8, level=level@entry=0) at /data/src/10.4/storage/innobase/include/mem0mem.inl:207
 
#9  0x0000560b80f95721 in BtrBulk::insert (tuple=0x7fd91428d4a8, this=0x7fd966a61080) at /data/src/10.4/storage/innobase/include/btr0bulk.h:313
 
#10 row_merge_insert_index_tuples (index=<optimized out>, old_table=old_table@entry=0x7fd920082218, fd=..., block=block@entry=0x0, row_buf=row_buf@entry=0x7fd923e6f928, btr_bulk=btr_bulk@entry=0x7fd966a61080, table_total_rows=<optimized out>, pct_progress=pct_progress@entry=0, pct_cost=pct_cost@entry=20, crypt_block=<optimized out>, space=<optimized out>, stage=<optimized out>) at /data/src/10.4/storage/innobase/row/row0merge.cc:3646
 
#11 0x0000560b80f9c3ae in row_merge_read_clustered_index (trx=trx@entry=0x7fd9673ff090, table=table@entry=0x7fd966a62670, old_table=<optimized out>, new_table=<optimized out>, online=online@entry=false, index=index@entry=0x7fd92005bbf8, fts_sort_idx=<optimized out>, psort_info=<optimized out>, files=<optimized out>, key_numbers=<optimized out>, n_index=<optimized out>, defaults=<optimized out>, add_v=<optimized out>, col_map=<optimized out>, add_autoinc=<optimized out>, sequence=..., block=<optimized out>, skip_pk_sort=<optimized out>, tmpfd=<optimized out>, stage=<optimized out>, pct_cost=<optimized out>, crypt_block=<optimized out>, eval_table=<optimized out>, allow_not_null=<optimized out>) at /data/src/10.4/storage/innobase/row/row0merge.cc:2596
 
#12 0x0000560b80f9d08e in row_merge_build_indexes (trx=<optimized out>, old_table=<optimized out>, new_table=<optimized out>, online=<optimized out>, indexes=0x7fd92005bbf8, key_numbers=<optimized out>, n_indexes=<optimized out>, table=<optimized out>, defaults=<optimized out>, col_map=<optimized out>, add_autoinc=<optimized out>, sequence=..., skip_pk_sort=<optimized out>, stage=<optimized out>, add_v=<optimized out>, eval_table=<optimized out>, allow_not_null=<optimized out>) at /data/src/10.4/storage/innobase/row/row0merge.cc:4697
 
#13 0x0000560b80efc326 in ha_innobase::inplace_alter_table (this=0x7fd9201282e0, altered_table=<optimized out>, ha_alter_info=0x7fd966a625d0) at /data/src/10.4/storage/innobase/handler/handler0alter.cc:8735
 
#14 0x0000560b80a8de3c in handler::ha_inplace_alter_table (ha_alter_info=0x7fd966a625d0, altered_table=0x7fd966a62670, this=<optimized out>) at /data/src/10.4/sql/handler.h:4355
 
#15 mysql_inplace_alter_table (thd=thd@entry=0x7fd920000c58, table_list=0x7fd920010490, table=table@entry=0x7fd9200bc998, altered_table=altered_table@entry=0x7fd966a62670, ha_alter_info=ha_alter_info@entry=0x7fd966a625d0, alter_ctx=alter_ctx@entry=0x7fd966a63ea0, target_mdl_request=0x7fd966a63460) at /data/src/10.4/sql/sql_table.cc:7918
 
#16 0x0000560b80a9a790 in mysql_alter_table (thd=thd@entry=0x7fd920000c58, new_db=new_db@entry=0x7fd9200052a0, new_name=new_name@entry=0x7fd9200056f8, create_info=create_info@entry=0x7fd966a64a90, table_list=<optimized out>, table_list@entry=0x7fd920010490, recreate_info=recreate_info@entry=0x7fd966a649b0, alter_info=<optimized out>, order_num=<optimized out>, order=<optimized out>, ignore=<optimized out>) at /data/src/10.4/sql/sql_table.cc:10446
 
#17 0x0000560b80af5159 in Sql_cmd_alter_table::execute (this=<optimized out>, thd=0x7fd920000c58) at /data/src/10.4/sql/sql_alter.cc:531
 
#18 0x0000560b809ec8f0 in mysql_execute_command (thd=thd@entry=0x7fd920000c58) at /data/src/10.4/sql/sql_parse.cc:6216
 
#19 0x0000560b809f2b31 in mysql_parse (thd=0x7fd920000c58, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /data/src/10.4/sql/sql_parse.cc:8010
 
#20 0x0000560b809f51ad in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7fd920000c58, packet=packet@entry=0x7fd920007d69 "SET STATEMENT SYSTEM_VERSIONING_ALTER_HISTORY=KEEP FOR ALTER TABLE t ADD PRIMARY KEY(a)", packet_length=packet_length@entry=87, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /data/src/10.4/sql/sql_parse.cc:1958
 
#21 0x0000560b809f752f in do_command (thd=0x7fd920000c58) at /data/src/10.4/sql/sql_parse.cc:1378
 
#22 0x0000560b80af0dbe in do_handle_one_connection (connect=connect@entry=0x560b839323c8) at /data/src/10.4/sql/sql_connect.cc:1420
 
#23 0x0000560b80af0edd in handle_one_connection (arg=arg@entry=0x560b839323c8) at /data/src/10.4/sql/sql_connect.cc:1324
 
#24 0x0000560b80e83ffb in pfs_spawn_thread (arg=0x560b83652288) at /data/src/10.4/storage/perfschema/pfs.cc:1869
 
#25 0x00007fd9718a7fd4 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
 
#26 0x00007fd9719285bc in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

10.4 900c4d69 debug

 
mysqld: /data/src/10.4/storage/innobase/row/row0merge.cc:691: ulint row_merge_buf_add(row_merge_buf_t*, dict_index_t*, const dict_table_t*, const dict_table_t*, fts_psort_t*, dtuple_t*, const row_ext_t*, bool, doc_id_t*, mem_heap_t*, dberr_t*, mem_heap_t**, TABLE*, trx_t*): Assertion `!(col->prtype & 256U)' failed.
 
230906  1:05:43 [ERROR] mysqld got signal 6 ;
 
 
 
#9  0x00007f5a8c453df2 in __GI___assert_fail (assertion=0x5577938f0f80 "!(col->prtype & 256U)", file=0x5577938f0420 "/data/src/10.4/storage/innobase/row/row0merge.cc", line=691, function=0x5577938f0e20 "ulint row_merge_buf_add(row_merge_buf_t*, dict_index_t*, const dict_table_t*, const dict_table_t*, fts_psort_t*, dtuple_t*, const row_ext_t*, bool, doc_id_t*, mem_heap_t*, dberr_t*, mem_heap_t**, TABL"...) at ./assert/assert.c:101
 
#10 0x00005577926199be in row_merge_buf_add (buf=0x615000045208, fts_index=0x61700004a008, old_table=0x618000033508, new_table=0x61800003d108, psort_info=0x6190000f2880, row=0x6310000b48c0, ext=0x0, history_fts=false, doc_id=0x7f5a777a6090, conv_heap=0x0, err=0x7f5a777a6030, v_heap=0x7f5a777a6070, my_table=0x7f5a777aa150, trx=0x7f5a843aa908) at /data/src/10.4/storage/innobase/row/row0merge.cc:691
 
#11 0x0000557792626813 in row_merge_read_clustered_index (trx=0x7f5a843aa908, table=0x7f5a777aa150, old_table=0x618000033508, new_table=0x61800003d108, online=false, index=0x6190000e9690, fts_sort_idx=0x61700004f408, psort_info=0x6190000f2880, files=0x60c000030b80, key_numbers=0x6190000e96b8, n_index=4, defaults=0x61d00026ea70, add_v=0x0, col_map=0x61d00026ebe8, add_autoinc=18446744073709551615, sequence=..., block=0x7f5a77228000 "", skip_pk_sort=false, tmpfd=0x7f5a777a6e80, stage=0x60700001e5c0, pct_cost=20, crypt_block=0x0, eval_table=0x7f5a777aa150, allow_not_null=false) at /data/src/10.4/storage/innobase/row/row0merge.cc:2323
 
#12 0x0000557792636278 in row_merge_build_indexes (trx=0x7f5a843aa908, old_table=0x618000033508, new_table=0x61800003d108, online=false, indexes=0x6190000e9690, key_numbers=0x6190000e96b8, n_indexes=4, table=0x7f5a777aa150, defaults=0x61d00026ea70, col_map=0x61d00026ebe8, add_autoinc=18446744073709551615, sequence=..., skip_pk_sort=false, stage=0x60700001e5c0, add_v=0x0, eval_table=0x7f5a777aa150, allow_not_null=false) at /data/src/10.4/storage/innobase/row/row0merge.cc:4697
 
#13 0x000055779238d10f in ha_innobase::inplace_alter_table (this=0x61d00024b8a8, altered_table=0x7f5a777aa150, ha_alter_info=0x7f5a777a83e0) at /data/src/10.4/storage/innobase/handler/handler0alter.cc:8735
 
#14 0x0000557791404266 in handler::ha_inplace_alter_table (this=0x61d00024b8a8, altered_table=0x7f5a777aa150, ha_alter_info=0x7f5a777a83e0) at /data/src/10.4/sql/handler.h:4355
 
#15 0x00005577913e5844 in mysql_inplace_alter_table (thd=0x62b00009a208, table_list=0x62b0000a1618, table=0x62000003d088, altered_table=0x7f5a777aa150, ha_alter_info=0x7f5a777a83e0, target_mdl_request=0x7f5a777a8600, alter_ctx=0x7f5a777a9660) at /data/src/10.4/sql/sql_table.cc:7918
 
#16 0x00005577913f7ffd in mysql_alter_table (thd=0x62b00009a208, new_db=0x62b00009ea10, new_name=0x62b00009ee68, create_info=0x7f5a777ab250, table_list=0x62b0000a1618, recreate_info=0x7f5a777ab0b0, alter_info=0x7f5a777ab150, order_num=0, order=0x0, ignore=false) at /data/src/10.4/sql/sql_table.cc:10446
 
#17 0x000055779157ea84 in Sql_cmd_alter_table::execute (this=0x62b0000a1e10, thd=0x62b00009a208) at /data/src/10.4/sql/sql_alter.cc:531
 
#18 0x00005577911881fd in mysql_execute_command (thd=0x62b00009a208) at /data/src/10.4/sql/sql_parse.cc:6216
 
#19 0x0000557791193a77 in mysql_parse (thd=0x62b00009a208, rawbuf=0x62b0000a1228 "SET STATEMENT SYSTEM_VERSIONING_ALTER_HISTORY=KEEP FOR ALTER TABLE t ADD PRIMARY KEY(a)", length=87, parser_state=0x7f5a777ad860, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:8010
 
#20 0x0000557791169d42 in dispatch_command (command=COM_QUERY, thd=0x62b00009a208, packet=0x62900029e209 "SET STATEMENT SYSTEM_VERSIONING_ALTER_HISTORY=KEEP FOR ALTER TABLE t ADD PRIMARY KEY(a)", packet_length=87, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1857
 
#21 0x00005577911668b1 in do_command (thd=0x62b00009a208) at /data/src/10.4/sql/sql_parse.cc:1378
 
#22 0x0000557791565e10 in do_handle_one_connection (connect=0x608000000ba8) at /data/src/10.4/sql/sql_connect.cc:1420
 
#23 0x0000557791565727 in handle_one_connection (arg=0x608000000ba8) at /data/src/10.4/sql/sql_connect.cc:1324
 
#24 0x00005577921d5e20 in pfs_spawn_thread (arg=0x615000006208) at /data/src/10.4/storage/perfschema/pfs.cc:1869
 
#25 0x00007f5a8c4a7fd4 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
 
#26 0x00007f5a8c5285bc in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

Comment by Marko Mäkelä [ 2023-09-06 ]

midenok, here is a partial answer to my question that you asked me to answer. After executing the following test and letting the server shut down:

--source include/have_innodb.inc
 
CREATE TABLE tf (f TEXT, FULLTEXT(f)) WITH SYSTEM VERSIONING CHARACTER SET utf8 ENGINE=InnoDB;
 
INSERT INTO tf VALUES ('foo');
 
DELETE FROM tf;
 
 
 
CREATE TABLE t (f TEXT) WITH SYSTEM VERSIONING CHARACTER SET utf8 ENGINE=InnoDB;
 
INSERT INTO t VALUES ('foo');
 
DELETE FROM t;

you can view the clustered index root page (page 3) of each table as follows:

od -Ax -t x1 -j 0xc000 -N 0x4000 var/mysqld.1/data/test/tf.ibd
 
od -Ax -t x1 -j 0xc000 -N 0x4000 var/mysqld.1/data/test/t.ibd

In both cases, the first field of the first (and only) user record starts 0x1c bytes after the page infimum, at 0xc07f. The contents is as follows:
tf(DB_ROW_ID,DB_TRX_ID,DB_ROLL_PTR,f,row_start,row_end,FTS_DOC_ID)=
(0x200,0x1c,(update),'foo',0x64f81d440840c5,0x64f81d440860a4,1)
t(DB_ROW_ID,DB_TRX_ID,DB_ROLL_PTR,f,row_start,row_end)=
(0x201,0x28,(update),'foo',0x64f81d44087747,0x64f81d44087c20)

I do not know how to decode the 7-byte row_start and row_end values. I assume that they are timestamps, possibly at microsecond precision.

Please explain how you think we should end up with 0 in FTS_DOC_ID while creating a fulltext index on a system-versioned table.

If you are unable or unwilling to fix this bug, a practical solution might be that InnoDB will refuse any native ALTER TABLE on system-versioned tables that contain FULLTEXT INDEX.

Comment by Aleksey Midenkov [ 2023-09-11 ]

I pushed innodb_fts.f test to bb-10.4-midenok which uses your method of peeking binary data. For SQL code of:

create table t2 (f text, fulltext(f)) with system versioning character set utf8 engine=innodb;
 
insert into t2 values ('foo');
 
delete from t2;
 
insert into t2 values ('bar');
 
create table t3 (f text) with system versioning character set utf8 engine=innodb;
 
insert into t3 values ('FOO');
 
delete from t3;
 
insert into t3 values ('BAR');
 
alter table t3 add fulltext (f);

It prints:

DB_ROW_ID=512; DB_TRX_ID=0; DB_ROLL_PTR=36028797018963968; FTS_DOC_ID=1
 
000000000200 000000000000 80000000000000 64ff550c08e7da 64ff550c09043a 0000000000000001 foo
 
DB_ROW_ID=513; DB_TRX_ID=0; DB_ROLL_PTR=36028797018963968; FTS_DOC_ID=2
 
000000000201 000000000000 80000000000000 64ff550c091ea8 7fffffff0f423f 0000000000000002 bar
 
DB_ROW_ID=514; DB_TRX_ID=0; DB_ROLL_PTR=36028797018963968; FTS_DOC_ID=0
 
000000000202 000000000000 80000000000000 64ff550c0950b6 64ff550c095c6b 0000000000000000 FOO
 
DB_ROW_ID=515; DB_TRX_ID=0; DB_ROLL_PTR=36028797018963968; FTS_DOC_ID=1
 
000000000203 000000000000 80000000000000 64ff550c0965af 7fffffff0f423f 0000000000000001 BAR

Please explain how you think we should end up with 0 in FTS_DOC_ID while creating a fulltext index on a system-versioned table.

This is the case of t3.FOO in the above example (history row upon add fulltext index)

Comment by Aleksey Midenkov [ 2023-09-12 ]

Note that it is important to check secondary index as well.

Comment by Aleksey Midenkov [ 2023-09-14 ]

The branch is bb-10.4-midenok-MDEV-30528

Comment by Marko Mäkelä [ 2023-10-20 ]

I do not understand why it would be necessary or correct to ignore duplicates when dealing with history rows.

I think that a safer fix would be to modify ha_innobase::check_if_inplace_alter_table() so that it will return something similar to the following in case a FTS_DOC_ID column exists in a system-versioned table:

	if ((ha_alter_info->handler_flags
 
	     & INNOBASE_ALTER_VERSIONED_REBUILD)
 
	    && altered_table->versioned(VERS_TIMESTAMP)) {
 
		ha_alter_info->unsupported_reason =
 
			"Not implemented for system-versioned timestamp tables";
 
		DBUG_RETURN(HA_ALTER_INPLACE_NOT_SUPPORTED);
 
	}

Along with this, the references to history_row or history_fts in row0merge.cc should be cleaned up.

Comment by Marko Mäkelä [ 2024-01-30 ]

I am going to implement the safer and simpler fix that I suggested: requiring ALGORITHM=COPY in CREATE FULLTEXT INDEX on versioned tables.

Comment by Matthias Leich [ 2024-01-31 ] 

origin/10.6 12d05c8266567ea9a62ccabc3180a90129bf81e0 + git cherry-pick --no-commit origin/10.4-MDEV-30528 ...
 
performed well in RQG testing.
 
Please note that my RQG tests
 
- replayed error patterns containing 'mbmaxlen' like 
  a) rem0rec.cc:....: ulint rec_get_converted_size_comp_prefix_low(....): Assertion `!col->mbmaxlen || len >= col->mbminlen * fixed_len / col->mbmaxlen' failed.
 
  b) rem0rec.cc:....: ulint rec_get_converted_size_comp_prefix_low(....): Assertion .field->col->is_dropped.. .. .field->col->mbmaxlen .. len >= field->col->mbminlen . fixed_len . field->col->mbmaxlen. failed.'
 
  c) row0sel.cc:....: void row_sel_field_store_in_mysql_format_func(....): Assertion `len * templ->mbmaxlen >= templ->mysql_col_len || (field_no == templ->icp_rec_field_no && field->prefix_len > 0) || templ->rec_field_is_prefix' failed
 
  d) InnoDB: Assertion failure in file /data/Server/10.6_with_patch/storage/innobase/data/data0type.cc line 67
 
       InnoDB: Failing assertion: !(prefix_len % mbmaxlen) || !(prefix_len % 4)
 
  somewhere in history but not in the current testing round
 
- have never replayed 
  Assertion `!mbmaxlen || !(prefix_len % mbmaxlen)' failed
 
  Assertion `!mbmaxlen || !(prefix_len % mbmaxlen) || !(prefix_len % 4)' failed
 
  assertion: !(prefix_len % mbmaxlen)

Generated at Thu Feb 08 10:16:54 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.