2020年におけるmackerel-plugin-jsonの使い方

この記事は Mackerel Advent Calendar 2020 2日目の記事です。

はじめに

皆さんはmackerel-plugin-jsonを使っていますか？

個人的にはかなり好きなプラグインなのですが、2017年に書かれたMackerel プラグインアドベントカレンダー以外ではあまり解説されていませんでした。

soudai.hatenablog.com

この記事よりも後に追加された機能を紹介している記事も見当たらなかったので、今回はそれらに絞って紹介していきます。

前回実行したときの結果との差分を投稿する-diffオプション

-diff オプションの後に正規表現を書くと、その正規表現にマッチしたメトリックに対して前回の実行時からの差分をMackerelに投稿することができます。

アプリケーション内に単調増加するカウンターとその値をJSONで返すエンドポイントを実装しておくことでプラグイン側が差分を計算し、例えば1分間でのリクエスト数などそれだけで簡単に取得できるようになります。

GoのアプリケーションであればカウンターとJSONで返すエンドポイントの実装を公式のexpvarパッケージを使うことで簡単に実現することができます。

このように書くことでアプリケーション側(今回はapp)で記録していたカウンターをJSONで返すことができます。

func Handler(w http.ResponseWriter, r *http.Request) {
    w.Header().Set("Content-Type", "application/json")
    fmt.Fprintln(w, expvar.Get("app"))
}

今まではこういった差分を送信したい場合はアプリケーション側で差分管理をきちんと実装してあげる必要がありましたが、プラグイン側で差分を計算するようになったためにそういった必要はなくなりました。

特にステータスコードでは表現しにくいアプリケーション固有のメトリックはログに書いてそれを集計するという方法が一般的だと思いますが、ログはディスクの容量や配送経路などいくつか考える必要が出てくるため準備も少し大変でした。

そういった場合でログから集計する方法を取りづらい場合にも役に立つと思います。

上のブログでもこうしたカウンター値にする機能がないことが欠点として書かれていましたが、その欠点をほぼ解決する機能になっていると思います。

ただし注意点としてmackerel-plugin-jsonはそのままの値をグラフしますのでカウンタ－値に自分で変換したい場合はやはりpluginにする必要があります。

エンドポイントの監視 ~ mackerel-plugin-jsonを読み解く - そーだいなるらくがき帳

このオプションは2018/12/13にリリースされた v1.1.0 以降で使えます。

HTTP リクエストヘッダを指定できる-headerオプション

外形監視や check-http のプラグインと同様に-header オプションを指定することでHTTP リクエストヘッダを設定できるようになりました。

-header オプションは -header=User-Agent:mackerel-http-checker/0.0.1 -header=Cache-Control:no-cache のように複数指定することもできます。

このオプションの使い道の一つに、インターネット上から監視用のエンドポイントにmackerel-plugin-jsonでリクエストしたい場合があります。

今までは一般にアクセスをさせないようにするにはIPアドレスで制限するといったことが多かったと思います。

それがこのオプションによって、リクエストヘッダベースの制限も掛けやすくなると思います。

ではどんな時に良いでしょうか？ 1つ目は直接自分の管理下に置いていないServer、つまりはレンタルサーバーなどです。 この場合はmackerel-agentのインストールが難しく、監視対象側から定期的にMackerelのAPIを叩くことが難しいでしょう。 そんな場合はモニタリング用のエンドポイントを作成してそこをmackerel-plugin-json経由で監視すればいいのです。

エンドポイントの監視 ~ mackerel-plugin-jsonを読み解く - そーだいなるらくがき帳

このオプションは2020/11/26にリリースされた v1.2.0 以降で使えます。

インストールの手間が改善されている

2017年の記事の当時では自分でビルドしてホストに配布する必要がありました。

mackerel-plugin-jsonのインストールですがmackerel-plugin-jsonは公式パッケージに同梱されていません。 そのため自分でbuildする必要があります。

エンドポイントの監視 ~ mackerel-plugin-jsonを読み解く - そーだいなるらくがき帳

しかし、現在はmkr plugin install mackerel-plugin-json というコマンドを実行するだけでインストールができるようになっているため、簡単に使い始めることができます。

また、2019/7以降にはmackerel-container-agentのプラグイン同梱版のイメージ(mackerel/mackerel-container-agent:plugins)にはデフォルトで同梱されるようになっています。

