sonots:blog

2016年04月

2016年04月11日09:00
カテゴリ

BigQuery テーブルのスキーマを変更する

先週金曜日にあった #bq_sushi tokyo #3 で、BigQueryのテーブルスキーマ変更における困難についてトークしてきたので資料をおいておきます。 bq_sushi #1、#2 の頃はまだ BigQuery を使っておらず、ただの聴衆だったので、今回話をできてよかったです。急遽枠を作ってくれた @kazunori_279 さん、@hakobera さんありがとうございました。

https://speakerdeck.com/sonots/bigquery-schema-migration-number-bq-sushi




今回公開したツールのアドレスはこちらになります。gem リリースもしました。社内で作っているツールから、今回の発表にあわせて切り出したものになるので、発表機会がなかったらおそらくOSSにされることはなかったでしょう😜

https://github.com/sonots/bigquery_migration

内部の動きについては資料を参照していただいたほうが良いのですが、簡単に言うと、以下のような動きをします。基本的には select & copy なので(データを再ロードするのに比べて)素早くスキーマ変更を実施できます。

  1. あるべき姿のスキーマと、現在のスキーマを比較する
  2. カラムの追加が必要な場合は、まず patch table API を呼び出す
  3. カラムの削除、または型変更が必要な場合は、そこからさらに select & copy する (load job API に query と destination_table を指定する)
    • 型変更はキャスト関数を使って実現
    • カラム削除はそのカラムを select しなければ実現できる

ただし、制約として以下のものがあって、発表ではそのあたりの困難さをずっと話していました。BigQuery の現在の機能上、解決できない認識でいますが、何かうまくできる方法を御存知の方がいらっしゃったら是非お教えください。

  • mode: REPEATED カラムを扱えない
  • mode: NULLABLE カラムのみ追加可能
  • 型変更すると mode: NULLABLE になる
  • 課金される(カラム追加だけならば patch table API なので課金されない)

このあたりの制約を許容できない場合は、時間がかかりますが、BigQuery へのデータ Load を丸ごとやり直して頂くしかないですね。話を聞くには皆さんはスキーマ変更、もしくはデータの洗い替えが必要な場合は仕方ないのでそのようにしているとのことでした。今回のツールは、制約を許容できる範囲内で、素早くスキーマ変更できる選択肢が増えたと捉えていただけると良いかと思います。早く patch table API で型変更と、削除ができるようになってくれ頼む〜:pray:

あと、資料にも貼ってありますが、4月23日発売の WEB+DB Press 4月号に Treasure Data の @frsyuki くんと自分と、クックパッド社の面々で、データ収集特集の記事を書いているのでよろしくお願いします。BigQuery ユーザの方もそうでない方も、Fluentd、Embulk ユーザの方もそうでない方も是非手にとってみてください！
image

最後に、今回のスキーマ変更の調査、実装に関しては、後ろの席の @kysnm さんのご協力がありました。この場を借りて御礼申しあげます mm

    このエントリーをはてなブックマークに追加
2016年04月04日02:36
カテゴリ

Geminabox を高速化した

DeNA では社内 rubygems として geminabox を運用しているのだが(主に@Spring_MT と自分が管理している)、なんだか遅い気がして気になってきたので高速化した記録。リアルISUCON。

Geminabox とは

一応前置きとして Geminabox の解説をしておくと、社内 rubygems を立てる時に使える何かである。

弊社では proxy モードで動かしていて、geminabox に gem がダウンロードされていなければ、rubygems.org にアクセスしてダウンロードして保存する、という仕組みで利用している。

社内 rubygems を立てている動機としては主に次の２点がある。

  1. rubygems.org が落ちても業務が止まらないようにする
  2. 社内 gem のリリース場所を確保する

１番は言わずもがなであるが、２番については補足すると、Gemfile では github 指定で gem のインストールができるのだが、gemspec では github 指定はできないため、社内 gem に依存する社内 gem が出てきた時に欲しくなったという背景がある。

完全ミラーリングではないことを考えると１番に対しては中途半端といえばそうなのではあるが、運用に回っているような gem はすでにミラーリングされているため、デプロイは止まらずに済む。以前 rubygems.org が１時間程度落ちたことがあったが、十分に恩恵を受けられたポジティブ体験がある。

