ProLogue ～ 最下級戦士の推理 ～
FILE.1 同時刻の StopInstances
👨「…おかしい。」
👨「EC2 インスタンスは確かに停止した。」
👨「動作は完璧だ。」
👨「だが…。」
（CloudTrail のイベント履歴に並ぶ、2 つのStopInstances…。）
👨「何故、StopInstancesが 2 つ記録されている…？」
👨「あれれ～？」
👨「おかしいぞ〜？？」
FILE.2 実害なきトリック
👨「インスタンスは正常に停止。実害は無い。普通ならここで見過ごす。」
👨「だが…。」
👨「この違和感、見逃すわけにはいかない…！」
👨「真実はいつも 1 つ…。」
👨「なら、この 2 件にも必ず『カラクリ』があるはずだ…！」
FILE.3 3 つの証拠
👨「requestID‐‐‐ 別物。」
👨「eventID‐‐‐ 別物。」
👨「つまり、『表示上のダブり』という線は消えた。」
👨「コイツは確かに… 2 回呼ばれている……!？」
👨「userIdentityのarnは一致。」
👨「invokedByは、どちらもevents.amazonaws.com…。」
👨「呼び出し元は、同一人物（プリンシパル）。」
👨「そして…accessKeyIdも一致…だ…と…！？」
👨「これで決まりだ！」
👨「犯行は『別々の仕掛け』じゃない！」
👨「たった 1 回の実行の中で、2 回StopInstancesが呼ばれている…！」
FILE.4 真犯人
👨「犯人は…お前だ！」
👨「AWS-StopEC2Instance ‐‐‐ ！！」
💻「…いつから気づいていた？！」（AWS-StopEC2Instance）
👨「最初からさ。
👨「お前のmainStepsは2段構え。」
👨「まず、stopInstancesで普通に止め、続くforceStopInstancesで強制停止のダメ押し。」
👨「だから、StopInstancesは 2 回記録された…。」
👨「それが、トリックの正体だ！」
💻「…フッ。」
💻「だが言っておくが、実害は無いぞ。」
💻「冪等な処理だからな。」
👨「ああ。」
👨「だから、余計に性格（タチ）が悪いのさ。」
👨「『気持ち悪いだけ』で放置されがちなこのトリック…。」
👨「だが、俺は見過ごせなかった。」
Epilogue 〜最下級戦士、真実に辿り着く〜
真実はいつも 1 つ。
というわけで、この記事ではこの「2回事件」の推理過程を、証拠とともに追っていきます。
事件の概要
- EC2 インスタンスを定時で自動停止していた。
- 停止は正常に動作している。（実害は無い。）
- ある日、CloudTrail のイベント履歴を見たら
StopInstancesが同時刻・同一インスタンスIDで2件記録されていた
停止はできている。実害もない。だが StopInstances が2つ並んでいる。この違和感の正体を突き止める。
3 つの仮説
「2 件ある！」と言っても、考えられる筋書きは複数あります。
（01）表示上の重複。（同じ 1 回の呼び出しが 2 行見えているだけ。）
（02）リトライによる重複。（呼び出し元がレスポンスを取りこぼして再送。）
（03）そもそも 2 系統の仕組みが 2 重に動いている。
どれが真犯人か。
イベントレコードという『証拠』を突き合わせて、1 つずつ潰していきます。
推理① 〜 requestID / eventID の謎 〜
まず 2 件の requestID と eventID を比較。
どちらも別物だった。
表示上の重複ではなく、本当に StopInstances API が 2 回呼ばれている。
これで仮説①『表示上の重複』は消えました。
コイツは確かに 2 回呼ばれている。
推理② 〜 呼び出し元は誰だ 〜
次に『誰が呼んだのか？』を確認
-
userIdentity.arn… 2 件とも一致。 -
invokedBy… 2 件ともevents.amazonaws.comだった。
呼び出し元（プリンシパル）は同一
※『プリンシパル』とは？ … 例えると、『誰が？』にあたる部分。
別々の仕組みが 2 重に動いている線も薄くなりました。
そして、 invokedBy が events.amazonaws.com ということは、EventBridge の Scheduler （新しい方）ではなく、スケジュールされたルール（レガシー） 経由で動いていたことが判明します。
推理③ 〜 決定的証拠の accessKeyId 〜
ダメ押しで accessKeyId を比較。
2 件とも一致
これで確定。
「同一の実行セッションから 2 回呼ばれている。」
リトライでも二重起動でもなく、1 回の実行の中で 2 回 API が叩かれている。
犯行現場は、たった 1 つの実行の中にあった。
真犯人 〜 ターゲットの SSM Automation ドキュメント 〜
レガシールールのターゲットを確認すると AWS-StopEC2Instance（SSM Automation ドキュメント）が 1 つだけ。
このドキュメントの定義を見にいくと、mainSteps が 2ステップ構成 になっていました。
| ステップ | アクション | 内容 |
|---|---|---|
stopInstances |
aws:changeInstanceState |
通常停止（onFailure: Continue） |
forceStopInstances |
aws:changeInstanceState |
強制停止（Force: true） |
つまり、『まず、普通に止める。 ⇒ 続けて、念の為、強制で止める。』という 2 段構え。
それぞれのステップが裏で StopInstances API を叩く為、CloudTrail に 2 件記録される。
これがトリックの正体でした。
裏取り 〜 Automation の実行履歴 〜
『Systems Manager＞Automation＞実行履歴』 から該当の実行を開くと、
-
stopInstances… 開始 04:30:49 GMT ／ ステータス 成功 -
forceStopInstances… 開始 04:31:30 GMT ／ ステータス 成功
2 ステップが順番に実行され、どちらも成功。
推理は証拠と一致しました。
ダメ押し 〜 Start と Stop は非対称 〜
念の為、 AWS-StartEC2Instance の実行履歴も開いてみると、こちらは startInstances の 1 ステップだけ。
- 停止：
stopInstances+forceStopInstancesの 2 段構え。
⇒StopInstancesが 2 回記録される。 - 起動：
startInstancesの 1 段のみ。
⇒StartInstancesは 1 回だけ。
『何故、【停止】だけ 2 回出るのか？？』の答えが、この非対称性に集約されていました。
【起動】には『強制起動でダメ押し』という保険ステップが不要なので 1 段で済む、という設計思想の違いです。
結論 〜 真実はいつも 1 つ 〜
- ルールは予定通り 1 回だけ発火している。（2 重【起動】ではない。）
-
AWS-StopEC2Instanceが『【停止】 ⇒ 強制【停止】』の 2 段構えなので、StopInstancesが 2 回記録されるのは仕様通り。 - 停止処理は冪等で実害ゼロ。
気持ち悪いだけなので、放置で問題無し。
気持ち悪さの正体は『【停止】＋念の為、強制【停止】』という 2 段構えドキュメントの素直な挙動でした。
『真実』はいつも 1 つ。
参考
- ドキュメント定義の実体。
2ステップ構成が確認できる。
aws-StopEC2Instance.json（awslabs） - 公式リファレンス
AWS-StopEC2Instance - Automation Runbook Reference - 各ステップが使うアクションの仕様。
aws:changeInstanceState - AWS Systems Manager