[MDEV-4832] mariadb crash on disk full with mysqld got signal 11 Created: 2013-08-01  Updated: 2018-10-30

Status: Open
Project: MariaDB Server
Component/s: None
Affects Version/s: 5.5.32
Fix Version/s: 5.5

Type: Bug Priority: Minor
Reporter: Daniel Assignee: Unassigned
Resolution: Unresolved Votes: 1
Labels: upstream
Environment:

Linux mysql55 2.6.32-358.el6.x86_64
Scientific Linux release 6.4 (Carbon)

Issue Links:
Relates
relates to MDEV-17307 "Incorrect key file for table" is pro... Open

 Description   

I have had ramdisk for "tmpdir". While temporary table use more space than available on tmpdir and query is killed, mysql will crash with "mysqld got signal 11"

For example, generic testing table:

MariaDB [cswiki]> show create table langlinks\G;
 
       Table: langlinks
 
Create Table: CREATE TABLE `langlinks` (
 
  `ll_from` int(8) unsigned NOT NULL DEFAULT '0',
 
  `ll_lang` varbinary(20) NOT NULL DEFAULT '',
 
  `ll_title` varbinary(255) NOT NULL DEFAULT '',
 
  UNIQUE KEY `ll_from` (`ll_from`,`ll_lang`),
 
  KEY `ll_lang` (`ll_lang`,`ll_title`)
 
) ENGINE=MyISAM DEFAULT CHARSET=ascii COMMENT='Denni prehledy poctu nabidek podle licenci'
 
1 row in set (0.00 sec)
 
 
 
CREATE TEMPORARY TABLE IF NOT EXISTS TEMPTABLES.test LIKE langlinks;
 
 
 
INSERT INTO  TEMPTABLES.test SELECT t.ll_from, t.ll_lang, t.ll_title from langlinks t;

Now, free space is exhausted and i have got:

130801 16:28:31 [ERROR] mysqld: Incorrect key file for table '/tmp/#sql6ecc_2_0.MYI'; try to repair it
 
130801 16:28:31 [ERROR] Got an error from unknown thread, /home/buildbot/buildbot/build/mariadb-5.5.32/storage/myisam/mi_write.c:224
 
130801 16:28:31 [Warning] mysqld: Disk is full writing '/tmp/#sql6ecc_2_0.MYI' (Errcode: 28). Waiting for someone to free space... (Expect up to 60 secs delay for server to continue after freeing disk space)
 
130801 16:28:31 [Warning] mysqld: Retry in 60 secs. Message reprinted in 600 secs

Now, i killed query by ctrl+c and everything seems ok. But, exactly one minutes after space exhaustion, db crashed with trace:

130801 16:29:31 [ERROR] mysqld got signal 11 ;
 
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 http://kb.askmonty.org/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: 5.5.32-MariaDB
 
key_buffer_size=134217728
 
read_buffer_size=131072
 
max_used_connections=3
 
max_threads=153
 
thread_count=2
 
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 466714 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0x0x2632990
 
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 = 0x7ff3580b3d78 thread_stack 0x48000
 
??:0(my_print_stacktrace)[0xa8631e]
 
??:0(handle_fatal_signal)[0x6cdd0b]
 
??:0(??)[0x7ff35d973500]
 
??:0(flush_key_blocks_int)[0xa74856]
 
??:0(flush_simple_key_cache_blocks)[0xa75a41]
 
??:0(mi_repair_by_sort)[0xa21c96]
 
??:0(ha_myisam::repair(THD*, st_handler_check_param&, bool))[0xa15cba]
 
??:0(ha_myisam::enable_indexes(unsigned int))[0xa15e71]
 
??:0(ha_myisam::end_bulk_insert())[0xa12be9]
 
??:0(select_insert::abort_result_set())[0x56e475]
 
??:0(handle_select(THD*, LEX*, select_result*, unsigned long))[0x5d9ddf]
 
??:0(mysql_execute_command(THD*))[0x58d849]
 
??:0(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x58e369]
 
??:0(dispatch_command(enum_server_command, THD*, char*, unsigned int))[0x58f790]
 
??:0(do_handle_one_connection(THD*))[0x647cdf]
 
??:0(handle_one_connection)[0x647d7c]
 
??:0(??)[0x7ff35d96b851]
 
??:0(??)[0x7ff35c2df90d]
 
 
 
Trying to get some variables.
 
