[MDEV-13828] Segmentation fault on RENAME TABLE Created: 2017-09-17  Updated: 2018-05-24  Resolved: 2018-05-23

Status: Closed
Project: MariaDB Server
Component/s: Admin statements, Data Definition - Alter Table
Affects Version/s: 10.0, 10.1, 10.0.31, 10.2, 10.3
Fix Version/s: 10.0.36, 10.1.34, 10.2.16, 10.3.8

Type: Bug Priority: Major
Reporter: Guillaume Lefranc Assignee: Michael Widenius
Resolution: Fixed Votes: 0
Labels: affects-tests, ddl

Attachments: File mdev13828.threads     File mdev13828.threads.full    
Issue Links:
Duplicate
is duplicated by MDEV-14547 Mariadb restart Closed

 Description   

Hi, we've encountered this crash several times in MariaDB 10.0.31 when renaming tables (query is in the stack trace below). By looking really quick at the traces I assume that the segfault has something to do with the stat tables (rename_table_in_stat_tables function).
Note that the tables being renamed are MyISAM. use_stat_tables is set to NEVER, the stat tables are in good condition despite being unused. There's some test data in it but unrelated to the tables being renamed.

Sep 17 07:49:15 db-01 mysqld: 170917  7:49:15 [ERROR] mysqld got signal 11 ;
 
Sep 17 07:49:15 db-01 mysqld: This could be because you hit a bug. It is also possible that this binary
 
Sep 17 07:49:15 db-01 mysqld: or one of the libraries it was linked against is corrupt, improperly built,
 
Sep 17 07:49:15 db-01 mysqld: or misconfigured. This error can also be caused by malfunctioning hardware.
 
Sep 17 07:49:15 db-01 mysqld: 
Sep 17 07:49:15 db-01 mysqld: To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
Sep 17 07:49:15 db-01 mysqld: 
Sep 17 07:49:15 db-01 mysqld: We will try our best to scrape up some info that will hopefully help
 
Sep 17 07:49:15 db-01 mysqld: diagnose the problem, but since we have already crashed, 
Sep 17 07:49:15 db-01 mysqld: something is definitely wrong and this may fail.
 
Sep 17 07:49:15 db-01 mysqld: 
Sep 17 07:49:15 db-01 mysqld: Server version: 10.0.31-MariaDB-1~trusty
 
Sep 17 07:49:15 db-01 mysqld: key_buffer_size=33554432
 
Sep 17 07:49:15 db-01 mysqld: read_buffer_size=2097152
 
Sep 17 07:49:15 db-01 mysqld: max_used_connections=3808
 
Sep 17 07:49:15 db-01 mysqld: max_threads=501
 
Sep 17 07:49:15 db-01 mysqld: thread_count=469
 
Sep 17 07:49:15 db-01 mysqld: It is possible that mysqld could use up to 
Sep 17 07:49:15 db-01 mysqld: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 3210111 K  bytes of memory
 
Sep 17 07:49:15 db-01 mysqld: Hope that's ok; if not, decrease some variables in the equation.
 
Sep 17 07:49:15 db-01 mysqld: 
Sep 17 07:49:15 db-01 mysqld: Thread pointer: 0x7f9d4d489008
 
Sep 17 07:49:15 db-01 mysqld: Attempting backtrace. You can use the following information to find out
 
Sep 17 07:49:15 db-01 mysqld: where mysqld died. If you see no messages after this, something went
 
Sep 17 07:49:15 db-01 mysqld: terribly wrong...
 
Sep 17 07:49:15 db-01 mysqld: stack_bottom = 0x7f9d51c24d68 thread_stack 0x48000
 
Sep 17 07:49:15 db-01 mysqld: (my_addr_resolve failure: fork)
 
Sep 17 07:49:15 db-01 mysqld: /usr/sbin/mysqld(my_print_stacktrace+0x2e) [0xbe68be]
 
Sep 17 07:49:15 db-01 mysqld: /usr/sbin/mysqld(handle_fatal_signal+0x3b6) [0x7428d6]
 
Sep 17 07:49:15 db-01 mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0x10330) [0x7fa378c99330]
 
Sep 17 07:49:15 db-01 mysqld: /usr/sbin/mysqld() [0xb84de8]
 
Sep 17 07:49:15 db-01 mysqld: /usr/sbin/mysqld() [0xba954c]
 
Sep 17 07:49:15 db-01 mysqld: /usr/sbin/mysqld(handler::ha_index_read_map(unsigned char*, unsigned char const*, unsigned long, ha_rkey_function)+0x134) [0x7474a4]
 
Sep 17 07:49:15 db-01 mysqld: /usr/sbin/mysqld(rename_table_in_stat_tables(THD*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*)+0x3bc) [0x64d30c]
 
Sep 17 07:49:15 db-01 mysqld: /usr/sbin/mysqld() [0x5f08d0]
 
Sep 17 07:49:15 db-01 mysqld: /usr/sbin/mysqld(mysql_rename_tables(THD*, TABLE_LIST*, bool)+0x1a2) [0x5f0b42]
 
Sep 17 07:49:15 db-01 mysqld: /usr/sbin/mysqld(mysql_execute_command(THD*)+0x53d1) [0x5da4e1]
 
Sep 17 07:49:15 db-01 mysqld: /usr/sbin/mysqld(mysql_parse(THD*, char*, unsigned int, Parser_state*)+0x1ca) [0x5dc69a]
 
Sep 17 07:49:15 db-01 mysqld: /usr/sbin/mysqld(dispatch_command(enum_server_command, THD*, char*, unsigned int)+0x1bd3) [0x5de823]
 
Sep 17 07:49:15 db-01 mysqld: /usr/sbin/mysqld(threadpool_process_request(THD*)+0xfb) [0x6e3afb]
 
Sep 17 07:49:15 db-01 mysqld: /usr/sbin/mysqld() [0x714e6d]
 
Sep 17 07:49:15 db-01 mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0x8184) [0x7fa378c91184]
 
Sep 17 07:49:15 db-01 mysqld: /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d) [0x7fa377b74ffd]
 
Sep 17 07:49:15 db-01 mysqld: 
Sep 17 07:49:15 db-01 mysqld: Trying to get some variables.
 
Sep 17 07:49:15 db-01 mysqld: Some pointers may be invalid and cause the dump to abort.
 
Sep 17 07:49:15 db-01 mysqld: Query (0x7f9d345b718d): is an invalid pointer
 
Sep 17 07:49:15 db-01 mysqld: Connection ID (thread ID): 104455320
 
Sep 17 07:49:15 db-01 mysqld: Status: NOT_KILLED
 
Sep 17 07:49:15 db-01 mysqld: 
Sep 17 07:49:15 db-01 mysqld: 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
 
Sep 17 07:49:15 db-01 mysqld: 
Sep 17 07:49:15 db-01 mysqld: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
 
Sep 17 07:49:15 db-01 mysqld: information that should help you find out what is causing the crash.
 
