ITPub博客

首页 > 数据库 > MySQL > MySQL 5.6 遭遇 OS bug INNODB MONITOR OUTPUT 事件

MySQL 5.6 遭遇 OS bug INNODB MONITOR OUTPUT 事件

原创 MySQL 作者:babyyellow 时间:2019-02-19 10:06:53 0 删除 编辑

数据库主机从库 报错了。 
持续的报出   INNODB  STAUTS OUTPUT  写到  err log文件里面去。 

END OF INNODB MONITOR OUTPUT
2019-02-19 02:10:16 7f7dc518b700 INNODB MONITOR OUTPUT
END OF INNODB MONITOR OUTPUT
2019-02-19 02:10:36 7f7dc518b700 INNODB MONITOR OUTPUT
END OF INNODB MONITOR OUTPUT
2019-02-19 02:10:56 7f7dc518b700 INNODB MONITOR OUTPUT
END OF INNODB MONITOR OUTPUT
2019-02-19 02:11:16 7f7dc518b700 INNODB MONITOR OUTPUT
END OF INNODB MONITOR OUTPUT
2019-02-19 02:11:36 7f7dc518b700 INNODB MONITOR OUTPUT
END OF INNODB MONITOR OUTPUT
2019-02-19 02:11:56 7f7dc518b700 INNODB MONITOR OUTPUT
END OF INNODB MONITOR OUTPUT
2019-02-19 02:12:16 7f7dc518b700 INNODB MONITOR OUTPUT
END OF INNODB MONITOR OUTPUT
2019-02-19 02:12:36 7f7dc518b700 INNODB MONITOR OUTPUT
END OF INNODB MONITOR OUTPUT
2019-02-19 02:12:56 7f7dc518b700 INNODB MONITOR OUTPUT
END OF INNODB MONITOR OUTPUT
2019-02-19 02:13:16 7f7dc518b700 INNODB MONITOR OUTPUT
END OF INNODB MONITOR OUTPUT
2019-02-19 02:13:36 7f7dc518b700 INNODB MONITOR OUTPUT
END OF INNODB MONITOR OUTPUT
2019-02-19 02:13:56 7f7dc518b700 INNODB MONITOR OUTPUT


然后从库无法连接主库。 

监控代码报错: 
mysql host:′ó?a??] slave ??3ì ?é?ü3??êìaá?£?show slave status £o??ê?1ê??
Warning: Using a password on the command line interface can be insecure.
              Master_Log_File: mysql-bin.000062
          Read_Master_Log_Pos: 94626697
               Relay_Log_File: mysql- relay-bin.000121
        Relay_Master_Log_File: mysql-bin.000062
             Slave_IO_Running: No
            Slave_SQL_Running: No
          Exec_Master_Log_Pos: 94626697
         Seconds_Behind_Master: NULL
      Slave_SQL_Running_State:




err 日志的报错信息: 

----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 158651
--Thread 140178133391104 has waited at trx0undo.ic line 191 for 924.00 seconds the semaphore:
S-lock on RW-latch at 0x7f8075840fc0 created in file buf0buf.cc line 1069
a writer (thread id 140178090628864) has reserved it in mode  exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file buf0flu.cc line 1056
Last time write locked in file /export/home/pb2/build/sb_0-19672887-1468230598.75/mysql-5.6.32/storage/innobase/include/trx0undo.
ic line 171
--Thread 140178090628864 has waited at trx0sys.ic line 103 for 924.00 seconds the semaphore:
X-lock (wait_ex) on RW-latch at 0x7f81bda169c0 created in file buf0buf.cc line 1069
a writer (thread id 140178090628864) has reserved it in mode  wait exclusive
number of readers 1, waiters flag 0, lock_word: ffffffffffffffff
Last time read locked in file buf0flu.cc line 1056
Last time write locked in file /export/home/pb2/build/sb_0-19672887-1468230598.75/mysql-5.6.32/storage/innobase/include/trx0sys.i
c line 103


晚上也懒得去细查了,  就重启了数据库问题解决。 

早上回来调查。

发现了这是一个bug。 

查看手册的时候发现自适应哈希索引可能会导致btr0sea.c文件的rw latch获取争用,从而导致SEMAPHORES问题。


详细链接: https://dev.mysql.com/doc/refman/5.6/en/innodb-adaptive-hash.html


解决方案:set global innodb_adaptive_hash_index=0;

进一步网上搜索发现


linux  6.6  有个bug 触发这个问题。 

https://groups.google.com/forum/#!topic/mechanical-sympathy/QbmpZxp6C64


