12月 052015
 

この記事はVarnish Cache Advent Calendar 2015の4日目の記事になります。

VCLには様々な変数の型がありまして、それぞれの型の間では暗黙的に変換されるものと、vmod_stdを使用して明示的に変換するものがあります。
型が結構多いのでいまいち何を使うか忘れることが多いので図にしてみました。
types
なお、ここでは特に変換にかかわらない型については取り上げていません(BLOB,ENUM,HTTP,PRIV_CALL,PRIV_VCL,PRIV_TASK,PRIV_TOP,PROBE,VOID)

ちなみに各型から暗黙的にSTRINGへ変換すると以下のようになります。

変換例
BYTES 2.000
DURATION 2.000
REAL 2.000
BOOL false
BACKEND default
INT 1
IP 192.168.1.1
TIME Fri, 04 Dec 2015 18:31:12 GMT
HEADER example.net

また、STRING_LISTですが基本的にはSTRINGと特に違いはないのですが、
これを引数として受け付ける関数の場合は型変換を意識しないとハマります。
例えばstd.logというログを出力する関数があるのですが、これは引数がSTRING_LISTです。
それを意識して以下のようなVCLを書くとエラーになります。


std.log(std.duration("10w",0s));


Command failed with error code 106
Message from VCC-compiler:
Wrong argument type.  Expected STRING_LIST.  Got DURATION.
('input' Line 31 Pos 31)
std.log(std.duration("10w",0s));
------------------------------#-
('input' Line 31 Pos 1) -- ('input' Line 31 Pos 30)
std.log(std.duration("10w",0s));
##############################--
Running VCC-compiler failed, exited with 2

これはdurationから一気にSTRING_LISTに暗黙的に変換できないからです。
そこでどうやるかというと、一度STRINGを経由させてあげればよいので


std.log("" + std.duration("10w",0s));

このように空文字を結合すると良いです。

まとめ
変数がどのように型変換が出きるかを知っておくと、その型では出来ない演算を変換した先でやって戻すみたいなことが出来ます。
覚えておくと結構便利なので、頭の片隅に置いておくと良いかなと思います。


12月 012015
 

この記事はVarnish Cache Advent Calendar 2015の1日目の記事になります。

何回か散発的に取り上げたことはあるのですがVSL-Queryの使い方についてまとまっては書いていなかったので書いてみます。
varnishlogのフォーマットの説明についてはv3の頃の記事ですがVarnishのログにアクセスしてみよう!を参考にしてください。

Varnishは他のミドルウェアでよくあるようにアクセスログをファイルに直接書き込むということはせずにリングバッファな共有メモリ(VSM)に出力します。
その際に出力されるログ(VSL)は非常に多岐に渡ります

  • ヘッダ(クライアントからのリクエストヘッダやバックエンドからのレスポンスヘッダなど)
  • ヘッダへの操作
  • どのアクション(vcl_recvなど)が呼ばれて何をリターン(hashなど)したか
  • std.logで出力した任意のログ
  • などなど

標準ではoffにされていますがonにすることでVCL中のどこのブロックを通過したかもトレースすることも可能です。
varnishncsaやvarnishlogなどの各種ツールはこのログを読んで出力します。
vsl
もちろんそのまま使うことも多いのですが、例えばエラーがでた・遅いリクエストだけを抽出したいということがあります。
その際に利用するのがVSL-Queryというもので、要はVSLに対して絞り込みを行う式を作成できます。


varnishncsa  -q "respstatus >= 400"

例えばこうすることでステータスコードが400以上のものを絞り込んで出力することができます。
今回はVSL-Query全般についての記事を書こうと思います。

VSL-Query

VSL-Queryは3つの要素からできています。

  • ログのグループ化
  • トランザクションの階層化
  • クエリ評価する
ログのグループ化

グループの種類は4種類あります。

raw
ログ1行を表します(何もグループ化されていない状態)
rawの場合はReqURLなどトランザクションに関わるデータとヘルスチェック等の非トランザクションデータの両方が含まれています。
ログを見た際にvxidが0のものは非トランザクションデータです。

