Digdag が突然止まった障害を受けて

こんにちは。 GunosyTechLab の Ads ML チームの村田（id:marice0819）です。スプラトゥーン3 で 2022 冬 Chill Season が開始しましたね。

こちらの記事は Gunosy Advent Calendar 2022 - Adventar の 5 日目の記事です。昨日の記事は takashi yamaguchi さんの「AWS Security Hubの導入から運用を回すためにやってきたこと」というタイトルでSecurity-JAWS#27に登壇しました - Gunosy Tech Blog でした。

要約
障害当日
原因調査
対策
- （1）Gradle の shadowJar タスクをもちいて各 plugin が依存する全 jar を取得、cache からローカルの Maven Repository の作成
- （2）Digdag のパラメータを変更して、デフォルトで見る Repository をローカルに変更
その他教訓
終わりに

今日の記事はある日起きた障害対応のはなしです。弊社では主なワークフローエンジンとして Digdag を使用しています。

私達のチームでは機械学習を中心としたグノシーのアプリ内の広告ロジックを開発しているのですが、Digdag は定期実行されるログの ETL や監視・機械学習用の ECS Task のキック等、様々な用途で使っています。

この Digdag がある日突然止まったので何が起こっていたのかと教訓を共有したいと思います。

要約

ワークフロー変更のリリース作業に伴って、Digdag で実行していたほとんどの Job が実行中のまま完了しなくなった
完了しなくなった Job はサードパーティプラグインに依存した Job だった
サードパーティプラグイン自身が依存しているプラグインは実行時に取得が行われる
Maven Repository の障害?によって、プラグイン取得のリクエストを受け取ったままサーバー側で握り続けられてしまった*1
これを受けて、Digdag の CI の段階でサードパーティプラグイン自身が依存している孫依存等も含めて事前にイメージに含むようにした

障害当日

その日は前日に問題が起こっていて恒久対応のために普段では避ける、遅めの時間にデプロイを行っていました。

デプロイされたワークフローのコード修正は軽微なもので、普段の業務で繰り返し行われている類の修正です。事前の確認でエラーが出るようなことは無さそうと思い、リリースする旨を共有しつつ軽い気持ちでデプロイを行いました。

デプロイが完了し、プロダクション環境で動いているかを確認したときに問題に気づきました。実行しているワークフロー内の Job で普段であれば 1 秒程度で終わるようなものが一向に完了しません。状況を確認すると変更を行ったワークフローと関係のないワークフローまで Job が完了しなくなっていました。

Digdag のすべてのワークフローの停止はビジネス影響が懸念されたため、このタイミングで他チームにも共有します。複数のメンバーが対応をはじめますがインフラ、ネットワーク関連で特に問題を発見できませんでした。今日行った変更のリバート & デプロイを行いましたが状況は変わりません。デプロイタイミングで起こったことはほぼ確実ではあったため、調査と並行してコードは変えずにデプロイを繰り返していました。

状況が変わらないまま時間だけが過ぎていきましたが、ある時から徐々にワークフローが正常に完了するようになってきました（ほぼ何もしていないのに直った状態）。必要なワークフローを再実行してから正常な状態に戻ったのを確認後、当日は時間が遅くなっていたのでステークホルダーへの終了報告をしました。

原因調査

障害翌日、ステージング環境で様々試しましたが障害が再現しません。最終的にはプロダクション環境まで同じコードをデプロイしましたが問題なく稼働しました。

障害当日のログ等を眺めながら、普段あまり読んでいなかった Digdag 自体のコードを読んでいきました。メッセージからどこで時間がかかっていた可能性が高いかを絞り込んでいたところ、サードパーティのプラグインの読み込みが怪しそうという仮説が出てきました。仮説を前提に当日のログを確認すると、サードパーティのプラグインへの依存が無い Job は完了しています。

この障害以前の変更でサードパーティのプラグインはイメージに含むようにしていました。しかし、調査を進めたところサードパーティのプラグインが依存しているプラグインは動的に取得されることが分かりました。動的な取得はネットワーク都合で繋がらない場合、他サーバーへのフォールバック等も行われるのですが、仮にリクエストは通るがサーバー側で握り続けられてしまうと上記のような状況になりそうでした。これを受けて、ローカルの環境で Maven Repository へのリクエストを自作のサーバーに向けてレスポンスをずっと返さないようにしたところ、ログの状況が一致したためこれを原因と結論づけました。

対策

