故障现象 描述:
1、应用方面:Java客户端,上传身份证图片和视频失败,有几次,报错时间大概是从 2018 09-27 22:27:34.815。
客户端错误信息:
2、服务器方面:查看日志,发现上传的 那个storage节点 报错了,报错信息为 :
无法 rename /data/xxxx01.tmp 文件到 /data/10/00/xxxxxxx.mp4路径 无法 rename /data/xxxx02.tmp 文件到 /data/10/00/xxxxxxx.mp4路径 无法 rename /data/xxxx03.tmp 文件到 /data/10/00/xxxxxxx.mp4路径 无法 rename /data/xxxx04.tmp 文件到 /data/10/00/xxxxxxx.mp4路径 ..................... 无法 rename /data/xxxx99.tmp 文件到 /data/10/00/xxxxxxx.mp4路径 .................... 详细如下----------------- [2018-07-31 01:36:50] INFO - file: tracker_client_thread.c, line: 310, successfully connect to tracker server 10.1.10.243:22122, continuous fail count: 25, as a tracker client, my ip is 10.1.10.247 [2018-08-28 15:27:33] ERROR - file: storage_nio.c, line: 371, client ip: 10.1.10.118, pkg length: -8728791489328468646 < 0 [2018-09-27 19:26:32] ERROR - file: storage_nio.c, line: 371, client ip: 10.1.11.88, pkg length: -939450282112145517 < 0 [2018-09-27 21:25:56] WARNING - file: storage_service.c, line: 506, rename /data/fastdfs/storage/data/.cp819598.tmp to /data/fastdfs/storage/data/10/00/CgEK9Vus2luAWvGOAATtxisTGPM212.mp4 fail, errno: 2, error info: No such file or directory [2018-09-27 21:25:57] WARNING - file: storage_service.c, line: 506,## rename /data/fastdfs/storage/data/.cp819599.tmp to /data/fastdfs/storage/data/10/00/CgEK9Vus2luAWvGOAATtxisTGPM212.mp4 fail, errno: 2, error info: No such file or directory .................... [2018-09-27 21:32:07] WARNING - file: storage_service.c, line: 506, rename /data/fastdfs/storage/data/.cp819971.tmp to /data/fastdfs/storage/data/10/00/CgEK9lus29aAUwe5AAciwZj2VXY814.jpg fail, errno: 2, error info: No such file or directory [2018-09-27 21:32:08] WARNING - file: storage_service.c, line: 506, rename /data/fastdfs/storage/data/.cp819972.tmp to /data/fastdfs/storage/data/10/00/CgEK9Vus2luAWvGOAATtxisTGPM212.mp4 fail, errno: 2, error info: No such file or directory ....................(中间全是一样的报错,总共有 905048 - 819598 = 85450次) [2018-09-28 09:28:07] WARNING - file: storage_service.c, line: 506, rename /data/fastdfs/storage/data/.cp905047.tmp to /data/fastdfs/storage/data/10/00/CgEK9lus29aAUwe5AAciwZj2VXY814.jpg fail, errno: 2, error info: No such file or directory [2018-09-28 09:28:08] WARNING - file: storage_service.c, line: 506, rename /data/fastdfs/storage/data/.cp905048.tmp to /data/fastdfs/storage/data/10/00/CgEK9Vus2luAWvGOAATtxisTGPM212.mp4 fail, errno: 2, error info: No such file or directory
查看data目录,发现有8万多个临时文件,恰好等于报错的日志条数。
全程只有两个文件:
最开始是 21:25:56 是 CgEK9Vus2luAWvGOAATtxisTGPM212.mp4 这个文件,
后面21:32:07 又增加了CgEK9lus29aAUwe5AAciwZj2VXY814.jpg
另外两个storage日志如下:
storage2: [2018-09-11 08:15:09] ERROR - file: storage_nio.c, line: 371, client ip: 10.1.10.119, pkg length: -8037590831910596577 < 0 [2018-09-21 09:28:30] ERROR - file: storage_nio.c, line: 371, client ip: 10.1.11.88, pkg length: -6839366949275813527 < 0 [2018-09-27 21:32:08] ERROR - file: tracker_proto.c, line: 48, server: 10.1.10.247:23000, response status 2 != 0 [2018-09-27 21:32:08] ERROR - file: storage_sync.c, line: 255, fdfs_recv_response fail, result: 2 [2018-09-27 21:32:09] INFO - file: storage_sync.c, line: 2733, successfully connect to storage server 10.1.10.247:23000 .......(中间一直重复 tracker_proto.c、storage_sync.c 报错信息,一直持续到2018-09-28 09:28:07) [2018-09-28 09:28:06] ERROR - file: tracker_proto.c, line: 48, server: 10.1.10.247:23000, response status 2 != 0 [2018-09-28 09:28:06] ERROR - file: storage_sync.c, line: 255, fdfs_recv_response fail, result: 2 [2018-09-28 09:28:07] INFO - file: storage_sync.c, line: 2733, successfully connect to storage server 10.1.10.247:23000 storage1: [2018-07-31 01:36:51] INFO - file: tracker_client_thread.c, line: 310, successfully connect to tracker server 10.1.10.243:22122, continuous fail count: 25, as a tracker client, my ip is 10.1.10.245 [2018-09-27 21:25:57] ERROR - file: tracker_proto.c, line: 48, server: 10.1.10.247:23000, response status 2 != 0 [2018-09-27 21:25:57] ERROR - file: storage_sync.c, line: 255, fdfs_recv_response fail, result: 2 [2018-09-27 21:25:58] INFO - file: storage_sync.c, line: 2733, successfully connect to storage server 10.1.10.247:23000 ....... [2018-09-28 09:28:06] ERROR - file: tracker_proto.c, line: 48, server: 10.1.10.247:23000, response status 2 != 0 [2018-09-28 09:28:06] ERROR - file: storage_sync.c, line: 255, fdfs_recv_response fail, result: 2 [2018-09-28 09:28:07] INFO - file: storage_sync.c, line: 2733, successfully connect to storage server 10.1.10.247:23000
临时解决方案:
一共有3个storage,关闭报错的那个storage,应用上传文件恢复正常。
故障排查分析:
关键点如下
1、为何无法 rename ?
答案:经过检查发现,是因为 /data/10 这个目录不存在。
启动FastDFS服务器时,正常情况下, /data/目录会有 包括00、10、11、12等在内的255 个目录。
其他254个目录都有,为何 /data/10/ 这个目录没有? 刚好文件同步到这个目录,肯定会报错。
2、查看 storage_service.c 源代码(这个文件有8000多行而且没有注释),找到506行:
static int storage_sync_copy_file_rename_filename( ....... if (rename(pFileContext->filename, full_filename) != 0) { result = errno != 0 ? errno : EPERM; logWarning("file: "__FILE__", line: %d, " \ "rename %s to %s fail, " \ "errno: %d, error info: %s", __LINE__, \ pFileContext->filename, full_filename, \ result, STRERROR(result)); return result; } } STORAGE_PROTO_CMD_SYNC_CREATE_FILE -> storage_sync_copy_file_done_callback() -> storage_sync_copy_file_rename_filename()
在同步文件时,会执行这个rename的操作,看上去同步失败,发起方会再次发起同步请求,直到同步成功为止。
3、这个文件同步失败的问题,影响到文件的上传了,导致文件上传只要是到这个storage的请求都会失败。
按道理说,同步文件失败,和新上传的文件没有联系的。会不会是因为服务器忙着同步文件,而无法响应其他请求?(根据客户端的报错来看,是getStoreStorage fail,errno code: 28,确实是连不上这个storage了。但是根据报错的频率来看,基本上是1秒钟一次,速度很快,而且服务器整体CPU、内存、磁盘空间都是正常的)
原因分析和初步结论:
此次事故,系 有两个文件 同步失败,失败后无限循环重试,引起某个 storage 无法再收到上传请求。
1、同步失败引起的原因是 因为 /data/10/ 这个目录不存在。为什么这个目录不存在,有两种可能性:
最开始有这个目录,但是由于某种故障或者bug,程序将这个目录删除了。
有人动过fastdfs服务器,不小心把这个目录删除了。(据悉,之前有用过unison去同步过文件,会不会是同步文件时把这个目录清除了?)
2、fastdfs自身程序不完善,体现在两个方面:
同步文件失败时,不应该无限循环且无间隔的去重试。
某两个文件同步失败,不应该整个storage都无法继续接受新的上传请求。
初步解决方案和应对策略:
分析:正常情况下,/data/下面的目录,不会无缘无故消失,生产系统已经运行几个月了,之前都很稳定。
但是如果真的再出现这种情况,无论是意外删除,还是程序bug导致,都需要避免。
这个问题的特征很清楚,只要有 同步失败,都很可能会引起此次的问题。监控fastdfs的日志,一旦有文件多次同步失败,就告警。恢复方式比较简单,手工同步一下,再重启一般就OK了。
关于fastdfs的bug,只能尝试联系作者,等等看能否修复,但是这个作者最近几年很不活跃,这个项目几乎没人维护。
找对c语言很熟悉的人,研究一下fastdfs源码,自己改一下,但是难度也比较大,fastdfs的源码还是比较复杂,而且没有代码注释,要看懂还是得花很大功夫。
题外话
其实,我并不推荐使用FastDFS,因为它并不满足我对中间件的选型要求,
我推荐使用:SeaweedFS【https://github.com/chrislusf/seaweedfs】
两者简单对比:比如Contributors(贡献者)数量,FastDFS为4,而SeaweedFS为61,发布版本数量,前者为6,后者为54,最重要的,FastDFS有250多个open的issues没人解决,近5年多,就没人再维护了,想想多可怕……再有,以我多年代码研究和评审的眼光来看,FastDFS的源码很糟糕,谁愿意去参与维护?