【Go】使用壓縮檔案優化io (二)

qiyin發表於2019-07-08
Go優化

原文連結： https://blog.thinkeridea.com/201907/go/compress_file_io_optimization2.html

上一篇文章《使用壓縮檔案優化io (一)》中記錄了日誌備份 io 優化方案，使用檔案流資料壓縮方案優化 io 效能，效果十分顯著。這篇文章記錄資料分析前置清洗、格式化資料的 io 優化方案，我們有一臺專用的日誌前置處理伺服器，所有業務日誌通過這臺機器從 OSS 拉取回來清洗、格式化，最後進入到資料倉儲中便於後續的分析。

隨著業務擴充套件這臺伺服器壓力越來越大，高峰時資料延遲越來越厲害，早期也是使用 Python 指令碼 + awk 以及一些 shell 命令完成相關工作，在資料集不是很大的時候這種方案很好，效率也很高，隨著資料集變大，發現伺服器負載很高，經過分析是還是 io 阻塞，依舊採用對資料流進行處理的方案優化io，以下記錄優化的過程。

背景介紹

伺服器配置：4 核 8G； 磁碟：1T

分析前置服務會根據業務不同分為十分鐘、一小時兩個階段拉取分析日誌，每隔一個階段會去 OSS 拉取日誌回到伺服器進行處理，處理過程因 io 阻塞，導致 CPU 和 load 異常高，且處理效率嚴重下降，這次優化主要就是降低 io 阻塞，提升 CPU 利用率 (處理業務邏輯而不是等待 io) 和處理效率。

後文中會詳細描述優化前後的方案，並用 go 編寫測試，使用一臺 2 核4G的伺服器進行測試，測試資料集大小為：

  • 檔案數量：432個
  • 壓縮檔案：17G
  • 解壓後檔案：63G
  • 壓縮方案：lzo
  • Goroutine 數量：20

優化前

優化前日誌處理流程：

  • 獲取待處理檔案列表
  • 拉取 OSS 日誌到本地磁碟 (壓縮檔案)
  • 解壓縮日誌檔案
  • 讀取日誌資料
  • 業務處理……
  • 匯入到資料倉儲中

導致 io 阻塞的部分主要是： 拉取 OSS 日誌、解壓縮日誌檔案及讀取日誌資料，優化也主要從這三塊著手。

這裡有一段公共的日誌讀取方法，該方法接收一個 io.Reader， 並按行讀取日誌，並簡單切分日誌欄位，並沒有實質的處理日誌資料，後面的優化方案也將使用這個方法讀取日誌。

package main

import (
    "bufio"
    "bytes"
    "io"

    "github.com/thinkeridea/go-extend/exbytes"
)

func Read(r io.Reader) {
    rawBuffer := make([]byte, 512)
    buf := bufio.NewReader(r)
    for {
        line, ok, err := readLine(buf, rawBuffer)
        if err == io.EOF {
            return
        }

        if err != nil {
            panic(nil)
        }

        if ok {
            rawBuffer = line
        }

        c := bytes.Count(line, []byte{'\x01'})
        if c != 65 {
            panic("無效的行")
        }
    }
}

func readLine(r *bufio.Reader, rawBuffer []byte) ([]byte, bool, error) {
    var ok bool
    line, err := r.ReadSlice('\n')
    if (err == bufio.ErrBufferFull || len(line) < 3 || exbytes.ToString(line[len(line)-3:]) != "\r\r\n") && err != io.EOF {
        rawBuffer = append(rawBuffer[:0], line...)
        for (err == bufio.ErrBufferFull || len(line) < 3 || exbytes.ToString(line[len(line)-3:]) != "\r\r\n") && err != io.EOF {
            line, err = r.ReadSlice('\n')
            rawBuffer = append(rawBuffer, line...)
        }
        line = rawBuffer
        ok = true
    }

    if len(line) > 0 && err == io.EOF {
        err = nil
    }

    return line, ok, err
}

日誌按 \r\r\n 分隔行，使用 \x01 切分欄位，讀取方法使用 bufio.ReadSlice 方法，避免記憶體分配，且當 bufio 緩衝區滿之後使用 rwaBuffer 作為本地可擴充套件緩衝，每次擴充套件之後會保留最大的擴充套件空間，因為業務日誌每行大小差不多，這樣可以極大的減少記憶體分配，效率是 bufio.ReadLine 方法的好幾倍。

package main

