2月 222015
 

Varnish4.0.3がリリースされました。
今回のリリースは公式で行ってる通り多くのfixがありますが重要なバグフィックスを含みます。
比較的遭遇しやすいRaceコンディションに起因するpanicが修正されています。
アップデート時の注意事項はありますが、基本的にアップデートをおすすめします。

Changes
ダウンロード

変更内容から幾つか抜粋して紹介します。


バグフィックス

1650 – 複数のXFFヘッダがあった場合は折りたたむように修正しました

1620 – スレッドプールに空きが無い場合にclientスレッドを使うのを辞めました
空きが無いためbackgroundスレッドを作成出来ない場合にclientスレッドを使っていたのを辞めました。
また、フェッチするためにスレッドがない場合にカウントアップするカウンタfetch_no_threadが追加されました。
これがもし増えるような状況であればスレッド周りのパラメータ調整を行うと良いでしょう。

1566 – VCL中の「?」をエスケープするようにしました

1660 – SynthではRangeリクエストを無視するようになりました。
Synthでレスポンスを返すパスでrangeリクエストを受け付けた場合にassertしていたためです。

1637 – VEP(ESI処理)のコールバックが失敗した際にpanicしていたのをフェッチ失敗(503)として扱うようにしました

1665 – リクエストのタイムアウト計算をドキュメントに合わせました
リクエストのタイムアウトを計算する際にアイドルタイムを基準に計算していましたが
リクエストの最初のバイトを受け取った時間を基準に変更しました。

1672 – バックエンドが意図しない304をレスポンスしてきた場合にpanicしたのを修正しました
バックエンドに対してINM/IMSリクエストをしていないのに304をレスポンスしてきた場合にpanicしたのを修正しました。

1539 – lookupしようとしたオブジェクトがちょうどオブジェクトを開放していくスレッドに変更された際にpanicしてたのを修正しました
感覚的にですが、割と踏む確率が高かったバグです。

1349 – varnishadm:backend.set_healthyのマッチを修正しました

1623 – varnishhist:-dオプション使用時にsegfaultするのを修正しました

1378 – varnishncsa:印字不可能な文字をエスケープして出力するようにしました

1462 – varnishncsa:URLなどリクエストに関わる値は最初のエントリを利用しステータスコードなどレスポンスに関わるものは最後の値を使うように変更しました
いまいちわかりづらいのでIMSリクエストを送った場合のログで例をあげます
■4.0.2/varnishncsa


192.168.1.31 - - [19/Feb/2015:01:47:49 +0900] "GET http://192.168.1.37:6081/x.html HTTP/1.1" 200 0 "-" "Mozilla/5.0 (Windows NT 6.3; WOW64; rv:35.0) Gecko/20100101 Firefox/35.0"

■4.0.3/varnishncsa


192.168.1.31 - - [19/Feb/2015:01:47:16 +0900] "GET http://192.168.1.37:6083/x.html HTTP/1.1" 304 0 "-" "Mozilla/5.0 (Windows NT 6.3; WOW64; rv:35.0) Gecko/20100101 Firefox/35.0"

