[MDEV-14062] Upgrade from 10.0 fails on assertion `!is_user_rec || n >= index->n_core_fields || n >= rec_offs_n_fields(offsets)' failed in rec_offs_make_valid Created: 2017-10-12  Updated: 2017-10-13  Resolved: 2017-10-13

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

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-11369 Instant add column for InnoDB Closed
Relates
relates to MDEV-14022 Upgrade from 10.0/10.1 fails on asser... Closed

 Description   

In MDEV-14022 we had an assertion failure upon 10.3 startup on the 10.0 directory. Now it starts, but fails upon further mysql_upgrade, specifically on

alter table mysql.innodb_index_stats modify last_update timestamp not null default current_timestamp on update current_timestamp

The data directory is the same, https://jira.mariadb.org/secure/attachment/44299/data-10.0.tar.gz

Unpack, start 10.3 server and either run mysql_upgrade or execute ALTER above.

10.3 f3ad3bbe7704

 
2017-10-12 21:04:03 9 [ERROR] InnoDB: Column last_update in table `mysql`.`innodb_table_stats` is INT UNSIGNED NOT NULL but should be BINARY(4) NOT NULL (type mismatch).
 
mysqld: /data/src/10.3/storage/innobase/rem/rem0rec.cc:484: void rec_offs_make_valid(const rec_t*, const dict_index_t*, bool, ulint*): Assertion `!is_user_rec || n >= index->n_core_fields || n >= rec_offs_n_fields(offsets)' failed.
 
171012 21:04:03 [ERROR] mysqld got signal 6 ;
 
 
 
#7  0x00007fd920cb9ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
 
#8  0x00005589d6fd1120 in rec_offs_make_valid (rec=0x7fd8b003ef47 "", index=0x5589db13d308, leaf=true, offsets=0x7fd92010ddb0) at /data/src/10.3/storage/innobase/rem/rem0rec.cc:483
 
#9  0x00005589d7049d05 in row_build_low (type=1, index=0x5589db13d308, rec=0x7fd8fc010279 "", offsets=0x7fd92010ddb0, col_table=0x0, add_cols=0x0, add_v=0x0, col_map=0x0, ext=0x0, heap=0x7fd8b003eeb0) at /data/src/10.3/storage/innobase/row/row0row.cc:439
 
#10 0x00005589d704a3f1 in row_build (type=1, index=0x5589db13d308, rec=0x7fd8fc010279 "", offsets=0x7fd92010ddb0, col_table=0x0, add_cols=0x0, col_map=0x0, ext=0x0, heap=0x7fd8b003eeb0) at /data/src/10.3/storage/innobase/row/row0row.cc:608
 
#11 0x00005589d707f674 in row_upd_store_row (node=0x7fd8b0048238, thd=0x7fd8b0000b00, mysql_table=0x0) at /data/src/10.3/storage/innobase/row/row0upd.cc:2218
 
#12 0x00005589d7081f7e in row_upd_del_mark_clust_rec (node=0x7fd8b0048238, index=0x5589db13d308, offsets=0x7fd92010e340, thr=0x7fd8b004bd58, referenced=0, foreign=0, mtr=0x7fd92010e660) at /data/src/10.3/storage/innobase/row/row0upd.cc:2973
 
#13 0x00005589d70829f9 in row_upd_clust_step (node=0x7fd8b0048238, thr=0x7fd8b004bd58) at /data/src/10.3/storage/innobase/row/row0upd.cc:3161
 
#14 0x00005589d7082f00 in row_upd (node=0x7fd8b0048238, thr=0x7fd8b004bd58) at /data/src/10.3/storage/innobase/row/row0upd.cc:3278
 
#15 0x00005589d70833f7 in row_upd_step (thr=0x7fd8b004bd58) at /data/src/10.3/storage/innobase/row/row0upd.cc:3422
 
#16 0x00005589d6fc569d in que_thr_step (thr=0x7fd8b004bd58) at /data/src/10.3/storage/innobase/que/que0que.cc:1036
 
#17 0x00005589d6fc59a5 in que_run_threads_low (thr=0x7fd8b004bd58) at /data/src/10.3/storage/innobase/que/que0que.cc:1116
 
#18 0x00005589d6fc5b87 in que_run_threads (thr=0x7fd8b004bd58) at /data/src/10.3/storage/innobase/que/que0que.cc:1156
 
