[MDEV-16950] gcol.innodb_virtual_basic fails in buildbot, Failing assertion: cursor->old_rec Created: 2018-08-11  Updated: 2023-11-28

Status: Open
Project: MariaDB Server
Component/s: Storage Engine - InnoDB, Tests, Virtual Columns
Affects Version/s: 10.2
Fix Version/s: 10.4, 10.5, 10.6

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Sergei Golubchik
Resolution: Unresolved Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-17051 Failing assertion: cursor->old_rec in... Closed

 Description   

http://buildbot.askmonty.org/buildbot/builders/kvm-rpm-centos74-amd64/builds/4044

gcol.innodb_virtual_basic 'innodb'       w3 [ fail ]
        Test ended at 2018-08-10 15:44:09
 
CURRENT_TEST: gcol.innodb_virtual_basic
mysqltest: At line 432: query 'CALL DELETE_insert_t()' failed: 2013: Lost connection to MySQL server during query
 
The result from queries just before the failure was:
< snip >
UPDATE t SET a = REPEAT(CAST(1 AS CHAR), 1000) WHERE h = 1;
CREATE PROCEDURE UPDATE_t()
begin
DECLARE i INT DEFAULT 1;
WHILE (i <= 200) DO
UPDATE t SET a = REPEAT(CAST(i AS CHAR), 2000) WHERE h = 1;
SET i = i + 1;
END WHILE;
END|
CREATE PROCEDURE DELETE_insert_t()
begin
DECLARE i INT DEFAULT 1;
WHILE (i <= 200) DO
DELETE FROM t WHERE h = 1;
INSERT INTO t VALUES (REPEAT(CAST(i AS CHAR), 2000) ,  REPEAT('b', 2000), DEFAULT, DEFAULT, DEFAULT, 1);
SET i = i + 1;
END WHILE;
END|
CALL UPDATE_t();
CALL DELETE_insert_t();
 
More results from queries before failure can be found in /dev/shm/var/3/log/innodb_virtual_basic.log
 
 
Server [mysqld.1 - pid: 24469, winpid: 24469, exit: 256] failed during test run
Server log from this test:
----------SERVER LOG START-----------
2018-08-10 15:44:06 0x7f677affd700  InnoDB: Assertion failure in file /home/buildbot/buildbot/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX/mariadb-10.2.17/storage/innobase/btr/btr0pcur.cc line 273
InnoDB: Failing assertion: cursor->old_rec
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/
InnoDB: about forcing recovery.
180810 15:44:06 [ERROR] mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed, 
something is definitely wrong and this may fail.
 
Server version: 10.2.17-MariaDB-log
key_buffer_size=1048576
read_buffer_size=131072
max_used_connections=2
max_threads=153
thread_count=8
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 63022 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x7f674c0009a8
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0x7f677affcc30 thread_stack 0x49000
/usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x55b243beb42e]
/usr/sbin/mysqld(handle_fatal_signal+0x355)[0x55b243669125]
sigaction.c:0(__restore_rt)[0x7f679dcfc5e0]
:0(__GI_raise)[0x7f679c2091f7]
:0(__GI_abort)[0x7f679c20a8e8]
/usr/sbin/mysqld(+0x429928)[0x55b243418928]
/usr/sbin/mysqld(+0x9e7c76)[0x55b2439d6c76]
ut/ut0rbt.cc:221(rbt_tree_add_child(ib_rbt_t const*, ib_rbt_bound_t*, ib_rbt_node_t*) [clone .isra.4] [clone .part.5])[0x55b243929f53]
btr/btr0pcur.cc:251(btr_pcur_restore_position_func(unsigned long, btr_pcur_t*, char const*, unsigned int, mtr_t*))[0x55b24392ae32]
row/row0purge.cc:724(row_purge_step(que_thr_t*))[0x55b24392c4ee]
que/que0que.cc:1049(que_run_threads(que_thr_t*))[0x55b2438e8164]
include/my_atomic.h:274(srv_worker_thread)[0x55b24395bf1c]
pthread_create.c:0(start_thread)[0x7f679dcf4e25]
/lib64/libc.so.6(clone+0x6d)[0x7f679c2cc34d]
 
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x0): 
Connection ID (thread ID): 5
Status: NOT_KILLED
 
Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on
 
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
Writing a core file at /dev/shm/var/3/mysqld.1/data/
----------SERVER LOG END-------------



 Comments   
Comment by Alice Sherepa [ 2020-10-30 ]

currently test fails on 10.2 http://buildbot.askmonty.org/buildbot/builders/kvm-deb-jessie-x86/builds/11179/steps/mtr/logs/stdio

gcol.innodb_virtual_basic 'innodb'       w1 [ fail ]  Found warnings/errors in server log file!
        Test ended at 2020-10-28 05:35:55
