[MDEV-30429] InnoDB: Failing assertion: stat_value != UINT64_UNDEFINED in storage/innobase/dict/dict0stats.cc line 3647 Created: 2023-01-18  Updated: 2023-01-26  Resolved: 2023-01-26

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.7.8, 10.6, 10.8, 10.9, 10.10, 10.11
Fix Version/s: 10.11.2, 10.6.12, 10.7.8, 10.8.7, 10.9.5, 10.10.3

Type: Bug Priority: Major
Reporter: Matthias Leich Assignee: Thirunarayanan Balathandayuthapani
Resolution: Fixed Votes: 0
Labels: rr-profile-analyzed

Attachments: File TBR-1730.cfg     File TBR-1730.yy    

 Description   

origin/10.7 d1a4f6e627b3ad2c86946da08b8e82909707da7c 2023-01-17T11:41:29+02:00
 
[rr 1292862 42382]2023-01-18 14:31:48 0x6aab7ab38700[rr 1292862 42385]  InnoDB: Assertion failure in file /data/Server/10.7B/storage/innobase/dict/dict0stats.cc line 3647
[rr 1292862 42387]InnoDB: Failing assertion: stat_value != UINT64_UNDEFINED
 
(rr) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x000021f1106b3859 in __GI_abort () at abort.c:79
#2  0x000055b07ef0a2f1 in ut_dbg_assertion_failed (expr=expr@entry=0x55b07fe7ce80 "stat_value != UINT64_UNDEFINED", file=file@entry=0x55b07fe75f40 "/data/Server/10.7B/storage/innobase/dict/dict0stats.cc", 
    line=line@entry=3647) at /data/Server/10.7B/storage/innobase/ut/ut0dbg.cc:60
#3  0x000055b07f137c92 in dict_stats_fetch_index_stats_step (node_void=<optimized out>, arg_void=<optimized out>) at /data/Server/10.7B/storage/innobase/dict/dict0stats.cc:3647
#4  0x000055b07edab468 in fetch_step (thr=thr@entry=0x6280000f7de8) at /data/Server/10.7B/storage/innobase/row/row0sel.cc:2475
#5  0x000055b07ec24c63 in que_thr_step (thr=0x6280000f7de8) at /data/Server/10.7B/storage/innobase/que/que0que.cc:581
#6  que_run_threads_low (thr=thr@entry=0x6280000f7de8) at /data/Server/10.7B/storage/innobase/que/que0que.cc:653
#7  0x000055b07ec254aa in que_run_threads (thr=0x6280000f7de8) at /data/Server/10.7B/storage/innobase/que/que0que.cc:673
#8  0x000055b07ec26ad4 in que_eval_sql (info=info@entry=0x616001da2508, 
    sql=sql@entry=0x55b07fe7bb40 "PROCEDURE FETCH_STATS () IS\nfound INT;\nDECLARE FUNCTION fetch_table_stats_step;\nDECLARE FUNCTION fetch_index_stats_step;\nDECLARE CURSOR table_stats_cur IS\n  SELECT\n  n_rows,\n  clustered_index_size,\n  "..., trx=trx@entry=0x356e22661440) at /data/Server/10.7B/storage/innobase/que/que0que.cc:712
#9  0x000055b07f134994 in dict_stats_fetch_from_ps (table=table@entry=0x61d000820b08) at /data/Server/10.7B/storage/innobase/dict/dict0stats.cc:3871
#10 0x000055b07f14a936 in dict_stats_update (table=table@entry=0x618000070908, stats_upd_option=DICT_STATS_FETCH_ONLY_IF_NOT_IN_MEMORY) at /data/Server/10.7B/storage/innobase/dict/dict0stats.cc:4160
#11 0x000055b07e932964 in dict_stats_init (table=0x618000070908) at /data/Server/10.7B/storage/innobase/include/dict0stats.inl:165
#12 ha_innobase::info_low (this=this@entry=0x61d0008200b8, flag=flag@entry=282, is_analyze=is_analyze@entry=false) at /data/Server/10.7B/storage/innobase/handler/ha_innodb.cc:14756
#13 0x000055b07e9345fe in ha_innobase::info (this=this@entry=0x61d0008200b8, flag=flag@entry=282) at /data/Server/10.7B/storage/innobase/handler/ha_innodb.cc:15020
#14 0x000055b07e936a89 in ha_innobase::open (this=0x61d0008200b8, name=<optimized out>) at /data/Server/10.7B/storage/innobase/handler/ha_innodb.cc:6176
#15 0x000055b07dfb79b8 in handler::ha_open (this=0x61d0008200b8, table_arg=table_arg@entry=0x619000478198, name=0x61b000061160 "./test/t1", mode=2, test_if_locked=test_if_locked@entry=18, 
    mem_root=mem_root@entry=0x0, partitions_to_open=0x0) at /data/Server/10.7B/sql/handler.cc:3348
