ENECHANGE Developer Blog

ENECHANGE開発者ブログ

アポストロフィ1文字のバグ修正で、初めてOSSにコントリビュートした話

はじめに

社内で利用しているCLIツールecskの不具合をきっかけに、初めてGitHub上のOSSへコントリビュートしました。Issueの起票からPull Requestの作成、マージまでの一連の流れを経験したので、その記録を残します。

本記事では、特定のコンテナだけECSに接続できないという事象の調査過程と、原因となっていたバグ、その修正、そしてコントリビュートの手順を順に説明します。

関連リンク:

前提：ecskとは

ecskは、ECS上のタスクをdocker run / docker execのような感覚で起動・操作できるOSSのCLIツールです。社内では、ECS上で動くアプリケーションのコンテナに入って作業する際に利用しています。

事象：特定のコンテナだけECSに接続できない

ステージング環境のコンテナに接続しようとしたところ、app-aというコンテナだけ次のエラーで失敗しました。

Waiting for the execute command agent...
operation error ECS: ExecuteCommand, https response error StatusCode: 400,
InvalidParameterException: The execute command failed because execute command was not enabled
when the task was run or the execute command agent isn't running.
Wait and try again or run a new task with execute command enabled and try again.

一方で、ほぼ同じ書式のコマンドでもapp-bという別のコンテナには問題なく接続できました。実行コマンド自体はほぼ同じで、指定先のtask-definition・security-group・コンテナ名のみが異なります。当初はIAM権限の差異を疑いました。

調査

エラーメッセージはExecuteCommandが有効化されていない、またはagentが起動していない、という内容です。考えられる原因を順に確認しました。

1. IAM権限の差異

ECS Execでは、task roleにssmmessages:*系の権限が必要です。失敗する側と成功する側のtask roleを比較しましたが、どちらも必要な4つの権限CreateControlChannel、CreateDataChannel、OpenControlChannel、OpenDataChannelを保持しており、差異はありませんでした。

2. セキュリティグループのアウトバウンド

SSMへの通信が遮断されているとagentは接続を確立できません。確認したところ、アウトバウンドは0.0.0.0/0で全開放されており、問題はありませんでした。

3. agentの起動状態

起動したタスクのmanagedAgentsの状態を直接確認しました。

aws ecs describe-tasks --cluster <cluster> --tasks <task-id> \
  --query 'tasks[0].containers[].managedAgents'
[
  [
    {
      "name": "ExecuteCommandAgent",
      "lastStatus": "RUNNING"
    }
  ]
]

lastStatusはRUNNINGでした。ECS Execの接続を担うエージェント（正式名はExecuteCommandAgent。以降はagentと表記します）は正常に起動しています。つまりエラー文言は実態と一致しておらず、本質的な原因はagentがreadyになる前にecskが接続を試み、リトライせずに終了している、というタイミングの問題だと推測しました。ここまでは推測なので、この後ソースコードで裏付けを取ります。

app-aはコンテナイメージが大きくagentがreadyになるまでに時間がかかる、app-bは起動が速いため初回の試行に間に合っていた、という違いだと考えられます。

原因特定

リトライが機能していない可能性を検証するため、ecskのソースコードを確認しました。ecskはGo製で、リポジトリはyukiarrr/ecskです。

Waiting for the execute command agent...という文字列で検索すると、pkg/cmd/run.goにリトライ処理が見つかりました。

const max = 10
for i := 0; i < max; i++ {
    err := startExec(ctx, ecsClient, ExecCommandOptions{ /* ... */ })
    if err != nil {
        if i < max-1 && strings.Contains(err.Error(), "the execute command agent isn't running") {
            // 3秒待ってリトライ
            select {
            case <-ctx.Done():
                return
            case <-time.After(3 * time.Second):
            }
            continue
        }
        // それ以外のエラーは即終了
        fmt.Fprintln(os.Stderr, err)
        os.Exit(1)
    }
    break
}

最大10回、3秒間隔でリトライする設計です。仕組みとしては正しく見えますが、実際にはリトライしていません。ではなぜ、正しく見えるコードが動かないのか。

そこでstrings.Containsに渡している文字列を実体ベースで、バイト単位で確認しました。

$ sed -n '398p' pkg/cmd/run.go | od -c
...  a   g   e   n   t       i   s   n   ’  t       r   u   n   n   i   n   g  ...