Sep 17 07:49:15 db-01 mysqld: 
Sep 17 07:49:15 db-01 mysqld: We think the query pointer is invalid, but we will try to print it anyway. 
Sep 17 07:49:15 db-01 mysqld: Query: RENAME TABLE market_orders_gmni TO market_orders_gmni_atomic, market_orders_gmni_new  TO market_orders_gmni
 
Sep 17 07:49:15 db-01 mysqld: 
Sep 17 07:49:16 db-01 mysqld_safe: Number of processes running now: 0
 
Sep 17 07:49:16 db-01 mysqld_safe: mysqld restarted
 
Sep 17 07:49:17 db-01 mysqld: 170917  7:49:17 [Note] /usr/sbin/mysqld (mysqld 10.0.31-MariaDB-1~trusty) starting as process 6836 ...



 Comments   
Comment by Elena Stepanova [ 2017-09-18 ]

Could you please paste or attach your cnf file(s) and the output of SHOW CREATE TABLE for tables which are involved in a crashing query (the quoted one or any other one, if they are different)?
Thanks.

Comment by Guillaume Lefranc [ 2017-09-18 ]

Table structure

CREATE TABLE `market_orders` (
 
  `label` char(20) NOT NULL,
 
  `ordertype` tinyint(4) NOT NULL,
 
  `price` decimal(20,10) NOT NULL,
 
  `quantity` decimal(20,10) NOT NULL,
 
  `total` decimal(20,10) NOT NULL,
 
  `timestamp` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,
 
  KEY `idx_ob_extract` (`label`,`ordertype`)

Comment by Guillaume Lefranc [ 2017-09-18 ]

Config

[mysqld]
 
user		= mysql
 
pid-file	= /var/run/mysqld/mysqld.pid
 
socket		= /var/run/mysqld/mysqld.sock
 
port		= 3306
 
basedir		= /usr
 
datadir		= /data/mysql
 
tmpdir		= /data/mysqltmp
 
lc_messages_dir	= /usr/share/mysql
 
lc_messages	= en_US
 
skip-external-locking
 
 
 
event_scheduler = ON
 
 
 
log-bin
 
binlog_format = ROW
 
max_connections		= 5000
 
max_connect_errors      = 4294967295
 
connect_timeout		= 5
 
wait_timeout		= 600
 
max_allowed_packet	= 128M
 
thread_cache_size       = 128
 
sort_buffer_size	= 4M
 
bulk_insert_buffer_size	= 16M
 
tmp_table_size		= 32M
 
max_heap_table_size	= 32M
 
myisam_recover          = BACKUP
 
key_buffer_size		= 32M
 
open-files-limit	= 2000
 
table_open_cache	= 1024
 
table_definition_cache  = 1024
 
myisam_sort_buffer_size	= 512M
 
concurrent_insert	= 2
 
read_buffer_size	= 2M
 
read_rnd_buffer_size	= 1M
 
query_cache_limit		= 128K
 
query_cache_size		= 4M
 
log_warnings		= 1
 
slow_query_log = 1
 
slow_query_log_file	= /var/log/mysql/mariadb-slow.log
 
long_query_time = 0.1
 
log_slow_verbosity	= innodb,query_plan
 
server-id		= 183562539
 
report_host		= db-01
 
log_bin			= /logs/mariadb-bin
 
log_bin_index		= /logs/mariadb-bin.index
 
binlog_annotate_row_events = 1
 
binlog_commit_wait_count = 10
 
binlog_commit_wait_usec  = 10000
 
sync_binlog		= 1
 
expire_logs_days	= 3
 
default_storage_engine	= InnoDB
 
innodb_log_file_size	= 1G
 
innodb_buffer_pool_size	= 22620M
 
innodb_log_buffer_size	= 200M
 
innodb_file_per_table	= 1
 
innodb_open_files	= 400
 
innodb_io_capacity	= 3000		
innodb_flush_method	= O_DIRECT
 
innodb_file_format	= Barracuda
 
innodb_buffer_pool_instances = 1
 
innodb_flush_neighbors = 0		
innodb_checksum_algorithm = CRC32
 
innodb_adaptive_hash_index_partitions = 8      
innodb_buffer_pool_dump_at_shutdown=1	 
transaction_isolation = READ-COMMITTED
 
thread_handling=pool-of-threads

Comment by Alice Sherepa [ 2017-09-19 ]

are tables market_orders_gmni and market_orders_gmni_new identical to market_orders?

Comment by Elena Stepanova [ 2017-10-01 ]

tanj,
You mentioned that stat tables are in good condition. Are they in initial condition, structure-wise, or could they have been altered somehow? For example, can they by any chance be converted to InnoDB? Strange things are known to happen when system tables are converted to InnoDB, it's true for stat tables, too.

Comment by Guillaume Lefranc [ 2017-10-02 ]

Hi Elena,

Yes the tables are in good condition. I moved this database to a fresh installation of MariaDB 10.1.26 and the crash is still encountered.

Comment by Elena Stepanova [ 2017-10-02 ]

tanj, how often does it happen? Would you be able to produce a coredump and get all threads' stack trace from it? Given that you have ~500 connections running simultaneously, I assume turning on general log is not an option, but if it is, maybe it will also show something. Is it a production instance? Would it be possible to use a debug binary for one round until it crashes again?

Comment by Guillaume Lefranc [ 2017-10-02 ]

It happens every day, almost. See history of the latest crashes:

Sep 26 17:42:49 db-orders mysqld[613]: 170926 17:42:49 [ERROR] mysqld got signal 11 ;
Sep 27 01:14:46 db-orders mysqld[17099]: 170927 1:14:46 [ERROR] mysqld got signal 11 ;
Sep 28 03:29:15 db-orders mysqld[14274]: 170928 3:29:15 [ERROR] mysqld got signal 11 ;
Oct 01 21:21:40 db-orders mysqld[4990]: 171001 21:21:40 [ERROR] mysqld got signal 11 ;

I probably could run a debug bin / produce a coredump if you gave me some instructions, this is definitely a production DB and we are loading gigabytes of data per hour, so, the general log would be a bit hard to analyze.

Comment by Guillaume Lefranc [ 2017-10-02 ]

@alice all tables are identical FYI. The schema I posted is just a template.

Comment by Guillaume Lefranc [ 2017-10-02 ]

Are those instructions up-to-date?

https://mariadb.com/kb/en/library/building-mariadb-server-for-debugging/ I don't think there are any precompiled debug binaries...

Comment by Elena Stepanova [ 2017-10-02 ]

tanj, most of the are up-to-date, yes, this one is probably most relevant:
https://mariadb.com/kb/en/library/how-to-produce-a-full-stack-trace-for-mysqld/

There are no pre-compiled debug binaries, so the instructions include the compiling part; if you want, we can compile one for you. Are you using trusty 64-bit?

Comment by Guillaume Lefranc [ 2017-10-02 ]

I'm using xenial 64-bit. OK, I have enabled core-file in the mysql config and restarted it.

I've also installed `mariadb-server-10.1-dbgsym` , not sure if that is enough to produce debug information

Comment by Elena Stepanova [ 2017-10-02 ]

Xenial is better, at least I think we should be able to resolve your stack traces, even though they are not from debug binary. The one in the description was from trusty, for which we don't provide symbols, so I couldn't do much with it.

Comment by Guillaume Lefranc [ 2017-10-02 ]

Yes, the old server was indeed running trusty, and also held other schemas with different activity. That one only has the market_orders DB so it's easier to restart it without impacting the whole production.

I'll update this issue as soon as I have something generated.

Comment by Guillaume Lefranc [ 2017-10-08 ]

Hi elenst, the server crashed again this morning.
Please find the core dump at this location: https://we.tl/qdYoVp7pec

And this is the corresponding stack trace:

Oct 08 07:23:25 db-orders mysqld[5127]: 171008  7:23:25 [ERROR] mysqld got signal 11 ;
 
Oct 08 07:23:25 db-orders mysqld[5127]: This could be because you hit a bug. It is also possible that this binary
 
Oct 08 07:23:25 db-orders mysqld[5127]: or one of the libraries it was linked against is corrupt, improperly built,
 
Oct 08 07:23:25 db-orders mysqld[5127]: or misconfigured. This error can also be caused by malfunctioning hardware.
 
Oct 08 07:23:25 db-orders mysqld[5127]: To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
Oct 08 07:23:25 db-orders mysqld[5127]: We will try our best to scrape up some info that will hopefully help
 
Oct 08 07:23:25 db-orders mysqld[5127]: diagnose the problem, but since we have already crashed,
 
Oct 08 07:23:25 db-orders mysqld[5127]: something is definitely wrong and this may fail.
 
Oct 08 07:23:25 db-orders mysqld[5127]: Server version: 10.1.28-MariaDB-1~xenial
 
Oct 08 07:23:25 db-orders mysqld[5127]: key_buffer_size=33554432
 
Oct 08 07:23:25 db-orders mysqld[5127]: read_buffer_size=2097152
 
Oct 08 07:23:25 db-orders mysqld[5127]: max_used_connections=475
 
Oct 08 07:23:25 db-orders mysqld[5127]: max_threads=1001
 
Oct 08 07:23:25 db-orders mysqld[5127]: thread_count=72
 
Oct 08 07:23:25 db-orders mysqld[5127]: It is possible that mysqld could use up to
 
Oct 08 07:23:25 db-orders mysqld[5127]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 6286057 K  bytes of memory
 
Oct 08 07:23:25 db-orders mysqld[5127]: Hope that's ok; if not, decrease some variables in the equation.
 
Oct 08 07:23:25 db-orders mysqld[5127]: Thread pointer: 0x7fc7a5620008
 
Oct 08 07:23:25 db-orders mysqld[5127]: Attempting backtrace. You can use the following information to find out
 
Oct 08 07:23:25 db-orders mysqld[5127]: where mysqld died. If you see no messages after this, something went
 
Oct 08 07:23:25 db-orders mysqld[5127]: terribly wrong...
 
Oct 08 07:23:25 db-orders mysqld[5127]: stack_bottom = 0x7fc7d19a3ff8 thread_stack 0x48400
 
Oct 08 07:23:25 db-orders mysqld[5127]: /usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x55f1d764754e]
 