どれぐらい遅いのか

さて、どれぐらい遅いのかであるが、次の Gemfile で source の向先きを変えて bundle update を打った時の時間を比べてみた。

Gemfile.org

source 'https://rubygems.org'

gem 'geminabox'
gem 'unicorn'
gem 'rake'
gem 'server-starter'
gem 'oneline_log_formatter'
gem 'rack-ltsv_logger'

$ time BUNDLE_GEMFILE=Gemfile.org bundle update
real    0m7.559s

$ time BUNDLE_GEMFILE=Gemfile.dena bundle update
real    0m16.821s

２倍以上遅い。。。つらい。。。

メトリクス

アクセスログから最近 1000 request のメトリクスを取ってみた

左から合計時間、リクエスト回数、平均時間、エンドポイント

977.1919999999992   725 1.3478510344827574  /api/v1/dependencies
588.7679999999999   20  29.438399999999994  /specs.4.8.gz
21.343000000000085  8852    0.002411093538183471    /upload
13.126  11  1.1932727272727273  /gems/nokogiri-1.6.7.2.gem
12.523  3   4.174333333333333   /
5.936   2   2.968   /api/v1/gems
5.072   4   1.268   /gems/aws-sdk-core-2.2.31.gem

/api/v1/dependencies と /specs.4.8.gz が明らかに遅い。

静的ファイルを nginx で返す

/specs.4.8.gz へのアクセスがあまりにも遅いのは、明確に geminabox の ruby プロセスでファイルを返していたためだった。何も設定してなくてすみません。。。って感じだ。

geminabox のコード(具体的には lib/geminabox/proxy/hostess.rb)を読んで、nginx で返した方が良さそうなものを try_files で返すようにした。

root /path/to/data;

location @webapp {
  proxy_pass http://webapp;
}

location ~ \.gz$ {
  try_files $uri @webapp;
}

location ~ \.(rz|Z)$ {
  try_files $uri @webapp;
}

location ~ ^/(yaml|Marshal\.4\.8|specs\.4\.8|latest_specs\.4\.8|prerelease_specs\.4\.8)$ {
  try_files $uri @webapp;
}

location ~ \.gem$ {
  try_files $uri @webapp;
}

curl で /specs.4.8.gz を叩いて 0.19 sec で返ってくるようになった ^^。

29sec が 0.2sec に改善💪

プロファイリング

stackprof

遅いエンドポイントはわかったが、コード的にはどこなのかわかりやすいように stackprof を仕込んでプロファイリングした。Geminabox::GemListMerge#hash が遅いようだ。

$ bundle exec stackprof tmp/stackprof-cpu-10055-1459421776.dump
==================================
  Mode: cpu(1000)
  Samples: 325 (11.68% miss rate)
  GC: 72 (22.15%)