import (
    "fmt"
    "os"
    "os/exec"
    "path/filepath"
    "strings"
    "sync"
    "time"

    ".../pkg/aliyun_oss" // 虛假的包
)

func main() {
    var oss *aliyun_oss.AliyunOSS // 對接阿里雲 OSS，需要自行封裝
    files := list()               // 這是一個虛構的方法，用來獲取待處理的檔案列表

    fmt.Printf("待處理檔案數量：%d\n", len(files))

    start := time.Now()
    defer func(t time.Time) {
        fmt.Printf("共耗時：%0.6f\n", time.Now().Sub(t).Seconds())
    }(start)

    // 下載日誌檔案
    n := 20
    var wg sync.WaitGroup
    c := make(chan string)
    wg.Add(n)
    for i := 0; i < n; i++ {
        go func() {
            defer wg.Done()
            for {
                f, ok := <-c
                if !ok {
                    return
                }

                if _, err := os.Stat(f); err == nil {
                    return
                } else if !os.IsNotExist(err) {
                    panic(err)
                }

                dir := filepath.Dir(f)
                err := os.MkdirAll(dir, 0755)
                if err != nil {
                    panic(err)
                }

                err = oss.GetObjectToFile(f, f)
                if err != nil {
                    panic(err)
                }
            }
        }()
    }

    for _, f := range files {
        c <- f
    }

    close(c)
    wg.Wait()

    fmt.Printf("下載檔案耗時：%0.6f\n", time.Now().Sub(start).Seconds())

    // 解壓日誌檔案
    start = time.Now()
    shell := exec.Command("/bin/bash", "-c", "lzop -df logs/*/*/*/*/*/*.lzo")
    err := shell.Run()
    if err != nil {
        panic(err)
    }

    fmt.Printf("解壓檔案耗時：%0.6f\n", time.Now().Sub(start).Seconds())

    // 讀取日誌檔案
    start = time.Now()
    c = make(chan string)
    wg.Add(n)
    for i := 0; i < n; i++ {
        go func() {
            defer wg.Done()
            for {
                file, ok := <-c
                if !ok {
                    return
                }
                f, err := os.Open(file)
                if err != nil {
                    panic(err)
                }

                Read(f)
                f.Close()
            }
        }()
    }

    for _, f := range files {
        c <- strings.TrimRight(f, ".lzo")
    }

    close(c)
    wg.Wait()

    fmt.Printf("讀取檔案耗時：%0.6f\n", time.Now().Sub(start).Seconds())
}

執行程式輸出如下：

待處理檔案數量：432
下載檔案耗時：303.562865
解壓檔案耗時：611.236232
讀取檔案耗時：460.371245
共耗時：1375.187261

通過 iostat -m -x 5 10000 分析各個階段結果如下：

  • 下載時：
avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           7.85    0.00   16.44   11.24    0.00   64.48

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
vda               0.00     0.00   80.40    7.80     8.98     0.04   209.36     0.40    4.57    4.64    3.77   0.50   4.44
vdb               1.40   761.20  247.60  264.00    14.70    60.92   302.72     9.17   17.92   10.36   25.00   0.52  26.52
  • 解壓時：
avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           8.54    0.00    8.33   68.39    0.00   14.74

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
vda               0.00     1.20    3.40   11.80     0.01     0.05     8.95     0.30   20.03    0.41   25.68   0.55   0.84
vdb               0.00 22037.80  107.80  243.20    26.45   107.01   778.71    83.52  236.68   74.31  308.65   2.52  88.54
  • 讀取時：
avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           2.74    0.00    5.07   92.19    0.00    0.00

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
vda               0.00     2.40    3.80   23.60     0.01     0.14    11.85     0.12    4.48    1.95    4.89   0.33   0.90
vdb               1.80     4.60  347.20    6.20   139.97     0.08   811.60   126.62  358.04  360.79  203.48   2.83 100.00

通過 iostat 結果可以看出，在解壓和讀取日誌時 io 阻塞比較嚴重，且執行時間較長，下載時 io 阻塞也存在，但還可以接受，通過下面兩個方案逐漸消除掉 io。

優化方案一

優化前的方案反應出在解壓和讀取日誌時 io 阻塞比較嚴重，那麼是否可以通過讀取 lzo 壓縮檔案，以此來消除解壓縮日誌耗時太大、io 太高的問題呢？並且讀取 lzo 壓縮檔案遠比解壓後檔案小，來降低讀取日誌耗時太大、io 太高的問題呢？

