OpenShiftのget eventの3.11での変更点

Red HatでOpenShiftのサポートをしているid:nekopです。OpenShift 全部俺 Advent Calendar 2018 - Qiitaの12日目のエントリです。

デプロイメントの状況をや問題を確認するにはEventログとPodログを見ることになります。

OpenShift 3.11でoc get eventsすると以下のような出力となります。

$ oc run sleep --image=registry.access.redhat.com/rhel-minimal --command -- tail -f /dev/null
$ oc get events
LAST SEEN   FIRST SEEN   COUNT     NAME                              KIND                    SUBOBJECT                     TYPE      REASON              SOURCE                                           MESSAGE
1m          1m           1         sleep-1-deploy.15701ca29ab92fac   Pod                                                   Normal    Scheduled           default-scheduler                                Successfully assigned test-events/sleep-1-deploy to node-1.example.com
1m          1m           1         sleep.15701ca29688a78d            DeploymentConfig                                      Normal    DeploymentCreated   deploymentconfig-controller                      Created new replication controller "sleep-1" for version 1
58s         58s          1         sleep-1.15701ca69bfcbb7c          ReplicationController                                 Normal    SuccessfulCreate    replication-controller                           Created pod: sleep-1-tjslb
58s         58s          1         sleep-1-tjslb.15701ca69d04b8bf    Pod                                                   Normal    Scheduled           default-scheduler                                Successfully assigned test-events/sleep-1-tjslb to node-2.kaizen.lab.rdu2.cee.redhat.com
46s         46s          1         sleep-1-deploy.15701ca97ebc7af2   Pod                     spec.containers{deployment}   Normal    Pulled              kubelet, node-1.example.com                      Container image "registry.redhat.io/openshift3/ose-deployer:v3.11.16" already present on machine
43s         43s          1         sleep-1-deploy.15701caa38a773dc   Pod                     spec.containers{deployment}   Normal    Created             kubelet, node-1.example.com                      Created container
42s         42s          1         sleep-1-deploy.15701caa7be825e2   Pod                     spec.containers{deployment}   Normal    Started             kubelet, node-1.example.com                      Started container
21s         21s          1         sleep-1-tjslb.15701caf3db14837    Pod                     spec.containers{sleep}        Normal    Pulling             kubelet, node-2.kaizen.lab.rdu2.cee.redhat.com   pulling image "registry.access.redhat.com/rhel-minimal"
19s         19s          1         sleep-1-tjslb.15701cafc71c1b54    Pod                     spec.containers{sleep}        Normal    Pulled              kubelet, node-2.kaizen.lab.rdu2.cee.redhat.com   Successfully pulled image "registry.access.redhat.com/rhel-minimal"
18s         18s          1         sleep-1-tjslb.15701cb01467b985    Pod                     spec.containers{sleep}        Normal    Created             kubelet, node-2.kaizen.lab.rdu2.cee.redhat.com   Created container
17s         17s          1         sleep-1-tjslb.15701cb033d15221    Pod                     spec.containers{sleep}        Normal    Started             kubelet, node-2.kaizen.lab.rdu2.cee.redhat.com   Started container

ちなみにOpenShift 3.11以前でoc get eventsすると、KINDでソートされていました。Eventは時間順で表示される、というバイアスがあるのでちょっと不自然に感じましたが、3.11で変更されたようです。

