使用並發 ssh 連接來提升撈日志腳本執行效率

問題背景

公司有個簡單粗暴的日志服務，它部署在多台機器實例上，收集的日志記錄在每台機器本地硬盤，寫一個小時自動切換日志文件，硬盤空間寫滿了自動回卷，大約可以保存兩三天的歷史數據。為什么說它粗暴呢？原來它不提供任何查詢日志的接口，想要獲取日志唯一的辦法就是直接查日志文件：

• ssh 執行 grep 得到結果
• scp 將結果復制到本地

最后將這些文件拼接在一起作為最終結果。有個前輩寫過一個腳本，不過比較簡單，基本就是一個 while 循環里串行查詢每台實例。獲取一次日志需要將近 1 個小時，嚴重拖慢了開發人員的節奏。作為一個資深 coder，時間是最富貴的財富，嬸可忍叔不可忍，於是決定對腳本作一番改造以提升查詢效率。

ssh 遠程腳本

在開始改造前，先看下原腳本的執行邏輯：

#!/bin/sh

date=$1
type=$2

# 1st, prepare the grep script
echo "#! /bin/sh" > bin/work_${type}.sh
echo "grep type=${type} /home/log/update.log.${date} >/tmp/work_${type}.log.${date}" >> bin/work_${type}.sh

# 2nd, send the script to each machine and run it
for i in $(get_instance_by_service xxxxx.xxx-xxxx-xxxxxxx-xxxxxx-xxxxxxx-xxxxxx-xxxxxxx.xxx.xxx | sort | uniq)
do
    echo $i
    scp -o "StrictHostKeyChecking no"  -o "PasswordAuthentication=no" -o "ConnectTimeout=3" bin/work_${type}.sh $i:/tmp/
    ssh -o "StrictHostKeyChecking no" -q -xT -o "PasswordAuthentication=no" -o "ConnectTimeout=3" $i "nohup sh /tmp/work_${type}.sh >/dev/null 2>err.log &"
done

# wait 'grep' a while
sleep 30
rm bin/work_${type}.sh

# 3rd, get log from each machine
for i in $(get_instance_by_service xxxxx.xxx-xxxx-xxxxxxx-xxxxxx-xxxxxxx-xxxxxx-xxxxxxx.xxx.xxx | sort | uniq)
do
    ssh -o "StrictHostKeyChecking no" -q -xT -o "PasswordAuthentication=no" -o "ConnectTimeout=3" $i "cat /tmp/work_${type}.log.${date}" >> data/work_${type}.log.${date}
    # delete to free spaces
    ssh -o "StrictHostKeyChecking no" -q -xT -o "PasswordAuthentication=no" -o "ConnectTimeout=3" $i "rm /tmp/work_${type}.log.${date} &"
done

針對上面的腳本，做個簡單說明：

• 目標日志位於遠程機器 /home/log/ 目錄，命名規范為 update.log.yyyyddmmhh，變量名 date 需要精確到小時，例如 2021010208；
• 本地生成的 grep 腳本命名規范為 work_xxxx.sh，其中 xxxx 表示日志類型，所有日志記錄都包含一個 type=xxx 的字段，因此一般通過 type 來過濾無關日志；
• 機器實例需要使用特殊的 get_instance_by_service 命令獲取，這是平台提供的命令，它接收一個 group 參數，返回與日志相關的 500 多台實例；
• 上行時將 grep 腳本上傳到遠程機器的 /tmp 目錄，生成的結果放置在實例的 /tmp 目錄，命名規范為 work_xxxx.log.yyyyddmmhh，xxxx 表示日志類型，后綴為日期；
• 下行時將結果下載到 data 目錄，命名規范為 work_xxxx.log.yyyyddmmhh，因為是串行執行，所以結果數據是直接追加到這個文件的

另外說明一下 ssh 與 scp 的幾個參數：

• -o 用於覆蓋 ssh 配置文件的設置，這里主要用到的是：
  • StrictHostKeyChecking：no - 不進行 known-host 的嚴格檢查，很多實例是第一次訪問，設置這個可以避免交互式提問從而卡死 shell 腳本；
  • PasswordAuthentication：no - 不檢驗 ssh 密碼，執行查詢腳本的機器已經同各個實例建立了證書信任，所以可以這樣設置，同樣是為了防止卡死 shell 腳本的；
  • ConnectTimeout：3 - ssh 連接超時秒數，防止因機器宕機或網絡不通導致長時間等待；
