BUG解析:InnoDB两次写与多实例bufferpool

在我测试过程中，使用的是自动提交，一条语句为一个事务，开8个线程的话大概是单线程复制的5倍（共有20个表），性能应该还是不错的，多线程下QPS可以达到32000，单线程差不多6500，但是这是把double write关了的情况，如果打开了double write，那么一开始的QPS也差不多是32000，但做几分钟之后，这个数字一直在减小，那个感觉啊真是不好，怎么老是一直减少呢，等到跟上来了，一直看着它减少到15000，这个很不好，相当于是2倍的提升，这个看上去完全是因为double write的影响，因为只是修改了这么一个参数而出现的两个不同的结果，但是查遍了网上也都说double write的影响只会是5-10%，那么就奇怪了，我这个的影响明显是50%以上啊，难道是两次写就是50%？不对的，因为double write本来就是连续写的。肯定是哪里有其它的问题。

超过十年行业经验，技术领先，服务至上的经营模式，全靠网络和口碑获得客户，为自己降低成本，也就是为客户降低成本。到目前业务范围包括了：成都网站制作、网站设计，成都网站推广，成都网站优化，整体网络托管，成都小程序开发，微信开发，App定制开发，同时也可以让客户的网站和网络营销和我们一样获得订单和生意！

然后在无奈之下，在测试时，通过pstack工具看MYSQL运行时慢到底是什么样的堆栈，到底是在等啥？什么影响了它的性能，然后看到很多时候堆栈都是这样的：

 
 
 
    
  
  
  
  1. Thread 4 (Thread 0x7fdadd357700 (LWP 9800)): 
    2. 
  
  
  
  2. #1  0x00000000008d3007 in os_event_wait_low () 
    3. 
  
  
  
  3. #2  0x00000000008230ae in sync_array_wait_event () 
    4. 
  
  
  
  4. #3  0x0000000000823f46 in mutex_spin_wait () 
    5. 
  
  
  
  5. #4  0x00000000008674df in buf_flush_buffered_writes () 
    6. 
  
  
  
  6. #5  0x0000000000868b97 in buf_flush_batch () 
    7. 
  
  
  
  7. #6  0x000000000086a6df in buf_flush_list () 
    8. 
  
  
  
  8. #7  0x00000000008c31b2 in log_check_margins () 
    9. 
  
  
  
  9. #8  0x00000000008eba6a in row_ins_index_entry_low () 
    10. 
  
  
  
  10. #9  0x00000000008efd9e in row_ins_step () 
    11. 
  
  
  
  11. #10 0x0000000000803be9 in row_insert_for_mysql () 
    12. 
  
  
  
  12. #11 0x00000000007f2d6c in ha_innobase::write_row(unsigned char*) () 
    13. 
  
  
  
  13. #12 0x000000000068c760 in handler::ha_write_row(unsigned char*) () 
    14. 
  
  
  
  14. #13 0x000000000055a2ed in write_record(THD*, TABLE*, st_copy_info*) () 
    15. 
  
  
  
  15. Thread 3 (Thread 0x7fdadd316700 (LWP 9801)): 
    16. 
  
  
  
  16. #1  0x00000000008d3007 in os_event_wait_low () 
    17. 
  
  
  
  17. #2  0x00000000008230ae in sync_array_wait_event () 
    18. 
  
  
  
  18. #3  0x0000000000823f46 in mutex_spin_wait () 
    19. 
  
  
  
  19. #4  0x00000000008674df in buf_flush_buffered_writes () 
    20. 
  
  
  
  20. #5  0x0000000000868b97 in buf_flush_batch () 
    21. 
  
  
  
  21. #6  0x000000000086a6df in buf_flush_list () 
    22. 
  
  
  
  22. #7  0x00000000008c31b2 in log_check_margins () 
    23. 
  
  
  
  23. #8  0x00000000008eba6a in row_ins_index_entry_low () 
    24. 
  
  
  
  24. #9  0x00000000008efd9e in row_ins_step () 
    25. 
  
  
  
  25. #10 0x0000000000803be9 in row_insert_for_mysql () 
    26. 
  
  
  
  26. #11 0x00000000007f2d6c in ha_innobase::write_row(unsigned char*) () 
    27. 
  
  
  
  27. #12 0x000000000068c760 in handler::ha_write_row(unsigned char*) () 
    28. 
  
  
  
  28. #13 0x000000000055a2ed in write_record(THD*, TABLE*, st_copy_info*) () 
    29.

