[MDEV-18901] Wrong results after ADD UNIQUE INDEX(blob_column) Created: 2019-03-12  Updated: 2019-03-22  Resolved: 2019-03-22

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.4.3
Fix Version/s: 10.4.4

Type: Bug Priority: Blocker
Reporter: Matthias Leich Assignee: Sachin Setiya (Inactive)
Resolution: Fixed Votes: 0
Labels: regression

Issue Links:
PartOf
includes MDEV-18922 Alter on long unique varchar column m... Closed
Problem/Incident
is caused by MDEV-371 Unique indexes for blobs Closed
is caused by MDEV-18967 Load data in system version with long... Closed
Relates
relates to MDEV-18910 Hash value unique long column is misc... Closed

 Description   

Problem found during RQG testing

--source include/have_innodb.inc
--disable_abort_on_error
 
--source include/have_innodb.inc
# harmless!! col1 VARCHAR(30)
CREATE TABLE t1 (
     col1 VARCHAR(7961) , col2 INTEGER
) ENGINE=InnoDB ;
 
INSERT INTO t1 ( col2, col1) VALUES
  (4, '8') , (2, '4') , (4, '4') , (8, '4') ;
 
SELECT col1, col2 FROM `t1` INTO OUTFILE 'load_t1'  ;
 
# This is harmless
# ALTER TABLE `t1` ADD IF NOT EXISTS ( `col1` SERIAL ) ;
  ALTER IGNORE TABLE `t1` ADD IF NOT EXISTS ( `col1` SERIAL ) ;
ALTER TABLE `t1` ADD SYSTEM VERSIONING ;
LOAD DATA INFILE 'load_t1' REPLACE INTO TABLE t1 ;   # <== assert
 
--enable_abort_on_error
DROP TABLE t1;
 