==================================
     TOTAL    (pct)     SAMPLES    (pct)     FRAME
       114  (35.1%)          97  (29.8%)     block in Geminabox::GemListMerge#hash
       234  (72.0%)          27   (8.3%)     block in <class:Server>
        23   (7.1%)          23   (7.1%)     Geminabox::GemListMerge#ignore_dependencies
        21   (6.5%)          21   (6.5%)     OpenSSL::Buffering#readpartial
        16   (4.9%)          16   (4.9%)     block in Geminabox::GemListMerge#ensure_symbols_as_keys
        35  (10.8%)          14   (4.3%)     block in Geminabox::GemListMerge#merge
        14   (4.3%)          12   (3.7%)     block in Geminabox::GemListMerge#combine_hashes
         3   (0.9%)           3   (0.9%)     ensure in block in Timeout#timeout
         3   (0.9%)           3   (0.9%)     block in HTTPClient#do_get_block
         2   (0.6%)           2   (0.6%)     HTTPClient::SSLConfig#default_verify_callback
         2   (0.6%)           2   (0.6%)     HTTPClient::SSLConfig#add_trust_ca_to_store
         2   (0.6%)           2   (0.6%)     JSON#parse
         2   (0.6%)           2   (0.6%)     HTTPClient::Session#create_socket
         2   (0.6%)           2   (0.6%)     block (2 levels) in Timeout#timeout
         3   (0.9%)           2   (0.6%)     <top (required)>
         3   (0.9%)           2   (0.6%)     <module:Protection>
         3   (0.9%)           1   (0.3%)     HTTPClient::SSLSocketWrap#ssl_connect
         1   (0.3%)           1   (0.3%)     block in OpenURI::Meta#content_type_parse
         1   (0.3%)           1   (0.3%)     block in OpenSSL::SSL#verify_certificate_identity
         1   (0.3%)           1   (0.3%)     OpenSSL::Buffering#fill_rbuff
         5   (1.5%)           1   (0.3%)     block in #<Module:0x007fa419a37658>.new
         1   (0.3%)           1   (0.3%)     Geminabox::GemListMerge#collection
         1   (0.3%)           1   (0.3%)     OpenSSL::SSL::Nonblock#initialize
         1   (0.3%)           1   (0.3%)     URI::Generic#initialize
         1   (0.3%)           1   (0.3%)     Rack::Builder#use
         1   (0.3%)           1   (0.3%)     block in HTTPClient::SSPINegotiateAuth#reset_challenge
         1   (0.3%)           1   (0.3%)     <module:Protection>
         1   (0.3%)           1   (0.3%)     block in Geminabox::DiskCache#marshal_read
         1   (0.3%)           1   (0.3%)     Rack::Protection::Base#html?
         1   (0.3%)           1   (0.3%)     <module:Protection>

rack-lineprof

遅い場所の検討はついたので、そのあたりに絞って rack-lineprof を仕込んで、その箇所を通るリクエスト(つまり/api/v1/dependencies)を投げて結果を出した。remote_gem_list (rubygems.org の /api/v1/dependencies を叩くところ)が支配的に遅くて、あとは local_gem_list とのマージ処理がそこそこ遅い。

[Rack::Lineprof] ===============================================================

lib/geminabox/server.rb
               |  95
               |  96      get '/api/v1/dependencies' do
 3561.2ms 40343 |  97        query_gems.any? ? Marshal.dump(gem_list) : 200
               |  98      end
               |  99
              .......
               |  213
               |  214      def dependency_cache
   1.0ms    30 |  215        self.class.dependency_cache
               |  216      end
               |  217
              .......
               |  253
               |  254      def gem_list
 3482.2ms     3 |  255        settings.rubygems_proxy ? combined_gem_list : local_gem_list
               |  256      end
               |  257
              .......
               |  261
               |  262      def local_gem_list
   2.3ms    18 |  263        query_gems.map{|query_gem| gem_dependencies(query_gem) }.flatten(1)
               |  264      end
               |  265
               |  266      def remote_gem_list
 3025.1ms     4 |  267        RubygemsDependency.for(*query_gems)
               |  268      end
               |  269
               |  270      def combined_gem_list
 3481.4ms     5 |  271        GemListMerge.from(local_gem_list, remote_gem_list)
               |  272      end
               |  273
              .......
               |  289        # Return a list of versions of gem 'gem_name' with the dependencies of each version.
               |  290        def gem_dependencies(gem_name)
   2.2ms    30 |  291          dependency_cache.marshal_cache(gem_name) do
               |  292            load_gems.
               |  293              select { |gem| gem_name == gem.name }.

lib/geminabox/gem_list_merge.rb
               |   4
               |   5      def self.from(*lists)
 453.5ms     8 |   6        lists.map{|list| new(list)}.inject(:merge)                                                                                                                  
               |   7      end
               |   8
              .......
               |  12
               |  13      def merge(other)
 453.5ms     4 |  14        combine_hashes(other).values.flatten.sort do |x, y|
  76.8ms 69765 |  15          x.values[ignore_dependencies] <=> y.values[ignore_dependencies]
               |  16        end
               |  17      end
              .......
               |  21        puts _list.size
               |  22        puts _list.first.to_s
 334.3ms     2 |  23        list.each do |item|
  43.6ms   872 |  24          ensure_symbols_as_keys(item)
   1.1ms   872 |  25          name = item[:name].to_sym
   0.7ms   872 |  26          collection[name] ||= []
 283.6ms 179169 |  27          collection[name] << item unless collection[name].include?(item)
               |  28        end
               |  29        collection
              .......
               |  35
               |  36      def combine_hashes(other)
 334.5ms     5 |  37        hash.merge(other.hash) do |key, value, other_value|
               |  38          (value + other_value).uniq{|v| v.values[ignore_dependencies]}
               |  39        end
              .......
               |  45
               |  46      def ensure_symbols_as_keys(item)
  40.9ms  1744 |  47        item.keys.each do |key|
   4.9ms  6976 |  48          next if key.kind_of? Symbol
  14.9ms 14824 |  49          item[key.to_sym] = item.delete(key)
               |  50        end
               |  51      end