mackerel-plugin-json は公式プラグインとしては同梱されてはいないのですが、今回 mackerel-container-agent の同梱プラグインとして追加いたしました。

mackerel-container-agent のアップデートを行いました - Mackerel ブログ #mackerelio

おわりに

アプリケーション側で監視用のエンドポイントを持つというのはここ最近かなり一般的になってきたように感じます。

その際に今のmackerel-plugin-jsonでできることを知ることで、そういったエンドポイントをより良く活用できるようになるのではと思っています。

mrubyを触ってみた

最近ngx_mrubyを触っていて、RubyのTime#httpdateを使いたかったもののmrubyにはないということがあった。

そもそもmruby自体にも全然慣れていないという課題もあったので、このメソッドを実装することを目標にライブラリを作りながらmrubyに慣れるということをやってみた。

mrubyをビルドする

ビルド手順は非常に簡単で、mrubyのリポジトリをcloneしてmakeするだけで良い。

git clone https://github.com/mruby/mruby.git
cd mruby
make

bin/ ディレクトリ以下にいくつか実行ファイルが作られて試すことが出来て、irbのmruby版であるmirbというものも使うことが出来る。

~/c/s/g/m/mruby ❯❯❯ bin/mirb
mirb - Embeddable Interactive Ruby Shell

> p Time.now
2020-10-20 22:30:13 +0900
 => 2020-10-20 22:30:13 +0900
>

ライブラリの作り方

これで最低限mrubyを使う準備はできたので、次はライブラリを作っていく。

mrubyのライブラリはmrbgem(mgem)と呼ばれており、 mrbgem.rake や mrblib/ など決まったファイル・ディレクトリ構造に従ってファイルを作成していくというものになっている。

~/c/s/g/c/mruby-time-library ❯❯❯ tree
.
├── LICENSE
├── README.md
├── mrbgem.rake
├── mrblib
│   └── mrb_time_library.rb
└── test
    └── mrb_time_library.rb

2 directories, 5 files

実装がある程度できたら動くかどうかテストをする準備をしていく。

テストの実行は少し特殊で、ライブラリのリポジトリではなくmrubyのリポジトリに以下のような build_config.rb というファイルを作成する。 conf.gemには作成しているライブラリのパスを指定する。

MRuby::Build.new do |conf|
  toolchain :gcc
  conf.gembox 'default'
  conf.gem '../mruby-time-library'
  conf.enable_test
end

そしてmrubyのリポジトリで rake test を実行することでライブラリのテストを走らせることが出来る。

そうすれば「ライブラリの実装とテストを修正し続けて rake test を実行する」というサイクルで開発をすすめることができる。

GitHub ActionsでCIする

手元環境の準備が整ったので、今度はリポジトリ上でCIできるようにする。

mrubyのライブラリはTravis CIを使っていることも多いけれど、せっかくなのでGitHub Actionsでやれるようにした。

CIでやる場合もmrubyのリポジトリでbuild_config.rbを使って指定するというのは変わらずだけど、手元のパスではなくGitHub上のリポジトリとブランチを指定するのでそこを工夫して書き換える必要がある。

ただし、ActionsのトリガーではブランチへのコミットとPRとでは作業ブランチの取得方法が微妙に異なるのでビルド前にいい感じにブランチ名を取っておくというのも必要。

      - name: get branch name
        if: github.event_name != 'pull_request'
        run: echo "BRANCH_NAME=$(echo ${GITHUB_REF#refs/heads/})" >> $GITHUB_ENV
      - name: get pull request branch name
        if: github.event_name == 'pull_request'
        run: echo "BRANCH_NAME=$(echo $GITHUB_HEAD_REF)" >> $GITHUB_ENV

この BRANCH_NAME を使ってbuild_config.rbを作ってrake testをしてやれば良い。

      - name: Rake test
        env:
          TEMPLATE: |
            MRuby::Build.new do |conf|
              toolchain :gcc
              enable_debug
              conf.enable_bintest
              conf.enable_test
              conf.gembox 'default'
              conf.gem :github => '${{ github.repository }}', :branch => '${BRANCH_NAME}'
            end
        run: |
          printf "${TEMPLATE}" > build_config.rb
          cd mruby
          env MRUBY_CONFIG=../build_config.rb rake test

そうして完成したワークフローは以下。

https://github.com/cohalz/mruby-time-library/blob/master/.github/workflows/test.yml

ライブラリを作った

