Bug #67657 mysqld 5.1.66 slave segfaults in a replication setup
Submitted: 21 Nov 2012 10:10 Modified: 27 Dec 2012 20:00
Reporter: petre rodan Email Updates:
Status: No Feedback Impact on me:
None 
Category:MySQL Server: Replication Severity:S2 (Serious)
Version:5.1.66 OS:Linux (stable hardened gentoo)
Assigned to: CPU Architecture:Any

[21 Nov 2012 10:10] petre rodan
Description:
I just upgraded mysql from 5.1.62 to 5.1.66 and each time I start the server without --skip-slave it crashes with SIGSEGV. the configuration files are the same, I had no previous upgrade-related problems, I did run mysql_upgrade. the previous mysqld version run with no problems.

the original bug report is here:
https://bugs.gentoo.org/show_bug.cgi?id=444054

I enabled the general_log, it appears that mysqld parses the relay_logs, starts inserting data from them to the local db, but crashes after a few seconds. based on the general_log it succeeds in inserting small amounts of data each time it is started. the last sequences are 
                    2 Query     BEGIN
                    2 Query     COMMIT /* implicit, from Xid_log_event */
                    2 Query     BEGIN
                    2 Query     COMMIT /* implicit, from Xid_log_event */
the last meaningful sql command is a simple insert.

I compiled the package with -ggdb and this would be the trace:

web3 ~ # gdb /usr/sbin/mysqld
GNU gdb (Gentoo 7.3.1 p2) 7.3.1
Copyright (C) 2011 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-pc-linux-gnu".
For bug reporting instructions, please see:
<http://bugs.gentoo.org/>...
Reading symbols from /usr/sbin/mysqld...done.
(gdb) run
Starting program: /usr/sbin/mysqld 
[New LWP 10609]

Program received signal SIGSEGV, Segmentation fault.
[Switching to LWP 10609]
0x000004c0d4834a64 in Item::delete_self (this=0x6b25e8005b90) at item.h:1030
1030        cleanup();
(gdb) bt
#0  0x000004c0d4834a64 in Item::delete_self (this=0x6b25e8005b90) at item.h:1030
#1  0x000004c0d4830bf3 in Query_arena::free_items (this=0x6b25e8000988) at sql_class.cc:2508
#2  0x000004c0d482c34a in THD::cleanup_after_query (this=0x6b25e8000970) at sql_class.cc:1275
#3  0x000004c0d4863f45 in mysql_parse (thd=0x6b25e8000970, rawbuf=0x6b25e800c811 "BEGIN", length=5, found_semicolon=0x6b260e7057f0)
    at sql_parse.cc:6149
#4  0x000004c0d4948153 in Query_log_event::do_apply_event (this=0x6b25e800ba20, rli=0x4c0d63a62f0, query_arg=0x6b25e800c811 "BEGIN", q_len_arg=5)
    at log_event.cc:3328
#5  0x000004c0d4947851 in Query_log_event::do_apply_event (this=0x6b25e800ba20, rli=0x4c0d63a62f0) at log_event.cc:3121
#6  0x000004c0d49e06ff in Log_event::apply_event (this=0x6b25e800ba20, rli=0x4c0d63a62f0) at log_event.h:1076
#7  0x000004c0d49dbd77 in apply_event_and_update_pos (ev=0x6b25e800ba20, thd=0x6b25e8000970, rli=0x4c0d63a62f0) at slave.cc:2216
#8  0x000004c0d49dbf7d in exec_relay_log_event (thd=0x6b25e8000970, rli=0x4c0d63a62f0) at slave.cc:2355
#9  0x000004c0d49dd94b in handle_slave_sql (arg=0x4c0d63a5000) at slave.cc:3148
#10 0x00006b260e364da6 in ?? ()
#11 0x0000000000000000 in ?? ()
(gdb) info local
No locals.
(gdb) up
#1  0x000004c0d4830bf3 in Query_arena::free_items (this=0x6b25e8000988) at sql_class.cc:2508
warning: Source file is more recent than executable.
2508        free_list->delete_self();
(gdb) info local
next = 0x6b25e8005c08
(gdb) up
#2  0x000004c0d482c34a in THD::cleanup_after_query (this=0x6b25e8000970) at sql_class.cc:1275
1275      free_items();
(gdb) info local
No locals.
(gdb) up
#3  0x000004c0d4863f45 in mysql_parse (thd=0x6b25e8000970, rawbuf=0x6b25e800c811 "BEGIN", length=5, found_semicolon=0x6b260e7057f0)
    at sql_parse.cc:6149
