HTTP/2 サーバープッシュ : H2OとRuby on Rails 5.2beta、HTTP 103 EarlyHintsでページ高速化

Ruby on Rails 5.2から、HTTP 103 Early Hintsによるサーバープッシュがサポートされるようになりました。
H2OとRuby on Rails 5.2beta0を使って、HTTP 103 Early Hintsの動作を確認してみます。
HTTP 103 Early Hintsの詳細については、HTTP の新しいステータスコード 103 Early Hints | blog.jxck.io
素晴らしい記事がありますので、そちらをご覧いただければと思います。

dockerでH2OとRuby on Railsの環境を構築

docker-composeを使って、H2OとRuby on Railsのコンテナを準備します。
H2Oのコンテナはlkwg82/h2o-http2-serverを、
Ruby on Rails用のコンテナはruby:2.4.2-alpine3.6をベースに作成しました。
EarlyHintsを利用するためにはRuby on Railsを動かすサーバーはpumaである必要がありますが、
Ruby on Rails 5からはデフォルトのサーバーがpumaになっているので、そのまま使用しています。

docker-compose.yml
version: '2'
services:
  rp:
    image: lkwg82/h2o-http2-server:v2.2.3
    working_dir: /etc/h2o
    command: h2o --conf conf/h2o.conf
    ports:
      - "443:443"
    volumes:
      - .:/app
      - ./docker/h2o/conf:/etc/h2o/conf
    depends_on:
      - web
    extra_hosts:
      - "${APP_HOST}:0.0.0.0"
  web:
    build: .
    command: bundle exec rails s -b 0.0.0.0 --early-hints
    volumes:
      - .:/app
    ports:
      - "3000:3000"

H2Oのコンテナの準備としては、.docker/h2o/confに以下のようなH2Oの設定ファイルとhttps接続に使用する秘密鍵とサーバー証明書を置いておきます。
hostnameのところは、docker-compose.ymlのextra_hostsで渡すホスト名と合わせます。本来はassets関係をH2Oから返すようにすべきだと思いますが、
今回は全てのリクエストをRuby on Railsが動いているwebのコンテナにプロキシする設定にしています。

h2o.conf
hosts:
  default_https:
    listen:
      host: yourhostname
      proxy-protocol: ON
      port: 443
      ssl:
        certificate-file: /etc/h2o/conf/fullchain.pem
        key-file: /etc/h2o/conf/key.pem
    paths:
      /:
        proxy.reverse.url: http://web:3000/

EarlyHintsはRuby on Rails 5.2beta以降の機能なので、GemfileのRailsのversion指定を5.2.0bataにしてbundle updateまたは、bundle install
を行います。

Gemfile
# frozen_string_literal: true
source "https://rubygems.org"

git_source(:github) {|repo_name| "https://github.com/#{repo_name}" }

gem "rails", "~> 5.2.0bata"
...

Ruby on Rails 5.2betaのインストールが終わったら、念のためrails serverコマンドのヘルプを確認してみます。

$ docker-compose run --rm web bin/rails s -h
Usage:
  rails server [puma, thin etc] [options]

Options:
  -p, [--port=port]                        # Runs Rails on the specified port - defaults to 3000.
  -b, [--binding=IP]                       # Binds Rails to the specified IP - defaults to 'localhost' in development and '0.0.0.0' in other environments'.
  -c, [--config=file]                      # Uses a custom rackup configuration.
                                           # Default: config.ru
  -d, [--daemon], [--no-daemon]            # Runs server as a Daemon.
  -e, [--environment=name]                 # Specifies the environment to run this server under (development/test/production).
  -P, [--pid=PID]                          # Specifies the PID file.
                                           # Default: tmp/pids/server.pid
  -C, [--dev-caching], [--no-dev-caching]  # Specifies whether to perform caching in development.
      [--early-hints], [--no-early-hints]  # Enables HTTP/2 early hints.

一番下にEarly Hintsに関する説明がありますね。上記のdocker-compose.ymlのcommandの記述もそのように書いていますが、
サーバー起動時のオプションとして--early-hintsのオプションを渡すことで有効になります。

