embulk-input-mysqlでのSSL通信にCommunications link failureが出た時の対処法

6699 ワード
Embulk embulk-input-mysql Embulk テキストリンク

経緯

  1. ある時期からSSLExceptionを見かけるようになり、何か対処が必要そうだと思い始める
  2. インスタンスローテーションのため、インスタンス再作成を行った後からエラーが発生し接続不可となった
  3. 応急的にSSL: true (SSL: enableと同義)から、 SSL: false と変更することで動作を確認
  4. 2020年からTLS v1.0/1.1の無効化が決定したのでその影響を疑う
  5. twitterで助けてもらう https://twitter.com/yoshi_ken/status/1398119709732610049
  6. 提案された設定を追加することで解決に至る

結論

embulkに渡す設定ファイルにoptions: {"enabledTLSProtocols":"TLSv1.2"} を指定しましょう。

もし複数のoptionを渡したい時には、次のように複数行表記が良いでしょう。

  options:
    enabledTLSProtocols: TLSv1.2
    sessionVariables: group_concat_max_len=10*1024

JDBC Optionを渡したことによるパラメータの変化

enabledTLSProtocols=TLSv1.2, が増えていることが分かります。

変更前
Connecting to jdbc:mysql://****.rds.amazonaws.com:3306/abc_db options {useCompression=true, socketTimeout=1800000, useSSL=true, user=test, useLegacyDatetimeCode=false, requireSSL=true, tcpKeepAlive=true, verifyServerCertificate=false, connectTimeout=300000, password=***, zeroDateTimeBehavior=convertToNull}

変更後
Connecting to jdbc:mysql://****.rds.amazonaws.com:3306/abc_db options {useCompression=true, enabledTLSProtocols=TLSv1.2, socketTimeout=1800000, useSSL=true, user=test, useLegacyDatetimeCode=false, requireSSL=true, verifyServerCertificate=false, tcpKeepAlive=true, connectTimeout=300000, password=***, zeroDateTimeBehavior=convertToNull}

前兆

次のSSLException が出始めていました

Wed Feb 24 00:08:16 UTC 2021 WARN: Caught while disconnecting...

EXCEPTION STACK TRACE:



** BEGIN NESTED EXCEPTION ** 

javax.net.ssl.SSLException
MESSAGE: closing inbound before receiving peer's close_notify

STACKTRACE:

javax.net.ssl.SSLException: closing inbound before receiving peer's close_notify
    at sun.security.ssl.Alert.createSSLException(Alert.java:133)
    at sun.security.ssl.Alert.createSSLException(Alert.java:117)
    at sun.security.ssl.TransportContext.fatal(TransportContext.java:311)
    at sun.security.ssl.TransportContext.fatal(TransportContext.java:267)
    at sun.security.ssl.TransportContext.fatal(TransportContext.java:258)
    at sun.security.ssl.SSLSocketImpl.shutdownInput(SSLSocketImpl.java:637)
    at sun.security.ssl.SSLSocketImpl.shutdownInput(SSLSocketImpl.java:616)
    at com.mysql.jdbc.MysqlIO.quit(MysqlIO.java:2246)
    at com.mysql.jdbc.ConnectionImpl.realClose(ConnectionImpl.java:4237)
    at com.mysql.jdbc.ConnectionImpl.close(ConnectionImpl.java:1465)
    at org.embulk.input.jdbc.JdbcInputConnection.close(JdbcInputConnection.java:208)
    at org.embulk.input.jdbc.AbstractJdbcInputPlugin.transaction(AbstractJdbcInputPlugin.java:215)
    at org.embulk.exec.BulkLoader.doRun(BulkLoader.java:507)
    at org.embulk.exec.BulkLoader.access$000(BulkLoader.java:35)
    at org.embulk.exec.BulkLoader$1.run(BulkLoader.java:353)
    at org.embulk.exec.BulkLoader$1.run(BulkLoader.java:350)
    at org.embulk.spi.Exec.doWith(Exec.java:22)
    at org.embulk.exec.BulkLoader.run(BulkLoader.java:350)
    at org.embulk.EmbulkEmbed.run(EmbulkEmbed.java:178)
    at org.embulk.EmbulkRunner.runInternal(EmbulkRunner.java:292)
    at org.embulk.EmbulkRunner.run(EmbulkRunner.java:156)
    at org.embulk.cli.EmbulkRun.runSubcommand(EmbulkRun.java:433)
    at org.embulk.cli.EmbulkRun.run(EmbulkRun.java:90)
    at org.embulk.cli.Main.main(Main.java:64)


** END NESTED EXCEPTION **

後日、Communications link failureというエラーが発生しSSL通信に失敗していました。

2021-05-25 06:22:00.934 +0000 [INFO] (0001:transaction): Connecting to jdbc:mysql://****.rds.amazonaws.com:3306/abc_db options {useCompression=true, socketTimeout=1800000, useSSL=true, user=test, useLegacyDatetimeCode=false, requireSSL=true, tcpKeepAlive=true, verifyServerCertificate=false, connectTimeout=300000, password=***, zeroDateTimeBehavior=convertToNull}
org.embulk.exec.PartialExecutionException: java.lang.RuntimeException: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 222 milliseconds ago.  The last packet sent successfully to the server was 217 milliseconds ago.
    at org.embulk.exec.BulkLoader$LoaderState.buildPartialExecuteException(BulkLoader.java:340)
    at org.embulk.exec.BulkLoader.doRun(BulkLoader.java:566)
    at org.embulk.exec.BulkLoader.access$000(BulkLoader.java:35)
    at org.embulk.exec.BulkLoader$1.run(BulkLoader.java:353)
    at org.embulk.exec.BulkLoader$1.run(BulkLoader.java:350)
    at org.embulk.spi.Exec.doWith(Exec.java:22)
    at org.embulk.exec.BulkLoader.run(BulkLoader.java:350)
    at org.embulk.EmbulkEmbed.run(EmbulkEmbed.java:178)
    at org.embulk.EmbulkRunner.runInternal(EmbulkRunner.java:292)
    at org.embulk.EmbulkRunner.run(EmbulkRunner.java:156)
    at org.embulk.cli.EmbulkRun.runSubcommand(EmbulkRun.java:433)
    at org.embulk.cli.EmbulkRun.run(EmbulkRun.java:90)
    at org.embulk.cli.Main.main(Main.java:64)
    Suppressed: java.lang.NullPointerException
        at org.embulk.exec.BulkLoader.doCleanup(BulkLoader.java:463)
        at org.embulk.exec.BulkLoader$3.run(BulkLoader.java:397)
        at org.embulk.exec.BulkLoader$3.run(BulkLoader.java:394)
        at org.embulk.spi.Exec.doWith(Exec.java:22)
        at org.embulk.exec.BulkLoader.cleanup(BulkLoader.java:394)
        at org.embulk.EmbulkEmbed.run(EmbulkEmbed.java:181)
        ... 5 more
Caused by: java.lang.RuntimeException: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

参考記事