Version: '10.4.4-MariaDB-debug-log'  socket: 'bld_debug/mysql-test/var/tmp/mysqld.1.sock'  port: 16000  Source distribution
2019-03-12 12:57:20 9 [ERROR] InnoDB: Record in index `col1` of table `test`.`t1` was not found on update: TUPLE (info_bits=0, 2 fields): {[8]  0    .(0x191D3085F812D82E),[6]      (0x000000000209)} at: COMPACT RECORD(info_bits=0, 2 fields): {[8]  0    .(0x191D3085F812D82E),[6]      (0x000000000207)}
mysqld: storage/innobase/row/row0upd.cc:2430: dberr_t row_upd_sec_index_entry(upd_node_t*, que_thr_t*): Assertion `0' failed.
190312 12:57:20 [ERROR] mysqld got signal 6 ;
...
Query (0x7fdf80014730): LOAD DATA INFILE 'load_t1' REPLACE INTO TABLE t1
Connection ID (thread ID): 9
Status: NOT_KILLED
...
#3  <signal handler called>
#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
#5  0x00007fdfdb520f5d in __GI_abort () at abort.c:90
#6  0x00007fdfdb516f17 in __assert_fail_base (fmt=<optimized out>, assertion=assertion@entry=0x55b1bf357c71 "0", file=file@entry=0x55b1bf359428 "storage/innobase/row/row0upd.cc", line=line@entry=2430, function=function@entry=0x55b1bf35c400 <row_upd_sec_index_entry(upd_node_t*, que_thr_t*)::__PRETTY_FUNCTION__> "dberr_t row_upd_sec_index_entry(upd_node_t*, que_thr_t*)") at assert.c:92
#7  0x00007fdfdb516fc2 in __GI___assert_fail (assertion=0x55b1bf357c71 "0", file=0x55b1bf359428 "storage/innobase/row/row0upd.cc", line=2430, function=0x55b1bf35c400 <row_upd_sec_index_entry(upd_node_t*, que_thr_t*)::__PRETTY_FUNCTION__> "dberr_t row_upd_sec_index_entry(upd_node_t*, que_thr_t*)") at assert.c:101
#8  0x000055b1bebd7273 in row_upd_sec_index_entry (node=0x7fdf80079438, thr=0x7fdf800797d0) at storage/innobase/row/row0upd.cc:2430
#9  0x000055b1bebd7960 in row_upd_sec_step (node=0x7fdf80079438, thr=0x7fdf800797d0) at storage/innobase/row/row0upd.cc:2543
#10 0x000055b1bebda3ca in row_upd (node=0x7fdf80079438, thr=0x7fdf800797d0) at storage/innobase/row/row0upd.cc:3322
#11 0x000055b1bebda731 in row_upd_step (thr=0x7fdf800797d0) at storage/innobase/row/row0upd.cc:3437
#12 0x000055b1beb88197 in row_update_for_mysql (prebuilt=0x7fdf80149788) at storage/innobase/row/row0mysql.cc:1890
#13 0x000055b1bea20cf0 in ha_innobase::update_row (this=0x7fdf801787d0, old_row=0x7fdf800732e8 "\240\001", new_row=0x7fdf800713b0 "\370\001") at storage/innobase/handler/ha_innodb.cc:8895
#14 0x000055b1be800f09 in handler::ha_update_row (this=0x7fdf801787d0, old_data=0x7fdf800732e8 "\240\001", new_data=0x7fdf800713b0 "\370\001") at sql/handler.cc:6747
#15 0x000055b1be4652ec in write_record (thd=0x7fdf80000ce8, table=0x7fdf80130e28, info=0x7fdfd483b000) at sql/sql_insert.cc:1941
#16 0x000055b1be49ad58 in read_sep_field (thd=0x7fdf80000ce8, info=..., table_list=0x7fdf80014898, fields_vars=..., set_fields=..., set_values=..., read_info=..., enclosed=..., skip_lines=0, ignore_check_option_errors=false) at sql/sql_load.cc:1157
#17 0x000055b1be499385 in mysql_load (thd=0x7fdf80000ce8, ex=0x7fdf80014810, table_list=0x7fdf80014898, fields_vars=..., set_fields=..., set_values=..., handle_duplicates=DUP_REPLACE, ignore=false, read_file_from_client=false) at sql/sql_load.cc:665
#18 0x000055b1be4b03f2 in mysql_execute_command (thd=0x7fdf80000ce8) at sql/sql_parse.cc:5230
#19 0x000055b1be4ba88f in mysql_parse (thd=0x7fdf80000ce8, rawbuf=0x7fdf80014730 "LOAD DATA INFILE 'load_t1' REPLACE INTO TABLE t1", length=48, parser_state=0x7fdfd483c170, is_com_multi=false, is_next_command=false) at sql/sql_parse.cc:8204
#20 0x000055b1be4a5ba0 in dispatch_command (command=COM_QUERY, thd=0x7fdf80000ce8, packet=0x7fdf8000a189 "LOAD DATA INFILE 'load_t1' REPLACE INTO TABLE t1 ", packet_length=49, is_com_multi=false, is_next_command=false) at sql/sql_parse.cc:1828
#21 0x000055b1be4a435f in do_command (thd=0x7fdf80000ce8) at sql/sql_parse.cc:1357
#22 0x000055b1be61cceb in do_handle_one_connection (connect=0x55b1c1a82548) at sql/sql_connect.cc:1399
#23 0x000055b1be61ca4f in handle_one_connection (arg=0x55b1c1a82548) at sql/sql_connect.cc:1302
#24 0x000055b1bef519aa in pfs_spawn_thread (arg=0x55b1c1ab90d8) at storage/perfschema/pfs.cc:1862
#25 0x00007fdfdc3c67fc in start_thread (arg=0x7fdfd483d700) at pthread_create.c:465
#26 0x00007fdfdb5fcb5f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 
Replay on
10.4 commit 6d68a3464e9a93baecc277a2c270cad28fbf50bd 2019-03-11
 
The results on
10.3.14 commit 09bd2138522787a4e0b015695c462903f4a9e728 2019-02-22
10.2.22 commit 28e713dc12881e7f50207d0c642523ca3e630114 2019-03-11
are different (no asserts) but bad too (https://jira.mariadb.org/browse/MDEV-18927).



 Comments   
Comment by Matthias Leich [ 2019-03-12 ]

Variation of the problem (assert at different place)
--------------------------------------------------------------------------------
 
--source include/have_innodb.inc
--disable_abort_on_error
 
SET SESSION sql_mode = 'NO_ENGINE_SUBSTITUTION' ;
CREATE TABLE t1 (
    pk INTEGER AUTO_INCREMENT ,
    col1 INTEGER ,
    col2 INTEGER ,
    PRIMARY KEY (pk)
)  ENGINE=InnoDB ;
INSERT INTO t1 (col2 , col1) VALUES ( 7, 1) ;
ALTER IGNORE TABLE `t1` ADD IF NOT EXISTS ( `col1` SERIAL ) ;
ALTER IGNORE TABLE `t1` MODIFY `col1` VARCHAR(15129) ;
ALTER TABLE `t1` ADD SYSTEM VERSIONING ;
SELECT * FROM `t1` INTO OUTFILE 'load_t1'  ;
 LOAD DATA INFILE 'load_t1' REPLACE INTO TABLE t1 ;
 LOAD DATA INFILE 'load_t1' REPLACE INTO TABLE t1 ;
--enable_abort_on_error
DROP TABLE t1;
 
On 10.4 I get:
Version: '10.4.4-MariaDB-debug-log'  socket: 'bld_debug/mysql-test/var/tmp/mysqld.1.sock'  port: 16000  Source distribution
2019-03-12 16:23:47 0x7fd8b97e4700  InnoDB: Assertion failure in file storage/innobase/row/row0ins.cc line 267
InnoDB: Failing assertion: !cursor->index->is_committed()
...
Query (0x7fd868014730): LOAD DATA INFILE 'load_t1' REPLACE INTO TABLE t1
Connection ID (thread ID): 9
Status: NOT_KILLED
...
#3  <signal handler called>
#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
#5  0x00007fd8c04c7f5d in __GI_abort () at abort.c:90
#6  0x00005599ed1b51f3 in ut_dbg_assertion_failed (expr=0x5599ed89cbe8 "!cursor->index->is_committed()", file=0x5599ed89caa0 "storage/innobase/row/row0ins.cc", line=267) at storage/innobase/ut/ut0dbg.cc:60
#7  0x00005599ed0cc3ba in row_ins_sec_index_entry_by_modify (flags=0, mode=2, cursor=0x7fd8b97dfd20, offsets=0x7fd8b97dfcc0, offsets_heap=0x7fd868138910, heap=0x7fd86806e430, entry=0x7fd86807cb08, thr=0x7fd8681b3788, mtr=0x7fd8b97e00e0) at storage/innobase/row/row0ins.cc:267
#8  0x00005599ed0d3e96 in row_ins_sec_index_entry_low (flags=0, mode=2, index=0x7fd8681311e8, offsets_heap=0x7fd868138910, heap=0x7fd86806e430, entry=0x7fd86807cb08, trx_id=0, thr=0x7fd8681b3788, dup_chk_only=false) at storage/innobase/row/row0ins.cc:3140
#9  0x00005599ed0d489b in row_ins_sec_index_entry (index=0x7fd8681311e8, entry=0x7fd86807cb08, thr=0x7fd8681b3788, dup_chk_only=false) at storage/innobase/row/row0ins.cc:3359
#10 0x00005599ed146775 in row_upd_sec_index_entry (node=0x7fd8681b33c0, thr=0x7fd8681b3788) at storage/innobase/row/row0upd.cc:2516
#11 0x00005599ed146960 in row_upd_sec_step (node=0x7fd8681b33c0, thr=0x7fd8681b3788) at storage/innobase/row/row0upd.cc:2543
#12 0x00005599ed1493ca in row_upd (node=0x7fd8681b33c0, thr=0x7fd8681b3788) at storage/innobase/row/row0upd.cc:3322
#13 0x00005599ed149731 in row_upd_step (thr=0x7fd8681b3788) at storage/innobase/row/row0upd.cc:3437
#14 0x00005599ed0f7197 in row_update_for_mysql (prebuilt=0x7fd86807f258) at storage/innobase/row/row0mysql.cc:1890
#15 0x00005599ecf8fcf0 in ha_innobase::update_row (this=0x7fd86807eaa0, old_row=0x7fd868074420 "\240\001", new_row=0x7fd8680708e0 "\370\001") at storage/innobase/handler/ha_innodb.cc:8895
#16 0x00005599ecd6ff09 in handler::ha_update_row (this=0x7fd86807eaa0, old_data=0x7fd868074420 "\240\001", new_data=0x7fd8680708e0 "\370\001") at sql/handler.cc:6747
#17 0x00005599ec9d42ec in write_record (thd=0x7fd868000ce8, table=0x7fd86807dca8, info=0x7fd8b97e2000) at sql/sql_insert.cc:1941
#18 0x00005599eca09d58 in read_sep_field (thd=0x7fd868000ce8, info=..., table_list=0x7fd868014898, fields_vars=..., set_fields=..., set_values=..., read_info=..., enclosed=..., skip_lines=0, ignore_check_option_errors=false) at sql/sql_load.cc:1157
#19 0x00005599eca08385 in mysql_load (thd=0x7fd868000ce8, ex=0x7fd868014810, table_list=0x7fd868014898, fields_vars=..., set_fields=..., set_values=..., handle_duplicates=DUP_REPLACE, ignore=false, read_file_from_client=false) at sql/sql_load.cc:665
#20 0x00005599eca1f3f2 in mysql_execute_command (thd=0x7fd868000ce8) at sql/sql_parse.cc:5230
#21 0x00005599eca2988f in mysql_parse (thd=0x7fd868000ce8, rawbuf=0x7fd868014730 "LOAD DATA INFILE 'load_t1' REPLACE INTO TABLE t1", length=48, parser_state=0x7fd8b97e3170, is_com_multi=false, is_next_command=false) at sql/sql_parse.cc:8204
#22 0x00005599eca14ba0 in dispatch_command (command=COM_QUERY, thd=0x7fd868000ce8, packet=0x7fd86800a189 "LOAD DATA INFILE 'load_t1' REPLACE INTO TABLE t1 ", packet_length=49, is_com_multi=false, is_next_command=false) at sql/sql_parse.cc:1828
#23 0x00005599eca1335f in do_command (thd=0x7fd868000ce8) at sql/sql_parse.cc:1357
#24 0x00005599ecb8bceb in do_handle_one_connection (connect=0x5599ef9a6548) at sql/sql_connect.cc:1399
#25 0x00005599ecb8ba4f in handle_one_connection (arg=0x5599ef9a6548) at sql/sql_connect.cc:1302
#26 0x00005599ed4c09aa in pfs_spawn_thread (arg=0x5599ef9dd0d8) at storage/perfschema/pfs.cc:1862
#27 0x00007fd8c136d7fc in start_thread (arg=0x7fd8b97e4700) at pthread_create.c:465
#28 0x00007fd8c05a3b5f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 

Comment by Marko Mäkelä [ 2019-03-13 ]

I believe that this is one more 10.4.3 regression due to MDEV-371. I cannot reproduce any crash on 10.2 or 10.3. In 10.4, the check fails for the index col1, whose fields internally are DB_ROW_HASH_1 and DB_ROW_ID.

Here is a simplified test with some commentary:

--source include/have_innodb.inc
 
# with VARCHAR(79), all results are correct
CREATE TABLE t1 (a VARCHAR(7961)) ENGINE=InnoDB;
 
INSERT INTO t1 VALUES ('f'), ('o'), ('o');
SELECT * FROM t1 INTO OUTFILE 'load.data';
 
ALTER IGNORE TABLE t1 ADD UNIQUE INDEX (a);
# returns 2 rows with a=NULL, instead of rows ('f'),('o')!
SELECT * FROM t1;
ALTER TABLE t1 ADD SYSTEM VERSIONING ;
# returns empty table instead of a table with the 2 rows!
SELECT * FROM t1;
REPLACE INTO t1 VALUES ('f'), ('o'), ('o');
# still returns an empty table instead of rows ('f'),('o')!
SELECT * FROM t1;
# This should be equivalent to the REPLACE above, but is not!
LOAD DATA INFILE 'load.data' REPLACE INTO TABLE t1;
DROP TABLE t1;
--let $datadir= `select @@datadir`
--remove_file $datadir/test/load.data

Without the ADD SYSTEM VERSIONING, the LOAD DATA INFILE would not crash, and the 2 last SELECT would return 2 records of a=NULL (instead of returning the 2 records with the correct data).

Comment by Sachin Setiya (Inactive) [ 2019-03-19 ]

bb-10.4-sachin

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