记录一个拷贝文件到GlusterFS卡住的解决过程
问题简介
我们有一个分布式服务，存储为Gluster FS，需要大量的读写文件。在公司开发环境、测试环境都正常的情况下，在线上环境、高仿环境却屡屡出现拷贝文件到Gluster FS卡住的问题（文件若是200M5G大小，概率大概在34%左右，文件已拷贝完成，源文件和目标文件md5一致，卡在目标文件句柄close处。）。
func CopyFile(src, dest string) (copiedSize int64, err error) {
copiedSize = 0
srcFile, err := os.Open(src)
if err != nil {
return copiedSize, err
}
defer srcFile.Close()
destFile, err := os.Create(dest)
if err != nil {
return copiedSize, err
}
defer destFile.Close() // 卡在这
return io.Copy(destFile, srcFile)
}
卡住的goroutine信息示例：
goroutine 109667 [syscall, 711 minutes]:
syscall.Syscall(0x3, 0xf, 0x0, 0x0, 0xafb1a0, 0xc42000c150, 0x0)
/usr/local/go/src/syscall/asm_linux_amd64.s:18 +0x5
syscall.Close(0xf, 0x0, 0x0)
/usr/local/go/src/syscall/zsyscall_linux_amd64.go:296 +0x4a
os.(*file).close(0xc420344f00, 0x455550, 0xc4203696d0)
/usr/local/go/src/os/file_unix.go:140 +0x86
os.(*File).Close(0xc4200289f0, 0x1b6, 0xc4200289f0)
/usr/local/go/src/os/file_unix.go:132 +0x33
Common/utils.CopyFile(0xc42031eea0, 0x5d, 0xc420314840, 0x36, 0x10ce9d94, 0x0, 0x0)
......
最后的/usr/local/go/src/syscall/asm_linux_amd64.s第18行前后代码如下
TEXT ·Syscall(SB),NOSPLIT,$0-56
CALL runtime·entersyscall(SB) // 卡在系统调用开始处
MOVQ a1+8(FP), DI
MOVQ a2+16(FP), SI
MOVQ a3+24(FP), DX
MOVQ $0, R10
MOVQ $0, R8
MOVQ $0, R9
MOVQ trap+0(FP), AX // syscall entry
SYSCALL
CMPQ AX, $0xfffffffffffff001
JLS ok
MOVQ $-1, r1+32(FP)
MOVQ $0, r2+40(FP)
NEGQ AX
MOVQ AX, err+48(FP)
CALL runtime·exitsyscall(SB)
RET
ok:
MOVQ AX, r1+32(FP)
MOVQ DX, r2+40(FP)
MOVQ $0, err+48(FP)
CALL runtime·exitsyscall(SB)
RET
解决过程
由于开发环境、测试环境用的Gluster FS是3.3.2，线上环境、高仿环境的Gluster FS版本是3.7.6，最开始是猜测可能是版本不一致导致的问题。因此最开始是从Gluster FS版本是否有问题，部署GlusterFS的软硬件是否有问题开始入手，
但始终找不出真正的原因。这时候公司流程就成了阻碍，因为原因基本靠经验猜测，但即便改一点点代码，都要提测，找多个领导签字，最坏的一次情况是一天都没走完一个流程。
最后，实在无奈，向领导申请操作部分高仿环境的权限。好了，终于可以施展拳脚了。
第一次，采用超时处理机制
我们想到的是，参考tensorflow的源码，在Golang中用reflect实现一个类似 ./tensorflow/core/platform/cloud/retrying_utils.cc的代码。基本原理就是，close等一些可能会卡住的函数是新启一个goroutine来做，如果在close阶段卡住，超过一定时间继续往下走，反正文件都已经拷贝完了。
主要代码如下：
type RetryingUtils struct {
Timeout time.Duration
MaxRetries int
}
type CallReturn struct {
Error error
ReturnValues []reflect.Value
}
func NewRetryingUtils(timeout time.Duration, maxRetries int) *RetryingUtils {
return &RetryingUtils{Timeout: timeout, MaxRetries: maxRetries}
}
func (r *RetryingUtils) CallWithRetries(any interface{}, args ...interface{}) CallReturn {
var callReturn CallReturn
var retries int
for {
callReturn.Error = nil
done := make(chan int, 1)
go func() {
function := reflect.ValueOf(any)
inputs := make([]reflect.Value, len(args))
for i, _ := range args {
inputs[i] = reflect.ValueOf(args[i])
}
callReturn.ReturnValues = function.Call(inputs)
done <- 1
}()
select {
case <-done:
return callReturn
case <-time.After(r.Timeout):
callReturn.Error = errTimeout
}
retries++
if retries >= r.MaxRetries {
break
}
}
return callReturn
}
调用方式示例：
NewRetryingUtils(time.Second*10, 1).CallWithRetries(fd.Close)
压测两天，此方法不可行。因为卡住之后，任务goroutine继续往下走，会有概率导致进程为defunct。（注：无数的文章告诉我们，defunct僵尸进程的产生是没有处理子进程退出信息之类的，这个只是僵尸进程的一部分；比如只要goroutine卡住，若kill该进程，进程就会成为defunct）
第二次，采用系统命令拷贝文件
我们采用linux的cp命令拷贝文件，压测两天，通过。（它为什么成功的原因，还没完全整明白。因为每次压测需要占用两位测试美女的大量时间，反反复复地压测，也不太好。如果是开发环境或测试环境，那好办，我们开发可以自己压测）
第三次，测试是否由于多申请了Read权限引起
我们开始通过阅读linux cp命令的源码来寻找原因。发现coreutils/src/copy.c的copy_reg函数，这个函数的功能是拷贝普通文件。golang的os.Create函数默认比该函数多申请了一个read权限。
copy_reg中的创建文件：
int open_flags =
O_WRONLY | O_BINARY | (x->data_copy_required ? O_TRUNC : 0);
dest_desc = open (dst_name, open_flags);
golang中的创建文件:
func Create(name string) (*File, error) {
return OpenFile(name, O_RDWR|O_CREATE|O_TRUNC, 0666)
}
由于以前我做远程进程注入的时候，知道申请不必要的权限，会导致失败率增加。因此，猜测可能是此原因。测试结果，很遗憾，不是。
第四次，在目标文件句柄关闭之前，显式调用Sync函数
如下所示：
func CopyFile(src, dest string) (copiedSize int64, err error) {
copiedSize = 0
srcFile, err := os.Open(src)
if err != nil {
return copiedSize, err
}
defer srcFile.Close()
destFile, err := os.Create(dest)
if err != nil {
return copiedSize, err
}
defer func() {
destFile.Sync() // 卡在这
destFile.Close()
}
return io.Copy(destFile, srcFile)
}
卡住的goroutine示例：
goroutine 51634 [syscall, 523 minutes]:
syscall.Syscall(0x4a, 0xd, 0x0, 0x0, 0xafb1a0, 0xc42000c160, 0x0)
/usr/local/go/src/syscall/asm_linux_amd64.s:18 +0x5
syscall.Fsync(0xd, 0x0, 0x0)
/usr/local/go/src/syscall/zsyscall_linux_amd64.go:492 +0x4a
os.(*File).Sync(0xc420168a00, 0xc4201689f8, 0xc420240000)
/usr/local/go/src/os/file_posix.go:121 +0x3e
Common/utils.CopyFile.func3()
越来越接近真相了，激动。想必原因是：write函数只是将数据写到缓存，并没有实际写到磁盘(这里是GlusterFS)。由于网络或其它原因，导致最后Sync()卡住。
真相
我们找到了这篇文章https://lists.gnu.org/archive/html/gluster-devel/2011-09/msg00005.html
这时运维查了下各个环境的GlusterFS配置，跟我们说，线上环境和高仿环境的GlusterFS的配置项performance.flush-behind为off，开发环境和测试环境是on。智者千虑，必有一失。严谨的运维们，偶尔疏忽实属正常。当然最开心的是终于解决了问题。
gluster> volume info
Volume Name: pre-volume
Type: Striped-Replicate
Volume ID: 3b018268-6b4b-4659-a5b0-38e1f949f10f
Status: Started
Number of Bricks: 1 x 2 x 2 = 4
Transport-type: tcp
Bricks:
Brick1: 10.10.20.201:/data/pre
Brick2: 10.10.20.202:/data/pre
Brick3: 10.10.20.203:/data/pre
Brick4: 10.10.20.204:/data/pre
Options Reconfigured:
performance.flush-behind: OFF // 此处若为on，就Ok
diagnostics.count-fop-hits: on
diagnostics.latency-measurement: on
performance.readdir-ahead: on