#19 0x00005589d6fc5e28 in que_eval_sql (info=0x7fd8b000c788, sql=0x7fd8b002e288 "PROCEDURE DROP_TABLE_PROC () IS\nsys_foreign_id CHAR;\ntable_id CHAR;\nindex_id CHAR;\nforeign_id CHAR;\nspace_id INT;\nfound INT;\nDECLARE CURSOR cur_fk IS\nSELECT ID FROM SYS_FOREIGN\nWHERE FOR_NAME = :table"..., reserve_dict_mutex=0, trx=0x7fd90b3fd0d8) at /data/src/10.3/storage/innobase/que/que0que.cc:1233
 
#20 0x00005589d70224da in row_drop_table_for_mysql (name=0x7fd92010fa70 "mysql/#sql2-95a-9", trx=0x7fd90b3fd0d8, drop_db=false, create_failed=0, nonatomic=true) at /data/src/10.3/storage/innobase/row/row0mysql.cc:3973
 
#21 0x00005589d6eccb8d in ha_innobase::delete_table (this=0x7fd8b0016e58, name=0x7fd920111240 "./mysql/#sql2-95a-9") at /data/src/10.3/storage/innobase/handler/ha_innodb.cc:13385
 
#22 0x00005589d6b9ff46 in handler::ha_delete_table (this=0x7fd8b0016e58, name=0x7fd920111240 "./mysql/#sql2-95a-9") at /data/src/10.3/sql/handler.cc:4358
 
#23 0x00005589d6b9a2ce in ha_delete_table (thd=0x7fd8b0000b00, table_type=0x5589da32d0f0, path=0x7fd920111240 "./mysql/#sql2-95a-9", db=0x7fd8b00136a0 "mysql", alias=0x7fd920111b90 "#sql2-95a-9", generate_warning=false) at /data/src/10.3/sql/handler.cc:2359
 
#24 0x00005589d699ae70 in quick_rm_table (thd=0x7fd8b0000b00, base=0x5589da32d0f0, db=0x7fd8b00136a0 "mysql", table_name=0x7fd920111b90 "#sql2-95a-9", flags=3, table_path=0x0) at /data/src/10.3/sql/sql_table.cc:2742
 
#25 0x00005589d69acea6 in mysql_alter_table (thd=0x7fd8b0000b00, new_db=0x7fd8b00136a0 "mysql", new_name=0x0, create_info=0x7fd920112db0, table_list=0x7fd8b0013700, alter_info=0x7fd920112d00, order_num=0, order=0x0, ignore=false) at /data/src/10.3/sql/sql_table.cc:9485
 
#26 0x00005589d6a2ae7b in Sql_cmd_alter_table::execute (this=0x7fd8b0014048, thd=0x7fd8b0000b00) at /data/src/10.3/sql/sql_alter.cc:331
 
#27 0x00005589d68de172 in mysql_execute_command (thd=0x7fd8b0000b00) at /data/src/10.3/sql/sql_parse.cc:6236
 
#28 0x00005589d68e2a1c in mysql_parse (thd=0x7fd8b0000b00, rawbuf=0x7fd8b0013528 "alter table mysql.innodb_index_stats modify last_update timestamp not null default current_timestamp on update current_timestamp", length=128, parser_state=0x7fd920114660, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:7921
 
#29 0x00005589d68d01bd in dispatch_command (command=COM_QUERY, thd=0x7fd8b0000b00, packet=0x7fd8b001b751 "alter table mysql.innodb_index_stats modify last_update timestamp not null default current_timestamp on update current_timestamp", packet_length=128, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:1819
 
#30 0x00005589d68cec1b in do_command (thd=0x7fd8b0000b00) at /data/src/10.3/sql/sql_parse.cc:1370
 
#31 0x00005589d6a259f4 in do_handle_one_connection (connect=0x5589dae37df0) at /data/src/10.3/sql/sql_connect.cc:1418
 
#32 0x00005589d6a25781 in handle_one_connection (arg=0x5589dae37df0) at /data/src/10.3/sql/sql_connect.cc:1324
 
#33 0x00007fd922bfe494 in start_thread (arg=0x7fd920115700) at pthread_create.c:333
 
#34 0x00007fd920d7693f in clone () from /lib/x86_64-linux-gnu/libc.so.6



 Comments   
Comment by Marko Mäkelä [ 2017-10-13 ]

Basically the MDEV-14022 fix was too narrow, and we need to relax a similar assertion in the debug function rec_offs_make_valid().
Like MDEV-14022, this only affects debug builds (too strict assertions). The column SYS_INDEXES.MERGE_THRESHOLD was "instantly" added to MySQL 5.7 and to MariaDB 10.2.2.

diff --git a/storage/innobase/rem/rem0rec.cc b/storage/innobase/rem/rem0rec.cc
 
index 3fed98f0f3d..c9d35521708 100644
 
--- a/storage/innobase/rem/rem0rec.cc
 
+++ b/storage/innobase/rem/rem0rec.cc
 
