kubernetes: Unneeded eviction triggered when reclaiming imagefs

Is this a request for help? (If yes, you should use our troubleshooting guide and community support channels, see http://kubernetes.io/docs/troubleshooting/.):

No

What keywords did you search in Kubernetes issues before filing this one? (If you have found any duplicates, you should instead reply there.):

unexpected error when attempting to reduce imagefs pressure

---

Is this a BUG REPORT or FEATURE REQUEST? (choose one):

BUG REPORT

Kubernetes version (use kubectl version):

Client Version: version.Info{Major:"1", Minor:"6", GitVersion:"v1.6.2", GitCommit:"477efc3cbe6a7effca06bd1452fa356e2201e1ee", GitTreeState:"clean", BuildDate:"2017-04-19T22:51:55Z", GoVersion:"go1.8.1", Compiler:"gc", Platform:"darwin/amd64"}
Server Version: version.Info{Major:"1", Minor:"6", GitVersion:"v1.6.2+coreos.0", GitCommit:"79fee581ce4a35b7791fdd92e0fc97e02ef1d5c0", GitTreeState:"clean", BuildDate:"2017-04-19T23:13:34Z", GoVersion:"go1.7.5", Compiler:"gc", Platform:"linux/amd64"}

Environment:

• Cloud provider or hardware configuration: Azure
• OS (e.g. from /etc/os-release): Container Linux by CoreOS 1298.7.0 (Ladybug)
• Kernel (e.g. uname -a): Linux node-4-vm 4.9.16-coreos-r1 #1 SMP Fri Mar 31 02:07:42 UTC 2017 x86_64 Intel® Xeon® CPU E5-2673 v3 @ 2.40GHz GenuineIntel GNU/Linux
• Install tools: https://github.com/edevil/kubernetes-deployment/

What happened:

Imagefs went above threshold, images started getting deleted. When this process finished the amount of free space that kubernetes wanted to have freed is not correct (9223372036854775807) and an eviction is triggered.

What you expected to happen:

No eviction should happen.

How to reproduce it (as minimally and precisely as possible):

2 example logs attached

node2

Apr 26 02:00:36 node-2-vm kubelet-wrapper[1064]: + exec /usr/bin/rkt run --uuid-file-save=/var/run/kubelet-pod.uuid --volume var-cni,kind=host,source=/var/lib/cni --mount volume=var-cni,target=/var/lib/cni --volume var-log,kind=host,source=/var/log --mount volume=var-log,target=/var/log --volume lib-modules,kind=host,source=/lib/modules --mount volume=lib-modules,target=/lib/modules --volume etc-resolv,kind=host,source=/etc/resolv.conf --mount volume=etc-resolv,target=/etc/resolv.conf --trust-keys-from-https --volume etc-kubernetes,kind=host,source=/etc/kubernetes,readOnly=false --volume etc-ssl-certs,kind=host,source=/etc/ssl/certs,readOnly=true --volume usr-share-certs,kind=host,source=/usr/share/ca-certificates,readOnly=true --volume var-lib-docker,kind=host,source=/var/lib/docker,readOnly=false --volume var-lib-kubelet,kind=host,source=/var/lib/kubelet,readOnly=false --volume os-release,kind=host,source=/usr/lib/os-release,readOnly=true --volume run,kind=host,source=/run,readOnly=false --mount volume=etc-kubernetes,target=/etc/kubernetes --mount volume=etc-ssl-certs,target=/etc/ssl/certs --mount volume=usr-share-certs,target=/usr/share/ca-certificates --mount volume=var-lib-docker,target=/var/lib/docker --mount volume=var-lib-kubelet,target=/var/lib/kubelet --mount volume=os-release,target=/etc/os-release --mount volume=run,target=/run --stage1-from-dir=stage1-fly.aci quay.io/coreos/hyperkube:v1.6.2_coreos.0 --exec=/kubelet -- --cloud-provider=azure --cloud-config=/etc/kubernetes/azure.json --kubeconfig=/etc/kubernetes/worker-kubeconfig.yaml --require-kubeconfig --container-runtime=docker --network-plugin-dir=/etc/kubernetes/cni/net.d --network-plugin=kubenet --register-node=true --allow-privileged=true --pod-manifest-path=/etc/kubernetes/manifests --cluster-dns=10.3.0.10 --cluster-domain=cluster.local --client-ca-file=/etc/kubernetes/ssl/ca.pem --anonymous-auth=false --image-gc-high-threshold=85 --image-gc-low-threshold=75 --eviction-max-pod-grace-period=600 --eviction-minimum-reclaim=memory.available=350Mi,imagefs.available=2Gi,nodefs.available=2Gi '--evi
Apr 26 02:00:36 node-2-vm kubelet-wrapper[1064]: ction-soft=memory.available<300Mi,nodefs.available<14%,nodefs.inodesFree<14%,imagefs.available<14%,imagefs.inodesFree<14' --eviction-soft-grace-period=memory.available=1m30s,nodefs.available=1m30s,imagefs.available=1m30s,nodefs.inodesFree=1m,imagefs.inodesFree=1m '--eviction-hard=memory.available<250Mi,nodefs.available<10%,nodefs.inodesFree<10%,imagefs.available<10%,imagefs.inodesFree<10' --node-labels=component_type=node
Apr 26 02:01:12 node-2-vm kubelet-wrapper[1064]: I0426 02:01:12.308688    1064 container_manager_linux.go:250] Creating Container Manager object based on Node Config: {RuntimeCgroupsName: SystemCgroupsName: KubeletCgroupsName: ContainerRuntime:docker CgroupsPerQOS:true CgroupRoot:/ CgroupDriver:cgroupfs ProtectKernelDefaults:false EnableCRI:true NodeAllocatableConfig:{KubeReservedCgroupName: SystemReservedCgroupName: EnforceNodeAllocatable:map[pods:{}] KubeReserved:map[] SystemReserved:map[] HardEvictionThresholds:[{Signal:memory.available Operator:LessThan Value:{Quantity:250Mi Percentage:0} GracePeriod:0s MinReclaim:<nil>} {Signal:nodefs.available Operator:LessThan Value:{Quantity:<nil> Percentage:0.1} GracePeriod:0s MinReclaim:<nil>} {Signal:nodefs.inodesFree Operator:LessThan Value:{Quantity:<nil> Percentage:0.1} GracePeriod:0s MinReclaim:<nil>} {Signal:imagefs.available Operator:LessThan Value:{Quantity:<nil> Percentage:0.1} GracePeriod:0s MinReclaim:<nil>} {Signal:imagefs.inodesFree Operator:LessThan Value:{Quantity:10 Percentage:0} GracePeriod:0s MinReclaim:<nil>}]} ExperimentalQOSReserved:map[]}
Apr 26 08:59:27 node-2-vm kubelet-wrapper[1064]: W0426 08:59:27.480936    1064 eviction_manager.go:299] eviction manager: attempting to reclaim imagefs
Apr 26 08:59:27 node-2-vm kubelet-wrapper[1064]: I0426 08:59:27.480963    1064 helpers.go:996] eviction manager: attempting to delete unused images
Apr 26 08:59:27 node-2-vm kubelet-wrapper[1064]: I0426 08:59:27.560529    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:896f0b69742a885415971c4c0ff5061b6be98b1f13b992a8d807cb01a8fb64bb" to free 414645633 bytes
Apr 26 08:59:54 node-2-vm kubelet-wrapper[1064]: I0426 08:59:54.148219    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:750a8b7ed0b9918789a4ea371f9253627436e45d8bc6c184163f1b77e7fd216b" to free 414645204 bytes
Apr 26 09:00:29 node-2-vm kubelet-wrapper[1064]: I0426 09:00:29.980684    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:597a45ef55ec52401fdcd2e1d6ee53c74b04afb264490d7fa67b6d98ad330dfe" to free 57892132 bytes
Apr 26 09:00:30 node-2-vm kubelet-wrapper[1064]: I0426 09:00:30.092175    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:5dbb6d76ba117f8a29c6d0000e9b33e8b5bdb29a9fe59ce560a381ed3e6688ed" to free 561602155 bytes
Apr 26 09:00:30 node-2-vm kubelet-wrapper[1064]: I0426 09:00:30.101097    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:ab31d62bf9e005ff4fe6660029bd7260fdfeca4adbaaccb9e82eb0018381e416" to free 414645523 bytes
Apr 26 09:01:05 node-2-vm kubelet-wrapper[1064]: I0426 09:01:05.426988    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:e83902fc224f39f7f5b6e2de914fd7b39687fe1d354da409615fcd1f21652837" to free 272701863 bytes
Apr 26 09:01:08 node-2-vm kubelet-wrapper[1064]: I0426 09:01:08.836144    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:ee590f1abe7181fd148a1a1ed48b24a6cbc54918e94569229e419ef9ea56c432" to free 693318312 bytes
Apr 26 09:01:12 node-2-vm kubelet-wrapper[1064]: I0426 09:01:12.591182    1064 image_gc_manager.go:270] [imageGCManager]: Disk usage on "/dev/sdb" (/var/lib/docker/overlay) is at 88% which is over the high threshold (85%). Trying to free 2440915968 bytes
Apr 26 09:01:59 node-2-vm kubelet-wrapper[1064]: I0426 09:01:59.969308    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:8c58dbb011843dfb79f13fc012e03db7469cbb7008d3ca06c5d202aeddd387e2" to free 659710039 bytes
Apr 26 09:03:01 node-2-vm kubelet-wrapper[1064]: I0426 09:03:01.031650    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:300fcce773504eff061b90e08e2fb2ba0e11ba5624a6f4e8bb615ddd2a9b3e9c" to free 60895216 bytes
Apr 26 09:03:01 node-2-vm kubelet-wrapper[1064]: W0426 09:03:01.032591    1064 image_gc_manager.go:176] [imageGCManager] Failed to update image list: rpc error: code = 2 desc = Error response from daemon: {"message":"layer does not exist"}
Apr 26 09:03:01 node-2-vm kubelet-wrapper[1064]: I0426 09:03:01.189973    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:3c734123a3d156f74608ab8fdc1e1776137c01b9026dd36901f70e1202f50c82" to free 748518122 bytes
Apr 26 09:03:38 node-2-vm kubelet-wrapper[1064]: I0426 09:03:38.314462    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:9785e6acd8bc4eed1fd73a069cb2fd1c22a2c61f22c5111b17493d61d5627975" to free 414601700 bytes
Apr 26 09:04:04 node-2-vm kubelet-wrapper[1064]: I0426 09:04:04.287542    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:c8a7f4332c60208f4703ea819c7a8921395a3ac9da2e4747e1572bab17046746" to free 791510824 bytes
Apr 26 09:04:04 node-2-vm kubelet-wrapper[1064]: W0426 09:04:04.289745    1064 image_gc_manager.go:176] [imageGCManager] Failed to update image list: rpc error: code = 2 desc = Error response from daemon: {"message":"layer does not exist"}
Apr 26 09:04:41 node-2-vm kubelet-wrapper[1064]: I0426 09:04:41.981125    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:0af158c1115f3526eb10df328a6a8d269468fe110f50915b2ab37661487e6211" to free 273002741 bytes
Apr 26 09:04:47 node-2-vm kubelet-wrapper[1064]: I0426 09:04:47.391232    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:98eae72f0f11dada4a06212f77d80accc6e3a143de1671e47a60fbfa8e705f94" to free 414603265 bytes
Apr 26 09:05:12 node-2-vm kubelet-wrapper[1064]: I0426 09:05:12.746695    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:91a48ff795cebb88646ec6cc4955bf7f500466feb44ec18b508f2ce94ed0d9b7" to free 664880136 bytes
Apr 26 09:05:12 node-2-vm kubelet-wrapper[1064]: I0426 09:05:12.795756    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:93a43bfb39bfe9795e76ccd75d7a0e6d40e2ae8563456a2a77c1b4cfc3bbd967" to free 8374840 bytes
Apr 26 09:05:13 node-2-vm kubelet-wrapper[1064]: I0426 09:05:13.025948    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:3f8119a98476b97e806057a72e8e836a2d3e65d56e9b4c790e75874e586b8db0" to free 146818590 bytes
Apr 26 09:05:20 node-2-vm kubelet-wrapper[1064]: I0426 09:05:20.834627    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:185e60a5dda7ba40e61bdc7e1d55bb48be944fed74b264ba32555c3d8b9dbdfc" to free 414603516 bytes
Apr 26 09:05:48 node-2-vm kubelet-wrapper[1064]: I0426 09:05:48.115665    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:32d762cb608daf7c6aefba1993b97009dcfe89166c7768c9a1d60ead71093db8" to free 414648849 bytes
Apr 26 09:06:15 node-2-vm kubelet-wrapper[1064]: I0426 09:06:15.191242    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:2ee0b872ccbb2dfd9e6faddfdc2341c909f4166aeb02004d918bab338b7eaf53" to free 863819225 bytes
Apr 26 09:07:03 node-2-vm kubelet-wrapper[1064]: I0426 09:07:03.517772    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:ef2ca8397823de41a0752186c644a88cb93abb280a4e09e75704e3ae02b9332d" to free 185506981 bytes
Apr 26 09:07:03 node-2-vm kubelet-wrapper[1064]: I0426 09:07:03.571210    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:0d738dc5a3854ca4bc81eea18f913f4776a5725e269443c4588369270474bb21" to free 273406715 bytes
Apr 26 09:07:03 node-2-vm kubelet-wrapper[1064]: I0426 09:07:03.579988    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:a724d4e76985d9c429f5da3b8e495f99fae0260382aa2d54d9a2a7ea7542b1ad" to free 415096187 bytes
Apr 26 09:07:47 node-2-vm kubelet-wrapper[1064]: I0426 09:07:47.540511    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:0f6692796628553bf4837d61a384e5f0f61d2834d7674b94e2fe25984ce6ba4b" to free 414509012 bytes
Apr 26 09:08:22 node-2-vm kubelet-wrapper[1064]: I0426 09:08:22.849766    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:e624a16e665b50f70d9edbe8af10e817926cf7ea52825ec9c7a35e0057e79306" to free 903598860 bytes
Apr 26 09:09:08 node-2-vm kubelet-wrapper[1064]: I0426 09:09:08.756822    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:93b7861812ab036ba0961a50691350f9a1adafbbcfa8f6abffca93dd507a137e" to free 273406785 bytes
Apr 26 09:09:17 node-2-vm kubelet-wrapper[1064]: I0426 09:09:17.944001    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:d1589959cf3d549ecfa0cfb07b17037a23e3053f5ecf7bf36d87d197285ebb8f" to free 415082550 bytes
Apr 26 09:09:17 node-2-vm kubelet-wrapper[1064]: W0426 09:09:17.953817    1064 image_gc_manager.go:176] [imageGCManager] Failed to update image list: rpc error: code = 2 desc = Error response from daemon: {"message":"layer does not exist"}
Apr 26 09:09:41 node-2-vm kubelet-wrapper[1064]: I0426 09:09:41.695594    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:512d06ca2b31a1217dfa0d27d5d8d62c2cf4171445a88a4fcec216b2e9ff2eaa" to free 415125623 bytes
Apr 26 09:10:20 node-2-vm kubelet-wrapper[1064]: I0426 09:10:20.864086    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:e458b00875ef2a207cc616b7faf3fcf34750b5ed7749c81e7a4fc2ca613a22d1" to free 414715845 bytes
Apr 26 09:10:47 node-2-vm kubelet-wrapper[1064]: I0426 09:10:47.753698    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:dd25de8e412f1f52fecf390eeebcf9e95832a1d0412e0e0007f54482ce17644e" to free 414601850 bytes
Apr 26 09:11:11 node-2-vm kubelet-wrapper[1064]: I0426 09:11:11.217929    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:8c5180a9f04f4d5335ae34036ca574891b7387f511e9278dc121311fa6a99ec0" to free 761001968 bytes
Apr 26 09:11:39 node-2-vm kubelet-wrapper[1064]: I0426 09:11:39.845599    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:83d6014ac5c8193fa43dd16b161f0e524141800f10cff44d7bad3b637991cf16" to free 183560546 bytes
Apr 26 09:11:45 node-2-vm kubelet-wrapper[1064]: I0426 09:11:45.285893    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:4739b6afb43578c3099de049456bfa623501ee902f307618705b97da71b454f4" to free 641168361 bytes
Apr 26 09:12:07 node-2-vm kubelet-wrapper[1064]: I0426 09:12:07.672331    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:1ee3d66b99f1a88f81c9347b732e646a775a4482ab825113bc6390ae0de1c0c6" to free 415082682 bytes
Apr 26 09:12:07 node-2-vm kubelet-wrapper[1064]: I0426 09:12:07.709123    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:99e59f495ffaa222bfeb67580213e8c28c1e885f1d245ab2bbe3b1b1ec3bd0b2" to free 746888 bytes
Apr 26 09:12:07 node-2-vm kubelet-wrapper[1064]: I0426 09:12:07.712029    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:d8d99e23406fba9037c247af8dd9a3e936c7f728b821ddc488458ff03fd474f5" to free 414508520 bytes
Apr 26 09:12:39 node-2-vm kubelet-wrapper[1064]: I0426 09:12:39.555437    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:57097b8b4e2a3b6cc90cf80c00646397fdeaab2976e0c617f7c9a3e120f4d290" to free 414649779 bytes
Apr 26 09:13:05 node-2-vm kubelet-wrapper[1064]: I0426 09:13:05.179673    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:a5f8d66a067e1d15ae5bc2cf75f2e9834581699dcc662d66e7cc33db82d79c4e" to free 179648037 bytes
Apr 26 09:13:05 node-2-vm kubelet-wrapper[1064]: I0426 09:13:05.184026    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:4779a897e7007a07d37ca64a6651d410ffed65da83034f39c7b41bcd6c2def9a" to free 273002785 bytes
Apr 26 09:13:09 node-2-vm kubelet-wrapper[1064]: E0426 09:13:09.518904    1064 eviction_manager.go:390] eviction manager: unexpected error when attempting to reduce imagefs pressure: wanted to free 9223372036854775807, but freed 13832984265 space with errors in image deletion: [rpc error: code = 2 desc = Error response from daemon: {"message":"conflict: unable to delete 5dbb6d76ba11 (cannot be forced) - image is being used by running container 62e0ff2934d0"}, rpc error: code = 2 desc = Error response from daemon: {"message":"conflict: unable to delete 91a48ff795ce (cannot be forced) - image is being used by running container 440c3c950d33"}, rpc error: code = 2 desc = Error response from daemon: {"message":"conflict: unable to delete ef2ca8397823 (cannot be forced) - image is being used by running container 82de671a9035"}, rpc error: code = 2 desc = Error response from daemon: {"message":"conflict: unable to delete 0d738dc5a385 (cannot be forced) - image is being used by running container fc4cbfae1022"}, rpc error: code = 2 desc = Error response from daemon: {"message":"conflict: unable to delete 1ee3d66b99f1 (cannot be forced) - image is being used by running container ba7dcec7522e"}, rpc error: code = 2 desc = Error response from daemon: {"message":"conflict: unable to delete 99e59f495ffa (cannot be forced) - image is being used by running container c6f5bc80dc3e"}, rpc error: code = 2 desc = Error response from daemon: {"message":"conflict: unable to delete a5f8d66a067e (cannot be forced) - image is being used by running container e1f71e592f81"}]
Apr 26 09:13:09 node-2-vm kubelet-wrapper[1064]: I0426 09:13:09.518941    1064 eviction_manager.go:313] eviction manager: must evict pod(s) to reclaim imagefs
Apr 26 09:13:09 node-2-vm kubelet-wrapper[1064]: I0426 09:13:09.519150    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:91a48ff795cebb88646ec6cc4955bf7f500466feb44ec18b508f2ce94ed0d9b7" to free 664880136 bytes
Apr 26 09:13:09 node-2-vm kubelet-wrapper[1064]: I0426 09:13:09.520105    1064 eviction_manager.go:332] eviction manager: pods ranked for eviction: kube-proxy-node-2-vm_kube-system(917a0ffe06a546ae9000a727a4395dfe), fluentd-logz-kmpfn_kube-system(e28a913d-28df-11e7-83bd-000d3a2709aa), brpx-com-2906161812-c2ld6_brpx-com(dc409ba5-28eb-11e7-83bd-000d3a2709aa), brpx-com-2906161812-3k541_brpx-com(dc408bab-28eb-11e7-83bd-000d3a2709aa), tviftttapp-3948648935-38knh_tvifttt(302c71fc-2a5e-11e7-be9c-000d3a27013b), trendex-1520046056-97jj7_trendex(f2977579-2910-11e7-83bd-000d3a2709aa), trendex-1520046056-jbk0h_trendex(f296a799-2910-11e7-83bd-000d3a2709aa), gobrpxio-2079375017-l7hxn_gobrpxio(3013cf2a-2a5e-11e7-be9c-000d3a27013b), worten-ac-simulator-1580616395-j9x0w_worten-ac-simulator(30658401-2a5e-11e7-be9c-000d3a27013b), nosslack-3081705298-xtb46_nosslack(30344757-2a5e-11e7-be9c-000d3a27013b), cathode-355706785-3c12t_cathode(30407fc7-2a5e-11e7-be9c-000d3a27013b), pixelscamp-3764821432-t1jt1_pixelscamp(3035c1bb-2a5e-11e7-be9c-000d3a27013b), roamersapp-159490837-rq2k9_roamersapp(303595eb-2a5e-11e7-be9c-000d3a27013b)
Apr 26 09:13:09 node-2-vm kubelet-wrapper[1064]: I0426 09:13:09.546088    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:a5f8d66a067e1d15ae5bc2cf75f2e9834581699dcc662d66e7cc33db82d79c4e" to free 179648037 bytes
Apr 26 09:13:09 node-2-vm kubelet-wrapper[1064]: I0426 09:13:09.566398    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:99e59f495ffaa222bfeb67580213e8c28c1e885f1d245ab2bbe3b1b1ec3bd0b2" to free 746888 bytes
Apr 26 09:13:09 node-2-vm kubelet-wrapper[1064]: I0426 09:13:09.578684    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:1ee3d66b99f1a88f81c9347b732e646a775a4482ab825113bc6390ae0de1c0c6" to free 415082682 bytes
Apr 26 09:13:09 node-2-vm kubelet-wrapper[1064]: I0426 09:13:09.588268    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:5dbb6d76ba117f8a29c6d0000e9b33e8b5bdb29a9fe59ce560a381ed3e6688ed" to free 561602155 bytes
Apr 26 09:13:09 node-2-vm kubelet-wrapper[1064]: I0426 09:13:09.607324    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:ef2ca8397823de41a0752186c644a88cb93abb280a4e09e75704e3ae02b9332d" to free 185506981 bytes
Apr 26 09:13:09 node-2-vm kubelet-wrapper[1064]: I0426 09:13:09.617033    1064 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:0d738dc5a3854ca4bc81eea18f913f4776a5725e269443c4588369270474bb21" to free 273406715 bytes
Apr 26 09:13:10 node-2-vm kubelet-wrapper[1064]: I0426 09:13:10.601150    1064 eviction_manager.go:362] eviction manager: pod kube-proxy-node-2-vm_kube-system(917a0ffe06a546ae9000a727a4395dfe) evicted successfully