Some pointers may be invalid and cause the dump to abort.
 
Query (0x7ff328004bd8): is an invalid pointer
 
Connection ID (thread ID): 2
 
Status: KILL_QUERY
 
 
 
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=off

This was purely testing environment with almost empty config file, but on production environment on 5.5.31 is the same problem.

 Comments   
Comment by Elena Stepanova [ 2013-08-01 ]

Hi Daniel,

Did you free the space before or after killing the query, or did you continue running with the full disk?
What do you mean by "everything seems ok" after killing the query – what exactly was okay, was server able to process queries, did you check the processlist to see that the query was gone, etc.?

Thanks.

Comment by Daniel [ 2013-08-02 ]

Hi Elena,

I didn't touch any files during whole test, so space was still exhausted, because i tryied to reproduce production failure which occured. Mysql client canceled query because of timeout, i tryied to cancel query by ctrl+c. Result is the same.

processlist after exhaustion, but before cancel

MariaDB [(none)]> show processlist;
 
+----+------+-----------+--------+---------+------+-------------------+---------------------------------------------------------------------------------------+----------+
 
| Id | User | Host      | db     | Command | Time | State             | Info                                                                                  | Progress |
 
+----+------+-----------+--------+---------+------+-------------------+---------------------------------------------------------------------------------------+----------+
 
|  1 | root | localhost | cswiki | Query   |   51 | Repair by sorting | INSERT INTO  TEMPTABLES.test SELECT t.ll_from, t.ll_lang, t.ll_title from langlinks t |    0.000 |
 
|  2 | root | localhost | NULL   | Query   |    0 | NULL              | show processlist                                                                      |    0.000 |
 
+----+------+-----------+--------+---------+------+-------------------+---------------------------------------------------------------------------------------+----------+
 
2 rows in set (0.00 sec)

processlist after cancelation

MariaDB [(none)]> show processlist;
 
+----+------+-----------+--------+---------+------+-------------------+---------------------------------------------------------------------------------------+----------+
 
| Id | User | Host      | db     | Command | Time | State             | Info                                                                                  | Progress |
 
+----+------+-----------+--------+---------+------+-------------------+---------------------------------------------------------------------------------------+----------+
 
|  1 | root | localhost | cswiki | Killed  |   54 | Repair by sorting | INSERT INTO  TEMPTABLES.test SELECT t.ll_from, t.ll_lang, t.ll_title from langlinks t |    0.000 |
 
|  2 | root | localhost | NULL   | Query   |    0 | NULL              | show processlist                                                                      |    0.000 |
 
+----+------+-----------+--------+---------+------+-------------------+---------------------------------------------------------------------------------------+----------+
 
2 rows in set (0.00 sec)

Comment by Elena Stepanova [ 2013-08-05 ]

Debug assertion failure:

