{"action":"created","issue":{"url":"https://api.github.com/repos/vmware/vic/issues/2372","repository_url":"https://api.github.com/repos/vmware/vic","labels_url":"https://api.github.com/repos/vmware/vic/issues/2372/labels{/name}","comments_url":"https://api.github.com/repos/vmware/vic/issues/2372/comments","events_url":"https://api.github.com/repos/vmware/vic/issues/2372/events","html_url":"https://github.com/vmware/vic/issues/2372","id":177870152,"number":2372,"title":"Property collector error: context deadline exceeded on container start","user":{"login":"mhagen-vmware","id":19393273,"avatar_url":"https://avatars.githubusercontent.com/u/19393273?v=3","gravatar_id":"","url":"https://api.github.com/users/mhagen-vmware","html_url":"https://github.com/mhagen-vmware","followers_url":"https://api.github.com/users/mhagen-vmware/followers","following_url":"https://api.github.com/users/mhagen-vmware/following{/other_user}","gists_url":"https://api.github.com/users/mhagen-vmware/gists{/gist_id}","starred_url":"https://api.github.com/users/mhagen-vmware/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/mhagen-vmware/subscriptions","organizations_url":"https://api.github.com/users/mhagen-vmware/orgs","repos_url":"https://api.github.com/users/mhagen-vmware/repos","events_url":"https://api.github.com/users/mhagen-vmware/events{/privacy}","received_events_url":"https://api.github.com/users/mhagen-vmware/received_events","type":"User","site_admin":false},"labels":[{"url":"https://api.github.com/repos/vmware/vic/labels/kind/bug","name":"kind/bug","color":"f7c6c7"},{"url":"https://api.github.com/repos/vmware/vic/labels/kind/bug/p0","name":"kind/bug/p0","color":"d93f0b"},{"url":"https://api.github.com/repos/vmware/vic/labels/kind/note","name":"kind/note","color":"bfd4f2"}],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":{"url":"https://api.github.com/repos/vmware/vic/milestones/37","html_url":"https://github.com/vmware/vic/milestones/VIC%20GA%20Release","labels_url":"https://api.github.com/repos/vmware/vic/milestones/37/labels","id":1799354,"number":37,"title":"VIC GA Release","description":"Milestone for tracking all work towards the GA goal","creator":{"login":"mdubya66","id":15821624,"avatar_url":"https://avatars.githubusercontent.com/u/15821624?v=3","gravatar_id":"","url":"https://api.github.com/users/mdubya66","html_url":"https://github.com/mdubya66","followers_url":"https://api.github.com/users/mdubya66/followers","following_url":"https://api.github.com/users/mdubya66/following{/other_user}","gists_url":"https://api.github.com/users/mdubya66/gists{/gist_id}","starred_url":"https://api.github.com/users/mdubya66/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/mdubya66/subscriptions","organizations_url":"https://api.github.com/users/mdubya66/orgs","repos_url":"https://api.github.com/users/mdubya66/repos","events_url":"https://api.github.com/users/mdubya66/events{/privacy}","received_events_url":"https://api.github.com/users/mdubya66/received_events","type":"User","site_admin":false},"open_issues":157,"closed_issues":289,"state":"open","created_at":"2016-05-31T17:50:00Z","updated_at":"2016-09-20T21:30:42Z","due_on":"2016-11-07T00:00:00Z","closed_at":null},"comments":2,"created_at":"2016-09-19T19:09:47Z","updated_at":"2016-09-20T21:48:16Z","closed_at":null,"body":"Saw this issue on a recent functional run on a Nimbus VC cluster with 3 ESX hosts. Probably related to #1822 , but I am going to leave that closed for the time being.\r\n\r\nFrom portlayer.log:\r\n```\r\ntime=\"2016-09-19T15:14:58Z\" level=debug msg=\"Found 1 subscribers to vsphere.VmEvent: fervent_bhaskar-1379b2830c2c417e926a0fa924bb6c4f60d432443a4dae6c5085eae25a924648 on  10.160.120.204 in ha-datacenter is powered off\" \r\ntime=\"2016-09-19T15:14:58Z\" level=debug msg=\"Event manager calling back to exec\" \r\ntime=\"2016-09-19T15:14:58Z\" level=debug msg=\"Container(1379b2830c2c417e926a0fa924bb6c4f60d432443a4dae6c5085eae25a924648) state set to Stopped via event activity\" \r\ntime=\"2016-09-19T15:14:58Z\" level=debug msg=\"Container(1379b2830c2c417e926a0fa924bb6c4f60d432443a4dae6c5085eae25a924648) closing 0 log followers\" \r\ntime=\"2016-09-19T15:14:58Z\" level=debug msg=\"[BEGIN] [github.com/vmware/vic/lib/portlayer/exec.(*Container).Update] Container.Update\" \r\ntime=\"2016-09-19T15:17:44Z\" level=error msg=\"Property collector error: context deadline exceeded\" \r\n```\r\n\r\nFrom docker-personality.log:\r\n```\r\ntime=\"2016-09-19T15:14:42Z\" level=debug msg=\"[BEGIN] [github.com/vmware/vic/lib/apiservers/engine/backends.(*Container).ContainerStart] 1379b2830c2c417e926a0fa924bb6c4f60d432443a4dae6c5085eae25a924648\" \r\ntime=\"2016-09-19T15:17:44Z\" level=debug msg=\"[ END ] [github.com/vmware/vic/lib/apiservers/engine/backends.(*Container).ContainerStart] [3m2.034466734s] 1379b2830c2c417e926a0fa924bb6c4f60d432443a4dae6c5085eae25a924648\" \r\ntime=\"2016-09-19T15:17:44Z\" level=error msg=\"Handler for POST /v1.23/containers/1379b2830c2c417e926a0fa924bb6c4f60d432443a4dae6c5085eae25a924648/start returned error: Server error from portlayer: unable to wait for process launch status: context deadline exceeded\" \r\n```\r\n\r\n[Test-Cases.Group1-Docker-Commands.1-11-Docker-RM-VCH-0-7900-container-logs.zip](https://github.com/vmware/vic/files/480885/Test-Cases.Group1-Docker-Commands.1-11-Docker-RM-VCH-0-7900-container-logs.zip)\r\n"},"comment":{"url":"https://api.github.com/repos/vmware/vic/issues/comments/248445131","html_url":"https://github.com/vmware/vic/issues/2372#issuecomment-248445131","issue_url":"https://api.github.com/repos/vmware/vic/issues/2372","id":248445131,"user":{"login":"jzt","id":128130,"avatar_url":"https://avatars.githubusercontent.com/u/128130?v=3","gravatar_id":"","url":"https://api.github.com/users/jzt","html_url":"https://github.com/jzt","followers_url":"https://api.github.com/users/jzt/followers","following_url":"https://api.github.com/users/jzt/following{/other_user}","gists_url":"https://api.github.com/users/jzt/gists{/gist_id}","starred_url":"https://api.github.com/users/jzt/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/jzt/subscriptions","organizations_url":"https://api.github.com/users/jzt/orgs","repos_url":"https://api.github.com/users/jzt/repos","events_url":"https://api.github.com/users/jzt/events{/privacy}","received_events_url":"https://api.github.com/users/jzt/received_events","type":"User","site_admin":false},"created_at":"2016-09-20T21:48:16Z","updated_at":"2016-09-20T21:48:16Z","body":"I believe @dougm's PR (#2405) addresses this issue.\r\n\r\nWhile looking at the logs attached to this ticket, @hmahmood and I found that the guestinfo key for `started` was never set (see @dougm's problem description in #2327). Since it was a short-lived container (a busybox `/bin/ls`), the vm was already powered off by the time `WaitForKeyInExtraConfig` was called. This caused the 3-minute context timeout to be reached, producing the CDE we saw in this integration test. @dougm's PR fixes this by not allowing the property collector to sit and wait if the VM is powered off.\r\n"}}
{"actor":{"display_login":"jzt"}}