Oct 08 07:23:25 db-orders mysqld[5127]: /usr/sbin/mysqld(handle_fatal_signal+0x2f5)[0x55f1d7190005]
 
Oct 08 07:23:25 db-orders mysqld[5127]: /lib/x86_64-linux-gnu/libpthread.so.0(+0x11390)[0x7fc7ea257390]
 
Oct 08 07:23:25 db-orders mysqld[5127]: /usr/sbin/mysqld(+0x7dbc0e)[0x55f1d73cbc0e]
 
Oct 08 07:23:26 db-orders mysqld[5127]: /usr/sbin/mysqld(+0x800dbc)[0x55f1d73f0dbc]
 
Oct 08 07:23:26 db-orders mysqld[5127]: /usr/sbin/mysqld(_ZN7handler17ha_index_read_mapEPhPKhm16ha_rkey_function+0x211)[0x55f1d71954a1]
 
Oct 08 07:23:26 db-orders mysqld[5127]: /usr/sbin/mysqld(_Z27rename_table_in_stat_tablesP3THDP19st_mysql_lex_stringS2_S2_S2_+0x594)[0x55f1d707b714]
 
Oct 08 07:23:26 db-orders mysqld[5127]: /usr/sbin/mysqld(+0x4287d2)[0x55f1d70187d2]
 
Oct 08 07:23:26 db-orders mysqld[5127]: /usr/sbin/mysqld(_Z19mysql_rename_tablesP3THDP10TABLE_LISTb+0x1ae)[0x55f1d7018a6e]
 
Oct 08 07:23:26 db-orders mysqld[5127]: /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x58e3)[0x55f1d6fff0b3]
 
Oct 08 07:23:26 db-orders mysqld[5127]: /usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x311)[0x55f1d7002ce1]
 
Oct 08 07:23:26 db-orders mysqld[5127]: /usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x22e8)[0x55f1d7006178]
 
Oct 08 07:23:26 db-orders mysqld[5127]: /usr/sbin/mysqld(_Z10do_commandP3THD+0x139)[0x55f1d7006c09]
 
Oct 08 07:23:26 db-orders mysqld[5127]: /usr/sbin/mysqld(_Z26threadpool_process_requestP3THD+0xff)[0x55f1d7115c9f]
 
Oct 08 07:23:26 db-orders mysqld[5127]: /usr/sbin/mysqld(+0x577805)[0x55f1d7167805]
 
Oct 08 07:23:26 db-orders mysqld[5127]: /lib/x86_64-linux-gnu/libpthread.so.0(+0x76ba)[0x7fc7ea24d6ba]
 
Oct 08 07:23:26 db-orders mysqld[5127]: /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7fc7e98f83dd]
 
Oct 08 07:23:26 db-orders mysqld[5127]: Trying to get some variables.

Comment by Elena Stepanova [ 2017-10-08 ]

tanj, thank you. Here is the stack trace from the coredump:

10.1.28+maria-1~xenial

 
#3  <signal handler called>
 
#4  0x000055f1d73cbc0e in _mi_pack_key (info=info@entry=0x7fc7b4e29008, keynr=keynr@entry=64, key=key@entry=0x7fc7b4e2b05e "\rmarket_orders\022market_orders_itbt_atomic", old=0x7fc7d19a1050 "\r", keypart_map=keypart_map@entry=3, last_used_keyseg=last_used_keyseg@entry=0x7fc7d199f988) at /home/buildbot/buildbot/build/mariadb-10.1.28/storage/myisam/mi_key.c:234
 
#5  0x000055f1d73f0dbc in mi_rkey (info=0x7fc7b4e29008, buf=0x7fc7ac5a6120 "\377\rmarket_orders", inx=64, key=<optimized out>, keypart_map=3, search_flag=HA_READ_KEY_EXACT) at /home/buildbot/buildbot/build/mariadb-10.1.28/storage/myisam/mi_rkey.c:62
 
