[MDEV-23318] Assertion `cache_empty(keycache)' failed in prepare_resize_simple_key_cache Created: 2020-07-28  Updated: 2020-10-06  Resolved: 2020-09-25

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - MyISAM
Affects Version/s: 10.4, 10.5
Fix Version/s: 10.4.16, 10.5.7

Type: Bug Priority: Minor
Reporter: Elena Stepanova Assignee: Michael Widenius
Resolution: Fixed Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-22590 SIGSEGV in flush_all_key_blocks when ... Closed

 Description   

Unfortunately the test scenario employs a combination of buggy functionality which I can't get rid of. First, it fails much more readily on the 2nd INSERT with endless variations of MDEV-21470 and alike, related to unique blobs; secondly, it can fail on the last line (restoring of the global key cache) with what looks like MDEV-22590; finally, DROP TABLE has also been seen to fail with a stack trace similar to MDEV-21755. So, not only the test case is non-deterministic (on whatever reason) and needs to be run with a high value of --repeat=N, but it also fails prematurely due to unrelated issues and has to be re-run many times before it hits the failure which this issue is about. Due to all of that, I'm setting it to Minor.

--source include/have_sequence.inc
 
SET @buffer_size.save= @@key_buffer_size;
SET GLOBAL key_buffer_size= 134217728;
SET myisam_repair_threads= 6;
 
CREATE TABLE t1 (
    pk INT AUTO_INCREMENT,
    a INTEGER,
    b DATE,
    c VARCHAR(1),
    d VARBINARY(40982),
    PRIMARY KEY (pk),
    KEY (a),
    KEY (b),
    KEY (c, a),
    UNIQUE (d)
) ENGINE=MyISAM;
 
INSERT INTO t1 (a,b,c) SELECT seq, '2020-12-12', 'x' FROM seq_1_to_20;
 
ALTER TABLE t1 DISABLE KEYS;
SET GLOBAL c.key_buffer_size= 13700864;
--error ER_WRONG_VALUE_COUNT_ON_ROW
INSERT INTO t1 SELECT 1;
SET  GLOBAL c.key_buffer_size= 0;
 
DROP TABLE t1;
SET GLOBAL key_buffer_size= @buffer_size.save;

10.5 3cb9131a

hash_link index: 19993
blocks: 10892  used: 0
hash_links: 22056  used: 0
 
hash_link index: 19993
blocks: 10892  used: 0
hash_links: 22056  used: 0
 
mariadbd: /data/src/10.5/mysys/mf_keycache.c:717: prepare_resize_simple_key_cache: Assertion `cache_empty(keycache)' failed.
200729  0:17:50 [ERROR] mysqld got signal 6 ;
 
#7  0x00007f6d7763cf12 in __GI___assert_fail (assertion=0x563daaab8fa8 "cache_empty(keycache)", file=0x563daaab8e70 "/data/src/10.5/mysys/mf_keycache.c", line=717, function=0x563daaabb220 <__PRETTY_FUNCTION__.12726> "prepare_resize_simple_key_cache") at assert.c:101
#8  0x0000563daa509e47 in prepare_resize_simple_key_cache (keycache=0x7f6d502d6c08, release_lock=0 '\000') at /data/src/10.5/mysys/mf_keycache.c:717
#9  0x0000563daa50a0b0 in resize_simple_key_cache (keycache=0x7f6d502d6c08, key_cache_block_size=1024, use_mem=0, division_limit=100, age_threshold=300, changed_blocks_hash_size=0) at /data/src/10.5/mysys/mf_keycache.c:852
#10 0x0000563daa5142ff in resize_key_cache (keycache=0x7f6d502d6a18, key_cache_block_size=1024, use_mem=0, division_limit=100, age_threshold=300, changed_blocks_hash_size=0) at /data/src/10.5/mysys/mf_keycache.c:6067
#11 0x0000563da9bfc162 in ha_resize_key_cache (key_cache=0x7f6d502d6a18) at /data/src/10.5/sql/handler.cc:5620
#12 0x0000563da9a4f52a in update_buffer_size (thd=0x7f6d50000b18, key_cache=0x7f6d502d6a18, offset=24, new_value=0) at /data/src/10.5/sql/sys_vars.ic:1089
#13 0x0000563da9a6800d in Sys_var_keycache::global_update (this=0x563dab42bb80 <Sys_key_buffer_size>, thd=0x7f6d50000b18, var=0x7f6d50013a40) at /data/src/10.5/sql/sys_vars.ic:1055
#14 0x0000563da9772731 in sys_var::update (this=0x563dab42bb80 <Sys_key_buffer_size>, thd=0x7f6d50000b18, var=0x7f6d50013a40) at /data/src/10.5/sql/set_var.cc:207
#15 0x0000563da97745f6 in set_var::update (this=0x7f6d50013a40, thd=0x7f6d50000b18) at /data/src/10.5/sql/set_var.cc:859
#16 0x0000563da977417c in sql_set_variables (thd=0x7f6d50000b18, var_list=0x7f6d50005a40, free=true) at /data/src/10.5/sql/set_var.cc:746
#17 0x0000563da989919d in mysql_execute_command (thd=0x7f6d50000b18) at /data/src/10.5/sql/sql_parse.cc:5008
#18 0x0000563da98a2d4d in mysql_parse (thd=0x7f6d50000b18, rawbuf=0x7f6d500138d0 "SET  GLOBAL c.key_buffer_size= 0", length=32, parser_state=0x7f6d70b7f520, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:7993
#19 0x0000563da988f046 in dispatch_command (command=COM_QUERY, thd=0x7f6d50000b18, packet=0x7f6d501af1e9 "SET  GLOBAL c.key_buffer_size= 0", packet_length=32, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:1867
#20 0x0000563da988d77e in do_command (thd=0x7f6d50000b18) at /data/src/10.5/sql/sql_parse.cc:1348
#21 0x0000563da9a3307a in do_handle_one_connection (connect=0x563dac9f8dc8, put_in_cache=true) at /data/src/10.5/sql/sql_connect.cc:1410
#22 0x0000563da9a32de2 in handle_one_connection (arg=0x563dac9f8dc8) at /data/src/10.5/sql/sql_connect.cc:1312
#23 0x0000563da9f71126 in pfs_spawn_thread (arg=0x563dac9f89f8) at /data/src/10.5/storage/perfschema/pfs.cc:2201
#24 0x00007f6d795c54a4 in start_thread (arg=0x7f6d70b80700) at pthread_create.c:456
#25 0x00007f6d776f9d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

Fails with some luck on 10.4-10.5. The test case is not applicable to earlier versions due to the use of unique blobs. It's unclear whether it has any effect on non-debug builds, since it fails in so many different ways.

Another failure which happens with the same test case is this:

Error: Freeing overrun buffer 0x7f0694e85880 at 0x5565121e09a1, mysys/safemalloc.c:194, mysys/my_malloc.c:210, myisam/mi_check.c:3111, myisam/ha_myisam.cc:1301, myisam/ha_myisam.cc:1646, myisam/ha_myisam.cc:1835, sql/handler.cc:4642
^ Found warnings in /dev/shm/var_mtr3/log/mysqld.1.err
ok

I can't tell whether it's related to the key cache problem or the virtual column / unique blob problem.



 Comments   
Comment by Michael Widenius [ 2020-09-17 ]

This problem happens when two threads in myisam repair are calling the code to calculate virtual fields at the same time.
Fixed by adding a mutex to ensure they don't change the table object at the same time
Pushed to bb-10.4-monty for testing

Comment by Michael Widenius [ 2020-09-25 ]

Review, testing and pushing

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