BigQueryのstreaming insertでログが欠損する #BigQuery

BigQueryは安価で高速なログ集計ツールだ。数億件のログでもGoogleの大規模コンピューター環境を使って、数秒で集計できる。

しかし、集計するためにログデータをBigQueryに格納する際に、ログ欠損が発生した。どのような経緯で発生したか？どのようにすれば減少するかを記載する。

今回の構成

自作プログラムでログに書込しつつ td-agentのin_tailプラグインでそのログを読み込み、bigqueryに保存する構成だ。

ログ欠損発生

あまり設定を変更せず、bigqueryにログを送信。以下のようになった。

送信	送信ログ数	ローカルに保存出来たログ量	BigQueryのログ量
送信件数	10,000,000	9,898,772	9,866,156
送信割合	100%	98.9877720%	98.661569%

ローカルに保存出来たログ量の時点で、98%に減って、さすがに看過出来ない。

ulimitでオープン出来るログ量を増やす。

Too Many Open Fileみたいな警告が出ていたので、下のリンクに書いているようにulimitを操作して、オープンできるファイル数を増やした。

ulimitの成果

送信	送信ログ数	ローカルに保存出来たログ量	BigQueryのログ量
送信件数	10,000,000	10,000,000	9,999,810
送信割合	100%	100%	99.9881%

おお、だいぶログ欠けが減った。
それでも、190件のログ欠けが発生した。

parameter 'buffer_chunk_records_limit' not found

buffer_chunk_records_limitは、BQ側の受け入れレコード最大数を決める数値だが、自分が試したflunet-plugin-bigquery0.2.7はconfファイルに設定したものが上手く反映されてないようだった。仕方なく、out_bigquery.rbのbuffer_chunk_records_limitを直接書き換えた。500->300

buffer_chunk_records_limit(500->300)変更の成果

送信	送信ログ数	ローカルに保存出来たログ量	BigQueryのログ量
送信件数	10,000,000	10,000,000	10,000,000
送信割合	100%	100%	100%

おお、全ての送信ログを保存した。

味を占めてもう少し大量のログではどうか調査した。

送信	送信ログ数	ローカルに保存出来たログ量	BigQueryのログ量
送信件数	30,000,000	30,000,000	29,997,395
送信割合	100%	100%	99.9913166%

3千万件送信して、2605件のログが欠落した。

今回の調査ではここまでになった。

BigQueryはログを取り入れてからは素晴らしいけど、まずログを取り入れる部分で不安がある。td-agentを使わなければ良いのかもしれないが、そうするとログ収集システムを自前で構築せねばならず非効率である。

googleはfluetdをGCEなどの標準ログコレクターにしたのだから、bigqueryプラグインについても手を加えてくれても良いかも知れない。

TreasureDataへ、並列送信

後半は、TreasureDataへも並列で送信を行った。一番最後に一千万件のログを送信した際には、TreasureData,BigQuery両方共ログ欠損はなかった。
TreasureDataの設定は特に何もしなくても、ログ欠損が起こらないのが素晴らしい。

ログ欠損とデータ分析

今回の調査ではfluent-plugin-bigqueryを用いたストリーミングインサートを行う際に、ログ欠損を起こることが分かった。上手くやれば、一万件に一件か１０万件に一件のレベルに出来る。統計的に、一万件に一件のログ欠損が大勢に影響を与えることはない。けれども経営陣の頭の中では、その集計値は信用のおけないものになってしまう。

そういう意味では、ログ収集の際に、複雑な設定をせずともログ欠落を起こさないtd-agentとtdlogの組み合わせは素晴らしいなと思った。

今回の設定

今回の設定は、
http://qiita.com/najeira/items/74799a67ac21c6b13415
を参考にした。

 File input
# read apache logs continuously and tags td.apache.access
<source>
  type tail
  format tsv
  keys insert_id,count,org,now,i_num
  #time_key key2
  path /var/log/test.log
  tag local.test
  #tag debug.test
  pos_file /tmp/td-agent.pos
</source>

## File output
## match tag=local.** and write to file
<match local.**>
  type copy
  <store>
    type file
    path /var/log/td-agent/access
  </store>
  <store>
    type bigquery
    buffer_type file
    buffer_path /var/log/td-agent/buffer/
    method insert
    auth_method private_key   # default
    email XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX@developer.gserviceaccount.com
    private_key_path /etc/td-agent/XXXXXXXXXXXXXXXXXXX.p12
    # private_key_passphrase notasecret # default
    project 1111111111
    dataset bg_test
    table   test7
    fetch_schema true
    buffer_chunk_limit           768k    # BigQuery上限
    buffer_queue_limit           5000       # 1GBくらい
    flush_interval               1s          # 暇な時間帯は1秒おき
    try_flush_interval           0.05       # チャンクが溜まったら早めに送信
    num_threads                  20          # HTTP POSTが遅いので複数スレッド
    queued_chunk_flush_interval  0.01       # チャンクが溜まった場合は待ち時間短めで連続送信
    insert_id_field insert_id
    retry_limit 15
    buffer_chunk_records_limit 300        # BigQuery上限なぜか機能しない
  </store>
  <store>
     type tdlog
     apikey 1231331xx23xx2111xx11111
     auto_create_table
     database hoge
     table test2
     buffer_type file
     buffer_path /var/log/td-agent/tdlog
     flush_interval 20  # second unit
   </store>
</match>