after the upgrade from 5.1.62-r1 to 5.1.66 mysql starts crashing with segfault. this happens on the production server, where this mysql is a slave in a replication setup. the configuration was not changed after the upgrade and all previous versions worked fine. right after the upgrade: 121120 10:01:39 [Note] Event Scheduler: Purging the queue. 0 events 121120 10:01:39 [Note] Error reading relay log event: slave SQL thread was killed 121120 10:01:39 [Note] Slave I/O thread killed while reading event 121120 10:01:39 [Note] Slave I/O thread exiting, read up to log 'skycaves.000547', position 607196663 121120 10:01:41 InnoDB: Starting shutdown... 121120 10:01:43 InnoDB: Shutdown completed; log sequence number 77 3125296691 121120 10:01:43 [Note] /usr/sbin/mysqld: Shutdown complete 121120 10:01:43 InnoDB: Initializing buffer pool, size = 16.0M 121120 10:01:43 InnoDB: Completed initialization of buffer pool 121120 10:01:43 InnoDB: Started; log sequence number 77 3125296691 121120 10:01:43 [Note] Slave SQL thread initialized, starting replication in log 'skycaves.000547' at position 607196663, relay log './web-relay-bin.012390' position: 8104 121120 10:01:43 [Note] Event Scheduler: Loaded 0 events 121120 10:01:43 [Note] /usr/sbin/mysqld: ready for connections. Version: '5.1.66-log' socket: '/var/run/mysqld/mysqld.sock' port: 3306 Gentoo Linux mysql-5.1.66 121120 10:01:43 [Note] Slave I/O thread: connected to master 'replication@127.0.0.1:3307',replication started in log 'skycaves.000547' at position 607196663 09:12:43 UTC - 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. 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. key_buffer_size=50331648 read_buffer_size=262144 max_used_connections=14 max_threads=256 thread_count=0 connection_count=0 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 248404 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. Thread pointer: 0x7037e8000970 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 = 703810698828 thread_stack 0x40000 /usr/sbin/mysqld(my_print_stacktrace+0x3c) [0x31478bbc83c] /usr/sbin/mysqld(handle_fatal_signal+0x493) [0x314789d9d73] /lib64/libpthread.so.0(+0x10460) [0x703810300460] /lib64/libc.so.6(cfree+0x14) [0x70380ed17174] /usr/sbin/mysqld(Item_func_get_user_var::~Item_func_get_user_var()+0x52) [0x3147883e9b2] /usr/sbin/mysqld(Item::safe_charset_converter(charset_info_st*)+0x18d) [0x31478809cbd] /usr/sbin/mysqld(Query_arena::free_items()+0x40) [0x314788c8780] /usr/sbin/mysqld(THD::cleanup_after_query()+0x5e) [0x314788c881e] /usr/sbin/mysqld(mysql_parse(THD*, char*, unsigned int, char const**)+0x22f) [0x314788f258f] /usr/sbin/mysqld(Query_log_event::do_apply_event(Relay_log_info const*, char const*, unsigned int)+0x406) [0x314789a5e56] /usr/sbin/mysqld(apply_event_and_update_pos(Log_event*, THD*, Relay_log_info*)+0xfd) [0x31478a160fd] /usr/sbin/mysqld(handle_slave_sql+0x829) [0x31478a16c19] /lib64/libpthread.so.0(+0x7da6) [0x7038102f7da6] /lib64/libc.so.6(clone+0x6d) [0x70380ed8250d] Trying to get some variables. Some pointers may be invalid and cause the dump to abort. Query (7037e809f728): is an invalid pointer Connection ID (thread ID): 2 Status: NOT_KILLED The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains information that should help you find out what is causing the crash. Reproducible: Always emerge --info Portage 2.1.11.31 (hardened/linux/amd64, gcc-4.5.4, unavailable, 3.5.4-grsec-a084 x86_64) ================================================================= System uname: Linux-3.5.4-grsec-a084-x86_64-Intel-R-_Xeon-R-_CPU_E5440_@_2.83GHz-with-gentoo-2.1 Timestamp of tree: Tue, 20 Nov 2012 03:45:01 +0000 ld GNU ld (GNU Binutils) 2.22 app-shells/bash: 4.2_p37 dev-lang/python: 2.6.8, 3.1.5, 3.2.3 dev-util/cmake: 2.8.9 dev-util/pkgconfig: 0.27.1 sys-apps/baselayout: 2.1-r1 sys-apps/openrc: 0.9.8.4 sys-apps/sandbox: 2.5 sys-devel/autoconf: 2.13, 2.68 sys-devel/automake: 1.10.3, 1.11.6 sys-devel/binutils: 2.22-r1 sys-devel/gcc: 4.5.4 sys-devel/gcc-config: 1.7.3 sys-devel/libtool: 2.4-r1 sys-devel/make: 3.82-r3 sys-kernel/linux-headers: 3.4-r2 (virtual/os-headers) sys-libs/glibc: 2.15-r3 Repositories: gentoo x-overlay ACCEPT_KEYWORDS="amd64" ACCEPT_LICENSE="* -@EULA" CBUILD="x86_64-pc-linux-gnu" CFLAGS="-O2 -pipe" CHOST="x86_64-pc-linux-gnu" CONFIG_PROTECT="/etc /local/adm/bin /usr/share/gnupg/qualified.txt /var/service" CONFIG_PROTECT_MASK="/etc/ca-certificates.conf /etc/env.d /etc/gconf /etc/gentoo-release /etc/php/apache2-php5.3/ext-active/ /etc/php/cgi-php5.3/ext-active/ /etc/php/cli-php5.3/ext-active/ /etc/revdep-rebuild /etc/sandbox.d /etc/terminfo" CXXFLAGS="-O2 -pipe" DISTDIR="/local/portage/distfiles" FCFLAGS="-O2 -pipe" FEATURES="assume-digests binpkg-logs buildpkg collision-protect config-protect-if-modified distlocks ebuild-locks fixlafiles merge-sync news parallel-fetch protect-owned sandbox sfperms strict unknown-features-warn unmerge-logs unmerge-orphans userfetch userpriv usersandbox" FFLAGS="-O2 -pipe" GENTOO_MIRRORS="http://distfiles.gentoo.org" LDFLAGS="-Wl,-O1 -Wl,--as-needed" MAKEOPTS="-j4" PKGDIR="/local/portage/packages" PORTAGE_CONFIGROOT="/" PORTAGE_RSYNC_OPTS="--recursive --links --safe-links --perms --times --compress --force --whole-file --delete --stats --human-readable --timeout=180 --exclude=/distfiles --exclude=/local --exclude=/packages" PORTAGE_TMPDIR="/local/portage/build" PORTDIR="/usr/portage" PORTDIR_OVERLAY="/local/portage/overlay" SYNC="rsync://rsync.bu.avira.com/gentoo-portage" USE="amd64 bzip2 caps crypt cxx hardened ipv6 jpeg multilib nptl pam pic png readline sse sse2 ssl truetype unicode xml zlib" APACHE2_MODULES="alias auth_basic authn_dbd authn_default authn_file authz_default authz_groupfile authz_host authz_user autoindex deflate dir env filter headers log_config mime rewrite setenvif" APACHE2_MPMS="prefork" CURL_SSL="openssl" ELIBC="glibc" KERNEL="linux" NGINX_MODULES_HTTP="access auth_basic autoindex browser gzip gzip_static headers_more limit_req limit_zone proxy referer rewrite stub_status" PHP_TARGETS="php5-3" USERLAND="GNU" Unset: CPPFLAGS, CTARGET, EMERGE_DEFAULT_OPTS, INSTALL_MASK, LANG, LC_ALL, LINGUAS, PORTAGE_BUNZIP2_COMMAND, PORTAGE_COMPRESS, PORTAGE_COMPRESS_FLAGS, PORTAGE_RSYNC_EXTRA_OPTS, USE_PYTHON
I guess I should open a bug in the upstream bugzilla? this crash happens every time mysqld is started without --skip-slave. use flags are as follows: [ebuild R ] dev-db/mysql-5.1.66 USE="ssl -berkdb -big-tables -cluster -community -debug -embedded -extraengine -latin1 -max-idx-128 -minimal -pbxt -perl -profiling (-selinux) -static {-test} -xtradb" 0 kB tried debug, but got a warning about it being broken since 5.1.51 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 relay_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);
stale bug. upstream was also uninterested in it.
