ぼちぼち日記

おそらくプロトコルネタを書いていることが多いんじゃないかと思います。

HTTP/2仕様のWGラストコール始まる

(注)8月1日にチェアより正式にWGラストコールの宣言がありました。 "Working Group Last Call: draft-ietf-httpbis-http2-14 and draft-ietf-httpbis-header-compression-09" すったもんだしたあげく、draft-14が出ることに。結局ヘッダフォーマットなど色々変わっちゃいました。

1. HTTP/2仕様は最終段階、いよいよラストコールへ

先週末の6月27日にhttpbis WG(ワーキンググループ)の議長のMark Nottingham氏より、 「HTTP/2 Implementation Draft 5 (and getting to Working Group Last Call)」 というアナウンスが出されました。6月上旬にNYCのGoogleオフィスでHTTP/2の中間会議が開催され、このアナウンスはそこでの議論の結果を受けて行われたものです。彼からのアナウンスをまとめると、

  • 先日(6/17に)出した HTTP/2仕様 draft-13 を5番目の実装仕様とする。
  • この仕様をもとに長期間(半年ほど)かけて広くHTTP/2の実装・デプロイを行う。
  • 幾つか issue がまだ残っているが、プロトコルフォーマットや実装挙動を変えるものではない。
  • issueが全部クローズするまでこのドラフトを正式に WGLC とはしないが、プロトコル設計自体はWGLCとして扱ってほしい。
  • 9月にWGラストコールを終了させる予定です。

という内容です。
2012年1月からHTTP/2仕様の検討が開始されましたが、2年半経ってようやくここまで来ました。当初2014年4月にWGLCの予定でしたが、多少遅くなってしまったのは仕方ないことです。

2. h2-13 実装と大規模デプロイ

h2-13(HTTP/2 draft-13仕様)の実装状況は、6月30日時点で早速 Twitter,Firefox Nightly,Chrom Canary で利用できるようになっています。そしてQ3にかけて、 GFE(Google Front End)や akamai 等の大規模サービスでh2-13の利用ができるようになる予定です。MicrosoftもQ3の夏の終わりに IE dev channel で HTTP/2ドラフト実装などが提供される見込みです(IISも取り組んでいるがまだ約束できないとのこと)。
httpbis WGは、この秋にHTTP/2がブラウザの安定版や実サービス環境で広く安定的に利用できることを実証し、この実績をもとにIETF内でのHTTP/2仕様の合意を目指す方針です。

3. 今後のスケジュール

NYC中間会議の最後のセッションで話し合った今後のスケジュールは下図の通りです。
9月上旬のWGLCの終了を受けて、10月上旬には他WGを含めたIETF Last Call を行い、12月上旬に IESGのレビューを受け、来年2月頃にはRFC 化という段取りです。

これは非常に理想的なスケジュールであり、今後様々な issue やコメントがフィードバックされてスケジュールの見直しが避けれられない可能性があります。

また、ラストコール中にも様々な機能追加の提案がされるでしょう。先日のNYC中間会議でHTTP/2仕様の独自拡張(フレームや設定値などの拡張)を行う機能が採択され、draft-12で少し膨らんだ機能仕様の一部が拡張機能に追い出されました。今後、追加機能の提案に対しては基本的に拡張機能として議論し、HTTP/2の仕様化完了の作業をブロックしないようにすることが合意されています。

とはいうものの、WebSocket の時のようにプロトコル的なセキュリティ脆弱性等が発見されると仕様自体一旦全部おしゃかになってしまう可能性もあります 。大詰めを迎えたHTTP/2仕様化作業は、これから大きな正念場を迎えます。

Node.js-v0.10.28でDate.now()が爆速になった

1. Node-v0.10.28とNode-v0.11.13のリリース

先週末、安定版のNode-v0.10.28と開発版のNode-v0.11.13がリリースされました。*1

次の0.11.14が0.11系の最後となる予定とアナウンス。そう、次々はいよいよNode-v0.12です。

安定版の0.10系は、基本バグフィックスなどが中心のリリースですが、今回
deps: make v8 use CLOCK_REALTIME_COARSE
のような修正が入りました。Node-v0.10のV8でLinux向けにNode固有の性能向上パッチが適応されたようです。
CLOCK_REALTIME_COARSEとはどのようなものでしょうか? RedHatのドキュメント「15.2.1. CLOCK_MONOTONIC_COARSE と CLOCK_REALTIME_COARSE」では、

カーネルへのコンテキストスイッチを避けるため、そして結果的にクロックの読み取りを迅速に行うために、CLOCK_MONOTONIC_COARSE および CLOCK_REALTIME_COARSE POSIX クロックへのサポートが VDSO ライブラリ関数の形式で可能になりました。

と説明されています。VDSO (Virtual Dynamically linked Shared Objects)とは、カーネルスペースの処理をユーザスペースで代用実行できるライブラリ機能で、システムコールの呼び出しにかかる負荷を大幅に低減できる仕組みです。

今回のパッチは、 Date.now() の時刻取得で利用されていたシステムコール(gettimeofday(2))を、VDSOに対応したシステムコール(CLOCK_REALTIME_COARSEを利用した clock_gettime(2))に置き換えて、Date.now()の高速化を図ったものです。これを利用できる条件は、今回のパッチでは

  1. Linux (kernel 2.6.32以上)であること。
  2. CLOCK_REALTIME_COARSEの時間解像度が 1 msec 以下であること。

が必要で、この2つ目の条件がLinuxディストリビューションによって違うみたいです(後述)。
またいろいろ試してみたところ、 VitualBoxやVmwareなど仮想化ハイパーバイザー側でシステムコールを処理してCLOCK_REALTIME_COARSE対応有無にかかわらず性能が変わらないといったことも見受けられました(誰か詳細わかる人教えてください)。

今回この高速化の恩恵が確認できた AWS の EC2 環境で、どこまで Date.now()が高速化できたのか、実際に測ってみました。

ちなみに、本家V8では以前に同じ対応がとられていましたが現状 revert されちゃっています。
Issue 69933005: Revert "linux: use CLOCK_{REALTIME,MONOTONIC}_COARSE" (Closed)
Chromeでビルドがフェイルしてしまったのが理由ですが、おそらく時間解像度を取得する clock_getres(2) のシステムコールChromeの sandbox 機能でブロックされちゃったのが原因だろうと想像しています。Nodeは関係ないので独自にパッチを当てたのでしょう(0.11系にはまだ未対応)。

2. CLOCK_REALTIME_COARSEが使えているか確認する

先述した通り、CLOCK_REALTIME_COARSEの時間解像度が1msec以下であることが必要ですが、チェックしてみましょう。

この時間解像度の値は、Linuxのタイマー割り込み頻度の設定に依存します。kernelをビルドする時に CONFIG_HZ で指定されたものです。タイマー割り込みの頻度は、OS全体のパフォーマンスに影響するのですが、各ディストリビューションで提供されているカーネルの設定値は、歴史的な経緯もあってばらつきがあるようです。

参考: FedoraとUbuntuのLinuxカーネル設定の比較

RedHat系(Fedora,CentOS含む)は、CONFIG_HZ は 1000, Ubuntuは 250のようです。
実際に確認してみましょう。

# EC2(m3.medium)のFedora20
[fedora@ip-172-31-45-147 ~]$ grep CONFIG_HZ /boot/config-3.11.10-301.fc20.x86_64 |grep -v \#
CONFIG_HZ_1000=y
CONFIG_HZ=1000

# EC2(m3.medium)のUbuntu14.04
ubuntu@ip-172-31-43-202:~$  grep CONFIG_HZ /boot/config-3.13.0-24-generic  |grep -v \#
CONFIG_HZ_250=y
CONFIG_HZ=250

