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

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

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

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

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

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

3.线上应用机器在最后一天才准备好，tomcat及数据库部署环境的检查并没有完全完成，留下了隐患。如mariadb的binlog功能在设置了my.cnf后仍然没有生成，部分核心表的索引没有建完全。

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

4.机器准备好后由于此时运维也在做监控及log查看基础设施的整体迁移工作，并且人力紧张，在半天时间内只能做一件事情，所以优先做了服务器监控，这里另一个隐患是告警系统。公司内部的服务器告警系统由支撑部门统一做，认为应该有，所以上线时没有测试告警功能，埋下了另一颗地雷。

活动前

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

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

活动开始

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

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

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

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

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

7：00PM 左右程序进行了调整，需要线上程序重新发布，运维同事在高速的回家路上，需要路边找个地方再将所有war包推送到服务器，等待。同时被告知下一波微信订阅号开始推送游戏图文，可能马上访问量就会有反应。

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负载飙升，但应用服务器并没有流量暴涨的异常问题，如果应用逻辑没问题，就暂时只能怀疑是连接池问题（用的是Druid）。当时的负载监控如下图：

后记

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

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

---

文章来自微信平台「麦芽面包」。转载请注明。