以上で、httpdateを含むtimeライブラリの特定のフォーマットの文字列にするメソッド(インスタンスメソッド)を使えるようにするライブラリを作成できた。

github.com

~/c/s/g/m/mruby ❯❯❯ bin/mirb
mirb - Embeddable Interactive Ruby Shell

> Time.now.httpdate
 => "Tue, 20 Oct 2020 14:44:03 GMT"
>

文字列をパースするメソッドに関しては、mrubyにはデフォルトでは正規表現が使えないというのもあり実装を後回しにしているけど、既に欲しくなってきたので近いうちに作りたい。

mackerel-plugin-axslogを使ってみた

Mackerel

Mackerelでアクセスログを集計したいときに、普段は公式プラグインであるmackerel-plugin-accesslogを使っていた。

そんな中ふと下のエントリーを思い出し、高速であるという点も気になるし、いくつかオプションも異なるということで試しに使ってみることにした。

kazeburo.hatenablog.com

mkr plugin installをすることでインストールできる。*1

mkr plugin install --upgrade kazeburo/mackerel-plugin-axslog@v0.2.1

インストールされたのを見たら、あとは必要なオプションをいくつか入れることですぐ使い始められる。

(mackerel-plugin-accesslogとオプション名が結構異なっているので注意)

[plugin.metrics.axslog]
command = '/opt/mackerel-agent/plugins/bin/mackerel-plugin-axslog --key-prefix=all --format=ltsv --status-key=status --ptime-key=reqtime --logfile=/var/log/nginx/access_log'

これだけで準備完了であとは待っていたらmackerel-plugin-accesslogに似たようなメトリックが表示されるようになる。

アクセス数の数字について

実際にアクセスしてメトリックを確認したところ、このようにアクセス数の数字が小数点以下の数字になった。

f:id:cohalz:20200628002338p:plain

当然1分間に0.0833回アクセスしたわけではないので、どういう実装になっているか見てみたところこのようになっていた。

fmt.Printf("axslog.access_num_%s.2xx_count\t%f\t%d\n", keyPrefix, s.c2xx/s.duration, now)

https://github.com/kazeburo/mackerel-plugin-axslog/blob/v0.2.1/axslog/axslog.go#L200-L206

カウント(s.c2xx)を期間(s.duration)で割っているということがわかる。

計測された数を期間で割っているのでつまりは「平均して1秒あたりにどのくらいのリクエストが来たか」というメトリックになっているということがわかった。 *2

何故こうなっているのか不思議だったけど、おそらく「プラグインの実行が何らかの形で失敗した場合、集計されるべきだった分が次回に加算されてしまい数字が大きく出てしまう」ということを回避するための仕組みなんだろうと思った。*3

一度プラグインの実行に失敗して次回1分後の集計の範囲が倍になったとしても、カウント数も期間も等しく倍になっているためメトリックとしては大きく変わることはないということになる。

このようにメトリック投稿を復帰させたあとのグラフに悪影響を及ぼさない上にメトリック自体も集計タイミングに依存しない、という感じでわかってしまえばなかなか合理的なメトリックになっているということがわかった。

filterについて

Usageにある通り、mackerel-plugin-axslogにはfilterオプションが存在する。

--filter= text for filtering log

このfilterの使い方についても調べてみた。

使い方

コードを見たところ、JSON/LTSVの文字列をパースする直前にbytes.Indexでマッチしているのか見ているようだった。

if len(filter) > 0 {
    if bytes.Index(b, filter) < 0 {
        continue
    }
}
c, pt, st := r.Parse(b)

https://github.com/kazeburo/mackerel-plugin-axslog/blob/v0.2.1/main.go#L50-L55

パースした結果を見るわけではないので、例えばLTSV形式のログでフィルタを使いたい場合は --filter="method:POST" のようにkey:valueの形式で指定するという使い方になる。

使い所

そしてこのフィルタ機能がmackerel-plugin-axslogを選ぶ大きな利点になっていると個人的に思っている。

というのもmackerel-plugin-accesslogではログからすべてのレイテンシとステータスコードを集計するため、ログに傾向の違うリクエストが混ざっている場合に実感とは異なるメトリックの傾向になるということがよくあった。(99パーセンタイル値だけが高い値を示しているなど)

そういう場合に、このフィルタ機能を使うことで重要なエンドポイントに絞ったレイテンシやステータスコードの集計ができるようになりそう。

そしてプラグインは複数実行できるので、confにフィルタを別にしたプラグインを複数書くことでフィルタしたメトリックをいくつも出すことができる。