優化後日志處理流程：

  • 獲取待處理檔案列表
  • 拉取 OSS 日誌到本地磁碟 (壓縮檔案)
  • 讀取壓縮日誌資料
  • 業務處理……
  • 匯入到資料倉儲中
package main

import (
    "fmt"
    "os"
    "path/filepath"
    "sync"
    "time"

    ".../pkg/aliyun_oss" // 虛假的包
    "github.com/cyberdelia/lzo"
)

func main() {
    var oss *aliyun_oss.AliyunOSS // 對接阿里雲 OSS，需要自行封裝
    files := list()               // 這是一個虛構的方法，用來獲取待處理的檔案列表

    fmt.Printf("待處理檔案數量：%d\n", len(files))
    start := time.Now()
    defer func(t time.Time) {
        fmt.Printf("共耗時：%0.6f\n", time.Now().Sub(t).Seconds())
    }(start)

    // 下載日誌檔案
    n := 20
    var wg sync.WaitGroup
    c := make(chan string)
    wg.Add(n)
    for i := 0; i < n; i++ {
        go func() {
            defer wg.Done()
            for {
                f, ok := <-c
                if !ok {
                    return
                }

                if _, err := os.Stat(f); err == nil {
                    return
                } else if !os.IsNotExist(err) {
                    panic(err)
                }

                dir := filepath.Dir(f)
                err := os.MkdirAll(dir, 0755)
                if err != nil {
                    panic(err)
                }

                err = oss.GetObjectToFile(f, f)
                if err != nil {
                    panic(err)
                }
            }
        }()
    }

    for _, f := range files {
        c <- f
    }

    close(c)
    wg.Wait()

    fmt.Printf("下載檔案耗時：%0.6f\n", time.Now().Sub(start).Seconds())

    start = time.Now()
    c = make(chan string)
    wg.Add(n)
    for i := 0; i < n; i++ {
        go func() {
            defer wg.Done()
            for {
                file, ok := <-c
                if !ok {
                    return
                }
                f, err := os.Open(file)
                if err != nil {
                    panic(err)
                }

                r, err := lzo.NewReader(f)
                if err != nil {
                    panic(err)
                }

                Read(r)
                r.Close()
                f.Close()
            }
        }()
    }

    for _, f := range files {
        c <- f
    }

    close(c)
    wg.Wait()

    fmt.Printf("讀取檔案耗時：%0.6f\n", time.Now().Sub(start).Seconds())
}

這個方案消除了解壓縮日誌，並且直接讀取壓縮日誌，使用 github.com/cyberdelia/lzo 包對壓縮檔案資料流進行邊讀取邊解壓，這次不用單獨封裝新的方法了，直接使用 lzo 包中的介面即可。

程式執行結果如下：

待處理檔案數量：432
下載檔案耗時：286.146603
讀取檔案耗時：132.787345
共耗時：418.942862

這個方案效果非常明顯，總耗時從 1375.187261 降低到 418.942862 提升了 3 倍的效率，不僅消除了壓縮的時間，還大大縮短了讀取檔案耗時，成果顯著。

通過 iostat -m -x 5 10000 分析各個階段結果如下：

下載時：

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           5.08    0.00   13.24   29.34    0.00   52.33

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
vda               0.00     2.80    1.40   11.80     0.01     0.07    12.00     0.02    1.85    1.14    1.93   0.18   0.24
vdb               0.00 17207.60    0.60  212.40     0.00    75.06   721.74    55.81  236.34   84.33  236.77   2.49  53.14

讀取時：

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
          80.66    0.00    4.83   14.50    0.00    0.00

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
vda               0.00     0.00    6.20    0.20     0.06     0.00    20.00     0.01    1.69    1.71    1.00   0.62   0.40
vdb               0.00     6.80  390.40   19.20   118.78     0.23   595.04    74.87  190.55  197.95   40.08   1.85  75.90

通過 iostat 結果分析，下載時 io 阻塞和優化前波動不是很大，讀取時的 io 優化已經非常好了，iowait 從 92.19% 降低到 14.5% ，CPU 更多的任務用來處理解壓縮日誌，而不是處理 io 阻塞。

優化方案二

本來優化到上面的效果已經非常滿意了，不過既然開始做優化就不能草草結束了，仔細思考業務場景，需要 本地 lzo 檔案？重新處理日誌的頻率高嗎？本地 lzo 日誌清理方便嗎？

通過上面的幾個問題發現，除非程式出現問題或者資料儲存出現故障，否者極少需要重新處理日誌，一年裡面這種情況也是極少的，甚至不會發生。