#16 0x000055b07daa4e65 in open_table_from_share (thd=thd@entry=0x62b0001ce218, share=share@entry=0x61b000060bb8, alias=alias@entry=0x629000d483e0, db_stat=db_stat@entry=33, prgflag=prgflag@entry=8, 
    ha_open_flags=18, outparam=<optimized out>, is_create_table=<optimized out>, partitions_to_open=<optimized out>) at /data/Server/10.7B/sql/table.cc:4427
#17 0x000055b07d5506c6 in open_table (thd=thd@entry=0x62b0001ce218, table_list=table_list@entry=0x629000d48398, ot_ctx=ot_ctx@entry=0x6aab7ab34bb0) at /data/Server/10.7B/sql/sql_base.cc:2036
#18 0x000055b07d5540bb in open_and_process_table (thd=thd@entry=0x62b0001ce218, tables=tables@entry=0x629000d48398, counter=counter@entry=0x6aab7ab34cc0, flags=flags@entry=0, 
    prelocking_strategy=prelocking_strategy@entry=0x6aab7ab34e90, has_prelocking_list=has_prelocking_list@entry=false, ot_ctx=<optimized out>) at /data/Server/10.7B/sql/sql_base.cc:3847
#19 0x000055b07d55a4d9 in open_tables (thd=thd@entry=0x62b0001ce218, options=..., start=start@entry=0x6aab7ab34cd0, counter=counter@entry=0x6aab7ab34cc0, flags=flags@entry=0, 
    prelocking_strategy=prelocking_strategy@entry=0x6aab7ab34e90) at /data/Server/10.7B/sql/sql_base.cc:4330
#20 0x000055b07d55bc4a in open_and_lock_tables (thd=thd@entry=0x62b0001ce218, options=..., tables=tables@entry=0x629000d48398, derived=derived@entry=true, flags=flags@entry=0, 
    prelocking_strategy=prelocking_strategy@entry=0x6aab7ab34e90) at /data/Server/10.7B/sql/sql_base.cc:5303
#21 0x000055b07d62bdb9 in open_and_lock_tables (flags=0, derived=true, tables=0x629000d48398, thd=0x62b0001ce218) at /data/Server/10.7B/sql/sql_base.h:509
#22 mysql_insert (thd=thd@entry=0x62b0001ce218, table_list=0x629000d48398, fields=..., values_list=..., update_fields=..., update_values=..., duplic=<optimized out>, ignore=<optimized out>, 
    result=<optimized out>) at /data/Server/10.7B/sql/sql_insert.cc:758
#23 0x000055b07d706333 in mysql_execute_command (thd=thd@entry=0x62b0001ce218, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /data/Server/10.7B/sql/sql_parse.cc:4566
#24 0x000055b07d6c6e7d in mysql_parse (thd=thd@entry=0x62b0001ce218, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x6aab7ab36130)
    at /data/Server/10.7B/sql/sql_parse.cc:8017
#25 0x000055b07d6f5337 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x62b0001ce218, 
    packet=packet@entry=0x629000d3e219 "INSERT INTO t1 (col4) VALUES (NULL) /* E_R Thread1 QNO 25 CON_ID 15 */ ", packet_length=packet_length@entry=71, blocking=blocking@entry=true)
    at /data/Server/10.7B/sql/sql_class.h:1364
#26 0x000055b07d6fc01e in do_command (thd=0x62b0001ce218, blocking=blocking@entry=true) at /data/Server/10.7B/sql/sql_parse.cc:1407
#27 0x000055b07db6a441 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x608000003638, put_in_cache=put_in_cache@entry=true) at /data/Server/10.7B/sql/sql_connect.cc:1416
#28 0x000055b07db6af8a in handle_one_connection (arg=0x608000003638) at /data/Server/10.7B/sql/sql_connect.cc:1318
#29 0x0000718342348609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#30 0x000021f1107b0293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
(rr)
pluto:/data/results/1674052194/TBR-1730$ _RR_TRACE_DIR=./1/rr/ rr replay --mark-stdio
 