• -q：打開 quiet 模式，減少 ssh 輸出
• -x：關閉 X11 Forwarding，一般用於 GUI 程序，這里是腳本所以不需要
• -T：禁用偽終端分配，偽終端一般用於交互式 console，這里不需要

總結一下遠程 ssh 執行腳本和 scp 的語法：

• ssh host script
• scp local-path host:remote-path
• scp host:remote-path local-path

其中 scp 也可以將遠程文件復制到本地 ，不過這里需要將數據追加到已有文件， 所以使用了 ssh+cat 的實現方式。其實 ssh 的那些選項都可以省略，因為機器之間已經預先建立好了證書信任關系，這里只是 in case。重點說明一下 ssh 執行位於遠程機器的腳本時需要注意的點：

• >/dev/null 2>err.log：重定向 stdout/stderr 到錯誤文件或 /dev/null；
• nohup：ssh tty 退出后繼續執行；
• &：后台執行；

其中比較重要的是第 1 條和第 3 條，nohup 親測可省略。關於這方面的驗證，可以查看文末鏈接。大家記住這個結論即可，后面會用到。

性能瓶頸

為了驗證腳本執行慢確實是由 ssh 串行引起的，這里做了一個實驗，執行以下簡單的腳本，並記錄整體耗時：

$ time ssh xxxx-xxxxxxxx-xxx-xx-xxx.xxxx 'pwd'
/home/rd

real	0m2.145s
user	0m0.026s
sys	0m0.008s

ssh 的第一個參數是實例機器名，由 get_instance_by_service 返回的實例列表中隨便選取一個；ssh 第二個參數是要遠程執行的命令，為了測量 ssh 時間這里使用了 pwd 命令，它的耗時基本可以忽略。

time 輸出證明一次 ssh 交互大概在 2 秒左右，參考上一節中的腳本，可以得出以下腳本耗時公式：

total=(ssh_time + scp_time) * instance_count + 30 + ssh_time * 2 * instance_count
     = ssh_time * 4 * instance_count + 30

這里出於計算方便考慮，忽略 scp 過程中文件傳輸的時間 (單個文件都比較小)，將它的耗時約等於 ssh 耗時，經過推導得到了第二個等式。令 ssh_time = 2，instance_count = 500，那么執行一次腳本就需要 4030 ≈ 1.12 小時，看來光消耗在連接上的時間就超過 1 小時了，怪不得這么慢呢！

預讀取實例列表

讀取實例列表其實比較快，統計了一下也就在幾十毫秒之間：

$ time get_instance_by_service xxxxx.xxx-xxxx-xxxxxxx-xxxxxx-xxxxxxx-xxxxxx-xxxxxxx.xxx.xxx
……
real	0m0.011s
user	0m0.003s
sys	0m0.006s

但當遇到連不通的實例時，一下就要耗掉 3 秒，統計了一下，500 多台實例中只有 300 多台可以連通 (amazing~)，相當於每次有 200 * 4 * 3 = 2400 秒，大約 40 分鍾的時間是浪費在無效的機器上了。當然可以將等待時間縮小到 1 秒，時間就可以降到 10 分鍾。但我連一秒也不願意浪費，何必傻等這 10 分鍾呢？通過提前檢查哪些機器是可以連通的，可以節約這 40 分鍾，具體的做法就是運行 check_instance.sh 這個腳本：

#!/bin/sh

ret=0
start_time=$(date +%s)
if [ -f instance.txt ]; then 
    mv instance.txt instance_old.txt
fi

for host in `get_instance_by_service xxxxx.xxx-xxxx-xxxxxxx-xxxxxx-xxxxxxx-xxxxxx-xxxxxxx.xxx.xxx | sort | uniq`
do
    echo "check $host"
    ssh -o "StrictHostKeyChecking no" -q -xT -o "PasswordAuthentication=no" -o "ConnectTimeout=3" $host "pwd"
    ret=$?
    if [ $ret -eq 0 ]; then 
        # only record success instance
        echo "$host" >> instance.txt
    else 
        echo "error $ret"
    fi
done

end_time=$(date +%s)
cost_time=$(($end_time-$start_time))
echo "check done, total time spend: $(($cost_time/60))m $(($cost_time%60))s "

簡單說明一下：