那麼思考一下，不下載日誌，直接讀取網路資料流，實現邊下邊解壓邊讀取，這樣豈不是沒有 io 了嗎?

優化後日志處理流程：

  • 獲取待處理檔案列表
  • 拉取 OSS 日誌，在記憶體中解壓並讀取分析日誌
  • 業務處理……
  • 匯入到資料倉儲中

具體實現如下：

package main

import (
    "fmt"
    "sync"
    "time"

    ".../pkg/aliyun_oss" // 虛假的包
    "github.com/cyberdelia/lzo"
)

func main() {
    var oss *aliyun_oss.AliyunOSS // 對接阿里雲 OSS，需要自行封裝
    files := list()               // 這是一個虛構的方法，用來獲取待處理的檔案列表

    fmt.Printf("待處理檔案數量：%d\n", len(files))

    start := time.Now()
    defer func(t time.Time) {
        fmt.Printf("共耗時：%0.6f\n", time.Now().Sub(t).Seconds())
    }(start)

    n := 20
    var wg sync.WaitGroup
    c := make(chan string)
    wg.Add(n)
    for i := 0; i < n; i++ {
        go func() {
            defer wg.Done()
            for {
                f, ok := <-c
                if !ok {
                    return
                }

                r1, err := oss.GetObject(f)
                if err != nil {
                    panic(err)
                }

                r, err := lzo.NewReader(r1)
                if err != nil {
                    panic(err)
                }

                Read(r)
                r.Close()
                r1.Close()
            }
        }()
    }

    for _, f := range files {
        c <- f
    }

    close(c)
    wg.Wait()

    fmt.Printf("讀取檔案耗時：%0.6f\n", time.Now().Sub(start).Seconds())
}

優化後只有一個流程了，程式碼簡潔了不少，看看效率如何吧！

程式執行結果如下：

待處理檔案數量：432
讀取檔案耗時：285.993661
共耗時：285.993717

天啊發生了什麼，我使勁擦了擦眼睛，太不可思議了，居然只消耗了下載日誌的耗時，較上一個方案總耗時從 418.942862 降低到 285.993717，提升了近 2 倍的效率，讓我們看看上個方案下載檔案耗時 286.146603 ，而新方案總耗時是 285.993717 居然只用了上個優化版本的下載時間，究竟發生了什麼？

通過 iostat -m -x 5 10000 分析結果如下：

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
          43.73    0.00    9.64    0.31    0.00   46.32

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
vda               0.00     1.20    4.40    3.80     0.02     0.03    10.93     0.01    1.49    0.59    2.53   0.71   0.58
vdb               0.00     6.80    0.00   24.60     0.00     0.27    22.83     0.02    0.84    0.00    0.84   0.28   0.68

通過 iostat 結果分析，在程式執行期間沒有任何 io 開銷，CPU 居然還有一半的空閒，前面兩個版本 CPU 是沒有空閒的啊，由此看來之前 CPU 更多的消耗在 io 阻塞上了，並沒有用來處理業務邏輯。

由此來看也就不足為奇了，為啥優化後只需要下載日誌的時間就能處理完所有日誌了，沒有了 io 阻塞，CPU 更多了用來處理業務，把之前下載時寫檔案 io 的耗時，用來解壓縮資料，讀取資料，且還有更多的空閒，跑出這樣的結果也就很正常了。

總結

從優化前耗時 1375.187261 秒到 285.993717 秒，效能提升 80%， 從 iowait 92.19% 到 0.31% 提升近 100%，從沒有任何 CPU 空閒到有一半空閒，這個過程中有很多值得總結的事情。

io 對效能的影響非常大，對 CPU 佔用非常嚴重，導致 CPU 處理業務邏輯的時間片非常少。從 io 轉移到 CPU 對效能提升非常明顯。CPU 計算效率十分的高，從 io 密集到密集計算，只要符合業務場景，往往能給我們帶來意想不到的效果。

往往優化業務並不需要十分高大上的技術，只是轉變一下思路，不僅程式碼更少，且程式更簡短、好維護、邏輯更清晰。

一定要結合實際業務場景進行思考，減少理所當然和業務無關的中間環節，往往就可以極大的提升程式效率。

轉載：

本文作者： 戚銀（thinkeridea）

本文連結： https://blog.thinkeridea.com/201907/go/compress_file_io_optimization2.html

版權宣告： 本部落格所有文章除特別宣告外，均採用 CC BY 4.0 CN協議 許可協議。轉載請註明出處！

相關文章