FastDFS问题分析和总结
2018年09月28日


故障现象 描述:


1、应用方面:Java客户端,上传身份证图片和视频失败,有几次,报错时间大概是从 2018 09-27 22:27:34.815。

1538120305812084930.png

客户端错误信息:

fastED835B785593.png


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/ 这个目录不存在。为什么这个目录不存在,有两种可能性:

  1. 最开始有这个目录,但是由于某种故障或者bug,程序将这个目录删除了。

  2. 有人动过fastdfs服务器,不小心把这个目录删除了。(据悉,之前有用过unison去同步过文件,会不会是同步文件时把这个目录清除了?)


2、fastdfs自身程序不完善,体现在两个方面:

  1. 同步文件失败时,不应该无限循环且无间隔的去重试。

  2. 某两个文件同步失败,不应该整个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的源码很糟糕,谁愿意去参与维护?