原因は Digdag にも使用されている Java のコードは依存として jar を持ちますが、 jar 自身が依存している jar を含んでいるとは限らず、それの動的な取得が実行時環境に依存になってしまっていたことでした（Java の知見がチーム内で少なく、今回の調査を通して認識しました）。

原因を受けて以下の修正を行いました。

CI のタイミングで孫依存等までサードパーティプラグインを Digdag のイメージに含むようにした
- （1）Gradle の shadowJar タスクをもちいて各 plugin が依存する全 jar を取得、cache からローカルの Maven Repository の作成
- 作成された Maven Repository を Digdag のイメージにコピー
  - 上記の Gradle task を実行する stage を用意して multistage build で対応
- （2）Digdag のパラメータを変更して、デフォルトで見る Repository をローカルに変更

（1）Gradle の shadowJar タスクをもちいて各 plugin が依存する全 jar を取得、cache からローカルの Maven Repository の作成

Gradle の shadowJar タスクを使用することにより、Digdag で使用しているサードパーティプラグイン自身が依存しているプラグイン群を取得します。取得後に下記のタスクをもちいて、cache からローカルの Maven Repository を作成します。作成された Maven Repository を Digdag が読むようになれば、すべての依存プラグインが含まれているため外部アクセスの必要が無くなります。

tasks.register<Copy>("dependenciesToLocalMavenRepository") {
    dependsOn("checkChacheFolder")
    from(cacheDirectory)
    into(destLocalRepository)
    // exclude development libraries
    exclude("com.github.johnrengelman.shadow/*", "org.apache.ant/*", "gradle*", "org.junit/*")
    eachFile {
        val parts = this.path.split('/')
        // NOTE: format path to local path of repository
        val repositoryPath = (parts[0] + '/' + parts[1]).replace('.', '/') + '/' + parts[2] + '/' + parts[4]
        this.setPath(repositoryPath)
        this.sourcePath
        println("Copy from ${cacheDirectory.absolutePath}/${this.relativeSourcePath} to ${destLocalRepository.absolutePath}/${this.path}")
    }
    includeEmptyDirs = false
}

参考URL: Need a Gradle task to copy ALL dependencies to a local maven repo - Help/Discuss - Gradle Forums

（2）Digdag のパラメータを変更して、デフォルトで見る Repository をローカルに変更

Digdag のパラメータの変更内容は以下のようなイメージになります。Digdag が最初に参照する LocalRepository をローカルにしておくことにより、事前にすべての依存を含んでいるため実行時の依存取得が無くなります。

  plugin:
    #  digdag が最初に参照する LocalRepository の設定。
    #  デフォルト値と同じだが digdag バージョンの更新によって変わらないことを担保
    local-path: /usr/app/digdag/.digdag/plugins
    # local-path と一致させる
    repositories:
      - file:///usr/app/digdag/.digdag/plugins
    dependencies:
      ...

上記の修正を行ったところ Maven Repository へのリクエストを自作のサーバーに向けてレスポンスをずっと返さないようにしても、問題なく動くようになりました（依存の取得のリクエストが自作サーバーにそもそも飛んでいない）。

その他教訓

本記事では当日の詳細な動きについて記載していない部分もありますが、ポストモーテムをした結果、得た教訓等についてまとめておきます。

誰に連絡を優先すべきなのかを明確にするためビジネス上のステークホルダーの整理
全停止等の想定しやすいケースでは事前に影響範囲のドキュメントを作っておく
- 影響範囲の報告は共有する優先度の高い情報だが、影響範囲を正確に把握している人ほど障害対応をしていることが多いので事前に作られていると良い
障害発生時のテンプレートを用意しておく
- この障害を受けて弊社では Slack で障害対応時に必要となるフローを表示するコマンドを作成しました。全体共有等に必要な各種ドキュメントへのリンク等がまとまっています
障害発生時に担当チーム以外の積極的な参加
- 障害発生時の作業ログ、状況ログ等をポストモーテム用に残しますが、障害対応をする知見を持っている人ほどドキュメントにさける余裕はなくなりがち。知見は少なくてもサポートしてもらえてありがたかった
（ワークフロー関連限定）それぞれのワークフローが求められている最低限の状態を整理
- 例）すべての実行が成功してないといけないのか、最新の一回だけ動いていれば良いのか等
- 復旧時にすべてのワークフローが同時にリトライすると負荷が大きく、それが原因でワークフローが止まる場合がある。整理をしておき、誰でも復旧作業ができるようにする