mysql got signal 11_【MySQL】mysqld got signal 11 案例一则

今天遇到一个案例:监控报警 mysql 服务器突然crash,登陆数据库服务器发现mysqld_safe 进程存在,但是无法登陆数据库。

root@rac1 # my

Entry Port ==== 3306

ERROR 2003 (HY000): Can't connect to MySQL server on '127.0.0.1' (111)

root@masterdb1a.cms.xyi.aliyun.com # ps -ef | grep mysqld

root     15511 12134  0 14:06 pts/1    00:00:00 /bin/sh /usr/bin/mysqld_safe --defaults-file=/etc/my330**f --skip-slave-start=1

mysql    19846 15511 69 14:10 pts/1    00:00:05 /usr/sbin/mysqld --defaults-file=/etc/my330**f --basedir=/ --datadir=/home/mysql/data3306/mysql --user=mysql --skip-slave-start=1 --log-error=/home/mysql/data3306/mysql/master-error.log --open-files-limit=8192 --pid-file=/home/mysql/data3306/mysql/rac1.pid --socket=/tmp/mysql3306.sock --port=3306

master-error.log中的报警日志如下，mysqld在不停的crash,restart,但是slave 重启之后,数据库立刻就crash。

130313 13:46:59 InnoDB Plugin 1.0.9 started; log sequence number 1854409642790

130313 13:46:59 [Note] Recovering after a crash using /home/mysql/data3306/mysql/mysql-bin

130313 13:46:59 [Note] Starting crash recovery...

130313 13:46:59 [Note] Crash recovery finished.

130313 13:46:59 [Note] Event Scheduler: Loaded 0 events

130313 13:46:59 [Note] /usr/sbin/mysqld: ready for connections.

Version: '5.1.48-aliyun-log'  socket: '/tmp/mysql3306.sock'  port: 3306  MySQL Community Server (GPL)

130313 13:46:59 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.003860' at position 498385473, relay log '/home/mysql/data3306/mysql/slave-relay.011248' position: 498385618

130313 13:46:59 [Note] Slave I/O thread: connected to master 'replicator@172.18.150.10:3306',replication started in log 'mysql-bin.003860' at position 521361565

130313 13:47:00 - 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=314572800

read_buffer_size=1048576

max_used_connections=1

max_threads=4000

threads_connected=0

It is possible that mysqld could use up to

key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 8540418 K

bytes of memory

Hope that's ok; if not, decrease some variables in the equation.

==========================================================================

上述内容实际上可以忽略 计算公式的值也不过850M,而数据库服务器总共47g,不会不满足分配对应的内存。由于数据库一启动slave 进程就crash,所以检查相关的binlog 内容 mysql-bin.003860  position 498385473 开始的内容是什么的？

root@rac1 # mysqlbinlog  --no-defaults -v -v -v --start-position=498385473 mysql-bin.003860 > /home/admin/003860.sql

root@rac1 #

root@rac1 #

root@rac1 #

root@rac1 # cd /home/admin/

root@rac1 # more 003860.sql

# at 498385473

#130313 13:43:25 server id 1503306010  end_log_pos 498385553    Query   thread_id=81671382      exec_time=0

....忽略一些注释信息

BEGIN

/*!*/;

# at 498385553

# at 498385657

# at 498385728

# at 498385794

# at 498386162

#130313 13:43:25 server id 1503306010  end_log_pos 498385657    Table_map: `c`.`node` mapped to number 0

#130313 13:43:25 server id 1503306010  end_log_pos 498385728    Table_map: `c`.`entry` mapped to number 0

#130313 13:43:25 server id 1503306010  end_log_pos 498385794    Table_map: `c`.`xxx_entry_rel` mapped to number 307680

#130313 13:43:25 server id 1503306010  end_log_pos 498386162    Update_rows: table id 0

#130313 13:43:25 server id 1503306010  end_log_pos 498386732    Update_rows: table id 0 flags: STMT_END_F

问题就出在红色的标记的位置,两个不同的表却被标记为 同一个0,sql thread 要用 number值来应用主库传过来的日志，重做sql，如果number值一样,就会出现张冠李戴的情况,sql应用报错。怀疑遇到bug。

thd: 0x2ab43a577000

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 = 0x582130c8 thread_stack 0x40000

/usr/sbin/mysqld(my_print_stacktrace+0x21)[0x89a177]

/usr/sbin/mysqld(handle_segfault+0x35c)[0x5c75c8]

/lib64/libpthread.so.0[0x313700e7c0]

/lib64/libc.so.6(memset+0xade)[0x313647b44e]

/usr/sbin/mysqld(_ZN12Field_string6unpackEPhPKhjb+0x99)[0x5985a9]

/usr/sbin/mysqld(_Z10unpack_rowPK14Relay_log_infoP8st_tablejPKhPK9st_bitmapPS5_Pmbb+0x158)[0x6a2350]

/usr/sbin/mysqld(_ZN14Rows_log_event8find_rowEPK14Relay_log_info+0x39c)[0x68ef6c]

/usr/sbin/mysqld(_ZN21Update_rows_log_event11do_exec_rowEPK14Relay_log_info+0x13)[0x697267]

/usr/sbin/mysqld(_ZN14Rows_log_event14do_apply_eventEPK14Relay_log_info+0x7a4)[0x69592e]

/usr/sbin/mysqld(_Z26apply_event_and_update_posP9Log_eventP3THDP14Relay_log_info+0xfd)[0x709b2d]

/usr/sbin/mysqld(handle_slave_sql+0x96a)[0x70f09a]

/lib64/libpthread.so.0[0x31370064a7]

/lib64/libc.so.6(clone+0x6d)[0x31364d3c2d]

Trying to get some variables.

Some pointers may be invalid and cause the dump to abort...

上面的信息是说一些update相关的事情(有待进一步确认具体意义),解析的binlog中事务都是在对entry表多update操作，且字段@7明显有问题 多达数千字节。和前端开发确定@7字段应该有限制。

### UPDATE c.entry

### WHERE

###   @1=24715 /* INT meta=0 nullable=1 is_null=0 */

###   @2=NULL /* INT meta=0 nullable=1 is_null=1 */

###   @3=838939137 /* INT meta=0 nullable=1 is_null=0 */

###   @4=1497432085 /* INT meta=0 nullable=1 is_null=0 */

###   @5=808530481 /* INT meta=0 nullable=1 is_null=0 */

###   @6=842086449 /* INT meta=0 nullable=1 is_null=0 */

###   @7=NULL /* INT meta=765 nullable=1 is_null=1 */

...

### SET

###   @1=-1593835520 (2701131776) /* INT meta=0 nullable=1 is_null=0 */

###   @2=72062304000948757 /* LONGINT meta=0 nullable=1 is_null=0 */

###   @3=3277057 /* INT meta=0 nullable=1 is_null=0 */

###   @4=30000 /* INT meta=0 nullable=1 is_null=0 */

###   @5=-903638655 (3391328641) /* INT meta=0 nullable=1 is_null=0 */

###   @6=4684 /* INT meta=0 nullable=1 is_null=0 */

###   @7='\x00\x00a\x1912\x00\x00\x1100:16:3e:0e:13:77 ........省略N多 ....'

最终的解决方法是跳过出问题的binlog位置，重新启动slave 进程。问题解决！

接下来

1 同步 entry表，使之和主库一致。

2 要求开发限制@7 字段的长度而非无限制。