后端服务(nginx部署)<status code 500>的一次排查经历
后端服务(nginx部署)<status code 500>的一次排查经历
本文介绍狼厂同事一次解决服务端接口报 http status 500错误的过程。问题不复杂，但是问题的起因在实际工作中并不多见，并且涉及多个知识点。
一、项目背景
项目是狼厂一个前后端分离的项目，项目简略框架如下图。
- 项目包含业务块比较多，分别由不同部门负责。
- 各业务块后端服务分别独立部署。
- 各业务块后端服务都在同一域名下，根据url路径进行区分，比如www.***.com/our/**表示我们的服务，www.***.com/abc/**表示另一服务。
- 上条所说的根据不同url路径往后端服务的转发是统一转发层来完成的，转发层服务器为nginx，主要配置如下： server { listen 80; server_name www.***.com; location /our/ { proxy_pass http://innerip:port1/; } location /abc/ { proxy_pass http://innerip:port2/; } }
- 我们的后端服务也是部署在Nginx服务器上。
- 转发层和后端服务都部署有很多台机器实例。
二、问题描述
忽然陆续接到用户反馈线上报错，而且结合QA同事复现，问题表象有以下特点：1.偶现，对同一用户也是偶现，2.只是部分功会有问题，这些偶现问题的功能基本都是写操作。
（事后总结，这儿其实由现象可以猜测出一些原因，针对同一用户偶现基本可以确定只是部分服务器实例出现问题，另外只有写操作相关功能有问题，可以猜测可能和http请求的请求参数数据包大小有关，当然这种猜测不能作为事发时解决问题的正常思路）
三、追踪步骤
程序员都知道解决bug最怕的问题是不能复现，好在此问题可以偶发复现。而且这是浏览器上访问出的问题，这相对于App报错又是相对简单的，解决思路如下：
- 浏览器打开调试模式，通过复现发现报错的操作都返回http status 500错误。
- 大家都知道根据http响应status code规范，5开头的code都是服务端错误，500的标准定义为 HTTP-Internal Server Error，即服务器内部错误，那就可以确定是后端服务的问题导致。思路就比较明确了，那就去追查nginx的error日志。
- 根据第一步项目介绍框架可知，有可能是转发层nginx出错，也有可能业务后端服务层本身Nginx出错，那么接下来就来确认一下究竟是哪一层的问题。
- 因为转发层和后端服务都部署有很多服务器实例，而且问题是偶现的，所以无法做到像调试单机那样去实时通过tail log文件的方式去追踪，而只能通过全量实例去分析过去某时间段的日志来分析。此时，团队平时在日志管理和分析方面所做的努力就发挥作用了，我们支持以小时粒度对过去的日志进行快速查看和搜索，而且是使用shell命令来执行，于是结合常用日志分析shell命令来快速分析出近一个小时内500错误的请求。
- 在转发层服务器实例上发现了大量500错误日志，并且所有错误日志都来自于同一台实例机器，这也验证了之前的第一个只有部分实例出问题的猜想，也就是说其实只有一个服务器实例除了问题。
- 那么这个500错误究竟是什么原因造成的呢？请看其中一条错误日志的详细内容： open() "/home/our/nginx/client_body_temp/0000000102" failed (28: No space left on device)
问题找到了，下面来说解决方法。
四、分析解决
1.no space left on device 的原因
后半句括号里字面（no space left on device）意思很简单理解，就是磁盘没有空间了嘛。
前半句中的目录/home/our/nginx/client_body_temp/0000000102是什么呢？简单说就是如果客户端POST一个比较大的内容，长度超过了nginx缓冲区的大小，nginx需要把这个文件的部分或者全部内容暂存到client_body_temp目录下的临时文件。
那么问题就比较清楚了，就是post请求的内容超过nginx配置的缓冲区大小，就会先写到临时文件中，由于没有存储空间可用，创建临时文件失败，于是导致500错误。
这也验证了本文第一部分的另一个和请求参数大小有关的猜想。
本着严谨的态度，去找运维同学帮机器给硬盘扩容之前，先自己用 df -h 命令查看来确认一下磁盘空间使用情况，结果如下，nginx所在目录的磁盘有很多可用空间，明明磁盘空间使用还不到一半，为什么提示没有空间可用了呢？
如果感觉奇怪的话，再来看另一个linux命令：df -i
显示使用率为100%，剩余可用数为0，来解释一下这个命令，-i 是指 inode，每个文件占用一个inode，包含以下几方面信息：
- 文件字节数
- 拥有者的user id、group id
- 文件的读写执行权限
- 文件时间戳ctime changetime mtime modify atime access
- 软连接和硬链接ln
- 文件block位置
综上，df -h可清楚查看磁盘空间使用情况，df -i 用来查看inode使用情况，磁盘空间和inode剩余为0时都会导致no space left on device 的错误。
2. inode为什么使用量这么多？
其它服务器实例配置都相似，为什么只有这台问题实例inode占满，其它实例还剩余很多。
而且我们联系运维同事试着删除了一些数百个log日志文件，问题解决，但过了几分钟后inode就又占满。感觉像有某个应用进程在持续快速的生成小文件。Google出如下shell命令可以来查看当前目录下的inode使用情况（并会展示出子目录的占用情况）：
很快找出某目录占用inode量巨大，联系运维同学，发现是运维同学在随机抽取样本实例来做一些服务器检测，检测应用会快速增量生成很多小文件。
运维同学先关掉了检测应用的进程，同时删除了小文件，问题解决。
五、总结
- 500错误就直接去服务端分析问题。
- nginx可以对缓冲区大小进行配置，当http请求数据大小超过这个值则会写入临时文件，针对这块配置其实有多个配置项，google很多介绍，本文不做详解。
- df -h 查看磁盘空间使用情况，df -i 查看系统inode使用情况，两者用尽后都会导致“no space left on device” 。
- 服务器监控机制有问题，此bug其实不应该由用户报上来，而应该由监控系统自动报警上报。事实上有针对nginx日志的监控，但是监控机制本身也涉及到写文件操作，所以同样因为inode用尽，导致监控系统本身也因此除了问题。
- 对于线上问题的追踪，对日志的管理很重要，要提前建立起一套方便快速查询分析日志的系统，不要笑，有不少公司仗着自己线上机器数少，当出现问题时，就登录所有机器单个进行追踪。