今天遇到一個案例:監控報警 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 # 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 欄位的長度而非無限制。

【MySQL】mysqld got signal 11 案例一則

相關文章