Elasticsearch, Kibanaを6.7.1から7.1.1にupgradeした

やり方は https://wyukawa.hatenablog.com/entry/20180124/1516762676  と同じで上書きアップグレードじゃなくて新旧double writeして切り替えました。

うちの環境だとfluentd→kafka→kafka-fluentd-consumer→fluentd→Elasticsearchという経路でElasticsearchに書き込んでいます。

すんなり行くかと思いきや結構難航しました。もっとも今回問題に遭遇したのはElasticsearchではなくそこに入れるfluentdのところでした。

もともとはfluentd 1系で、fluent-plugin-elasticsearch 2.11.10を使ってElasticsearch 6にデータを入れていました。

Elasticsearchは7からタイプが無くなるのでfluentdの設定ではtype_name _docとします。 https://www.elastic.co/blog/moving-from-types-to-typeless-apis-in-elasticsearch-7-0

またindex templateで_default_をなくす必要があります。

fluent-plugin-elasticsearch 3.4.2以前だと https://github.com/uken/fluent-plugin-elasticsearch/pull/573 が入ってないので下記のWARNが大量にでます。

[warn]: #0 [...] Detected ES 7.x or above: `_doc` will be used as the document `_type`.

一方で、当時最新だった3.4.2だと https://github.com/uken/fluent-plugin-elasticsearch/pull/586 の影響でCPU使用率が高くなります。 https://github.com/uken/fluent-plugin-elasticsearch/issues/584

そこは対応してもらって、https://github.com/uken/fluent-plugin-elasticsearch/pull/586 3.5.1でbulk_message_request_threshold -1にしました。

これで解決と思いきやElasticsearchを再起動するとfluentd側でdeadlockが起きてログ送信に失敗し続けます。

fluent-plugin-elasticsearchの問題なのかelasticsearcy rubyの問題なのか判断がつかなかったので両方にissue登録しました。 https://github.com/elastic/elasticsearch-ruby/issues/656 https://github.com/uken/fluent-plugin-elasticsearch/issues/587

で、その後fluent-plugin-elasticsearch 3.5.2, elasticsearch ruby 7.1.0にあげたらこの問題が起きなくなったのでこのissueはcloseしました。

なので最終的なGemfileのbefore/afterは下記です。

before

source 'https://rubygems.org'    
gem "fluentd", "1.2.5"  
gem "oj", "3.6.7"   
gem "fluent-plugin-ping-message", "1.0.0"   
gem "fluent-plugin-record-reformer", "0.9.1"    
gem "fluent-plugin-suppress", "1.0.0"   
gem "fluent-plugin-elasticsearch", "2.11.10"    
gem "typhoeus", "1.3.0" 
gem "fluent-plugin-prometheus", "1.0.1"

after

source 'https://rubygems.org'
gem "fluentd", "1.4.2"
gem "oj", "3.7.12"
gem "fluent-plugin-ping-message", "1.0.0"
gem "fluent-plugin-record-reformer", "0.9.1"
gem "fluent-plugin-suppress", "1.1.0"
gem "fluent-plugin-elasticsearch", "3.5.2"
gem "typhoeus", "1.3.1"
gem "fluent-plugin-prometheus", "1.3.0"

他にはCuratorによるdaily batchでのindex削除をやめてIndex Lifecycle Management(ILM)を使うようにしました。 index delete用のpolicyをKibana上から作って、cerebroで下記のようにindex templateを指定します。

  "settings": {
    "index": {
      "lifecycle": {
        "name": "delete-daily-policy"
      },
      ...
    }
  },

index templateをいじるときはcerebro使ってます。

これでめでたしと思ったらKibana monitoringでNodeが見れない! search.max_bucket増やして一瞬解決したと思ったけど、結局Kibanaのbugらしい。 https://github.com/elastic/kibana/issues/36892

他にはthread_pool.write.queue_size: 1000と増やしてもやっぱり下記のようなエラーがたまに出る。もっと増やす必要があるのかなあ。