次に実際にCLOCK_REALTIME_COARSEの時間解像度を求めてみます。
clock_getres() を使用したクロック精度の比較で紹介されている時刻精度を取得するサンプルコード(show_clock_getre)を少し改変して実行すると、

# EC2(m3.medium)のFedora20
[fedora@ip-172-31-45-147 ~]$ ./show_clock_getres
CLOCK_REALTIME: 1ns
CLOCK_REALTIME_COARSE: 1000000ns

# EC2(m3.medium)のUbuntu14.04
ubuntu@ip-172-31-43-202:~$ ./show_clock_getres
CLOCK_REALTIME: 1ns
CLOCK_REALTIME_COARSE: 4000000ns

うわぁー、やっぱりUbuntuじゃVDSOの恩恵は受けられなさそうです。
次に、 straceを用いて Date.now() 実行時の時刻取得システムコール(clock_gettime(2))を見てみましょう。

# EC2(m3.medium)のFedora20
[fedora@ip-172-31-45-147 ~]$ strace ./node_0_10_28 -e 'Date.now()' 2>&1 |grep gettime
clock_gettime(CLOCK_MONOTONIC, {873, 33640556}) = 0

# EC2(m3.medium)のUbuntu14.04
ubuntu@ip-172-31-43-202:~$ strace node-v0.10.28/node -e 'Date.now()' 2>&1 |grep gettime
clock_gettime(CLOCK_MONOTONIC, {4423, 358081345}) = 0
clock_gettime(CLOCK_REALTIME, {1399488630, 840884468}) = 0
clock_gettime(CLOCK_REALTIME, {1399488630, 846318927}) = 0
clock_gettime(CLOCK_REALTIME, {1399488630, 883844301}) = 0

Fedoraの方は、CLOCK_REALTIMEの時刻取得のシステムコールがないので、VDSOが効いているのがわかります。

3. どれだけDate.now()が速くなるのか?

さぁ、どれだけ速くなるのかベンチマークです。100万回 Date.now()を実行してみます。

// date_now.js
var i = 1000000;
while (--i > 0) Date.now();

Node-v0.10.26とNode-v0.10.28で実行時間を比べてみます。

[fedora@ip-172-31-45-147 ~]$ time ./node_0_10_26 date_now.js
real    0m1.688s
user    0m0.413s
sys     0m0.475s

[fedora@ip-172-31-45-147 ~]$ time ./node_0_10_28 date_now.js
real    0m0.114s
user    0m0.039s
sys     0m0.025s

おぉー! Node-v0.10.28 は、Date.now()が約15倍速くなった。

straceでシステムコール統計を取ってみるとその違いは明らかです。Node-v0.10.28では、システムコール数がわずか数百。

[fedora@ip-172-31-45-147 ~]$ strace -c ./node_0_10_26 date_now.js
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 99.96    2.625466           3   1000076           gettimeofday
  0.04    0.001000          71        14           brk
  0.00    0.000017           9         2           getcwd
(中略)
  0.00    0.000000           0         2           pipe2
------ ----------- ----------- --------- --------- ----------------
100.00    2.626497               1000318        15 total

[fedora@ip-172-31-45-147 ~]$ strace -c ./node_0_10_28 date_now.js
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 89.55    0.000120           2        70           mmap
 10.45    0.000014           2         9           close
  0.00    0.000000           0         9           read
(中略)
  0.00    0.000000           0         2           pipe2
------ ----------- ----------- --------- --------- ----------------
100.00    0.000134                   248         9 total

ちなみに Ubuntuで同じベンチをやってみたんですが、予想通りほとんど変わらずです。

ubuntu@ip-172-31-43-202:~$ time node-v0.10.26/node date_now.js
real    0m2.430s
user    0m1.104s
sys     0m1.321s

ubuntu@ip-172-31-43-202:~$ time node-v0.10.28/node date_now.js
real    0m2.597s
user    0m1.130s
sys     0m1.462s

Nodeコアの中の timer で Date.now() とかを使っているので http サーバとかどれだけ速くなるだろうかと hello world のベンチをしてみたのですが、結果ほとんど変わりませんでした(他のボトルネックの方が大きい)。

先述の通り、仮想化環境やディストリビューションカーネル設定に依存しますが、EC2上のRedHat系OSで時刻取得を頻繁に行うような処理をしているNodeがあれば、Node-v0.10.28へのバージョンアップを検討することをお勧めします。

*1:Node-v0.10.27は、npmの変数名typoによる致命的なバグが見つかったので使わないようにしましょう。

Node-v0.12からデフォルトでES6の一部が使えるようになった(WeakMap解説編)

このエントリーは、4月24日(木)に行われる「東京Node学園 12時限目」の発表ネタを先出ししたものです。

1. はじめに、

 過去2回、Node-v0.12における ES6(ECMAScript6)関連のエントリー*1を続けて書きました

いつNodeでES6の機能がデフォルトで使えるようになるのか…と夢見てたのですが、なんとすぐその時がやってきました。

パチパチ! Angular2.0 の開発のため Chrome M35 の機能として先行的に一部ES6対応したようです。 *2

Googleさん、えらい。

 Nodeの現リーダTJも、最初はこのV8アップグレードに”ちょっと待った”をしていたみたいですが、今では”現状容認”に変わりました。
 今後、V8 3.25で何か問題があればダウングレードする可能性がありますが、このままいけば Node-v0.12 で Promise, Object.observe, WeakMap,WeakSet がデフォルト(オプションなし)で使えるようになりそうです。 既にPromise, Object.observe の解説エントリーを書いたので、今回残っている WeakCollection (WeakMap/WeakSet)について書いてみます。

2. WeakMap/WeakSet とは、

 オブジェクトのみをキーにしたハッシュテーブルです。WeakMapは、キーと値を WeakSet はキーのみ登録できます。弱参照なのでキーがGCされるとエントリーが自動的に削除されてしまいます。そのため for とかで内部のエントリーを列挙したり、格納されているエントリー数を取得するようなことはできません。
 今回、WeakMapの方がいろいろ使い方があるので WeakMapだけ解説します。まず単純な使い方を見てみましょう。

// sample0.js WeakMapの使い方
// WeakMapコンストラクタで weakmapオブジェクトを生成
var weakmap = new WeakMap();
function MyObj(i) {
  this.hoge = i;
}
var obj1 = new MyObj(1);
weakmap.set(obj1, 1); // obj1をキーに1を格納
var obj2 = new MyObj(2);
weakmap.set(obj2, 2); // obj1をキーに1を格納
// WeakMap値を取得
console.log(weakmap.get(obj1));
console.log(weakmap.get(obj2));
weakmap.clear(); // エントリーをクリア
console.log(weakmap.get(obj1));
console.log(weakmap.get(obj2));

で、実行してみます。

$ node -v
v0.11.13-pre
$ node sample0.js
1
2
undefined
undefine

キーのオブジェクトがないと中身がわからないので、GCでエントリーが削除されているか確認する方法が思いつかないです。もし誰かやり方を知っていたら教えてください。
 このWeakMapは、もともと soft field と object cache という目的で仕様化された機能です。ブラウザでDOMを扱う場合、DOMのプロパティを勝手に拡張してフィールドを付け加えるのではなく、WeakMapを使いましょうということです。Cacheの用途は、エントリー削除ポリシーとかの制御ができないのでなかなか限定的な使い方になりそうです。(あまりいい例が見つからなかった)

3. WeakMapの使い方(soft field)

 Nodeの場合でも、王道の soft field での使い方を考えてみます。HTTPリクエストのレスポンス時間の統計を測るスクリプトを考えてみます。クライアントオブジェクトの開始時間の格納にWeakMapが使えます。*3

