4 of 72

Varnish4.0での変更点

オフィシャルで触れているもの

クライアント/バックエンドの通信スレッドを分離

ストリームのフルサポート
バックグラウンドでのfetch対応(grace時の動作変更)

VSLの強化

VSL Query Expressions
VSLのグルーピング

VCLの変更
起動パラメータの変更
セキュリティ対策(inline-Cデフォルト無効化など）

オフィシャルで触れていないものをいくつか

5 of 72

Client/Backendのスレッド分離

6 of 72

clientとbackendのスレッド分離

Varnish4での一番大きい変更はこれ

言葉にすると単純だけどVarnishのコードがかなりリファクタリングされている

V3まではclient・backendのやりとりを同一のスレッドで処理する
V4ではclient・backendを別々のスレッドで処理する

※但しlimitに達している場合は同一スレッドが使われる
※pipe時は同一スレッドが使われる

分離することで1リクエストで同時にフェッチすることや通信中のバックエンドを複数クライアントで共有するのも楽に

今回は対応していないけどパラレルフェッチESIなども・・・（公式で言及してる）

7 of 72

ストリームのフルサポート

V3まではバックエンドと通信しているスレッドでしかストリームができなかった

つまり最初にリクエストしたクライアントのみが対象

V4では特にその制限がなくなった

10 of 72

バックグラウンドでのfetch対応(grace)

V3まではクライアントとバックエンドのスレッドが同じだったため�最初にアクセスしてきたクライアントがバックエンドにフェッチする必要があった
V4でその制限がなくなった

13 of 72

VSL Query Expressions

14 of 72

VSL Query Expressions

非常に強力なログのフィルタリング機能
すごく簡単にいうとこんな絞り込みが出来る

1秒以上かかった若しくはエラー出したもの
ESIのサブリクエストで1秒以上かかったもの

2つの機能で構成されている

VSLのグルーピング

リクエスト・1行毎などの単位（後述）

グルーピングされたログに対してのフィルタリングクエリ

15 of 72

VSLのグルーピング

varnishの生ログ(VSL)は非常に強力

どのアクションを呼んだかなど通常のMWのデバッグレベルの情報
VSLを整形することで各コマンドの出力としている(varnishncsaなど）

しかし情報過多で人類には早過ぎる

というかグルーピングされていないのが辛い

なので普通は整形されたコマンドを使う

■Version3ログ例

13 RxHeader b Content-Length: 20

13 RxHeader b Connection: close

13 RxHeader b Content-Type: text/html; charset=UTF-8

13 Fetch_Body b 4(length) cls 0 mklen 1

13 Length b 20

13 BackendClose b default

11 SessionOpen c 192.168.1.199 35936 :80

11 ReqStart c 192.168.1.199 35936 549986251

11 RxRequest c GET

11 RxURL c /date.php

11 RxProtocol c HTTP/1.0

11 RxHeader c User-Agent: Wget/1.12 (linux-gnu)

11 RxHeader c Accept: */*

11 RxHeader c Host: 192.168.1.44

11 RxHeader c Connection: Keep-Alive

11 VCL_call c recv lookup

16 of 72

VSLのグルーピング

Varnish4ではvarnishlogでも分かりやすいグルーピングが出来るようになった

varnishlog -g <session|request|vxid|raw>

種類は4種類

session
request
vxid
raw

17 of 72

各グループの関係性

18 of 72

session

セッション単位でrequestをグルーピングする
1セッションで複数のRequestがある場合は複数出力（keep-alive）
ログのprefixの[*]や[-]の個数はlevelを表す(raw以外のタイプで共通)

深くなると[-4-]といった表示になる

* << Session >> 65539

- Begin 　　sess 0 HTTP/1

- SessOpen 192.168.1.199 60878 :80 192.168.1.45 80 1398350189.793820 12

- Link 　　　req 65540 rxreq

- SessClose RESP_CLOSE 0.013

- End

** << Request >> 65540

-- Begin 　　req 65539 rxreq

lv=1

lv=2

lv=1

lv=2

19 of 72

request

1つのHTTPのリクエストに関わるトランザクション(vxid)をグルーピングする
このグループタイプは論理的なもので特有の情報を持っているわけではない

トランザクションをまとめるためにある

* << Request >> 2

- Begin req 1 rxreq

- Timestamp Start: 1398350630.794942 0.000000 0.000000

- Timestamp Req: 1398350630.794942 0.000000 0.000000

…

** << BeReq >> 3

-- Begin bereq 2 fetch

-- Timestamp Start: 1398350630.795294 0.000000 0.000000

-- BereqMethod GET

lv=1

lv=2

lv=1

lv=2

20 of 72

vxid

1つのトランザクション(vxid)をグルーピングする
あくまで1つのトランザクションのみなのでbereqなどの派生したトランザクションは別のものと扱われる

全てlv1となる

* << BeReq >> 3

- Begin bereq 2 fetch

- Timestamp Start: 1398350650.914294 0.000000 0.000000

- BereqMethod GET

- BereqURL /es1.html

* << BeReq >> 5

- Begin bereq 4 fetch

- Timestamp Start: 1398350650.917951 0.000000 0.000000

lv=1

21 of 72

raw

生ログ表示

Version3の時と同じフォーマット

但しタグ名はだいぶ変わっている

トランザクションに関わるデータとそうでないデータが含まれる

vxid > 0はトランザクションに関わるデータ
vxid==0はトランザクションに関わらないデータ

ヘルスチェックやexpireイベントのログなど

0 CLI - Rd ping

0 CLI - Wr 200 19 PONG 1398308779 1.0

3 Begin b bereq 2 fetch

3 Timestamp b Start: 1398308778.129624 0.000000 0.000000

3 BereqMethod b GET

3 BereqURL b /date.php

22 of 72

VSLグルーピングのまとめ

非常に難解だったVarnishの生ログをグルーピングすることで元の情報を�損なわずに表示ができる

23 of 72

VSL Query

先述した各グループ中にQueryにマッチするパタンがあれば出力する
文法

[レコード] [演算子] [値]

BerespStatus >= 500

レコード

{レベル}タグ:レコードのPrefix[フィールド]

{2+}Timestamp:Resp[2]

演算子
値
論理演算子

24 of 72

{レベル}タグ:レコードのPrefix[フィールド]

{2+}Timestamp:Resp[2]

省略可能
たとえばlv2を指定したい場合は{2}
ESIのようにlvが増える場合において2以上のように指定したい場合は{2+}

25 of 72

{レベル}タグ:レコードのPrefix[フィールド]

{2+}Timestamp:Resp[2]

必須
評価するタグを指定する

Timestamp
ReqMethod
RespHeader
などなど

「*」を先頭・末尾・単一指定することが可能

先頭指定

*Header 末尾にHeaderが付くタグ全て

末尾指定

Resp* 先頭にRespが付くタグ全て

単一指定

*　全てのタグ

26 of 72

{レベル}タグ:レコードのPrefix[フィールド]

{2+}Timestamp:Resp[2]

省略可能
タグのデータが「:」で区切られている場合でのKey

ヘッダに便利

例　ReqHeader:User-Agent

27 of 72

{レベル}タグ:レコードのPrefix[フィールド]

{2+}Timestamp:Resp[2]

省略可能
タグのデータがスペースで区切られている場合のインデックス番号

先頭は1

たとえばTimeStampは以下の様なフォーマット

Resp: 1398360533.209337 0.496943 0.496843
[Event]: [タイムスタンプ] [開始からの経過時間] [前のtimestampからの経過時間]

レスポンスタイムを指定する場合は以下のようにする

Timestamp:Resp[2]

28 of 72

演算子

数値(int, float)

== != < <= > >=

文字列

eq 一致
ne 不一致

正規表現

~ 一致
!~ 不一致

29 of 72

値

Integer

整数型（signed）
評価するレコードがFloatの場合は一致しない

0.9 > 0 は一致しない

Float

浮動小数点型(sigined)
小数部がなくても「.」を含む場合はFloatになる(例: 1.)
評価するレコードが整数でも一致する

9 > 0.5は一致する

String

文字列型

Regular expression

正規表現型(PCRE)

30 of 72

論理演算子

not <expr>
<expr1> and <expr2>
<expr1> or <expr2>

31 of 72

クエリ例

1秒以上かかったリクエストを表示

Timestamp:Resp[2] > 1.

クッキーを含んでいないリクエスト

not ReqHeader:cookie

レスポンスのステータスが400以上

RespStatus >= 400

ESIのリクエストで1秒以上かかっているかステータスが500以上

BerespStatus >= 500 or {2+}Timestamp:Resp[2] > 1.
※group指定はrequestであること

User-AgentにiPhoneを含んでいて1秒以上かかってるもの

ReqHeader:user-agent ~ “iPhone” and Timestamp:Resp[2] > 1.

32 of 72

VCLの変更

33 of 72

VCLの変更

3→4での変更点は非常に多い
変更点を理解する上で抑えておきたいのは2点で

スレッドが分離されたことで独立性が高まった

backendスレッドからreq.*にはアクセスできない
clientスレッドからpipeを除いてbereq.*にはアクセスできない

Directorがvmodに移管された

他の変更

文法の細かい変更

34 of 72

V3とV4のVCLアクションの比較

35 of 72

変数の流れ

36 of 72

各アクションでアクセス可能な変数

V3まで便利につかえていたreq.http.*が使えなくなっているのに注意が必要

コード上はbackend_responseでreq.esiにアクセスできるような表記あるけどassertエラーになるので注意

39 of 72

各アクションでreturnした際に次に呼ばれるアクション/挙動

40 of 72

文法/動作上の変更点

VCLの先頭に「vcl 4.0;」をつける必要がある
prefixにvclが付くサブルーチンを定義できなくなった（予約語）
vcl_fetchの変更

v3: vcl_fetch
v4: vcl_backend_response

vcl_errorの変更

v3:vcl_error
v4:vcl_synth / vcl_backend_error　(fetch errorなど)

error(XXX, YYY)の変更

v3:error(404, ”Not Found”);
v4:return(synth(404, ”Not Found”));

41 of 72

文法/動作上の変更点

purgeの変更

v3:purge
v4:return(purge)

removeがunsetに変更
ban_urlが無くなった
vcl_synthで使うobj.*がresp.*に
return(hit_for_pass)の変更

v3:return(hit_for_pass);
v4:set beresp.uncacheable = true;� return(deliver);

42 of 72

文法/動作上の変更点

vcl_recvのreturn(lookup)がreturn(hash)に
vcl_hashのreturn(hash)がreturn(lookup)に
vcl_passのreturn(pass)がreturn(fetch)に
vcl_recv呼び出し前にX-Forwarded-forを自動的につけるように
vcl_recv呼び出し後にAccept-Encodingの正規化を自動的にするように

gzipを含む場合はgzipに
gzipを含まない場合はunset

43 of 72

変数の変更点

新規

bereq.backend
bereq.retries
bereq.uncacheable
bereq.xid
beresp.uncacheable
obj.uncacheable
req.ttl

44 of 72

変数の変更点

削除

beresp.backend.port
beresp.saintmode
obj.lastuse
req.grace

45 of 72

変数の変更点

変更

req.request -> req.method
bereq.request -> bereq.method
beresp.response -> beresp.reason
obj.response -> obj.reason
resp.response -> resp.reason
server.port -> std.port(server.ip)
req.backend_healthy -> std.healthy(backend)
req.backend -> req.backend_hint
beresp.storage -> beresp.storage_hint
obj.hits -> obj.hits(読み取り専用に変更)

46 of 72

Directorの変更

V4では組み込みのdirectorはなくなりvmod化された(vmod_directors)
使い方がかなり変更されてvcl_initで初期化、関数で取得といった流れになる
directorの定義のところにロジックを入れられるので環境によってbackendを�調整する必要がある場合などに便利

backend ws01_imgw {.host="192.168.1.100";}

backend ws02_imgw {.host="192.168.1.101";}

director ws random {

{.weight = 5;.backend=ws01_imgw;}

{.weight = 5;.backend=ws02_imgw;}

}

sub vcl_recv{

set req.backend = ws;

...

vcl 4.0;

import directors;

backend ws01_imgw {.host="192.168.1.100";}

backend ws02_imgw {.host="192.168.1.101";}

sub vcl_init{

new ws = directors.random();

ws.add_backend(ws01_imgw, 1.0);

ws.add_backend(ws02_imgw, 1.0);

}

sub vcl_recv{

set req.backend_hint = ws.backend();

...

47 of 72

Directorの変更

vmod化されたdirectorの振り分けアルゴリズム

roundrobin
fallback
hash
random
(DNSはなくなった)
(clientの代替にhashを使う)

.add_backend()について

hash,randomは第二引数に振り分けの重みを指定する

XXX.add_backend(YYY, 1.0);

.backend()について

hashは引数に振り分けのキーを指定する

XXX.backend(req.http.cookie);

48 of 72

起動オプションの変更

49 of 72

起動オプションの変更

varnishdの指定

-w min[,max[,timeout]]がなくなった

-p thread_pool_(min|max|timeout)=XXXに書き換え
多分defaultファイルをそのままコピーして動かそうとして�一番嵌るポイント

50 of 72

起動オプションの変更

追加

ban_lurker_age
ban_lurker_batch
busyobj_worker_cache
cli_limit
pool_req
pool_sess
pool_vbc
pool_vbo
sigsegv_handler
vsl_space
vsm_space

51 of 72

起動オプションの変更

追加

tcp_keepalive_intvl
tcp_keepalive_probes
tcp_keepalive_time
thread_queue_limit
timeout_req
vcc_unsafe_path
max_retries
vcc_allow_inline_c

52 of 72

起動オプションの変更

変更

diag_bitmap

debug (指定方法が変わってるので注意)

esi_syntax

feature (指定方法が変わってるので注意)

gzip_stack_buffer

gzip_buffer

vcl_trace

vsl_mask (指定方法が変わってるので注意)

thread_pool_workspace

workspace_thread

53 of 72

起動オプションの変更

変更

sess_workspace

workspace_backend
workspace_client
workspace_session

sess_timeout

timeout_idle

session_linger

timeout_linger

thread_pool_purge_delay

thread_pool_destroy_delay

54 of 72

起動オプションの変更

削除

expiry_sleep
gzip_tmp_space
gzip_window
log_hashstring
log_local_address
queue_max
saintmode_threshold
shm_workspace
thread_pool_add_threshold

56 of 72

セキュリティ対策

inline-Cがデフォルト無効に

使用する場合はvcc_allow_inline_cをonに

VMODがリクエストボディへのアクセスが可能に

POSTリクエストを舐めることでまずいものをクリーンアップするなど
試しにreq.bodyにアクセスするvmodを作ってみたけど数行レベル簡単

57 of 72

累積バグが解消されている

今まで修正はされていたもののリリースには含まれていなかったバグ修正が�ほぼ取り込まれています
たとえば

syntheticでASCIIコード以外が文字化けするバグ (#545)
vclをdiscardしてもヘルスチェックが止まらないバグ(#1141)

などが直っています

58 of 72

いろいろ書いてきましたが

やっぱり使ってみないとわからないよね

59 of 72

Varnish4をとあるサイトに導入

リリースされた数日後に投入
趣味で手伝っている画像投稿系サイトのappとimgの前段にいれてみた
中規模ぐらいのサイト
app側はmalloc img側はpersistentストレージ
ハマった点はいくつかあるものの安定運用中

60 of 72

Varnish4の安定性について

メジャーの最初のものだったので盛大にバグを踏むかなとおもったが�頭を抱えるようなバグはなかった

Amedia ASとRedpill Linpro ASの実トラフィックを流してテストを行っていたとのこと

61 of 72

Expiresの計算が楽に

こういうケース

set resp.http.Expires = now + 30d;

Expires: 1398593739.120

Expires: Sun, 27 Apr 2014 10:16:35 GMT

内部でfloat型に扱いが変更にならないようになった

62 of 72

varnishstatコマンドがめっちゃ見やすく

パラメータの説明が

出るように（一部）

63 of 72

コマンド関連

varnishstat

hit-rateが出なくなった(これパッチ投げようかな・・・）
statの名前が変わっているので監視には注意

varnishncsa

%Dの表示が変わった

v3: 3.004772 (秒単位)
v4: 3009227.037430 （μ秒単位）

varnishhist

-Pパラメータで任意のヘッダを指定可能に

64 of 72

コマンド関連

varnishsizes

varnishhist -P sizeに統合

varnishreplay

パッケージには含まれていないがコードはあるのでビルド漏れ？

65 of 72

レスポンスタイムとか

varnishhist見ててあれ？遅くなったとおもって見てた

表示上は桁オーダー単位で遅く？

とりあえずログを出しつつ確認

3.0.5

4.0.0

66 of 72

レスポンスタイムとか

とりあえずログを出しつつ確認(ab)

非力な本番だったので取り敢えずそんな差があるのかぐらいの簡易な確認
v3(-n100 -c1):Requests per second: 12.79 [#/sec] (mean)
v4(-n100 -c1):Requests per second: 12.49 [#/sec] (mean)
v3(-n1000 -c10):Requests per second: 23.98 [#/sec] (mean)
v4(-n1000 -c10):Requests per second: 24.52 [#/sec] (mean)

ぶっちゃけ誤差
多分内部で使ってる時間のカウンタが�変わった

3.0.5

4.0.0

テストURLのみで絞り込み

67 of 72

persistentストレージのio負荷軽減

3.0.5

4.0.0

write時のリクエストサイズが大きくなりiops低減

68 of 72

persistentストレージの動作変更

ストレージを使い切った場合の動作
V3まで

先頭siloがexpireしている場合

特に問題なく動作

先頭siloがexpireしていない場合

再起動して先頭からsiloを幾つか開放して使用

先頭siloがexpireしている場合

特に問題なく動作

先頭siloがexpireしていない場合

transientストレージを使う（再起動しない）

transientはサイズ制限したほうが無難

69 of 72

directorのハッシュ分散が同じにならない

vmod化される際に内部のロジックが少し変わっていて同じ値を入れても�同一サーバに振り分けされるとは限らない
以下の場合で並行稼動or移行には手順・構成の考慮が必要になります

多段構成を組んでいる

objectが下位階層で重複するので全体のヒットレートが落ちる
ban/purgeを行う際に分散を前提として流し込む場合消しきれない

cookie persistenceのような使い方

並行稼動させるとpersistenceにならない

70 of 72

beresp.ttlの罠

とりあえずキャッシュがしたいときはberesp.ttl=1d;のようなコードを書くと�思いますがV4ではberesp.http.ageの評価をするようになっており�意識しないとキャッシュできなくなります

キャッシュ出来ないケース

beresp.http.Age >= beresp.ttl

キャッシュできるが想定より短い

beresp.http.Age分キャッシュが短い

想定通りのTTL

beresp.http.Ageが含まれない

一応これで回避は出来る

set beresp.ttl = std.duration(beresp.http.age+"s",0s) + beresp.ttl;

ttlにAgeぶんを足し込む

スマートな方法ないかなーと探し中

71 of 72

beresp.uncacheableの罠

今回追加された変数にberesp.uncacheableという注意が必要なものがある
uncacheableとttlの組み合わせで以下のような動きになる

beresp.uncacheable=false beresp.ttl=120s (Ageはなし)

120秒キャッシュ

beresp.uncacheable=true beresp.ttl=120s (Ageはなし)

120秒hit-for-pass(期間中常にmiss)

たとえばcache-control: no-storeのものはuncacheable=trueに設定される
強制的にキャッシュしたい場合はuncacheableをfalseにする必要がある

72 of 72

確認しているバグっぽいやつ

vcl_purgeでのreturn値がfetch/synthを指定できるが両方ともsynthになる

#1493

backend_responseでreq.esiにアクセスするとassert error

#1489(fixed)
backend_responseでreq.esiにアクセスできなくなる形でFix済

poolに戻されたスレッドがカウンタ上KILLされても開放されない

#1490(fixed)
とりあえず生成が走らないように十分なスレッドを最初から確保しとくといい

persistentストレージのサイズがまれに指定サイズ確保できない（V3のときから）
varnishreplayのビルド

1 of 72

2 of 72

3 of 72

4 of 72

5 of 72

6 of 72

7 of 72

8 of 72

9 of 72

10 of 72

11 of 72

12 of 72

13 of 72

14 of 72

15 of 72

16 of 72

17 of 72

18 of 72

19 of 72

20 of 72

21 of 72

22 of 72

23 of 72

24 of 72

25 of 72

26 of 72

27 of 72

28 of 72

29 of 72

30 of 72

31 of 72

32 of 72

33 of 72

34 of 72

35 of 72

36 of 72

37 of 72

38 of 72

39 of 72

40 of 72

41 of 72

42 of 72

43 of 72

44 of 72

45 of 72

46 of 72

47 of 72

48 of 72

49 of 72

50 of 72

51 of 72

52 of 72

53 of 72

54 of 72

55 of 72

56 of 72

57 of 72

58 of 72

59 of 72

60 of 72

61 of 72

62 of 72

63 of 72

64 of 72

65 of 72

66 of 72

67 of 72

68 of 72

69 of 72

70 of 72

71 of 72

72 of 72