#6  0x000055f1d71954a1 in handler::ha_index_read_map (this=this@entry=0x7fc7b1dcdb20, buf=0x7fc7ac5a6120 "\377\rmarket_orders", key=key@entry=0x7fc7d19a1050 "\r", keypart_map=keypart_map@entry=3, find_flag=find_flag@entry=HA_READ_KEY_EXACT) at /home/buildbot/buildbot/build/mariadb-10.1.28/sql/handler.cc:2652
 
#7  0x000055f1d707b714 in Stat_table_write_iter::init (n_keyparts=2, this=0x7fc7d19a0e30) at /home/buildbot/buildbot/build/mariadb-10.1.28/sql/sql_statistics.cc:1464
 
#8  rename_table_in_stat_tables (thd=thd@entry=0x7fc7a5620008, db=db@entry=0x7fc7d19a1cf0, tab=tab@entry=0x7fc7d19a1d00, new_db=new_db@entry=0x7fc7d19a1d20, new_tab=new_tab@entry=0x7fc7d19a1d10) at /home/buildbot/buildbot/build/mariadb-10.1.28/sql/sql_statistics.cc:3547
 
#9  0x000055f1d70187d2 in do_rename (skip_error=false, new_table_alias=<optimized out>, new_table_name=<optimized out>, new_db=0x7fc7acbf5f58 "market_orders", ren_table=0x7fc7acbf5350, thd=0x7fc7a5620008) at /home/buildbot/buildbot/build/mariadb-10.1.28/sql/sql_rename.cc:301
 
#10 rename_tables (thd=thd@entry=0x7fc7a5620008, table_list=table_list@entry=0x7fc7acbf4698, skip_error=skip_error@entry=false) at /home/buildbot/buildbot/build/mariadb-10.1.28/sql/sql_rename.cc:379
 
#11 0x000055f1d7018a6e in mysql_rename_tables (thd=thd@entry=0x7fc7a5620008, table_list=table_list@entry=0x7fc7acbf4698, silent=silent@entry=false) at /home/buildbot/buildbot/build/mariadb-10.1.28/sql/sql_rename.cc:153
 
#12 0x000055f1d6fff0b3 in mysql_execute_command (thd=thd@entry=0x7fc7a5620008) at /home/buildbot/buildbot/build/mariadb-10.1.28/sql/sql_parse.cc:3644
 
#13 0x000055f1d7002ce1 in mysql_parse (thd=thd@entry=0x7fc7a5620008, rawbuf=rawbuf@entry=0x7fc7acbf018d "RENAME TABLE market_orders_ccjp TO market_orders_ccjp_atomic, market_orders_ccjp_new  TO market_orders_ccjp;  DROP TABLE market_orders_ccjp_atomic", length=length@entry=146, parser_state=parser_state@entry=0x7fc7d19a33a0) at /home/buildbot/buildbot/build/mariadb-10.1.28/sql/sql_parse.cc:7333
 
#14 0x000055f1d7006178 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7fc7a5620008, packet=packet@entry=0x7fc7a7482009 "", packet_length=packet_length@entry=511) at /home/buildbot/buildbot/build/mariadb-10.1.28/sql/sql_parse.cc:1571
 
#15 0x000055f1d7006c09 in do_command (thd=thd@entry=0x7fc7a5620008) at /home/buildbot/buildbot/build/mariadb-10.1.28/sql/sql_parse.cc:1106
 
#16 0x000055f1d7115c9f in threadpool_process_request (thd=0x7fc7a5620008) at /home/buildbot/buildbot/build/mariadb-10.1.28/sql/threadpool_common.cc:271
 
#17 0x000055f1d7167805 in handle_event (connection=0x7fc7a4842208) at /home/buildbot/buildbot/build/mariadb-10.1.28/sql/threadpool_unix.cc:1452
 
#18 worker_main (param=0x7fc7d179b008) at /home/buildbot/buildbot/build/mariadb-10.1.28/sql/threadpool_unix.cc:1500
 
#19 0x00007fc7ea24d6ba in start_thread (arg=0x7fc7d19a4b00) at pthread_create.c:333
 
#20 0x00007fc7e98f83dd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

All threads' stack trace is attached . mdev13828.threads mdev13828.threads.full

Comment by Elena Stepanova [ 2017-10-08 ]

The stack trace seems pretty simple, only two transactions, both doing similar RENAME / DROP on different tables, one in lock waiting and another one crashing with bad data

(gdb) p keynr
 
$20 = 64
 
(gdb) p info->s->keyinfo[keynr].seg
 
$21 = (HA_KEYSEG *) 0x0

However, I can't reproduce the crash with stress tests.

tanj, the table definition that you pasted earlier is incomplete, can there be some other keys or unusual flags on the table, or can definiitions of other tables involved into the crash be different? How are new tables are created, is it via LIKE, or via CREATE .. SELECT, or in some other way? Are the old and new tables empty, or if not, how big can they be?

Comment by Guillaume Lefranc [ 2017-10-08 ]

elenst the table definition is complete. There is no PK, only a regular key. Maybe ENGINE=MyISAM is missing, but we're not using InnoDB for those tables anyway.

This is the workflow we use to create, fill and drop the tables:

                12430630 Query  DROP TABLE IF EXISTS market_orders_gmni_new ;  DROP TABLE IF EXISTS market_orders_gmni_atomic;  CREATE TABLE market_orders_gmni_new  LIKE market_orders_gmni;
 
 LOAD DATA LOCAL INFILE '/data/market_orders/GMNI_orders.csv'
 
 REPLACE
 
 INTO TABLE market_orders_gmni_new
 
 FIELDS TERMINATED BY ','
 
 ENCLOSED BY '"'
 
 LINES TERMINATED BY '\n'
 
 IGNORE 1 LINES
 
;
 
  RENAME TABLE market_orders_gmni TO market_orders_gmni_atomic, market_orders_gmni_new  TO market_orders_gmni;  DROP TABLE market_orders_gmni_atomic

The data size is typically small, can be up to a couple of hundred thousand rows, nothing out of the ordinary. In the crash above the affected table was market_orders_itbt which has 558 rows at the moment. I haven't seen crashes hitting a particular market table, it's fairly random.

I'm happy to give you access to more data if you need.

Comment by Elena Stepanova [ 2017-12-25 ] 

CREATE TABLE t1 (i int);
 
 
 
--connect (con1,localhost,root,,test)
 
--send
 
RENAME TABLE t1 TO t2;
 
--connection default
 
FLUSH TABLES;
 
--connection con1
 
--reap
 
 
 
# Cleanup
 
--disconnect con1
 
--connection default
 
DROP TABLE IF EXISTS t1, t2;

10.0 4b8cd4536a2c6 debug ASAN

 
ERROR: AddressSanitizer: heap-use-after-free on address 0x61c00006f298 at pc 0x8457dc bp 0x7f10ec3a0f30 sp 0x7f10ec3a0f28
 
