从一个线上问题分析binlog与内部XA事务提交过程

1. 问题
业务上新增一条订单记录,用户接收到BinLake拉取的MySQL从库数据消息后,马上根据消息内的订单号去查询同一个MySQL从库,发现有些时候无法查到该条数据,等待大约500ms~1000ms后再去查询数据库,可以查询到该条数据。
注: BinLake为京东商城数据库技术部自研的一套订阅和消费MySQL数据库binlog的组件,本例所描述的问题是业务方希望根据订阅的binlog来获取实时订单等业务消息。
2. Binlog与内部XA
2.1. XA的概念
XA(分布式事务)规范主要定义了(全局)事务管理器(TM: Transaction Manager)和(局部)资源管理器(RM: Resource Manager)之间的接口。XA为了实现分布式事务,将事务的提交分成了两个阶段:也就是2PC (tow phase commit),XA协议就是通过将事务的提交分为两个阶段来实现分布式事务。
两阶段
1)prepare 阶段
事务管理器向所有涉及到的数据库服务器发出prepare"准备提交"请求,数据库收到请求后执行数据修改和日志记录等处理,处理完成后只是把事务的状态改成"可以提交",然后把结果返回给事务管理器。即:为prepare阶段,TM向RM发出prepare指令,RM进行操作,然后返回成功与否的信息给TM。
2)commit 阶段
事务管理器收到回应后进入第二阶段,如果在第一阶段内有任何一个数据库的操作发生了错误,或者事务管理器收不到某个数据库的回应,则认为事务失败,回撤所有数据库的事务。数据库服务器收不到第二阶段的确认提交请求,也会把"可以提交"的事务回撤。如果第一阶段中所有数据库都提交成功,那么事务管理器向数据库服务器发出"确认提交"请求,数据库服务器把事务的"可以提交"状态改为"提交完成"状态,然后返回应答。即:为事务提交或者回滚阶段,如果TM收到所有RM的成功消息,则TM向RM发出提交指令;不然则发出回滚指令。
外部与内部XA
MySQL中的XA实现分为:外部XA和内部XA。前者是指我们通常意义上的分布式事务实现;后者是指单台MySQL服务器中,Server层作为TM(事务协调者,通常由binlog模块担当),而服务器中的多个数据库实例作为RM,而进行的一种分布式事务,也就是MySQL跨库事务;也就是一个事务涉及到同一条MySQL服务器中的两个innodb数据库(目前似乎只有innodb支持XA)。内部XA也可以用来保证redo和binlog的一致性问题。
2.2. redo与binlog的一致性问题
我们MySQL为了兼容其它非事务引擎的复制,在server层面引入了 binlog, 它可以记录所有引擎中的修改操作,因而可以对所有的引擎使用复制功能; 然而这种情况会导致redo log与binlog的一致性问题;MySQL通过内部XA机制解决这种一致性的问题。
第一阶段:InnoDB prepare, write/sync redo log;binlog不作任何操作;
第二阶段:包含两步,1> write/sync Binlog; 2> InnoDB commit (commit in memory);
当然在5.6之后引入了组提交的概念,可以在IO性能上进行一些提升,但总体的执行顺序不会改变。
当第二阶段的第1步执行完成之后,binlog已经写入,MySQL会认为事务已经提交并持久化了(在这一步binlog就已经ready并且可以发送给订阅者了)。在这个时刻,就算数据库发生了崩溃,那么重启MySQL之后依然能正确恢复该事务。在这一步之前包含这一步任何操作的失败都会引起事务的rollback。
第二阶段的第2大部分都是内存操作,比如释放锁,释放mvcc相关的read view等等。MySQL认为这一步不会发生任何错误,一旦发生了错误那就是数据库的崩溃,MySQL自身无法处理。这个阶段没有任何导致事务rollback的逻辑。在程序运行层面,只有这一步完成之后,事务导致变更才能通过API或者客户端查询体现出来。
下面的一张图,说明了MySQL在何时会将binlog发送给订阅者。

理论上来说,也可以在commit阶段完成之后再将binlog发送给订阅者,但这样会增大主从延迟的风险。
3. 相关代码

  1. int MYSQL_BIN_LOG::ordered_commit(THD *thd, bool all, bool skip_commit) {
  2. .....
  3. //进入flush stage,
  4. change_stage(thd, Stage_manager::FLUSH_STAGE, thd, NULL, &LOCK_log);
  5. ....
  6. //通知底层存储引擎日志刷盘
  7. process_flush_stage_queue(&total_bytes, &do_rotate, &wait_queue);
  8. .....
  9. //将各个线程的binlog从cache写到文件中
  10. flush_cache_to_file(&flush_end_pos);
  11. ....
  12. //进入到Sync stage
  13. change_stage(thd, Stage_manager::SYNC_STAGE, wait_queue, &LOCK_log,
  14. &LOCK_sync));
  15. //binlog fsync落盘
  16. sync_binlog_file(false)
  17. //通知binlog发送线程,有新的binlog落盘可以发送到订阅者了
  18. update_binlog_end_pos(tmp_thd->get_trans_pos());
  19. //进入commit state
  20. change_stage(thd, Stage_manager::COMMIT_STAGE, final_queue,
  21. leave_mutex_before_commit_stage, &LOCK_commit);
  22. ....
  23. //事务状态提交
  24. process_commit_stage_queue(thd, commit_queue);
  25. ....
    }

