reizist's blog

ウェブ

prestodbにおけるelapsed timeとは何か

prestodbを扱っていてクエリメトリクスを見る上で必ず参照することになるelapsed timeが一体何なのかを調べたメモ。 一言でいうとクエリが作成されてからクエリが完了するまでの時間なんだけど、じゃあそれがいつなのかというのをソースを追う。

全体の流れを追うのに、

https://www.slideshare.net/frsyuki/hadoop-source-code-reading-15-in-japan-presto

https://image.slidesharecdn.com/hsr15-presto-131223202205-phpapp01/95/hadoop-source-code-reading-15-in-japan-presto-10-638.jpg?cb=1387830178

presto_executor_and_coordinator.md · GitHub

あたりが非常に参考になるので足がかりにするとよい。

実際に createTime , endTime を作成しているのは QueryStateMachine 内で、

https://github.com/prestodb/presto/blob/bcfb4c6f2872f9de39c0e8f42c6bd43dd08241c2/presto-main/src/main/java/com/facebook/presto/execution/QueryStateMachine.java#L90

  • endTime : recordDoneStats() コール時
    • transitionToFinished() or transitionToFailed() or transitionToCanceled() の処理内で recordDoneStats() が呼ばれる

https://github.com/prestodb/presto/blob/bcfb4c6f2872f9de39c0e8f42c6bd43dd08241c2/presto-main/src/main/java/com/facebook/presto/execution/QueryStateMachine.java#L657

実際に QueryStateMachineインスタンスSqlQueryExecution のコンストラクタ内で作成され、 transitionToXXX()com.google.common.util.concurrent.Futures#addCallback() によって onSuccess() などのcallbackとして処理される。

https://github.com/prestodb/presto/blob/bcfb4c6f2872f9de39c0e8f42c6bd43dd08241c2/presto-main/src/main/java/com/facebook/presto/execution/QueryStateMachine.java#L636

SqlQueryExecution のオブジェクトは SqlQueryManager#createQuery によって作成される。

https://github.com/prestodb/presto/blob/dba2648ddc34875aa8b4f8e32a4dba7ba5920e0d/presto-main/src/main/java/com/facebook/presto/execution/SqlQueryManager.java#L412


メトリクスを把握するのによく参照する時間周りのまとめ。

タイプ 処理クラス
createTime クエリ作成時間 QueryStateMachine
startTime 実際のクエリ処理開始時間 Session
endTime 実際のクエリ処理完了時間 QueryStateMachine
queuedTime duration(startTime - createTime) QueryStateMachine
elapsedTime duration(endTime - createTime) QueryStateMachine
executionTime elapsedTime - queuedTime QueryStats

雑いけどひとまずメモ。

mac上のhiveのデータストアにS3を使う

reizist.hatenablog.com

の続き。

EXTERNAL TABLEのLOCATIONにS3を使う場合の設定。

やることは2つ。

  • S3AFileSystemを使うために2つファイルを編集してパスを通す

$HADOOP_CONF_DIR/hadoop-env.sh