We had this one bite us hard and scare the %$^! out of us, so I figured I'd share the fear...
The linux futex_wait call has been broken for about a year (in upstream since 3.14, around Jan 2014), and has just recently been fixed (in upstream 3.18, around October 2014). More importantly this breakage seems to have been back ported into major distros (e.g. into RHEL 6.6 and its cousins, released in October 2014), and the fix for it has only recently been back ported (e.g. RHEL 6.6.z and cousins have the fix).
The impact of this kernel bug is very simple: user processes can deadlock and hang in seemingly impossible situations. A futex wait call (and anything using a futex wait) can stay blocked forever, even though it had been properly woken up by someone. Thread.park() in Java may stay parked. Etc. If you are lucky you may also find soft lockup messages in your dmesg logs. If you are not that lucky (like us, for example), you'll spend a couple of months of someone's time trying to find the fault in your code, when there is nothing there to find. 
This behavior seems to regularly appear in the wild on Haswell servers (all the machines where we have had customers hit it in the field and in labs been Haswells), and since Haswell servers are basically what you get if you buy a new machine now, or run on the cool new amazon EC2/GCE/Azure stuff, you are bound to experience some interesting behavior. I don't know of anyone that will see this as a good thing for production systems. Except for maybe Netflix (maybe we should call this the linux fumonkey).

The commit for the fix is here:  https://github.com/torvalds/linux/commit/76835b0ebf8a7fe85beb03c75121419a7dec52f0
The commit explanation says that it fixes https://github.com/torvalds/linux/commit/b0c29f79ecea0b6fbcefc999e70f2843ae8306db (presumably the bug introduced with that change), which was made in Jan of 2014into 3.14. That 3.14 code added logic to avoid taking a lock if the code knows that there are no waiters. It documents (pretty elaborately) how "…thus preventing tasks sleeping forever if wakers don't acknowledge all possible waiters" with logic that explains how memory barriers guarantee the correct order (see paragraph at line 141), which includes the statement "this is done by the barriers in get_futex_key_refs(), through either ihold or atomic_inc, depending on the futex type." (this assumption is the actual bug). The assumption is further reinforced in the fact that the change added a comment to every calls to get_futex_key_refs() in the code that says "/* implies MB (B) */".

The problem was that get_futex_key_refs() did NOT imply a memory barrier. It only included a memory barrier for two explicit cases in a switch statement that checks the futex type, but did not have a default case handler, and therefor did not apply a memory barrier for other fuxtex types. Like private futexes. Which are a very commonly used type of futex.
The fix is simple, an added default case for the switch that just has an explicit smp_mb() in it. There was a missing memory barrier in the wakeup path, and now (hopefully) it's not missing any more...
So lets be clear: RHEL 6.6 (and CentOS 6.6., and Scientific Linux 6.6.) are certainly broken on Haswell servers. It is likely that recent versions other distros are too (SLES, Ubuntu, Debia, Oracle Linux, etc.). The good news is that fixes are out there (including 6.6.z). But the bad news is that there is not much chatter saying "if you have a Haswell system, get to version X now". For some reason, people seem to not have noticed this or raised the alarm. We certainly haven't seen much "INSTALL PATCHES NOW" fear mongering. And we really need it, so I'm hoping this posting will start a panic.

Bottom line: the bug is very real, but it probably only appeared in the 3.14 upstream version (and distro versions that had backported https://github.com/torvalds/linux/commit/b0c29f79ecea0b6fbcefc999e70f2843ae8306db , presumably after Jan 2014). The bug was fixed in 3.18 in October 2014, but backports probably took a while (and some may still be pending). I now for a fact that RHEL 6.6.z has the fix. I don't know about other distro families and versions (yet), but if someone else does, please post (including when was it broken, and when was it fixed).
Note: I would like to profusely thank @aplokhotnyuk. His tweet originally alerted me to the bug's existence, and started us down the path of figuring out the what//why/where/when behind it. Why this is not being shouted in the streets is a mystery to me, and scary in its own right. We were lucky enough that I had a "that looks suspiciously familiar" moment when I read that tweet, and that I put 3.14 and 1.618 together and thought enough to ask "Umm... have we only been seeing this bug on Haswell servers?". Without @aplokhotnyuk's tweet we'd probably still be searching for the nonexistent bugs in our own locking code... And since the tweet originated from another discussion on this group, it presents a rare "posting and reading twitter actually helps us solve bugs sometimes" example.


而且刚刚好,我们的os 为  centos 6.6  

cpu 为  haswell 架构。 

model name      : Intel(R) Xeon(R) CPU E5-2620 v4 @ 2.10GHz
stepping        : 1

https://www.infoq.com/news/2015/05/redhat-futex



看来要升级os 才能搞定曾问题了。 









来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/133735/viewspace-2636330/,如需转载,请注明出处,否则将追究法律责任。

上一篇: 2018年总结
请登录后发表评论 登录
全部评论
oracle MySQL Postgresql 专职数据库dba。 系统架构师。 mysql 官方认知dba 。 15年专职dba 经验。

注册时间:2010-12-02

  • 博文量
    247
  • 访问量
    1468480