検証

H2OとRuby on Rails 5.2beta0でEarlyHintsを試す環境を構築できたので、nghttpsとchromeでどのような振る舞いをするか確認してみます。

nghttp2の確認

nghttp2でサーバーにアクセスして、動作を確認します。

root@aws.local:~# nghttp https://yourhostname -ns

...

id  responseEnd requestStart  process code size request path
  2    +30.44ms *   +30.38ms     63us  200  12K /assets/index.self-0397218313f0bf485bad06248f5edee9d90cf44ff8df81140667ee9bd2dabd3d.css?body=1
  4    +33.47ms *   +33.45ms     22us  200    0 /assets/page.self-e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855.css?body=1
  6    +37.19ms *   +37.16ms     22us  200    0 /assets/ranking.self-e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855.css?body=1
 10    +40.66ms *   +40.65ms     13us  200    0 /assets/top.self-e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855.css?body=1
 12    +45.70ms *   +45.68ms     22us  200  676 /assets/application.self-f0d704deea029cf000697e2c0181ec173a1b474645466ed843eb5ee7bb215794.css?body=1
  8    +48.09ms *   +40.63ms   7.46ms  200   1K /assets/reset.self-649fc63ac67dcbc63fc475b131dccd66ca88da93e36e89561e590e06c60b66a8.css?body=1
 14    +52.59ms *   +50.80ms   1.79ms  200  84K /assets/jquery-3.2.1.min.self-5c2148f394c0d0085e316066a9ec847d1d5335885c0ab4a32480ad882998ed3f.js?body=1
 16    +54.20ms *   +52.56ms   1.64ms  200  16K /assets/underscore-min.self-8c17561264389571750ac522c272868d7105cf5e3f8af4761d09489b631d177c.js?body=1
 18    +57.30ms *   +57.03ms    275us  200  41K /assets/index.self-f96b375198e843bd72a908a58a9ff3dd892431607f77986dbd3838ca78f43257.js?body=1
 20    +60.58ms *   +60.55ms     21us  200  634 /assets/application.self-eba3cb53a585a0960ade5a8cb94253892706bb20e3f12097a13463b1f12a4528.js?body=1
 13   +138.58ms        +47us 138.53ms  200  31K /

「/」のパスのコンテンツを受け取る前に複数のassets(stylesheet_link_tagとjavascript_include_tagに記述されているもの)が受信できていることが確認できます。
requestStartの項目の前に「*」が付いているものが、サーバーからプッシュされていることを示しています。
「/」のresponseEndよりも、その他のコンテンツのresponseEndの方が早いので、「/」のコンテンツを受け取る際にはページのレンダリングに必要なコンテンツが
全てそろっている状態になり、40ms程度はページのレンダリング開始が早くなっているとこの例では言えると思います。

次にRuby on Railsのbefore actionとafter_actionで処理を加えて、どのような動作をするか確認してみます。
before_actionに処理を加えたときの結果は以下のようになりました。

my_controller.rb
class MyController < ApplicationController

  before_action :wait

  def wait
    sleep 1
  end

  def index
...
  end
