[教程] venus-worker 各阶段耗时统计

[Fatman13]

原文 by @denniszou

启动venus-worker的时候设置了环境变量RUST_LOG为INFO级别。

PC1耗时统计:

$ grep seal_pre_commit_phase1 <venus-worker.log> | sort -k 8 | awk -f vw-duration.awk

PC2耗时统计:

grep seal_pre_commit_phase2 <venus-worker.log> | sort -k3,1 | awk -f vw-duration.awk

vw-duration.awk脚本：

function strts(datetime) {
    ts= mktime(substr(datetime, 1, 4)" "substr(datetime, 6, 2)" "substr(datetime, 9, 2)" "substr(datetime, 12, 2)" "substr(datetime, 15, 2)" "substr(datetime, 18, 2))
    return ts
}
function ts_format(ts) {
        dur_str = ""
        if (ts > 86400 ) {
                dur_str = dur_str int(ts/86400)"D"
                ts = ts - 86400 * int(ts/86400)
        }
        if (ts > 3600) {
                dur_str = dur_str int(ts/3600)"H"
                ts = ts - 3600 * int(ts/3600)
        }
        if (ts > 60) {
                dur_str = dur_str int(ts/60)"M"
                ts = ts - 60 * int(ts/60)
        }
        dur_str = dur_str ts"S"
        return dur_str
}
BEGIN {
        pc1_count = 0
        pc1_total_time = 0
        pc2_count = 0
        pc2_total_time = 0
        c2 = 0
        c2_total_time = 0
}
/seal_pre_commit_phase1:start/ {
    pc1_start_ts = strts($1);
    pc1_start_str = $1
}
/seal_pre_commit_phase1:finish/ {
    pc1_end_ts = strts($1)
    print $8"PC1\t"pc1_start_str"\t"$1"\t duration: "pc1_end_ts-pc1_start_ts" ("ts_format(pc1_end_ts-pc1_start_ts)")"
    pc1_count ++
    pc1_total_time += pc1_end_ts - pc1_start_ts
}
/seal_pre_commit_phase2:start/ {
    pc2_start_ts = strts($1);
    pc2_start_str = $1
}
/seal_pre_commit_phase2:finish/ {
    pc2_end_ts = strts($1)
    print "PC2\t"pc2_start_str"\t"$1"\t duration: "pc2_end_ts-pc2_start_ts" ("ts_format(pc2_end_ts-pc2_start_ts)")"
    pc2_count ++
    pc2_total_time += pc2_end_ts - pc2_start_ts
}
/seal_commit_phase2:start/ {
    c2_start_ts = strts($1);
    c2_start_str = $1
}
/seal_commit_phase2:finish/ {
    c2_end_ts = strts($1)
    print "C2\t"c2_start_str"\t"$1"\t duration: "c2_end_ts-c2_start_ts" ("ts_format(c2_end_ts-c2_start_ts)")"
    c2_count ++
    c2_total_time += c2_end_ts - c2_start_ts
}
END {
        if (pc1_count > 0)
                print "PC1 Sector Count: "pc1_count"\tTotal Time:" pc1_total_time"("ts_format(pc1_total_time)")\tAverage: "pc1_total_time/pc1_count"("ts_format(pc1_total_time/pc1_count)
        if (pc2_count > 0)
                print "PC2 Sector Count: "pc2_count"\tTotal Time:" pc2_total_time"("ts_format(pc2_total_time)")\tAverage: "pc2_total_time/pc2_count"("ts_format(pc2_total_time/pc2_count)
        if (c2_count > 0)
                print "C2 Sector Count: "c2_count"\tTotal Time:" c2_total_time"("ts_format(c2_total_time)")\tAverage: "c2_total_time/c2_count"("ts_format(c2_total_time/c2_count)
}