1.故障现象
mysql 5.7的从库最近延迟一直在上升,查看状态发现exec_master_log_pos 一直卡在154794029不动,slave_sql_running_state一直为 Reading event from the relay log
2.解决步骤
尝试关闭slave进程,再启动,发现没效果。
观察io状态,还有mysql error log,没有什么发现。
尝试重启mysql从库,再启动复制进程,没有效果。
尝试查看有没锁表状态,没发现异常。
尝试解析relay log状态:
[root@sz-hbs-db2 relaylog]# /usr/local/mysql/bin/mysqlbinlog -vvv relay.000033 | grep -i -B 30 -A 10 "154794029"
# at 154793953
#240127 22:25:03 server id 101137 end_log_pos 154793998 CRC32 0x0413d22f Update_rows: table id 1705 flags: STMT_END_F
'/*!*/;
### UPDATE `apolloportaldb`.`spring_session`
### WHERE
### @1='a19a31f3-2522-43b0-98a5-0afc96123dee' /* STRING(144) meta=65168 nullable=0 is_null=0 */
### @2='b11d28dc-a8d1-49d3-b49f-e6ed5b7b1bb7' /* STRING(144) meta=65168 nullable=0 is_null=0 */
### @3=1706181767938 /* LONGINT meta=0 nullable=0 is_null=0 */
### @4=1706365442850 /* LONGINT meta=0 nullable=0 is_null=0 */
### @5=1800 /* INT meta=0 nullable=0 is_null=0 */
### @6=1706367242850 /* LONGINT meta=0 nullable=0 is_null=0 */
### @7='apollo' /* VARSTRING(400) meta=400 nullable=1 is_null=0 */
### SET
### @1='a19a31f3-2522-43b0-98a5-0afc96123dee' /* STRING(144) meta=65168 nullable=0 is_null=0 */
### @2='b11d28dc-a8d1-49d3-b49f-e6ed5b7b1bb7' /* STRING(144) meta=65168 nullable=0 is_null=0 */
### @3=1706181767938 /* LONGINT meta=0 nullable=0 is_null=0 */
### @4=1706365503834 /* LONGINT meta=0 nullable=0 is_null=0 */
### @5=1800 /* INT meta=0 nullable=0 is_null=0 */
### @6=1706367303834 /* LONGINT meta=0 nullable=0 is_null=0 */
### @7='apollo' /* VARSTRING(400) meta=400 nullable=1 is_null=0 */
# at 154794211
#240127 22:25:03 server id 101137 end_log_pos 154794029 CRC32 0xcb592723 Xid = 193750557
COMMIT/*!*/;
# at 154794242
#240127 22:24:36 server id 101137 end_log_pos 154794094 CRC32 0xa5e0c7b1 Anonymous_GTID last_committed=35 sequence_number=36 rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 154794307
#240127 22:24:36 server id 101137 end_log_pos 154794168 CRC32 0x689ab05d Query thread_id=801492 exec_time=0 error_code=0
SET TIMESTAMP=1706365476/*!*/;
/*!C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=33/*!*/;
查看154794029 这个点位是已经执行过了update语句,对比下表的数据是否已经更改过来。
发现下一步事件是设置SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 154794242
#240127 22:24:36 server id 101137 end_log_pos 154794094 CRC32 0xa5e0c7b1 Anonymous_GTID last_committed=35 sequence_number=36 rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
尝试跳过这个event
STOP SLAVE ;
SET GLOBAL sql_slave_skip_counter=1;
START SLAVE;
之后发现从库延迟立马降了下来。