ブログトップ 記事一覧 ログイン 無料ブログ開設

wyukawa’s blog

2017-01-17

haveged入れたらOracle DBに対するsqoop importでConnection resetが出なくなった

Oracle DBに対してsqoop importするときに下記のようにurandomを使うのは割と一般的な話かなと思います。

sqoop import -D mapreduce.map.java.opts="-Djava.security.egd=file:/dev/../dev/urandom" ...

sqoopのマニュアルにも書いてありますね。

https://sqoop.apache.org/docs/1.4.6/SqoopUserGuide.html#_oracle_connection_reset_errors

この辺も参考になるかも

ORACLEと接続するJavaで作ったバッチ処理が動かないときの対処方法 - Qiita

どうやらOracleのJDBCドライバが内から呼び出しているSecureRandomクラスでのシード生成で時間がかかってコネクションが切れてしまうっぽいです。

この設定をしているにもかかわらず、下記のようなエラーが出るようになってちょっと困ってました。ただ5分後のリトライでは成功していたのでなんか気持ち悪いなと思いつつ放置していました。

java.sql.SQLRecoverableException: IO Error: Connection reset
    at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:498)
    at oracle.jdbc.driver.PhysicalConnection.<init>(PhysicalConnection.java:553)
    at oracle.jdbc.driver.T4CConnection.<init>(T4CConnection.java:254)
    at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:32)
    at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:528)
    at java.sql.DriverManager.getConnection(DriverManager.java:571)
    at java.sql.DriverManager.getConnection(DriverManager.java:215)
    at org.apache.sqoop.manager.OracleManager.makeConnection(OracleManager.java:322)
    at org.apache.sqoop.manager.GenericJdbcManager.getConnection(GenericJdbcManager.java:52)
    at org.apache.sqoop.manager.SqlManager.execute(SqlManager.java:685)
    at org.apache.sqoop.manager.SqlManager.execute(SqlManager.java:708)
    at org.apache.sqoop.manager.SqlManager.getColumnTypesForRawQuery(SqlManager.java:243)
    at org.apache.sqoop.manager.SqlManager.getColumnTypes(SqlManager.java:226)
    at org.apache.sqoop.manager.ConnManager.getColumnTypes(ConnManager.java:347)
    at org.apache.sqoop.orm.ClassWriter.getColumnTypes(ClassWriter.java:1298)
    at org.apache.sqoop.orm.ClassWriter.generate(ClassWriter.java:1110)
    at org.apache.sqoop.tool.CodeGenTool.generateORM(CodeGenTool.java:96)
    at org.apache.sqoop.tool.ImportTool.importTable(ImportTool.java:396)
    at org.apache.sqoop.tool.ImportTool.run(ImportTool.java:506)
    at org.apache.sqoop.Sqoop.run(Sqoop.java:147)
    at org.apache.hadoop.util.ToolRunner.run(ToolRunner.java:70)
    at org.apache.sqoop.Sqoop.runSqoop(Sqoop.java:183)
    at org.apache.sqoop.Sqoop.runTool(Sqoop.java:222)
    at org.apache.sqoop.Sqoop.runTool(Sqoop.java:231)
    at org.apache.sqoop.Sqoop.main(Sqoop.java:240)
Caused by: java.net.SocketException: Connection reset
    at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:118)
    at java.net.SocketOutputStream.write(SocketOutputStream.java:159)
    at oracle.net.ns.DataPacket.send(DataPacket.java:210)
    at oracle.net.ns.NetOutputStream.flush(NetOutputStream.java:230)
    at oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:321)
    at oracle.net.ns.NetInputStream.read(NetInputStream.java:268)
    at oracle.net.ns.NetInputStream.read(NetInputStream.java:190)
    at oracle.net.ns.NetInputStream.read(NetInputStream.java:107)
    at oracle.jdbc.driver.T4CSocketInputStreamWrapper.readNextPacket(T4CSocketInputStreamWrapper.java:124)
    at oracle.jdbc.driver.T4CSocketInputStreamWrapper.read(T4CSocketInputStreamWrapper.java:80)
    at oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1137)
    at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:350)
    at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:227)
    at oracle.jdbc.driver.T4CTTIoauthenticate.doOSESSKEY(T4CTTIoauthenticate.java:407)
    at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:416)
    ... 24 more

