系统上线那点事 - 记一次线上系统故障

Posted 2020-09-27 yfceshi

该项目是一个微信转盘游戏抽奖营销项目。因为运营营销时间要求紧迫。开发測试部署上线用了10天不到，有些准备工作并没有到位，如：

1.因为总体开发在上线前2天才完毕，測试了解这个项目需求是在开发的第二周，并没有充足的时间进行完好的功能，UI机型适配，系统压力測试。

2.技术上因为合作方的公众号密钥并不适合直接给出，所以由对方封装微信接口获取所需功能，对方封装的微信接口给出比較迟,在预定開始时间前三天；

微信的网页接口授权回调域名仅仅有一个。这个回调域名还有其它应用在使用，不能直接简单的改为我们部署应用的域名。须要合作方在其内网设置nginx进行http转发。保证微信的回调能发送到我们的server，封装的API接口測试也要等转发配置完毕才干进行。

此种网络配置方式也导致了之后遇到的部分用户页面无法加载时，排除问题难度加大，不能在自己的机房解决。

3.线上应用机器在最后一天才准备好，tomcat及数据库部署环境的检查并没有全然完毕。留下了隐患。

如mariadb的binlog功能在设置了my.cnf后仍然没有生成，部分核心表的索引没有建全然。

而且活动仅仅有七天，经过估算。觉得摇奖压力大部分应该在应用端，数据库无压力。所以配置了10几台tomcat及redis缓存，没有为mariadb配置主从结构做备份，成为了一个单点。

4.机器准备好后因为此时运维也在做监控及log查看基础设施的总体迁移工作，而且人力紧张，在半天时间内仅仅能做一件事情。所以优先做了server监控，这里还有一个隐患是告警系统。

公司内部的server告警系统由支撑部门统一做，觉得应该有，所以上线时没有測试告警功能，埋下了还有一颗地雷。

活动前

10：00AM 手机挂代理測试发现因为对方nginx转发过来的http head头上的host为对方地址，所以游戏活动的每次请求都会先过对方server一遍，再转发回来。这个转发在第一次走微信验证时。这在游戏首页的延迟影响较大。

10：30AM 还有半小时開始。曾想測试一下将对方代理过来的请求重定向。但因为此前官微推送过消息。在活动開始前,一些零散用户已经開始訪问活动页面，但被挡在活动未開始页面，暂时改程序影响比較大，再加上前一天为了測试接口压力測试也搞到1点。脑子比較混沌，略微改了測试下没有成功，暂时放弃。

活动開始

11：00AM 系统正式开放，用户已经能够进入转盘抽奖页。系统监控正常，系统负载，网络均没有异常。

2:00PM 观察数据库某表一个经常使用字段没有建索引。逻辑上因为仅仅实用户未登录时才会查询一次。考虑到在线上库做alter index操作可能会对当时时间点的数据库操作有影响，就没有补上这个索引。

4：10PM 公司VPN断开。因为无法连接就没法工作，几个开发转到茶水间去喝水放松。过了一会突然被通知活动页白屏无法訪问，运维的同事通知说server机房的移动入口线路中断。赶紧通知支撑部门排查原因。同一时候紧急切换该域名的地址解析到机房电信IP上，等域名生效理论上须要10分钟。

4：50PM 断开的机房入口通道恢复，为了保险还是等了一会才将域名解析IP又一次切回到移动线路。

5：00PM 又一波官微订阅号開始推图文引导用户进入。

7：00PM 左右程序进行了调整，须要线上程序又一次公布，运维同事在快速的回家路上。须要路边找个地方再将全部war包推送到server。等待。同一时候被告知下一波微信订阅号開始推送游戏图文，可能立即訪问量就会有反应。

7：30PM 几个人总算有空去找饭吃，悲剧的发现食堂和全家的饭都没了。仅仅能吃泡面面包了。

。。

7：50PM 左右运维反馈将全部war包推送完毕。

随后发现游戏页面又開始进入缓慢。而且关注公众号的用户已经開始不能进入游戏页面了，返回请关注引导界面。