其中,在update_binlog_end_pos之后,binlog发送线程就已经可以读取最新的binlog发送给订阅者了。当订阅者收到这些binlog之后如果process_commit_stage_queue因为系统调度等原因还未执行完成,那么订阅者碰巧在此时发起问题中所描述的查询,就会发生查询不到的情况。
下面我们看一下process_commit_stage_queue都做了什么。
在process_commit_stage_queue会分别调用到binlog的commit方法binlog_commit和innodb的commit函数trx_commit_in_memory。

  1. static int binlog_commit(handlerton , THD , bool) {
  2. DBUG_ENTER("binlog_commit");
  3. /*
  4. Nothing to do (any more) on commit.
  5. */
  6. DBUG_RETURN(0);
  7. }
    在binlog_commit中什么也不做,因为跟binlog有关的操作前面都已经做完了。
    最后看一下存储引擎innodb的trx_commit_in_memory都干了什么。
  8. static void trx_commit_in_memory(
  9. trx_t trx, /!< in/out: transaction */
  10. const mtr_t mtr, /!< in: mini-transaction of
  11. trx_write_serialisation_history(), or NULL if
  12. the transaction did not modify anything */
  13. bool serialised)
  14. /*!< in: true if serialisation log was
  15. written */
  16. {
  17. ....
  18. //释放锁
  19. lock_trx_release_locks(trx);
  20. ut_ad(trx_state_eq(trx, TRX_STATE_COMMITTED_IN_MEMORY));
  21. .....
  22. //释放mvcc相关的read view
  23. if (trx->read_only || trx->rsegs.m_redo.rseg == NULL) {
  24. MONITOR_INC(MONITOR_TRX_RO_COMMIT);
  25. if (trx->read_view != NULL) {
  26. trx_sys->mvcc->view_close(trx->read_view, false);
  27. }
  28. } else {
  29. ut_ad(trx->id > 0);
  30. MONITOR_INC(MONITOR_TRX_RW_COMMIT);
  31. }
  32. }
  33. ....
  34. //清理insert操作相关的undo log(注意,此时只有insert的undo需要清理)
  35. if (mtr != NULL) {
  36. if (trx->rsegs.m_redo.insert_undo != NULL) {
  37. trx_undo_insert_cleanup(&trx->rsegs.m_redo, false);
  38. }
  39. if (trx->rsegs.m_noredo.insert_undo != NULL) {
  40. trx_undo_insert_cleanup(&trx->rsegs.m_noredo, true);
  41. }
  42. }

这一步完成之后,在运行时刻事务的变更才能被查询到。但需要记住,MySQL在binlog落盘成功后就认为事务的持久化已经完成。
30. 总结
在binlog落盘之后,MySQL就会认为事务的持久化已经完成(在这个时刻之后,就算数据库发生了崩溃都可以在重启后正确的恢复该事务)。但是该事务产生的数据变更被别的客户端查询出来还需要在commit全部完成之后。MySQL会在binlog落盘之后会立即将新增的binlog发送给订阅者以尽可能的降低主从延迟。但由于多线程时序等原因,当订阅者在收到该binlog之后立即发起一个查询操作,可能不会查询到任何该事务产生的数据变更(因为此时该事务所处线程可能尚未完成最后的commit步骤)。
如果应用需要根据binlog作为一些业务逻辑的触发点,还是需要考虑引入一些延时重试机制或者重新考虑合适的实现架构。

本文由京东商城数据库技术部王治提供。

原文地址:http://blog.51cto.com/wangwei007/2323844

时间: 2024-10-09 01:33:36

从一个线上问题分析binlog与内部XA事务提交过程的相关文章

[MySQL CPU]线上飙升800%,load达到12的解决过程

接到报警通知,负载过高,达到800%,load也过高,有11了. MySQL版本号为5.6.12-log 1 top 之后,确实是mysqld进程占领了全部资源. 2 查看error日志,无不论什么异常 3 show eninge innodb status\G,没有死锁信息. 4 show full processlist; 没有耗时很大的慢sql再跑.看并发,当前的线程总数量也才30个左右. 5 查看iostat,读写正常. 究竟是什么问题呢?查看slow log,发现例如以下SQL,频繁运