// sample3.js HTTPリクエストのレスポンス時間統計を測定
var http = require('http');
var opts = {
  host: 'localhost',
  port: 80,
  path: '/'
};
var maxi = 100; // 試行回数
var results = [];
var weakmap = new WeakMap(); // WeakMapを生成
for(var i = 0; i < maxi; i++) {
  var client = http.get(opts);
  // リクエストの開始時間を weakmap に保存
  weakmap.set(client, Date.now());
  client.on('response', function(res) {
    res.resume();
    res.on('end', function() {
      // 開始時間からレスポンス時間を計算して結果を格納
      results.push(Date.now() - weakmap.get(client));
    });
  });
}
// 統計結果出力
process.on('exit', function() {
  var max = 0;
  var min = Infinity;
  var ave = 0;
  results.forEach(function(e) {
    max = e > max ? e: max;
    min = e < min ? e: min;
    ave += e;
  });
  if (!results.length) ave = ave/results.length;
  console.log('min:', min, ',max:', max, ',average:', ave, 'in [msec]');
});

で実行してみます。

$ node sample3.js
min: 30 ,max: 69 ,average: 52.76 in [msec]

まさに WeakMapの王道の使い方です。

4. WeakMap の使い方(プライベート変数の格納)

 他にユースケースないかなーと調べてみたんですが、なかなか皆さん苦労されているみたいです。一つこれは、と見つけたのは、Nodeの用途に限ったものではないですが、WeakMapを使ってプライベート変数を隠匿させる方法です。

 ご存知の通り JavaScript では、プライベート変数の機能が標準で提供されていません。例えば、乱数値を格納するクラスを考えると、アンダースコアを変数名に付けて、下記の通りなんちゃってプライベートにしていることも多いです。

module.exports = Hoge;
function Hoge(size) {
  size = +size || 8;
  // 変数をアンダースコア名にしてプライベート感を演出
  this._rand = require('crypto').randomBytes(size);
};
Hoge.prototype.getRand = function() {
  return this._rand;
};

他に クロージャー内の変数を使うと下記の通り変数を隠匿できますが、アクセスするにはコンストラクタ内のスコープじゃないとダメなので、見栄えがちょっとイケてないですね。

module.exports = Hoge;
function Hoge(size) {
  size = +size || 8;
  var rand = require('crypto').randomBytes(size);
  this.getRand = function() {
    return rand;
  };
};

そこでWeakMapを使うとちょっときれいに書けます。モジュール内に WeakMapを生成して、this をキーとしてプライベート変数を格納するのです。
早速書いてみると、

// WeakMapを使った Private変数の隠匿
var weakmap = new WeakMap();
module.exports = Hoge;
function Hoge(size) {
  size = +size || 8;
  var rand = require('crypto').randomBytes(size);
  // thisをキーとしてプライベート変数をWeakMapに格納
  weakmap.set(this, rand);
};
Hoge.prototype.getRand = function() {
  // WeakMapからプライベート変数を取り出す
  return weakmap.get(this);
};

これ結構良い使い方ですね。FirefoxOS アプリのソースとか見ると WeakMapの定番の使い方みたいになってる感じです。
 先のエントリーで、クロージャー変数を使う方法よりWeakMapの方が prototype オブジェクトを使えて、メモリ的に節約できるメリットがあると書いてあったので、実際に比べてみました。10万個のオブジェクトを生成してみます。

var kind = process.argv[2] || 'weakmap';
var Hoge = require('./' + kind + '-module.js');
var hogelist = [];
for(var i = 0;  i < 100000; i++) {
  hogelist.push(new Hoge(16));
}
console.log(kind, process.memoryUsage());

で実行します。

$ node sample2.js weakmap
weakmap { rss: 52260864, heapTotal: 35416704, heapUsed: 20998084 }
$ node sample2.js closure
closure { rss: 49442816, heapTotal: 35178496, heapUsed: 24271728 }

うーん、100,000オブジェクトを作って2割程度の違いですか。おそらくV8の hidden class が効いているのでメモリや性能的にはそれほど違いはないかと推測します。もし、他にもWeakMapの活用方法を知っている方がいらっしゃいましたら紹介してください。

5. Node-v0.12の新機能について発表します

「東京Node学園 12時限目」は、来週月曜4月21日に募集開始です。この他 Node-v0.12 の新機能についていろいろ発表する予定です(発表予定アジェンダ)。 20分ではなかなか細かく全部は説明できませんが、新しいNodeがどういうものになるのか知りたい方は是非ご参加ください。

*1:厳密には Object.observeはES7の機能です。

*2:不思議なんですが現breeding edge V8 3.26では再度オプション要に revert されています。誰か理由を知っている人は教えてください。

*3:実際は、そのままクライアントオブジェクトにプロパティを追加してもまぁ問題ないでしょう

Object.observe()とNode.jsのイベントループの関係

1. はじめに

最近 Chrome で Object.observe() がデフォルトで有効になりました。

コミットログを見ればわかりますが、2回 revert された後の3度目の正直のコミットです。

確かに Object.observe() は非常に強力なAPIですけど、ES6の仕様候補の機能に入っていません。(ES.harmony or ES7?) ちょっと前に大幅な仕様見直しがあったので、こんな苦労してまでよくデフォルトで有効にするなぁと不思議でした。

しかし今日 AngularJS 2.0 のリリースを見て合点いきました。PolymerのMLにも流れてました。

Googleさん、攻めてますねー。

Object.observe()の機能については下記記事を参照にしてください。(また js-nextさんの記事の紹介だ、いつもありがとうございます。)

仕様改定前の古いものですがいちおう私のエントリーも載せておきます。

そこで気になるNodeとの関係です。デフォルトで Object.observe()が使えるのは、最新(breeding edge)版のV8 3.25なので、昨日紹介した Node(V8 3.24)では、依然 harmony オプションが必要です。ただこのまま Node-v0.12 のリリースが遅れると、ひょっとして Node の V8 が3.25にアップデートするかもしれませんし、次の Node-v0.13(もしかして1.x?)では確実に入るでしょう。近い将来、NodeでObject.observe() がデフォルトで使えるとなると、これまでと全く違う世界が現れるのではないかと夢がひろがりんぐしてしまいます。

個人的には、まだ具体的に夢のあるグッとくるような使い方は考えられていませんが、NodeでObject.observe()を使うと、そのコールバックってNodeのコールバックとどう違うんだろう、それともどう一緒なんだろうか? といった疑問がふとわいてきました。そう思うと気になって気になって仕方がなく、我慢できずにさっそく検証してみました。(原稿の締め切り直前にやってていいんだろうか・・・・)

2. Node では Object.observe() のコールバックはどのタイミング実行される?

V8の最新版の実装を見てみると Object.observe() は内部に Microtask Queue を保持して、タスク管理をしているようです。昨日紹介した Promise も同じ仕組みみたいです。

Nodeで扱うコールバックは、I/Oコールバック、setImmediate、0秒の setTimeout、process.nextTick、EventEmitterとざっと5種類。これに Object.observeのコールバック、Object.deliverChangeRecordsによるコールバックの2種類で合計7種類あります。
EventEmitter と Object.deliverChangeRecords は同期的な動作だと予想されるので2つのEventEmitterの間に Object.deliverChangeRecords を挟み込みます。結果、コールバックの起動順序を表示するテストスクリプトを以下の様にしました。