isnの後ろのアポストロフィが、ASCIIの'(U+0027)ではなく'(U+2019)、いわゆるcurly quoteになっていました。

AWSが実際に返すエラーメッセージはASCIIアポストロフィ'です。そのためstrings.Containsはマッチせず、リトライ判定が機能していませんでした。max = 10と定義されているにもかかわらず、実質的に1回も再試行されていなかったということです。

見た目での区別はほぼ困難です。

the execute command agent isn’t running   ← ソースコードの文字列（アポストロフィは U+2019 / UTF-8 バイト列 e2 80 99）
the execute command agent isn't running   ← AWS が返す実際の文字列（アポストロフィは U+0027 / バイト 27）

暫定対応：社内向けにパッチ版をビルド

原因が判明したため、まず業務を止めないための暫定対応を行いました。ソースをcloneしてアポストロフィをASCIIに修正し、あわせてapp-aのように起動の遅いコンテナでも余裕を持って待てるよう、リトライ回数を10から20に増やしたうえで、ビルドしたバイナリを社内に配布しました。Go製のため、バイナリ単体で配布できます。ecskはMITライセンスのため、社内での改変・配布も問題ありません。

これによりapp-aへの接続も安定し、当面の課題は解消しました。

コントリビュート

暫定対応で社内の問題は解消しましたが、他の利用者も同じバグを踏む可能性があり、本家で修正されれば社内パッチを保守する必要もなくなります。そのため本家へのコントリビュートを行いました。これが初めてのOSSコントリビュートです。

Step 1. Issueの起票

いきなりPRを作成するのではなく、まずIssue #24で状況を整理して報告しました。記載した内容は次のとおりです。

  • 概要
  • 該当箇所へのパーマリンク
  • 再現条件
  • 修正案
  • PRを作成してよいかの確認

メンテナの方が読みやすいよう日本語と英語の両方で記載し、最後にPR作成の可否を確認しました。

Step 2. 修正方針の見直し

当初は、ソースのcurly quoteが誤りで、ASCIIに修正すれば直る、と考えていました。

しかしIssue #24でのメンテナとのやり取りの中で、AWSは環境によってcurly quote（U+2019）とASCII（U+0027）のどちらのアポストロフィでもこのエラーメッセージを返すことがわかりました。自分の環境ではASCIIが返っていましたが、curly quoteが返る環境も存在するということです。単純にASCIIへ置き換えるだけでは、今度はcurly quoteを返す環境でリトライが機能しなくなります。

したがって、片方に寄せるのではなく両方にマッチさせる、という方針に変更しました。

Step 3. PRの作成

最終的にPR #25として、両方のアポストロフィにマッチするようOR条件にする修正を作成しました。変更は1ファイル、5行追加1行削除の小さなものです。

errMsg := err.Error()
// AWS returns this error with either a curly apostrophe (U+2019) or
// an ASCII apostrophe (U+0027) depending on the environment; match both variants.
if i < max-1 && (strings.Contains(errMsg, "the execute command agent isn’t running") || // U+2019 curly
    strings.Contains(errMsg, "the execute command agent isn't running")) { // U+0027 ASCII

なお、2つのstrings.Containsに渡している文字列は、見た目はほぼ同じですがアポストロフィの文字コードだけが異なります（前者がU+2019、後者がU+0027）。

Step 4. マージ

PRはメンテナのyukiarrrさんによってマージされました。

まとめ

今回の調査と対応から得られた点をまとめます。

  • エラーメッセージを鵜呑みにしない。今回はagentが起動していないというメッセージでしたが、実際のlastStatusはRUNNINGでした。describe-tasksで実際の状態を確認したことが原因特定の決め手になりました。
  • 見た目で区別できない文字の違いがバグになる。curly quoteとASCIIアポストロフィのように、目視では区別できない文字が原因となる場合があります。挙動とコードが矛盾するときは、od -cなどでバイト単位で確認するのが有効です。
  • OSSコントリビュートの手順自体は難しくない。業務で遭遇したバグを調査し、Issueで報告・相談したうえで小さなPRを作成する、という流れで進められました。日常的に使うツールの挙動の違和感を起点に、コントリビュートにつなげられます。

最後に、便利なツールを公開し、PRをレビュー・マージしてくださったyukiarrrさんに感謝します。