/api/v1/dependencies.json は遅いよ

https://bundler.rubygems.org/api/v1/dependencies が遅いならどうしようもないかなぁと思うのであるが、geminabox 経由で叩くと異様に遅い。

geminabox 経由だと 3sec

$ time curl --silent 'https://geminabox/api/v1/dependencies?gems=rake%2Cflexmock%2Cparallel_tests%2Csimplecov%2Crr%2Ctimecop%2Ctest-unit%2Ctest-unit-rr%2Coj%2Cpry%2Cpry-nav%2Cfluent-plugin-s3%2Cfluent-plugin-forest%2Cfluent-plugin-record-reformer%2Cmsgpack%2Cjson%2Cyajl-ruby%2Ccool.io%2Chttp_parser.rb%2Csigdump%2Ctzinfo%2Ctzinfo-data%2Cstrptime' > /dev/null
3.195 total

bundler.rubygems.org 直接だと 1.6sec

$ time curl --silent 'https://bundler.rubygems.org/api/v1/dependencies?gems=rake%2Cflexmock%2Cparallel_tests%2Csimplecov%2Crr%2Ctimecop%2Ctest-unit%2Ctest-unit-rr%2Coj%2Cpry%2Cpry-nav%2Cfluent-plugin-s3%2Cfluent-plugin-forest%2Cfluent-plugin-record-reformer%2Cmsgpack%2Cjson%2Cyajl-ruby%2Ccool.io%2Chttp_parser.rb%2Csigdump%2Ctzinfo%2Ctzinfo-data%2Cstrptime' > /dev/null
1.661 total

どうやら geminabox が Marshal dump を返す /api/v1/dependencies ではなく、JSON を返す/api/v1/dependencies.json を呼んでいるようで、それが遅かった。さらにハッシュの key を symbol に直す処理を JSON.parse(body, symbolize_names: true) ではなく、自前で ruby コードでやっていたりしてそれも遅い要因となっているようだったので、/api/v1/dependencies を利用するように変更した。

time curl --silent https://bundler.rubygems.org/api/v1/dependencies.json\?gems\=rake,flexmock,parallel_tests,simplecov,rr,timecop,test-unit,test-unit-rr,oj,pry,pry-nav,fluent-plugin-s3,fluent-plugin-forest,fluent-plugin-record-reformer,msgpack,json,yajl-ruby,cool.io,http_parser.rb,sigdump,tzinfo,tzinfo-data,strptime > /dev/null
3.021 total

3.0sec が 1.6sec に改善💪

マージ処理が遅い

remote_gem_list と local_gem_list のマージに、ものよっては 1.1sec かかることもあった。ごにょごにょ弄った結果、0.04 sec に高速化することができた > https://github.com/geminabox/geminabox/pull/230/commits/39f5b2ff29be21895285c00654c73981b3750271 

1.1sec が 0.04sec に改善💪

Accept-Encoding: gzip

curl で /api/v1/dependencies を叩くとほとんど差がなくなったので、良さそう😀 と思ったのだが、bundle update で叩くと rubygems.org の方が早い。

bundler のリクエストヘッダを見るために、bundler の net/http/persistent に connection.debug_output = $stdout をつけてヘッダを出すようにした。どうやら gzip と keep-alive を有効にしているようだ。