vxid
複数行のログをHTTPトランザクション毎にグループ化します。
例えばクライアントからのトランザクションを処理する際にバックエンドまで問い合わせを行った場合は
クライアント<->VarnishとVarnish<->バックエンドの2トランザクションに分かれます。
なお、このデータにはraw時に含まれていたトランザクションにかかわらないデータ(ヘルスチェックなど)は含まれていません。
ちなみにvxidとはVarnish Transaction IDの略でトランザクションを識別するためのIDです。
X-Varnishヘッダで挿入される数値についてもそれです。

request
複数のHTTPトランザクションをまとめてリクエスト毎にします。
ESIやrestartを利用した場合はrequest内にrequestが含まれる事があります。
基本的にこの粒度で見ていればクライアント・Varnish・バックエンドでの流れがわかるので便利です。

session
複数のリクエストをまとめてセッション毎にします。
複数のリクエストが含まれるケースはkeep-aliveが有効な場合です。

grp
図にするとこんな感じです。

トランザクションの階層化

vsl-queryではログのグループ化を行うと同時に階層構造を作成します。
例えばVarnishからバックエンドへのトランザクションはその前にクライアントからVarnishへのトランザクションがあります。当然ですがそれは親子関係です。
トランザクション間の親子関係を作っているので、当然ながらログ一行ずつをグループとしているrawやトランザクション単体をグループとしているvxidでは階層化は行われません。
requestとsessionにおいて階層化が行われます。
実際に例で考えてみましょう。

グループ分けをrequestでVarnishがクライアントのリクエストを受付して、バックエンドに問い合わせして返却するケースでの階層は以下になります。


[Lv1] +ClientとVarnishのやりとり
[Lv2] | +VarnishとBackendのやり取り

次にグループ分けをsessionにしてそのセッションからのリクエストが2つあった場合は以下になります。


[Lv1] +セッション
[Lv2] | +ClientとVarnishのやりとり
[Lv3] | | +VarnishとBackendのやり取り
[Lv2] | +ClientとVarnishのやりとり
[Lv3] | | +VarnishとBackendのやり取り

実際のログだとどのように出力されるかというと(グループ分け=request)


*   << Request  >> 44645623
-   Begin          req 44645581 rxreq
-   Timestamp      Start: 1448894183.500204 0.000000 0.000000
-   Timestamp      Req: 1448894183.500204 0.000000 0.000000
-   ReqStart       ****** 47457
-   ReqMethod      GET
...
-   VCL_return     fetch
-   Link           bereq 44645624 pass
-   Timestamp      Fetch: 1448894183.708612 0.208408 0.208408
-   RespProtocol   HTTP/1.1
...
-   Timestamp      Resp: 1448894183.710162 0.209958 0.001442
-   ReqAcct        881 0 881 1994 7476 9470
-   End
**  << BeReq    >> 44645624
--  Begin          bereq 44645623 pass
--  Timestamp      Start: 1448894183.500314 0.000000 0.000000
--  BereqMethod    GET
-

こうなります。
なおレベルは1スタートとなります。

クエリ評価

グループとクエリの関係
何に対してクエリ評価を行うかというと、先ほどグループ化した中でqueryを評価して、一致するものがあればそのグループを出力します。
つまりグループがrawの場合は1行単位で評価するので


# varnishlog -graw -q "respstatus >= 400"
  61146578 RespStatus     c 404
  35190583 RespStatus     c 404
  52614757 RespStatus     c 404
  52656165 RespStatus     c 400

条件にひっかかる行だけが出力されます。

逆にsessionで評価した場合


# varnishlog -gsession -q "respstatus >= 400"
*   << Session  >> 60621569
-   Begin          sess 0 HTTP/1
-   SessOpen       ******* 62077 :80 ******* 80 1448897491.204370 99
-   Link           req 60621570 rxreq
-   Link           req 60621571 rxreq
-   VSL            store overflow
-   End            synth
**  << Request  >> 60621570
--  Begin          req 60621569 rxreq
...
--  RespStatus     200
--  RespReason     OK
...
--  End
**  << Request  >> 60621571
...
--  RespStatus     404
--  RespReason     Not Found
...

