tail -Fなどの標準出力を一定時間ごとに指定のコマンドに渡し、その実行結果をシーケンシャルに出力するコマンド evry を作った

ログの流量やサマリを、カジュアルに、そしてリアルタイムに確認したかったので作ってみました。

github.com

これはなに

標準入力の内容を、一定時間ごと(もしくは一定行ごと)にまとめて指定のコマンドに渡し、その実行結果をシーケンシャルに出力するコマンドです。

使い方

例えば、「NGINXの10秒あたりのリクエスト数を確認する」には、以下のように evry で10秒ごとにまとめた標準入力を wc -l に渡します。

$ tail -F /var/log/nginx/access.log | evry -s 10 -c 'wc -l'
    8700
    1260
    8580
    6430
    [...]

例えば、「Apacheの1000リクエストあたりのアクセス先ランキング上位5を確認する」には、以下のように書けます(GNU sedを使用)。

$ tail -F /var/log/httpd/access.log | evry -l 1000 -c 'cut -d" " -f7 | sort | uniq -c | sort -nr | head -5 | sed "0,/^/ s/^/---\\n/g"'
---
  90 /category/electronics
  65 /category/software
  55 /category/games
  45 /category/books
  27 /category/computers
---
 108 /category/electronics
  76 /category/software
  63 /category/games
  44 /category/books
  31 /category/computers
---
  97 /category/electronics
  55 /category/games
  52 /category/software
  48 /category/books
  35 /category/office
---
  99 /category/electronics
  55 /category/software
  53 /category/games
  [...]

他のコマンドを使ったり組み合わせた書き方はあるかと思うのですが、直感的に書ける のが良いと思っています。

インストール

go get か Homebrewでインストールできます。

$ go get github.com/k1LoW/evry
$ brew install k1LoW/tap/evry

シーケンシャルに入力を受け取り、パラレルに実行し、シーケンシャルに出力する

evry を実装するにあたって実現したかったのが、

  1. 標準入力はリアルタイムに受け取って処理したい
  2. 出力は1の標準入力から受け取った順に出力したい(そのほうが 直感的 だと考えているから)

ということです。そのために、

  • 標準入力からの値を、都度 -c のコマンドに渡して、コマンド自体はそれぞれ並行に実行することによって、時間のかかるコマンドでもできるかぎり処理をブロックしないようにする
  • 並列に実行しているコマンドの実行時間によって出力順番が変わらないようにする

という挙動を実装しました。

具体的には図のように

f:id:k1LoW:20190114200758p:plain
evryの処理の流れ

  1. 標準入力から流れてくる値を一定時間もしくは一定行にまとめる(緑)
  2. 「入力の順番」を記憶する(オレンジ左)。
  3. 指定コマンドの標準入力に1でまとめた値を渡して、それぞれ並行に実行させる(青)。
  4. 実行結果の出力は記憶している「入力の順番」に出力する(オレンジ右)

という動きをします。

上記の evry の動きの例としては、以下のコマンドを実行するとわかりやすいかと思います。

$ echo "3\n5\n2" | evry -l 1 -c 'xargs -I@ sh -c "sleep @; echo @"'

コマンドは、352 をそれぞれ xargs -I@ sh -c "sleep @; echo @" に渡してその実行結果を出力する(@秒sleepしてecho @するだけ)というものです。

指定コマンドに sleep が入っているので、それぞれ3秒、5秒、2秒待つような挙動をします。

上記を実行すると、約3秒後に3が、その約2秒に 52 が一気に出力されます。

time を挟むとわかりやすいです。

$ time echo "3\n5\n2" | evry -l 1 -c 'xargs -I@ sh -c "sleep @; echo @"'
3
5
2
echo "3\n5\n2"  0.00s user 0.00s system 38% cpu 0.001 total
evry -l 1 -c 'xargs -I@ sh -c "sleep @; echo @"'  0.01s user 0.02s system 0% cpu 5.019 total

実行時間が(10秒ではなく)約5秒になっている ことがわかります。

実行時間からわかるように、'xargs -I@ sh -c "sleep @; echo @"' を並列に実行しています。

かつ、その出力順は、それぞれの実行時間(3秒、5秒、2秒)に関わらず352と元の標準入力の順を保っています。

Goの並行処理は自分にはまだ難しいけれどうまくハマると面白い

今回、evry で実現したかった「シーケンシャル->パラレル->シーケンシャル」を自分なりに sync.Mutexsync.WaitGroup とチャンネルを組み合わせて実装できました。面白かったです。

うんうん唸って設計して実装しただけに、意図したとおりに動いたときはテンションが上りました。Goで並行処理を実装する良いお題だったのかもしれません。

そして、もう少し並行処理を実装する感覚に慣れていく必要がありそうです。

今は、答え合わせの意味も含めて「Go言語による並行処理」を読み進めています。

読んでいて、全く思いついたことのないパターンに「なるほど」と思ったり、実装したことのあるパターンがすっきりと整理されていたり、とても勉強になります。「Go言語による並行処理」で学んだ内容をもとに evry の実装をもっと良くできそうな気がします。

Go言語による並行処理

Go言語による並行処理