<- "GET /api/v1/dependencies?gems=rspec-support HTTP/1.1\r\nAccept-Encoding: gzip;q=1.0,deflate;q=0.6,identity;q=0.3\r\nAccept: */*\r\nUser-Agent: bundler/1.11.2 rubygems/2.5.1 ruby/2.3.0 (x86_64-apple
-darwin15.2.0) command/update options/ d01203161a479cba\r\nConnection: keep-alive\r\nKeep-Alive: 30\r\nHost: bundler.rubygems.org\r\n\r\n"
-> "HTTP/1.1 200 OK\r\n"
-> "Server: Cowboy\r\n"
-> "Date: Sat, 02 Apr 2016 16:27:42 GMT\r\n"
-> "Connection: keep-alive\r\n"
-> "Content-Type: application/octet-stream\r\n"
-> "X-Content-Type-Options: nosniff\r\n"
-> "Vary: Accept-Encoding\r\n"
-> "Content-Encoding: gzip\r\n"
-> "Transfer-Encoding: chunked\r\n"
-> "Via: 1.1 vegur\r\n"

gzip と keep-alive 有効にして２つの URL に連続で GET (速い)

$ time curl -v 'https://bundler.rubygems.org/api/v1/dependencies' 'https://bundler.rubygems.org/api/v1/dependencies?gems=rake%2Cflexmock%2Cparallel_tests%2Csimplecov%2Crr%2Ctimecop%2Ctest-unit%2Ctest-unit-rr%2Coj%2Cpry%2Cpry-nav%2Cfluent-plugin-s3%2Cfluent-plugin-forest%2Cfluent-plugin-record-reformer%2Cmsgpack%2Cjson%2Cyajl-ruby%2Ccool.io%2Chttp_parser.rb%2Csigdump%2Ctzinfo%2Ctzinfo-data%2Cstrptime' -H 'Accept-Encoding: gzip;q=1.0,deflate;q=0.6,identity;q=0.3' -H 'Accept: */*' -H 'User-Agent: bundler/1.11.2 rubygems/2.5.1 ruby/2.3.0 (x86_64-apple-darwin15.2.0) command/update options/ 2c0046654ef44b07' -H 'Connection: keep-alive' -H 'Keep-Alive: 30' > /dev/null
1.609 total

gzip も keep-alive も無効にして２つの URL に連続で GET (遅い)

$ time curl -v 'https://bundler.rubygems.org/api/v1/dependencies' 'https://bundler.rubygems.org/api/v1/dependencies?gems=rake%2Cflexmock%2Cparallel_tests%2Csimplecov%2Crr%2Ctimecop%2Ctest-unit%2Ctest-unit-rr%2Coj%2Cpry%2Cpry-nav%2Cfluent-plugin-s3%2Cfluent-plugin-forest%2Cfluent-plugin-record-reformer%2Cmsgpack%2Cjson%2Cyajl-ruby%2Ccool.io%2Chttp_parser.rb%2Csigdump%2Ctzinfo%2Ctzinfo-data%2Cstrptime' -H 'Connection: close' --no-keepalive  > /dev/null
3.217 total

geminabox が rubygems.org にリクエストを送る処理を見ると、httpclient を使っていて、keepalive はデフォルトで有効になっているようであるが、Accept-Encoding: gzip はつけていないようなので付けるようにして高速化した。

      def http_client
 -      @http_client ||= HTTPClient.new(ENV['http_proxy'])
 +      @http_client ||= HTTPClient.new(ENV['http_proxy']).tap {|client|
 +        client.transparent_gzip_decompression = true
 +      }
      end

1.4sec が 1.1sec に改善 💪

nginx の設定

bundler が rubygems.org に期待しているのと同様の挙動をするように nginx の設定をした。具体的には

  • keekpalive を有効 (keepalive_timeout を伸ばして、keepalive_requests を増やした)
  • gzip on にした
  • ついでに nginx => upstream の接続も keepalive させた (アプリの特性上、これはさほど影響しないが)

http session の再利用頻度を増やすために puma に置き換える

Geminabox を動かすための HTTP サーバとして unicorn を使用していた。また、多数のユーザをさばけるようにプロセス数を比較的大きめにしていた (Geminabox の特性上、CPUはほとんど使われない)。

bundle update を打つと、

Fetching gem metadata from https://rubygems.org/..............
Fetching version metadata from https://rubygems.org/...
Fetching dependency metadata from https://rubygems.org/..

