Kubernetes Podのcommandに/bin/shを使うときは終了ステータスの扱いに気をつけようという話

まとめ

Pod終了時のphaseはコンテナのcommandとargsで指定されたメインプロセスの終了ステータスで判定されるので,

commandに/bin/sh -cを指定し, argsにコマンドを羅列するような場合は子プロセスの終了ステータスの扱いに気をつけないとエラーが発生しているのに異常終了しないことがある.

set -eや&&, $?を適宜使い分けるのが大切.

# falseコマンドで終了ステータス=1が返っているがハンドリングされていないので最後まで実行される
$ /bin/sh -c 'echo "abc"; false; echo "def"'
abc
def
$ echo $?
0

# set -eで途中0以外の終了ステータスが発生したらそこでプロセスを止める
$ /bin/sh -c 'set -e; echo "abc"; false; echo "def"'
abc
$ echo $?
1

# $?で終了ステータスを扱うことでも止められる
$ /bin/sh -c 'echo "abc"; false; result=$?; if [ $result -ne 0 ]; then exit $result; fi; echo "def"'
abc
$ echo $?
1

# &&を使って前のコマンドが正常に終了したときだけ次のコマンドを実行させる
$ /bin/sh -c 'echo "abc" && false && echo "def"'
abc
$ echo $?
1

環境

macOS Mojave 10.14
Docker Desktop for Mac
- Version 2.5.0.0
- Docker version 19.03.13
kind
- v0.9.0 go1.15.5 darwin/amd64
kubectl
- Client Version: v1.19.3
- Server Version: v1.19.1

# JobのPodが正常終了している
$ kubectl apply -f job-01.yaml
$ kubectl get job example-job-command-not-found
NAME                            COMPLETIONS   DURATION   AGE
example-job-command-not-found   1/1           7s         3m42s

$ kubectl get pod -l job-name=example-job-command-not-found
NAME                                  READY   STATUS      RESTARTS   AGE
example-job-command-not-found-j2dbv   0/1     Completed   0          3m20s

# not foundのエラーはちゃんと発生しているのに最後(echo "def")まで実行されている
$ kubectl logs example-job-command-not-found-j2dbv
abc
/bin/sh: yourcoolcmd: not found
def

コマンドの結果がなにかおかしかったら異常終了してほしいようなときにこの挙動は少し困ってしまう.

なんで?

結論から言うと, 原因は先のJob(というかPod)で起動したコンテナのプロセス

/bin/sh -c 'echo "abc"; yourcoolcmd; echo "def"'

が異常終了していなかった(終了ステータスが0だった)ため.

# exitCodeが0(正常終了)になっている
$ kubectl get pod example-job-command-not-found-j2dbv -o yaml | yq r - "status"
...
containerStatuses:
  - containerID: containerd://36c7d09a5f262ff2c18bb328f006059c87aafb8414ae293517eca3ec1e75844f
    image: docker.io/library/busybox:latest
    imageID: docker.io/library/busybox@sha256:c5439d7db88ab5423999530349d327b04279ad3161d7596d2126dfb5b02bfd1f
    lastState: {}
    name: busybox
    ready: false
    restartCount: 0
    started: false
    state:
      terminated:
        containerID: containerd://36c7d09a5f262ff2c18bb328f006059c87aafb8414ae293517eca3ec1e75844f
        exitCode: 0
        finishedAt: "2021-01-24T07:40:28Z"
        reason: Completed
        startedAt: "2021-01-24T07:40:28Z"
phase: Succeeded
...

まず大前提として, コンテナが終了したときのPodのステータス(phase)は次のどちらかの状態になる¹.

Succeeded
- Pod内のすべてのコンテナが正常に終了した
Failed
- Pod内のすべてのコンテナが終了し、少なくとも1つのコンテナが異常終了した(コンテナが0以外のステータスで終了したか、システムによって終了された)

Failedの条件のコンテナが0以外のステータスで終了したというのが重要.

先程のPodのコンテナでargsに指定したコマンド

echo "abc"
yourcoolcmd
echo "def"

はそれぞれ/bin/sh -c echo ...というプロセスの子プロセスとして起動される.

試しにMac上で同じコマンドを実行してみるとよくわかるが, たとえ途中のコマンド(yourcoolcmd)が失敗しても親プロセスが止まらず最後のコマンド(echo "def")が正常に終了しているので/bin/sh -c echo ...の終了ステータスは0(正常終了)になる.