ただし、並列で何回も同じアクセスログを読み直すので効率は悪く負荷が増え、メトリック数もその分増えるのでその点は考慮して工夫する必要がある。

例えば、本当に重要な条件のみに絞ったり、ログの形式をフィルタに合わせた形に変たりなどして複数実行の数を減らすとか、無理が出たらmackerel-plugin-axslogじゃなくてちゃんとログ集計基盤を作るとかになるとは思う。

とはいえアクセスログから1つ2つ重要な部分のみに絞った集計を少ない手間で可視化できるというのは相当に便利だとは思う。

まとめ

mackerel-plugin-axslogは後発のプラグインということもあり、フィルタのようなmackerel-plugin-accesslogにはない機能もある、ということでかなり面白いプラグインということがわかった。

*1:mkr plugin installでプラグインをインストールする - Mackerel ヘルプ

*2:試しに期間を正確に1分と仮定すると0.0833 * 60 = 4.998となり確かにほぼ整数に近い値になった。

*3:fluent-plugin-mackerelを使ってMackerelにメトリックを投稿する際にも、途中のログ配送が詰まると復旧後に加算されてしまうという現象が起こる。

Varnishでレスポンスをカスタマイズする方法

表題の方法を実現したくなって、調べたところ実現する方法が結構面白かったのでメモ。

例えば以下のような「キャッシュ破棄リクエストを受け付けて200を返す」というVCLがあったとする。

sub vcl_recv {
    if (req.method == "BAN") {
        ban("req.http.host == " + req.http.host + " && req.url == " + req.url);

        return(synth(200, "Ban added"));
    }
}

この状態で curl -XBAN localhost:6081 を実行してみると、レスポンスは以下のように Ban added だけではなく他のHTMLタグや諸々が含まれて返ってくる。

<!DOCTYPE html>
<html>
  <head>
    <title>200 Ban added</title>
  </head>
  <body>
    <h1>Error 200 Ban added</h1>
    <p>Ban added</p>
    <h3>Guru Meditation:</h3>
    <p>XID: 196749</p>
    <hr>
    <p>Varnish cache server</p>
  </body>
</html>

そしてこのレスポンスをもし Ban added だけにしたい場合にどのようにするとよいかという話。

結論としては、この状態から以下のように vcl_synth を変更することで実現できる。

sub vcl_synth {
    if (req.method == "BAN") {

        synthetic(resp.reason);

        # これも上と同等の処理
        # set resp.body = resp.reason;

        return (deliver);
    }
}

結構不思議な感じだけど、これで何故動くのかを説明していく。

まず synthetic 関数について、公式ドキュメントには以下のように説明されており、レスポンスをセットする関数になっている。

synthetic(STRING) Prepare a synthetic response body containing the STRING. Available in vcl_synth and vcl_backend_error. Identical to set resp.body / set beresp.body.

https://varnish-cache.org/docs/6.0/reference/vcl.html#synthetic-string

そして resp.reason について。

return synthした際の2つの引数は resp.status , resp.reason にそれぞれセットされる。*1

今回はそのうちの resp.reason を使って参照し、レスポンスを Ban added だけに書き換えることができたという理由になる。

ちなみに注意事項として、synthetic を呼ぶ際は vcl_recv でreturnしたときと同じ条件で囲わないとBANメソッド以外の場合にもレスポンスが書き換わってしまうというのがあるため、もし元々のHTMLも返したい場合には気をつける必要がある。

これを応用してこのような固定のレスポンスを返すだけではなく、例えばリクエストの User-Agent をレスポンスとして返すみたいなことも以下のようにして実現できる。

return(synth(200, req.http.User-Agent));

もちろんVarnishはキャッシュサーバなので複雑なレスポンスを組み立てて返すというのは向いていないけれど、例えばキャッシュ破棄のようなロジックを入れる際にレスポンスを少しカスタマイズする事はあると思う。

例えばvmod_xkey*2を使ってタグベースのキャッシュを行った際に、キャッシュ破棄できた数を返すことで「複数のVarnishサーバで合計でどのくらいキャッシュ破棄できたのか」の集計がしやすくなるなどがありそう。

*1:builtinのvcl_synthで使われている https://github.com/varnishcache/varnish-cache/blob/varnish-6.0.6/bin/varnishd/builtin.vcl#L129

*2:https://github.com/varnish/varnish-modules/blob/6.0-lts/docs/vmod_xkey.rst