// Object.observe()とNodeのコールバックの実行順を確認するテスト
var util = require('util');
var EventEmitter = require('events').EventEmitter;
var fs = require('fs');
var order = 1;
// Test Event Object
function MyObj() {}
util.inherits(MyObj, EventEmitter);
var myobj = new MyObj();
// Event emitter callback
myobj.on('myevent', function(msg) {
  console.log(order++, 'myevent msg: '+ msg +' emitted');
});
// Object.observe callback
function callback(changeRecord) {
  console.log(order++, 'Object.observed:', changeRecord);
}
Object.observe(myobj, callback);

// Start Testing
fs.stat(__filename, function(stat) {
  console.log(order++, 'I/O callback(fs.stat)');
});
// At the last of event loop
setImmediate(function() {
  console.log(order++, 'setImmediate called');
});
// Timer
setTimeout(function() {
  console.log(order++, 'setTimeout 0sec called');
}, 0);
// At the finish of JavaScript Runtime
process.nextTick(function(){
  console.log(order++, 'process.nextTick called');
});

myobj.hoge = 'deliverChanged';
myobj.emit('myevent', 'first event');
Object.deliverChangeRecords(callback);
myobj.emit('myevent', 'second event');
myobj.hoge = 'foo';

で、実行結果がこれです。

$ node --harmony test1.js
1 'myevent msg: first event emitted'
2 'Object.observed:' [ { type: 'add',
    object: { _events: [Object], hoge: 'deliverChanged' },
    name: 'hoge' } ]
3 'myevent msg: second event emitted'
4 'process.nextTick called'
5 'Object.observed:' [ { type: 'update',
    object: { _events: [Object], hoge: 'foo' },
    name: 'hoge',
    oldValue: 'deliverChanged' } ]
6 'setTimeout 0sec called'
7 'I/O callback(fs.stat)'
8 'setImmediate called'

結果を表にまとめるとこんな感じです。

機能 記述順 実行順
I/O callback(fs.stat) 1 7
setImmediate 2 8
setTimeout 3 6
process.nextTick 4 4
event emitter #1 5 1
Object.deliverChangeRecords 6 2
event emitter #2 7 3
Observed Object property の変更 8 5

3. コールバック起動の順番とイベントループの関係

個人的に予想したのは Object.observe()のコールバックの後に process.nextTickかなと思ったのですが違ってました。ソースを確認すると、メインモジュールの呼び出し・実行の最後に process.nextTick を呼び出していました。
https://github.com/joyent/node/blob/master/lib/module.js#L491-L492
また、Object.observe() のコールバックは JS の実行(Run)の最後に行われるので、メインモジュール実行完了後に起動されます。
図にするとこんな感じです。

まとめると、

  1. EventEmitter と Object.deliverChangeRecords() は、JSの実行中に同期的にコールバックが起動されるので書いた順番に依存します。テストスクリプトの出力は、イベントループの図「0:Load」で起動しています。
  2. process.nextTickはメインモジュールの読み込み・実行の最後やNodeのコールバック処理の最後で呼び出されるため、V8実行の最後の Object.observe()よりも前に起動される。
  3. その他のコールバック(Timer, SetImmediate, I/O)は libuv で実装されたイベントループの順番で起動される。

ということです。

あぁ、すっきりした。

Node.jsにPromiseが再びやって来た!

tl;dr

サンプルコードを付けたら記事がかなり長くなってしまったのでご注意下さい。
Node.jsの current master で V8がアップデートされ ES6の Promise が使えるようになりました(要オプションですが)。Promise を使うと Node.jsの非同期処理がどのようになるのか、Stream と Promise を組み合わせた使い方なども含めて紹介します。

1. はじめに

Nodeの次期安定版 v0.12は、すぐ出ると言われながら既に v0.10のリリースから1年が過ぎてしまいました。
現在、v0.12の主要な新機能の実装は完了していますが、まだ安定版のリリースに向けて手当できていない部分が残っている感じです。そんな残っている部分の一つだった V8 のアップデートが先週末に行われました。

現在の安定版 Node-v0.10.26 では、 V8 は 3.14.5 を利用しています。Node の安定版では、基本 V8 のバージョンアップは行わず、V8 に関してはバックポート等によるバグフィックス対応が中心です。Node-v0.10のリリース後、V8のAPI仕様が大幅に変更されたので、それに対応するためNodeの中身は大きく変わっています。(合わせて multi context対応もやっています)

そんなこともあり、開発版では長らく3.22が使われていましたが、最近になって 3.24に上がりました。これまでにも、安定版リリース直前によくV8のバージョンを上げたり下げたりしますので、今回も実は0.12リリース直前の予兆かもしれません。

この V8 Ver. 3.24で何がいいかというと、個人的には ES6 で現在仕様検討中の Promise が使えるようになったことです。実は昔の Node では Promise が独自実装されていました。4年ほど前に議論の末 deprecate されたのですが、今回ES6で検討中で PromiseA+ 仕様をベースとしたV8の機能となって Promise が再登場です。