のように表示されるが、この１つの . に付き、１回 /api/v1/dependencies を呼んでおり、それを keepalive connection で連続的に叩いている。

さて、このような前提において、geminabox に連続的にリクエストしても、リクエストごとに別の unicorn worker がリクエストを処理することになり、それぞれが /api/v1/dependencies を個別に叩くため、httpclient の keepalive (session reuse) が有効に働いていないようだ。特に https 接続するので SSL session の開始に時間がかかっている。

そこで、http session の再利用頻度を増やしつつ、しかし並列度は下げないために、HTTPサーバを unicorn から puma に置き換えた。なお、httpclient はスレッドセーフに作られているので、問題なく利用できた🙏

FYI: SSL session の開始に時間がかかる問題に関しては、rubygems.org へのアクセスを https から http に切り替えるという手もある。。。オススメはできないが速さだけを求めるならこれで大分速くなるだろう。

まとめ

高速化結果

  • rubygems.org: 7.559 sec
  • BEFORE: 16.821 sec
  • AFTER: 8.543 sec

1secぐらいの差なら許容できるのではないだろうか！！💪

補足：/api/v1/dependencies が返すデータの量が大きいと Marshal.load/dump およびマージにかかる時間が増えるので rubygems.org 直接の場合との差が大きくなりやすい

Geminabox の変更

PR 送ってある > https://github.com/geminabox/geminabox/pull/230

Nginx の設定ファイル

ちょっと端折っているが、こんな感じ

http {
    root /path/to/data;
    gzip on;

    proxy_http_version 1.1;
    proxy_set_header Connection '';
    proxy_set_header Host $http_host;
    proxy_set_header X-Real-IP          $remote_addr;
    proxy_set_header X-Forwarded-Host   $host;
    proxy_set_header X-Forwarded-Server $host;
    proxy_set_header X-Forwarded-For    $proxy_add_x_forwarded_for;
    proxy_set_header X-Forwarded-Proto  https;

    upstream webapp {
        server 127.0.0.1:3000 fail_timeout=0;
        keepalive 32;
    }

    server {
        listen 443 ssl;
        keepalive_timeout   75;
        keepalive_requests  100;

        location @webapp {
            proxy_pass http://webapp;
        }
        location / {
            proxy_pass http://webapp;
        }
        # see lib/geminabox/proxy/hostess.rb
        location ~ \.gz$ {
            try_files $uri @webapp;
        }
        location ~ \.(rz|Z)$ {
            try_files $uri @webapp;
        }
        location ~ ^/(yaml|Marshal\.4\.8|specs\.4\.8|latest_specs\.4\.8|prerelease_specs\.4\.8)$ {
            try_files $uri @webapp;
        }
        location ~ \.gem$ {
            try_files $uri @webapp;
        }
    }
}

なお、nginx の conf を書くときは nginx 実践入門が役に立つようだ😀

Puma の設定ファイル

宗教上の理由で puma on server-starter on daemontools にして動かしているが、それを除くとこれぐらい。

APP_ROOT = File.dirname(__FILE__)
pidfile File.join(APP_ROOT, 'tmp/pids/puma.pid')
state_path File.join(APP_ROOT, 'tmp/pids/puma.state')
preload_app!
threads 0, 16
workers 2

server starter の puma 対応はこちらをご参照ください > ruby-server-stater/example/puma

    このエントリーをはてなブックマークに追加
そのっつ (SEO Naotoshi)@sonots
A Ruby and Fluentd committer working at DeNA. 記事本文および記事中のコード片は引用および特記あるものを除いてすべて修正BSDライセンスとします。 #ruby #fluentd #growthforecast #haikanko #yohoushi #specinfra #serverspec #focuslight
はてぶ人気エントリー
人気記事
最新記事
ブログ移行
ISUCON8 の予選問題出題を担当した
objdump でインライン展開を追う
perf でアプリケーションのプロファイリング
Rubyアソシエーション開発助成成果報告会で Cumo の報告をしてきた
Optimized C++ を読んだ
RubyKaigi 2018 で Cumo の話をしてきた
pybind11 に contribution した
valgrind --tool=callgrind で CPU profiling
「Linux の仕組み」を読んだ

Template by decoweb