同じ場所に旅行をする、ということ

何かの用事で過去に行ったことがある場所にまた旅行しに行く、というのをよくやっている。

特に学生時代の修学旅行や留学、家族旅行で行った場所を行くようにしている。

同じ場所に旅行をするモチベーション

いい場所だったからまた行きたい、というのもあるけれど、個人的には下の3つの理由で行くことが多い。

  • 当時は行けなかったところにリベンジできる
  • 当時と変わっているところ・変わっていないところなど時間の経過を感じられることがある
  • 思わぬ再会があったりする

同じ場所に旅行をするようになったきっかけ

そもそも大学入った頃にお金がないというのもあり、旅行に行くという習慣がなかった。

夏休みでどこか行ってみようと思ったものの、どこに行こうか良いのが思いつかなかった。

そこで小さい頃によく行っていた・実家から日帰りで帰れるというお手頃な点から、養老天命反転地に行ったのが初めてだったと思う。

www.yoro-park.com

ここから、過去に行ったところにまた行くのは面白いんじゃないかと思うようになり、奈良や広島など修学旅行で行ったところにまた行くということをするようになった。

それから色んな場所に行く機会があり、最後に行ってから時間の経った場所というのも増えてきた。

時間の経過を感じる: 石巻の例

2015年6月に初めて石巻に行き、街の復興の様子を見るということがあった。

「今どうなってるかな」と気になって、2017年3月にまた行くことができた。

当時と変わらない風景もあれば、復興が進んで知らない風景もあり、2015年には知らなかった海鮮のお店も知ることができた。

この店は行った当時は仮店舗だったが、去年に震災前の場所に店を開くことができたらしく、また風景が変わっているので楽しみになっている。

www.tomofukumaru.co.jp

思わぬ再開: 台湾の例

2019年の10月に台湾(桃園)に行った。

過去に2016年に短期留学をしていたが、その場所が近かったというのもあり当時住んでいたあたりを歩き回るなどしていた。

そしてそこには当時交流のあったIngressプレイヤーがまだおり、自分の名前を見てすぐにゲーム内のチャットで話しかけてもらった。

3年も経って名前を覚えてもらっていたのも嬉しいし、まさか再開できるとも思っていなかったので本当にまた行けてよかったなと思った瞬間だった。

終わり

新しい場所に行くというのも面白いけれど、長らく行ってない場所にまた旅行をするというのもどうでしょうか。

__twitter_impression=true というクエリ文字列を含むリクエストは204を返すのが望ましい

AMP

__twitter_impression=true というクエリ文字列を見かけて、これはどういうものか調べたメモ。

これは名前の通りにTwitterが付与しているクエリ文字列で、Publish faster articles with AMPには以下のように書かれている。

When users are presented with the optimized AMP version of your page, Twitter instructs the AMP runtime to also ping your original article URL. This allows your analytics software to record a visit as if the original article were viewed.

For these ping requests, Twitter appends an additional query parameter to your URL — __twitter_impression=true — which you can use to distinguish these AMP views from organic traffic. (For example, to understand the impact of AMP on your audience, or filter these impressions if you already instrument AMP elsewhere.)

要約すると、以下のことが書いてある。

  • TwitterからAMP版ページに遷移する際、AMP版のページを表示するとともに非AMP版のページにもリクエストを飛ばす(pingと呼んでいる)
    • (pingと呼んでいるものの、アクセスログを見たところ普通に GET リクエストであることがわかった)
  • そのpingリクエストには区別のため、 _twitter_impression=true というパラメータが付く

そしてこのクエリ文字列の扱いに関しても書いてある。

When receiving a request for an article including the __twitter_impression=true parameter, you should return an HTTP 204 response, with no response body. While a regular HTTP 200 response is valid, it is wasteful. You can improve performance and save your and your user's bandwidth by omitting it, the response body will be ignored by Twitter and the AMP runtime.

そのパラメータが付いたリクエストに関しては中身を見ないので、単に204を返すことによりパフォーマンスの向上(レスポンスの高速化？)やユーザの帯域を節約できるということらしい。

nginxであれば、以下のように $arg_name *1を使うことで実現できる。アンダースコアが3つ並んでいるのは変に見えるけどちゃんと動く。

if ($arg___twitter_impression = "true") {
    return 204;
}

*1:http://nginx.org/en/docs/http/ngx_http_core_module.html#variables