■4.0.2/varnishlog -graw -c


         6 Begin          c sess 0 HTTP/1
         6 SessOpen       c 192.168.1.31 59552 :6081 192.168.1.37 6081 1424279850.057539 15
         6 Link           c req 7 rxreq
         7 Begin          c req 6 rxreq
         7 Timestamp      c Start: 1424279850.057624 0.000000 0.000000
         7 Timestamp      c Req: 1424279850.057624 0.000000 0.000000
         7 ReqStart       c 192.168.1.31 59552
         7 ReqMethod      c GET
         7 ReqURL         c /x.html
         7 ReqProtocol    c HTTP/1.1
         7 ReqHeader      c Host: 192.168.1.37:6081
         7 ReqHeader      c User-Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; rv:35.0) Gecko/20100101 Firefox/35.0
         7 ReqHeader      c Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
         7 ReqHeader      c Accept-Language: ja,en-us;q=0.7,en;q=0.3
         7 ReqHeader      c Accept-Encoding: gzip, deflate
         7 ReqHeader      c Connection: keep-alive
         7 ReqHeader      c If-Modified-Since: Wed, 18 Feb 2015 16:43:37 GMT
         7 ReqHeader      c If-None-Match: "280ea4-b-50f5f855c1b9e"
         7 ReqHeader      c Cache-Control: max-age=0
         7 ReqHeader      c X-Forwarded-For: 192.168.1.31
         7 VCL_call       c RECV
         7 VCL_return     c hash
         7 ReqUnset       c Accept-Encoding: gzip, deflate
         7 ReqHeader      c Accept-Encoding: gzip
         7 VCL_call       c HASH
         7 VCL_return     c lookup
         7 Debug          c "XXXX MISS"
         7 VCL_call       c MISS
         7 VCL_return     c fetch
         7 Link           c bereq 8 fetch
         7 Timestamp      c Fetch: 1424279850.058979 0.001355 0.001355
         7 RespProtocol   c HTTP/1.1
         7 RespStatus     c 200★←これが使われた
         7 RespReason     c OK
         7 RespHeader     c Date: Wed, 18 Feb 2015 17:17:30 GMT
         7 RespHeader     c Server: Apache/2.2.22 (Ubuntu)
         7 RespHeader     c Last-Modified: Wed, 18 Feb 2015 16:43:37 GMT
         7 RespHeader     c ETag: "280ea4-b-50f5f855c1b9e"
         7 RespHeader     c Vary: Accept-Encoding
         7 RespHeader     c Content-Encoding: gzip
         7 RespHeader     c Content-Type: text/html
         7 RespHeader     c X-Varnish: 7
         7 RespHeader     c Age: 0
         7 RespHeader     c Via: 1.1 varnish-v4
         7 VCL_call       c DELIVER
         7 VCL_return     c deliver
         7 Timestamp      c Process: 1424279850.059049 0.001425 0.000070
         7 RespProtocol   c HTTP/1.1
         7 RespStatus     c 304★←本当はこれを使ってほしい
         7 RespReason     c Not Modified
         7 RespReason     c Not Modified
         7 Debug          c "RES_MODE 0"
         7 RespHeader     c Connection: keep-alive
         7 Timestamp      c Resp: 1424279850.059136 0.001513 0.000087
         7 Debug          c "XXX REF 2"
         7 ReqAcct        c 423 0 423 315 0 315
         7 End            c

■4.0.3/varnishlog -graw -c


     32774 Begin          c sess 0 HTTP/1
     32774 SessOpen       c 192.168.1.31 59586 :6083 192.168.1.37 6083 1424279998.331551 15
     32774 Link           c req 32775 rxreq
     32775 Begin          c req 32774 rxreq
     32775 Timestamp      c Start: 1424279998.331637 0.000000 0.000000
     32775 Timestamp      c Req: 1424279998.331637 0.000000 0.000000
     32775 ReqStart       c 192.168.1.31 59586
     32775 ReqMethod      c GET
     32775 ReqURL         c /x.html
     32775 ReqProtocol    c HTTP/1.1
     32775 ReqHeader      c Host: 192.168.1.37:6083
     32775 ReqHeader      c User-Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; rv:35.0) Gecko/20100101 Firefox/35.0
     32775 ReqHeader      c Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
     32775 ReqHeader      c Accept-Language: ja,en-us;q=0.7,en;q=0.3
     32775 ReqHeader      c Accept-Encoding: gzip, deflate
     32775 ReqHeader      c Connection: keep-alive
     32775 ReqHeader      c If-Modified-Since: Wed, 18 Feb 2015 16:43:37 GMT
     32775 ReqHeader      c If-None-Match: "280ea4-b-50f5f855c1b9e"
     32775 ReqHeader      c Cache-Control: max-age=0
     32775 ReqHeader      c X-Forwarded-For: 192.168.1.31
     32775 VCL_call       c RECV
     32775 VCL_return     c hash
     32775 ReqUnset       c Accept-Encoding: gzip, deflate
     32775 ReqHeader      c Accept-Encoding: gzip
     32775 VCL_call       c HASH
     32775 VCL_return     c lookup
     32775 Debug          c "XXXX MISS"
     32775 VCL_call       c MISS
     32775 VCL_return     c fetch
     32775 Link           c bereq 32776 fetch
     32775 Timestamp      c Fetch: 1424279998.333049 0.001412 0.001412
     32775 RespProtocol   c HTTP/1.1
     32775 RespStatus     c 200
     32775 RespReason     c OK
     32775 RespHeader     c Date: Wed, 18 Feb 2015 17:19:58 GMT
     32775 RespHeader     c Server: Apache/2.2.22 (Ubuntu)
     32775 RespHeader     c Last-Modified: Wed, 18 Feb 2015 16:43:37 GMT
     32775 RespHeader     c ETag: "280ea4-b-50f5f855c1b9e"
     32775 RespHeader     c Vary: Accept-Encoding
     32775 RespHeader     c Content-Encoding: gzip
     32775 RespHeader     c Content-Length: 31
     32775 RespHeader     c Content-Type: text/html
     32775 RespHeader     c X-Varnish: 32775
     32775 RespHeader     c Age: 0
     32775 RespHeader     c Via: 1.1 varnish-v4
     32775 VCL_call       c DELIVER
     32775 VCL_return     c deliver
     32775 Timestamp      c Process: 1424279998.333124 0.001487 0.000075
     32775 RespProtocol   c HTTP/1.1
     32775 RespStatus     c 304★←これを使った(最後のエントリ)
     32775 RespReason     c Not Modified
     32775 RespReason     c Not Modified
     32775 RespUnset      c Content-Length: 31
     32775 Debug          c "RES_MODE 0"
     32775 RespHeader     c Connection: keep-alive
     32775 Timestamp      c Resp: 1424279998.333257 0.001620 0.000133
     32775 Debug          c "XXX REF 2"
     32775 ReqAcct        c 423 0 423 319 0 319
     32775 End            c