line
2020-10-28  5:35:52 2829003584 [Warning] InnoDB: Record in index `idx` of table `test`.`t` was not found on rollback, trying to insert: TUPLE (info_bits=0, 3 fields): {[100]2323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323(0x32333233323332333233323332333233323332333233323332333233323332333233323332333233323332333233323332333233323332333233323332333233323332333233323332333233323332333233323332333233323332333233323332333233),[20]bbbbbbbbbbbbbbbbbbbb(0x6262626262626262626262626262626262626262),[4]    (0x80000001)} at: COMPACT RECORD(info_bits=32, 3 fields): {[100]2222222222222222222222222222222222222222222222222222222222222222222222222222222222222222222222222222(0x32323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232),[20]xxxxxxxxxxxxxxxxxxxx(0x7878787878787878787878787878787878787878),[4]    (0x80000001)}
^ Found warnings in /dev/shm/var/1/log/mysqld.1.err

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

10.4 2447172afb5afed1687779e46eed217c38f89ebc

gcol.innodb_virtual_basic 'innodb'       w52 [ fail ]
        Test ended at 2023-11-07 14:06:24
 
CURRENT_TEST: gcol.innodb_virtual_basic
mysqltest: At line 330: query 'CALL UPDATE_t()' failed: 2013: Lost connection to MySQL server during query
Version: '10.4.32-MariaDB-debug-log'  socket: '/dev/shm/10.4m/mysql-test/var/tmp/52/mysqld.1.sock'  port: 17160  Source distribution
mysqld: /mariadb/10.4m/storage/innobase/include/dict0dict.inl:389: dict_v_col_t *dict_table_get_nth_v_col(const dict_table_t *, ulint): Assertion `!table->v_cols[pos].m_col.is_added()' failed.
#8  0x00007f7b33c533a2 in __assert_fail (assertion=0x555e0e17d1eb "!table->v_cols[pos].m_col.is_added()", file=0x555e0e0b0d8b "/mariadb/10.4m/storage/innobase/include/dict0dict.inl", line=389, function=0x555e0e20583a "dict_v_col_t *dict_table_get_nth_v_col(const dict_table_t *, ulint)") at ./assert/assert.c:101
#9  0x0000555e0edd2c10 in dict_table_get_nth_v_col (table=table@entry=0x7f7acc1b3140, pos=pos@entry=0) at /mariadb/10.4m/storage/innobase/include/dict0dict.inl:389
#10 0x0000555e0edd2113 in innobase_build_v_templ (table=table@entry=0x7f7acc1e9b38, ib_table=ib_table@entry=0x7f7acc1b3140, s_templ=s_templ@entry=0x7f7af40164c0, add_v=add_v@entry=0x0, locked=true) at /mariadb/10.4m/storage/innobase/handler/ha_innodb.cc:5929
#11 0x0000555e0edea08c in innobase_init_vc_templ (table=0x7f7acc1b3140) at /mariadb/10.4m/storage/innobase/handler/ha_innodb.cc:20649
#12 0x0000555e0f0f9f24 in row_purge_parse_undo_rec (node=0x555e11412ba8, undo_rec=0x7f7af4018610 "", updated_extern=0x7f7b017f900e, thr=0x555e11412ae8) at /mariadb/10.4m/storage/innobase/row/row0purge.cc:1250
#13 row_purge (node=node@entry=0x555e11412ba8, undo_rec=0x7f7af4018610 "", thr=thr@entry=0x555e11412ae8) at /mariadb/10.4m/storage/innobase/row/row0purge.cc:1395
#14 0x0000555e0f0f9a07 in row_purge_step (thr=thr@entry=0x555e11412ae8) at /mariadb/10.4m/storage/innobase/row/row0purge.cc:1476
#15 0x0000555e0f076f7f in que_thr_step (thr=<optimized out>) at /mariadb/10.4m/storage/innobase/que/que0que.cc:966
#16 que_run_threads_low (thr=0x555e11412ae8) at /mariadb/10.4m/storage/innobase/que/que0que.cc:1028
#17 que_run_threads (thr=0x555e11412ae8) at /mariadb/10.4m/storage/innobase/que/que0que.cc:1068
#18 0x0000555e0f1775fb in trx_purge (n_purge_threads=4, truncate=false, slot=slot@entry=0x555e0f4fb148 <srv_sys+584>) at /mariadb/10.4m/storage/innobase/trx/trx0purge.cc:1297
#19 0x0000555e0f1555f9 in srv_do_purge (slot=0x555e0f4fb148 <srv_sys+584>, n_total_purged=<optimized out>) at /mariadb/10.4m/storage/innobase/srv/srv0srv.cc:2579
#20 srv_purge_coordinator_thread (arg=<optimized out>) at /mariadb/10.4m/storage/innobase/srv/srv0srv.cc:2720
#21 0x00007f7b33ca63ec in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:444
#22 0x00007f7b33d26a4c in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

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