$ oc get events
LAST SEEN   FIRST SEEN   COUNT     NAME                              KIND                    SUBOBJECT                     TYPE      REASON                  SOURCE                            MESSAGE
52s         52s          1         sleep-1-9lsfm.15701caef94c7362    Pod                                                   Normal    Scheduled               default-scheduler                 Successfully assigned sleep-1-9lsfm to s39.example.com
52s         52s          1         sleep-1-9lsfm.15701caf041ef4b8    Pod                                                   Normal    SuccessfulMountVolume   kubelet, s39.example.com          MountVolume.SetUp succeeded for volume "default-token-dftpl"
50s         50s          1         sleep-1-9lsfm.15701caf8bc51822    Pod                     spec.containers{sleep}        Normal    Pulling                 kubelet, s39.example.com          pulling image "registry.access.redhat.com/rhel-minimal"
48s         48s          1         sleep-1-9lsfm.15701caff5b87264    Pod                     spec.containers{sleep}        Normal    Pulled                  kubelet, s39.example.com          Successfully pulled image "registry.access.redhat.com/rhel-minimal"
48s         48s          1         sleep-1-9lsfm.15701caffb4f9612    Pod                     spec.containers{sleep}        Normal    Created                 kubelet, s39.example.com          Created container
48s         48s          1         sleep-1-9lsfm.15701cb00ce7b8d5    Pod                     spec.containers{sleep}        Normal    Started                 kubelet, s39.example.com          Started container
58s         58s          1         sleep-1-deploy.15701cad97a0173b   Pod                                                   Normal    Scheduled               default-scheduler                 Successfully assigned sleep-1-deploy to s39.example.com
58s         58s          1         sleep-1-deploy.15701cada6db286d   Pod                                                   Normal    SuccessfulMountVolume   kubelet, s39.example.com          MountVolume.SetUp succeeded for volume "deployer-token-756rx"
56s         56s          1         sleep-1-deploy.15701cae3b3dba8f   Pod                     spec.containers{deployment}   Normal    Pulled                  kubelet, s39.example.com          Container image "openshift3/ose-deployer:v3.9.40" already present on machine
56s         56s          1         sleep-1-deploy.15701cae3f6b9288   Pod                     spec.containers{deployment}   Normal    Created                 kubelet, s39.example.com          Created container
55s         55s          1         sleep-1-deploy.15701cae623efbea   Pod                     spec.containers{deployment}   Normal    Started                 kubelet, s39.example.com          Started container
46s         46s          1         sleep-1-deploy.15701cb081a839c3   Pod                     spec.containers{deployment}   Normal    Killing                 kubelet, s39.example.com          Killing container with id docker://deployment:Need to kill Pod
53s         53s          1         sleep-1.15701caef7fcf71e          ReplicationController                                 Normal    SuccessfulCreate        replication-controller            Created pod: sleep-1-9lsfm
58s         58s          1         sleep.15701cad9505cfec            DeploymentConfig                                      Normal    DeploymentCreated       deploymentconfig-controller       Created new replication controller "sleep-1" for version 1

また、3.10ではoc get events -wとしたときに以下のようにAbsolute timestampで表示されていたのですが、3.11では相対時間表示のままになっています。

$ oc get events -w
LAST SEEN                       FIRST SEEN                      COUNT     NAME                             KIND                    SUBOBJECT   TYPE      REASON                  SOURCE                            MESSAGE
2018-12-14 16:51:13 +0900 JST   2018-12-14 16:51:13 +0900 JST   1         sleep-1-cwfjr.157023a7312a611c   Pod                                 Normal    Scheduled               default-scheduler                 Successfully assigned sleep-1-cwfjr to s39.usersys.redhat.com

エンジニアリングに確認したところ意図的に変更を行ったとの回答だったので、実装を調べてみます。関連するPRは以下です。

oc get events -wの出力はAbsoluteTimestampsというフラグで切り替えています。1.10では以下のコードとなっていました。

$ cd kubernetes # https://github.com/kubernetes/kubernetes/
$ git co release-1.10
$ git grep AbsoluteTimestamps
pkg/kubectl/cmd/util/printing.go:               AbsoluteTimestamps: isWatch(cmd),
pkg/printers/interface.go:      AbsoluteTimestamps bool
pkg/printers/internalversion/printers.go:       if options.AbsoluteTimestamps {

1.11では以下になっています。

$ git co release-1.11
$ git grep AbsoluteTimestamps
pkg/kubectl/cmd/get/humanreadable_flags.go:     AbsoluteTimestamps bool
pkg/kubectl/cmd/get/humanreadable_flags.go:             AbsoluteTimestamps: false,
pkg/printers/interface.go:      AbsoluteTimestamps bool
pkg/printers/internalversion/printers.go:       if options.AbsoluteTimestamps {

1.10ではwatchではAbsoluteTimestampsをtrueにしますが、1.11ではfalseに設定するコードしかないので実質false固定となっています。

ちなみに3.11での表示順ですが、3.11以前のようにeventのソートは行っておらず、apiserverからのnatural orderに変更された結果、より見た目的に自然な順序になっているようです。

* 各記事は著者の見解によるものでありその所属組織を代表する公式なものではありません。その内容については非公式見解を含みます。