[MDEV-17051] Failing assertion: cursor->old_rec in innobase/btr/btr0pcur.cc or `sec_mtr->has_committed() == node->vcol_info.is_requested()' in row_purge_poss_sec Created: 2018-08-23  Updated: 2018-10-01  Resolved: 2018-10-01

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB, Virtual Columns
Affects Version/s: 10.2, 10.3
Fix Version/s: 10.3.10, 10.2.19

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Marko Mäkelä
Resolution: Fixed Votes: 0
Labels: None

Issue Links:
Problem/Incident
is caused by MDEV-15855 Assertion `mysql_table' failed in inn... Closed
Relates
relates to MDEV-16950 gcol.innodb_virtual_basic fails in bu... Open

 Description   

The test case runs in a loop itself, so there is no need to run with --repeat; but if you want to, also use --force-restart.
The loop inside the test is currently 50 repetitions. 10-15 is usually enough on my machine, but I suppose it can vary.

--source include/have_innodb.inc
 
--let $run= 50
 
while ($run)
{
  CREATE TABLE t1 ( 
    f1 INT,
    f2 CHAR(8),
    f3 YEAR,
    f4 CHAR(8) AS (f2) VIRTUAL,
    f5 YEAR AS (f3) VIRTUAL,
    f6 CHAR(8),
    f7 INT,
    PRIMARY KEY(f1),
    UNIQUE(f4,f7),
    UNIQUE(f6,f5),
    UNIQUE(f4)
  ) ENGINE=InnoDB;
 
  CREATE TABLE t2 ( 
    f1 INT,
    f2 CHAR(8) DEFAULT '',
    f3 YEAR,
    f4 CHAR(8) DEFAULT '',
    f5 YEAR,
    f6 CHAR(8),
    f7 INT
  ) ENGINE=InnoDB;
  INSERT IGNORE INTO t2 (f1,f5,f6,f7) VALUES
   (1,2018,'a',NULL),
   (2,NULL,'b',10),
   (3,2030,'c',11),
   (4,2000,'d',12),
   (5,1978,'e',13),
   (1,1977,'f',14),
   (6,2012,'t',15),
   (7,1999,'t',16),
   (8,1997,'t',17);
 
  SELECT * FROM t2 INTO OUTFILE 'load.data';
  LOAD DATA INFILE 'load.data' REPLACE INTO TABLE t1;
 
  # Cleanup
  DROP TABLE t1, t2;
  --let $datadir=`SELECT @@datadir`
  --remove_file $datadir/test/load.data
 
  --dec $run
  --echo #
  --echo # $run round(s) left
  --echo #
  --source include/restart_mysqld.inc
}

10.2 2676f3371c non-debug

2018-09-07 21:18:00 0x7f80fa7fc700  InnoDB: Assertion failure in file /data/src/10.2/storage/innobase/btr/btr0pcur.cc line 273
InnoDB: Failing assertion: cursor->old_rec
 
#4  0x00007f8115e2c3fa in abort () from /lib/x86_64-linux-gnu/libc.so.6
#5  0x0000558e856b3c05 in ut_dbg_assertion_failed (expr=0x558e85f10ecc "cursor->old_rec", file=0x558e85f10ef8 "/data/src/10.2/storage/innobase/btr/btr0pcur.cc", line=273) at /data/src/10.2/storage/innobase/ut/ut0dbg.cc:61
#6  0x0000558e85c7b8b0 in btr_pcur_restore_position_func (latch_mode=8194, cursor=0x7f80fa7fb460, file=0x558e85f039d8 "/data/src/10.2/storage/innobase/row/row0purge.cc", line=279, mtr=0x7f80fa7fb6c0) at /data/src/10.2/storage/innobase/btr/btr0pcur.cc:273
#7  0x0000558e85bdc229 in row_purge_restore_vsec_cur (is_tree=false, sec_mtr=0x7f80fa7fb6c0, sec_pcur=0x7f80fa7fb460, index=0x7f80bc024820, node=0x558e8973a620) at /data/src/10.2/storage/innobase/row/row0purge.cc:277
#8  row_purge_poss_sec (node=node@entry=0x558e8973a620, index=index@entry=0x7f80bc024820, entry=entry@entry=0x7f80d4006e20, sec_pcur=sec_pcur@entry=0x7f80fa7fb460, sec_mtr=sec_mtr@entry=0x7f80fa7fb6c0, is_tree=is_tree@entry=false) at /data/src/10.2/storage/innobase/row/row0purge.cc:379
#9  0x0000558e85bdc85f in row_purge_remove_sec_if_poss_leaf (node=0x558e8973a620, index=0x7f80bc024820, entry=0x7f80d4006e20) at /data/src/10.2/storage/innobase/row/row0purge.cc:597
#10 0x0000558e85bde9d8 in row_purge_remove_sec_if_poss (entry=<optimized out>, index=<optimized out>, node=<optimized out>) at /data/src/10.2/storage/innobase/row/row0purge.cc:710
#11 row_purge_del_mark (node=<optimized out>) at /data/src/10.2/storage/innobase/row/row0purge.cc:784
#12 row_purge_record_func (updated_extern=<optimized out>, thr=<optimized out>, undo_rec=<optimized out>, node=<optimized out>) at /data/src/10.2/storage/innobase/row/row0purge.cc:1094
#13 row_purge (thr=<optimized out>, undo_rec=<optimized out>, node=<optimized out>) at /data/src/10.2/storage/innobase/row/row0purge.cc:1155
#14 row_purge_step (thr=0x2, thr@entry=0x558e8973a470) at /data/src/10.2/storage/innobase/row/row0purge.cc:1241
#15 0x0000558e85b9fd96 in que_thr_step (thr=0x558e8973a470) at /data/src/10.2/storage/innobase/que/que0que.cc:1049
#16 que_run_threads_low (thr=0x558e8973a470) at /data/src/10.2/storage/innobase/que/que0que.cc:1111
#17 que_run_threads (thr=thr@entry=0x558e8973a470) at /data/src/10.2/storage/innobase/que/que0que.cc:1151
#18 0x0000558e85c0a4d6 in srv_task_execute () at /data/src/10.2/storage/innobase/srv/srv0srv.cc:2561
#19 srv_worker_thread (arg=<optimized out>) at /data/src/10.2/storage/innobase/srv/srv0srv.cc:2608
#20 0x00007f8117afa494 in start_thread (arg=0x7f80fa7fc700) at pthread_create.c:333
#21 0x00007f8115ee093f in clone () from /lib/x86_64-linux-gnu/libc.so.6