そんなおりに見つけたこのブログ

/dev/random のエントロピーが足りないときは Haveged を使う - tokuhirom's blog

エントロピーってなんじゃらほいとか思いつつ、すでにインストールしていたnode_exporterのnode_entropy_available_bitsをみたら確かにConnection resetが起きた時間帯のエントロピーが0に近い。

f:id:wyukawa:20170117163002p:image

havege入れたら下記のようにエントロピーが急増しました。

f:id:wyukawa:20170117163003p:image

havege入れて1週間ぐらい経ちましたがまだConnection resetは起きてないです。

たぶん最初はバッチの数が少なかったからエントロピーが足りてたんだと思います。

あとsqoopを実行するバッチサーバーはひとつなので足りなくなりがちだったのかなとも思います。

2016-12-30

ベジタブルマラソン走ってきた

記録はネットタイムが1時間49分33秒。去年が1時間44分17秒、一昨年が1時間42分7秒(なおこれがハーフのベストです)だったのでそれに比べるとだいぶ遅い。衰えは隠せないですが、走っている時はエイドのキュウリ、ミニトマト、パイナップル、オレンジを少々、走り終わった後は豚汁、熊谷駅ではうどん、を食べて帰ってきました。

今日が走り納めです。今年はフルを7回ハーフを2回走りました。フルが増えてハーフが減りましたね。来年も似たような感じになると思います。

2016-12-29

2016振り返り

今日が仕事納めでした。

今年も去年に引き続いてデータエンジニアリング業していたんですが、違いとしては今年に入ってからモニタリングにPrometheusを試すようになり、その延長でPromCon 2016に登壇しました。海外のカンファレンスで喋るのは初めての経験です。うまくプレゼンできたかは自分ではよくわからんですが、いい経験でした。ただ英語は厳しいですね。オフラインでの雑談以外でもプレゼンの内容を理解できないことも多くもっと勉強しないとなと思いました。

英語の勉強は2015年3月に会社の補助でレアジョブを始めて以来コツコツとやってますが、最近は伸び悩んでいる感じです。今はレアジョブ、iKnow、HiNavtive Trekをやってますが、やり方を変えようかなあと考えてます。とくにTrekは高いので。

他にはHadoopクラスタのアップグレード、Elasticsearchの導入とアップグレード、Fluentdの運用といったことをやってきました。他にも既存ツールのメンテナンスは随時やってました。yanagishimaとかshibとか。

直近ではSpring Bootを使ったAPIサーバーの実装もやりました。この経験があってひらめいたんですが、Prestoの実行結果をキャッシュするAPIサーバーaoshimaを実装しました。ただまだREADMEはちゃんと書いてないです。

https://github.com/wyukawa/aoshima

なんで実装したかというとBIツールからのクエリを高速化するためです。prestogresからprestoにクエリをなげるんじゃなくてaoshimaがprestoのふりをして結果をキャッシュするのを試そうとしています。prestogres -> aoshima -> presto という経路です。まだプロダクション運用はしてないですが、管理画面も実装したのでこれを使ってうまいことレポートを高速化できないかともくろんでいます。

今年のgithub.comでの活動状況は下記で去年と比べると減りましたね。

f:id:wyukawa:20161229155825p:image

rebuildfmリスナーだった影響もあり、他のpodcastもいろいろ聞いてたんですが、ついに9月から自分でpodcastを始めました。音が小さい、内輪向け、といったフィードバックもありますが、改善して細々と続けられたらなと思ってます。

https://itunes.apple.com/jp/podcast/wyukawas-podcast/id1152456701

今年はフルマラソンを7回走りました。サブ4は一回だけなのでこちろも記録が停滞しておりますが、楽しみながらやってます。

2016-12-13

fluent-plugin-elasticsearchでCannot get new connection from poolが出た

題名の通りで動作環境は以下の通りです。

Elasticsearch側はcerebroで見る限りgreenで正常に見えました。

  • fluentd 0.12.27
  • fluent-plugin-elasticsearch 1.9.0
  • Elasticsearch 5.0.1

fluentdの設定はこんな感じ