READ of size 4 at 0x61c00006f298 thread T6
 
    #0 0x8457db in handler::ha_index_or_rnd_end() /data/src/10.0/sql/handler.h:2682
 
    #1 0x8457db in Stat_table_write_iter::cleanup() /data/src/10.0/sql/sql_statistics.cc:1372
 
    #2 0x8457db in ~Stat_table_write_iter /data/src/10.0/sql/sql_statistics.cc:1379
 
    #3 0x8457db in rename_table_in_stat_tables(THD*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*) /data/src/10.0/sql/sql_statistics.cc:3429
 
    #4 0x713de1 in do_rename /data/src/10.0/sql/sql_rename.cc:301
 
    #5 0x713de1 in rename_tables /data/src/10.0/sql/sql_rename.cc:379
 
    #6 0x7145ba in mysql_rename_tables(THD*, TABLE_LIST*, bool) /data/src/10.0/sql/sql_rename.cc:153
 
    #7 0x6d3a24 in execute_rename_table /data/src/10.0/sql/sql_parse.cc:5363
 
    #8 0x6d3a24 in mysql_execute_command(THD*) /data/src/10.0/sql/sql_parse.cc:3188
 
    #9 0x6e19f7 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /data/src/10.0/sql/sql_parse.cc:6569
 
    #10 0x6e5616 in dispatch_command(enum_server_command, THD*, char*, unsigned int) /data/src/10.0/sql/sql_parse.cc:1296
 
    #11 0x6e9f0f in do_command(THD*) /data/src/10.0/sql/sql_parse.cc:999
 
    #12 0x975c3b in do_handle_one_connection(THD*) /data/src/10.0/sql/sql_connect.cc:1377
 
    #13 0x975ea2 in handle_one_connection /data/src/10.0/sql/sql_connect.cc:1292
 
    #14 0x11a95d4 in pfs_spawn_thread /data/src/10.0/storage/perfschema/pfs.cc:1861
 
    #15 0x7f10f6e2a493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493)
 
    #16 0x7f10f51e393e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe893e)
 
 
 
0x61c00006f298 is located 536 bytes inside of 1884-byte region [0x61c00006f080,0x61c00006f7dc)
 
    #0 0x7f10f7094527 in __interceptor_free (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x54527)
 
    #1 0x18e68b3 in free_memory /data/src/10.0/mysys/safemalloc.c:276
 
 
 
previously allocated by thread T6 here:
 
    #0 0x7f10f709473f in malloc (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x5473f)
 
    #1 0x18e6986 in sf_malloc /data/src/10.0/mysys/safemalloc.c:115
 
    #2 0x19c964a (/data/bld/10.0-asan/bin/mysqld+0x19c964a)
 
 
 
Thread T6 created by T0 here:
 
    #0 0x7f10f7063bba in pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x23bba)
 
    #1 0x11b4e2b in spawn_thread_v1 /data/src/10.0/storage/perfschema/pfs.cc:1911
 
 
 
SUMMARY: AddressSanitizer: heap-use-after-free /data/src/10.0/sql/handler.h:2682 handler::ha_index_or_rnd_end()
 
Shadow bytes around the buggy address:
 
  0x0c3880005e00: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c3880005e10: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3880005e20: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3880005e30: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3880005e40: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
=>0x0c3880005e50: fd fd fd[fd]fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3880005e60: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3880005e70: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3880005e80: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3880005e90: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3880005ea0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
Shadow byte legend (one shadow byte represents 8 application bytes):
 
  Addressable:           00
 
  Partially addressable: 01 02 03 04 05 06 07 
  Heap left redzone:       fa
 
  Heap right redzone:      fb
 
  Freed heap region:       fd
 
  Stack left redzone:      f1
 
  Stack mid redzone:       f2
 
  Stack right redzone:     f3
 
  Stack partial redzone:   f4
 
  Stack after return:      f5
 
  Stack use after scope:   f8
 
  Global redzone:          f9
 
  Global init order:       f6
 
  Poisoned by user:        f7
 
  Contiguous container OOB:fc
 
  ASan internal:           fe

10.1 db3bdca7c298 debug + valgrind

 
==12731== Invalid read of size 4
 
==12731==    at 0x5B8F12: handler::ha_index_or_rnd_end() (handler.h:2820)
 
==12731==    by 0x68BF44: Stat_table_write_iter::cleanup() (sql_statistics.cc:1514)
 
==12731==    by 0x68BF7F: Stat_table_write_iter::~Stat_table_write_iter() (sql_statistics.cc:1521)
 
==12731==    by 0x6882C8: rename_table_in_stat_tables(THD*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*) (sql_statistics.cc:3562)
 
==12731==    by 0x608389: do_rename(THD*, TABLE_LIST*, char*, char*, char*, bool) (sql_rename.cc:301)
 
==12731==    by 0x6085BD: rename_tables(THD*, TABLE_LIST*, bool) (sql_rename.cc:379)
 
==12731==    by 0x607E59: mysql_rename_tables(THD*, TABLE_LIST*, bool) (sql_rename.cc:153)
 
==12731==    by 0x5DFCE8: mysql_execute_command(THD*) (sql_parse.cc:3638)
 
==12731==    by 0x5EB2C2: mysql_parse(THD*, char*, unsigned int, Parser_state*) (sql_parse.cc:7347)
 
==12731==    by 0x5DA185: dispatch_command(enum_server_command, THD*, char*, unsigned int) (sql_parse.cc:1477)
 
==12731==    by 0x5D8F0A: do_command(THD*) (sql_parse.cc:1106)
 
==12731==    by 0x716FC0: do_handle_one_connection(THD*) (sql_connect.cc:1330)
 
==12731==    by 0x716D24: handle_one_connection (sql_connect.cc:1242)
 
==12731==    by 0xAF1D77: pfs_spawn_thread (pfs.cc:1861)
 
==12731==    by 0x4E3F493: start_thread (pthread_create.c:333)
 
==12731==    by 0x6AC793E: clone (clone.S:97)
 
==12731==  Address 0xddedbc8 is 440 bytes inside a block of size 1,792 free'd
 
==12731==    at 0x4C2CDDB: free (vg_replace_malloc.c:530)
 
==12731==    by 0xED9977: my_free (my_malloc.c:217)
 
==12731==    by 0xECAC27: free_root (my_alloc.c:389)
 
==12731==    by 0x6D2DB0: closefrm(TABLE*, bool) (table.cc:3085)
 
==12731==    by 0x56FC54: intern_close_table(TABLE*) (sql_base.cc:354)
 
==12731==    by 0x7AC3F9: tc_release_table(TABLE*) (table_cache.cc:360)
 
==12731==    by 0x571359: close_thread_table(THD*, TABLE**) (sql_base.cc:1089)
 
==12731==    by 0x570B35: close_open_tables(THD*) (sql_base.cc:812)
 
==12731==    by 0x5710E3: close_thread_tables(THD*) (sql_base.cc:1036)
 
==12731==    by 0x58283E: close_system_tables(THD*, Open_tables_backup*) (sql_base.cc:9313)
 
==12731==    by 0x688299: rename_table_in_stat_tables(THD*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*) (sql_statistics.cc:3587)
 
==12731==    by 0x608389: do_rename(THD*, TABLE_LIST*, char*, char*, char*, bool) (sql_rename.cc:301)
 
==12731==    by 0x6085BD: rename_tables(THD*, TABLE_LIST*, bool) (sql_rename.cc:379)
 