线上日志分析与其他一些脚本

对一些线上常用的脚本进行了一下总结和说明,免得以后忘记了~ 一·线上发布API集群的代码脚本: #!/bin/bash #Author CCC host=' 10.44.22.113 10.44.22.113 10.44.22.112 10.44.22.112 10.44.22.113 10.44.22.113 10.44.22.114 10.44.22.114 10.44.22.115 10.44.22.115 10.44.22.119 10.44.22.119 ' #basePath='/v

【MySQL 线上 BUG 分析】之 多表同字段异常:Column ‘xxx’ in field list is ambiguous

一.生产出错! 今天早上11点左右,我在工作休息之余,撸了一下猫.突然,工作群响了,老大在里面说:APP出错了! 妈啊,这太吓人了,因为只是说了出错,但是没说错误的信息.所以我赶紧到APP上看看. 这果然是出错了,而且还是简单而粗暴的500,太吓人了. 二.本地赶紧调试起来! 既然线上出错了,我们又不能直接进行调试,那当然得马上在本地搞起来了! 1.代码是否有错? 立马启动本地的项目,访问对应的接口,看看是不是代码哪里出错了. 好了,本地的代码和 SQL 都是没错的! 2.SQL 是否有错? 那

线上解决问题分析

昨天公司的服务器升级硬件,只升级了CPU和 内存,然后重启过后,线上运行的东西就运行不了,查了一下,所有端口和服务有没有开放,防火墙那些,结果发现端口和服务,防火墙允许的端口都开了 还是运行不了,带到晚上10点,突然有一个哥们说了一句,要不把防火墙关了试一下,结果就好了,忘了查看防火墙信息 目前我们只用到了的端口是 cat: /etc/sysconfig/iptables: Permission denied [[email protected]-8a6e210a8d27536a ~]$ sud

线上环境 分析java问题 常见命令

在生产上进程需要分析jvm运行情况,今天分享几个自己常用的命令,持续更新,欢迎补充 1.jps jstack -l {pid} > jstack.log #查看线程快照信息 2.jps jmap -heap {pid} #查看gc快照信息 jmap -dump:format=b,file=dump.bin {pid} #dump内存快照 用mat分析dump文件 3.jps top -H -p {pid} 查看运行线程数量和高CPU和长期未释放的线程 线程id 10转16进制 jstack -l

(转)HBase工程师线上工作经验总结----HBase常见问题及分析

阅读本文可以带着下面问题:1.HBase遇到问题,可以从几方面解决问题?2.HBase个别请求为什么很慢?你认为是什么原因?3.客户端读写请求为什么大量出错?该从哪方面来分析?4.大量服务端exception,一般原因是什么?5.系统越来越慢的原因是什么?6.Hbase数据写进去,为什么会没有了,可能的原因是什么?7. regionserver发生abort,遇到最多是什么情况?8.从哪些方面可以判断HBase集群是否健康?9.为了加强HBase的安全性,你会采取哪些措施?在Tcon分布式系统测

HBase工程师线上工作经验总结----HBase常见问题及分析

阅读本文可以带着下面问题:1.HBase遇到问题,可以从几方面解决问题?2.HBase个别请求为什么很慢?你认为是什么原因?3.客户端读写请求为什么大量出错?该从哪方面来分析?4.大量服务端exception,一般原因是什么?5.系统越来越慢的原因是什么?6.Hbase数据写进去,为什么会没有了,可能的原因是什么?7. regionserver发生abort,遇到最多是什么情况?8.从哪些方面可以判断HBase集群是否健康?9.为了加强HBase的安全性,你会采取哪些措施? 在Tcon分布式系统

记一次线上故障处理

前言 下面信息裁剪了一些,有的不确定了就拍脑袋定了,大体情况还是和实际相似. 整体过程 最开始接到告警 一个周六的 9:00 接到钉钉告警A应用线上 499 数量大量增加, A应用的背景介绍 先说下A应用的背景,我们A应用每天上亿次访问,主要是给别的厂商买接口的,按照各个厂商的调用量收钱,A 应用的实例数有几十个,接入的 nginx 也有 10 个以上,分布在 3 个机房,平均RT时间 15 ms,一般 499 数量多是某个tomcat或者某个机房的资源有问题导致的,这种问题登录我们收集了 ng

线上使用zabbix报警脚本(含图片)

分享一个线上使用的自定义zabbix报警脚本,脚本思路大致如下: 1.使用爬虫获取报警图片(前提是要获得报警的item) 2.将图片与邮件内容整合 3.发送邮件 4.日志记录 脚本内容如下: #!/usr/bin/python #coding:utf-8 import sys,time,re,os,glob import smtplib from email.mime.text import MIMEText from email.mime.image import MIMEImage from