A similar non-debug assertion failure happens or was happening in buildbot and is filed as MDEV-16950.

10.2 2676f3371c

mysqld: /data/src/10.2/storage/innobase/row/row0purge.cc:327: bool row_purge_poss_sec(purge_node_t*, dict_index_t*, const dtuple_t*, btr_pcur_t*, mtr_t*, bool): Assertion `sec_mtr->has_committed() == node->vcol_info.is_requested()' failed.
180907 21:20:00 [ERROR] mysqld got signal 6 ;
 
#7  0x00007f9adfc4cee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
#8  0x0000557446235d9a in row_purge_poss_sec (node=0x557449b92108, index=0x7f9a88134f88, entry=0x7f9aa80117a8, sec_pcur=0x7f9ac4ff8560, sec_mtr=0x7f9ac4ff87c0, is_tree=false) at /data/src/10.2/storage/innobase/row/row0purge.cc:326
#9  0x0000557446236a87 in row_purge_remove_sec_if_poss_leaf (node=0x557449b92108, index=0x7f9a88134f88, entry=0x7f9aa80117a8) at /data/src/10.2/storage/innobase/row/row0purge.cc:597
#10 0x0000557446236f6a in row_purge_remove_sec_if_poss (node=0x557449b92108, index=0x7f9a88134f88, entry=0x7f9aa80117a8) at /data/src/10.2/storage/innobase/row/row0purge.cc:710
#11 0x0000557446237177 in row_purge_del_mark (node=0x557449b92108) at /data/src/10.2/storage/innobase/row/row0purge.cc:784
#12 0x0000557446237d94 in row_purge_record_func (node=0x557449b92108, undo_rec=0x557449b926b8 "\001a\016\001\023", thr=0x557449b91f50, updated_extern=false) at /data/src/10.2/storage/innobase/row/row0purge.cc:1094
#13 0x000055744623800b in row_purge (node=0x557449b92108, undo_rec=0x557449b926b8 "\001a\016\001\023", thr=0x557449b91f50) at /data/src/10.2/storage/innobase/row/row0purge.cc:1155
#14 0x000055744623834a in row_purge_step (thr=0x557449b91f50) at /data/src/10.2/storage/innobase/row/row0purge.cc:1241
#15 0x00005574461c991b in que_thr_step (thr=0x557449b91f50) at /data/src/10.2/storage/innobase/que/que0que.cc:1049
#16 0x00005574461c9b19 in que_run_threads_low (thr=0x557449b91f50) at /data/src/10.2/storage/innobase/que/que0que.cc:1111
#17 0x00005574461c9cc2 in que_run_threads (thr=0x557449b91f50) at /data/src/10.2/storage/innobase/que/que0que.cc:1151
#18 0x000055744628470a in srv_task_execute () at /data/src/10.2/storage/innobase/srv/srv0srv.cc:2561
#19 0x0000557446284858 in srv_worker_thread (arg=0x0) at /data/src/10.2/storage/innobase/srv/srv0srv.cc:2608
#20 0x00007f9ae1923494 in start_thread (arg=0x7f9ac4ff9700) at pthread_create.c:333
#21 0x00007f9adfd0993f in clone () from /lib/x86_64-linux-gnu/libc.so.6

The provided test case doesn't seem to fail on 10.3, but at least the debug assertion failure has been observed in concurrent tests on 10.3 as well.



 Comments   
Comment by Marko Mäkelä [ 2018-09-07 ]

I believe that this is a regression caused by MDEV-15855.

Comment by Marko Mäkelä [ 2018-09-07 ]

I cannot repeat the crash on 10.2 ASAN or debug build (gcc 8), but I can repeat with a non-debug build (clang 6.0), on the first round:

10.2 980d1bf1a921a270423ab36bd5d1ce2a1cd7590b

CURRENT_TEST: innodb.mdev-17051
mysqltest: At line 45: query 'DROP TABLE t1, t2' failed: 2013: Lost connection to MySQL server during query

This was the ut_a(cursor->old_rec) failing on purge.

Comment by Thirunarayanan Balathandayuthapani [ 2018-10-01 ]

Fixed as a part of mdev-17215's patch.

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