记一次数据库bug故障恢复

从一件小事说起

最近一个月不知何故,博客的VPS IP无法ping通。提交ticket要求更换ip, 毫无意外的被拒绝了。于是直接从当前VPS clone 一台间接实现了IP的更换。clone的文章参考官方指引即可。因为是克隆操作,因此所有的环境和数据都保持不变,配置成本约定于0。整个过程加上修改DNS,10分钟搞定。正准备来杯清茶休息一下的时候,发现新机器的mysql挂了:

2020-03-21T12:00:03.913175Z 0 [Note] InnoDB: Apply batch completed
2020-03-21T12:00:04.016847Z 0 [Note] InnoDB: Removed temporary tablespace data file: “ibtmp1”
2020-03-21T12:00:04.016974Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2020-03-21T12:00:04.017051Z 0 [Note] InnoDB: Setting file ‘./ibtmp1’ size to 12 MB. Physically writing the file full; Please wait …
2020-03-21T12:00:04.020703Z 0 [Note] InnoDB: Starting in background the rollback of uncommitted transactions
2020-03-21T12:00:04.020779Z 0 [Note] InnoDB: Rolling back trx with id 35499526, 1 rows to undo
12:00:04 UTC – mysqld got signal 11 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.

key_buffer_size=8388608
read_buffer_size=131072
max_used_connections=0
max_threads=151
thread_count=0
connection_count=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 68195 K bytes of memory
Hope that’s ok; if not, decrease some variables in the equation.

Thread pointer: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong…
stack_bottom = 0 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x2c)[0xed2ebc]
/usr/sbin/mysqld(handle_fatal_signal+0x451)[0x7b4ea1]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x10340)[0x7f85fd1a5340]
/usr/sbin/mysqld(_Z32page_cur_search_with_match_bytesPK11buf_block_tPK12dict_index_tPK8dtuple_t15page_cur_mode_tPmS9_S9_S9_P10page_cur_t+0x168)[0xf89528]
/usr/sbin/mysqld(_Z27btr_cur_search_to_nth_levelP12dict_index_tmPK8dtuple_t15page_cur_mode_tmP9btr_cur_tmPKcmP5mtr_t+0x1121)[0x10b2d31]
/usr/sbin/mysqld(_Z22row_search_index_entryP12dict_index_tPK8dtuple_tmP10btr_pcur_tP5mtr_t+0x11f)[0xffd4ff]
/usr/sbin/mysqld[0x11cb0d6]
/usr/sbin/mysqld(_Z12row_undo_insP11undo_node_tP9que_thr_t+0x22b)[0x11cc0bb]
/usr/sbin/mysqld(_Z13row_undo_stepP9que_thr_t+0x405)[0x1019385]
/usr/sbin/mysqld(_Z15que_run_threadsP9que_thr_t+0x871)[0xfa97c1]
/usr/sbin/mysqld(_Z31trx_rollback_or_clean_recoveredm+0xcdc)[0x106c8dc]
/usr/sbin/mysqld(trx_rollback_or_clean_all_recovered+0x4e)[0x106d7ee]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x8182)[0x7f85fd19d182]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f85fc6aa47d]
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
2020-03-21T12:00:04.056733Z mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended

从错误信息 mysqld got signal 11 看,应该是启动过程是尝试fix table触发了bug,因此启动失败。

如何解决 mysqld got signal 11

既然是fix corrupted table导致的问题,那么思路自然是先把mysql启动起来,备份数据,然后找到存在问题的table, 再逐步恢复数据(我的mysql server版本是:5.7.23,不同版本可能稍有差异):

  1. 如果服务器未正常停止,先停止mysql: service mysql stop
  2. 备份文件/var/lib/mysql/ib*: mkdir /tmp/fixdb && cp -rp /var/lib/mysql/ib* /tmp/fixdb
  3. 在配置文件/etc/mysql/my.cnf中添加如下内容:

[mysqld]

innodb_force_recovery = 3

  1. 启动mysql: service mysql start. 如果启动失败,尝试改大步骤3的数字,直到启动成功。
  2. 备份数据表: mysqldump -A -uUSERNAME -p > dump.sql
  3. 删除所有用户数据库:

mysql -uUSERNAME -p

drop database xxx…

  1. 停止mysql: service mysql stop
  2. 删除ib文件:rm /var/lib/mysql/ib*
  3. 删除步骤3中添加的两行内容
  4. 启动mysql: service mysql start. 在mysql错误文件(/var/log/mysql/error.log)中应该可以看到最开始导致启动失败的corrupted table.
  5. 恢复数据:mysql -uUSERNAME -p < dump.sql. 如果恢复过程中出现 Tablespace exists错误,则尝试删除ibd文件,然后重新导入数据:

ERROR 1813 (HY000) at line 268: Tablespace ‘DBNAME.TABLENAME‘ exists.

