{"id":2528,"date":"2020-04-10T15:49:13","date_gmt":"2020-04-10T15:49:13","guid":{"rendered":"http:\/\/kedar.nitty-witty.com\/?p=2528"},"modified":"2023-04-19T13:53:55","modified_gmt":"2023-04-19T13:53:55","slug":"still-have-mysql-5-6-variable-binlog_error_action-as-ignore_error","status":"publish","type":"post","link":"https:\/\/kedar.nitty-witty.com\/blog\/still-have-mysql-5-6-variable-binlog_error_action-as-ignore_error","title":{"rendered":"Still have MySQL 5.6 variable binlog_error_action as IGNORE_ERROR?"},"content":{"rendered":"\n
Recently, we were affected by an \nignored configuration option introduced in MySQL 5.6. This incident \ncaused us to perform extended planning of downtime and the rebuilding of\n the slave. In this post, we\u2019ll discuss our encounter with \nbinlog_error_action and likely bad default.<\/p>\n\n\n\n
The incident started with an alert \nfrom our monitoring platform that a check failed to verify a MySQL \nmaster\u2019s binary log coordinates. My colleague working from the other \nside of the globe observed the following:<\/p>\n\n\n\n
mysql> show master status;\nEmpty set (0.00 sec)\nmysql> show binary logs;\nERROR 1381 (HY000): You are not using binary logging<\/code><\/pre>\n\n\n\n
Interestingly, the MySQL slave was still reporting that everything was okay!<\/p>\n\n\n\n
Guess what my colleague saw in the error log?<\/p>\n\n\n\n\n\n\n\n
2020-03-18 07:23:50 14694 [ERROR] \/usr\/sbin\/mysqld: Incorrect key file for table '\/tmp\/#sql_3966_2.MYI'; try to repair it\n 2020-03-18 07:23:50 14694 [ERROR] Got an error from unknown thread, \/mnt\/workspace\/percona-server-5.6-redhat-binary-new\/label_exp\/min-centos-7-x64\/test\/rpmbuild\/BUILD\/percona-server-5.6.46-86.2\/storage\/myisam\/mi_write.c:230\n 2020-03-18 14:10:46 14694 [Warning] IP address '192.168.0.10' could not be resolved: Name or service not known\n 2020-03-19 00:55:59 7f5589a9a700 InnoDB: Error: Write to file (merge) failed at offset 5678039040.\n InnoDB: 1048576 bytes should have been written, only 892928 were written.\n InnoDB: Operating system error number 28.\n InnoDB: Check that your OS and file system support files of this size.\n InnoDB: Check also that the disk is not full or a disk quota exceeded.\n InnoDB: Error number 28 means 'No space left on device'.\n InnoDB: Some operating system error numbers are described at\n InnoDB: http:\/\/dev.mysql.com\/doc\/refman\/5.6\/en\/operating-system-error-codes.html\n 2020-03-19 00:57:59 7f5589a9a700 InnoDB: Error: Write to file (merge) failed at offset 3308257280.\n InnoDB: 1048576 bytes should have been written, only 888832 were written.\n InnoDB: Operating system error number 28.\n InnoDB: Check that your OS and file system support files of this size.\n InnoDB: Check also that the disk is not full or a disk quota exceeded.\n InnoDB: Error number 28 means 'No space left on device'.\n InnoDB: Some operating system error numbers are described at\n InnoDB: http:\/\/dev.mysql.com\/doc\/refman\/5.6\/en\/operating-system-error-codes.html\n 2020-03-19 13:29:08 14694 [ERROR] \/usr\/sbin\/mysqld: Incorrect key file for table '\/tmp\/#sql_3966_2.MYI'; try to repair it\n 2020-03-19 13:29:08 14694 [ERROR] Got an error from unknown thread, \/mnt\/workspace\/percona-server-5.6-redhat-binary-new\/label_exp\/min-centos-7-x64\/test\/rpmbuild\/BUILD\/percona-server-5.6.46-86.2\/storage\/myisam\/mi_write.c:230\n 2020-03-19 13:29:11 14694 [ERROR] \/usr\/sbin\/mysqld: Incorrect key file for table '\/tmp\/#sql_3966_5.MYI'; try to repair it\n 2020-03-19 13:29:11 14694 [ERROR] Got an error from unknown thread, \/mnt\/workspace\/percona-server-5.6-redhat-binary-new\/label_exp\/min-centos-7-x64\/test\/rpmbuild\/BUILD\/percona-server-5.6.46-86.2\/storage\/myisam\/mi_write.c:230\n 2020-03-19 13:29:11 14694 [ERROR] \/usr\/sbin\/mysqld: Incorrect key file for table '\/tmp\/#sql_3966_2.MYI'; try to repair it\n ...\n 2020-03-19 15:27:33 14694 [ERROR] Got an error from unknown thread, \/mnt\/workspace\/percona-server-5.6-redhat-binary-new\/label_exp\/min-centos-7-x64\/test\/rpmbuild\/BUILD\/percona-server-5.6.46-86.2\/storage\/myisam\/mi_write.c:230\n 2020-03-19 15:27:33 14694 [ERROR] \/usr\/sbin\/mysqld: Incorrect key file for table '\/tmp\/#sql_3966_3.MYI'; try to repair it\n 2020-03-19 15:27:33 14694 [ERROR] Got an error from unknown thread, \/mnt\/workspace\/percona-server-5.6-redhat-binary-new\/label_exp\/min-centos-7-x64\/test\/rpmbuild\/BUILD\/percona-server-5.6.46-86.2\/storage\/myisam\/mi_write.c:230\n 2020-03-19 15:27:35 14694 [ERROR] An error occurred during flush stage of the commit. 'binlog_error_action' is set to 'IGNORE_ERROR'. Hence turning logging off for the whole duration of the MySQL server process. To turn it on again: fix the cause, shutdown the MySQL server and restart it.<\/pre><\/code><\/pre>\n\n\n\n
Further debugging of the issue with PMM, confirmed a spike on the \/tmp disk.<\/p>\n\n\n\n<\/figure>\n\n\n\n
PMM Disk Check<\/p>\n\n\n\n
The environment here is an \nactive-passive replication with the Orchestrator looking over them and \ndoing its thing. It also has application traffic flowing through a \nProxySQL cluster directed to the current active database.<\/p>\n\n\n\n
So, What\u2019s the Situation?<\/h1>\n\n\n\n
\n
We need to restart the master to fix this, as mentioned in the error-log.<\/li>\n\n\n\n
The master is no longer writing binary logs and therefore the slave is broken.<\/li>\n\n\n\n
Because the slave is broken, it\u2019s no longer able to take over an active position. No backups and no HA.<\/li>\n<\/ul>\n\n\n\n
Here\u2019s a TL;DW (write) summary of solution offered:<\/p>\n\n\n\n
# Raise \/tmp disk partition more than largest table-size.<\/li>\n<\/ul>\n\n\n\n
Bad Default?!<\/h1>\n\n\n\n
This option was introduced in MySQL 5.6.22 as a solution to the bug report about \u201cmysqld continues operation without logging when binlogs cannot be written!<\/em>\u201d The default value was \u201cIGNORE_ERROR\u201d. The alternate option is to crash the server with the value \u201cABORT_SERVER\u201d.<\/p>\n\n\n\n
Had it been ABORT_SERVER, we had our \nSWAT team of Orchestrator and ProxySQL to manage the HA. They\u2019d have \nperformed the failover to the passive-node. Then, the only thing left to\n resolve this issue is to verify the status of the aborted (crashed) \nMySQL database server, which, if running at all, would already be \ndemoted to a passive position.<\/p>\n\n\n\n
Thankfully, this default is changed in MySQL 5.7.7 and later versions to ABORT_SERVER.<\/p>\n\n\n\n
A Task for You!<\/h1>\n\n\n\n
Here is something for you to do:<\/p>\n\n\n\n
For the EOL of MySQL 5.6, we still have almost a year to go. It\u2019s scheduled for February 2021. <\/p>\n\n\n\n
If you\u2019re using MySQL 5.6, go ahead \nand change the binlog_error_action variable. This is a dynamic change \nand won\u2019t affect anything in \u201clive.\u201d Make sure you persist it in the \nMySQL config file.<\/p>\n\n\n\n
mysql> SET GLOBAL binlog_error_action=ABORT_SERVER<\/pre>\n\n\n\n
p.s.<\/strong> Are you still using MySQL 5.6? Consider upgrading your MySQL sooner than later.<\/p>\n\n\n\n
PS2: This blog was originally published on Pythian Blog: https:\/\/blog.pythian.com\/still-have-binlog_error_action-as-ignore_error\/<\/p>\n","protected":false},"excerpt":{"rendered":"Recently, we were affected by an ignored configuration option introduced in MySQL 5.6. This incident caused us to perform extended planning of downtime and the rebuilding of the slave. In…\n","protected":false},"author":1,"featured_media":0,"comment_status":"open","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"om_disable_all_campaigns":false,"_monsterinsights_skip_tracking":false,"_monsterinsights_sitenote_active":false,"_monsterinsights_sitenote_note":"","_monsterinsights_sitenote_category":0,"footnotes":""},"categories":[8,377],"tags":[491,490,492,427,493],"class_list":{"0":"post-2528","1":"post","2":"type-post","3":"status-publish","4":"format-standard","6":"category-mysql","7":"category-mysql-articles","8":"tag-binlog_error_action","9":"tag-configuration-option","10":"tag-ignore_error","11":"tag-mysql","12":"tag-mysql-5-6"},"aioseo_notices":[],"amp_enabled":true,"_links":{"self":[{"href":"https:\/\/kedar.nitty-witty.com\/blog\/wp-json\/wp\/v2\/posts\/2528","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/kedar.nitty-witty.com\/blog\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/kedar.nitty-witty.com\/blog\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/kedar.nitty-witty.com\/blog\/wp-json\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"https:\/\/kedar.nitty-witty.com\/blog\/wp-json\/wp\/v2\/comments?post=2528"}],"version-history":[{"count":6,"href":"https:\/\/kedar.nitty-witty.com\/blog\/wp-json\/wp\/v2\/posts\/2528\/revisions"}],"predecessor-version":[{"id":2810,"href":"https:\/\/kedar.nitty-witty.com\/blog\/wp-json\/wp\/v2\/posts\/2528\/revisions\/2810"}],"wp:attachment":[{"href":"https:\/\/kedar.nitty-witty.com\/blog\/wp-json\/wp\/v2\/media?parent=2528"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/kedar.nitty-witty.com\/blog\/wp-json\/wp\/v2\/categories?post=2528"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/kedar.nitty-witty.com\/blog\/wp-json\/wp\/v2\/tags?post=2528"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}
![\"PMM](\"https:\/\/blog.pythian.com\/wp-content\/uploads\/Screenshot-2020-03-27-at-10.48.22-AM.png\")
<\/figure>\n\n\n\n