mysqld: 5.5/mysys/mf_keycache.c:3800: flush_cached_blocks: Assertion `(block->status & ~(512 | 128)) == (2 | 16 | 32 | 64)' failed.
130805 3:20:59 [ERROR] mysqld got signal 6 ;

#5 0x00007f74200b8b8b in __GI_abort () at abort.c:91
#6 0x00007f74200ae0ee in __assert_fail_base (fmt=<optimized out>, assertion=0x17fd3e0 "(block->status & ~(512 | 128)) == (2 | 16 | 32 | 64)", file=0x17fbfa0 "5.5/mysys/mf_keycache.c", line=<optimized out>, function=<optimized out>) at assert.c:94
#7 0x00007f74200ae192 in _GI__assert_fail (assertion=0x17fd3e0 "(block->status & ~(512 | 128)) == (2 | 16 | 32 | 64)", file=0x17fbfa0 "5.5/mysys/mf_keycache.c", line=3800, function=0x17fd9e0 "flush_cached_blocks") at assert.c:103
#8 0x00000000011291ad in flush_cached_blocks (keycache=0x3254cb0, file=42, cache=0x7f7421823af0, end=0x7f7421823af8, type=FLUSH_FORCE_WRITE) at 5.5/mysys/mf_keycache.c:3799
#9 0x0000000001129adf in flush_key_blocks_int (keycache=0x3254cb0, file=42, type=FLUSH_FORCE_WRITE) at 5.5/mysys/mf_keycache.c:4074
#10 0x000000000112a506 in flush_simple_key_cache_blocks (keycache=0x3254cb0, file=42, file_extra=0x7f73d001d330, type=FLUSH_FORCE_WRITE) at 5.5/mysys/mf_keycache.c:4355
#11 0x000000000112d771 in flush_key_blocks (keycache=0x3226e90, file=42, file_extra=0x7f73d001d330, type=FLUSH_FORCE_WRITE) at 5.5/mysys/mf_keycache.c:6351
#12 0x0000000000fa1fc4 in mi_drop_all_indexes (param=0x7f73d003bc28, info=0x7f73d001db70, force=0 '\000') at 5.5/storage/myisam/mi_check.c:1460
#13 0x0000000000fa65cc in mi_repair_by_sort (param=0x7f73d003bc28, info=0x7f73d001db70, name=0x7f7421828630 "5.5/data/tmp/#sql89e_5_3", rep_quick=1) at 5.5/storage/myisam/mi_check.c:2283
#14 0x0000000000f934a1 in ha_myisam::repair (this=0x7f73d001c0e8, thd=0x43f8e70, param=..., do_optimize=false) at 5.5/storage/myisam/ha_myisam.cc:1134
#15 0x0000000000f94b41 in ha_myisam::enable_indexes (this=0x7f73d001c0e8, mode=2) at 5.5/storage/myisam/ha_myisam.cc:1448
#16 0x0000000000f952ca in ha_myisam::end_bulk_insert (this=0x7f73d001c0e8) at 5.5/storage/myisam/ha_myisam.cc:1595
#17 0x00000000006695a4 in handler::ha_end_bulk_insert (this=0x7f73d001c0e8) at 5.5/sql/handler.h:1933
#18 0x0000000000666668 in select_insert::abort_result_set (this=0x7f73d0006008) at 5.5/sql/sql_insert.cc:3738
#19 0x00000000006d5d75 in handle_select (thd=0x43f8e70, lex=0x43fc0d8, result=0x7f73d0006008, setup_tables_done_option=1073741824) at 5.5/sql/sql_select.cc:324
#20 0x000000000068cc4e in mysql_execute_command (thd=0x43f8e70) at 5.5/sql/sql_parse.cc:3031
#21 0x0000000000699a9e in mysql_parse (thd=0x43f8e70, rawbuf=0x7f73d00051c8 "insert into l2 select * from langlinks", length=38, parser_state=0x7f7421829550) at 5.5/sql/sql_parse.cc:5769
#22 0x0000000000684b7c in dispatch_command (command=COM_QUERY, thd=0x43f8e70, packet=0x7f73d0037b91 "insert into l2 select * from langlinks", packet_length=38) at 5.5/sql/sql_parse.cc:1071
#23 0x000000000068357d in do_command (thd=0x43f8e70) at 5.5/sql/sql_parse.cc:794
#24 0x000000000082a16f in do_handle_one_connection (thd_arg=0x43f8e70) at 5.5/sql/sql_connect.cc:1266
#25 0x00000000008298a0 in handle_one_connection (arg=0x43f8e70) at 5.5/sql/sql_connect.cc:1181
#26 0x00007f7420e7ee9a in start_thread (arg=0x7f742182a700) at pthread_create.c:308
#27 0x00007f7420172cbd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112

Comment by Elena Stepanova [ 2013-08-05 ]

The scenario is as initially described:

  • load data into a temporary table while there is not enough space in tmp left;
  • wait until it hits the error (in the log file)

130805 3:32:19 [Warning] mysqld: Disk is full writing '/data/smalldisk/#sqlb62_2_0.MYI' (Errcode: 28). Waiting for someone to free space... (Expect up to 60 secs delay for server to continue after freeing disk space)
130805 3:32:19 [Warning] mysqld: Retry in 60 secs. Message reprinted in 600 secs

  • kill the query (it's better to do kill query <thread id> from another session rather than Ctrl-C, it's more reliable);
  • make sure the processlist says that the query is killed;
  • wait till another 60-sec checkpoint happens
    => get the assertion failure.
Comment by Elena Stepanova [ 2013-08-05 ]

Also reproducible on MySQL 5.1, 5.6 (on 5.6 the assertion is slightly different, but otherwise the result is the same).

So, it's an upstream bug. Are you willing to file it at bugs.mysql.com?

Comment by Daniel [ 2013-08-05 ]

fill in at http://bugs.mysql.com/bug.php?id=69926

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