==12731==    by 0x607E59: mysql_rename_tables(THD*, TABLE_LIST*, bool) (sql_rename.cc:153)
 
==12731==    by 0x5DFCE8: mysql_execute_command(THD*) (sql_parse.cc:3638)
 
==12731==    by 0x5EB2C2: mysql_parse(THD*, char*, unsigned int, Parser_state*) (sql_parse.cc:7347)
 
==12731==  Block was alloc'd at
 
==12731==    at 0x4C2BBAF: malloc (vg_replace_malloc.c:299)
 
==12731==    by 0xED9490: my_malloc (my_malloc.c:101)
 
==12731==    by 0xECA61F: alloc_root (my_alloc.c:184)
 
==12731==    by 0x518C78: Sql_alloc::operator new(unsigned long, st_mem_root*) (sql_list.h:43)
 
==12731==    by 0xB0C406: myisam_create_handler(handlerton*, TABLE_SHARE*, st_mem_root*) (ha_myisam.cc:129)
 
==12731==    by 0x826E3E: get_new_handler(TABLE_SHARE*, st_mem_root*, handlerton*) (handler.cc:265)
 
==12731==    by 0x6D1987: open_table_from_share(THD*, TABLE_SHARE*, char const*, unsigned int, unsigned int, unsigned int, TABLE*, bool) (table.cc:2666)
 
==12731==    by 0x5741C3: open_table(THD*, TABLE_LIST*, Open_table_context*) (sql_base.cc:2553)
 
==12731==    by 0x576A30: open_and_process_table(THD*, LEX*, TABLE_LIST*, unsigned int*, unsigned int, Prelocking_strategy*, bool, Open_table_context*) (sql_base.cc:4068)
 
==12731==    by 0x577AAB: open_tables(THD*, DDL_options_st const&, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*) (sql_base.cc:4579)
 
==12731==    by 0x578DE5: open_and_lock_tables(THD*, DDL_options_st const&, TABLE_LIST*, bool, unsigned int, Prelocking_strategy*) (sql_base.cc:5259)
 
==12731==    by 0x56C4CA: open_and_lock_tables(THD*, TABLE_LIST*, bool, unsigned int) (sql_base.h:535)
 
==12731==    by 0x58270D: open_system_tables_for_read(THD*, TABLE_LIST*, Open_tables_backup*) (sql_base.cc:9279)
 
==12731==    by 0x684B57: open_stat_tables(THD*, TABLE_LIST*, Open_tables_backup*, bool) (sql_statistics.cc:270)
 
==12731==    by 0x687FA0: rename_table_in_stat_tables(THD*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*) (sql_statistics.cc:3536)
 
==12731==    by 0x608389: do_rename(THD*, TABLE_LIST*, char*, char*, char*, bool) (sql_rename.cc:301)
 
==12731== Invalid read of size 4
 
==12731==    at 0x5B8F2F: handler::ha_index_or_rnd_end() (handler.h:2820)
 
==12731==    by 0x68BF44: Stat_table_write_iter::cleanup() (sql_statistics.cc:1514)
 
==12731==    by 0x68BF7F: Stat_table_write_iter::~Stat_table_write_iter() (sql_statistics.cc:1521)
 
==12731==    by 0x6882C8: rename_table_in_stat_tables(THD*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*) (sql_statistics.cc:3562)
 
==12731==    by 0x608389: do_rename(THD*, TABLE_LIST*, char*, char*, char*, bool) (sql_rename.cc:301)
 
==12731==    by 0x6085BD: rename_tables(THD*, TABLE_LIST*, bool) (sql_rename.cc:379)
 
==12731==    by 0x607E59: mysql_rename_tables(THD*, TABLE_LIST*, bool) (sql_rename.cc:153)
 
==12731==    by 0x5DFCE8: mysql_execute_command(THD*) (sql_parse.cc:3638)
 
==12731==    by 0x5EB2C2: mysql_parse(THD*, char*, unsigned int, Parser_state*) (sql_parse.cc:7347)
 
==12731==    by 0x5DA185: dispatch_command(enum_server_command, THD*, char*, unsigned int) (sql_parse.cc:1477)
 
==12731==    by 0x5D8F0A: do_command(THD*) (sql_parse.cc:1106)
 
==12731==    by 0x716FC0: do_handle_one_connection(THD*) (sql_connect.cc:1330)
 
==12731==    by 0x716D24: handle_one_connection (sql_connect.cc:1242)
 
==12731==    by 0xAF1D77: pfs_spawn_thread (pfs.cc:1861)
 
==12731==    by 0x4E3F493: start_thread (pthread_create.c:333)
 
==12731==    by 0x6AC793E: clone (clone.S:97)
 
==12731==  Address 0xddedbc8 is 440 bytes inside a block of size 1,792 free'd
 
==12731==    at 0x4C2CDDB: free (vg_replace_malloc.c:530)
 
==12731==    by 0xED9977: my_free (my_malloc.c:217)
 
==12731==    by 0xECAC27: free_root (my_alloc.c:389)
 
==12731==    by 0x6D2DB0: closefrm(TABLE*, bool) (table.cc:3085)
 
==12731==    by 0x56FC54: intern_close_table(TABLE*) (sql_base.cc:354)
 
==12731==    by 0x7AC3F9: tc_release_table(TABLE*) (table_cache.cc:360)
 
==12731==    by 0x571359: close_thread_table(THD*, TABLE**) (sql_base.cc:1089)
 
==12731==    by 0x570B35: close_open_tables(THD*) (sql_base.cc:812)
 
==12731==    by 0x5710E3: close_thread_tables(THD*) (sql_base.cc:1036)
 
==12731==    by 0x58283E: close_system_tables(THD*, Open_tables_backup*) (sql_base.cc:9313)
 
==12731==    by 0x688299: rename_table_in_stat_tables(THD*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*) (sql_statistics.cc:3587)
 
==12731==    by 0x608389: do_rename(THD*, TABLE_LIST*, char*, char*, char*, bool) (sql_rename.cc:301)
 
==12731==    by 0x6085BD: rename_tables(THD*, TABLE_LIST*, bool) (sql_rename.cc:379)
 
==12731==    by 0x607E59: mysql_rename_tables(THD*, TABLE_LIST*, bool) (sql_rename.cc:153)
 
==12731==    by 0x5DFCE8: mysql_execute_command(THD*) (sql_parse.cc:3638)
 
==12731==    by 0x5EB2C2: mysql_parse(THD*, char*, unsigned int, Parser_state*) (sql_parse.cc:7347)
 
==12731==  Block was alloc'd at
 
==12731==    at 0x4C2BBAF: malloc (vg_replace_malloc.c:299)
 
==12731==    by 0xED9490: my_malloc (my_malloc.c:101)
 
==12731==    by 0xECA61F: alloc_root (my_alloc.c:184)
 
==12731==    by 0x518C78: Sql_alloc::operator new(unsigned long, st_mem_root*) (sql_list.h:43)
 
==12731==    by 0xB0C406: myisam_create_handler(handlerton*, TABLE_SHARE*, st_mem_root*) (ha_myisam.cc:129)
 