warning: Source file is more recent than executable.
6149        thd->cleanup_after_query();
(gdb) info local
lex = 0x6b25e8002338
parser_state = {m_lip = {m_thd = 0x6b25e8000970, yylineno = 1, yytoklen = 0, yylval = 0x6b260e703420, m_ptr = 0x6b25e800c817 "\f", 
    m_tok_start = 0x6b25e800c817 "\f", m_tok_end = 0x6b25e800c817 "\f", m_end_of_query = 0x6b25e800c816 "", m_tok_start_prev = 0x6b25e800c816 "", 
    m_buf = 0x6b25e800c811 "BEGIN", m_buf_length = 5, m_echo = true, m_echo_saved = 4, m_cpp_buf = 0x6b25e8005ba0 "", 
    m_cpp_ptr = 0x6b25e8005ba5 "", m_cpp_tok_start = 0x6b25e8005ba5 "", m_cpp_tok_start_prev = 0x6b25e8005ba5 "", 
    m_cpp_tok_end = 0x6b25e8005ba5 "", m_body_utf8 = 0x0, m_body_utf8_ptr = 0x0, m_cpp_utf8_processed_ptr = 0x0, next_state = MY_LEX_END, 
    found_semicolon = 0x0, tok_bitmap = 17 '\021', ignore_space = false, stmt_prepare_mode = false, in_comment = NO_COMMENT, 
    in_comment_saved = 3892316528, m_cpp_text_start = 0x50ac8f25 <Address 0x50ac8f25 out of bounds>, 
    m_cpp_text_end = 0x23653cf235435b00 <Address 0x23653cf235435b00 out of bounds>, m_underscore_cs = 0x0}, m_yacc = {yacc_yyss = 0x0, 
    yacc_yyvs = 0x0}}
err = false
(gdb) up
#4  0x000004c0d4948153 in Query_log_event::do_apply_event (this=0x6b25e800ba20, rli=0x4c0d63a62f0, query_arg=0x6b25e800c811 "BEGIN", q_len_arg=5)
    at log_event.cc:3328
warning: Source file is more recent than executable.
3328          mysql_parse(thd, thd->query(), thd->query_length(), &found_semicolon);
(gdb) info local
found_semicolon = 0x0
new_db = {str = 0x6b25e800c804 "aviraweb_rep", length = 12}
expected_error = 0
actual_error = 0
db_options = {table_charset = 0x0, default_table_charset = 0x4c0d5103680, connect_string = {str = 0x0, length = 0}, password = 0x0, 
  tablespace = 0x0, comment = {str = 0x0, length = 0}, data_file_name = 0x0, index_file_name = 0x0, alias = 0x0, max_rows = 0, min_rows = 0, 
  auto_increment_value = 0, table_options = 0, avg_row_length = 0, used_fields = 0, key_block_size = 0, 
  merge_list = {<Sql_alloc> = {<No data fields>}, elements = 0, first = 0x0, next = 0x0}, db_type = 0x0, row_type = ROW_TYPE_DEFAULT, 
  null_bits = 0, options = 0, merge_insert_method = 0, extra_size = 0, unused1 = HA_CHOICE_UNDEF, table_existed = false, frm_only = false, 
  varchar = false, storage_media = HA_SM_DEFAULT, unused2 = HA_CHOICE_UNDEF}
(gdb) up
#5  0x000004c0d4947851 in Query_log_event::do_apply_event (this=0x6b25e800ba20, rli=0x4c0d63a62f0) at log_event.cc:3121
3121      return do_apply_event(rli, query, q_len);
(gdb) info local
No locals.
(gdb) up
#6  0x000004c0d49e06ff in Log_event::apply_event (this=0x6b25e800ba20, rli=0x4c0d63a62f0) at log_event.h:1076
1076        return do_apply_event(rli);
(gdb) info local
No locals.
(gdb) up
#7  0x000004c0d49dbd77 in apply_event_and_update_pos (ev=0x6b25e800ba20, thd=0x6b25e8000970, rli=0x4c0d63a62f0) at slave.cc:2216
warning: Source file is more recent than executable.
2216        exec_res= ev->apply_event(rli);
(gdb) info local
exec_res = 0
reason = 0
(gdb) up
#8  0x000004c0d49dbf7d in exec_relay_log_event (thd=0x6b25e8000970, rli=0x4c0d63a62f0) at slave.cc:2355
2355        exec_res= apply_event_and_update_pos(ev, thd, rli);

How to repeat:
start the slave replication server, wait for 10 seconds
[27 Nov 2012 20:00] Sveta Smirnova
Thank you for the report.

This looks like duplicate of bug #55986 which should be fixed by fix for bug #56080 which was pushed into version 5.6.3. Is it possible for you to try with another slave which uses version 5.6.8 to ensure they are really duplicates?
[28 Dec 2012 1:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".