[MDEV-21608] Assertion `n_ext == dtuple_get_n_ext(dtuple)' failed during updation of PK Created: 2020-01-30  Updated: 2020-02-07  Resolved: 2020-02-07

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.2.31, 10.3.22, 10.4.12, 10.5.1
Fix Version/s: 10.5.1, 10.2.32, 10.3.23, 10.4.13

Type: Bug Priority: Major
Reporter: Matthias Leich Assignee: Thirunarayanan Balathandayuthapani
Resolution: Fixed Votes: 0
Labels: affects-tests

Attachments: File ML_1.test     HTML File prt    
Issue Links:
Problem/Incident
is caused by MDEV-21511 Wrong estimate of affected BLOB colum... Closed

 Description   

MariaDB Version 10.5.1-MariaDB-debug
 - SSL connections supported
 - binaries are debug compiled
 - binaries built with wsrep patch
Collecting tests...
Installing system database...
=========================================================================
TEST                                      RESULT   TIME (ms) or COMMENT
--------------------------------------------------------------------------
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
SET SESSION sql_mode = 'NO_ENGINE_SUBSTITUTION' ;
CREATE TABLE t4 ( col1 INT PRIMARY KEY, col2 INT, col_int2 INTEGER, col_varchar VARCHAR(500), col_text TEXT ) ENGINE = InnoDB ROW_FORMAT = Redundant ;
SET @fill_amount = (@@innodb_page_size / 2 ) + 1 ;
INSERT INTO t4 (col1,col2, col_int2, col_text ) VALUES ( 20, 19, 2, REPEAT(2, @fill_amount) ) ;
ALTER TABLE t4 ADD COLUMN col_text_copy TEXT  ;
UPDATE t4 SET col_text_copy = col_text ;
ALTER TABLE t4 ADD KEY ( col_text(9) ) ;
UPDATE t4 SET col1 = 52 ORDER BY col1 DESC LIMIT 2 ;
ERROR HY000: Lost connection to MySQL server during query
CREATE TABLE t1 (col1 INT) ENGINE = InnoDB;
ERROR HY000: MySQL server has gone away
DROP TABLE t1;
ERROR HY000: MySQL server has gone away
DROP TABLE t4;
ERROR HY000: MySQL server has gone away
main.ML_1 'innodb'                       [ fail ]
        Test ended at 2020-01-30 16:03:06
CURRENT_TEST: main.ML_1
...
Version: '10.5.1-MariaDB-debug-log'  socket: '/home/mleichbld_debug/mysql-test/var/tmp/mysqld.1.sock'  port: 16000  Source distribution
mysqld: storage/innobase/include/rem0rec.ic:1393: ulint rec_get_converted_size(dict_index_t*, const dtuple_t*, ulint): Assertion `n_ext == dtuple_get_n_ext(dtuple)' failed.
200130 16:03:06 [ERROR] mysqld got signal 6 ;
...
Query (0x7f6c880126d0): UPDATE t4 SET col1 = 52 ORDER BY col1 DESC LIMIT 2
Connection ID (thread ID): 4
Status: NOT_KILLED
...
Thread 1 (Thread 0x7f6cb8e47700 (LWP 338691)):
#0  __pthread_kill (threadid=<optimized out>, signo=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:62
#1  0x00005581637ef573 in my_write_core (sig=6) at mysys/stacktrace.c:518
#2  0x0000558162ecdd87 in handle_fatal_signal (sig=6) at sql/signal_handler.cc:343
#3  <signal handler called>
#4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:58
#5  0x00007f6cbfabc37a in __GI_abort () at abort.c:89
#6  0x00007f6cbfab2b47 in __assert_fail_base (fmt=<optimized out>, assertion=assertion@entry=0x558163d0ce28 "n_ext == dtuple_get_n_ext(dtuple)", file=file@entry=0x558163d0ca98 "storage/innobase/include/rem0rec.ic", line=line@entry=1393, function=function@entry=0x558163d14280 <_ZZL22rec_get_converted_sizeP12dict_index_tPK8dtuple_tmE19__PRETTY_FUNCTION__> "ulint rec_get_converted_size(dict_index_t*, const dtuple_t*, ulint)") at assert.c:92
#7  0x00007f6cbfab2bf2 in __GI___assert_fail (assertion=0x558163d0ce28 "n_ext == dtuple_get_n_ext(dtuple)", file=0x558163d0ca98 "storage/innobase/include/rem0rec.ic", line=1393, function=0x558163d14280 <_ZZL22rec_get_converted_sizeP12dict_index_tPK8dtuple_tmE19__PRETTY_FUNCTION__> "ulint rec_get_converted_size(dict_index_t*, const dtuple_t*, ulint)") at assert.c:101
#8  0x00005581635b11b0 in rec_get_converted_size (index=0x7f6c88160dc8, dtuple=0x7f6c88071e58, n_ext=1) at storage/innobase/include/rem0rec.ic:1393
#9  0x00005581635c122c in btr_cur_optimistic_insert (flags=0, cursor=0x7f6cb8e44110, offsets=0x7f6cb8e440a8, heap=0x7f6cb8e440a0, entry=0x7f6c88071e58, rec=0x7f6cb8e440b0, big_rec=0x7f6cb8e44098, n_ext=1, thr=0x7f6c8805d1e0, mtr=0x7f6cb8e44470) at storage/innobase/btr/btr0cur.cc:3410
#10 0x0000558163472b67 in row_ins_clust_index_entry_low (flags=0, mode=2, index=0x7f6c88160dc8, n_uniq=1, entry=0x7f6c88071e58, n_ext=1, thr=0x7f6c8805d1e0) at storage/innobase/row/row0ins.cc:2763
#11 0x0000558163474404 in row_ins_clust_index_entry (index=0x7f6c88160dc8, entry=0x7f6c88071e58, thr=0x7f6c8805d1e0, n_ext=1) at storage/innobase/row/row0ins.cc:3236
#12 0x00005581634fcf9d in row_upd_clust_rec_by_insert (node=0x7f6c8805ce18, index=0x7f6c88160dc8, thr=0x7f6c8805d1e0, referenced=0, foreign=false, mtr=0x7f6cb8e45140) at storage/innobase/row/row0upd.cc:2805
#13 0x00005581634fe6f2 in row_upd_clust_step (node=0x7f6c8805ce18, thr=0x7f6c8805d1e0) at storage/innobase/row/row0upd.cc:3223
#14 0x00005581634fead8 in row_upd (node=0x7f6c8805ce18, thr=0x7f6c8805d1e0) at storage/innobase/row/row0upd.cc:3297
#15 0x00005581634ff09e in row_upd_step (thr=0x7f6c8805d1e0) at storage/innobase/row/row0upd.cc:3441
#16 0x000055816349c7c0 in row_update_for_mysql (prebuilt=0x7f6c8805c598) at storage/innobase/row/row0mysql.cc:1889
#17 0x00005581632ed826 in ha_innobase::update_row (this=0x7f6c8806bc50, old_row=0x7f6c88175f68 "\344\024", new_row=0x7f6c88175d50 "\344\064") at storage/innobase/handler/ha_innodb.cc:8584
#18 0x0000558162ee35f9 in handler::ha_update_row (this=0x7f6c8806bc50, old_data=0x7f6c88175f68 "\344\024", new_data=0x7f6c88175d50 "\344\064") at sql/handler.cc:6702
#19 0x0000558162caad9e in mysql_update (thd=0x7f6c88000a98, table_list=0x7f6c880127e8, fields=..., values=..., conds=0x0, order_num=1, order=0x7f6c88013218, limit=2, ignore=false, found_return=0x7f6cb8e45ff0, updated_return=0x7f6cb8e460b0) at sql/sql_update.cc:1054
#20 0x0000558162b8c077 in mysql_execute_command (thd=0x7f6c88000a98) at sql/sql_parse.cc:4359
#21 0x0000558162b99322 in mysql_parse (thd=0x7f6c88000a98, rawbuf=0x7f6c880126d0 "UPDATE t4 SET col1 = 52 ORDER BY col1 DESC LIMIT 2", length=50, parser_state=0x7f6cb8e46570, is_com_multi=false, is_next_command=false) at sql/sql_parse.cc:7988
#22 0x0000558162b843e1 in dispatch_command (command=COM_QUERY, thd=0x7f6c88000a98, packet=0x7f6c88007f29 "UPDATE t4 SET col1 = 52 ORDER BY col1 DESC LIMIT 2 ", packet_length=51, is_com_multi=false, is_next_command=false) at sql/sql_parse.cc:1846
#23 0x0000558162b82b3b in do_command (thd=0x7f6c88000a98) at sql/sql_parse.cc:1364
#24 0x0000558162d23104 in do_handle_one_connection (connect=0x558165648938, put_in_cache=true) at sql/sql_connect.cc:1422
#25 0x0000558162d22e38 in handle_one_connection (arg=0x558165648938) at sql/sql_connect.cc:1319
#26 0x000055816327e609 in pfs_spawn_thread (arg=0x55816529c868) at storage/perfschema/pfs.cc:1869
#27 0x00007f6cc08ff6da in start_thread (arg=0x7f6cb8e47700) at pthread_create.c:456
#28 0x00007f6cbfb8dd7f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:105
 