• 腳本運行完成后將實例列表存儲在本地 instance.txt 文件中
• 如果之前已經存在這個文件，將備份到 instance.bak.txt，方便對比前后輸出結果
• 對每個機器實例，通過 ssh 運行 pwd 命令來檢查它是否可以免密登錄，ssh 相關選項和之間保持一致
• 如果成功，記錄在 instance.txt 文件；否則不記錄，打印一條錯誤信息告知用戶該實例無法連通
• 最后輸出本次檢查耗時

注意，這個腳本仍然是串行的，下面是一次實際的運行耗時：

check done, total time spend: 60m 43s 

印證了之前的計算結果，光 ssh 連接就得耗費一個多小時。好在這個腳本很長時間才運行一次，耗時久還能接受。

預復制過濾腳本

第二塊耗時就是上傳 grep 過濾腳本到實例機器，平均消耗 ssh_time * instance_count = 600 秒 (有效實例按 300 計算)。照搬前面的思路，如果將這個腳本做成通用的並提前上傳到各台實例，那么這一步的耗時也可以省下來了。來看下通用的過濾腳本 fetch_log.sh：

#!/bin/sh

if [ $# -ne 1 -a $# -ne 2 ]; then
    echo "Usage: fetch_log.sh keyword [date]"
    echo "       keyword: anything you think a keyword, support regular expression that grep accepts"
    echo "       date: 2021020308, if no date provide using log file currently writing"
    exit 1
fi

keyword=$1
# using keyword md5 as filename part to avoid file confliction
# and prevent keyword contain invalid character for path names...
keymd5=$(echo $keyword | md5sum | awk '{print $1}')

if [ $# -eq 1 ]; then 
    # if no date provide, using current log file 
    # one can only filter logs that not currently writing ago, 
    # now we can filter them by not providing date parameter.
    grep -a "${keyword}" /home/log/update.log >/tmp/work.${keymd5}.log
else 
    date=$2

    # using keyword md5 as filename part to avoid file confliction
    grep -a "${keyword}" /home/log/update.log.$date >/tmp/work.${date}.${keymd5}.log
fi

 簡單說明一下：

• 腳本接受兩個參數，一個是 keyword，傳遞給 grep 的，不限於 type=xxx 的形式、可以指定任意過濾字符串；一個是精確到小時的日期，用於定位日志文件，如果不傳遞第二個參數，默認使用日志服務當前正在寫的日志文件，它位於 /home/log/update.log，一般做一些實時的測試時可以利用這個特性，避免等待漫長的日志切換時間
• 當多個用戶同時執行腳本且指定了同樣的時間時，這里使用 keyword 的 md5 作為文件名的一部分 (eg: /tmp/work.yyyymmddhh.xxxxxxxxxxxx)，避免服務器文件沖突 (同時指定一個 keyword 的場景最好共享結果，另外這個不能防止本地文件沖突，因此不同用戶最好有自己單獨的腳本副本)
• 腳本接收的參數由真正執行日志撈取的腳本傳遞，關於如何給遠程腳本傳遞參數，稍后給出

干活的腳本有了，下面就來看一下負責上傳腳本的 upload_fetch_log.sh：

#!/bin/sh

ret=0
start_time=$(date +%s)

if [ ! -f instance.txt ]; then 
    echo "generate reliable instance list first.."
    sh check_instance.sh
fi

# upload the fetch_log.sh to each machine
for host in `cat instance.txt`
do
    echo "uploading $host"
    scp -o "StrictHostKeyChecking no"  -o "PasswordAuthentication=no" -o "ConnectTimeout=3" fetch_log.sh $host:/tmp/
    ret=$?
    if [ $ret -ne 0 ]; then 
        echo "error $ret"
    fi
done

end_time=$(date +%s)
cost_time=$(($end_time-$start_time))
echo "upload done, total time spend: $(($cost_time/60))m $(($cost_time%60))s "

做個簡單說明：

• 如果沒有檢測到 instance.txt  的存在，會自動拉起 check_instance.sh 生成實例列表，防止后面遍歷失敗
• 遍歷實例列表，針對每個機器實例，運行 scp 拷貝 fetch_log.sh 到 /tmp/ 目錄備用
• 如果出錯，打印錯誤實例信息
• 最后輸出本次上傳耗時

有兩點需要注意

• 因為依賴 instance.txt，所以需要在執行 check_instance.sh 后執行此腳本，否則會自動執行 check_instance.sh
• 這個腳本仍然是串行的，好在只有每次更新 instance.txt 文件時才執行，耗時久可以接受

下面是一次實際的運行耗時：

upload done, total time spend: 10m 14s

看起來比 check_instance.sh 快多了，主要是只需要對可連通的機器執行 ssh 連接，速度會快很多。

這樣一套組合拳下來，新的腳本不光節省了執行時間，還得到了更強大的過濾表達式、更及時的日志撈取，比之前好用不止一點點。

ssh 並發

上面做了足夠多的鋪墊，可以開始本文的重頭戲了 —— ssh 連接的並發執行。其實聰明的讀者已經看出來了，上面一頓忙活，也只是解決了 1/4 的耗時問題，還有三大耗時在這兒擺着：

• 執行過濾腳本
• 回傳過濾結果
• 刪除過濾結果

而且這已經是在遠程機異步執行了，如果同步執行那就更慢了。所以問題的關鍵不是 grep 慢，而是啟動遠程 grep 慢 (之前有過統計，大概是 2 秒左右)。如何節約這個時間呢？第一個想到的方案是並行執行 ssh，將啟動 ssh 的過程也后台化 (&)，這樣 2 秒內就可以並行啟動多個連接了，如果一次能將 300 台實例全部啟動，時間就可以直接縮短到 2 秒，是不是很厲害！

當然了，考慮到並發連接上限、對日志服務的沖擊等因素，最好不要一次啟動那么多連接，如果一次能啟動 10 個並發連接，那么 300 台實例需要 60 (300 / 10 * 2 ) 秒，也相當快了。不過各個批次之間，需要有一個等待操作，以保證開啟下個批次前上個批次的腳本都執行完畢了，這就增大了復雜性。

不過對於第一步 (過濾) 而言，還沒有回傳文件的問題，相對來說簡單一點，來看一下 exec_fetch_log.sh 腳本：

#!/bin/sh

if [ $# -ne 1 -a $# -ne 2 ]; then
    echo "Usage: exec_fetch_log.sh keyword [date]"
    echo "       keyword: anything you think a keyword，support regular expression that grep accepts"
    echo "       date: 2021020308, if no date provide using log file currently writing"
    exit 1
fi

if [ ! -f instance.txt ]; then 
    echo "generate reliable instance list first.."
    sh check_instance.sh
fi

n=0
batch_size=10
batch_num=0
batch_no=0
keyword=$1
# using keyword md5 as filename part to avoid file confliction
# and prevent keyword contain invalid character for path names...
keymd5=$(echo "$keyword" | md5sum | awk '{print $1}')
date=""
if [ $# -eq 1 ]; then 
    date=`date "+%Y%m%d%H"`
else
    date=$2
fi

echo -e "=======================================================================\nkeyword=$keyword; date=$date; keymd5=$keymd5" | tee -a error.log
start_time=$(date +%s)
echo "start grep from each machine"
for host in `cat instance.txt`
do
    batch_no=$(($n % $batch_size))
    batch_num=$(($n / $batch_size))
    if [ $batch_no -eq 0 -a $n -gt 0 ]; then 
        echo "wait batch $batch_num"
        wait
    fi

    echo "$(($n+1)): $host"
    if [ $# -eq 1 ]; then 
        ssh -o "StrictHostKeyChecking no" -q -xT -o "PasswordAuthentication=no" -o "ConnectTimeout=3" $host "nohup sh /tmp/fetch_log.sh \"$keyword\" >/dev/null 2>err.log &" >> error.log 2>&1 &
    else 
        ssh -o "StrictHostKeyChecking no" -q -xT -o "PasswordAuthentication=no" -o "ConnectTimeout=3" $host "nohup sh /tmp/fetch_log.sh \"$keyword\" \"$date\" >/dev/null 2>err.log &" >> error.log 2>&1  &
    fi
    n=$(($n+1))
done

echo "wait last batch $(($batch_num+1))"
wait

……

做個簡單說明：

• 接收參數與 fetch_log.sh 保持一致，包括 Usage 打印的內容
• 如果沒有檢測到 instance.txt  的存在，會自動拉起 check_instance.sh 生成實例列表，這個對於新同學會比較友好，自動建立依賴
• batch_size 默認為 10，如果當前實例數 (n) 達到整批次，說明要開啟一個新的批次了，此時需要先 wait 上個批次的所有進程，確保它們都完成了 ssh 執行，這一步很重要，否則會一次建立 300 多個連接，就不能實現之前說的分批運行目標
• 分批運行每個實例的連接和之前非常像，唯一的區別在於末尾的 '>> error.log 2>&1 &'， 這一句將 ssh 本身也異步執行了，是整個腳本的靈魂。異步執行會非常快的返回，不存在之前那 2 秒的排隊問題了
• 之前已經將過濾腳本上傳到了遠程實例的 /tmp 目錄，所以這里直接調用 /tmp/fetch_log.sh
• 遠程 ssh 腳本傳參比較直觀，就是直接在腳本后面加相應的參數字符串，為防止參數中的空格中斷參數解析，這里加了雙引號 (在雙引號中間需要 \ 釋義)
• 按是否有 date 參數做下區分，有的話會將 date 參數給到遠程實例的 fetch_log.sh 腳本，沒有的話不傳遞這樣就會使用當前日志文件了
• 從 while 循環結束時，通過 wait 等待最后一個批次的 ssh 執行完成，來保證所有連接都關閉了

ssh 並發的關鍵是批次控制，每個異步執行的 ssh 都將成為一個單獨的子進程，通過 wait 等待子進程就可以完成批次的等待，不過這有一個前題 —— 並發腳本沒有其它獨立運行的子進程，換句話說，就是不能同時有其它異步執行的任務。當然了，也可以通過在數組中記錄子進程的 pid 並挨個 wait 它們來實現，不過那樣開發成本就太高了，這里沒有采取，感興趣的可以看下 man wait：

       wait [n ...]
              Wait  for  each  specified  process  and return its termination status.  Each n may be a process ID or a job
              specification; if a job spec is given, all processes in that job’s pipeline are waited for.   If  n  is  not
              given, all currently active child processes are waited for, and the return status is zero.  If n specifies a
              non-existent process or job, the return status is 127.  Otherwise, the return status is the exit  status  of
              the last process or job waited for.

老腳本的 ssh 異步其實只進行到了第一步 —— 遠程執行，而 ssh 連接本身還是同步的，新腳本最大的改進是連 ssh 本身也異步了，並提供了並發數量控制，可以實現更極致的並發能力。如果有些人不在乎並發量，可以直接一個循環異步啟動所有 ssh 連接，那樣代碼更簡單。

並發數量也會隨機器數量增多而增長，不過這里沒有將這個參數暴露在外面，主要是防止一些人為了快而不擇手段，對現在運行的日志服務造成影響 (當然了，只能防一些小白誤操作)。

文件合並

有了上面的基礎，再處理剩下的兩大耗時操作也就不難了，與執行過濾和刪除結果不同，回傳結果要求腳本執行完成后將數據保存在本地，之前順序執行時一個追加操作就能搞定的事情現在變復雜了，批量並行后如何處理同時返回的多個文件塊成為一個問題。首先不能再簡單的追加了，因為多進程追加有可能導致數據混亂，保險的方式是每個子進程寫一個臨時文件，最后再將它們合並起來，繼續看主腳本 exec_fetch_log：

n=0
batch_num=0
dir=""
olddir=""
if [ ! -d data ]; then 
    mkdir data
fi

echo "fetch result logs from each machine"
for host in `cat instance.txt`
do
    batch_no=$(($n % $batch_size))
    batch_num=$(($n / $batch_size))
    dir="data/$date.$batch_num"
    if [ ! -d "$dir" ]; then 
        mkdir "$dir"
        echo "create data dir: $dir"
    fi
    if [ $batch_no -eq 0 -a $n -gt 0 ]; then 
        # splice previous batch files
        if [ $batch_num -gt 1 ]; then 
            # has previous batch
            echo "batch end, try to splice previous batch files..."
            olddir="data/$date.$(($batch_num-2))"
            for file in $olddir/work.*.log
            do
                echo "handle $file: $(stat -c \"%s\" $file)"
                cat "$file" >> data/work.$date.log
            done 

            rm -rf "$olddir"
            echo "delete dir: $olddir"
        fi

        echo "wait batch $batch_num"
        wait
    fi

    echo "$(($n+1)): $host"
    if [ $# -eq 1 ]; then 
        scp -o "StrictHostKeyChecking no"  -o "PasswordAuthentication=no" -o "ConnectTimeout=3" "$host:/tmp/work.$keymd5.log" "$dir/work.$host.log" >> error.log 2>&1 &
    else
        scp -o "StrictHostKeyChecking no"  -o "PasswordAuthentication=no" -o "ConnectTimeout=3" "$host:/tmp/work.$date.$keymd5.log" "$dir/work.$host.log" >> error.log 2>&1 &
    fi
    n=$(($n+1))
done

# splice previous batch files
echo "batch end, try to splice last batch files..."
olddir="data/$date.$(($batch_num-1))"
for file in $olddir/work.*.log
do
    echo "handle $file: $(stat -c \"%s\" $file)"
    cat "$file" >> data/work.$date.log
done 

rm -rf "$olddir"
echo "delete dir: $olddir"
echo "wait last batch $(($batch_num+1))"
wait

if [ $batch_no -ne 0 ]; then 
    olddir="data/$date.$batch_num"
    for file in $olddir/work.*.log
    do
        echo "handle $file: $(stat -c \"%s\" $file)"
        cat "$file" >> data/work.$date.log
    done 

    rm -rf "$olddir"
    echo "delete dir: $olddir"
fi

做個簡單說明：

• 所有數據存儲於 data 目錄，不存在時創建之
• 大的 for 循環先看下面真正干活的 scp 語句，去遠程機器上獲取過濾后的日志：/tmp/work.yyyyddmmhh.xxxx.log，這是之前上傳到各實例的過濾腳本默認的輸出路徑
• 根據是否提供第二個參數 date，獲取的文件名也有所區別，這一點和之前是一致的
• scp 的異步執行也加了 '>> error.log 2>&1 &'，這一點和之前 ssh 的異步執行異曲同工，可節約額外的 2 秒時間
• 數據塊是按批次保存的，在 data 下面建二級目錄 0/1/2 等數字代碼批次，例如第一批數據全部位於目錄 0，第二批位於目錄 1……以此類推
• 批次目錄下的數據通過實例名稱區分，例如第一批的十塊數據，命名為 work.xxxx-xxxxxx-xxxxxx-xxxxxxxx-xx-xxx.xxxx.log，中間長長的一串就是機器實例，不會沖突
• 批次目錄在該批次第一個實例進入循環后創建，開始新的批次前等待上一個批次全部子進程結束 (wait) 的邏輯和之前一致
• 稍有不同的地方位於文件塊合並處，wait 第一批次的時候，還沒有文件塊下載，所以是跳過的
• 當 wait 后續批次時 (batch_num > 1)，就可以伺機合並前一批次下載的數據塊了，例如 wait 第二批次前合並第一批次的數據，wait 第三批次前合並第二批次的數據……以此類推，此時可以合並前一個批次是因為上個批次的進程已經全部 wait 到了，可以保證沒有任何子進程在操作對應批次目錄中的文件
• 合並文件的邏輯相對簡單，就是遍歷批次目錄，將其中的文件塊追加到最終的文件 data/work.yyyymmddhh.log 中，合並成功后批次目錄將被刪除，釋放臨時文件占用的空間
• 從大的 for 循環出來后的邏輯稍等復雜一些，首先是要有一個 wait 來保證最后一個批次結束，這個 wait 后有一個文件合並來保證最后一批數據塊合入母文件
• 比較難以理解的是 for 循環出來后、wait 前有一個文件合並操作，這個其實是合並的倒數第二批數據塊。從前面的類推可以得知，for 循環中 wait 第 N-1 批次前合並了第 N-2 批次的數據，退出循環后第 N-1 批次還沒合並呢，它只是進程都退出了但數據塊還處於待合並狀態，所以這里需要在 wait 前先補一個合並

其實在 wait 后合並是比較符合一般人思維習慣的，此時子進程都退出了，正好就把數據塊合並了事，這樣在 for 循環結束后就只需要一次 wait 和合並就可以了，代碼看上去更清爽。為什么沒有這樣做呢？並發，還是並發！當一批子進程 wait 成功時，先去啟動下一批的 ssh 連接，在 ssh 連接干活的空隙 (2 秒) 去合並數據塊綽綽有余，等合並完了再回來一個 wait 可能還得等上個 1 秒多，這樣是不是就省下了數據塊合並的時間呢？哈哈，這才是真正的時間管理大師好伐😎，為了節省時間代碼寫的 ugly 也不管了~

另外再說一下數據塊順序的問題，不同批次的實例數據是有序的，同一批次多個實例之間的數據是隨機的，依賴 'for ... in' 語句返回的文件順序。不過實例之間本來就是並行的關系，在這里討論它們之間的順序其實有點扯淡，如果需要結果按日志時間排序，只能對最終結果文件重排一下就好了，畢竟每個實例包含的日志時間本身就是犬牙交錯的。

主腳本最后一部分是刪除過濾結果的腳本：

n=0
batch_num=0
# prevent disk full
echo "delete result logs from each machine"
for host in `cat instance.txt`
do
    batch_no=$(($n % $batch_size))
    batch_num=$(($n / $batch_size))
    if [ $batch_no -eq 0 -a $n -gt 0 ]; then 
        echo "wait batch $batch_num"
        wait
    fi

    echo "$(($n+1)): $host"
    if [ $# -eq 1 ]; then 
        ssh -o "StrictHostKeyChecking no" -q -xT -o "PasswordAuthentication=no" -o "ConnectTimeout=3" $host "rm /tmp/work.$keymd5.log" >> error.log 2>&1 &
    else 
        ssh -o "StrictHostKeyChecking no" -q -xT -o "PasswordAuthentication=no" -o "ConnectTimeout=3" $host "rm /tmp/work.$date.$keymd5.log" >> error.log 2>&1 &
    fi
    n=$(($n+1))
done

if [ $batch_no -ne 0 ]; then 
    echo "wait last batch $(($batch_num+1))"
    wait
fi

end_time=$(date +%s)
cost_time=$(($end_time-$start_time))
echo "execute done, total time spend: $(($cost_time/60))m $(($cost_time%60))s "

這部分沒有文件回傳的問題，甚至沒有分批的問題，直接 for 循環遍歷所有實例就搞定了，不再贅述。

結語

經過改進的腳本執行效率大大提升，從之前一個多小時能降到 5 ~ 10 分鍾，有輸出為證：

sh exec_fetch_log.sh 'type=task_summary.*version=3.0.0.100' 2022010915
=======================================================================
keyword=type=task_summary.*version=3.0.0.100; date=2022010915; keymd5=ab31c5c20804570d72d432d119f5bbf9
start grep from each machine
1: xxxx-mco-cloud-xxxxxxxx.xxxx
2: xxxx-mco-cloud-xxxxxxxx.xxxx
3: xxxx-mco-yun-xxxxxxxx-b0cae.xxxx
4: xxxx-mco-yun-xxxxxxxx-178c5.xxxx
5: xxxx-mco-yun-xxxxxxxx-2644c.xxxx
6: xxxx-mco-yun-xxxxxxxx-44cdc.xxxx
7: xxxx-mco-yun-xxxxxxxx-9c10d.xxxx
8: xxxx-mco-yun-xxxxxxxx-4f75a.xxxx
9: xxxx-mco-yun-xxxxxxxx-d73bc.xxxx
10: xxxx-mco-yun-xxxxxxxx-b6bb1.xxxx
wait batch 1
11: xxxx-mco-yun-xxxxxxxx-6dbe6.xxxx
12: xxxx-mco-yun-xxxxxxxx-d46bd.xxxx
13: xxxx-mco-yun-xxxxxxxx.xxxx
14: xxxx-xxxxxxxx-r00-00-021.xxxx
15: xxxx-xxxxxxxx-r00-00-037.xxxx
16: xxxx-xxxxxxxx-r00-00-040.xxxx
17: xxxx-xxxxxxxx-r00-00-078.xxxx
18: xxxx-xxxxxxxx-r00-00-083.xxxx
19: xxxx-xxxxxxxx-r00-01-008.xxxx
20: xxxx-xxxxxxxx-r00-01-011.xxxx
wait batch 2
21: xxxx-xxxxxxxx-r00-01-016.xxxx
22: xxxx-xxxxxxxx-r00-01-072.xxxx
23: xxxx-xxxxxxxx-r00-01-075.xxxx
24: xxxx-xxxxxxxx-r00-02-013.xxxx
25: xxxx-xxxxxxxx-r00-02-032.xxxx
26: xxxx-xxxxxxxx-r00-02-070.xxxx
27: xxxx-xxxxxxxx-r00-02-072.xxxx
28: xxxx-xxxxxxxx-r00-02-073.xxxx
29: xxxx-xxxxxxxx-r00-02-076.xxxx
30: xxxx-xxxxxxxx-r00-03-003.xxxx
wait batch 3
……
281: xxxx-xxxxxxxx-r01-00-135.xxxx
282: xxxx-xxxxxxxx-r01-00-139.xxxx
283: xxxx-xxxxxxxx-r01-00-140.xxxx
284: xxxx-xxxxxxxx-r01-01-057.xxxx
285: xxxx-xxxxxxxx-r01-01-065.xxxx
286: xxxx-xxxxxxxx-r01-01-087.xxxx
287: xxxx-xxxxxxxx-r01-01-089.xxxx
288: xxxx-xxxxxxxx-r01-01-099.xxxx
289: xxxx-xxxxxxxx-r01-01-111.xxxx
290: xxxx-xxxxxxxx-r01-01-115.xxxx
wait batch 29
291: xxxx-xxxxxxxx-r01-02-067.xxxx
292: xxxx-xxxxxxxx-r01-02-080.xxxx
293: xxxx-xxxxxxxx-r01-02-090.xxxx
294: xxxx-xxxxxxxx-r01-02-112.xxxx
295: xxxx-xxxxxxxx-r01-02-114.xxxx
296: xxxx-xxxxxxxx-r01-02-117.xxxx
297: xxxx-xxxxxxxx-r01-03-056.xxxx
298: xxxx-xxxxxxxx-r01-03-071.xxxx
299: xxxx-xxxxxxxx-r01-03-084.xxxx
300: xxxx-xxxxxxxx-r01-03-089.xxxx
wait batch 30
301: xxxx-xxxxxxxx-r01-03-100.xxxx
302: xxxx-xxxxxxxx-r01-03-103.xxxx
303: xxxx-xxxxxxxx-r01-03-105.xxxx
wait last batch 31
execute done, total time spend: 5m 14s

程序員的效率有了提升，又能愉快的完成 okr 啦~

總結一下整個腳本性能優化過程，可以梳理出以下幾個關鍵點：

1. 只做一次的事情單獨提出來預先執行
2. ssh 遠程異步執行包含兩個層面
   1. 遠程服務器腳本后台異步執行
   2. 本機啟動 ssh 后台異步執行

主要優化的是 1 和 2.b 兩點，其中 2.b 又涉及到批的管理和數據塊的合並，是本次優化的核心。

細心的讀者可能已經發現，批量執行是任務隔離的，那多個任務之間 (執行過濾腳本、回傳過濾結果、刪除過濾結果) 能不能並行呢？答案肯定是否定的，沒有執行完腳本就沒有結果、沒有結果就提不上刪除，如果不等上個任務結果就執行下個任務，可能會導致意料之外的事情發生。特別是執行過濾腳本與回傳結果之間，一定要留足夠的時間間隔，可是看腳本似乎並沒有做任何等待，這又是怎么回事呢？原來這里每個任務用跑批的方式處理后，就已經有足夠的時間間隔了，所以沒有特地寫 sleep 去等待，如果一些人打算不跑批直接循環啟動所有連接、或者跑批時量比較小導致等待時間不夠，就需要自己在上面兩個任務之間加上 Sleep。回傳過濾結果和刪除之間不需要 Sleep，因為前者在跑批中已經 wait 了，子進程結束后對應的任務也結束了，不像執行過濾腳本，子進程結束時，真正的 grep 進程可能還在遠程實例上跑着呢！

這個腳本還可以繼續優化，就是 check_instance.sh 和 upload_fetch_log.sh 也可以由串行改為並行，感興趣的讀者自己實現一下吧~

ssh 連接獲取日志的方式還是太原始了，得到的數據幾乎只有總量的一半多 (大量 ssh 連不通)，后來聽老同事說可以通過集群命令的方式獲取全量日志，不知道腳本中能不能直接用😅，不過對於拉取少量日志而言，這種方式還是解決了我的實際痛點，沒有做無用功。

參考

[1]. ssh 遠程執行命令

[2]. linux-ssh遠程后台執行腳本-放置后台執行問題（轉）

[3]. [Jenkins][Git]ssh原理以及與https的區別

[4]. Linux 系統 SSH 和 SCP 服務器搭建與訪問

[5]. ssh 遠程執行命令