从上面的堆栈中可以看出，SQL线程很多都是在buf_flush_buffered_writes函数中等待，而这个函数正好是处理double write的函数，所以我重点看了这里，然后一进去就明白了是为什么了，看到这个函数一开始有一行mutex_enter(&(trx_doublewrite->mutex))，而在函数退出前有一行mutex_exit(&(trx_doublewrite->mutex))，里面是处理所有double write缓存起来的页面，也就是前面要刷的页面，因为INNODB支持多个BUFFER POOL实例，这样可以增大并发度，页面可以放在不同的BUFFER POOL中，这样两个BUFFER POOL中的页面在同时访问时可以互不干扰，那么可想而知，double write缓存的页面就是来自多个SQL线程并发收集起来的，那么很容易想到，问题其实就里在这里，由多个线程做检查点，但只有一个线程会做double write，这样产生了瓶颈，导致等待一段时间后就会越来越慢，也许就是这个问题，那后面就看了一下代码，它的实现是否允许多个线程做检查点呢，主要是看函数log_free_check（log_check_margins）的实现，因为这个函数才是用户线程调用的，代码是这样的：

 
 
 
    
  
  
  
  1.  log_free_check(void) 
    2. 
  
  
  
  2. { 
    3. 
  
  
  
  3.        if (log_sys->check_flush_or_checkpoint) 
    4. 
  
  
  
  4.               log_check_margins(); 
    5. 
  
  
  
  5. } 
    6.

那就主要是log_sys->check_flush_or_checkpoint有没有可能多个线程进来了，最后发现在里面直接就调log_checkpoint_margin函数了，而再进去里面，就是对buffer pool中的脏页面进行刷盘了，同时这里刷盘是刷每一个buffer pool instance的，而不是分开自己刷自己的，当然对于某一个buffer pool instance，只会有一个线程做，进来之后会找到没有任何一个线程在做刷盘的buffer pool instance来做，所以其实是并发处理这多个buffer pool instance的，那么现在得到的结论就是经常性的多个线程一起做刷盘操作，而做完刷盘之后，如果打开了double write，则要将所有的buffer pool instance要刷的页面做double write，上面也看到了，它是一个mutex，多个线程一起抢这一个临界区，导致系统的并发度大大的降低，那么现在问题已经很明显，原因也已经很明显，这个其实与DOUBLEWRITE没关系，那个5-10%我还是承认的，这里只不过是代码实现有问题而已。

那么结论就里说，这其实是INNODB的一个BUG，就是多BUFFERPOOL实例下，DOUBLEWRITE会导致系统并发性能大大降低的问题。

那如何解决呢？

首先我已经向bugs.mysql.com报了BUG，链接http://bugs.mysql.com/bug.php?id=67808&edit=2，本人英语不好，写得挺费劲。

难道就这样等它解决吗？不对，我已经等不上了，即使出来了也不是在5.5.27上啊，所以自己解决吧。

这里归根结底的问题就是做检查点函数log_checkpoint_margin中存在并发，导致DOUBLEWRITE的瓶颈出现了，因为在INNODB的增删改操作的一开始，都会直接先调用log_free_check这个函数，出现这样的问题的概率太高了。

想想，这个做检查点需要多个线程吗？如果是一个线程在做是不是就没有问题了？DOUBLEWRITE的瓶颈也不存在了？确实是这样的。

再想想，做检查点需要多个线程吗？只有一个线程做是不是就够了？因为检查点归根结底是为了给日志让空间出来，日志一直往2个（默认）日志文件中循环添加，第一个写完写第二个，写完第二个再写第一个，其实就里一个圈，不断的循环，那么这里就必须要保证，向里面写的数据的位置不能走到检查点的位置的前面去（因为数据的LSN是新产生的日志的LSN，肯定是要小于检查点的LSN的，也可以表示为，数据的LSN必须要小于检查点的LSN加上整个日志组的日志容量），因为检查点LSN前面的日志表明，所有数据已经都写入磁盘了，可以扔掉了，那如果大于了，就会把没有做检查点的日志覆盖掉，这样会导致数据错误或者更严重的一些问题。

有了这样的想法，则这个问题应该不难解决，先在log_sys中加入一个成员checkpoint_doing，用来表示现在是否有线程正在做检查点，再修改函数log_check_margins，最前面加上代码段：

 
 
 
    
  
  
  
  1. mutex_enter(&(log_sys->mutex)); 
    2. 
  
  
  
  2. if (log_sys->checkpoint_doing > 0) { 
    3. 
  
  
  
  3.        mutex_exit(&(log_sys->mutex)); 
    4. 
  
  
  
  4.       return; 
    5. 
  
  
  
  5. } 
    6. 
  
  
  
  6. log_sys->checkpoint_doing++; 
    7. 
  
  
  
  7. mutex_exit(&(log_sys->mutex)); 
    8.