Description: last_log: [2019-07-03T00:00:42,038 +0900][ERROR][o.e.a.b.TransportBulkAction] [...] failed to execute pipeline for a bulk request
org.elasticsearch.common.util.concurrent.EsRejectedExecutionException: rejected execution of org.elasticsearch.ingest.IngestService$4@677150d7 on EsThreadPoolExecutor[name = .../write, queue capacity = 1000, org.elasticsearch.common.util.concurrent.EsThreadPoolExecutor@edd1093[Running, pool size = 40, active threads = 40, queued tasks = 1087, completed tasks = 23132289]]

南魚沼グルメマラソン

6年連続6回目の参加です。結果はネットタイムで1時間54分41秒でした。

 

去年とは違って8:26に浦佐駅につく一本遅い新幹線で来たけど9:00のスタートに普通に間に合ったので来年参加する場合もこれでいこうかな。

今年は荷物預かりの場所が変わって、グルメ村から少し遠くなって、預け入れ・受け取りに時間がかかるようになってた。それ以外はいつも通りの素晴らしい大会でした。

 

いつものようにゴール後はごはんとつまみとビール。この後、鮎の塩焼きと汁物とビール2杯目もいっちゃった。鶏肉を焼いてるのがすげーうまそうだったけど、並んでたので断念。

https://www.instagram.com/p/ByeS3l0A1yk/

gourmet marathon done

 

黒部名水マラソンで走ってきた

去年申し込んだけど諸事情で参加できなかった大会に行ってきました。

感想は、ともかく暑かった。。常時30度超えのなかネットタイム4:31:59はまあよく走った方でしょう。

ほぼ2kmごとに給水があるのでそれで完走できました。

36kmのエイドではアイスがあってしかもベンチもあったのでちょっと座ってゆっくり食していました。アイスうまい。ついでにトイレも行ってスッキリして残り頑張れました。

掛川・新茶マラソンで走ってきた

去年に続いて5回目の参加です。
https://wyukawa.hatenablog.com/entry/20180415/1523793968

結果はネットタイムが4時間7分58秒でした。前半はよかったけど30km以降失速。

おにぎり、戦国汁、バナナ、メロン、いちご、オレンジいただきました。ごちそうさまです。

今年は更衣室と荷物預かりの場所がスタート、ゴール地点の近くになってて良かった。

この大会は坂がきついもののエイドも充実してるし、関東近辺なら日帰りで行けるし、人数がそこまで多くないせいかスタート前のトイレもそんなに混んでなくて、良い大会だと思うんだけど、runnetの評価があんまり高くないのはなんでだろう。

鳥取マラソン

鳥取ラソンで走ってきた。

www.nnn.co.jp

 

記録はネットタイムでギリギリサブ4の3:59:31

シーズンに1回はサブ4出したいと思っててなんとか達成できた。

しかし代償としてエイドのうどん食いそびれたw

 

大会としては良い大会なんだけど、もうちょっと給水を増やしていただけるとありがたい。。

 

鳥取砂丘のそばからスタートして県庁、とりぎんバードスタジアムを通り陸上競技場がゴール。地味にアップダウンがあり雨も降っててちょっと大変だったけど、最後までペースは保ててゴールできた。

 

ゴール後は牛骨ラーメン500円とランナーには無料配布されるおしるこ食って帰宅

spark thrift server gc

spark thrift serverが不安定でOutOfMemoryになったりしてたんでJVMオプションをいじってた。

うちの環境だとambari管理なのでjava heapを増やす場合はAdvanced spark2-envのspark_daemon_memoryを増やせばOKです。ちなみにデフォルトは1GBです。 それ以外はSPARK_DAEMON_JAVA_OPTSを設定します。下記のような感じ。ちなみにどっちもいじるとspark history serverでも有効になります。