<match ...>
  type forest
  subtype elasticsearch
  <template>
    hosts ...
    id ...
    buffer_type "file"
    buffer_path "..."
    flush_at_shutdown true
    buffer_chunk_limit 4m
    buffer_queue_limit 512
    flush_interval 1s
    num_threads 8
    logstash_format true
    logstash_prefix ${tag}
    utc_index false
    type_name fluentd
    include_tag_key true
    tag_key tag_key 
    request_timeout 30s
  </template>
</match>

エラーログはこんな感じ

error_class="Elasticsearch::Transport::Transport::Error" error="Cannot get new connection from pool." plugin_id="..."
/home/.../local/ruby-2.1/lib/ruby/gems/2.1.0/gems/elasticsearch-transport-1.0.18/lib/elasticsearch/transport/transport/base.rb:249:in `perform_request'
/home/.../local/ruby-2.1/lib/ruby/gems/2.1.0/gems/elasticsearch-transport-1.0.18/lib/elasticsearch/transport/transport/http/faraday.rb:20:in `perform_request'
/home/.../local/ruby-2.1/lib/ruby/gems/2.1.0/gems/elasticsearch-transport-1.0.18/lib/elasticsearch/transport/client.rb:128:in `perform_request'
/home/.../local/ruby-2.1/lib/ruby/gems/2.1.0/gems/elasticsearch-api-1.0.18/lib/elasticsearch/api/actions/bulk.rb:90:in `bulk'
/home/.../local/ruby-2.1/lib/ruby/gems/2.1.0/gems/fluent-plugin-elasticsearch-1.9.0/lib/fluent/plugin/out_elasticsearch.rb:353:in `send_bulk'
/home/.../local/ruby-2.1/lib/ruby/gems/2.1.0/gems/fluent-plugin-elasticsearch-1.9.0/lib/fluent/plugin/out_elasticsearch.rb:339:in `write_objects'
/home/.../local/ruby-2.1/lib/ruby/gems/2.1.0/gems/fluentd-0.12.27/lib/fluent/output.rb:480:in `write'
/home/.../local/ruby-2.1/lib/ruby/gems/2.1.0/gems/fluentd-0.12.27/lib/fluent/buffer.rb:354:in `write_chunk'
/home/.../local/ruby-2.1/lib/ruby/gems/2.1.0/gems/fluentd-0.12.27/lib/fluent/buffer.rb:333:in `pop'
/home/.../local/ruby-2.1/lib/ruby/gems/2.1.0/gems/fluentd-0.12.27/lib/fluent/output.rb:338:in `try_flush'
/home/.../local/ruby-2.1/lib/ruby/gems/2.1.0/gems/fluentd-0.12.27/lib/fluent/output.rb:149:in `run'

時系列でいうと以下のような感じ

11/17(木) Elasticsearch 5にアップグレード

12/3(土) 「Cannot get new connection from pool.」発生。fluentd再起動して一旦回避

12/5(月) FluentdからAmazon Elasticsearch Serviceへログ転送する時の注意点 | 本日も乙およびElasitcsearch-ruby raises "Cannot get new connection from pool" error - Elasticsearch - Discuss the Elastic Stack を見てresurrect_afterを0に設定

12/9(金) 「Cannot get new connection from pool.」再度発生。

試しにreload_on_failure trueにして再起動するもすぐ再発

Amazon Elasticsearch使ってないけどreload_connections falseにして再起動するもすぐ再発

fluent-plugin-elasticsearchが依存しているelasticsearch-rubyのソース見てもなぜget_connectionでnilかfalseが返ってくるのか理解できず、排他制御周りでなんかバグってるのかなと思い、num_threads 1にして再起動するもすぐ再発

https://github.com/elastic/elasticsearch-ruby/blob/master/elasticsearch-transport/lib/elasticsearch/transport/transport/base.rb

        def perform_request(method, path, params={}, body=nil, &block)
          raise NoMethodError, "Implement this method in your transport class" unless block_given?
          start = Time.now if logger || tracer
          tries = 0

          begin
            tries     += 1
            connection = get_connection or raise Error.new("Cannot get new connection from pool.")
        def get_connection(options={})
          resurrect_dead_connections! if Time.now > @last_request_at + @resurrect_after

          @counter_mtx.synchronize { @counter += 1 }
          reload_connections!         if reload_connections && counter % reload_after == 0
          connections.get_connection(options)
        end

        # Reloads and replaces the connection collection based on cluster information
        #
        # @see Sniffer#hosts
        #
        def reload_connections!
          hosts = sniffer.hosts
          __rebuild_connections :hosts => hosts, :options => options
          self
        rescue SnifferTimeoutError
          logger.error "[SnifferTimeoutError] Timeout when reloading connections." if logger
          self
        end

        # Tries to "resurrect" all eligible dead connections
        #
        # @see Connections::Connection#resurrect!
        #
        def resurrect_dead_connections!
          connections.dead.each { |c| c.resurrect! }
        end

https://github.com/elastic/elasticsearch-ruby/blob/master/elasticsearch-transport/lib/elasticsearch/transport/transport/connections/connection.rb

          def resurrect!
            alive! if resurrectable?
          end

          # Returns true if the connection is eligible to be resurrected as alive, false otherwise.
          #
          # @return [Boolean]
          #
          def resurrectable?
            @state_mutex.synchronize {
              Time.now > @dead_since + ( @options[:resurrect_timeout] * 2 ** (@failures-1) )
            }
          end

resurrect_afterが0ならすぐresurrect_dead_connections!が呼ばれてコネクション使えそうだけど、resurrect_timeout(defaultが60s)をexponential backoffした分は待ちそう。

resurrect_timeoutいじろうかと思ったけどfluent-plugin-elasticsearch側からresurrect_timeoutを設定できない。

この時点でだいぶ困ったけど、fluent-plugin-elasticsearchが使っているelasticsearch-rubyが1.0.18なのに気づく。

僕が使っているのはElasticsearch 5なので5系を使うべきなのではと思い始める。

だって、

https://github.com/elastic/elasticsearch-ruby

にも1系は1系しか互換性なさそうに見えるし。

そんなわけでgemspecをいじってdeployしたらこの日はエラーが収まって今のところ大丈夫という状況です。

https://github.com/wyukawa/fluent-plugin-elasticsearch/commit/b73cc0e21d8558d536c7819adcc3eb3b89ec5368

Elasticsearch側は問題なさそうに見えた。Elasticsearch 2.4を使っているときは発生してなかった。

この辺から想像するにelasitcsearch-rubyに何か関係してそうな気はしてますが、正直わかりません。

なんかわかったら教えてもらえると嬉しいです。

2016-12-12

青島太平洋マラソンを走ってきた

第30回青島太平洋マラソン2016

去年参加して応援の素晴らしさに感動したので今年も行ってきました。

青島太平洋マラソン走ってきた - wyukawa’s blog

ホテルや飛行機は去年と同じく大会のサイトで案内されている宿泊プランでまかないました。

ホテルで選手受付できるし、ホテルからスタート地点までバスで送ってくれるので便利です。

天気は去年と同じく暖かかくて良いコンディションでした。

結果はネットタイムで4時間16分58秒。練習状況を考えるとこんなもんかな。

最初の10kmぐらいは国道をひたすら走るので応援は少ないですが、宮崎市街地に入ると応援が増えてきて、宮崎神宮で折り返すポイントがピークなのかなという感じでした。20km過ぎまでは素晴らしい応援が続きます。

後半はラスト10kmが青島に行って折り返すコースで、ゴールである運動公園に一回近づいてからまた遠ざかります。去年は、「あれ、もうゴールだっけ?」って一瞬思いました。ラスト10kmはコースが狭くなりますが、海沿いを走るので景色は良いです。

ゴール後は屋台でうどん食った後に、青島グランドホテルで温泉行って汗を流しました。この辺は去年と同じ。マラソン参加者は入浴料が600円から300円になります。あとタクシーの割引券も2枚もらえるので、僕は運動公園〜青島グランドホテル、青島グランドホテル〜宮崎空港間で使いました。

関東圏の人はこの時期はつくばマラソンか湘南国際マラソンに出る人が多いと思いますが、僕は来年もたぶん青島太平洋マラソンに出てそうな気がします。