記錄一個拷貝檔案到GlusterFS卡住的解決過程

問題簡介

我們有一個分散式服務，儲存為 Gluster FS，需要大量的讀寫檔案。在公司開發環境、測試環境都正常的情況下，線上上環境、高仿環境卻屢屢出現拷貝檔案到 Gluster FS 卡住的問題（檔案若是 200M~5G 大小，概率大概在 3~4% 左右，檔案已拷貝完成，原始檔和目標檔案 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

相關 issue：https://github.com/gluster/glusterfs/issues/341 flush-behind 介紹：https://github.com/gluster/glusterfs/blob/7e1ee2efa0b4f5c42a48282204f3d3977ab41fe2/doc/developer-guide/write-behind.md