export SPARK_DAEMON_JAVA_OPTS="$SPARK_DAEMON_JAVA_OPTS -javaagent:/usr/local/lib/jmx_prometheus_javaagent-0.11.0.jar=20015:/usr/local/etc/jmx_exporter_spark.yaml -Xloggc:/var/log/spark2/gc_%p_%t.log -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps"

で、GCログを見ると以下のようになってる。

2019-03-08T12:54:41.265+0900: 89936.447: [GC (Allocation Failure) [PSYoungGen: 1225762K->14514K(1689088K)] 3800753K->2593725K(6508032K), 0.0097586 secs] [Times: user=0.16 sys=0.00, real=0.01 secs]
2019-03-08T12:55:25.468+0900: 89980.650: [GC (Allocation Failure) [PSYoungGen: 1228978K->11218K(1225728K)] 3808189K->2593142K(6044672K), 0.0093735 secs] [Times: user=0.14 sys=0.00, real=0.01 secs]
2019-03-08T12:55:57.112+0900: 90012.294: [GC (System.gc()) [PSYoungGen: 937862K->8066K(1673216K)] 3519786K->2591721K(6492160K), 0.0087363 secs] [Times: user=0.15 sys=0.01, real=0.01 secs]
2019-03-08T12:55:57.121+0900: 90012.303: [Full GC (System.gc()) [PSYoungGen: 8066K->0K(1673216K)] [ParOldGen: 2583655K->1464248K(4818944K)] 2591721K->1464248K(6492160K), [Metaspace: 154960K->154935K(1187840K)], 1.3926389 secs] [Times: user=32.27 sys=0.12, real=1.39 secs]
2019-03-08T12:56:37.166+0900: 90052.347: [GC (Allocation Failure) [PSYoungGen: 1220096K->3678K(1224192K)] 2684344K->1467927K(6043136K), 0.0078803 secs] [Times: user=0.11 sys=0.00, real=0.01 secs]
2019-03-08T12:57:20.567+0900: 90095.748: [GC (Allocation Failure) [PSYoungGen: 1223774K->5886K(1647104K)] 2688023K->1470135K(6466048K), 0.0088429 secs] [Times: user=0.11 sys=0.00, real=0.01 secs]
2019-03-08T13:01:22.166+0900: 90337.347: [GC (Allocation Failure) [PSYoungGen: 1230590K->3231K(1228288K)] 2694839K->1467479K(6047232K), 0.0100951 secs] [Times: user=0.13 sys=0.01, real=0.01 secs]

Full GC (System.gc())ってなんじゃらほいって思ったけど、どうもcontext-cleaner-periodic-gcスレッドでSystem.gc()呼んでる模様 https://github.com/apache/spark/blob/v2.1.1/core/src/main/scala/org/apache/spark/ContextCleaner.scala#L128

なおambari管理だとspark thrift serverが不安定になると二度的に再起動してくれるので便利

release yanagishima 19.0(support sparksql)

yanagishimaというpresto web uiを作っていて気づけばhive, elasticsearchに続いてsparksqlをサポートしたので今回はその辺をちょっと書いてみようと思います。 https://github.com/yanagishima/yanagishima

sparkではspark thrift serverなるものを起動すればHive JDBC Driverを使ってsqlをsubmitすることができます。 https://spark.apache.org/docs/latest/sql-distributed-sql-engine.html

うちの環境だとsparkをyarn上で動かしています。 この場合spark thrift serverを起動すると一つのyarn applicationが立ち上がります。 このApplication Masterのリンクをクリックするとsparkのweb uiを見ることができます。 http://sparkthriftserver:4040にアクセスしても同じ。

複数のユーザがこのyarn applicationを共有する感じになります。 containerというかexecutorの数はsparkのdynamic allocationの仕組みで動いていてdefaultだとmaxでも10個のcontainerしか動かないので、うちの環境では増やしてます。 spark.dynamicAllocation.minExecutorsを50にしているので最初は50個のcontainerが動きます。 ちなみにspark thrift serverで一つ使うので合計すると51個動きます。

