スクエニ ITエンジニア ブログ

MavenのConnecion timed outと向き合う

yotaです。 私のチームではCI/CDツールConcourse上でMavenを使ったJavaプロジェクトのビルド環境を構築中です。 この記事はこちらの記事で言及した、

実は後にConnection timed outの根本的な原因が判明したのですが、それは別途投稿します。

にあたるものです。

今回の問題は、MavenによるJavaプロジェクトのビルドが時折Connection timed outでエラーになることでした。
以下のようなエラーですが、対象となるプラグイン、ライブラリは常に同じというわけではありませんでした。

[ERROR] Failed to execute goal org.apache.maven.plugins:maven-surefire-plugin:3.0.0-M8:test (default-test) on project <プロジェクト名>: Execution default-test of goal org.apache.maven. 
plugins:maven-surefire-plugin:3.0.0-M8:test failed: Plugin org.apache.maven.
plugins:maven-surefire-plugin:3.0.0-M8 or one of its dependencies could not be resolved: Failed to collect dependencies at org.apache.maven.plugins:maven-surefire-plugin:jar:3.0.0-M8 -> org.apache.maven.
surefire:maven-surefire-common:jar:3.0.0-M8: Failed to read artifact descriptor for org.apache.maven.
surefire:maven-surefire-common:jar:3.0.0-M8: Could not transfer artifact org.apache.maven.
surefire:maven-surefire-common:pom:3.0.0-M8 from/to (https://<社内ミラーリポジトリ>): transfer failed for https://<社内ミラーリポジトリ>/org/apache/maven/surefire/maven-surefire-common/3.0.0-M8/maven-surefire-common-3.0.0-M8.pom: Connect to <社内ミラーリポジトリ>:443 failed: Connection timed out (Connection timed out) -> [Help 1]

Maven…?

Maven実行のジョブ以外では同様の問題は発生していなかったので、Mavenに見当をつけてインターネット上で調べていると、偶然以下のGitHubのissueを見つけました。

https://github.com/actions/runner-images/issues/1499

これはGitHub Actions (GitHub-hosted runner)上で同様にConnection timed outが頻発するという旨のissueでした。

抜粋すると、

  • これはおそらくGitHub-hosted runnerではなく、AzureのNATの挙動で、Mavenは長期間のコネクションを保持しようとするが、AzureのNATが途中でパケットを落としてしまうよう
  • Mavenの設定で -Dhttp.keepAlive=false -Dmaven.wagon.http.pool=false と付与するとよさそう
    • -Dmaven.wagon.httpconnectionManager.ttlSeconds=120 もセットで、と言及されている投稿もあるが、不要そう

という内容でした。我々の環境はGitHub ActionsでもAzureでもないですが、事象として似ていたので適用してみることにしました。

パイプライン設定の詳細は割愛しますが、 我々のパイプラインでも -Dhttp.keepAlive=false -Dmaven.wagon.http.pool=false を指定して実行するように変更したところ、明らかに従来より安定するようになりました。

具体的には、設定前後のMaven実行の成功率を数十回のジョブの結果で計測したところ、

  • 設定前:約32%
  • 設定後:約75%

でした。1

NAT…?

Mavenの設定変更で改善したとはいえ、まだ平均して4回に1回の割合でMaven実行が失敗するような状況でした。ビルドの安定性は開発効率につながるため、より安定させたいです。

ここで上記issueを振り返ってみるとAzureのNATとの相性が問題視されていましたが、我々のConcourseでもGCPのNAT(Cloud NAT)を使っていたことを思い出しました。

というのも、我々のConcourseはGKE上に構築されており、ConcourseからGCP外にある社内利用のミラーリポジトリにアクセスする際にCloud NATを使っていました。

そこで、Cloud NATがパケットを落としていないか確認することにしました。

Google Cloud公式のブログ、効果的な Cloud NAT モニタリングのための6つのベスト プラクティスの「Cloud NAT で切断が発生する原因をモニタリングする」を参考にダッシュボードを作成、確認したところ、まさにジョブの実行時に OUT_OF_RESOURCEタイプの切断が発生していました。

以下の画像はある日のConcourse workerが動作しているインスタンスに接続されているCloud NATのポート使用量と切断の量を表しています。2

Cloud NATポート使用量(インスタンスごと)

Cloud NATパケット切断量

実際は切断が起きているときに必ずジョブが失敗するとは限らなかったので、これが今回の問題の根本的な要因という確証はなかったのですが、ひとまずこの切断を解消することにしました。
ポート使用量によるとインスタンスごとにポート数が1000程度で頭打ちしていたため設定を確認したところ、各インスタンスに割り当てられるポート数は固定で、

ポートの予約手順(Google Cloudドキュメント)

静的ポートの割り当てが構成され、ゲートウェイが、複数のアドレス(/32 より小さいネットマスク)を持つエイリアス IP 範囲に対して NAT を実行する場合、Cloud NAT は VM あたりの最小ポート数を次の 2 つの値の大きい方になるように調整します。

  • 指定した VM インスタンスあたりの最小ポート数
  • 1,024

によって1024になっていました。
そこで、使用ポート数を4096に増やしたたところ、切断が起きなくなり、Maven実行も失敗しなくなりました。

本記事の執筆時点で設定変更から数か月経過していますが、Maven実行が全く失敗しなくなったため、これが根本的な原因だったと考えています。

まとめ

MavenによるJavaプロジェクトのビルドがConnection timed outで失敗するという問題の根本的な原因は、ミラーリポジトリへの接続に使っているCloud NATのポート不足による通信切断でした。

Cloud NATの設定で割り当てるポート数を固定値ではなく使用量に動的に割りあてることも可能なため、Cloud NATに使うポート総数はチューニングの余地があるのですが、現状インスタンスの数とワークロードに対して余裕があるので今後必要に応じて行えればと思います。


  1. Concourse worker上のキャッシュが効いていない場合のみカウントしています ↩︎

  2. パケットの切断の要因は実際は2種類あり、OUT_OF_RESOURCES要因のもの(緑色)とENDPOINT_INDEPENDENCE_CONFLICT要因のもの(青色)に分けられますが、OUT_OF_RESOURCESが支配的でした。 ↩︎

この記事を書いた人

記事一覧
SQUARE ENIXでは一緒に働く仲間を募集しています!
興味をお持ちいただけたら、ぜひ採用情報ページもご覧下さい!