export HADOOP_CLASSPATH=$HADOOP_CLASSPATH:$HADOOP_HOME/libexec/share/hadoop/tools/lib/*
  • S3AFileSystemの指定とアクセスキーの設定

$HADOOP_CONF_DIR/yarn-site.xml

<?xml version="1.0"?>
<configuration>
  <property>
    <name>fs.s3a.impl</name>
    <value>org.apache.hadoop.fs.s3a.S3AFileSystem</value>
  </property>
  <property>
    <name>fs.s3a.access.key</name>
    <value>AWSのアクセスキー</value>
  </property>
  <property>
    <name>fs.s3a.secret.key</name>
    <value>AWSのシークレットキー</value>
  </property>
</configuration>

hadoop fs -ls s3a://bucket名/ で疎通が確認とれればOK。

java.lang.RuntimeException: java.lang.ClassNotFoundException: Class org.apache.hadoop.fs.s3a.S3AFileSystem not found

が発生した場合、正しくパスが通ってない。

mac上にhive+hive metastore on mysql環境を構築する

hadoop & hive on macの環境構築記事結構ちらほらあるんだけど、その通りにやって動かなかったり、信頼に欠けるコメントがついていたりするので改めて自分でまとめる。

hadoop + hive + hive metastore on mysqlを想定してます。

環境

準備

java

$ brew cask install java

$ echo 'export JAVA_HOME=`/usr/libexec/java_home -v 1.8`' >> ~/.zshrc
$ echo 'export PATH="PATH=$JAVA_HOME/bin:$PATH"' >> ~/.zshrc

mysql

$ brew install mysql

hadoop

$ brew install hadoop

$ echo 'export HADOOP_HOME="/usr/local/Cellar/hadoop/2.8.2"' >> ~/.zshrc
$ echo 'export HADOOP_CONF_DIR="$HADOOP_HOME/libexec/etc/hadoop"' >> ~/.zshrc

$HADOOP_CONF_DIR 上で2つの設定ファイルを追加

  • core-site.xml
<configuration>
    <property>
        <name>fs.defaultFS</name>
        <value>hdfs://localhost:9000</value>
    </property>
</configuration>
<configuration>
    <property>
        <name>dfs.name.dir</name>
        <value>/var/lib/hdfs/name</value>
    </property>
    <property>
        <name>dfs.data.dir</name>
        <value>/var/lib/hdfs/data</value>
    </property>
    <property>
        <name>dfs.replication</name>
        <value>1</value>
    </property>
</configuration>

hive

$ brew install hive
$ echo 'export HIVE_HOME="/usr/local/Cellar/hive/2.3.1"' >> ~/.zshrc
$ echo 'export HIVE_CONF_DIR="$HIVE_HOME/libexec/conf"' >> ~/.zshrc

$HIVE_CONF_DIR 上で1つの設定ファイルを追加( cp hive-default.xml.template hive-site.xml としても可)

  • hive-site.xml
<property>
  <name>javax.jdo.option.ConnectionURL</name>
  <value>jdbc:mysql://localhost/hive_metastore</value>
</property>
<property>
  <name>javax.jdo.option.ConnectionDriverName</name>
  <value>com.mysql.jdbc.Driver</value>
</property>
<property>
  <name>javax.jdo.option.ConnectionUserName</name>
  <value>[mysql上に構築するhive metastore用dbにつなぐユーザー名 e.g. hive]</value>
</property>
<property>
  <name>javax.jdo.option.ConnectionPassword</name>
  <value>[mysql上に構築するhive metastore用dbにつなぐユーザー名 e.g. password]</value>
</property>
<property>
    <name>hive.exec.local.scratchdir</name>
    <value>/tmp/hive</value>
    <description>Local scratch space for Hive jobs</description>
</property>
<property>
    <name>hive.downloaded.resources.dir</name>
    <value>/tmp/hive</value>
    <description>Temporary local directory for added resources in the remote file system.</description>
</property>
<property>
    <name>hive.querylog.location</name>
    <value>/tmp/hive</value>
    <description>Location of Hive run time structured log file</description>
</property>

hive metastore接続用JDBCドライバを配置

$ curl -O https://cdn.mysql.com/Downloads/Connector-J/mysql-connector-java-5.1.44.tar.gz
$ tar xvzf mysql-connector-java-5.1.44.tar.gz
$ mv mysql-connector-java-5.1.44/mysql-connector-java-5.1.44-bin.jar $HIVE_HOME/lib

localhostへのssh

システム環境設定→共有→リモートログインをON

設定

hadoop hdfsフォーマット

$ hdfs namenode -format

mysqlにhive metastore用環境準備

  • FAQによれば、 When using MySQL as a metastore I see the error "com.mysql.jdbc.exceptions.MySQLSyntaxErrorException: Specified key was too long; max key length is 767 bytes". に対する回避策としてcharacter setに latin1 を使うパターンを記載しています。手っ取り早いのでこれで対応
$ mysql -u root
mysql> create database hive_metastore default character set 'latin1';
mysql> use hive_metastore;
mysql> create user 'hive'@'localhost' identified by 'password';

metastore用のテーブル初期化作成

$ schematool -dbType mysql -initSchema -verbose

Unable to instantiate org.apache.hadoop.hive.metastore.HiveMetaStoreClient が出る場合はmysqlにmetastoreテーブルが作られているか確認する

$ mysql -u hive -p
Enter password:
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 836
Server version: 5.7.19 Homebrew

Copyright (c) 2000, 2017, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> use hive_metastore;
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
mysql> show tables;

hive側からmetastoreにアクセスできればOK

$ hive
SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/usr/local/Cellar/hive/2.3.1/libexec/lib/log4j-slf4j-impl-2.6.2.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/usr/local/Cellar/hadoop/2.8.2/libexec/share/hadoop/common/lib/slf4j-log4j12-1.7.10.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
SLF4J: Actual binding is of type [org.apache.logging.slf4j.Log4jLoggerFactory]
show tables;

Logging initialized using configuration in jar:file:/usr/local/Cellar/hive/2.3.1/libexec/lib/hive-common-2.3.1.jar!/hive-log4j2.properties Async: true
Hive-on-MR is deprecated in Hive 2 and may not be available in the future versions. Consider using a different execution engine (i.e. spark, tez) or using Hive 1.X releases.
hive> show tables;
OK
Time taken: 3.35 seconds
hive>

何かしらのエラーが発生する場合

hive -hiveconf hive.root.logger=DEBUG,console

としてログを見る。

hiveの細かいプロパティはConfiguration Properties 参照。例えば datanucleus.schema.autoCreateAll (hive2.0以降は datanucleus.autoCreateSchema ではない)を有効にすると初回起動時のメタストア作成を自動的に行なってくれる。

#prestodb のクエリ履歴を保持する

TL;DR

  • prestoのクエリログを全て保持したい
  • 簡易に行うならAPI経由で取得できる
  • きちんと環境を準備するなら event-listenerを使う方法がよく、自分のケースでは presto-fluentdを使用してfluentdを経由しデータストアに送信している

背景

prestoはFacebookが開発した、Hadoop上で動作する分散SQLエンジンである。 Hiveと比較すると、オンメモリで動作するのでCPU効率が良く高速に処理されるので、アドホックな環境に向いている。 このprestoを運用する上で欠かせないであろう実行クエリの履歴管理に関して、きちんとまとまっているエントリは少ないと感じたので書く。

クエリログの取得

方法1: 簡易(API経由)

手っ取り早く情報を取得するには、 http://<master node ip>/v1/query APIが使用できる。

[
    {
        "memoryPool": "general",
        "query": "SELECT ...",
        "queryId": "20171117_163751_00480_7vfi8",
        "queryStats": {
            "blockedReasons": [],
            "completedDrivers": 83,
            "createTime": "2017-11-17T16:37:51.152Z",
            "cumulativeMemory": 355882963.0,
            "elapsedTime": "1.79s",
            "endTime": "2017-11-17T16:37:52.943Z",
            "executionTime": "1.79s",
            "fullyBlocked": true,
            "peakMemoryReservation": "0B",
            "progressPercentage": 100.0,
            "queuedDrivers": 0,
            "runningDrivers": 0,
            "totalCpuTime": "86.63ms",
            "totalDrivers": 83,
            "totalMemoryReservation": "0B"
        },
        "scheduled": true,
        "self": "http://172.xx.xx.xx:8889/v1/query/20171117_163751_00480_7vfi8",
        "session": {
            "catalogProperties": {},
            "clientTransactionSupport": false,
            "locale": "en_US",
            "preparedStatements": {},
            "queryId": "20171117_163751_00480_7vfi8",
            "remoteUserAddress": "172.xx.xx.xx",
            "startTime": 1510936671152,
            "systemProperties": {},
            "timeZoneKey": 0,
            "transactionId": "26a22b5a-0c8d-4413-9b07-13ab4412e822",
            "user": "hadoop",
            "userAgent": "presto-ruby/0.5.2"
        },
        "state": "FINISHED"
    },
    {
       //   
    }
]

上記のようなフォーマットで実行されたクエリ最新N件の情報が取得できる。 このAPIを定期的に叩いてパースしてデータストアに突っ込むだけでよいので、容易に実装ができる。 ただし 最新N件取得する という点が問題で、例えば1分起きにAPIを叩くスクリプトを実行したとして、深夜帯など一切クエリが更新されない環境の場合APIを叩くたびに同じクエリIDの情報を格納することになってしまうので、大量の重複データがデータストアに溜まることになる。 このため、重複を許容するか、何らかの方法で重複させない実装を挟む必要がある。 即解決可能な策としてはデータストアにRDBを用いてクエリIDをuniqueにする方法が考えられるが、ここではfluentdを使った方法を紹介する。

拙作ではあるが fluentd-plugin-comparison-filterというfluentd filter gemがある。 このgemは、 column_key で指定したカラムの値で、次に処理するレコードが最新のものか判断し、最新のレコードだけ出力する プラグインだ。

細かい値や制御を無視して要点だけ実装すると、このようになる。

require 'json'
require 'yaml'
require 'erb'
require 'presto/metrics'
stage = ENV["STAGE"] || "development"
config = YAML.load(ERB.new(File.read(File.expand_path("../init_config.yml", __FILE__))).result(binding))[stage]
client = Presto::Metrics::Client.new(host: config["host"], port: config["port"])

metrics = JSON.parse(client.get('/v1/query'))
metrics.select{|m| m["state"] == "FINISHED" || m["state"] == "FAILED"}.sort_by{|m| m["queryStats"]["endTime"] }.select do |m|
  query_id     = m["queryId"]
  start_at     = DateTime.parse(m["queryStats"]['createTime']).to_s
  end_at       = DateTime.parse(m["queryStats"]['endTime']).to_s
  query        = m["query"].gsub(/(\r\n|\r|\n)/, '\\\\n')
  status       = m["state"]
  puts JSON.dump({query_id: query_id, query: query, start_at: start_at, end_at: end_at, status: status))
end
  • in_execを用いてデータを受け取るfluentdの設定の例
<source>
  @type exec
  tag presto.query_stats
  command ruby /opt/presto/fluentd_put_query_stats.rb
  run_interval 1m
  <parse>
    @type json
  </parse>
</source>

<filter presto.query_stats>
  @type comparison
  <comparison>
    column_key end_at
    column_key_type time
    time_type string
    time_format %Y-%m-%dT%H:%M:%S %z
  </comparison>
</filter>

<match presto.query_stats>
  @type copy

  <store>
    @type relabel
    @label @bigquery-out
  </store>
</match>

# 後続の処理

APIを1度叩いて得たreponseに関して実行された順にfluentdで処理を行い、fluentdではクエリの実行完了時間を用いて「レコードが最新かどうか」判断することで、再びAPIを叩いて全く同じレスポンスだったとしても前回のレスポンスにより最新のレコードまで取り込んであるので、取り込み済のレコードはフィルタリングされるという挙動になる。 これでクエリの重複は回避することができた。

しかし、実はこれでもまだ問題がある。 APIを叩く頻度を1分毎であるとする。また、1回のAPIで得られるクエリ件数は40件とする。 この状況で、例えば高負荷により分間40回を超えるクエリが実行された場合、今度はクエリの取り逃しが発生する。

取り逃しを発生させないために頻度を上げて例えば10秒に1回実行するなどの選択肢はあるが、そもそも不要な処理を行い負荷をかけるのは良い判断とはいえない。

方法2: event-listener経由

方法1では、クエリ情報取得の重複・漏れの可能性があったが、実はprestoには event-listenerと呼ばれる機構があり、クエリ完了時に任意のプログラムを走らせることが可能である。 これを用いてクエリ完了時に各メトリクスをデータストアに保持するようにすれば、無駄なく漏れなくクエリログの取得が可能である。

観測範囲では2つのプラグインがあり、 一つはクエリ結果をファイルに書き出すpluginpresto-audit、もう一つはfluentdに送信するpresto-fluentdだ。 個人的にはfluentdはretry処理や複数のデータストアへの送信を柔軟に行える点で便利だと考え後者を採用した。

fluentdが非常に容易に各メトリクスを処理できるので、

  • メトリクスはdatadogに
  • クエリログはbigqueryに

それぞれ送信し、日々の監視/運用に役立てている。

  • event-listener.properties
event-listener.name=presto-fluentd
event-listener.fluentd-port=24224
event-listener.fluentd-tag=presto.query
event-listener.fluentd-host=<送信対象のfluentd host>"
  • fluentd.conf
<match presto.query>
  @type copy

  <store>
    @type relabel
    @label @presto-query-stats
  </store>

  <store>
    @type relabel
    @label @presto-query-storage
  </store>
</match>

<label @presto-query-stats>
  <match **>
    @type copy

    # elapsed_time
    <store>
      @label @presto-datadog-out
      @type record_reformer
      enable_ruby true
      renew_record true
      tag presto.query_stats.elapsed_time

      <record>
        type gauge
        metric presto-observer-<%= ENV["STAGE"] %>.query_stats.elapsed_time
        value ${(record["endTime"] - record["createTime"]) / 1000.0}
        tag ${record["user"]}
      </record>
    </store>
    # 略: その他各メトリクス
  </match>
</label>

<label @presto-query-storage>
  <match **>
    @label @presto-bigquery-out
    @type record_reformer
    renew_record true
    tag presto.query_storage.big_query
    <record>
      query_id ${record["queryId"]}
      user_name ${record["user"]}
      elapsed_time ${(record["endTime"] - record["createTime"]) / 1000.0}
      start_at ${Time.at(record["executionStartTime"]/1000).utc.strftime("%Y-%m-%d %H:%M:%S.%3N")}
      end_at ${Time.at(record["endTime"]/1000).utc.strftime("%Y-%m-%d %H:%M:%S")}
      query ${record["query"]}
      status ${record["state"]}
    </record>
  </match>
</label>

<label @presto-datadog-out>
  <match **>
    @type dd
    dd_api_key <%= ENV['DATADOG_API_KEY'] %>
    <buffer>
      # 略
    </buffer>
  </match>
</label>

<label @presto-bigquery-out>
  <match presto.query_storage.**>
    @id bigquery-partitioned
    @type bigquery
    method load
    auth_method json_key
    json_key /fluentd/env/googleauth_key.json

    <buffer>
      # 略
    </buffer>
  </match>
</label>

結論

event-listenerを用いて、重複・漏れなく効率的にクエリの履歴を残すことができる。 fluentdを使うことで複数のデータストアに結果を送信することができるので、柔軟に監視環境を構築することができる。

datadogの設定をterraform formatで出力するgem dd2tfをリリースした

datadogの設定をterraform formatで出力するgem dd2tfを作った。

github.com

kurochan/datadog_monitor2terraformにインスパイアされて勢いで作った。 (尚動機としては、コード管理していない設定、例えばmonitorを管理者が(レビューの範囲外で)手動操作を行い想定外の挙動をしてしまった出来事があり、アラートは特にしっかりと管理したいモチベーションがあった。)

現在terraform側で扱えるdatadogのリソースとしてはdowntime, monitor, timeboard, userがあって、 このうち現在はmonitor, timeboard, userをサポートしている。

downtimeをそもそも使っていないのでサボってしまったが手間じゃないのではやいうちに追加しなくては。

datadogの設定がコードで記述できるという点はやはりメリットが大きいんだけど、

q = "avg:presto_staging.cluster_memory_manager_metrics.cluster_memory_usage_bytes{*}"

みたいなクエリを毎回書くのか、というと微妙なところで、グラフの様子を見ながらいじって決めるということが多く

今の自分の使い方としては

まず画面でポチポチいじって、dd2tf使ってコードをexportしコードをリポジトリ管理下に置いている。

terraform apply するタイミングで注意することがあって、既存のリソースを terraform import しておかないと、 重複してリソース登録されてしまう。

なので、実際に行う手順としては

  • web consoleから各リソース設定
  • terraform import
    • この際、 dd2tf print <resource> が便利で、 terraform importコマンドを出力してくれる
dd2tf print monitor --dd_api_key=xxx --dd-app_key=xxx
terraform import datadog_monitor.auto_clock_in_sync_with_ntp 29xxxxx
terraform import datadog_monitor.presto_long_time_query_occured 29xxxxxx
  • dd2tf import
dd2tf import monitor --dd_api_key=xxx --dd-app_key=xxx

のようになる。

datadogの使用頻度が増してきているので、且つコミュニケーションの齟齬なく運用できそうなので便利。

ある程度実装してから、 terraform import して得た <resource>.tfstate をparseする方針の方が筋が良いのでは、と思った気がしたけど忘れた。

自作PCやるぞと思ったら時期が悪かった

MacbookProの不安定さにエンジニアのmac離れが進む昨今、PCの組み立ての1つや2つやっておくべきだろJK(死語)という安直な考えからPCを組み立てるためにパーツ選びをした。

パーツ選びの最中って、楽しいなーーーーーーーーー?

よーしパーツ固まった、今週末買いに行くぞ!っていうテンションの絶頂時に「近いうち新世代CPU出るぞ」という情報をもらい、 改めて調べなおして時期が悪いということがわかりテンションがだだ下がっている。

尚新たにリリースされる(た)新世代CPUについては概ね

www.itmedia.co.jp

を参照すると良さそう。この世代から対応チップセットが変わるので、現時点で他のパーツを購入するのはだめっぽい。

少し前にryzenがハイスペ・コスパ良CPUをリリースし、 いい感じにintelと価格競争する体制に入ったのか次世代から10年ぶりらしいラインナップの刷新が行われた。

尚海外では既に発売されているのでベンチマーク等をぐぐるとよい。

尚組もうと思っていたパーツを列挙するが、噂によると新世代CPUはめちゃめちゃコスパの良いモデルもあるようなので、 CPUを新世代に/それに伴いマザボを300シリーズに/電源もちょっとアップデート あたりを予定していて、まぁ乗って+2万くらいじゃね?と予想している。 11月後半には出るんじゃないかと思ってるので楽しみに生きる。

グラボ

まぁ1070くらいでいいのではという気持ち。10万超えのGPU買うくらいなら差分の5万使ってipad proとか360℃カメラとかに投資する。 リリースされているほぼすべてのゲームで高画質プレイできるという話を聞いている。

CPU

intel製で現時点で日本発売済の一般的なレンジの最上位あたり。 別にOCに特別興味はないが多少1コアあたりのスペック高いので。 尚新世代発売したら8700Kか値段によってはi5-8400あたりを買う予定。

ケース

よく知らないので無難 of 無難。水冷にするつもりは最初はないが、最低限冷やし性能を持ちつつ拡張性もあるミドルタワー。

電源

gtx1070使ってて550wの電源使ってて不安定みたいなレビューを見た気がするので600w以上、まあ700あれば長く活きてくれるでしょう5000円程度ケチらないくらいの雑な選択。

マザボ

7700Kに対応してればなんでもいいやくらいの雑な選択。

メモリ

とりあえず16GBあれば人権ある。linux OSにすればmacほど要らんしそんなめちゃくちゃ高画質なゲームやるつもりはないし。あっても4本メモリ挿せる構成なので32GBいける

HDD

んーOSロード用ディスクはSSDにする予定なんだけど今のところHDDでコスト削減をもくろんでいる・・・・が買うタイミングでSSDにしてしまう未来が見える

SSD

一応500GBは確保。

雑に見積もった感じ17万くらいなんだけど新世代のCPUにするにあたりアプデするもの(マザボ等)、SSDの件を考慮するとなんだかんだ20万いきそうだなー15万想定で組んでいるのになー不思議

prestoの挙動で困っているメモ

よく The node may have crashed or be under too much load. などで PrestoQueryError が発生するのでログを辿ったところ、

  • GCが頻発している
  • S3 readが時間がかかっている
  • 謎のWARNが発生している

ことを発見したのでメモ

GCが頻発している

2017-08-18T07:04:13.189Z        INFO    Code-Cache-GC-Trigger   com.facebook.presto.server.CodeCacheGcTrigger   Triggering GC to avoid Code Cache eviction bugs
2017-08-18T07:05:08.208Z        INFO    Code-Cache-GC-Trigger   com.facebook.presto.server.CodeCacheGcTrigger   Triggering GC to avoid Code Cache eviction bugs
2017-08-18T07:05:32.265Z        INFO    Code-Cache-GC-Trigger   com.facebook.presto.server.CodeCacheGcTrigger   Triggering GC to avoid Code Cache eviction bugs
2017-08-18T07:05:56.210Z        INFO    Code-Cache-GC-Trigger   com.facebook.presto.server.CodeCacheGcTrigger   Triggering GC to avoid Code Cache eviction bugs

GCしすぎちゃうか

解決策はいくつかあり、

CodeCacheSizeをいじる

jvmの各パラメータをいじればよさそう

  • InitialCodeCacheSize (byte)
  • ReservedCodeCacheSize (byte)

CodeCacheThresholdをいじる 

classification: presto-configcode-cache-collection-threshold をいじればよさそう(config.properties)

GC1を使えば良さそう

ここは一切チューニング・検証してないのでjust idea JVMとGCについてちゃんと調べなきゃいけないんだけど、Full GCが高い頻度で発生していると問題 Full GCが遅いのは全ての領域対象だから。 New領域のみ対象のScavenge GCなら頻度高くても処理時間はそこまでぽい。

参考: G1GCのつかいどころメモ - nekop's blog

S3 read時間がかかっている

ちょうどquery metricsを取得実装始めていたんだけど、 status: FINISHED のみ取得しており、結果的にFAILEDな本件では情報無く無事死。

com.amazonaws.latency    ServiceName=[Amazon S3], StatusCode=[206], ServiceEndpoint=[https://xxxx.s3-ap-northeast-1.amazonaws.com], RequestType=[GetObjectRequest], AWSRequestID=[xxxx], HttpClientPoolPendingCount=0, RetryCapacityConsumed=0, HttpClientPoolAvailableCount=0, RequestCount=1, HttpClientPoolLeasedCount=4, ResponseProcessingTime=[0.046], ClientExecuteTime=[101.892], HttpClientSendRequestTime=[0.044], HttpRequestTime=[101.613], RequestSigningTime=[0.086], CredentialsRequestTime=[0.0], HttpClientReceiveResponseTime=[73.346],

みたいなログが20-30行程続いており不穏。なんだ101って。異常では

謎のWARNが発生している

Aug 18, 2017 6:44:53 AM WARNING: parquet.hadoop.ParquetRecordReader: Can not initialize counter due to context is not a instance of TaskInputOutputContext, but is org.apache.hadoop.mapreduce.task.TaskAttemptContextImpl

これはバグ?

https://issues.apache.org/jira/browse/SPARK-18660

ふー地道に調べるか