またspark thrift serverはdefaultだと1GBのメモリで動いていてOutOfMemoryに遭遇したので4GBに増やしました。 https://community.hortonworks.com/content/supportkb/233822/sparkthriftserver-crashing-with-java-heap-outofmem.html

うちはHDP環境なのでAmbariでSPARK_DAEMON_MEMORYをいじって設定しました。

なお僕はyanagishimaを作って運用して4年ぐらい経ちますが、この手のビッグデータを扱うsqlフロントエンドツールではジョブをsubmitして結果を表示するだけでは不十分です。

ジョブの進捗状況が見れて、クエリを途中でキャンセル出来ることが重要です。また全ジョブの実行状況が見れることも管理上必要です。

そしてつくづく分かったのはprestoはapiというかアーキテクチャからして上記の要件を実装しやすいが、他はそれが簡単ではないということです。 prestoの場合はJDBCではなくpresto-clientを使えばジョブをsubmitしてすぐにquery idを取得できます。 そしてこのquery idを使ってapiをたたけば途中の進捗状況も取れますし、クエリのキャンセルも可能です。 ジョブの一覧を見るのも容易です。

一方、Hive JDBC Driverを使うとStatement#cancelを使えばクエリのキャンセルこそできますが、進捗状況や全ジョブ一覧を知るには一工夫必要です。 Hive on MapReduceであればyarn rest apiを使えば割といろいろできますが、自分が投げたジョブがどのジョブかを判断するのは簡単ではありません。

yanagishima hiveではshibを真似してmapreduce.job.nameをいじってyanagishima-hive-wyukawa-20190305_060438_9235eaae6f11cd0ff3de907771b28914みたいなユニークなidを採番して設定してトラッキングします。 このidは自前で採番します。prestoとはここが違います。

Hive on Tezだと同じことができないので進捗状況を知ることができません。

sparksqlの場合はどうするかというとすごく泥臭いことをしました。

sparkもapiはありますが、十分ではありません。 https://spark.apache.org/docs/latest/monitoring.html https://medium.com/@an_chee/how-to-get-spark-metrics-as-json-using-spark-rest-api-in-yarn-cluster-mode-52a88002c826

sparkのjob idがわかればnumCompletedTasks / numTasksで進捗状況がわかります。 問題はどうやって知るかです。

http//[resourcemanager]:8088/proxy/[spark application id]/api/v1/applications/[spark application id]/jobs をたたけばジョブ一覧が取れます。

以下は一つのジョブの例です。

  "jobId" : 15,
  "name" : "run at AccessController.java:0",
  "submissionTime" : "2019-02-21T02:23:54.513GMT",
  "stageIds" : [ 21 ],
  "jobGroup" : "b46b9cee-bb9d-4d10-8b44-5f7328ce5748",
  "status" : "RUNNING",
  "numTasks" : 1093,
  "numActiveTasks" : 1,
  "numCompletedTasks" : 488,
  "numSkippedTasks" : 0,
  "numFailedTasks" : 0,
  "numActiveStages" : 1,
  "numCompletedStages" : 0,
  "numSkippedStages" : 0,
  "numFailedStages" : 0

これだけだと誰がどんなクエリ投げたのかわからないですが、http://sparkthriftserver:4040/sqlserverSQL StatisticsのところにUser, JobID, GroupID, Start Time, Finish Time, Duration, Statement, State, Detail があって、ここのJobIDと上記のjobGroupを紐づければ誰がどんなクエリを投げたかわかります。やったね。 だがしかしapiが無いようなので仕方なくhtml parseしました。。。

ともあれ、そんな感じで作りました。

sparkも今後rest apiが充実するといいなあというか、そういう状況だからApache Livyが存在しているという気もする。 遠い昔まだhadoop 1の時代にrest apiがなかったのでHuahin Managerがあったように。