==12731==    by 0x826E3E: get_new_handler(TABLE_SHARE*, st_mem_root*, handlerton*) (handler.cc:265)
 
==12731==    by 0x6D1987: open_table_from_share(THD*, TABLE_SHARE*, char const*, unsigned int, unsigned int, unsigned int, TABLE*, bool) (table.cc:2666)
 
==12731==    by 0x5741C3: open_table(THD*, TABLE_LIST*, Open_table_context*) (sql_base.cc:2553)
 
==12731==    by 0x576A30: open_and_process_table(THD*, LEX*, TABLE_LIST*, unsigned int*, unsigned int, Prelocking_strategy*, bool, Open_table_context*) (sql_base.cc:4068)
 
==12731==    by 0x577AAB: open_tables(THD*, DDL_options_st const&, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*) (sql_base.cc:4579)
 
==12731==    by 0x578DE5: open_and_lock_tables(THD*, DDL_options_st const&, TABLE_LIST*, bool, unsigned int, Prelocking_strategy*) (sql_base.cc:5259)
 
==12731==    by 0x56C4CA: open_and_lock_tables(THD*, TABLE_LIST*, bool, unsigned int) (sql_base.h:535)
 
==12731==    by 0x58270D: open_system_tables_for_read(THD*, TABLE_LIST*, Open_tables_backup*) (sql_base.cc:9279)
 
==12731==    by 0x684B57: open_stat_tables(THD*, TABLE_LIST*, Open_tables_backup*, bool) (sql_statistics.cc:270)
 
==12731==    by 0x687FA0: rename_table_in_stat_tables(THD*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*) (sql_statistics.cc:3536)
 
==12731==    by 0x608389: do_rename(THD*, TABLE_LIST*, char*, char*, char*, bool) (sql_rename.cc:301)
 
==12731== Invalid read of size 4
 
==12731==    at 0x5B8F12: handler::ha_index_or_rnd_end() (handler.h:2820)
 
==12731==    by 0x68BF44: Stat_table_write_iter::cleanup() (sql_statistics.cc:1514)
 
==12731==    by 0x68BF7F: Stat_table_write_iter::~Stat_table_write_iter() (sql_statistics.cc:1521)
 
==12731==    by 0x6882E6: rename_table_in_stat_tables(THD*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*) (sql_statistics.cc:3546)
 
==12731==    by 0x608389: do_rename(THD*, TABLE_LIST*, char*, char*, char*, bool) (sql_rename.cc:301)
 
==12731==    by 0x6085BD: rename_tables(THD*, TABLE_LIST*, bool) (sql_rename.cc:379)
 
==12731==    by 0x607E59: mysql_rename_tables(THD*, TABLE_LIST*, bool) (sql_rename.cc:153)
 
==12731==    by 0x5DFCE8: mysql_execute_command(THD*) (sql_parse.cc:3638)
 
==12731==    by 0x5EB2C2: mysql_parse(THD*, char*, unsigned int, Parser_state*) (sql_parse.cc:7347)
 
==12731==    by 0x5DA185: dispatch_command(enum_server_command, THD*, char*, unsigned int) (sql_parse.cc:1477)
 
==12731==    by 0x5D8F0A: do_command(THD*) (sql_parse.cc:1106)
 
==12731==    by 0x716FC0: do_handle_one_connection(THD*) (sql_connect.cc:1330)
 
==12731==    by 0x716D24: handle_one_connection (sql_connect.cc:1242)
 
==12731==    by 0xAF1D77: pfs_spawn_thread (pfs.cc:1861)
 
==12731==    by 0x4E3F493: start_thread (pthread_create.c:333)
 
==12731==    by 0x6AC793E: clone (clone.S:97)
 
==12731==  Address 0xddf73e8 is 440 bytes inside a block of size 1,792 free'd
 
==12731==    at 0x4C2CDDB: free (vg_replace_malloc.c:530)
 
==12731==    by 0xED9977: my_free (my_malloc.c:217)
 
==12731==    by 0xECAC27: free_root (my_alloc.c:389)
 
==12731==    by 0x6D2DB0: closefrm(TABLE*, bool) (table.cc:3085)
 
==12731==    by 0x56FC54: intern_close_table(TABLE*) (sql_base.cc:354)
 
==12731==    by 0x7AC3F9: tc_release_table(TABLE*) (table_cache.cc:360)
 
==12731==    by 0x571359: close_thread_table(THD*, TABLE**) (sql_base.cc:1089)
 
==12731==    by 0x570B35: close_open_tables(THD*) (sql_base.cc:812)
 
==12731==    by 0x5710E3: close_thread_tables(THD*) (sql_base.cc:1036)
 
==12731==    by 0x58283E: close_system_tables(THD*, Open_tables_backup*) (sql_base.cc:9313)
 
==12731==    by 0x688299: rename_table_in_stat_tables(THD*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*) (sql_statistics.cc:3587)
 
==12731==    by 0x608389: do_rename(THD*, TABLE_LIST*, char*, char*, char*, bool) (sql_rename.cc:301)
 
==12731==    by 0x6085BD: rename_tables(THD*, TABLE_LIST*, bool) (sql_rename.cc:379)
 
==12731==    by 0x607E59: mysql_rename_tables(THD*, TABLE_LIST*, bool) (sql_rename.cc:153)
 
==12731==    by 0x5DFCE8: mysql_execute_command(THD*) (sql_parse.cc:3638)
 
==12731==    by 0x5EB2C2: mysql_parse(THD*, char*, unsigned int, Parser_state*) (sql_parse.cc:7347)
 
==12731==  Block was alloc'd at
 
==12731==    at 0x4C2BBAF: malloc (vg_replace_malloc.c:299)
 
==12731==    by 0xED9490: my_malloc (my_malloc.c:101)
 
==12731==    by 0xECA61F: alloc_root (my_alloc.c:184)
 
==12731==    by 0x518C78: Sql_alloc::operator new(unsigned long, st_mem_root*) (sql_list.h:43)
 
==12731==    by 0xB0C406: myisam_create_handler(handlerton*, TABLE_SHARE*, st_mem_root*) (ha_myisam.cc:129)
 
==12731==    by 0x826E3E: get_new_handler(TABLE_SHARE*, st_mem_root*, handlerton*) (handler.cc:265)
 
==12731==    by 0x6D1987: open_table_from_share(THD*, TABLE_SHARE*, char const*, unsigned int, unsigned int, unsigned int, TABLE*, bool) (table.cc:2666)
 
==12731==    by 0x5741C3: open_table(THD*, TABLE_LIST*, Open_table_context*) (sql_base.cc:2553)
 
==12731==    by 0x576A30: open_and_process_table(THD*, LEX*, TABLE_LIST*, unsigned int*, unsigned int, Prelocking_strategy*, bool, Open_table_context*) (sql_base.cc:4068)
 
==12731==    by 0x577AAB: open_tables(THD*, DDL_options_st const&, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*) (sql_base.cc:4579)
 