# 途中の子プロセスが異常終了しても親プロセスが最後まで実行されている
$ /bin/sh -c 'echo "abc"; yourcoolcmd; echo "def"'
abc
/bin/sh: yourcoolcmd: command not found
def

$ echo $?
0

したがって, Podのcommandとargsで指定されたプロセスの終了ステータスが0になってしまうので,
PodのphaseがSucceededとなりJobも成功扱いになっている(たぶん).

これを防ぐためには, それぞれの終了ステータス($?)を観てエラーハンドリングするか, set -eもしくは&&を使うのが良い.

# 終了ステータス($?)を観てエラーハンドリングする
$ /bin/sh -c 'echo "abc"; yourcoolcmd; if [ $? -ne 0 ]; then exit 1; fi; echo "def"'
abc
/bin/sh: yourcoolcmd: command not found
$ echo $?
1

# set -eを使う
# 途中で0以外の終了ステータスが発生したときにそこで終了する
$ /bin/sh -c 'set -e; echo "abc"; yourcoolcmd; echo "def"'
abc
/bin/sh: yourcoolcmd: command not found
$ echo $?
127

# &&を使う
# 前のコマンドが正常終了しない場合は次のコマンドが実行されない
$ /bin/sh -c 'echo "abc" && yourcoolcmd && echo "def"'
abc
/bin/sh: yourcoolcmd: command not found
$ echo $?
127

試してみる

原因がなんとなくわかったので,
さっきのJobをちゃんと0以外の終了ステータスで終わるようにした.
(バッチ処理を想定して&&を使っているが, もちろん用途に応じて適宜set -eとか$?を使い分けるべき.)

# JobがBackoffLimitExceededで終了している
$ kubectl apply -f job-02.yaml
$ kubectl get job example-job-command-not-found-2
NAME                              COMPLETIONS   DURATION   AGE
example-job-command-not-found-2   0/1           2m14s      2m14s

$ kubectl get job example-job-command-not-found-2 -o yaml | yq r - "status"
conditions:
  - lastProbeTime: "2021-01-24T09:10:53Z"
    lastTransitionTime: "2021-01-24T09:10:53Z"
    message: Job has reached the specified backoff limit
    reason: BackoffLimitExceeded
    status: "True"
    type: Failed
failed: 2
startTime: "2021-01-24T09:10:40Z"

# Podのコンテナがちゃんと0以外の終了ステータス(exitCode)で終了している
$ kubectl get pod -l job-name=example-job-command-not-found-2
NAME                                    READY   STATUS   RESTARTS   AGE
example-job-command-not-found-2-bq4bl   0/1     Error    0          3m16s
example-job-command-not-found-2-jkdcw   0/1     Error    0          3m13s

$ kubectl get pod example-job-command-not-found-2-bq4bl -o yaml | yq r - "status"
...
containerStatuses:
  - containerID: containerd://09caecce3d813e48cacd53f90eefd5e4f18b7565af7c9351c7fef47dbe397834
    image: docker.io/library/busybox:latest
    imageID: docker.io/library/busybox@sha256:c5439d7db88ab5423999530349d327b04279ad3161d7596d2126dfb5b02bfd1f
    lastState: {}
    name: busybox
    ready: false
    restartCount: 0
    started: false
    state:
      terminated:
        containerID: containerd://09caecce3d813e48cacd53f90eefd5e4f18b7565af7c9351c7fef47dbe397834
        exitCode: 127
        finishedAt: "2021-01-24T09:10:42Z"
        reason: Error
        startedAt: "2021-01-24T09:10:42Z"
phase: Failed
...

$ kubectl logs example-job-command-not-found-2-bq4bl
abc
/bin/sh: yourcoolcmd: not found

ちゃんとPodの終了ステータスが0以外となり, Jobが失敗扱いになったことを確認できた.

おわり

Kubernetesというよりはシェルスクリプトの基本のおさらいになってしまったが, たまにやってしまうので戒めとして書いた.

終了ステータスの扱いは大切.

おまけ

俺によっかかって寝るねこ

https://kubernetes.io/ja/docs/concepts/workloads/pods/pod-lifecycle/#pod-phase ↩︎