4.0.2の場合はステータス200でLength:0で帰ってきています。
これは最初に現れたRespStatusを利用したためです
期待しているのはdeliverする直前、つまり最後の値なわけで4.0.3では最後のRespStatusの304を出力するようになっています。

機能追加

vmod_std: VOID std.cache_req_body(BYTES)が追加されました
使い方については以前書いたこちらの記事を参照してください(Varnishでテストコードを書こう!~実践編~+Bodyを読もう!

vmod_std: TIME std.time(STRING,TIME)が追加されました


//VCL
std.log(""+now);
std.log(""+std.time("hogehoge",now));//無効な文字列を指定すると第二引数が使われる
std.log(""+std.time("Sun, 22 Feb 2015 00:0:00 GMT",now));

//結果
//-   VCL_Log        Sun, 22 Feb 2015 01:21:31 GMT
//-   VCL_Log        Sun, 22 Feb 2015 01:21:31 GMT
//-   VCL_Log        Sun, 22 Feb 2015 00:00:00 GMT

使用可能なフォーマットは


"Sun, 06 Nov 1994 08:49:37 GMT"
"Sunday, 06-Nov-94 08:49:37 GMT"
"Sun Nov  6 08:49:37 1994"
"1994-11-06T08:49:37"
"784111777.00"
"784111777"

です

VCL変更

bereq.uncacheableがread-onlyになりました

obj.uncacheableがvcl_hitではなくvcl_deliverで使えるようになりました

パラメータ変更

fetch_chunksizeが128KBから16KBに変更されました

アップデート時の注意

fileストレージを利用している場合で空き容量が指定サイズを上回っている場合に
「larger than file system」と出て起動に失敗します。(関係するコミット
Varnishのfileストレージを利用する場合にフラグメントを防ぐためにddで先にファイルを作っておく事を公式でも推奨していますが
既に確保しているサイズを考慮していないため、ddで事前確保しようとするとディスクサイズの50%以下しか使用できません。
一旦消してしまえば問題なく起動しますが注意が必要です。
また、この問題は当然ですが4.0.3にアップデートしたあとにrestartを行っても起きるので注意してください。(reloadは問題なしです)
あとでチケットきろうかなと思います。


 Leave a Reply

You may use these HTML tags and attributes: <a href="" title=""> <abbr title=""> <acronym title=""> <b> <blockquote cite=""> <cite> <code> <del datetime=""> <em> <i> <q cite=""> <s> <strike> <strong>

(required)

(required)