Node 3

Apr 26 09:23:26 node-3-vm kubelet-wrapper[1288]: + exec /usr/bin/rkt run --uuid-file-save=/var/run/kubelet-pod.uuid --volume var-cni,kind=host,source=/var/lib/cni --mount volume=var-cni,target=/var/lib/cni --volume var-log,kind=host,source=/var/log --mount volume=var-log,target=/var/log --volume lib-modules,kind=host,source=/lib/modules --mount volume=lib-modules,target=/lib/modules --volume etc-resolv,kind=host,source=/etc/resolv.conf --mount volume=etc-resolv,target=/etc/resolv.conf --trust-keys-from-https --volume etc-kubernetes,kind=host,source=/etc/kubernetes,readOnly=false --volume etc-ssl-certs,kind=host,source=/etc/ssl/certs,readOnly=true --volume usr-share-certs,kind=host,source=/usr/share/ca-certificates,readOnly=true --volume var-lib-docker,kind=host,source=/var/lib/docker,readOnly=false --volume var-lib-kubelet,kind=host,source=/var/lib/kubelet,readOnly=false --volume os-release,kind=host,source=/usr/lib/os-release,readOnly=true --volume run,kind=host,source=/run,readOnly=false --mount volume=etc-kubernetes,target=/etc/kubernetes --mount volume=etc-ssl-certs,target=/etc/ssl/certs --mount volume=usr-share-certs,target=/usr/share/ca-certificates --mount volume=var-lib-docker,target=/var/lib/docker --mount volume=var-lib-kubelet,target=/var/lib/kubelet --mount volume=os-release,target=/etc/os-release --mount volume=run,target=/run --stage1-from-dir=stage1-fly.aci quay.io/coreos/hyperkube:v1.6.2_coreos.0 --exec=/kubelet -- --cloud-provider=azure --cloud-config=/etc/kubernetes/azure.json --kubeconfig=/etc/kubernetes/worker-kubeconfig.yaml --require-kubeconfig --container-runtime=docker --network-plugin-dir=/etc/kubernetes/cni/net.d --network-plugin=kubenet --register-node=true --allow-privileged=true --pod-manifest-path=/etc/kubernetes/manifests --cluster-dns=10.3.0.10 --cluster-domain=cluster.local --client-ca-file=/etc/kubernetes/ssl/ca.pem --anonymous-auth=false --image-gc-high-threshold=85 --image-gc-low-threshold=75 --eviction-max-pod-grace-period=600 --eviction-minimum-reclaim=memory.available=350Mi,imagefs.available=2Gi,nodefs.available=2Gi '--evi
Apr 26 09:23:26 node-3-vm kubelet-wrapper[1288]: ction-soft=memory.available<300Mi,nodefs.available<14%,nodefs.inodesFree<14%,imagefs.available<14%,imagefs.inodesFree<14' --eviction-soft-grace-period=memory.available=1m30s,nodefs.available=1m30s,imagefs.available=1m30s,nodefs.inodesFree=1m,imagefs.inodesFree=1m '--eviction-hard=memory.available<250Mi,nodefs.available<10%,nodefs.inodesFree<10%,imagefs.available<10%,imagefs.inodesFree<10' --node-labels=component_type=node
Apr 26 09:24:06 node-3-vm kubelet-wrapper[1288]: I0426 09:24:06.718452    1288 container_manager_linux.go:250] Creating Container Manager object based on Node Config: {RuntimeCgroupsName: SystemCgroupsName: KubeletCgroupsName: ContainerRuntime:docker CgroupsPerQOS:true CgroupRoot:/ CgroupDriver:cgroupfs ProtectKernelDefaults:false EnableCRI:true NodeAllocatableConfig:{KubeReservedCgroupName: SystemReservedCgroupName: EnforceNodeAllocatable:map[pods:{}] KubeReserved:map[] SystemReserved:map[] HardEvictionThresholds:[{Signal:memory.available Operator:LessThan Value:{Quantity:250Mi Percentage:0} GracePeriod:0s MinReclaim:<nil>} {Signal:nodefs.available Operator:LessThan Value:{Quantity:<nil> Percentage:0.1} GracePeriod:0s MinReclaim:<nil>} {Signal:nodefs.inodesFree Operator:LessThan Value:{Quantity:<nil> Percentage:0.1} GracePeriod:0s MinReclaim:<nil>} {Signal:imagefs.available Operator:LessThan Value:{Quantity:<nil> Percentage:0.1} GracePeriod:0s MinReclaim:<nil>} {Signal:imagefs.inodesFree Operator:LessThan Value:{Quantity:10 Percentage:0} GracePeriod:0s MinReclaim:<nil>}]} ExperimentalQOSReserved:map[]}
Apr 26 09:27:32 node-3-vm kubelet-wrapper[1288]: W0426 09:27:32.212234    1288 eviction_manager.go:299] eviction manager: attempting to reclaim imagefs
Apr 26 09:27:32 node-3-vm kubelet-wrapper[1288]: I0426 09:27:32.212259    1288 helpers.go:996] eviction manager: attempting to delete unused images
Apr 26 09:27:32 node-3-vm kubelet-wrapper[1288]: I0426 09:27:32.321234    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:83d6014ac5c8193fa43dd16b161f0e524141800f10cff44d7bad3b637991cf16" to free 183560546 bytes
Apr 26 09:27:52 node-3-vm kubelet-wrapper[1288]: I0426 09:27:52.947094    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:9ec203d124a6b68a6b7aaf2781980a23cb8bf25e5182be58fdee68c4ea923aaa" to free 871175724 bytes
Apr 26 09:28:27 node-3-vm kubelet-wrapper[1288]: I0426 09:28:27.738286    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:f84560f49efb2588bb02e40ec2f4c4c5921f19a05d5e1a16f97c0a79676d13c3" to free 181587389 bytes
Apr 26 09:28:33 node-3-vm kubelet-wrapper[1288]: I0426 09:28:33.674407    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:dee0c21171b2fad0ea7b3d8ecb3367f736545a5352664f0e4363fae9eeaf52d1" to free 414603265 bytes
Apr 26 09:28:33 node-3-vm kubelet-wrapper[1288]: W0426 09:28:33.676812    1288 image_gc_manager.go:176] [imageGCManager] Failed to update image list: rpc error: code = 2 desc = Error response from daemon: {"message":"layer does not exist"}
Apr 26 09:29:06 node-3-vm kubelet-wrapper[1288]: I0426 09:29:06.976314    1288 image_gc_manager.go:270] [imageGCManager]: Disk usage on "/dev/sdb" (/var/lib/docker/overlay) is at 90% which is over the high threshold (85%). Trying to free 2964397056 bytes
Apr 26 09:29:08 node-3-vm kubelet-wrapper[1288]: I0426 09:29:08.978328    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:896f0b69742a885415971c4c0ff5061b6be98b1f13b992a8d807cb01a8fb64bb" to free 414645633 bytes
Apr 26 09:29:42 node-3-vm kubelet-wrapper[1288]: I0426 09:29:42.307318    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:23e06117ef295ada062462ed6d942a9cc71b28207ba54002685f8a742160a2af" to free 871180902 bytes
Apr 26 09:30:19 node-3-vm kubelet-wrapper[1288]: I0426 09:30:19.809220    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:5e9aec5d1f8258478c5d923e6130d4261ac4486518276e3c2b125ccae6195b5d" to free 674664162 bytes
Apr 26 09:30:19 node-3-vm kubelet-wrapper[1288]: W0426 09:30:19.810449    1288 image_gc_manager.go:176] [imageGCManager] Failed to update image list: rpc error: code = 2 desc = Error response from daemon: {"message":"layer does not exist"}
Apr 26 09:30:36 node-3-vm kubelet-wrapper[1288]: I0426 09:30:36.934116    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:a8d49a60310d1c2d69287718724c2b59f6c589bfec1699decc2758141bfee5e5" to free 414603265 bytes
Apr 26 09:30:59 node-3-vm kubelet-wrapper[1288]: I0426 09:30:59.756611    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:3c734123a3d156f74608ab8fdc1e1776137c01b9026dd36901f70e1202f50c82" to free 748518122 bytes
Apr 26 09:31:30 node-3-vm kubelet-wrapper[1288]: I0426 09:31:30.832890    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:4779a897e7007a07d37ca64a6651d410ffed65da83034f39c7b41bcd6c2def9a" to free 273002785 bytes
Apr 26 09:31:41 node-3-vm kubelet-wrapper[1288]: I0426 09:31:41.813643    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:ef2ca8397823de41a0752186c644a88cb93abb280a4e09e75704e3ae02b9332d" to free 185506981 bytes
Apr 26 09:31:47 node-3-vm kubelet-wrapper[1288]: I0426 09:31:47.478619    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:1180413103fdfd00a7882d3d8653a220d88c6ea4466fb860e98376c45ee1a1d0" to free 103563297 bytes
Apr 26 09:31:47 node-3-vm kubelet-wrapper[1288]: I0426 09:31:47.563776    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:99e59f495ffaa222bfeb67580213e8c28c1e885f1d245ab2bbe3b1b1ec3bd0b2" to free 746888 bytes
Apr 26 09:31:47 node-3-vm kubelet-wrapper[1288]: I0426 09:31:47.565923    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:512d06ca2b31a1217dfa0d27d5d8d62c2cf4171445a88a4fcec216b2e9ff2eaa" to free 415125623 bytes
Apr 26 09:32:18 node-3-vm kubelet-wrapper[1288]: I0426 09:32:18.074035    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:7a32fb6af2795d1761fd2983ec8fe37a5aad496e6e640f5b3f21f7e2b6f22590" to free 414601831 bytes
Apr 26 09:32:41 node-3-vm kubelet-wrapper[1288]: I0426 09:32:41.005883    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:6e5b5780cb380efbd828c4f6b60139db1eda21de3ef6113c34a8ae590c501cfc" to free 414645625 bytes
Apr 26 09:33:01 node-3-vm kubelet-wrapper[1288]: I0426 09:33:01.499874    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:c5fcd8f5fe67278d877709cf1da47f33cd2c15ef79782c9a419f06a26cc21063" to free 414648929 bytes
Apr 26 09:33:24 node-3-vm kubelet-wrapper[1288]: W0426 09:33:24.157771    1288 image_gc_manager.go:176] [imageGCManager] Failed to update image list: rpc error: code = 2 desc = Error response from daemon: {"message":"layer does not exist"}
Apr 26 09:33:24 node-3-vm kubelet-wrapper[1288]: I0426 09:33:24.158230    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:3f8119a98476b97e806057a72e8e836a2d3e65d56e9b4c790e75874e586b8db0" to free 146818590 bytes
Apr 26 09:33:30 node-3-vm kubelet-wrapper[1288]: I0426 09:33:30.684768    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:5dbb6d76ba117f8a29c6d0000e9b33e8b5bdb29a9fe59ce560a381ed3e6688ed" to free 561602155 bytes
Apr 26 09:33:30 node-3-vm kubelet-wrapper[1288]: I0426 09:33:30.687293    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:79a2226593dda8d6fd9956ec678af5f6b104d0eb8e8df30c1be62283c0a68877" to free 414715845 bytes
Apr 26 09:33:51 node-3-vm kubelet-wrapper[1288]: I0426 09:33:51.395912    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:cb3475bac179739e6d982aa90c921bb0b583b24b7cbabd740302fe8d05f55c5e" to free 414568784 bytes
Apr 26 09:34:14 node-3-vm kubelet-wrapper[1288]: I0426 09:34:14.532056    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:2ee0b872ccbb2dfd9e6faddfdc2341c909f4166aeb02004d918bab338b7eaf53" to free 863819225 bytes
Apr 26 09:34:14 node-3-vm kubelet-wrapper[1288]: I0426 09:34:14.559276    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:1a9f79a809a7882738516f53848f872baea546897933dea78a8402e7f8963038" to free 974481562 bytes
Apr 26 09:34:14 node-3-vm kubelet-wrapper[1288]: I0426 09:34:14.570443    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:91a48ff795cebb88646ec6cc4955bf7f500466feb44ec18b508f2ce94ed0d9b7" to free 664880136 bytes
Apr 26 09:34:14 node-3-vm kubelet-wrapper[1288]: I0426 09:34:14.572576    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:5b77efb72fcbbeb8d1282b96a18b675f11644b08ce5a88a952b6810bbda5b539" to free 751380229 bytes
Apr 26 09:34:39 node-3-vm kubelet-wrapper[1288]: I0426 09:34:39.201827    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:f71539c16f7407d68f351d1ea72ef7e075ea6d19b1a228229b029bf0a90bfe39" to free 1008205660 bytes
Apr 26 09:35:44 node-3-vm kubelet-wrapper[1288]: I0426 09:35:44.323401    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:e624a16e665b50f70d9edbe8af10e817926cf7ea52825ec9c7a35e0057e79306" to free 903598860 bytes
Apr 26 09:36:11 node-3-vm kubelet-wrapper[1288]: I0426 09:36:11.967106    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:ee590f1abe7181fd148a1a1ed48b24a6cbc54918e94569229e419ef9ea56c432" to free 693318312 bytes
Apr 26 09:36:58 node-3-vm kubelet-wrapper[1288]: I0426 09:36:58.853541    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:93b7861812ab036ba0961a50691350f9a1adafbbcfa8f6abffca93dd507a137e" to free 273406785 bytes
Apr 26 09:37:06 node-3-vm kubelet-wrapper[1288]: I0426 09:37:06.408117    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:0fad4ed4855b1092b05c4e7fa6fe660047d4d3378c015cd34823b5326d0cce5c" to free 414650028 bytes
Apr 26 09:37:30 node-3-vm kubelet-wrapper[1288]: I0426 09:37:30.423168    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:c3b1d136672c23484b112e14749735b354d9c7dc05365d4a0b90adc0c17eba0a" to free 414509012 bytes
Apr 26 09:37:50 node-3-vm kubelet-wrapper[1288]: I0426 09:37:50.212160    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:a5f8d66a067e1d15ae5bc2cf75f2e9834581699dcc662d66e7cc33db82d79c4e" to free 179648037 bytes
Apr 26 09:38:10 node-3-vm kubelet-wrapper[1288]: I0426 09:38:10.739730    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:4739b6afb43578c3099de049456bfa623501ee902f307618705b97da71b454f4" to free 641168361 bytes
Apr 26 09:38:29 node-3-vm kubelet-wrapper[1288]: I0426 09:38:29.066874    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:f221d902bfa1d13809e5a3892b3d361ec8e37aa90cbe59d578f8658b61639cf0" to free 415186811 bytes
Apr 26 09:38:48 node-3-vm kubelet-wrapper[1288]: I0426 09:38:48.980938    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:0de7d8cab78b2d5e7a14ba8529eb6acf1efc6c1fe8cb18ba14f0f790dc875269" to free 414715665 bytes
Apr 26 09:39:14 node-3-vm kubelet-wrapper[1288]: I0426 09:39:14.346209    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:91a48ff795cebb88646ec6cc4955bf7f500466feb44ec18b508f2ce94ed0d9b7" to free 664880136 bytes
Apr 26 09:39:14 node-3-vm kubelet-wrapper[1288]: E0426 09:39:14.346813    1288 eviction_manager.go:390] eviction manager: unexpected error when attempting to reduce imagefs pressure: wanted to free 9223372036854775807, but freed 14081525058 space with errors in image deletion: [rpc error: code = 2 desc = Error response from daemon: {"message":"conflict: unable to delete 99e59f495ffa (cannot be forced) - image is being used by running container 1b191bec34dd"}, rpc error: code = 2 desc = Error response from daemon: {"message":"conflict: unable to delete 5dbb6d76ba11 (cannot be forced) - image is being used by running container 8ecfe612b1c0"}, rpc error: code = 2 desc = Error response from daemon: {"message":"conflict: unable to delete 2ee0b872ccbb (cannot be forced) - image is being used by running container a42d6771288a"}, rpc error: code = 2 desc = Error response from daemon: {"message":"conflict: unable to delete 1a9f79a809a7 (cannot be forced) - image is being used by running container e4c0672d38ea"}, rpc error: code = 2 desc = Error response from daemon: {"message":"conflict: unable to delete 91a48ff795ce (cannot be forced) - image is being used by running container 9bee9ae28d51"}]
Apr 26 09:39:14 node-3-vm kubelet-wrapper[1288]: I0426 09:39:14.346842    1288 eviction_manager.go:313] eviction manager: must evict pod(s) to reclaim imagefs
Apr 26 09:39:14 node-3-vm kubelet-wrapper[1288]: I0426 09:39:14.347822    1288 eviction_manager.go:332] eviction manager: pods ranked for eviction: kube-proxy-node-3-vm_kube-system(917a0ffe06a546ae9000a727a4395dfe), tv-directory-4148676373-1g3zq_tv-directory(5c49b524-2a62-11e7-be9c-000d3a27013b), nginx-3757477279-2hzxp_nginx-ingress(5c4c6933-2a62-11e7-be9c-000d3a27013b), roamersapp-159490837-mk8ws_roamersapp(5be44228-2a62-11e7-be9c-000d3a27013b), fluentd-logz-1dmdm_kube-system(fdfc4d47-d0f2-11e6-b156-000d3a2709aa), cathode-355706785-sq0zr_cathode(5be4553d-2a62-11e7-be9c-000d3a27013b), nosslack-3081705298-vch8g_nosslack(5c2669fe-2a62-11e7-be9c-000d3a27013b), raster-2089787901-ft9fb_raster(5bebc12b-2a62-11e7-be9c-000d3a27013b), bitshopping-2917900847-kcc53_bitshopping(5becec47-2a62-11e7-be9c-000d3a27013b), nosslackbot-104706747-06psp_nosslack(5c6460fd-2a62-11e7-be9c-000d3a27013b), gobrpxio-2079375017-85w0b_gobrpxio(5c912596-2a62-11e7-be9c-000d3a27013b), default-http-backend-3981334675-kfbrq_nginx-ingress(5c647b47-2a62-11e7-be9c-000d3a27013b)
Apr 26 09:39:14 node-3-vm kubelet-wrapper[1288]: I0426 09:39:14.516146    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:99e59f495ffaa222bfeb67580213e8c28c1e885f1d245ab2bbe3b1b1ec3bd0b2" to free 746888 bytes
Apr 26 09:39:14 node-3-vm kubelet-wrapper[1288]: I0426 09:39:14.543119    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:2ee0b872ccbb2dfd9e6faddfdc2341c909f4166aeb02004d918bab338b7eaf53" to free 863819225 bytes
Apr 26 09:39:14 node-3-vm kubelet-wrapper[1288]: I0426 09:39:14.573738    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:1a9f79a809a7882738516f53848f872baea546897933dea78a8402e7f8963038" to free 974481562 bytes
Apr 26 09:39:14 node-3-vm kubelet-wrapper[1288]: I0426 09:39:14.581163    1288 image_gc_manager.go:335] [imageGCManager]: Removing image "sha256:5dbb6d76ba117f8a29c6d0000e9b33e8b5bdb29a9fe59ce560a381ed3e6688ed" to free 561602155 bytes
Apr 26 09:39:14 node-3-vm kubelet-wrapper[1288]: I0426 09:39:14.898393    1288 eviction_manager.go:362] eviction manager: pod kube-proxy-node-3-vm_kube-system(917a0ffe06a546ae9000a727a4395dfe) evicted successfully