8：00PM 開始排查发生错误原因。查看线上机器tomcat并没有什么异常，此时登陆数据库机器发如今命令行下系统响应速度不正常。命令输入后2。3秒以上才有反应。
再看top负载，cpu负载非常不正常，已经超载。系统load也是一样。

8：30PM 发现数据库异常后。决定重新启动数据库。

8：45PM systemctl stop db。 然后就悲剧了，系统负载下来了，但又一次start不起来了， mysql error-log中查启动问题：

InnoDB: Error: log file ./ib_logfile0 is of different size 0 >5256780 bytes
InnoDB: than specified in the .cnf file 0 1077645824 bytes!
[ERROR] Plugin ‘InnoDB’ init function returned error.
[ERROR] Plugin ‘InnoDB’ registration as a STORAGE ENGINE failed.
[ERROR] Unknown/unsupported storage engine: InnoDB
[ERROR] Aborting

查了下资料，正常shutdown后将logfile0删除后再启动能成功，为保险将此文件mv到另外的文件夹。再尝试启动，仍然起不来。全然晕菜

150703 23:44:27 InnoDB: Could not open or create data files.
150703 23:44:27 InnoDB: If you tried to add new data files, and >it failed here,
150703 23:44:27 InnoDB: you should now edit >innodb_data_file_path in my.cnf back
150703 23:44:27 InnoDB: to what it was, and remove the new >ibdata files InnoDB created
150703 23:44:27 InnoDB: in this failed attempt. InnoDB only >wrote those files full of
150703 23:44:27 InnoDB: zeros, but did not yet use them in any >way. But be careful: do not
150703 23:44:27 InnoDB: remove old data files which contain your >precious data!
150703 23:44:27 [ERROR] Plugin ‘InnoDB’ init function returned >error.
150703 23:44:27 [ERROR] Plugin ‘InnoDB’ registration as a >STORAGE ENGINE failed.
150703 23:44:27 [Note] Plugin ‘FEEDBACK’ is disabled.
150703 23:44:27 [ERROR] Unknown/unsupported storage engine: >innodb
150703 23:44:27 [ERROR] Aborting

此时事情已经開始棘手。这是微信活动第一天上线的周五晚上，从七点多逐渐服务不可用到八点多数据库shutdown后crash已经过去不短的一段时间了。大量用户在官微大号消息推送后进入抽奖游戏时被挡在404页面上不能进入。而且因为之前说的此活动为7天，定义此数据库为一个暂时库。没有挂从库。也没有dump备份。如今第一天就竟然遇到数据库崩溃的问题。

部门没有DBA,处理数据库不能启动的问题找不到直接能够咨询的人，上级给了个其它部门的DBA电话咨询。远水解不了近渴，电话里大致聊了下也说不清楚，没有时间耗在恢复这个数据库上了。

此时经过商议决定又一次初始化一个数据库虚机。急忙dump了一个原測试线上环境时的老数据库到新的数据库上。又一次公布应用切换到新数据库上。让用户先能进行游戏再说。

9：55PM 数据库虚机初始化完毕，应用又一次上线，几个开发略微松了口气。

10:00PM-1:20AM 此时大脑已经比較迟钝了。尝试恢复老数据库一次失败后放弃。跟同事reivew这次问题，通过监控数据发现晚7点数据库突然连接数暴涨，同一时候CPU负载飙升，但应用server并没有流量暴涨的异常问题，假设应用逻辑没问题，就暂时仅仅能怀疑是连接池问题（用的是Druid）。当时的负载监控例如以下图：

后记

周末歇息后，周一过来略微捣鼓了下老数据库就启动了。看来还是不能疲劳作战。启动后将须要同步的表数据导入线上库，至此事情基本告一段落。

此次遇到突发情况比較多。各种小问题累积在一起压断了最后一根稻草。依照Scrum的review规则记录一下经验，总结教训。

---

文章来自微信平台「麦芽面包」。

转载请注明。