end
id  responseEnd requestStart  process code size request path
  2      +1.03s *     +1.03s     81us  200  12K /assets/index.self-0397218313f0bf485bad06248f5edee9d90cf44ff8df81140667ee9bd2dabd3d.css?body=1
  4      +1.04s *     +1.04s     25us  200    0 /assets/page.self-e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855.css?body=1
  6      +1.04s *     +1.04s     46us  200    0 /assets/ranking.self-e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855.css?body=1
 10      +1.04s *     +1.04s     12us  200    0 /assets/top.self-e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855.css?body=1
 12      +1.05s *     +1.05s     33us  200  676 /assets/application.self-f0d704deea029cf000697e2c0181ec173a1b474645466ed843eb5ee7bb215794.css?body=1
  8      +1.05s *     +1.04s   8.24ms  200   1K /assets/reset.self-649fc63ac67dcbc63fc475b131dccd66ca88da93e36e89561e590e06c60b66a8.css?body=1
 14      +1.05s *     +1.05s   1.20ms  200  84K /assets/jquery-3.2.1.min.self-5c2148f394c0d0085e316066a9ec847d1d5335885c0ab4a32480ad882998ed3f.js?body=1
 16      +1.06s *     +1.06s     63us  200  16K /assets/underscore-min.self-8c17561264389571750ac522c272868d7105cf5e3f8af4761d09489b631d177c.js?body=1
 18      +1.08s *     +1.08s    133us  200  41K /assets/index.self-f96b375198e843bd72a908a58a9ff3dd892431607f77986dbd3838ca78f43257.js?body=1
 20      +1.08s *     +1.08s     20us  200  634 /assets/application.self-eba3cb53a585a0960ade5a8cb94253892706bb20e3f12097a13463b1f12a4528.js?body=1
 13      +1.16s        +52us    1.16s  200  31K /

requestStartが1秒近く+された状態になります。EarlyHintsはbefore_actionの後に返されることが分かります。
after_actionで処理を加えた場合でも計測してみました。

my_controller.rb
class MyController < ApplicationController

  after_action :wait

  def wait
    sleep 1
  end

  def index
...
  end