@@ -480,7 +480,8 @@ rec_offs_make_valid(
 
 	/* The infimum and supremum records carry 1 field. */
 
 	ut_ad(is_user_rec || n == 1);
 
 	ut_ad(is_user_rec || rec_offs_n_fields(offsets) == 1);
 
-	ut_ad(!is_user_rec || n >= index->n_core_fields
 
+	ut_ad(!is_user_rec
 
+	      || (n + (index->id == DICT_INDEXES_ID)) >= index->n_core_fields
 
 	      || n >= rec_offs_n_fields(offsets));
 
 	for (; n < rec_offs_n_fields(offsets); n++) {
 
 		ut_ad(leaf);

elenst, please test if there are any other failures in this upgrade case before I push this fix to 10.3.

Comment by Elena Stepanova [ 2017-10-13 ]

10.3 f3ad3bbe7704d with the patch

 
2017-10-13 17:44:48 17 [ERROR] InnoDB: Column last_update in table `mysql`.`innodb_table_stats` is INT UNSIGNED NOT NULL but should be BINARY(4) NOT NULL (type mismatch).
 
mysqld: /data/src/10.3-bug/storage/innobase/include/dict0mem.h:1068: const byte* dict_index_t::instant_field_value(uint, ulint*) const: Assertion `is_instant()' failed.
 
 
 
#7  0x00007fc069db4ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
 
#8  0x00005588f92340c2 in dict_index_t::instant_field_value (this=0x5588fc672328, n=9, len=0x7fc054530720) at /data/src/10.3-bug/storage/innobase/include/dict0mem.h:1068
 
#9  0x00005588f93781b4 in row_build_low (type=1, index=0x5588fc672328, rec=0x7fc048010279 "", offsets=0x7fc054530bb0, col_table=0x5588fc670128, add_cols=0x0, add_v=0x0, col_map=0x0, ext=0x0, heap=0x7fbffc069640) at /data/src/10.3-bug/storage/innobase/row/row0row.cc:512
 
#10 0x00005588f937841f in row_build (type=1, index=0x5588fc672328, rec=0x7fc048010279 "", offsets=0x7fc054530bb0, col_table=0x0, add_cols=0x0, col_map=0x0, ext=0x0, heap=0x7fbffc069640) at /data/src/10.3-bug/storage/innobase/row/row0row.cc:608
 
#11 0x00005588f93ad6a2 in row_upd_store_row (node=0x7fbffc06d568, thd=0x7fbffc000b00, mysql_table=0x0) at /data/src/10.3-bug/storage/innobase/row/row0upd.cc:2218
 
#12 0x00005588f93affac in row_upd_del_mark_clust_rec (node=0x7fbffc06d568, index=0x5588fc672328, offsets=0x7fc054531140, thr=0x7fbffc071088, referenced=0, foreign=0, mtr=0x7fc054531460) at /data/src/10.3-bug/storage/innobase/row/row0upd.cc:2973
 
#13 0x00005588f93b0a27 in row_upd_clust_step (node=0x7fbffc06d568, thr=0x7fbffc071088) at /data/src/10.3-bug/storage/innobase/row/row0upd.cc:3161
 
#14 0x00005588f93b0f2e in row_upd (node=0x7fbffc06d568, thr=0x7fbffc071088) at /data/src/10.3-bug/storage/innobase/row/row0upd.cc:3278
 
#15 0x00005588f93b1425 in row_upd_step (thr=0x7fbffc071088) at /data/src/10.3-bug/storage/innobase/row/row0upd.cc:3422
 
#16 0x00005588f92f369d in que_thr_step (thr=0x7fbffc071088) at /data/src/10.3-bug/storage/innobase/que/que0que.cc:1036
 
#17 0x00005588f92f39a5 in que_run_threads_low (thr=0x7fbffc071088) at /data/src/10.3-bug/storage/innobase/que/que0que.cc:1116
 
#18 0x00005588f92f3b87 in que_run_threads (thr=0x7fbffc071088) at /data/src/10.3-bug/storage/innobase/que/que0que.cc:1156
 
#19 0x00005588f92f3e28 in que_eval_sql (info=0x7fbffc069328, sql=0x7fbffc4ce018 "PROCEDURE DROP_TABLE_PROC () IS\nsys_foreign_id CHAR;\ntable_id CHAR;\nindex_id CHAR;\nforeign_id CHAR;\nspace_id INT;\nfound INT;\nDECLARE CURSOR cur_fk IS\nSELECT ID FROM SYS_FOREIGN\nWHERE FOR_NAME = :table"..., reserve_dict_mutex=0, trx=0x7fc06811e0d8) at /data/src/10.3-bug/storage/innobase/que/que0que.cc:1233
 
#20 0x00005588f9350508 in row_drop_table_for_mysql (name=0x7fc054532870 "mysql/#sql2-1ed5-11", trx=0x7fc06811e0d8, drop_db=false, create_failed=0, nonatomic=true) at /data/src/10.3-bug/storage/innobase/row/row0mysql.cc:3973
 
#21 0x00005588f91fab8d in ha_innobase::delete_table (this=0x7fbffc016548, name=0x7fc054534040 "./mysql/#sql2-1ed5-11") at /data/src/10.3-bug/storage/innobase/handler/ha_innodb.cc:13385
 
#22 0x00005588f8ecdf46 in handler::ha_delete_table (this=0x7fbffc016548, name=0x7fc054534040 "./mysql/#sql2-1ed5-11") at /data/src/10.3-bug/sql/handler.cc:4358
 
#23 0x00005588f8ec82ce in ha_delete_table (thd=0x7fbffc000b00, table_type=0x5588fb862100, path=0x7fc054534040 "./mysql/#sql2-1ed5-11", db=0x7fbffc499680 "mysql", alias=0x7fc054534990 "#sql2-1ed5-11", generate_warning=false) at /data/src/10.3-bug/sql/handler.cc:2359
 
#24 0x00005588f8cc8e70 in quick_rm_table (thd=0x7fbffc000b00, base=0x5588fb862100, db=0x7fbffc499680 "mysql", table_name=0x7fc054534990 "#sql2-1ed5-11", flags=3, table_path=0x0) at /data/src/10.3-bug/sql/sql_table.cc:2742
 
#25 0x00005588f8cdaea6 in mysql_alter_table (thd=0x7fbffc000b00, new_db=0x7fbffc499680 "mysql", new_name=0x0, create_info=0x7fc054535bb0, table_list=0x7fbffc4996e0, alter_info=0x7fc054535b00, order_num=0, order=0x0, ignore=false) at /data/src/10.3-bug/sql/sql_table.cc:9485
 
#26 0x00005588f8d58e7b in Sql_cmd_alter_table::execute (this=0x7fbffc49a028, thd=0x7fbffc000b00) at /data/src/10.3-bug/sql/sql_alter.cc:331
 
#27 0x00005588f8c0c172 in mysql_execute_command (thd=0x7fbffc000b00) at /data/src/10.3-bug/sql/sql_parse.cc:6236
 
#28 0x00005588f8c2e35b in Prepared_statement::execute (this=0x7fbffc492470, expanded_query=0x7fc0545374e0, open_cursor=false) at /data/src/10.3-bug/sql/sql_prepare.cc:4729
 
#29 0x00005588f8c2c7a2 in Prepared_statement::execute_loop (this=0x7fbffc492470, expanded_query=0x7fc0545374e0, open_cursor=false, packet=0x0, packet_end=0x0) at /data/src/10.3-bug/sql/sql_prepare.cc:4158
 
#30 0x00005588f8c2a3f0 in mysql_sql_stmt_execute (thd=0x7fbffc000b00) at /data/src/10.3-bug/sql/sql_prepare.cc:3265
 
#31 0x00005588f8c036be in mysql_execute_command (thd=0x7fbffc000b00) at /data/src/10.3-bug/sql/sql_parse.cc:3747
 
#32 0x00005588f8c10a1c in mysql_parse (thd=0x7fbffc000b00, rawbuf=0x7fbffc0135c8 "execute stmt", length=12, parser_state=0x7fc054538660, is_com_multi=false, is_next_command=false) at /data/src/10.3-bug/sql/sql_parse.cc:7921
 
#33 0x00005588f8bfe1bd in dispatch_command (command=COM_QUERY, thd=0x7fbffc000b00, packet=0x7fbffc01b7f1 "", packet_length=12, is_com_multi=false, is_next_command=false) at /data/src/10.3-bug/sql/sql_parse.cc:1819
 
#34 0x00005588f8bfcc1b in do_command (thd=0x7fbffc000b00) at /data/src/10.3-bug/sql/sql_parse.cc:1370
 
#35 0x00005588f8d539f4 in do_handle_one_connection (connect=0x5588fc374bd0) at /data/src/10.3-bug/sql/sql_connect.cc:1418
 
#36 0x00005588f8d53781 in handle_one_connection (arg=0x5588fc374bd0) at /data/src/10.3-bug/sql/sql_connect.cc:1324
 
#37 0x00007fc06bcf9494 in start_thread (arg=0x7fc054539700) at pthread_create.c:333
 
#38 0x00007fc069e7193f in clone () from /lib/x86_64-linux-gnu/libc.so.6

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