rm /var/lib/mysql/DBNAME/*.ibd

mysql -uUSERNAME -p < dump.sql

终于大功告成。恢复过程中小紧张了一下,使用了10年的VPS终于满血复活。

参考文献

基于 Docker 搭建 Mac 本地 HBase 环境

说起玩大数据,相信很多人都会因为 Apache 全家桶软件配置而菊花一紧。Docker 的出现,把很多玩大数据就是配机器、配环境的开发者从泥潭中拯救了出来,虽然还不能完全替代线上环境,但是在开发环境,无疑为开发者节约了大量搭建本地环境的时间。比较遗憾的是,我们团队之前也是没有独立的数据测试环境?,于是把在本地搭建 HBase 环境整理和记录如下。

系统环境:

  • MacBook Pro (Retina, 15-inch, Mid 2015)
  • 2.2 GHz Intel Core i7
  • 16 GB 1600 MHz DDR3
  • macOS 10.13.6

安装 Docker CE for Mac

Docker Community Edition for Mac下载安装。

Mac 上的 Docker 环境经过 docker-machine/virtualbox 几次变化,如今的 Docker CE 已经支持原生 Mac 环境,因此当前阶段 Docker CE for Mac 就是唯一推荐的 Mac Docker 环境,再也不用通过安装 virtualbox 这种借蛋生鸡的方式了,实在是很赞。此外,现在的 Docker CE 集成了 Kubernetes, 因此本地玩 k8s 也不需要额外进行安装配置。如果你计划以后就是玩 k8s, 那么你以前安装的 Kitematic 也可以卸载掉了。Kitematic 除了一个图形化的 container 管理界面,实在没有什么值得留恋的,因此官方停止其开发无疑是个正确的决定。

获取和启动 HBase Docker 镜像

  • 获取容器镜像

更多大数据全家桶 Docker 镜像可以参见 HariSekhon/Dockerfiles

  • 启动容器

参数解释:

  • -d: 后台启动。
  • -h: 容器主机名,必须设置该项并配置 hosts,否则无法连通容器。
  • -p: 网络端口映射,这里只把要使用的端口(zookeeper端口、HBase Master端口、HBase RegionServer端口等)映射了出来,你可以根据自己需要进行端口映射。常用 HBase端口可以参见下表:

但是,harisekhon/hbase 修改了默认端口:

因此,你看到启动参数中的端口参数是那样的。

  • --name: 容器别名。

设置hosts (推荐使用 Gas Mask):

成功启动后,就可以在 http://localhost:16010/master-status 查看 HBase 状态了:

需要注意的一点是:容器销毁后,数据也也会被同时销毁。因此你可以通过 -v YOUR_DIR:/hbase-data 的方式将数据目录映射到宿主机目录,防止数据丢失。

编写测试代码

  • 创建 table

  • 读写 table

Maven 添加依赖:

HelloHBase.java:

扩展阅读

一次非典型性 Redis 阻塞总结

南方逐渐进入一年中最好的时节,用户也开始骚动起来。看了眼数据,活跃用户已经double很远,马上triple了。

一日睡眼惺忪的清晨,正看着数据默默yy时候,线上开始告警…… MMP,用户早上骚动的增长比想象好快呢。同事第一时间打开立体监控瞥了一眼,结合服务的错误日志,很快把问题锁定到了一个Redis实例(事实上,自从立体监控上线以后,基本上处理流程从以前的 < 80%时间定位问题 + 20%解决问题 > 变成了 < 少量时间确认问题 + 解决问题 >)。团队处理效率还是挺快的,原因定位到AOF持久化:

这是当时的Redis配置:

127.0.0.1:6379> config get *append*
1) "no-appendfsync-on-rewrite"
2) "no"
3) "appendonly"
4) "yes"
5) "appendfsync"
6) "everysec"

从配置看,原因理论上就很清楚了:我们的这个Redis示例使用AOF进行持久化(appendonly),appendfsync策略采用的是everysec刷盘。但是AOF随着时间推移,文件会越来越大,因此,Redis还有一个rewrite策略,实现AOF文件的减肥,但是结果的幂等的。我们no-appendfsync-on-rewrite的策略是 no. 这就会导致在进行rewrite操作时,appendfsync会被阻塞。如果当前AOF文件很大,那么相应的rewrite时间会变长,appendfsync被阻塞的时间也会更长。

这不是什么新问题,很多开启AOF的业务场景都会遇到这个问题。解决的办法有这么几个:

  1. no-appendfsync-on-rewrite设置为yes. 这样可以避免与appendfsync争用文件句柄,但是在rewrite期间的AOF有丢失的风险。
  2. 给当前Redis实例添加slave节点,当前节点设置为master, 然后master节点关闭AOF,slave节点开启AOF。这样的方式的风险是如果master挂掉,尚没有同步到salve的数据会丢失。

我们采取了折中的方式:在master节点设置将no-appendfsync-on-rewrite设置为yes,同时添加slave节点。

理论上,问题应该解决了吧?啊蛤,的确是理论上。

修改后第一天,问题又出现了。惊不惊喜,意不意外?

于是,小伙伴又重新复习了一下当时出问题时候的Redis日志:

有两个点比较可以:

  1. 前几条AOF日志告警日志发生在晚上3~5点之间,而那个时候,我们整个系统负载是非常低的。
  2. 清晨的告警日志不是某一个Redis实例告警,而是该机器上的所有Redis实例都在告警。

在这种百思不得骑姐的情况下,结合历史上被坑的经验,我们99%断定是我们使用的云主机存在问题。

这个问题有可能是宿主机超售太多导致单个租户实际能使用到的云盘IO比标称值低,也有可能是租户隔离做得不好,导致坏邻居过度占用IO影响其他租户。

这个很好理解:我们使用的是阿里云的云SSD,而阿里云目前的架构还没有做到计算和存储分离,即计算和存储的网络IO是共享的。

当然目前这个问题还没有实锤,我们也还在跟阿里云积极沟通解决。同时为了避免给自己惹麻烦,我还是留了1%的其他可能性?

祝大家周末愉快!

参考资料

Redis相关—Redis持久化