==12731==    by 0x578DE5: open_and_lock_tables(THD*, DDL_options_st const&, TABLE_LIST*, bool, unsigned int, Prelocking_strategy*) (sql_base.cc:5259)
 
==12731==    by 0x56C4CA: open_and_lock_tables(THD*, TABLE_LIST*, bool, unsigned int) (sql_base.h:535)
 
==12731==    by 0x58270D: open_system_tables_for_read(THD*, TABLE_LIST*, Open_tables_backup*) (sql_base.cc:9279)
 
==12731==    by 0x684B57: open_stat_tables(THD*, TABLE_LIST*, Open_tables_backup*, bool) (sql_statistics.cc:270)
 
==12731==    by 0x687FA0: rename_table_in_stat_tables(THD*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*) (sql_statistics.cc:3536)
 
==12731==    by 0x608389: do_rename(THD*, TABLE_LIST*, char*, char*, char*, bool) (sql_rename.cc:301)
 
==12731== Invalid read of size 4
 
==12731==    at 0x5B8F2F: handler::ha_index_or_rnd_end() (handler.h:2820)
 
==12731==    by 0x68BF44: Stat_table_write_iter::cleanup() (sql_statistics.cc:1514)
 
==12731==    by 0x68BF7F: Stat_table_write_iter::~Stat_table_write_iter() (sql_statistics.cc:1521)
 
==12731==    by 0x6882E6: rename_table_in_stat_tables(THD*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*) (sql_statistics.cc:3546)
 
==12731==    by 0x608389: do_rename(THD*, TABLE_LIST*, char*, char*, char*, bool) (sql_rename.cc:301)
 
==12731==    by 0x6085BD: rename_tables(THD*, TABLE_LIST*, bool) (sql_rename.cc:379)
 
==12731==    by 0x607E59: mysql_rename_tables(THD*, TABLE_LIST*, bool) (sql_rename.cc:153)
 
==12731==    by 0x5DFCE8: mysql_execute_command(THD*) (sql_parse.cc:3638)
 
==12731==    by 0x5DA185: dispatch_command(enum_server_command, THD*, char*, unsigned int) (sql_parse.cc:1477)
 
==12731==    by 0x5D8F0A: do_command(THD*) (sql_parse.cc:1106)
 
==12731==    by 0x716FC0: do_handle_one_connection(THD*) (sql_connect.cc:1330)
 
==12731==    by 0x716D24: handle_one_connection (sql_connect.cc:1242)
 
==12731==    by 0xAF1D77: pfs_spawn_thread (pfs.cc:1861)
 
==12731==    by 0x4E3F493: start_thread (pthread_create.c:333)
 
==12731==    by 0x6AC793E: clone (clone.S:97)
 
==12731==  Address 0xddf73e8 is 440 bytes inside a block of size 1,792 free'd
 
==12731==    at 0x4C2CDDB: free (vg_replace_malloc.c:530)
 
==12731==    by 0xED9977: my_free (my_malloc.c:217)
 
==12731==    by 0xECAC27: free_root (my_alloc.c:389)
 
==12731==    by 0x6D2DB0: closefrm(TABLE*, bool) (table.cc:3085)
 
==12731==    by 0x56FC54: intern_close_table(TABLE*) (sql_base.cc:354)
 
==12731==    by 0x7AC3F9: tc_release_table(TABLE*) (table_cache.cc:360)
 
==12731==    by 0x571359: close_thread_table(THD*, TABLE**) (sql_base.cc:1089)
 
==12731==    by 0x570B35: close_open_tables(THD*) (sql_base.cc:812)
 
==12731==    by 0x5710E3: close_thread_tables(THD*) (sql_base.cc:1036)
 
==12731==    by 0x58283E: close_system_tables(THD*, Open_tables_backup*) (sql_base.cc:9313)
 
==12731==    by 0x688299: rename_table_in_stat_tables(THD*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*) (sql_statistics.cc:3587)
 
==12731==    by 0x608389: do_rename(THD*, TABLE_LIST*, char*, char*, char*, bool) (sql_rename.cc:301)
 
==12731==    by 0x6085BD: rename_tables(THD*, TABLE_LIST*, bool) (sql_rename.cc:379)
 
==12731==    by 0x607E59: mysql_rename_tables(THD*, TABLE_LIST*, bool) (sql_rename.cc:153)
 
==12731==    by 0x5DFCE8: mysql_execute_command(THD*) (sql_parse.cc:3638)
 
==12731==    by 0x5EB2C2: mysql_parse(THD*, char*, unsigned int, Parser_state*) (sql_parse.cc:7347)
 
==12731==  Block was alloc'd at
 
==12731==    at 0x4C2BBAF: malloc (vg_replace_malloc.c:299)
 
==12731==    by 0xED9490: my_malloc (my_malloc.c:101)
 
==12731==    by 0xECA61F: alloc_root (my_alloc.c:184)
 
==12731==    by 0x518C78: Sql_alloc::operator new(unsigned long, st_mem_root*) (sql_list.h:43)
 
==12731==    by 0xB0C406: myisam_create_handler(handlerton*, TABLE_SHARE*, st_mem_root*) (ha_myisam.cc:129)
 
==12731==    by 0x826E3E: get_new_handler(TABLE_SHARE*, st_mem_root*, handlerton*) (handler.cc:265)
 
==12731==    by 0x6D1987: open_table_from_share(THD*, TABLE_SHARE*, char const*, unsigned int, unsigned int, unsigned int, TABLE*, bool) (table.cc:2666)
 
==12731==    by 0x5741C3: open_table(THD*, TABLE_LIST*, Open_table_context*) (sql_base.cc:2553)
 
==12731==    by 0x576A30: open_and_process_table(THD*, LEX*, TABLE_LIST*, unsigned int*, unsigned int, Prelocking_strategy*, bool, Open_table_context*) (sql_base.cc:4068)
 
==12731==    by 0x577AAB: open_tables(THD*, DDL_options_st const&, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*) (sql_base.cc:4579)
 
==12731==    by 0x578DE5: open_and_lock_tables(THD*, DDL_options_st const&, TABLE_LIST*, bool, unsigned int, Prelocking_strategy*) (sql_base.cc:5259)
 
==12731==    by 0x56C4CA: open_and_lock_tables(THD*, TABLE_LIST*, bool, unsigned int) (sql_base.h:535)
 
==12731==    by 0x58270D: open_system_tables_for_read(THD*, TABLE_LIST*, Open_tables_backup*) (sql_base.cc:9279)
 
==12731==    by 0x684B57: open_stat_tables(THD*, TABLE_LIST*, Open_tables_backup*, bool) (sql_statistics.cc:270)
 
==12731==    by 0x687FA0: rename_table_in_stat_tables(THD*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*, st_mysql_lex_string*) (sql_statistics.cc:3536)
 
==12731==    by 0x608389: do_rename(THD*, TABLE_LIST*, char*, char*, char*, bool) (sql_rename.cc:301)

I'm getting the failure every time, but the test case implies concurrency, so if it's not reproducible right away, try --repeat=N.

Comment by Michael Widenius [ 2018-05-23 ]

Problem was that destructor called methods for closed table.
Fixed by removing code in destructor.

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