No replay
- on 10.5 compiled without debug
- 10.2.21  commit 67240858b2bfa0afc436d88fc9da0595e1391b60
- if using ROW_FORMAT != Redundant 



 Comments   
Comment by Marko Mäkelä [ 2020-01-31 ]

I suspect that this may have been fixed by the merge of MDEV-21511 from 10.2 to 10.5. Please double-check.

Comment by Matthias Leich [ 2020-02-03 ]

When testing on bb-10.2-kevgs with
     5838b5274342 storage/innobase/include/rem0rec.ic (Marko Mäkelä 2020-01-17 10:46:33 +0200 1629) ut_ad(n_ext == dtuple_get_n_ext(dtuple));
set to comment all went fine.  I hit the usual small share of other already known bugs but no new asserts or SEGV's.

Comment by Thirunarayanan Balathandayuthapani [ 2020-02-07 ]

The following test case can repeat the issue :

--source include/have_innodb.inc
create table t1(f1 int primary key, f2 text)engine=innodb
                row_format=redundant;
insert into t1 values(1, repeat(2, 9000));
update t1 set f1= 2;

Comment by Thirunarayanan Balathandayuthapani [ 2020-02-07 ]

It is caused by the following commit:

commit 5838b52743423a2f9cf8d1a80e21c502cd308604
Author: Marko Mäkelä <marko.makela@mariadb.com>
Date:   Fri Jan 17 10:46:33 2020 +0200
    MDEV-21511 Wrong estimate of affected BLOB columns in update

Comment by Marko Mäkelä [ 2020-02-07 ]

A bogus (too strict) debug assertion was added in MDEV-21511. When the PRIMARY KEY of a record is updated, InnoDB will delete-mark the record and insert a new one. The new record may inherit externally stored columns from the old delete-marked record.

This does not affect release builds.

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