{"action":"created","issue":{"url":"https://api.github.com/repos/GoogleCloudPlatform/kubernetes/issues/3952","labels_url":"https://api.github.com/repos/GoogleCloudPlatform/kubernetes/issues/3952/labels{/name}","comments_url":"https://api.github.com/repos/GoogleCloudPlatform/kubernetes/issues/3952/comments","events_url":"https://api.github.com/repos/GoogleCloudPlatform/kubernetes/issues/3952/events","html_url":"https://github.com/GoogleCloudPlatform/kubernetes/issues/3952","id":55965563,"number":3952,"title":"0-20 second delay before running pod transitions to status: Running","user":{"login":"alex-mohr","id":8729097,"avatar_url":"https://avatars.githubusercontent.com/u/8729097?v=3","gravatar_id":"","url":"https://api.github.com/users/alex-mohr","html_url":"https://github.com/alex-mohr","followers_url":"https://api.github.com/users/alex-mohr/followers","following_url":"https://api.github.com/users/alex-mohr/following{/other_user}","gists_url":"https://api.github.com/users/alex-mohr/gists{/gist_id}","starred_url":"https://api.github.com/users/alex-mohr/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/alex-mohr/subscriptions","organizations_url":"https://api.github.com/users/alex-mohr/orgs","repos_url":"https://api.github.com/users/alex-mohr/repos","events_url":"https://api.github.com/users/alex-mohr/events{/privacy}","received_events_url":"https://api.github.com/users/alex-mohr/received_events","type":"User","site_admin":false},"labels":[{"url":"https://api.github.com/repos/GoogleCloudPlatform/kubernetes/labels/api/kubelet","name":"api/kubelet","color":"fbca04"},{"url":"https://api.github.com/repos/GoogleCloudPlatform/kubernetes/labels/area/usability","name":"area/usability","color":"00cc00"},{"url":"https://api.github.com/repos/GoogleCloudPlatform/kubernetes/labels/priority/P2","name":"priority/P2","color":"fbca04"}],"state":"open","locked":false,"assignee":null,"milestone":null,"comments":1,"created_at":"2015-01-29T22:16:30Z","updated_at":"2015-01-30T00:20:39Z","closed_at":null,"body":"@dchen1107 There seems to be a 0 to 20 second delay before a single pause pod to get to Running.  It should be << 10 seconds.  For version 0.8.1, part of #3936.\r\n\r\nHere's an example.  In this case, scheduler seemed to schedule it reasonably quickly (< 1 sec), the kubelet launched it quickly (<1 sec), and docker transitioned container to running quickly (<1 sec), but pod status available via the master took another 15 seconds.  In particular, the status update seemed to either be blocked on the following kubelet.log entry, or that entry is triggered by something or another that was blocked:\r\n> I0129 22:08:20.019854    4903 server.go:324] GET /api/v1beta1/podInfo?podID=pause-pod-1fcbe922&podNamespace=default: (4.894854ms) 200\r\n\r\n\r\nFrom my workstation:\r\n> % gcloud preview container pods --cluster=${PROJECT} create --name=pause-pod-1fcbe922 --image=kubernetes/pause --port=${PORT}\r\n\r\nOutput of list pods with timestamps in PST:\r\nThu Jan 29 14:08:03 PST 2015: 1: creating pause-pod-1fcbe922 on port 30069\r\npause-pod-1fcbe922\r\nThu Jan 29 14:08:05 PST 2015: 1: fetching pod list\r\npause-pod-1fcbe922                       pause-pod-1fcbe922   kubernetes/pause    k8s-prod5-node-1.c.mohr-instance-manager.internal/                 name=pause-pod-1fcbe922   Unknown\r\nThu Jan 29 14:08:06 PST 2015: 1: fetching pod list\r\npause-pod-1fcbe922                       pause-pod-1fcbe922   kubernetes/pause    k8s-prod5-node-1.c.mohr-instance-manager.internal/                 name=pause-pod-1fcbe922   Unknown\r\nThu Jan 29 14:08:08 PST 2015: 1: fetching pod list\r\npause-pod-1fcbe922                       pause-pod-1fcbe922   kubernetes/pause    k8s-prod5-node-1.c.mohr-instance-manager.internal/                 name=pause-pod-1fcbe922   Unknown\r\nThu Jan 29 14:08:10 PST 2015: 1: fetching pod list\r\npause-pod-1fcbe922                       pause-pod-1fcbe922   kubernetes/pause    k8s-prod5-node-1.c.mohr-instance-manager.internal/                 name=pause-pod-1fcbe922   Unknown\r\nThu Jan 29 14:08:11 PST 2015: 1: fetching pod list\r\npause-pod-1fcbe922                       pause-pod-1fcbe922   kubernetes/pause    k8s-prod5-node-1.c.mohr-instance-manager.internal/                 name=pause-pod-1fcbe922   Unknown\r\nThu Jan 29 14:08:13 PST 2015: 1: fetching pod list\r\npause-pod-1fcbe922                       pause-pod-1fcbe922   kubernetes/pause    k8s-prod5-node-1.c.mohr-instance-manager.internal/                 name=pause-pod-1fcbe922   Unknown\r\nThu Jan 29 14:08:14 PST 2015: 1: fetching pod list\r\npause-pod-1fcbe922                       pause-pod-1fcbe922   kubernetes/pause    k8s-prod5-node-1.c.mohr-instance-manager.internal/                 name=pause-pod-1fcbe922   Unknown\r\nThu Jan 29 14:08:16 PST 2015: 1: fetching pod list\r\npause-pod-1fcbe922                       pause-pod-1fcbe922   kubernetes/pause    k8s-prod5-node-1.c.mohr-instance-manager.internal/                 name=pause-pod-1fcbe922   Unknown\r\nThu Jan 29 14:08:18 PST 2015: 1: fetching pod list\r\npause-pod-1fcbe922                       pause-pod-1fcbe922   kubernetes/pause    k8s-prod5-node-1.c.mohr-instance-manager.internal/                 name=pause-pod-1fcbe922   Unknown\r\nThu Jan 29 14:08:19 PST 2015: 1: fetching pod list\r\nThu Jan 29 14:08:21 PST 2015: 1: 1 running\r\nThu Jan 29 14:08:21 PST 2015: 1: deleting all pods\r\n\r\nRelevant kubelet log in UTC:\r\nI0129 22:08:05.297181    4903 logs.go:39] etcd DEBUG: recv.success.http://10.240.222.31:4001/v2/keys/registry/nodes/k8s-prod5-node-1.c.mohr-instance-manager.interna\r\nl/boundpods?consistent=true&wait=true&waitIndex=12699\r\nI0129 22:08:05.297448    4903 logs.go:39] etcd DEBUG: get /registry/nodes/k8s-prod5-node-1.c.mohr-instance-manager.internal/boundpods [http://10.240.222.31:4001]\r\nI0129 22:08:05.297535    4903 logs.go:39] etcd DEBUG: Connecting to etcd: attempt1forkeys/registry/nodes/k8s-prod5-node-1.c.mohr-instance-manager.internal/boundpods\r\n?consistent=true&wait=true&waitIndex=12706\r\nI0129 22:08:05.297548    4903 logs.go:39] etcd DEBUG: send.request.to http://10.240.222.31:4001/v2/keys/registry/nodes/k8s-prod5-node-1.c.mohr-instance-manager.inte\r\nrnal/boundpods?consistent=true&wait=true&waitIndex=12706 | method GET\r\nW0129 22:08:05.308951    4903 config.go:307] Pod 1 () from etcd failed validation, ignoring: [name: required value '' namespace: required value 'default']\r\nI0129 22:08:05.312089    4903 logs.go:39] etcd DEBUG: recv.response.fromhttp://10.240.222.31:4001/v2/keys/registry/nodes/k8s-prod5-node-1.c.mohr-instance-manager.in\r\nternal/boundpods?consistent=true&wait=true&waitIndex=12706\r\nI0129 22:08:05.314162    4903 kubelet.go:793] Network container doesn't exist for pod \"pause-pod-1fcbe922.default.etcd\", killing and re-creating the pod\r\nI0129 22:08:05.317955    4903 event.go:92] Event(api.ObjectReference{Kind:\"BoundPod\", Namespace:\"default\", Name:\"pause-pod-1fcbe922\", UID:\"4cadf377-a803-11e4-a2ec-42010af0de1f\", APIVersion:\"v1beta1\", ResourceVersion:\"\", FieldPath:\"implicitly required container net\"}): status: 'waiting', reason: 'pulled' Successfully pulled image \"kubernetes/pause:latest\"\r\nI0129 22:08:05.419784    4903 event.go:92] Event(api.ObjectReference{Kind:\"BoundPod\", Namespace:\"default\", Name:\"pause-pod-1fcbe922\", UID:\"4cadf377-a803-11e4-a2ec-42010af0de1f\", APIVersion:\"v1beta1\", ResourceVersion:\"\", FieldPath:\"implicitly required container net\"}): status: 'waiting', reason: 'created' Created with docker id 93b26b849bfb454cc86cd6467a32906a79eb72a5705c3ae473ee1c7edc64b7ee\r\nI0129 22:08:05.554694    4903 event.go:92] Event(api.ObjectReference{Kind:\"BoundPod\", Namespace:\"default\", Name:\"pause-pod-1fcbe922\", UID:\"4cadf377-a803-11e4-a2ec-42010af0de1f\", APIVersion:\"v1beta1\", ResourceVersion:\"\", FieldPath:\"implicitly required container net\"}): status: 'running', reason: 'started' Started with docker id 93b26b849bfb454cc86cd6467a32906a79eb72a5705c3ae473ee1c7edc64b7ee\r\nI0129 22:08:05.675279    4903 event.go:92] Event(api.ObjectReference{Kind:\"BoundPod\", Namespace:\"default\", Name:\"pause-pod-1fcbe922\", UID:\"4cadf377-a803-11e4-a2ec-42010af0de1f\", APIVersion:\"v1beta1\", ResourceVersion:\"\", FieldPath:\"spec.containers{pause-pod-1fcbe922}\"}): status: 'waiting', reason: 'created' Created with docker id 80def133b602fa2e4d2cf98a9e7903f9c83887fa281277d38f2850dbfcbaeed8\r\nI0129 22:08:05.777623    4903 event.go:92] Event(api.ObjectReference{Kind:\"BoundPod\", Namespace:\"default\", Name:\"pause-pod-1fcbe922\", UID:\"4cadf377-a803-11e4-a2ec-42010af0de1f\", APIVersion:\"v1beta1\", ResourceVersion:\"\", FieldPath:\"spec.containers{pause-pod-1fcbe922}\"}): status: 'running', reason: 'started' Started with docker id 80def133b602fa2e4d2cf98a9e7903f9c83887fa281277d38f2850dbfcbaeed8\r\nI0129 22:08:07.996475    4903 server.go:324] GET /healthz: (10.235us) 200\r\nI0129 22:08:10.519742    4903 server.go:324] GET /healthz: (11.461us) 200\r\nI0129 22:08:10.960311    4903 file.go:171] Got pod from file \"/etc/kubernetes/manifests/cadvisor.manifest\": default.cadvisor-agent (cadvisormanifes12uqn2ohido76855gdecd9roadm7l0)\r\nI0129 22:08:18.003785    4903 server.go:324] GET /healthz: (11.971us) 200\r\nI0129 22:08:20.011837    4903 server.go:324] GET /healthz: (10.642us) 200\r\nI0129 22:08:20.012008    4903 server.go:324] GET /healthz: (3.816us) 200\r\nI0129 22:08:20.015171    4903 logs.go:39] http: multiple response.WriteHeader calls\r\nI0129 22:08:20.015208    4903 server.go:324] GET /api/v1beta1/podInfo?podID=&podNamespace=: (80.895us) 400\r\ngoroutine 42938 [running]:\r\ngithub.com/GoogleCloudPlatform/kubernetes/pkg/httplog.(*respLogger).WriteHeader(0xc209810600, 0x190)\r\n        /go/src/github.com/GoogleCloudPlatform/kubernetes/_output/dockerized/go/src/github.com/GoogleCloudPlatform/kubernetes/pkg/httplog/log.go:182 +0x9c\r\nnet/http.Error(0x7f3876a0f830, 0xc209810600, 0xaf2cf0, 0x1d, 0x190)\r\n        /usr/src/go/src/pkg/net/http/server.go:1244 +0x96\r\ngithub.com/GoogleCloudPlatform/kubernetes/pkg/kubelet.(*Server).handlePodInfo(0xc20812a320, 0x7f3876a0f830, 0xc209810600, 0xc20a112dd0, 0x95d6901)\r\n        /go/src/github.com/GoogleCloudPlatform/kubernetes/_output/dockerized/go/src/github.com/GoogleCloudPlatform/kubernetes/pkg/kubelet/server.go:212 +0x2a4\r\ngithub.com/GoogleCloudPlatform/kubernetes/pkg/kubelet.(*Server).handlePodInfoVersioned(0xc20812a320, 0x7f3876a0f830, 0xc209810600, 0xc20a112dd0)\r\n        /go/src/github.com/GoogleCloudPlatform/kubernetes/_output/dockerized/go/src/github.com/GoogleCloudPlatform/kubernetes/pkg/kubelet/server.go:197 +0x4a\r\ngithub.com/GoogleCloudPlatform/kubernetes/pkg/kubelet.*Server.(github.com/GoogleCloudPlatform/kubernetes/pkg/kubelet.handlePodInfoVersioned)·fm(0x7f3876a0f830, 0xc209810600, 0xc20a112dd0)\r\n        /go/src/github.com/GoogleCloudPlatform/kubernetes/_output/dockerized/go/src/github.com/GoogleCloudPlatform/kubernetes/pkg/kubelet/server.go:92 +0x44\r\nnet/http.HandlerFunc.ServeHTTP(0xc2081264e0, 0x7f3876a0f830, 0xc209810600, 0xc20a112dd0)\r\n        /usr/src/go/src/pkg/net/http/server.go:1235 +0x40\r\nnet/http.(*ServeMux).ServeHTTP(0xc20811ab10, 0x7f3876a0f830, 0xc209810600, 0xc20a112dd0)\r\n        /usr/src/go/src/pkg/net/http/server.go:1511 +0x1a3\r\ngithub.com/GoogleCloudPlatform/kubernetes/pkg/kubelet.(*Server).ServeHTTP(0xc20812a300, 0x7f3876a0f7f8, 0xc208131220, 0xc20a112dd0)\r\n        /go/src/github.com/GoogleCloudPlatform/kubernetes/_output/dockerized/go/src/github.com/GoogleCloudPlatform/kubernetes/pkg/kubelet/server.go:323 +0x11d\r\nnet/http.serverHandler.ServeHTTP(0xc208112ba0, 0x7f3876a0f7f8, 0xc208131220, 0xc20a112dd0)\r\n        /usr/src/go/src/pkg/net/http/server.go:1673 +0x19f\r\nnet/http.(*\r\nI0129 22:08:20.019854    4903 server.go:324] GET /api/v1beta1/podInfo?podID=pause-pod-1fcbe922&podNamespace=default: (4.894854ms) 200\r\nI0129 22:08:20.910257    4903 server.go:324] GET /healthz: (11.933us) 200\r\nI0129 22:08:22.819342    4903 logs.go:39] etcd DEBUG: recv.success.http://10.240.222.31:4001/v2/keys/registry/nodes/k8s-prod5-node-1.c.mohr-instance-manager.internal/boundpods?consistent=true&wait=true&waitIndex=12706\r\nI0129 22:08:22.819569    4903 logs.go:39] etcd DEBUG: get /registry/nodes/k8s-prod5-node-1.c.mohr-instance-manager.internal/boundpods [http://10.240.222.31:4001]\r\nI0129 22:08:22.819603    4903 logs.go:39] etcd DEBUG: Connecting to etcd: attempt1forkeys/registry/nodes/k8s-prod5-node-1.c.mohr-instance-manager.internal/boundpods?consistent=true&wait=true&waitIndex=12714\r\nI0129 22:08:22.819613    4903 logs.go:39] etcd DEBUG: send.request.to http://10.240.222.31:4001/v2/keys/registry/nodes/k8s-prod5-node-1.c.mohr-instance-manager.internal/boundpods?consistent=true&wait=true&waitIndex=12714 | method GET\r\nW0129 22:08:22.831964    4903 config.go:307] Pod 1 () from etcd failed validation, ignoring: [name: required value '' namespace: required value 'default']\r\nI0129 22:08:22.834110    4903 logs.go:39] etcd DEBUG: recv.response.fromhttp://10.240.222.31:4001/v2/keys/registry/nodes/k8s-prod5-node-1.c.mohr-instance-manager.internal/boundpods?consistent=true&wait=true&waitIndex=12714\r\nI0129 22:08:22.836408    4903 kubelet.go:1044] Killing unwanted container {podFullName:pause-pod-1fcbe922.default.etcd uuid:4cadf377-a803-11e4-a2ec-42010af0de1f containerName:pause-pod-1fcbe922}\r\n"},"comment":{"url":"https://api.github.com/repos/GoogleCloudPlatform/kubernetes/issues/comments/72131750","html_url":"https://github.com/GoogleCloudPlatform/kubernetes/issues/3952#issuecomment-72131750","issue_url":"https://api.github.com/repos/GoogleCloudPlatform/kubernetes/issues/3952","id":72131750,"user":{"login":"erictune","id":8105590,"avatar_url":"https://avatars.githubusercontent.com/u/8105590?v=3","gravatar_id":"","url":"https://api.github.com/users/erictune","html_url":"https://github.com/erictune","followers_url":"https://api.github.com/users/erictune/followers","following_url":"https://api.github.com/users/erictune/following{/other_user}","gists_url":"https://api.github.com/users/erictune/gists{/gist_id}","starred_url":"https://api.github.com/users/erictune/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/erictune/subscriptions","organizations_url":"https://api.github.com/users/erictune/orgs","repos_url":"https://api.github.com/users/erictune/repos","events_url":"https://api.github.com/users/erictune/events{/privacy}","received_events_url":"https://api.github.com/users/erictune/received_events","type":"User","site_admin":false},"created_at":"2015-01-30T00:20:39Z","updated_at":"2015-01-30T00:20:39Z","body":"Why is kubelet talking to etcd?  A recently built kubelet should only talk\r\nto apiserver.\r\n\r\nOn Thu, Jan 29, 2015 at 2:16 PM, Alex Mohr <notifications@github.com> wrote:\r\n\r\n> @dchen1107 <https://github.com/dchen1107> There seems to be a 0 to 20\r\n> second delay before a single pause pod to get to Running. It should be <<\r\n> 10 seconds. For version 0.8.1, part of #3936\r\n> <https://github.com/GoogleCloudPlatform/kubernetes/issues/3936>.\r\n>\r\n> Here's an example. In this case, scheduler seemed to schedule it\r\n> reasonably quickly (< 1 sec), the kubelet launched it quickly (<1 sec), and\r\n> docker transitioned container to running quickly (<1 sec), but pod status\r\n> available via the master took another 15 seconds. In particular, the status\r\n> update seemed to either be blocked on the following kubelet.log entry, or\r\n> that entry is triggered by something or another that was blocked:\r\n>\r\n> I0129 22:08:20.019854 4903 server.go:324] GET\r\n> /api/v1beta1/podInfo?podID=pause-pod-1fcbe922&podNamespace=default:\r\n> (4.894854ms) 200\r\n>\r\n> From my workstation:\r\n>\r\n> % gcloud preview container pods --cluster=${PROJECT} create\r\n> --name=pause-pod-1fcbe922 --image=kubernetes/pause --port=${PORT}\r\n>\r\n> Output of list pods with timestamps in PST:\r\n> Thu Jan 29 14:08:03 PST 2015: 1: creating pause-pod-1fcbe922 on port 30069\r\n> pause-pod-1fcbe922\r\n> Thu Jan 29 14:08:05 PST 2015: 1: fetching pod list\r\n> pause-pod-1fcbe922 pause-pod-1fcbe922 kubernetes/pause\r\n> k8s-prod5-node-1.c.mohr-instance-manager.internal/ name=pause-pod-1fcbe922\r\n> Unknown\r\n> Thu Jan 29 14:08:06 PST 2015: 1: fetching pod list\r\n> pause-pod-1fcbe922 pause-pod-1fcbe922 kubernetes/pause\r\n> k8s-prod5-node-1.c.mohr-instance-manager.internal/ name=pause-pod-1fcbe922\r\n> Unknown\r\n> Thu Jan 29 14:08:08 PST 2015: 1: fetching pod list\r\n> pause-pod-1fcbe922 pause-pod-1fcbe922 kubernetes/pause\r\n> k8s-prod5-node-1.c.mohr-instance-manager.internal/ name=pause-pod-1fcbe922\r\n> Unknown\r\n> Thu Jan 29 14:08:10 PST 2015: 1: fetching pod list\r\n> pause-pod-1fcbe922 pause-pod-1fcbe922 kubernetes/pause\r\n> k8s-prod5-node-1.c.mohr-instance-manager.internal/ name=pause-pod-1fcbe922\r\n> Unknown\r\n> Thu Jan 29 14:08:11 PST 2015: 1: fetching pod list\r\n> pause-pod-1fcbe922 pause-pod-1fcbe922 kubernetes/pause\r\n> k8s-prod5-node-1.c.mohr-instance-manager.internal/ name=pause-pod-1fcbe922\r\n> Unknown\r\n> Thu Jan 29 14:08:13 PST 2015: 1: fetching pod list\r\n> pause-pod-1fcbe922 pause-pod-1fcbe922 kubernetes/pause\r\n> k8s-prod5-node-1.c.mohr-instance-manager.internal/ name=pause-pod-1fcbe922\r\n> Unknown\r\n> Thu Jan 29 14:08:14 PST 2015: 1: fetching pod list\r\n> pause-pod-1fcbe922 pause-pod-1fcbe922 kubernetes/pause\r\n> k8s-prod5-node-1.c.mohr-instance-manager.internal/ name=pause-pod-1fcbe922\r\n> Unknown\r\n> Thu Jan 29 14:08:16 PST 2015: 1: fetching pod list\r\n> pause-pod-1fcbe922 pause-pod-1fcbe922 kubernetes/pause\r\n> k8s-prod5-node-1.c.mohr-instance-manager.internal/ name=pause-pod-1fcbe922\r\n> Unknown\r\n> Thu Jan 29 14:08:18 PST 2015: 1: fetching pod list\r\n> pause-pod-1fcbe922 pause-pod-1fcbe922 kubernetes/pause\r\n> k8s-prod5-node-1.c.mohr-instance-manager.internal/ name=pause-pod-1fcbe922\r\n> Unknown\r\n> Thu Jan 29 14:08:19 PST 2015: 1: fetching pod list\r\n> Thu Jan 29 14:08:21 PST 2015: 1: 1 running\r\n> Thu Jan 29 14:08:21 PST 2015: 1: deleting all pods\r\n>\r\n> Relevant kubelet log in UTC:\r\n> I0129 22:08:05.297181 4903 logs.go:39] etcd DEBUG: recv.success.\r\n> http://10.240.222.31:4001/v2/keys/registry/nodes/k8s-prod5-node-1.c.mohr-instance-manager.interna\r\n> l/boundpods?consistent=true&wait=true&waitIndex=12699\r\n> I0129 22:08:05.297448 4903 logs.go:39] etcd DEBUG: get\r\n> /registry/nodes/k8s-prod5-node-1.c.mohr-instance-manager.internal/boundpods\r\n> [http://10.240.222.31:4001]\r\n> I0129 22:08:05.297535 4903 logs.go:39] etcd DEBUG: Connecting to etcd:\r\n> attempt1forkeys/registry/nodes/k8s-prod5-node-1.c.mohr-instance-manager.internal/boundpods\r\n> ?consistent=true&wait=true&waitIndex=12706\r\n> I0129 22:08:05.297548 4903 logs.go:39] etcd DEBUG: send.request.to\r\n> http://10.240.222.31:4001/v2/keys/registry/nodes/k8s-prod5-node-1.c.mohr-instance-manager.inte\r\n> rnal/boundpods?consistent=true&wait=true&waitIndex=12706 | method GET\r\n> W0129 22:08:05.308951 4903 config.go:307] Pod 1 () from etcd failed\r\n> validation, ignoring: [name: required value '' namespace: required value\r\n> 'default']\r\n> I0129 22:08:05.312089 4903 logs.go:39] etcd DEBUG:\r\n> recv.response.fromhttp://\r\n> 10.240.222.31:4001/v2/keys/registry/nodes/k8s-prod5-node-1.c.mohr-instance-manager.in\r\n> ternal/boundpods?consistent=true&wait=true&waitIndex=12706\r\n> I0129 22:08:05.314162 4903 kubelet.go:793] Network container doesn't exist\r\n> for pod \"pause-pod-1fcbe922.default.etcd\", killing and re-creating the pod\r\n> I0129 22:08:05.317955 4903 event.go:92]\r\n> Event(api.ObjectReference{Kind:\"BoundPod\", Namespace:\"default\",\r\n> Name:\"pause-pod-1fcbe922\", UID:\"4cadf377-a803-11e4-a2ec-42010af0de1f\",\r\n> APIVersion:\"v1beta1\", ResourceVersion:\"\", FieldPath:\"implicitly required\r\n> container net\"}): status: 'waiting', reason: 'pulled' Successfully pulled\r\n> image \"kubernetes/pause:latest\"\r\n> I0129 22:08:05.419784 4903 event.go:92]\r\n> Event(api.ObjectReference{Kind:\"BoundPod\", Namespace:\"default\",\r\n> Name:\"pause-pod-1fcbe922\", UID:\"4cadf377-a803-11e4-a2ec-42010af0de1f\",\r\n> APIVersion:\"v1beta1\", ResourceVersion:\"\", FieldPath:\"implicitly required\r\n> container net\"}): status: 'waiting', reason: 'created' Created with docker\r\n> id 93b26b849bfb454cc86cd6467a32906a79eb72a5705c3ae473ee1c7edc64b7ee\r\n> I0129 22:08:05.554694 4903 event.go:92]\r\n> Event(api.ObjectReference{Kind:\"BoundPod\", Namespace:\"default\",\r\n> Name:\"pause-pod-1fcbe922\", UID:\"4cadf377-a803-11e4-a2ec-42010af0de1f\",\r\n> APIVersion:\"v1beta1\", ResourceVersion:\"\", FieldPath:\"implicitly required\r\n> container net\"}): status: 'running', reason: 'started' Started with docker\r\n> id 93b26b849bfb454cc86cd6467a32906a79eb72a5705c3ae473ee1c7edc64b7ee\r\n> I0129 22:08:05.675279 4903 event.go:92]\r\n> Event(api.ObjectReference{Kind:\"BoundPod\", Namespace:\"default\",\r\n> Name:\"pause-pod-1fcbe922\", UID:\"4cadf377-a803-11e4-a2ec-42010af0de1f\",\r\n> APIVersion:\"v1beta1\", ResourceVersion:\"\",\r\n> FieldPath:\"spec.containers{pause-pod-1fcbe922}\"}): status: 'waiting',\r\n> reason: 'created' Created with docker id\r\n> 80def133b602fa2e4d2cf98a9e7903f9c83887fa281277d38f2850dbfcbaeed8\r\n> I0129 22:08:05.777623 4903 event.go:92]\r\n> Event(api.ObjectReference{Kind:\"BoundPod\", Namespace:\"default\",\r\n> Name:\"pause-pod-1fcbe922\", UID:\"4cadf377-a803-11e4-a2ec-42010af0de1f\",\r\n> APIVersion:\"v1beta1\", ResourceVersion:\"\",\r\n> FieldPath:\"spec.containers{pause-pod-1fcbe922}\"}): status: 'running',\r\n> reason: 'started' Started with docker id\r\n> 80def133b602fa2e4d2cf98a9e7903f9c83887fa281277d38f2850dbfcbaeed8\r\n> I0129 22:08:07.996475 4903 server.go:324] GET /healthz: (10.235us) 200\r\n> I0129 22:08:10.519742 4903 server.go:324] GET /healthz: (11.461us) 200\r\n> I0129 22:08:10.960311 4903 file.go:171] Got pod from file\r\n> \"/etc/kubernetes/manifests/cadvisor.manifest\": default.cadvisor-agent\r\n> (cadvisormanifes12uqn2ohido76855gdecd9roadm7l0)\r\n> I0129 22:08:18.003785 4903 server.go:324] GET /healthz: (11.971us) 200\r\n> I0129 22:08:20.011837 4903 server.go:324] GET /healthz: (10.642us) 200\r\n> I0129 22:08:20.012008 4903 server.go:324] GET /healthz: (3.816us) 200\r\n> I0129 22:08:20.015171 4903 logs.go:39] http: multiple response.WriteHeader\r\n> calls\r\n> I0129 22:08:20.015208 4903 server.go:324] GET\r\n> /api/v1beta1/podInfo?podID=&podNamespace=: (80.895us) 400\r\n> goroutine 42938 [running]:\r\n> github.com/GoogleCloudPlatform/kubernetes/pkg/httplog.(\r\n>\r\n>\r\n>\r\n> *respLogger).WriteHeader(0xc209810600, 0x190)\r\n> /go/src/github.com/GoogleCloudPlatform/kubernetes/_output/dockerized/go/src/github.com/GoogleCloudPlatform/kubernetes/pkg/httplog/log.go:182\r\n> <http://github.com/GoogleCloudPlatform/kubernetes/_output/dockerized/go/src/github.com/GoogleCloudPlatform/kubernetes/pkg/httplog/log.go:182>\r\n> +0x9c net/http.Error(0x7f3876a0f830, 0xc209810600, 0xaf2cf0, 0x1d, 0x190)\r\n> /usr/src/go/src/pkg/net/http/server.go:1244 +0x96\r\n> github.com/GoogleCloudPlatform/kubernetes/pkg/kubelet.(\r\n> <http://github.com/GoogleCloudPlatform/kubernetes/pkg/kubelet.(>*Server).handlePodInfo(0xc20812a320,\r\n> 0x7f3876a0f830, 0xc209810600, 0xc20a112dd0, 0x95d6901)\r\n> /go/src/\r\n> github.com/GoogleCloudPlatform/kubernetes/_output/dockerized/go/src/github.com/GoogleCloudPlatform/kubernetes/pkg/kubelet/server.go:212\r\n> +0x2a4\r\n> github.com/GoogleCloudPlatform/kubernetes/pkg/kubelet.(\r\n>\r\n> *Server).handlePodInfoVersioned(0xc20812a320, 0x7f3876a0f830,\r\n> 0xc209810600, 0xc20a112dd0)\r\n> /go/src/github.com/GoogleCloudPlatform/kubernetes/_output/dockerized/go/src/github.com/GoogleCloudPlatform/kubernetes/pkg/kubelet/server.go:197\r\n> <http://github.com/GoogleCloudPlatform/kubernetes/_output/dockerized/go/src/github.com/GoogleCloudPlatform/kubernetes/pkg/kubelet/server.go:197>\r\n> +0x4a github.com/GoogleCloudPlatform/kubernetes/pkg/kubelet\r\n> <http://github.com/GoogleCloudPlatform/kubernetes/pkg/kubelet>.*Server.(\r\n> github.com/GoogleCloudPlatform/kubernetes/pkg/kubelet.handlePodInfoVersioned)·fm(0x7f3876a0f830\r\n> <http://github.com/GoogleCloudPlatform/kubernetes/pkg/kubelet.handlePodInfoVersioned)%C2%B7fm(0x7f3876a0f830>,\r\n> 0xc209810600, 0xc20a112dd0)\r\n> /go/src/\r\n> github.com/GoogleCloudPlatform/kubernetes/_output/dockerized/go/src/github.com/GoogleCloudPlatform/kubernetes/pkg/kubelet/server.go:92\r\n> +0x44\r\n> net/http.HandlerFunc.ServeHTTP(0xc2081264e0, 0x7f3876a0f830, 0xc209810600,\r\n> 0xc20a112dd0)\r\n> /usr/src/go/src/pkg/net/http/server.go:1235 +0x40\r\n> net/http.(\r\n>\r\n> *ServeMux).ServeHTTP(0xc20811ab10, 0x7f3876a0f830, 0xc209810600,\r\n> 0xc20a112dd0) /usr/src/go/src/pkg/net/http/server.go:1511 +0x1a3\r\n> github.com/GoogleCloudPlatform/kubernetes/pkg/kubelet.(\r\n> <http://github.com/GoogleCloudPlatform/kubernetes/pkg/kubelet.(>*Server).ServeHTTP(0xc20812a300,\r\n> 0x7f3876a0f7f8, 0xc208131220, 0xc20a112dd0)\r\n> /go/src/\r\n> github.com/GoogleCloudPlatform/kubernetes/_output/dockerized/go/src/github.com/GoogleCloudPlatform/kubernetes/pkg/kubelet/server.go:323\r\n> +0x11d\r\n> net/http.serverHandler.ServeHTTP(0xc208112ba0, 0x7f3876a0f7f8,\r\n> 0xc208131220, 0xc20a112dd0)\r\n> /usr/src/go/src/pkg/net/http/server.go:1673 +0x19f\r\n> net/http.(*\r\n> I0129 22:08:20.019854 4903 server.go:324] GET\r\n> /api/v1beta1/podInfo?podID=pause-pod-1fcbe922&podNamespace=default:\r\n> (4.894854ms) 200\r\n> I0129 22:08:20.910257 4903 server.go:324] GET /healthz: (11.933us) 200\r\n> I0129 22:08:22.819342 4903 logs.go:39] etcd DEBUG: recv.success.\r\n> http://10.240.222.31:4001/v2/keys/registry/nodes/k8s-prod5-node-1.c.mohr-instance-manager.internal/boundpods?consistent=true&wait=true&waitIndex=12706\r\n> I0129 22:08:22.819569 4903 logs.go:39] etcd DEBUG: get\r\n> /registry/nodes/k8s-prod5-node-1.c.mohr-instance-manager.internal/boundpods\r\n> [http://10.240.222.31:4001]\r\n> I0129 22:08:22.819603 4903 logs.go:39] etcd DEBUG: Connecting to etcd:\r\n> attempt1forkeys/registry/nodes/k8s-prod5-node-1.c.mohr-instance-manager.internal/boundpods?consistent=true&wait=true&waitIndex=12714\r\n> I0129 22:08:22.819613 4903 logs.go:39] etcd DEBUG: send.request.to\r\n> http://10.240.222.31:4001/v2/keys/registry/nodes/k8s-prod5-node-1.c.mohr-instance-manager.internal/boundpods?consistent=true&wait=true&waitIndex=12714\r\n> | method GET\r\n> W0129 22:08:22.831964 4903 config.go:307] Pod 1 () from etcd failed\r\n> validation, ignoring: [name: required value '' namespace: required value\r\n> 'default']\r\n> I0129 22:08:22.834110 4903 logs.go:39] etcd DEBUG:\r\n> recv.response.fromhttp://\r\n> 10.240.222.31:4001/v2/keys/registry/nodes/k8s-prod5-node-1.c.mohr-instance-manager.internal/boundpods?consistent=true&wait=true&waitIndex=12714\r\n> I0129 22:08:22.836408 4903 kubelet.go:1044] Killing unwanted container\r\n> {podFullName:pause-pod-1fcbe922.default.etcd\r\n> uuid:4cadf377-a803-11e4-a2ec-42010af0de1f containerName:pause-pod-1fcbe922}\r\n>\r\n> —\r\n> Reply to this email directly or view it on GitHub\r\n> <https://github.com/GoogleCloudPlatform/kubernetes/issues/3952>.\r\n>"}}