同一セッション内で404を返しているリクエストがあるためステータス200で返してるリクエストも引っかかってきています。
たとえば400以上のステータスコードを吐いてるリクエストのみを取得するのであればグループはrequest若しくはvxidが適切でしょう。
このようにグループ分けは狙ったログを出力する際には非常に重要です。

クエリの文法
クエリは次のように書きます。
[レコード] [演算子] [被演算子]
例: respstatus >= 400

レコードは次のように書きます。
{階層レベル}タグリスト:レコードのPrefix[フィールド]
これは全て指定する必要はなく、最低限タグだけを指定すればOKです。
フルで指定するとこのような指定になります
{2+}Timestamp:Resp[2]
1つずつ説明します。

階層レベル ( {2+}Timestamp:Resp[2] )
先ほど説明したトランザクションの階層化におけるレベルになります。
レベルは次のような指定の仕方があります。

指定方法/サンプル 説明
{2} Lv == 2
{2+} Lv >= 2
{2-} Lv <= 2

ちなみに{0+}も指定できます。この場合は全てのレベルと一致します

タグリスト ( {2+}Timestamp:Resp[2] )
タグの一覧はこちらになります
また、複数のタグを以下のように指定できます

指定方法 サンプル 説明
[tag],[tag] respheader,reqheader カンマ区切りでタグをを完全一致で指定します。
*[tag名の一部] *header 後方一致するタグを指定します。
[tag名の一部]* resp* 前方一致するタグを指定します。

[,]と[*]は同時に指定可能です。
また、[*]を途中で挿入することもできません。


#OKパタン
req*,resp*
#NGパタン
*eq*

レコードのPrefix ( {2+}Timestamp:Resp[2] )
データが「:」で区切られている場合はそれをキーとして使えます。
例えばTimestampでのイベントラベルやReqHeaderなどのヘッダ名に対して使用できます。
例:ReqHeader:User-Agent #リクエストヘッダのUser-Agentを指定

フィールド ( {2+}Timestamp:Resp[2] )
データがスペースで区切られている場合はそれを区切り文字として1スタートで指定できます。
例えばレスポンスが完了するまでにかかった時間を指定したい場合は以下のようにします。
例:Timestamp:Resp[2] #Timestamp:Respの第2フィールドを指定

演算子
演算子は以下のものが使用できます

タイプ 演算子
数値(int,float) == != < <= > >=
文字列 eq ne
正規表現 ~ !~

被演算子
以下が使用できます

タイプ サンプル
int 100
float 0. 0.8
string hoge
regex (iPad|iPhone)

なおregexはpcre(3)を利用しているので、例えば大小文字を無視する場合は以下のようにします


(?i)wget

文字列や正規表現は基本的に[‘]か[“]でquoteするのが良いかと思いますが、以下の文字のみで構成する場合はquoteは不要です


a-z A-Z 0-9 + - _ . *

論理演算子
先ほどの[レコード] [演算子] [被演算子]を一つの式として、論理演算子と組み合わせることで複数の条件を指定できます。
使用可能なのは以下です。

指定方法 説明
not [expr] exprが一致しない場合に真
[expr1] and [expr2] expr1と2が両方とも真の場合に真
[expr1] or [expr2] expr1か2のどちらかが真の場合に真

もちろん[expr1] and not [expr2]や[expr1] or not [expr2]の指定も可能です。

その他
他には以下の様な指定が可能です。

指定方法/サンプル 説明
respstatus タグ名だけを指定するとそのタグが存在する場合に真となる
(fetcherror ~’no backend’ and respstatus == 503) or respstatus == 400 ()を式中に含めることが可能です

実際のサンプル

自分がよく使うqueryの一部を紹介します