end
id  responseEnd requestStart  process code size request path
  2    +31.81ms *   +31.73ms     78us  200  12K /assets/index.self-0397218313f0bf485bad06248f5edee9d90cf44ff8df81140667ee9bd2dabd3d.css?body=1
  4    +35.06ms *   +35.04ms     17us  200    0 /assets/page.self-e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855.css?body=1
  6    +39.06ms *   +39.04ms     22us  200    0 /assets/ranking.self-e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855.css?body=1
 10    +42.64ms *   +42.62ms     26us  200    0 /assets/top.self-e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855.css?body=1
 12    +49.31ms *   +49.29ms     19us  200  676 /assets/application.self-f0d704deea029cf000697e2c0181ec173a1b474645466ed843eb5ee7bb215794.css?body=1
  8    +50.70ms *   +42.60ms   8.09ms  200   1K /assets/reset.self-649fc63ac67dcbc63fc475b131dccd66ca88da93e36e89561e590e06c60b66a8.css?body=1
 14    +54.85ms *   +53.41ms   1.45ms  200  84K /assets/jquery-3.2.1.min.self-5c2148f394c0d0085e316066a9ec847d1d5335885c0ab4a32480ad882998ed3f.js?body=1
 16    +56.84ms *   +54.65ms   2.18ms  200  16K /assets/underscore-min.self-8c17561264389571750ac522c272868d7105cf5e3f8af4761d09489b631d177c.js?body=1
 18    +59.94ms *   +59.72ms    218us  200  41K /assets/index.self-f96b375198e843bd72a908a58a9ff3dd892431607f77986dbd3838ca78f43257.js?body=1
 20    +63.44ms *   +63.42ms     18us  200  634 /assets/application.self-eba3cb53a585a0960ade5a8cb94253892706bb20e3f12097a13463b1f12a4528.js?body=1
 13      +1.14s        +49us    1.14s  200  31K /```

responseEndが1秒を超えているのに対し、requestStartは数十ms程度になっています。
この結果からEarlyHintsはafter_actionの前、つまりrenderメソッドが実行された後に返されていることが分かります。
本番環境ではcss,jsともに1ファイルにまとめられていると思いますし、renderメソッドが実行されてクライアントにhtmlが渡らなければ、
ブラウザでコンテンツを見ることが出来ないので、renderメソッドの実行後にEarlyHintsが返る形でも表示速度への恩恵は十分にありそうです。

Chromeでの確認

Chromeからはどう見えるのかを検証してみました。
下記の画像が--early-hintsありでRuby on Railsのサーバーを
立ち上げた状態でChrome developer toolsのNetworkを計測した
スクリーンショットです。

enable_early_hints.PNG

InitiatorのところにPush/(index)と表示されていて、Early Hintsに基づいてコンテンツがpushされていることがわかります。
このアクセスのサーバー側のログは以下になります。

14.11.212.160 - -  2017/12/02:23:37:18.225 "GET /assets/index.self-0397218313f0bf485bad06248f5edee9d90cf44ff8df81140667ee9bd2dabd3d.css?body=1 HTTP/2" 200 12619 "Mozilla/5.0 (iPhone; CPU iPhone OS 9_1 like Mac OS X) AppleWebKit/601.1.46 (KHTML, like Gecko) Version/9.0 Mobile/13B143 Safari/601.1" "-" 0.002542
14.11.212.160 - -  2017/12/02:23:37:18.228 "GET /assets/page.self-e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855.css?body=1 HTTP/2" 200 0 "Mozilla/5.0 (iPhone; CPU iPhone OS 9_1 like Mac OS X) AppleWebKit/601.1.46 (KHTML, like Gecko) Version/9.0 Mobile/13B143 Safari/601.1" "-" 0.001462
14.11.212.160 - -  2017/12/02:23:37:18.233 "GET /assets/reset.self-649fc63ac67dcbc63fc475b131dccd66ca88da93e36e89561e590e06c60b66a8.css?body=1 HTTP/2" 200 1916 "Mozilla/5.0 (iPhone; CPU iPhone OS 9_1 like Mac OS X) AppleWebKit/601.1.46 (KHTML, like Gecko) Version/9.0 Mobile/13B143 Safari/601.1" "-" 0.001724
14.11.212.160 - -  2017/12/02:23:37:18.231 "GET /assets/ranking.self-e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855.css?body=1 HTTP/2" 200 0 "Mozilla/5.0 (iPhone; CPU iPhone OS 9_1 like Mac OS X) AppleWebKit/601.1.46 (KHTML, like Gecko) Version/9.0 Mobile/13B143 Safari/601.1" "-" 0.004803
14.11.212.160 - -  2017/12/02:23:37:18.236 "GET /assets/top.self-e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855.css?body=1 HTTP/2" 200 0 "Mozilla/5.0 (iPhone; CPU iPhone OS 9_1 like Mac OS X) AppleWebKit/601.1.46 (KHTML, like Gecko) Version/9.0 Mobile/13B143 Safari/601.1" "-" 0.001469
14.11.212.160 - -  2017/12/02:23:37:18.238 "GET /assets/application.self-f0d704deea029cf000697e2c0181ec173a1b474645466ed843eb5ee7bb215794.css?body=1 HTTP/2" 200 676 "Mozilla/5.0 (iPhone; CPU iPhone OS 9_1 like Mac OS X) AppleWebKit/601.1.46 (KHTML, like Gecko) Version/9.0 Mobile/13B143 Safari/601.1" "-" 0.001873
14.11.212.160 - -  2017/12/02:23:37:18.245 "GET /assets/underscore-min.self-8c17561264389571750ac522c272868d7105cf5e3f8af4761d09489b631d177c.js?body=1 HTTP/2" 200 16450 "Mozilla/5.0 (iPhone; CPU iPhone OS 9_1 like Mac OS X) AppleWebKit/601.1.46 (KHTML, like Gecko) Version/9.0 Mobile/13B143 Safari/601.1" "-" 0.002946
14.11.212.160 - -  2017/12/02:23:37:18.251 "GET /assets/application.self-eba3cb53a585a0960ade5a8cb94253892706bb20e3f12097a13463b1f12a4528.js?body=1 HTTP/2" 200 634 "Mozilla/5.0 (iPhone; CPU iPhone OS 9_1 like Mac OS X) AppleWebKit/601.1.46 (KHTML, like Gecko) Version/9.0 Mobile/13B143 Safari/601.1" "-" 0.013023
14.11.212.160 - -  2017/12/02:23:37:18.242 "GET /assets/jquery-3.2.1.min.self-5c2148f394c0d0085e316066a9ec847d1d5335885c0ab4a32480ad882998ed3f.js?body=1 HTTP/2" 200 86660 "Mozilla/5.0 (iPhone; CPU iPhone OS 9_1 like Mac OS X) AppleWebKit/601.1.46 (KHTML, like Gecko) Version/9.0 Mobile/13B143 Safari/601.1" "-" 0.022530
14.11.212.160 - -  2017/12/02:23:37:18.249 "GET /assets/index.self-f96b375198e843bd72a908a58a9ff3dd892431607f77986dbd3838ca78f43257.js?body=1 HTTP/2" 200 42540 "Mozilla/5.0 (iPhone; CPU iPhone OS 9_1 like Mac OS X) AppleWebKit/601.1.46 (KHTML, like Gecko) Version/9.0 Mobile/13B143 Safari/601.1" "-" 0.016336
14.11.212.160 - -  2017/12/02:23:37:18.211 "GET / HTTP/2" 200 32518 "Mozilla/5.0 (iPhone; CPU iPhone OS 9_1 like Mac OS X) AppleWebKit/601.1.46 (KHTML, like Gecko) Version/9.0 Mobile/13B143 Safari/601.1" "-" 0.060606

一番最初にアクセスされた「/」に対するGETリクエストよりも先にpushされた
コンテンツのログが先に出力されているところに特徴があります。

--early-hintsオプションなしの状態でのブラウザアクセス時のスクリーンショット
は以下になります。

disable_early_hints.PNG

こちらの場合は当然ですが、InitiatorのところにPushの表示は見当たりません。
サーバーの側のログは以下になります。

14.11.212.160 - -  2017/12/02:23:43:25.378 "GET / HTTP/2" 200 32518 "Mozilla/5.0 (iPhone; CPU iPhone OS 9_1 like Mac OS X) AppleWebKit/601.1.46 (KHTML, like Gecko) Version/9.0 Mobile/13B143 Safari/601.1" "-" 0.984478
14.11.212.160 - -  2017/12/02:23:43:26.445 "GET /assets/index.self-0397218313f0bf485bad06248f5edee9d90cf44ff8df81140667ee9bd2dabd3d.css?body=1 HTTP/2" 200 12619 "Mozilla/5.0 (iPhone; CPU iPhone OS 9_1 like Mac OS X) AppleWebKit/601.1.46 (KHTML, like Gecko) Version/9.0 Mobile/13B143 Safari/601.1" "-" 0.003000
14.11.212.160 - -  2017/12/02:23:43:26.449 "GET /assets/ranking.self-e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855.css?body=1 HTTP/2" 200 0 "Mozilla/5.0 (iPhone; CPU iPhone OS 9_1 like Mac OS X) AppleWebKit/601.1.46 (KHTML, like Gecko) Version/9.0 Mobile/13B143 Safari/601.1" "-" 0.001763
14.11.212.160 - -  2017/12/02:23:43:26.449 "GET /assets/page.self-e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855.css?body=1 HTTP/2" 200 0 "Mozilla/5.0 (iPhone; CPU iPhone OS 9_1 like Mac OS X) AppleWebKit/601.1.46 (KHTML, like Gecko) Version/9.0 Mobile/13B143 Safari/601.1" "-" 0.003422
14.11.212.160 - -  2017/12/02:23:43:26.456 "GET /assets/reset.self-649fc63ac67dcbc63fc475b131dccd66ca88da93e36e89561e590e06c60b66a8.css?body=1 HTTP/2" 200 1916 "Mozilla/5.0 (iPhone; CPU iPhone OS 9_1 like Mac OS X) AppleWebKit/601.1.46 (KHTML, like Gecko) Version/9.0 Mobile/13B143 Safari/601.1" "-" 0.001500
14.11.212.160 - -  2017/12/02:23:43:26.456 "GET /assets/top.self-e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855.css?body=1 HTTP/2" 200 0 "Mozilla/5.0 (iPhone; CPU iPhone OS 9_1 like Mac OS X) AppleWebKit/601.1.46 (KHTML, like Gecko) Version/9.0 Mobile/13B143 Safari/601.1" "-" 0.003099
14.11.212.160 - -  2017/12/02:23:43:26.460 "GET /assets/application.self-f0d704deea029cf000697e2c0181ec173a1b474645466ed843eb5ee7bb215794.css?body=1 HTTP/2" 200 676 "Mozilla/5.0 (iPhone; CPU iPhone OS 9_1 like Mac OS X) AppleWebKit/601.1.46 (KHTML, like Gecko) Version/9.0 Mobile/13B143 Safari/601.1" "-" 0.001886
14.11.212.160 - -  2017/12/02:23:43:26.462 "GET /assets/application.self-eba3cb53a585a0960ade5a8cb94253892706bb20e3f12097a13463b1f12a4528.js?body=1 HTTP/2" 200 634 "Mozilla/5.0 (iPhone; CPU iPhone OS 9_1 like Mac OS X) AppleWebKit/601.1.46 (KHTML, like Gecko) Version/9.0 Mobile/13B143 Safari/601.1" "-" 0.004634
14.11.212.160 - -  2017/12/02:23:43:26.462 "GET /assets/index.self-f96b375198e843bd72a908a58a9ff3dd892431607f77986dbd3838ca78f43257.js?body=1 HTTP/2" 200 42540 "Mozilla/5.0 (iPhone; CPU iPhone OS 9_1 like Mac OS X) AppleWebKit/601.1.46 (KHTML, like Gecko) Version/9.0 Mobile/13B143 Safari/601.1" "-" 0.005531
14.11.212.160 - -  2017/12/02:23:43:26.467 "GET /assets/main-visual-16e3af579f2655750f10f485ab74b42d33229e357f4414369b9d956144bea918.png HTTP/2" 200 45810 "Mozilla/5.0 (iPhone; CPU iPhone OS 9_1 like Mac OS X) AppleWebKit/601.1.46 (KHTML, like Gecko) Version/9.0 Mobile/13B143 Safari/601.1" "-" 0.003483
14.11.212.160 - -  2017/12/02:23:43:26.470 "GET /assets/rank03-254f011ca156da0cab6f8831dd621596f182c890b3b8eef9e5012e9967bb36a3.png HTTP/2" 200 16677 "Mozilla/5.0 (iPhone; CPU iPhone OS 9_1 like Mac OS X) AppleWebKit/601.1.46 (KHTML, like Gecko) Version/9.0 Mobile/13B143 Safari/601.1" "-" 0.002873

こちらは、「/」に対するGETリクエストの後にコンテンツへのアクセスのログが出力されていて、レスポンスとして
受け取ったhtmlを解釈してからコンテンツへのリクエストを行っている様子が確認できます。
ブラウザの優先度制御にもよりますが、cssやjpgの前に画像ファイルを取得していることもあるため、css,jsを先に
クライアントに届けるという意味でもEarlyHintsは有効な手段だと思います。

awsで使うには

実際にAWS環境で使う場合、ドメインのAレコードが指し示すIPはH2Oが動いているサーバーではなく、ロードバランサーであったりします。
残念ながら現時点ではAWSのロードバランサー(Application Load Balancer)をhttpsのエンドポイントにした場合、EarlyHintsに対応していないため、
ロードバランサーに接続したインスタンス上で、H2OとRuby on Railsを動かしても、EarlyHintsを用いてクライアントにコンテンツをサーバープッシュすることは出来ません。
AWSのロードバランサーで冗長化をしたまま、EarlyHintsを使う場合は、Classic Load BalancerでProxy Protocolを有効にした状態で、各インスタンスの
443ポートにTCP接続する方法しかなさそうです。

まとめ

H2Oサーバーを使うこと、そして、Ruby on Railsのサーバー起動時にオプションを追加するだけで、
HTTP 103 EarlyHintsを用いたサーバープッシュが行えるようになりました。
Chrome, Edge,Firefoxなど、主要なブラウザはHTTP 103 EarlyHintsを用いたサーバープッシュに対応しているので、アプリケーション側の処理を変えることなく
ページを表示するのに、必要なcss,jsをサーバープッシュできるようになるので、大変便利な仕組みだと思いました。

1473695324