RQG
===
# git clone https://github.com/mleich1/rqg --branch <pick the right branch> RQG
#
# GIT_SHOW: HEAD -> master, origin/master, origin/HEAD 76ba3d6b1e1b417f22f80bb0cf8598089afd6cf9 2023-01-16T18:43:26+01:00
# rqg.pl  : Version 4.2.1 (2022-12)
#
# $RQG_HOME/rqg.pl \
# --duration=300 \
# --queries=10000000 \
# --no_mask \
# --seed=random \
# --gendata=conf/runtime/alter_online.zz \
# --rpl_mode=none \
# --max_gd_duration=1200 \
# --engine=InnoDB \
# --mysqld=--loose-idle_transaction_timeout=0 \
# --mysqld=--loose-innodb_read_only_compressed=OFF \
# --mysqld=--plugin-load-add=file_key_management.so \
# --mysqld=--wait_timeout=28800 \
# --mysqld=--loose-idle_write_transaction_timeout=0 \
# --mysqld=--loose-plugin-load-add=provider_lz4.so \
# --mysqld=--loose-idle_readonly_transaction_timeout=0 \
# --mysqld=--innodb-lock-wait-timeout=50 \
# --mysqld=--innodb-buffer-pool-size=24M \
# --mysqld=--loose-max-statement-time=30 \
# --mysqld=--net_read_timeout=30 \
# --mysqld=--log_bin_trust_function_creators=1 \
# --mysqld=--loose_innodb_lock_schedule_algorithm=fcfs \
# --mysqld=--innodb_page_size=64K \
# --mysqld=--log-output=none \
# --mysqld=--innodb_sort_buffer_size=65536 \
# --mysqld=--loose-innodb_fatal_semaphore_wait_threshold=300 \
# --mysqld=--file-key-management-filename=$RQG_HOME/conf/mariadb/encryption_keys.txt \
# --mysqld=--log-bin \
# --mysqld=--lock-wait-timeout=86400 \
# --mysqld=--net_write_timeout=60 \
# --mysqld=--sync-binlog=1 \
# --mysqld=--connect_timeout=60 \
# --mysqld=--slave_net_timeout=60 \
# --mysqld=--loose-table_lock_wait_timeout=50 \
# --mysqld=--loose-debug_assert_on_not_freed_memory=0 \
# --mysqld=--interactive_timeout=28800 \
# --reporters=Backtrace,Deadlock,None \
# --validators=None \
# --grammar=TBR-1730.yy \
# --threads=2 \
# <local settings>
 
TBR-1730.yy
------------------
query:
    { exit 0 } ;
 
thread1:
    insert_rolled_back ;
 
thread1_init:
    CREATE TABLE t1 (col4 TEXT) ENGINE = InnoDB ;
 
thread2:
    ALTER TABLE t1 ADD UNIQUE KEY uidx ( col4(10) ) |
    ALTER TABLE t1 ADD KEY idx ( col4(10) )         |
    insert_rolled_back |
    insert_rolled_back ;
 
thread2_init:
    ;
 
thread_connect:
    SET AUTOCOMMIT = 0, foreign_key_checks = 0, unique_checks = 0 ;
 
insert_rolled_back:
    INSERT INTO t1 (col4) VALUES (NULL); ROLLBACK ;



 Comments   
Comment by Thirunarayanan Balathandayuthapani [ 2023-01-25 ]

Patch is in bb-10.6-MDEV-30429

Comment by Marko Mäkelä [ 2023-01-25 ]

The patch looks reasonable to me.

Comment by Matthias Leich [ 2023-01-25 ]

Results of RQG testing on origin/bb-10.6-MDEV-30429 1b4919cfc061e71fc9e573ab1e736bd01dd3fc8a 2023-01-25T12:43:47+05:30

  • the uploaded test: No replay of the bad effect within ~ 1600 test runs. And also no other bad effect observed.
  • test battery for broad range functional coverage: Bad effects observed are in the main trees too.
Generated at Thu Feb 08 10:16:11 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.