vcl_log:[key] ~ 任意の文字列
std.log(“key:文字列”)でデバッグ用の文字列を仕込んで、それでマッチさせます。
場合によっては数値を利用して比較演算子と組み合わせるのも便利です。

reqheader:Host ~ [ホスト名]
ホスト名を絞って表示したい場合

respstatus >=400
エラーを起こしたもの

最後に

これ書いてる時にバグっぽいのを見つけたので調べてバグならチケット切ってきます(その部分の記述は削りましたw)


10月 122015
 

Varnish4.1.0がリリースされました。
多くの新機能・改善・バグフィックスとほんの少しのVCLの変更があります。
特にバグフィックスを求めるユーザにとっては朗報です。
今までチケット上は修正されたけど各ブランチにマージされていなかったものが全て今回4.1ブランチにマージされたのでそれを求めるユーザにとっても更新するのも良いと思います。
割と大規模な変更があるので安定性について気になっている方もいると思いますが、4.1.0-beta1を2週間強ほど知り合いのサイト(ESI含む)に入れて運用しましたが
踏んだバグは一つ(#1792)で修正済みで安定して動いています。
また、CPUの使用率も下がっているようです。
ダウンロードはこちら

VCLの変更について
本家のアップデートガイドでも書いてある通り4.0.xのVCLをそのまま使用することが出来ます。
但しdeprecated的なのが増えているのとvmod_stdで引数の追加があるので注意が必要です。

HTTP/0.9のサポートを終了しました
むしろしていたのかという気持ちに・・

PROXY Protocol(v1/v2)のサポート
PROXY Protocol(v1/v2)をサポートしています。
使用する場合は起動オプションで以下のように指定します。(,PROXYを追加)


-a [IP Address]:[Port],PROXY

これに伴いremote.ip/local.ipが追加されました(後述)
接続してくる上位PROXYサーバのIPを制限したい時(ACL)に便利です。
またVarnishではhitchというPROXY Protocolを喋るTLS/SSLProxyを作っており(この前バージョンが1.0.0になった)
これと組み合わせるのを想定していると考えています。

VCLの自動cold/warm機能
Varnishはvclをreloadをした場合でも古いvclを保持しておいて後で使用することが出来ました。
この状態ではオリジンにヘルスチェックが飛んでしまい、それを防ぐには古いvclを削除するには明示的にdiscradをする必要がありました。
しかし4.1では使用されなくなったVCLは一定時間経過後(vcl_cooldown)にcold状態になりヘルスチェックが止まります。

セキュリティの強化(jails)
4.0.3


root     30262  0.0  4.2 124540 84320 ?        SLs  Oct05   0:43 /usr/sbin/varnishd ...
nobody   30264  0.1  4.2 582932 85724 ?        Sl   Oct05  15:19  \_ /usr/sbin/varnishd ...

4.1.0


varnish   1278  0.2  0.2 124768  5376 ?        Ss   16:32   0:00 /usr/sbin/varnishd ...
varnish   1280  1.7  5.8 1639192 117276 ?      Sl   16:32   0:00  \_ /usr/sbin/varnishd ...

今まではマスタープロセスはroot権限で動いていたのですが4.1からはセキュリティの強化のためになるだけ別ユーザで動くようにしました。
デフォルトではvarnishを使います。
もし任意のユーザ名を指定したい場合は起動オプションで-jオプションで指定可能です。

VMODでアクセスできる範囲の大幅な強化
これはどちらかと言うとVMODを作る人向けなのですが
以下のことが可能になっています

  • レスポンスボディに対するフィルタ機能(VFP/VDP)
  • バックエンドの動的生成
  • カスタムバックエンドの作成

まだすべて試しきれていないのですがどれも非常に強力です。
これは機会があれば別記事で取り上げようと思います。

動作変更

stale-while-revalidate(RFC5861)に対応しました
graceの初期値に使う感じです。

VCL変更/アクションのリターン値

vcl_hit
return(fetch)はreturn(miss)に変更する必要があります。
ただし4.1.0時点では変更を促すログを出しますがfetchはmissと同じように動作します
恐らく次の大型バージョンアップ時で消されるのではないかと思います。

vcl_backend_error
return(abandon)が追加されました。

vcl_init
return(fail)が追加されました。
文字通りfailを返すとvclの初期化に失敗します。

VCL変更/変数

remote.ip / local.ip (IP READ)
先程も述べたとおりPROXY Protocolに対応したため、それに伴いclient.ip/server.ipにPROXYサーバから渡された値が入ってくるようになりました。
(※ここで言うPROXYサーバはhaxproxyだったりAWSのELB等のPROXY Protocolを喋る上位サーバです。)
そのためclient.ipがVarnishに接続してきたIPアドレスを示すのではなくPROXYサーバがに接続してきたIPアドレスが入ってくる可能性が出てきました。
言葉で説明するよりマトリックスで示したほうが分かりやすいので以下に示します。


Direct
[client(192.168.1.200)]
   ↓
[Varnish(192.168.1.100:6081)]

Proxy Protocol
[client(192.168.1.200)]
   ↓
[HAProxy(192.168.1.10:8080)]
   ↓
[Varnish(192.168.1.100:6086)]

Description Direct PROXY Protcol
remote.ip ローカル(Varnish)に接続してきたIPアドレス 192.168.1.200(Client) 192.168.1.10(HAProxy)
client.ip クライアントのIPアドレス 192.168.1.200(Client) 192.168.1.200(Client)
local.ip ローカル(Varnish)のIPアドレス 192.168.1.100:6081(Varnish) 192.168.1.100:6086(Varnish)
server.ip クライアントのコネクションを受けたIPアドレス 192.168.1.100:6081(Varnish) 192.168.1.10:8080(HAProxy)

req_top.* (READ)
トップリクエストのreq.*を参照します、書き込みは出来ません。
何に使えるかというとESIの時に親(top)のreq.urlを知りたいといった時です。
取得できるのはあくまでもリクエストに関わるものなので例えばreq_top.backend_hintみたいなものはありません。
使用できるのは以下です。
req_top.method
req_top.url
req_top.http.*
req_top.proto

beresp.was_304 (BOOL READ)
文字通りbackendから304(Not Modified)が返却され、既に取得しているオブジェクトのリフレッシュに成功した場合にtrueになります。

beresp.age / obj.age (DURATION READ)
オブジェクトが生成されてからの経過時間(Age)を返却します。

beresp.backend (BACKEND READ)
fetchに利用したバックエンドを返却します。
例えばバックエンド名を取得したい場合はberesp.backend.nameとします。

resp.is_streaming (BOOL READ)
ストリーミングされている場合にtrueになります。

パラメータの変更

変更されたもの
workspace_session
4.0.3: 384byte
4.1.0: 512byte

vsl_mask
4.0.3: -VCL_trace,-WorkThread,-Hash
4.1.0: -VCL_trace,-WorkThread,-Hash,-VfpAcct
※VfpAcctは4.1.0で追加されたログ項目

削除されたもの
group
group_cc
listen_address
user
pool_vbc
timeout_req
timeout_idleと統一

追加されたもの
vcl_cooldown
VCLがcold状態に遷移するまでの時間

vmod_std

real2integerが追加されました。
型変換関数でfallbackがなかったものにfallbackが追加されました(time2integer / time2real / real2time)

varnishstat

-wがなくなりました

varnishhist / log / ncsa / top

-tオプションが追加されました(VSMを開く際のタイムアウト設定)

その他

vmodを追加しました
追加したといってもデフォルトで入っているわけではなく別reposです
libvmod_saintmode
Varnish3.0系であったsaintmodeです

libvmod_xkey
セカンダリハッシュを作成します。主にパージに利用し高速に動作します。
恐らくですがVarnishPlusで提供されていたhash-ninjaと同等のものと考えています。

libvmod-rtstatus
varnishstatと同等のデータを出力します

リンク

https://www.varnish-cache.org/docs/trunk/whats-new/changes.html
https://github.com/varnish/Varnish-Cache/blob/4.1/doc/changes.rst