上面这表示如果有线程已经做了，那这里不会再进去，直接就出去了，如果没有线程在做，那么当前线程才做，同时将标志置为正在做。这样保证了只有一个用户线程会做检查点。当然在修改及判断这个checkpoint_doing的时候必须要对其进行保护，上面代码中也已经有所体现。那么这样就好了吗？如果当前系统的压力非常大，那么出去了，而没有做检查点检查，继续做写操作，这样有可能会导致新的日志写的超过了检查点的位置，导致数据覆盖，所以还需要做一个修改操作。

因为在INNODB中写日志的函数只有log_write_up_to，并且这只会有一个线程写，那么为了防止这个问题的话是不是在它写日志的时候检查一下，如果空间不够了等待或者做一次检查点后再继续做，是不是就没有问题了？我认为确实是这样的，那么继续修改：

 
 
 
    
  
  
  
  1. if (!log_sys->checkpoint_waiting && log_sys->lsn - log_sys->last_checkpoint_lsn > log_sys->max_checkpoint_age) 
    2. 
  
  
  
  2. { 
    3. 
  
  
  
  3.      mutex_exit(&(log_sys->mutex)); 
    4. 
  
  
  
  4.        log_sys->checkpoint_waiting = 1; 
    5. 
  
  
  
  5.        log_check_margins(); 
    6. 
  
  
  
  6.        log_sys->checkpoint_waiting = 0; 
    7. 
  
  
  
  7.        goto loop; 
    8. 
  
  
  
  8. } 
    9.

这段代码就加在log_write_up_to函数中五个判断条件之后，能走到这里说明这次的日志要写入日志文件了，那么这里检查是最合适的，上面的代码有一个条件判断，最主要是的log_sys->lsn - log_sys->last_checkpoint_lsn > log_sys->max_checkpoint_age，这个表示的是如果当前的最新LSN超过检查点LSN的数目已经大于最大的做检查点差值数，则就等待或者做一次检查点，这个条件与log_checkpoint_margin函数中判断是不是要做检查点的条件是一样的，这样的话就保证了这段代码中调用了log_check_margins时要么里面已经有人正在做，要么自己肯定能做一次检查点，不然在这里会产生死循环。做了之后从而使的log_sys->last_checkpoint_lsn变大，向前走，让出空间，这样这次日志就可以写入进去了，那么goto loop可以起到循环等待的作用。

上面还看到一个新的成员checkpoint_waiting，这个是为了防止进入死循环而设置的，因为log_check_margins里面还会再调用log_write_up_to。

那么到现在为止，这个问题应该算是可以了的，接下来就是测试了，把多线程的SLAVE复制跑起来，我发现这个是一个非常好的并发测试工具，不需要专门写应用来设置并发环境。

测试的结果表明，那么问题不复存在，平均的QPS在打开DOUBLEWRITE时都是31000，这个数字挺好的。问题解决，同时发现那个分支就从来没有进去过，说明用户线程做了已经足够了，那里只是一个机率很小的问题预防而已。

但是这个修改现在还没有办法去验证，只能由各位先从理论上看看是不是正确吧，我本人认为应该还是没什么大问题的，请各位大侠指点！

这里要感谢一下我的好朋友好战友陈福荣同学，在MYSQL学习及实现方面一直不断的讨论，研究，我们共同进步。

原文链接：http://www.cnblogs.com/bamboos/archive/2012/12/05/2802997.html

【编辑推荐】

  1. 适合初学者的MySQL学习笔记之库操作示例
  2. 适合初学者的MySQL学习笔记之表操作示例
  3. 适合初学者的MySQL学习笔记之MySQL管理心得
  4. 适合初学者的MySQL学习笔记之MySQL查询示例
  5. 适合初学者的MySQL学习笔记之管理员常用操作总结

网站栏目：BUG解析:InnoDB两次写与多实例bufferpool
文章分享：http://www.shufengxianlan.com/qtweb/news45/164795.html

网站建设、网络推广公司-创新互联，是专注品牌与效果的网站制作，网络营销seo公司；服务项目有等

广告

声明：本网站发布的内容（图片、视频和文字）以用户投稿、用户转载内容为主，如果涉及侵权请尽快告知，我们将会在第一时间删除。文章观点不代表本网站立场，如需处理请联系客服。电话：028-86922220；邮箱：631063699@qq.com。内容未经允许不得转载，或转载时需注明来源： 创新互联

猜你还喜欢下面的内容

网站建设知识

分类信息网站

香港云主机　　 　成都免费网站建设公司　　 　微信小程序开发　　 　成都二枢机房　　 　教育网站设计方案　　 　德昌麦琪建站　　 　成都画册快印　　 　简阳服务器托管　　 　成都网站制作　　 　东方电机技改服务有限公司　　 　网站解决方案　　 　营销型网站建设　　 　平武做网站　　 　微信服务号订阅号开发　　 　南充护栏钻孔机　　 　钢筋机械设备　　 　重庆小程序开发公司　　 　证企宝　　 　四川搅拌罐车　　 　成都棕树机房