ブラウザでは昨年11月ぐらいから利用できていて、今手元の Google Chrome(33.0.1750.154)は、 V8 3.23.17.23 なのでおそらく次の M34 (現beta or Dev?)から Promise が使えるようになるんじゃないかと思います。(ChromeでES6系の機能を利用するには、chrome://flags で「JavaScript の試験運用機能を有効にする」を指定しておくことが必要です。)

Promiseについては下記記事が詳しいのでここでは説明しません。(ちなみに PromiseA+仕様策定の中心人物 Domenic Denicola さんは、Node-v0.12で入る新VMモジュールの作者でもあります。)

また Node での ES6系機能の扱いは下記記事を参照するとよいでしょう。

2. 早速 Node で Promiseを使ってみる

まだ github の master ブランチにしかないので自分でビルドしてみましょう。NodeとV8のバージョンを確認します。

$ node -v
v0.11.13-pre
$ node -e 'console.log(process.versions.v8)'
3.24.35.17

まずは Promise がちゃんと動作するかの確認です。ファイルの stat を取る非同期処理で試してみます。

// 引数で指定したファイルの確認を Promise で処理するサンプル promise_sample1.js
var fs = require('fs');
var file = process.argv[2] || __filename;
var promise = new Promise(function(onFulfilled, onRejected) {
  fs.stat(file, function(err, stat) {
    // return stat object when fulfilled
    err ? onRejected(err) : onFulfilled(stat);
  });
});
// 正常処理なら onFulfilled, エラーなら onRejected が実行される
promise.then(
  function(stat) {
    console.log('Fulfilled:', file, stat);
  },
  function(error) {
    console.log("Rejected:", error.message);
  }
);

で実行してみます。

# ファイルが存在している時
$ node --harmony promise_sample1.js  promise_sample2.js
Fulfilled: promise_sample2.js { dev: 64512,
  mode: 33204,
(中略)
  ctime: Tue Mar 18 2014 15:26:45 GMT+0900 (JST),
  birthtime: Tue Mar 18 2014 15:26:45 GMT+0900 (JST) }

# ファイルが存在していない時
$ node --harmony promise_sample1.js  hoge.txt
Rejected: ENOENT, stat 'hoge.txt'

おぉ、ちゃんと動きました。ではもうちょっと応用を。

3. thenable を使ってみる

thenableというのは、then()メソッドを持つ普通の(Promiseでない)オブジェクトの事です。
PromiseA+仕様では、なんとこの thenableからPromiseオブジェクトを生成できるのです。素晴らしい。

早速 thenable を試しましょう。

サンプルとして静的ファイルを出力するHTTPサーバを作ります。登録されたmimeタイプを持つファイルにアクセスしたらそれを出力、そうでなければ404を返します。HTTPサーバのリクエストオブジェクトを thenable にして、非同期のエラー処理を Promiseで行います。
ここでは、Promise.resolve()というクラスメソッドを用いて thenable から Promiseオブジェクトを生成します。

// Promiseを使って静的ファイルを出力するHTTPサーバのサンプル promise_sample2.js
var path = require('path');
var http = require('http');
var fs = require('fs');
// List of valid file extensions
var mime_type = {'.txt': 'text/plain', '.html': 'text/html', '.png': 'image/png'};

// http.Server のrequestオブジェクトを thenable にする
http.IncomingMessage.prototype.then = function(onFulfilled, onRejected) {
  var mime = mime_type[path.extname(this.url)];
  if (!mime) { // extensin check
    onRejected(new Error('Invalid extension'));
    return;
  }
  fs.readFile('./public' + this.url, function(err, data) {
    err ? onRejected(err): onFulfilled({data: data, mime: mime});
  });
};

var server = http.createServer(function(req, res) {
  var p = Promise.resolve(req); // thenableからPromiseを生成
  p.then(
    function(x) { // 静的ファイルの出力
      res.writeHead(200,
        {'content-type': x.mime, 'content-length': x.data.length});
      res.end(x.data);
    },
    function(err) { // エラーページ処理
      res.writeHead(404);
      res.end('Not Found');
    }
  );
}).listen(8080);

実際試してみるとちゃんと動作しました。 thenableが使えると既存のコードとPromiseの親和性が増します。

4. Promise.all による非同期処理の結合

Promiseを使う醍醐味の一つは、複数の非同期処理の一括取りまとめ処理です。
Nodeのコードを書く際に嫌われている、いわゆる「コールバック地獄」を避けることができます。Promise.allを使い、プロミスオブジェクトのリストを渡すと全部の正常処理が完了した処理が書けるのです。
通常Nodeだと、

fs.readdir(dir1, function(...) {
   fs.readFile(file1, function(...) {
     hash.update(data);
     fs.readdir(dir2, function(...) {
       fs.readFile(file2, function(...) {
          ...
       });
     });   
  });
});

の用にコールバック(地獄)処理をつらつら書き続けないといけないのですが、Promise を使うとこうなります。

function compareDirHash(dir1, dir2) {
  return compareFilesPromise(dir1, dir2).then(function(files) {
    return Promise.all(files.map(function(f) {
      return compareHashPromise(dir1, dir2, f);
    }));
  }).then(
    function(x) {
      // 正常処理
    },
    function(err) { // all case of errors
      // エラー処理
    }
  );
}
compareDirHash('./dir1/', './dir2/');

Promiseを使う方針としては、各処理を行う Promiseオブジェクトを返す関数を作り、最後に Promise.allで取りまとめるやり方です。
Promise.allを使う際には、Array.map を使ってプロミスオブジェクトのリストを生成するととても便利です。
こういったやり方は、Promise Anti-patternsを見ると参考になります。

// 2つのディレクトリ中の全てのファイルハッシュ値を比較するサンプル promise_sample3.js
var fs = require('fs');
var crypto = require('crypto');

// ディレクトリ中のファイルリストを取得する Promise処理
function readDirPromise(dir) {
  return new Promise(function(onFulfilled, onRejected) {
    fs.readdir(dir, function(err, files) {
      err ? onRejected(err): onFulfilled(files);
    });
  });
}
// dir1 と dir2 のファイルリストを比較する Promise 処理
function compareFilesPromise(dir1, dir2) {
  return new Promise(function(onFulfilled, onRejected) {
    Promise.all([
      readDirPromise(dir1),
      readDirPromise(dir2)
    ]).then(
      function(x) { // contains file lists in two directory
        var check = (x[0].length === x[1].length) &&
                    (x[0].sort().join() === x[1].sort().join());
        check ? onFulfilled(x[0]): onRejected(new Error('file lists are inconsist.'));
      },
      function(err) { onRejected(err);}
    );
  });
}
// ファイルの sha1 ハッシュを取得する Promise処理
function hashPromise(filename) {
  return new Promise(function(onFulfilled, onRejected) {
    var hash = crypto.createHash('sha1');
    var s = fs.createReadStream(filename);
    s.pipe(hash);
    s.on('error', function(err) {
      onRejected(err); // Hash calclation error
    });
    s.on('end', function() {
      onFulfilled(hash.read().toString('hex'));
    });
  });
}
// dir1 と dir2 中のファイルのハッシュ値を比較する Promise処理
function compareHashPromise(dir1, dir2, file) {
  return new Promise(function(onFulfilled, onRejected) {
    Promise.all([
      hashPromise(dir1 + file),
      hashPromise(dir2 + file)
    ]).then(
      function(x) { // contains has hash data list of two files
        x[0] === x[1] ? onFulfilled(x[0]): onRejected(new Error('hashes are inconsistent.'));
      },
      function(err) {
        onRejected(err);
      }
    );
  });
}
// dir1 と dir2 中の全てのファイルのハッシュ値を比較する Promise処理
function compareDirHash(dir1, dir2) {
  return compareFilesPromise(dir1, dir2).then(function(files) {
    return Promise.all(files.map(function(f) { // ハッシュ比較のPromiseオブジェクトを配列にして Promise.all に渡す
      return compareHashPromise(dir1, dir2, f);
    }));
  }).then(
    function(x) { // contains hash list of all files
      console.log('Success:', dir1, dir2, 'Hashes of all files are equal.');
    },
    function(err) { // all case of errors
      console.log('Error:', dir1, dir2, err.message);
    }
  );
}
// テストの実行 dir1 に9個のテキストファイル(hoge[1-9].txt)を格納
compareDirHash('./dir1/', './dir2/'); // dir1とdir2は全部一致
compareDirHash('./dir1/', './dir3/'); // dir3で1つファイルを削除
compareDirHash('./dir1/', './dir4/'); // dir4で1つファイルを変更 
compareDirHash('./dir1/', './not_exist_dir/'); // 存在していないディレクトリを指定

実行結果です。エラー処理もちゃんと動いてうれしい。

$ node --harmony promise_sample3.js
Error: ./dir1/ ./dir3/ file lists are inconsist.
Error: ./dir1/ ./not_exist_dir/ ENOENT, readdir './not_exist_dir/'
Success: ./dir1/ ./dir2/ Hashes of all files are equal.
Error: ./dir1/ ./dir4/ hashes are inconsistent.

5. Node の Stream と Promise を組み合わせて利用する

実はちょっと前に @azu_re さんよりStreamの宿題をいただいており、その中に「StreamとPromise」がテーマとして挙げられていました。初っ端から大物テーマですが、タイミングがいいので取り組んでみます。
・・・
とはいうものの、なかなかこれだというのが思いつかないです。

Generator と同じく Promise を使いこなすには、かなり頭の体操が必要です。でもあまり時間もかけてられないので、ボツネタ2個と採用ネタ1つで許してください。
誰か Stream と Promise の素晴らしい使い方を思いついたら教えて欲しいです。

5.1 Streams API 風に使う(ボツネタ)

WHATWG/W3Cで現在仕様化が進められている Streams API を参考にしてみます。
これは Promise かつ Stream の両方を兼ね備えたナイスなAPIです。この仕様の example に書いてあるよう、streamデータの読み込みを Promiseを使って再帰的に処理することが可能です。

function ReadStream() {
  stream.read().then(
    function(data) {
       data処理 ...
       ReadStream();
    },
    function(err) {
       エラー処理 ...
    }
  );
}
ReadStream();

実際にサンプルコードを書いたのですが、Nodeでは readable イベントや data イベントでデータ読み込み処理ができるので、こういう方法はあまりメリットがないかなぁと思い、ボツにしました。

5.2 Streamのエラー処理に(ボツネタ)

Promise は catch で個別にエラーハンドリングができるので、これ使って

  stream1.catch(function(err){...}).pipe(stream2).catch(function(err){...}).pipe(stream3) ...

な感じに書けるのがいいんじゃないかと。でも on('error', function(err){}) と同じなのでボツ。

5.3 複数の Piped Stream 処理の結合(採用ネタ)

やっぱりこれでしょ。複数同時に pipe でつないだストリームをガッチャンコするために Promise を使うやり方です。

var pipe1 = stream11.pipe(stream12).pipe(stream13);
var pipe2 = stream21.pipe(stream22).pipe(stream23);
Promise.all([pipe1, pipe2]).then(
  function(result) {
    // 結合時の成功処理
  },
  function(err) {
    // エラー処理
  }
);

な感じに書ければ最高です。endイベントに合わせて Promise 状態をFulfillにしてやればいいでしょう。

以下サンプルコードです。長いので興味のある方以外は読み飛ばして結構です。

サンプルコードでは、簡単のためストリームソースとして object stream を扱います。プロパティ値を1倍、10倍、100倍にするtransform stream と1足す、10足す、100足すtransform stream を別々に処理して最後に値を合わせます。
作る際にちょっと苦労した点は以下の3点です。

  1. TransformストリームとPromiseを多重継承したオブジェクトは作れないのでpromiseを内部に埋め込んだ。(mix-inも試しましたがコンストラクタが instance of をチェックしているので断念しました)
  2. error は pipe で伝搬しないので、独自に promise_err イベントを作って、最後のストリームまで伝搬させました。(5.2みたいに個別 catchもありですけど)
  3. stream はデータを取り出してやらないと end しないので、 consume() メソッドを最後につけました。
var util = require('util');
var Transform = require('stream').Transform;

// Base Class of Transform which contains promise
function TransformPromise(manupilate, options) {
  Transform.call(this, options);
  this._writableState.objectMode = true;
  this._readableState.objectMode = true;
  this.bufs = []; // all filtered data stored
  var self = this;
  // for propagation promise_err to pipe end
  this.on('pipe', function(src) {
    src.on('promise_err', function(err) {
      self.emit('promise_err', err);
    });
  });
  // promise fullfilled in 'end' and rejected in 'promise error'
  this.promise = new Promise(function(onFulfilled, onRejected) {
    self.on('end', function() {
      onFulfilled(self.bufs); // return all data
    });
    self.on('promise_err', function(err) {
      onRejected(err);
    });
  });
}
util.inherits(TransformPromise, Transform);

// data consuming to store data and emit 'end' event
TransformPromise.prototype.consume = function() {
  this.on('readable', function() {
    var b = this.read();
    if (b) this.bufs.push(b);
  });
  return this;
};

// all values in object stream are multiplied
function Multiply(multiple, options) {
  TransformPromise.call(this, options);
  this.multiple = multiple || 1;
}
util.inherits(Multiply, TransformPromise);
Multiply.prototype._transform = function(chunk, encoding, cb) {
  var out =  {};
  for(var key in chunk) {
    if (!checkProperty(this, chunk[key])) break;
    out[key] = this.multiple * chunk[key];
  }
  this.push(out);
  cb();
};

// all values in object stream are incremented
function Plus(plus, options) {
  TransformPromise.call(this, options);
  this.plus = plus || 0;
}
util.inherits(Plus, TransformPromise);
Plus.prototype._transform = function(chunk, encoding, cb) {
  var out = {};
  for(var key in chunk) {
    if (!checkProperty(this, chunk[key])) break;
    out[key] = chunk[key] + this.plus;
  }
  this.push(out);
  cb();
};

var multi1 = new Multiply(1);     // *1 filter
var multi10 = new Multiply(10);   // *10 filter
var multi100 = new Multiply(100); // *100 fiter

var plus1 = new Plus(1);          // +1 filter
var plus10 = new Plus(10);        // +10 filter
var plus100 = new Plus(100);      // +100 filter

// filtered to vaule*1*10*100
var pipe1 = multi1.pipe(multi10).pipe(multi100).consume();
// filtered to value+1+10+100
var pipe2 = plus1.pipe(plus10).pipe(plus100).consume();

// two streams meets when both are fulfilled
Promise.all([pipe1.promise, pipe2.promise]).then(function(x) {
  var result = concatArrayElm(x[0], x[1]);
  console.log(result);
}).catch(function(err) {
  // catch all promise_errors
  console.log('Error:', err.message);
});

// data source of object stream
var source = [{a:1, b:2, c:3}, {d:4, e:5}, {f:6}];
// var source = [{a:1, b:2, c:3}, {d:4, e:'5'}, {f:6}]; // for error test

// write data to two streams;
source.forEach(function(elm) {
  multi1.write(elm);
  plus1.write(elm);
});

// finish writing
multi1.end();
plus1.end();

// check the property values if they are number
function checkProperty(self, value) {
  if(typeof value === 'number') {
    return true;
  } else {
    self.emit('promise_err', new Error(value + ' is not a number.'));
    return false;
  }
}

// final result is concated each values in two streams
function concatArrayElm(ar1, ar2) {
  if (ar1.length !== ar2.length) {
    throw new Error('source length is inconsistent.');
    return;
  }
  var ret = [];
  for(var i = 0; i < ar1.length; i++) {
    var obj = {};
    for(var key in ar1[i]) {
      obj[key] = ar1[i][key] + ar2[i][key];
    }
    ret.push(obj);
  }
  return ret;
}

で、実行結果。

# 正常時
$ node --harmony promise_sample5.js
[ { a: 1112, b: 2113, c: 3114 },
  { d: 4115, e: 5116 },
  { f: 6117 } ]
# エラー時
$ node --harmony promise_sample5.js
Error: 5 is not a number.

Generator とも組み合わせて考えるともっと面白いことができるかもしれません。今後に期待です。

Firefox NightlyでHTTP/2を試す方法

(注) 2014/3/27の Nightly より draft-10 (h2-10)対応になりました。

ちょっと前からですが、Firefox の Nightly ビルドで HTTP/2 が試験的に使えるようになりました。

Bug 950768 - Land http/2 draft08 pref'd off in mozilla-central

これまでは tryサーバでビルドしたものを置いてもらいダウンロードしていたんですが、開発担当の Patrick McManus さん曰く、もう面倒になったんで入れちゃったらしいです。

そこでテスト用にHTTP/2を利用したい方向けに、私が普段HTTP/2のテストをする手順通り Firefox Nightly を使って HTTP/2 の動作確認する方法を記載しておきます。

注意事項:

  • Nightly ビルドの動作は不安定な場合もあります。テスト以外には使わないでください。
  • 2014年2月12日時点での動作挙動をもとにしています。 将来HTTP/2のドラフト更新によって動作が変わる場合があります。(twitterのサーバ挙動も)
  • その他本記事を試して発生した不具合については保証しかねますので、試す場合は自己責任でお願いします。

1. Firefox Nightly Buildの入手

http://nightly.mozilla.org/
から記載の指示に従ってFirefox Nightlyを入手します。(注意事項が記載されていればよく読んでください)

2. Firefox Nightly で HTTP/2 と ALPN の機能を有効化する。

about:config で network.http.spdy.enabled.http2draft と security.ssl.enable_alpn の値を true に変更します(下図)。

3. (お好みで) プロファイルを切り替えて起動

私は普段Win上で Firefox を使っているので、オプションを指定してNightly 用にdefaultとは別のプロファイルに切り替えて起動しています。お好みでどうぞ。

"C:\Program Files (x86)\Nightly\firefox.exe" -no-remote -P "Nightly"

4. HTTP/2の動作確認

2014年2月12日現在 twitter が本番環境で HTTP-draft-09/2.0 対応していますので、twitter にアクセスして Firefox が HTTP/2 でアクセスしているか確認します。
ただ、そのままでは見た目で全く判別ができないので、 F12 を押して開発コンソールのネットワークでHTTPのレスポンスを確認します。
下図の通り、Version が HTTP/2 になっていて、 X-Firefox-Spdy ヘッダが HTTP/2 の Version Identification を出力していれば動作確認完了です。

他にも https://github.com/http2/http2-spec/wiki/Implementations のリスト中で動作しているHTTP/2サーバがあれば、そちらも試してみればよいでしょう。

SPDYとLinuxの間でGoogleマップがハマった落とし穴

tl;dr

書いていたら思わず長文の大作になってしまいましたので、プロトコルオタ以外の方は文章の多さに退屈されるかと思います。GoogleマップサービスでSPDYの問題が発覚し、GoogleLinuxカーネルに修正を加えて対応したというお話です。将来 Linux + nginx + SPDY を使いリバースプロキシでサービス運用を検討されている方は参考になるかもしれません。

1. はじめに、

プロトコルに執着する年寄りエンジニアの老害が叫ばれて久しい。

年甲斐もなく自分好みのパケットを追っかけるおやじエンジニアの姿を見て眉をひそめる若者も多いと聞く。
そんな批判に目もくれず、今日も一つ、プロトコルオタのネタをブログで公開したいと思いますw

今回はちょうど1年ほど前に書いたブログ記事 「GmailがハマったSPDYの落とし穴」の続編です。といっても今度の舞台は、Googleマップ。ネタ元も同じ Google の Will. Chan のブログ "Prioritization Only Works When There's Pending Data to Prioritize" から取っています。

事の発端は、Googleマップチームの担当者が新バージョンのサイトを試したところ、地図のタイル情報がミニマップの画像データより遅れて受信することがあるとの指摘からでした。

地図のタイル情報は、Googleマップのユーザ体感を高速化するためミニマップの画像データよりできるだけ早く受信することが求められます。SPDYは、0から7まで8段階の優先度設定ができます。Chromeでは、タイル情報は Ajax を利用して優先度2、画像データは優先度3、に指定してリクエストを送っているはずです。しかしGoogleマップチームがGFE(Google Front End)サーバから返ってくるレスポンスを見ると、SPDYの優先度指定が全く反映されていないことが発覚。実際にその試験データが示されて Will. Chan の調査が始まりました。

2. Googleサービスのシステム構成

まずGoogleサービスのシステム構成の概要とSPDY優先度の機能の関係について説明します。W Chan のブログでは、笑えることに自社サービスをスノーデンがNSAから漏洩させたシステム図を引用して説明してたりします。(図1)

GFEは Google Front End の略でクライアントからのSSL接続の終端をします。Googleサービスは外向けにほとんどSSL+SPDY対応になっていますので、GFEでSSL+SPDYのリクエストを処理して、各種サービス向けのバックエンドサーバにリクエストを投げています。NSAは、Googleデータセンター間の光ファイバー網を盗聴しているという暴露もありましたので、今ではきっとGoogle DC内のバックエンド通信もSSL化されているでしょう。

GFEの機能詳細は不明ですが、おそらく複数のバックエンドから各種レスポンスデータを受け取り、いろいろデータ処理した後にSPDYで指定された優先度順でクライアントにデータを送信するといった流れだと思われます。(図2.1, 図2.2)


今回の問題の指摘は、このGFEがSPDYの優先度を正しくハンドリングできていない可能性を疑わせるものでした。

3. Googleマップで起きていたSPDYの問題

Googleマップチームが検証したテストは、高速回線環境下と低速回線環境下の2通りで実施されています。そのどちらの測定結果も優先度が高いタイルデータより低い画像データが先に受信していることを示していました。高速回線環境でのテスト結果では、画像データの受信開始から70ミリ秒程度遅れてタイルデータの受信が始まっていました。しかしこのケースでの現象の説明は簡単です。

一般的にバックエンドサーバが扱うデータのサイズや処理の負荷などは様々で、画像配信を扱うバックエンドサーバの方がタイル配信を扱うバックエンドサーバより早くレスポンスを返す場合もあります。一方GFEは、優先度が高いデータの到着を待つことはなく、GFE内の処理が済み次第優先度の低いデータでも送信キュー入れ込みます。
高速回線環境下では短時間でデータがクライアント側に送られますので、その結果タイルデータがGFEに到着した時には時すでに遅く、画像データがクライアントに送信済になっていたということです。この場合SPDYの優先度に関係なく、先に到着したデータをクライアントに送信することになります。(図3.1)

しかし低速回線環境でのテストデータでは、画像ファイルの受信開始からなんと1.3秒後にタイルファイルの受信が始まったということを示していました。これは先のような説明がつきません。

もちろんバックエンドサーバ間でレスポンスの時間差は多少あるでしょうが、1秒以上の余裕があればGFEは全てのバックエンドからタイルデータの受信を完了しているはずです。そしてその時GFEは、まだクライアントへの画像データを送信している途中です。このテストデータから、GFEは優先度に関係なく先に届いたデータを送信しているように見えます。そうなるとGFEは、SPDYが指定した優先度のハンドリングができていないことになります。(図3.2)

4. 原因は Linux カーネルにあり

W. Chan は、SPDY仕様を作った Robert と GFE担当のGoogleで一番の"おしゃれ"と名高い Hasan と協力して原因が Linuxカーネルにあることを突き止めました。

GFEのSPDYサーバのプロセスは、クライアントへデータを送信する際、SPDYの優先度設定に従って(おそらくプライオリティキューを使い)カーネルのソケットにデータを書き込みます。書き込まれたデータは、Linuxカーネル内のソケットバッファに蓄えられ、順次クライアントへ送信されます。

ソケットバッファ内には、途中でロストした場合に備えて再送用に既に送信済のデータを保持しています。(ackが届いたら解放します) 他方ソケットバッファ内のデータは、一度に全部のデータを送信できるわけではなくまだ未送信のデータも一部残ります。この未送信のデータ少ないと、高速通信環境下ではウィンドウサイズが短時間に増加するので一時的に送信データが枯渇し、せっかくデータを送る余地があるのにデータが送れないといった状況が発生します。
そのため一般的にOSのカーネルは、送信パフォーマンスを最大化するためこの未送信のデータサイズを自動でチューニングして増加させています。そのサイズはLinuxのデフォルトでは無制限(0xFFFFFFFF)です。今回これが裏目に出ました。(図4)

低速環境下でこの未送信のデータサイズが大きいと、SPDYサーバのプロセスは、まだソケットバッファに余裕があると判断し、このデータが未送信状態で保持されるとも知らず送信データを次々とカーネルに書き込んでしまいます。その結果、先に届いた画像データは直ちにSPDYサーバプロセスの送信キューから吐き出され、タイルデータが届いた時には画像データは、すっかりソケットバッファ内に全部格納されてしまっていた状態だったのです。
こうなるとSPDYサーバプロセスは優先度の送信順番調整などできません。しかもTLSの暗号化処理がされた後では、送信データの順番の入れ替えなどできる余地は全くありません。よってタイルデータはいくら優先度が高くても、画像データが全部送信し終わるまでじっと送信を待たないといけなくなったのです。

5. Linux の新しいソケットオプション TCP_NOTSENT_LOWAT

これを解決する手段はさすがGoogleLinuxカーネルコミッタを揃えています。

ソケットバッファ内の未送信データサイズを指定する新たなソケットオプション "TCP_NOTSENT_LOWAT" を新たに導入しました。
このTCP_NOTSENT_LOWATの値を設定すると未送信のデータサイズを明示的に制限することができます。そのため、低速回線環境下でもカーネルに送信データを飲み込まれることなく、SPDYサーバプロセスが優先度に応じたデータ送信を制御できることになります。(図5)

高速回線環境下ではこのTCP_NOTSENT_LOWAT の値を大きく、低速回線環境下では TCP_NOTSENT_LOWAT の値を小さくすればいいのです。

この新ソケットオプション(TCP_NOTSENT_LOWAT)は既に Linuxカーネルにコミットされ、kernel-3.12 から利用することができます。Googleさん、めでたしめでたしです。

6. Googleマップ問題の再現と解決方法の検証

ここで単なるブログの紹介記事に終わらないのがプロトコルオタのおやじエンジニアです。実際にSPDY優先度とLinuxカーネルのソケットバッファの問題を再現して、TCP_NOTSENT_LOWATがどのように効くのか検証して見てみましょう。

検証環境は以下の通り SPDY/3.1に対応した新バージョンの nginx とバックエンドに Node.js の HTTPサーバを用いました。*1 Linuxの kernelは TCP_NOTSETN_LOWAT に対応した kernel-3.12.9 を利用しています。(図6)

Chrome は JSファイルのリクエストは優先度2、画像ファイルのリンクによるリクエストは優先度3になります。この2つのリンクを含むHTMLファイルにアクセスし、JSファイルはリクエストを受けてから 0.2秒後にレスポンスを返すように調整します。画像ファイルは待ちはありません。 サイズの影響をなくすため画像ファイルとJSファイルはほぼ同じサイズのファイルにしています。(JS中のコメントサイズを増やして調整しています。約700K)バックエンドサーバ用のNode.jsのコードを以下に示します。

/ Googleマップ問題再現用バックエンドサーバ
var http = require('http'),fs = require('fs');

// HTMLコンテンツ画像とJSファイルへのリンクのみ
var main_html = '<!DOCTYPE html><html>';
main_html += '<head><title>Test page</title></head>';
main_html += '<body>This is a test page.<div id="finish"></div>';
main_html += '<img src="photo.jpg">';
main_html += '<script src="foo.js"></script>';
main_html += '</body>';
main_html += '</html>';

// 遅延レスポンスを返す関数
function delayedResponse(res, type, length, content, delay) {
  setTimeout(function() {
    res.writeHead(200, {
      'content-type': type,
      'content-length': length
    });
    res.end(content);
  }, delay);
}

var jsfile = fs.readFileSync(__dirname + '/foo.js');
var photo = fs.readFileSync(__dirname + '/photo.jpg');
var server = http.createServer(function(req, res) {
  var ip = req.socket.remoteAddress;
  var now = (new Date()).toString();
  var url = req.url;
  var ua = req.headers['user-agent'];
  var remote_ip = req.headers['x-real-ip'];
  console.log(ip, now, url, ua, remote_ip);
  switch(url) {
    case '/photo.jpg': // 画像ファイルは即時レスポンスを返す
      res.writeHead(200, {
        'content-type': 'image/jpg',
        'content-length': photo.length
      });
      res.end(photo);
    break;
    case '/foo.js':
      var delay = 2 * 100; // JSファイルは 0.2秒後にレスポンスを返す
      delayedResponse(res, 'text/javascript', jsfile.length, jsfile, delay);
    break;
    default: // 上記以外のURLは常にHTMLファイルを返す
    res.writeHead(200, {
      'content-type': 'text/html',
      'content-length': Buffer.byteLength(main_html)
    });
    res.end(main_html);
  }

});

server.listen(8080, function() {
  console.log('Listening on 8080');
});

7. 検証結果

まずはSPDYのリクエストで優先度設定がきちんと設定されているかの確認です。 Chrome の SPDYセッション情報を見るとちゃんとJSファイルは優先度2、画像ファイルは優先度3が設定されています。(図7.1)しかもあえてハンデを付けて画像ファイルのリンクをJSファイルより前に記載しています。

何もソケットオプションを指定していない時の Chrome での受信リクエストタイムラインを示します。(図7.2)

クライアントとnginx間が高速であるので 0.2秒遅れてJSファイルのレスポンスが届く前に画像ファイルがクライアントに送信完了しています。Googleの高速化環境下の試験結果が再現されています。

続いて低速環境下での試験です。nginx上でtcを使って 128Kbps で 300msec 遅延のネットワークを人為的に設定してクライアントから接続します。結果は、次の図7.3です。

やっほ!低速環境下試験でGoogleマップ問題の再現ができました。JSファイルは画像ファイルの0.2秒遅延でレスポンスを返しているのですが、JSファイルがクライアントで受信するのは画像ファイルがほとんど受信した数秒後です。これはカーネルのソケットバッファ内の未送信データの影響によるものです。ただしこれは何回かリロードしてカーネルの自動チューニングが発生した後でないとこのようなタイムライにはなりませんでした。

次に新ソケットオプション TCP_NOTSENT_LOWAT を使ってみます。果たしてこれで無事問題が解消できるでしょうか? TCP_NOTSENT_LOWATを 128Kbyte の131072に設定してみます。タイムラインは次の図7.4です。

おぉ! すごい。ちゃんと 0.2秒後ぐらいに JSファイルの受信が始まって最終的に画像ファイルより先にJSファイルの受信が完了しています。これこそSPDY優先度処理の効果がテキメンに現れている状態です。まさしくTCP_NOTSENT_LOWATの設定が、ちゃんと有効な解決策であることを示しています。

8. どうやって決める? TCP_NOTSENT_LOWAT

さぁGoogleマップの問題を解決するには、この TCP_NOTSENT_LOWAT を適切に設定すれば良いと分かったのですが、それでは具体的にどんな値に設定すればいいでしょうか?
GoogleLinux Kernel エンジニアは、この値を余り小さくするとシステムコールを処理するコンテキストスイッチのオーバヘッドが増え、未送信データが枯渇し十分なTCPの送信スループが落ちる場合があると警告しています。

W. Chanがブログで書いているようクライアントのネットワーク環境に依存するんですが、いったいどうやって決めたらいいでしょうか。 ちょうど先日チューリッヒIETF httpbis WG の HTTP/2.0に関する中間会議があり W. Chan と直接会う機会がありましたので聞いてみました。

私:  「ブログに書いてあるTCP_NOTSENT_LOWATの値って簡単に決められないよね。」
Chan: 「そう、ネットワーク環境によって違うからちゃんとモニターして決めないと。」
私:  「Googleではどうしているの?」
Chan: 「データ送信キューの遅延をモニターして値を決めてるよ。」
私:  「えっ! どうやって? ユーザーランドからはそんなのわかんないよ。」
Chan: 「そりゃカーネルに手を入れて測定しているさ。」

さすがGoogle・・・

今回もパフォーマンスに問題が発生するとOSカーネルの変更まで巻き込んで対応してしまう、そんなGoogleのWeb高速化にかける意気込みみたいなものを感じました。
将来Linuxサーバの nginx を使ってSPDYのリバースプロキシ構成でサービス運用しようと計画されている方も多いかと思います。そんな時、ここで書いたSPDYの優先度と TCP_NOTSENT_LOWATの設定を頭の隅いれて運用しましょう。

*1:実は最初検証がうまくいかなかったのでいろいろ調べたところ nginx の SPDY/3.1実装に優先度値読み込みのバグがあることがわかりました。これを修正する1行パッチを送付したところすぐ採用され、直後に1.5.10がリリースされました。