chef-provisioning-docker icon indicating copy to clipboard operation
chef-provisioning-docker copied to clipboard

NoMethodError: undefined method 'id' for nil:nilClass when using machine_image resource

Open vardaofthevalier opened this issue 9 years ago • 3 comments

I'm attempting to use the following recipe to create a docker image on a CentOS 7 Virtualbox VM (for testing purposes):

require 'chef/provisioning/docker_driver'
machine_image 'zookeeper-test' do
    recipe 'zookeeper'
    driver 'docker'
    machine_options :docker_options => {
        :base_image => {
            :name => 'ubuntu',
            :repository => 'ubuntu',
            :tag => '14.04'
        }
    }
end

And here is the relevant part of the output from "chef-client -l debug" when I run this recipe:

[2015-04-14T12:43:41-07:00] INFO: Processing machine_image[zookeeper-test] action create (tests::machine_image_test line 3)
[2015-04-14T12:43:41-07:00] DEBUG: providers for generic machine_image resource enabled on node include: []
[2015-04-14T12:43:41-07:00] DEBUG: providers that refused resource machine_image[zookeeper-test] were: []
[2015-04-14T12:43:41-07:00] DEBUG: providers that support resource machine_image[zookeeper-test] include: []
[2015-04-14T12:43:41-07:00] DEBUG: no providers supported the resource, falling back to enabled handlers
[2015-04-14T12:43:41-07:00] DEBUG: providers that survived replacement include: []
[2015-04-14T12:43:41-07:00] DEBUG: dynamic provider resolver FAILED to resolve a provider
[2015-04-14T12:43:41-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONInput#handle_request
[2015-04-14T12:43:41-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONOutput#handle_request
[2015-04-14T12:43:41-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::CookieManager#handle_request
[2015-04-14T12:43:41-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Decompressor#handle_request
[2015-04-14T12:43:41-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Authenticator#handle_request
[2015-04-14T12:43:41-07:00] DEBUG: Signing the request as kube-master
[2015-04-14T12:43:41-07:00] DEBUG: String to sign: 'Method:GET
Hashed Path:7Z7zFOSXUinpODHzpJ+EIsUyzbA=
X-Ops-Content-Hash:2jmj7l5rSw0yVb/vlWAYkK/YBwk=
X-Ops-Timestamp:2015-04-14T19:43:41Z
X-Ops-UserId:kube-master'
Header hash: {"X-Ops-Sign"=>"algorithm=sha1;version=1.0;", "X-Ops-Userid"=>"kube-master", "X-Ops-Timestamp"=>"2015-04-14T19:43:41Z", "X-Ops-Content-Hash"=>"2jmj7l5rSw0yVb/vlWAYkK/YBwk=", "X-Ops-Authorization-1"=>"VMjVnN3HqhuKP7SjUGQxCcRWzdNNdZamISuIIbkWSJri8X9w4fB06pcZDcB1", "X-Ops-Authorization-2"=>"hoVhpSsVEpHhmPAAI4cyMmBA2XqIJ+Yqk7ORe6T+QfuZ3+M9fkZwdFrgVT2q", "X-Ops-Authorization-3"=>"jXY0OEABe3ZGwnrJTVtP3nR2gzi8oSbP3bSB4MfDdGIlhXH18h7zFE0xmCI8", "X-Ops-Authorization-4"=>"jhjfeCN3k+gMDINV3L6ngoOuVKfQ0x+ljL46V/3DIDd4Uy254j87jCxC6vzZ", "X-Ops-Authorization-5"=>"QnhrjUUg7zM0m4lOjv8yKipcISezYcqFkTTzFKITeaysNoRHqu7B5qzJf6WP", "X-Ops-Authorization-6"=>"ADkZ4/fvJdVHJg0j/dMY3YCs4gP1OBUufG+WtrxDPw=="}
[2015-04-14T12:43:41-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::RemoteRequestID#handle_request
[2015-04-14T12:43:41-07:00] DEBUG: Initiating GET to https://chef-server-centos.com/organizations/tcga/data/machine_image/zookeeper-test
[2015-04-14T12:43:41-07:00] DEBUG: ---- HTTP Request Header Data: ----
[2015-04-14T12:43:41-07:00] DEBUG: Accept: application/json
[2015-04-14T12:43:41-07:00] DEBUG: Accept-Encoding: gzip;q=1.0,deflate;q=0.6,identity;q=0.3
[2015-04-14T12:43:41-07:00] DEBUG: X-OPS-SIGN: algorithm=sha1;version=1.0;
[2015-04-14T12:43:41-07:00] DEBUG: X-OPS-USERID: kube-master
[2015-04-14T12:43:41-07:00] DEBUG: X-OPS-TIMESTAMP: 2015-04-14T19:43:41Z
[2015-04-14T12:43:41-07:00] DEBUG: X-OPS-CONTENT-HASH: 2jmj7l5rSw0yVb/vlWAYkK/YBwk=
[2015-04-14T12:43:41-07:00] DEBUG: X-OPS-AUTHORIZATION-1: VMjVnN3HqhuKP7SjUGQxCcRWzdNNdZamISuIIbkWSJri8X9w4fB06pcZDcB1
[2015-04-14T12:43:41-07:00] DEBUG: X-OPS-AUTHORIZATION-2: hoVhpSsVEpHhmPAAI4cyMmBA2XqIJ+Yqk7ORe6T+QfuZ3+M9fkZwdFrgVT2q
[2015-04-14T12:43:41-07:00] DEBUG: X-OPS-AUTHORIZATION-3: jXY0OEABe3ZGwnrJTVtP3nR2gzi8oSbP3bSB4MfDdGIlhXH18h7zFE0xmCI8
[2015-04-14T12:43:41-07:00] DEBUG: X-OPS-AUTHORIZATION-4: jhjfeCN3k+gMDINV3L6ngoOuVKfQ0x+ljL46V/3DIDd4Uy254j87jCxC6vzZ
[2015-04-14T12:43:41-07:00] DEBUG: X-OPS-AUTHORIZATION-5: QnhrjUUg7zM0m4lOjv8yKipcISezYcqFkTTzFKITeaysNoRHqu7B5qzJf6WP
[2015-04-14T12:43:41-07:00] DEBUG: X-OPS-AUTHORIZATION-6: ADkZ4/fvJdVHJg0j/dMY3YCs4gP1OBUufG+WtrxDPw==
[2015-04-14T12:43:41-07:00] DEBUG: HOST: chef-server-centos.com:443
[2015-04-14T12:43:41-07:00] DEBUG: X-REMOTE-REQUEST-ID: dbe4a079-ac26-43f4-a244-90ca08b0c21e
[2015-04-14T12:43:41-07:00] DEBUG: ---- End HTTP Request Header Data ----
[2015-04-14T12:43:41-07:00] DEBUG: ---- HTTP Status and Header Data: ----
[2015-04-14T12:43:41-07:00] DEBUG: HTTP 1.1 404 Object Not Found
[2015-04-14T12:43:41-07:00] DEBUG: server: ngx_openresty/1.4.3.6
[2015-04-14T12:43:41-07:00] DEBUG: date: Tue, 14 Apr 2015 12:43:40 GMT
[2015-04-14T12:43:41-07:00] DEBUG: content-length: 81
[2015-04-14T12:43:41-07:00] DEBUG: connection: close
[2015-04-14T12:43:41-07:00] DEBUG: x-ops-api-info: flavor=cs;version=12.0.0;oc_erchef=1.5.0
[2015-04-14T12:43:41-07:00] DEBUG: ---- End HTTP Status/Header Data ----
[2015-04-14T12:43:41-07:00] DEBUG: ---- HTTP Response Body ----
[2015-04-14T12:43:41-07:00] DEBUG: {"error":["Cannot load data bag item zookeeper-test for data bag machine_image"]}
[2015-04-14T12:43:41-07:00] DEBUG: ---- End HTTP Response Body -----
[2015-04-14T12:43:41-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::RemoteRequestID#handle_response
[2015-04-14T12:43:41-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Authenticator#handle_response
[2015-04-14T12:43:41-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Decompressor#handle_response
[2015-04-14T12:43:41-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::CookieManager#handle_response
[2015-04-14T12:43:41-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONOutput#handle_response
[2015-04-14T12:43:41-07:00] DEBUG: Expected JSON response, but got content-type ''
[2015-04-14T12:43:41-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONInput#handle_response
[2015-04-14T12:43:41-07:00] INFO: HTTP Request Returned 404 Object Not Found: error
[2015-04-14T12:43:41-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONInput#handle_request
[2015-04-14T12:43:41-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONOutput#handle_request
[2015-04-14T12:43:41-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::CookieManager#handle_request
[2015-04-14T12:43:41-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Decompressor#handle_request
[2015-04-14T12:43:41-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Authenticator#handle_request
[2015-04-14T12:43:41-07:00] DEBUG: Signing the request as kube-master
[2015-04-14T12:43:41-07:00] DEBUG: String to sign: 'Method:GET
Hashed Path:AMDCmRLYENS9SExi5vSX0/wD12w=
X-Ops-Content-Hash:2jmj7l5rSw0yVb/vlWAYkK/YBwk=
X-Ops-Timestamp:2015-04-14T19:43:41Z
X-Ops-UserId:kube-master'
Header hash: {"X-Ops-Sign"=>"algorithm=sha1;version=1.0;", "X-Ops-Userid"=>"kube-master", "X-Ops-Timestamp"=>"2015-04-14T19:43:41Z", "X-Ops-Content-Hash"=>"2jmj7l5rSw0yVb/vlWAYkK/YBwk=", "X-Ops-Authorization-1"=>"Gv7TrJGhytYk+yhWo9jzccfSsVWB0jUJ7M1t5R6adgZDfHKJdja+Ve+W+VkZ", "X-Ops-Authorization-2"=>"Uxk0sZHNSyY8XVXW+B8ZQdXVCPzmO/R5YFgHsnVQCDs67WweeqpncQw4ZFc9", "X-Ops-Authorization-3"=>"mRsyPMrPXLHsKtXvVERdEzKlXZC4KMHf74AZsptSLE63608kIPVy7CfLnY6a", "X-Ops-Authorization-4"=>"zWAc2iWNaC5tyhdGxOjK6Nm9RvXg+a2SUmMEgBIediT3IuLABSCh1YNUXkXd", "X-Ops-Authorization-5"=>"qj0sjXCfYdJbwsW1dEC1CnaPNpy946nmaRWqQ5HnpMZpLmUrti/BwwguIYMs", "X-Ops-Authorization-6"=>"J9WBf7gFPcna7ih0+D8s8zIZmSWxfOm5tK5ngu6nEA=="}
[2015-04-14T12:43:41-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::RemoteRequestID#handle_request
[2015-04-14T12:43:41-07:00] DEBUG: Initiating GET to https://chef-server-centos.com/organizations/tcga/data/images/zookeeper-test
[2015-04-14T12:43:41-07:00] DEBUG: ---- HTTP Request Header Data: ----
[2015-04-14T12:43:41-07:00] DEBUG: Accept: application/json
[2015-04-14T12:43:41-07:00] DEBUG: Accept-Encoding: gzip;q=1.0,deflate;q=0.6,identity;q=0.3
[2015-04-14T12:43:41-07:00] DEBUG: X-OPS-SIGN: algorithm=sha1;version=1.0;
[2015-04-14T12:43:41-07:00] DEBUG: X-OPS-USERID: kube-master
[2015-04-14T12:43:41-07:00] DEBUG: X-OPS-TIMESTAMP: 2015-04-14T19:43:41Z
[2015-04-14T12:43:41-07:00] DEBUG: X-OPS-CONTENT-HASH: 2jmj7l5rSw0yVb/vlWAYkK/YBwk=
[2015-04-14T12:43:41-07:00] DEBUG: X-OPS-AUTHORIZATION-1: Gv7TrJGhytYk+yhWo9jzccfSsVWB0jUJ7M1t5R6adgZDfHKJdja+Ve+W+VkZ
[2015-04-14T12:43:41-07:00] DEBUG: X-OPS-AUTHORIZATION-2: Uxk0sZHNSyY8XVXW+B8ZQdXVCPzmO/R5YFgHsnVQCDs67WweeqpncQw4ZFc9
[2015-04-14T12:43:41-07:00] DEBUG: X-OPS-AUTHORIZATION-3: mRsyPMrPXLHsKtXvVERdEzKlXZC4KMHf74AZsptSLE63608kIPVy7CfLnY6a
[2015-04-14T12:43:41-07:00] DEBUG: X-OPS-AUTHORIZATION-4: zWAc2iWNaC5tyhdGxOjK6Nm9RvXg+a2SUmMEgBIediT3IuLABSCh1YNUXkXd
[2015-04-14T12:43:41-07:00] DEBUG: X-OPS-AUTHORIZATION-5: qj0sjXCfYdJbwsW1dEC1CnaPNpy946nmaRWqQ5HnpMZpLmUrti/BwwguIYMs
[2015-04-14T12:43:41-07:00] DEBUG: X-OPS-AUTHORIZATION-6: J9WBf7gFPcna7ih0+D8s8zIZmSWxfOm5tK5ngu6nEA==
[2015-04-14T12:43:41-07:00] DEBUG: HOST: chef-server-centos.com:443
[2015-04-14T12:43:41-07:00] DEBUG: X-REMOTE-REQUEST-ID: dbe4a079-ac26-43f4-a244-90ca08b0c21e
[2015-04-14T12:43:41-07:00] DEBUG: ---- End HTTP Request Header Data ----
[2015-04-14T12:43:42-07:00] DEBUG: ---- HTTP Status and Header Data: ----
[2015-04-14T12:43:42-07:00] DEBUG: HTTP 1.1 404 Object Not Found
[2015-04-14T12:43:42-07:00] DEBUG: server: ngx_openresty/1.4.3.6
[2015-04-14T12:43:42-07:00] DEBUG: date: Tue, 14 Apr 2015 12:43:40 GMT
[2015-04-14T12:43:42-07:00] DEBUG: content-length: 74
[2015-04-14T12:43:42-07:00] DEBUG: connection: close
[2015-04-14T12:43:42-07:00] DEBUG: x-ops-api-info: flavor=cs;version=12.0.0;oc_erchef=1.5.0
[2015-04-14T12:43:42-07:00] DEBUG: ---- End HTTP Status/Header Data ----
[2015-04-14T12:43:42-07:00] DEBUG: ---- HTTP Response Body ----
[2015-04-14T12:43:42-07:00] DEBUG: {"error":["Cannot load data bag item zookeeper-test for data bag images"]}
[2015-04-14T12:43:42-07:00] DEBUG: ---- End HTTP Response Body -----
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::RemoteRequestID#handle_response
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Authenticator#handle_response
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Decompressor#handle_response
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::CookieManager#handle_response
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONOutput#handle_response
[2015-04-14T12:43:42-07:00] DEBUG: Expected JSON response, but got content-type ''
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONInput#handle_response
[2015-04-14T12:43:42-07:00] INFO: HTTP Request Returned 404 Object Not Found: error
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONInput#handle_request
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONOutput#handle_request
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::CookieManager#handle_request
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Decompressor#handle_request
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Authenticator#handle_request
[2015-04-14T12:43:42-07:00] DEBUG: Signing the request as kube-master
[2015-04-14T12:43:42-07:00] DEBUG: String to sign: 'Method:GET
Hashed Path:EXE2LPExbDohXR8mehvp+dZnBfw=
X-Ops-Content-Hash:2jmj7l5rSw0yVb/vlWAYkK/YBwk=
X-Ops-Timestamp:2015-04-14T19:43:42Z
X-Ops-UserId:kube-master'
Header hash: {"X-Ops-Sign"=>"algorithm=sha1;version=1.0;", "X-Ops-Userid"=>"kube-master", "X-Ops-Timestamp"=>"2015-04-14T19:43:42Z", "X-Ops-Content-Hash"=>"2jmj7l5rSw0yVb/vlWAYkK/YBwk=", "X-Ops-Authorization-1"=>"lesf0+354i3049yCUcSNLBBIQj3nBDxHtSgQRW8M3Gb4dVE9BK6OPHLomgEL", "X-Ops-Authorization-2"=>"Hx97QRuPQ/muClI1wXlP1BKVJGAn2bhAZSbf4ZDqIPlkWn1s3agC2ePUB0rg", "X-Ops-Authorization-3"=>"k1+GO4Dow3mrfog/AW24sX/l/vDOZy8C/ROAjYg8EaLIf847/caAyO6wt3R1", "X-Ops-Authorization-4"=>"Vln/PLWxQ/EkZq/H9JpskAp7TI5Qrioz4kku2iLa4OhvAB95meMCQYY1yBM3", "X-Ops-Authorization-5"=>"eNo6Y2l7KYmJJW0qJYJ47wpK1q3LD40mTHGXoO+xzIk76WF0pzEYnlNSSHCl", "X-Ops-Authorization-6"=>"yuTEYx7A4miGPN87j5+IDTaTVdpkIASi61ee5/7QTA=="}
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::RemoteRequestID#handle_request
[2015-04-14T12:43:42-07:00] DEBUG: Initiating GET to https://chef-server-centos.com/organizations/tcga/nodes/zookeeper-test
[2015-04-14T12:43:42-07:00] DEBUG: ---- HTTP Request Header Data: ----
[2015-04-14T12:43:42-07:00] DEBUG: Accept: application/json
[2015-04-14T12:43:42-07:00] DEBUG: Accept-Encoding: gzip;q=1.0,deflate;q=0.6,identity;q=0.3
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-SIGN: algorithm=sha1;version=1.0;
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-USERID: kube-master
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-TIMESTAMP: 2015-04-14T19:43:42Z
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-CONTENT-HASH: 2jmj7l5rSw0yVb/vlWAYkK/YBwk=
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-AUTHORIZATION-1: lesf0+354i3049yCUcSNLBBIQj3nBDxHtSgQRW8M3Gb4dVE9BK6OPHLomgEL
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-AUTHORIZATION-2: Hx97QRuPQ/muClI1wXlP1BKVJGAn2bhAZSbf4ZDqIPlkWn1s3agC2ePUB0rg
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-AUTHORIZATION-3: k1+GO4Dow3mrfog/AW24sX/l/vDOZy8C/ROAjYg8EaLIf847/caAyO6wt3R1
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-AUTHORIZATION-4: Vln/PLWxQ/EkZq/H9JpskAp7TI5Qrioz4kku2iLa4OhvAB95meMCQYY1yBM3
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-AUTHORIZATION-5: eNo6Y2l7KYmJJW0qJYJ47wpK1q3LD40mTHGXoO+xzIk76WF0pzEYnlNSSHCl
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-AUTHORIZATION-6: yuTEYx7A4miGPN87j5+IDTaTVdpkIASi61ee5/7QTA==
[2015-04-14T12:43:42-07:00] DEBUG: HOST: chef-server-centos.com:443
[2015-04-14T12:43:42-07:00] DEBUG: X-REMOTE-REQUEST-ID: dbe4a079-ac26-43f4-a244-90ca08b0c21e
[2015-04-14T12:43:42-07:00] DEBUG: ---- End HTTP Request Header Data ----
[2015-04-14T12:43:42-07:00] DEBUG: ---- HTTP Status and Header Data: ----
[2015-04-14T12:43:42-07:00] DEBUG: HTTP 1.1 200 OK
[2015-04-14T12:43:42-07:00] DEBUG: server: ngx_openresty/1.4.3.6
[2015-04-14T12:43:42-07:00] DEBUG: date: Tue, 14 Apr 2015 12:43:40 GMT
[2015-04-14T12:43:42-07:00] DEBUG: content-type: application/json
[2015-04-14T12:43:42-07:00] DEBUG: transfer-encoding: chunked
[2015-04-14T12:43:42-07:00] DEBUG: connection: close
[2015-04-14T12:43:42-07:00] DEBUG: x-ops-api-info: flavor=cs;version=12.0.0;oc_erchef=1.5.0
[2015-04-14T12:43:42-07:00] DEBUG: content-encoding: gzip
[2015-04-14T12:43:42-07:00] DEBUG: ---- End HTTP Status/Header Data ----
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::RemoteRequestID#handle_response
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Authenticator#handle_response
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Decompressor#handle_response
[2015-04-14T12:43:42-07:00] DEBUG: decompressing gzip response
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::CookieManager#handle_response
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONOutput#handle_response
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONInput#handle_response
[2015-04-14T12:43:42-07:00] INFO: Processing chef_node[zookeeper-test] action create (basic_chef_client::block line 57)
[2015-04-14T12:43:42-07:00] DEBUG: providers for generic chef_node resource enabled on node include: []
[2015-04-14T12:43:42-07:00] DEBUG: providers that refused resource chef_node[zookeeper-test] were: []
[2015-04-14T12:43:42-07:00] DEBUG: providers that support resource chef_node[zookeeper-test] include: []
[2015-04-14T12:43:42-07:00] DEBUG: no providers supported the resource, falling back to enabled handlers
[2015-04-14T12:43:42-07:00] DEBUG: providers that survived replacement include: []
[2015-04-14T12:43:42-07:00] DEBUG: dynamic provider resolver FAILED to resolve a provider
[2015-04-14T12:43:42-07:00] DEBUG: Platform basic_chef_client not found, using all defaults. (Unsupported platform?)
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONInput#handle_request
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONOutput#handle_request
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::CookieManager#handle_request
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Decompressor#handle_request
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Authenticator#handle_request
[2015-04-14T12:43:42-07:00] DEBUG: Signing the request as kube-master
[2015-04-14T12:43:42-07:00] DEBUG: String to sign: 'Method:GET
Hashed Path:EXE2LPExbDohXR8mehvp+dZnBfw=
X-Ops-Content-Hash:2jmj7l5rSw0yVb/vlWAYkK/YBwk=
X-Ops-Timestamp:2015-04-14T19:43:42Z
X-Ops-UserId:kube-master'
Header hash: {"X-Ops-Sign"=>"algorithm=sha1;version=1.0;", "X-Ops-Userid"=>"kube-master", "X-Ops-Timestamp"=>"2015-04-14T19:43:42Z", "X-Ops-Content-Hash"=>"2jmj7l5rSw0yVb/vlWAYkK/YBwk=", "X-Ops-Authorization-1"=>"lesf0+354i3049yCUcSNLBBIQj3nBDxHtSgQRW8M3Gb4dVE9BK6OPHLomgEL", "X-Ops-Authorization-2"=>"Hx97QRuPQ/muClI1wXlP1BKVJGAn2bhAZSbf4ZDqIPlkWn1s3agC2ePUB0rg", "X-Ops-Authorization-3"=>"k1+GO4Dow3mrfog/AW24sX/l/vDOZy8C/ROAjYg8EaLIf847/caAyO6wt3R1", "X-Ops-Authorization-4"=>"Vln/PLWxQ/EkZq/H9JpskAp7TI5Qrioz4kku2iLa4OhvAB95meMCQYY1yBM3", "X-Ops-Authorization-5"=>"eNo6Y2l7KYmJJW0qJYJ47wpK1q3LD40mTHGXoO+xzIk76WF0pzEYnlNSSHCl", "X-Ops-Authorization-6"=>"yuTEYx7A4miGPN87j5+IDTaTVdpkIASi61ee5/7QTA=="}
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::RemoteRequestID#handle_request
[2015-04-14T12:43:42-07:00] DEBUG: Initiating GET to https://chef-server-centos.com/organizations/tcga/nodes/zookeeper-test
[2015-04-14T12:43:42-07:00] DEBUG: ---- HTTP Request Header Data: ----
[2015-04-14T12:43:42-07:00] DEBUG: Accept: application/json
[2015-04-14T12:43:42-07:00] DEBUG: Accept-Encoding: gzip;q=1.0,deflate;q=0.6,identity;q=0.3
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-SIGN: algorithm=sha1;version=1.0;
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-USERID: kube-master
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-TIMESTAMP: 2015-04-14T19:43:42Z
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-CONTENT-HASH: 2jmj7l5rSw0yVb/vlWAYkK/YBwk=
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-AUTHORIZATION-1: lesf0+354i3049yCUcSNLBBIQj3nBDxHtSgQRW8M3Gb4dVE9BK6OPHLomgEL
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-AUTHORIZATION-2: Hx97QRuPQ/muClI1wXlP1BKVJGAn2bhAZSbf4ZDqIPlkWn1s3agC2ePUB0rg
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-AUTHORIZATION-3: k1+GO4Dow3mrfog/AW24sX/l/vDOZy8C/ROAjYg8EaLIf847/caAyO6wt3R1
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-AUTHORIZATION-4: Vln/PLWxQ/EkZq/H9JpskAp7TI5Qrioz4kku2iLa4OhvAB95meMCQYY1yBM3
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-AUTHORIZATION-5: eNo6Y2l7KYmJJW0qJYJ47wpK1q3LD40mTHGXoO+xzIk76WF0pzEYnlNSSHCl
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-AUTHORIZATION-6: yuTEYx7A4miGPN87j5+IDTaTVdpkIASi61ee5/7QTA==
[2015-04-14T12:43:42-07:00] DEBUG: HOST: chef-server-centos.com:443
[2015-04-14T12:43:42-07:00] DEBUG: X-REMOTE-REQUEST-ID: dbe4a079-ac26-43f4-a244-90ca08b0c21e
[2015-04-14T12:43:42-07:00] DEBUG: ---- End HTTP Request Header Data ----
[2015-04-14T12:43:42-07:00] DEBUG: ---- HTTP Status and Header Data: ----
[2015-04-14T12:43:42-07:00] DEBUG: HTTP 1.1 200 OK
[2015-04-14T12:43:42-07:00] DEBUG: server: ngx_openresty/1.4.3.6
[2015-04-14T12:43:42-07:00] DEBUG: date: Tue, 14 Apr 2015 12:43:40 GMT
[2015-04-14T12:43:42-07:00] DEBUG: content-type: application/json
[2015-04-14T12:43:42-07:00] DEBUG: transfer-encoding: chunked
[2015-04-14T12:43:42-07:00] DEBUG: connection: close
[2015-04-14T12:43:42-07:00] DEBUG: x-ops-api-info: flavor=cs;version=12.0.0;oc_erchef=1.5.0
[2015-04-14T12:43:42-07:00] DEBUG: content-encoding: gzip
[2015-04-14T12:43:42-07:00] DEBUG: ---- End HTTP Status/Header Data ----
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::RemoteRequestID#handle_response
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Authenticator#handle_response
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Decompressor#handle_response
[2015-04-14T12:43:42-07:00] DEBUG: decompressing gzip response
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::CookieManager#handle_response
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONOutput#handle_response
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONInput#handle_response
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONInput#handle_request
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONOutput#handle_request
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::CookieManager#handle_request
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Decompressor#handle_request
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Authenticator#handle_request
[2015-04-14T12:43:42-07:00] DEBUG: Signing the request as kube-master
[2015-04-14T12:43:42-07:00] DEBUG: String to sign: 'Method:PUT
Hashed Path:EXE2LPExbDohXR8mehvp+dZnBfw=
X-Ops-Content-Hash:73ker5e4SW7j/QWKhueUImjIA5M=
X-Ops-Timestamp:2015-04-14T19:43:42Z
X-Ops-UserId:kube-master'
Header hash: {"X-Ops-Sign"=>"algorithm=sha1;version=1.0;", "X-Ops-Userid"=>"kube-master", "X-Ops-Timestamp"=>"2015-04-14T19:43:42Z", "X-Ops-Content-Hash"=>"73ker5e4SW7j/QWKhueUImjIA5M=", "X-Ops-Authorization-1"=>"TQ30Gh05GFfQ5fCnoKcXnA3bYUanlhnLqfR1s87L5+yiOF+THTKYZ/HEVSz2", "X-Ops-Authorization-2"=>"HInCsGlAmuQ8NUSb6syJk4bB8VrnyQDewB2ZWqj4jUdTSFz+OM1f14IsokmF", "X-Ops-Authorization-3"=>"vvkptFSJb29xpaJTHEZDlmAmOZmKK+IReBFxfx+I5YvjKrrT5KUPtNfSpcuN", "X-Ops-Authorization-4"=>"FIzslulwoPCXmjHcjZID/1em90NkuLVpZXKk8a/pT3st5I3STHl/IF+uQoLn", "X-Ops-Authorization-5"=>"1FpL8wrkpaj0tqC45RHQY/InJ89Niix3Qw0tVg52BAZViEzfWKLph0a5xsdq", "X-Ops-Authorization-6"=>"7Gqz3RuXJR34dYV7KFmo4jHpglAPVPZ94MPksqqAow=="}
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::RemoteRequestID#handle_request
[2015-04-14T12:43:42-07:00] DEBUG: Initiating PUT to https://chef-server-centos.com/organizations/tcga/nodes/zookeeper-test
[2015-04-14T12:43:42-07:00] DEBUG: ---- HTTP Request Header Data: ----
[2015-04-14T12:43:42-07:00] DEBUG: Content-Type: application/json
[2015-04-14T12:43:42-07:00] DEBUG: Accept: application/json
[2015-04-14T12:43:42-07:00] DEBUG: Accept-Encoding: gzip;q=1.0,deflate;q=0.6,identity;q=0.3
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-SIGN: algorithm=sha1;version=1.0;
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-USERID: kube-master
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-TIMESTAMP: 2015-04-14T19:43:42Z
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-CONTENT-HASH: 73ker5e4SW7j/QWKhueUImjIA5M=
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-AUTHORIZATION-1: TQ30Gh05GFfQ5fCnoKcXnA3bYUanlhnLqfR1s87L5+yiOF+THTKYZ/HEVSz2
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-AUTHORIZATION-2: HInCsGlAmuQ8NUSb6syJk4bB8VrnyQDewB2ZWqj4jUdTSFz+OM1f14IsokmF
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-AUTHORIZATION-3: vvkptFSJb29xpaJTHEZDlmAmOZmKK+IReBFxfx+I5YvjKrrT5KUPtNfSpcuN
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-AUTHORIZATION-4: FIzslulwoPCXmjHcjZID/1em90NkuLVpZXKk8a/pT3st5I3STHl/IF+uQoLn
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-AUTHORIZATION-5: 1FpL8wrkpaj0tqC45RHQY/InJ89Niix3Qw0tVg52BAZViEzfWKLph0a5xsdq
[2015-04-14T12:43:42-07:00] DEBUG: X-OPS-AUTHORIZATION-6: 7Gqz3RuXJR34dYV7KFmo4jHpglAPVPZ94MPksqqAow==
[2015-04-14T12:43:42-07:00] DEBUG: HOST: chef-server-centos.com:443
[2015-04-14T12:43:42-07:00] DEBUG: X-REMOTE-REQUEST-ID: dbe4a079-ac26-43f4-a244-90ca08b0c21e
[2015-04-14T12:43:42-07:00] DEBUG: Content-Length: 471
[2015-04-14T12:43:42-07:00] DEBUG: ---- End HTTP Request Header Data ----
[2015-04-14T12:43:42-07:00] DEBUG: ---- HTTP Status and Header Data: ----
[2015-04-14T12:43:42-07:00] DEBUG: HTTP 1.1 200 OK
[2015-04-14T12:43:42-07:00] DEBUG: server: ngx_openresty/1.4.3.6
[2015-04-14T12:43:42-07:00] DEBUG: date: Tue, 14 Apr 2015 12:43:40 GMT
[2015-04-14T12:43:42-07:00] DEBUG: content-type: application/json
[2015-04-14T12:43:42-07:00] DEBUG: transfer-encoding: chunked
[2015-04-14T12:43:42-07:00] DEBUG: connection: close
[2015-04-14T12:43:42-07:00] DEBUG: x-ops-api-info: flavor=cs;version=12.0.0;oc_erchef=1.5.0
[2015-04-14T12:43:42-07:00] DEBUG: content-encoding: gzip
[2015-04-14T12:43:42-07:00] DEBUG: ---- End HTTP Status/Header Data ----
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::RemoteRequestID#handle_response
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Authenticator#handle_response
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Decompressor#handle_response
[2015-04-14T12:43:42-07:00] DEBUG: decompressing gzip response
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::CookieManager#handle_response
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONOutput#handle_response
[2015-04-14T12:43:42-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONInput#handle_response
[2015-04-14T12:43:42-07:00] DEBUG: No matching images for chef:zookeeper-test, creating!
[2015-04-14T12:44:05-07:00] DEBUG: Allocated Docker::Image { :id => d0955f21bf24, :info => {"id"=>"d0955f21bf24", :headers=>{}}, :connection => Docker::Connection { :url => unix:///, :options => {:socket=>"/var/run/docker.sock"} } }
[2015-04-14T12:44:05-07:00] DEBUG: Tagged image Docker::Image { :id => d0955f21bf24, :info => {"id"=>"d0955f21bf24", :headers=>{}, "RepoTags"=>["chef:zookeeper-test"]}, :connection => Docker::Connection { :url => unix:///, :options => {:socket=>"/var/run/docker.sock"} } }
[2015-04-14T12:44:05-07:00] DEBUG: Start machine for container zookeeper-test using base image chef:zookeeper-test with options {:base_image=>{:name=>"ubuntu", :repository=>"ubuntu", :tag=>"14.04"}}
[0m
================================================================================[0m
[31mError executing action `create` on resource 'machine_image[zookeeper-test]'[0m
================================================================================[0m

[0mNoMethodError[0m
-------------[0m
undefined method `id' for nil:NilClass[0m

[0mResource Declaration:[0m
---------------------[0m
# In /var/chef/cache/cookbooks/tests/recipes/machine_image_test.rb
[0m
[0m  3: machine_image 'zookeeper-test' do
[0m  4:    recipe 'zookeeper'
[0m  5:    driver 'docker'
[0m  6:    machine_options :docker_options => {
[0m  7:        :base_image => {
[0m  8:            :name => 'ubuntu',
[0m  9:            :repository => 'ubuntu',
[0m 10:            :tag => '14.04'
[0m 11:        }
[0m 12:    }
[0m 13: end
[0m
[0mCompiled Resource:[0m
------------------[0m
# Declared in /var/chef/cache/cookbooks/tests/recipes/machine_image_test.rb:3:in `from_file'
[0m
[0mmachine_image("zookeeper-test") do
[0m  action :create
[0m  retries 0
[0m  retry_delay 2
[0m  default_guard_interpreter :default
[0m  chef_server {:chef_server_url=>"https://chef-server-centos.com/organizations/tcga", :options=>{:client_name=>"kube-master", :signing_key_filename=>"/etc/chef/client.pem"}}
[0m  driver "docker"
[0m  machine_options {:docker_options=>{:base_image=>{:name=>"ubuntu", :repository=>"ubuntu", :tag=>"14.04"}}}
[0m  declared_type :machine_image
[0m  cookbook_name "tests"
[0m  recipe_name "machine_image_test"
[0m  run_list_modifiers [#<Chef::RunList::RunListItem:0x00000003521ef0 @version=nil, @type=:recipe, @name="zookeeper">]
[0mend
[0m
[0m[2015-04-14T12:44:06-07:00] INFO: Running queued delayed notifications before re-raising exception
[2015-04-14T12:44:06-07:00] DEBUG: Re-raising exception: NoMethodError - machine_image[zookeeper-test] (tests::machine_image_test line 3) had an error: NoMethodError: undefined method `id' for nil:NilClass
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-docker-0.5.2/lib/chef/provisioning/docker_driver/driver.rb:200:in `rescue in start_machine'
  /opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-docker-0.5.2/lib/chef/provisioning/docker_driver/driver.rb:194:in `start_machine'
  /opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-docker-0.5.2/lib/chef/provisioning/docker_driver/driver.rb:88:in `ready_machine'
  /opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-0.20.1/lib/chef/provider/machine.rb:38:in `block in <class:Machine>'
  /opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:60:in `instance_eval'
  /opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:60:in `recipe_eval_with_update_check'
  /opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:45:in `block in action'
  /opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-0.20.1/lib/chef/provider/machine.rb:55:in `block in <class:Machine>'
  /opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:60:in `instance_eval'
  /opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:60:in `recipe_eval_with_update_check'
  /opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:45:in `block in action'
  /opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-0.20.1/lib/chef/provider/machine_image.rb:60:in `create_image'
  /opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-0.20.1/lib/chef/provider/machine_image.rb:35:in `block in <class:MachineImage>'
  /opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:138:in `instance_eval'
  /opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:138:in `block in action'
  /opt/chef/embedded/apps/chef/lib/chef/provider.rb:149:in `run_action'
  /opt/chef/embedded/apps/chef/lib/chef/resource.rb:561:in `run_action'
  /opt/chef/embedded/apps/chef/lib/chef/runner.rb:49:in `run_action'
  /opt/chef/embedded/apps/chef/lib/chef/runner.rb:81:in `block (2 levels) in converge'
  /opt/chef/embedded/apps/chef/lib/chef/runner.rb:81:in `each'
  /opt/chef/embedded/apps/chef/lib/chef/runner.rb:81:in `block in converge'
  /opt/chef/embedded/apps/chef/lib/chef/resource_collection/resource_list.rb:83:in `block in execute_each_resource'
  /opt/chef/embedded/apps/chef/lib/chef/resource_collection/stepable_iterator.rb:116:in `call'
  /opt/chef/embedded/apps/chef/lib/chef/resource_collection/stepable_iterator.rb:116:in `call_iterator_block'
  /opt/chef/embedded/apps/chef/lib/chef/resource_collection/stepable_iterator.rb:85:in `step'
  /opt/chef/embedded/apps/chef/lib/chef/resource_collection/stepable_iterator.rb:104:in `iterate'
  /opt/chef/embedded/apps/chef/lib/chef/resource_collection/stepable_iterator.rb:55:in `each_with_index'
  /opt/chef/embedded/apps/chef/lib/chef/resource_collection/resource_list.rb:81:in `execute_each_resource'
  /opt/chef/embedded/apps/chef/lib/chef/runner.rb:80:in `converge'
  /opt/chef/embedded/apps/chef/lib/chef/client.rb:331:in `block in converge'
  /opt/chef/embedded/apps/chef/lib/chef/client.rb:326:in `catch'
  /opt/chef/embedded/apps/chef/lib/chef/client.rb:326:in `converge'
  /opt/chef/embedded/apps/chef/lib/chef/client.rb:345:in `converge_and_save'
  /opt/chef/embedded/apps/chef/lib/chef/client.rb:449:in `run'
  /opt/chef/embedded/apps/chef/lib/chef/application.rb:271:in `block in fork_chef_client'
  /opt/chef/embedded/apps/chef/lib/chef/application.rb:259:in `fork'
  /opt/chef/embedded/apps/chef/lib/chef/application.rb:259:in `fork_chef_client'
  /opt/chef/embedded/apps/chef/lib/chef/application.rb:225:in `block in run_chef_client'
  /opt/chef/embedded/apps/chef/lib/chef/local_mode.rb:38:in `with_server_connectivity'
  /opt/chef/embedded/apps/chef/lib/chef/application.rb:213:in `run_chef_client'
  /opt/chef/embedded/apps/chef/lib/chef/application/client.rb:392:in `block in interval_run_chef_client'
  /opt/chef/embedded/apps/chef/lib/chef/application/client.rb:382:in `loop'
  /opt/chef/embedded/apps/chef/lib/chef/application/client.rb:382:in `interval_run_chef_client'
  /opt/chef/embedded/apps/chef/lib/chef/application/client.rb:372:in `run_application'
  /opt/chef/embedded/apps/chef/lib/chef/application.rb:60:in `run'
  /opt/chef/embedded/apps/chef/bin/chef-client:26:in `<top (required)>'
  /bin/chef-client:51:in `load'
  /bin/chef-client:51:in `<main>'
[2015-04-14T12:44:06-07:00] ERROR: Running exception handlers
[2015-04-14T12:44:06-07:00] ERROR: Exception handlers complete
[2015-04-14T12:44:06-07:00] FATAL: Stacktrace dumped to /var/chef/cache/chef-stacktrace.out
[2015-04-14T12:44:06-07:00] DEBUG: NoMethodError: machine_image[zookeeper-test] (tests::machine_image_test line 3) had an error: NoMethodError: undefined method `id' for nil:NilClass
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-docker-0.5.2/lib/chef/provisioning/docker_driver/driver.rb:200:in `rescue in start_machine'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-docker-0.5.2/lib/chef/provisioning/docker_driver/driver.rb:194:in `start_machine'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-docker-0.5.2/lib/chef/provisioning/docker_driver/driver.rb:88:in `ready_machine'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-0.20.1/lib/chef/provider/machine.rb:38:in `block in <class:Machine>'
/opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:60:in `instance_eval'
/opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:60:in `recipe_eval_with_update_check'
/opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:45:in `block in action'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-0.20.1/lib/chef/provider/machine.rb:55:in `block in <class:Machine>'
/opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:60:in `instance_eval'
/opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:60:in `recipe_eval_with_update_check'
/opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:45:in `block in action'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-0.20.1/lib/chef/provider/machine_image.rb:60:in `create_image'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-0.20.1/lib/chef/provider/machine_image.rb:35:in `block in <class:MachineImage>'
/opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:138:in `instance_eval'
/opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:138:in `block in action'
/opt/chef/embedded/apps/chef/lib/chef/provider.rb:149:in `run_action'
/opt/chef/embedded/apps/chef/lib/chef/resource.rb:561:in `run_action'
/opt/chef/embedded/apps/chef/lib/chef/runner.rb:49:in `run_action'
/opt/chef/embedded/apps/chef/lib/chef/runner.rb:81:in `block (2 levels) in converge'
/opt/chef/embedded/apps/chef/lib/chef/runner.rb:81:in `each'
/opt/chef/embedded/apps/chef/lib/chef/runner.rb:81:in `block in converge'
/opt/chef/embedded/apps/chef/lib/chef/resource_collection/resource_list.rb:83:in `block in execute_each_resource'
/opt/chef/embedded/apps/chef/lib/chef/resource_collection/stepable_iterator.rb:116:in `call'
/opt/chef/embedded/apps/chef/lib/chef/resource_collection/stepable_iterator.rb:116:in `call_iterator_block'
/opt/chef/embedded/apps/chef/lib/chef/resource_collection/stepable_iterator.rb:85:in `step'
/opt/chef/embedded/apps/chef/lib/chef/resource_collection/stepable_iterator.rb:104:in `iterate'
/opt/chef/embedded/apps/chef/lib/chef/resource_collection/stepable_iterator.rb:55:in `each_with_index'
/opt/chef/embedded/apps/chef/lib/chef/resource_collection/resource_list.rb:81:in `execute_each_resource'
/opt/chef/embedded/apps/chef/lib/chef/runner.rb:80:in `converge'
/opt/chef/embedded/apps/chef/lib/chef/client.rb:331:in `block in converge'
/opt/chef/embedded/apps/chef/lib/chef/client.rb:326:in `catch'
/opt/chef/embedded/apps/chef/lib/chef/client.rb:326:in `converge'
/opt/chef/embedded/apps/chef/lib/chef/client.rb:345:in `converge_and_save'
/opt/chef/embedded/apps/chef/lib/chef/client.rb:449:in `run'
/opt/chef/embedded/apps/chef/lib/chef/application.rb:271:in `block in fork_chef_client'
/opt/chef/embedded/apps/chef/lib/chef/application.rb:259:in `fork'
/opt/chef/embedded/apps/chef/lib/chef/application.rb:259:in `fork_chef_client'
/opt/chef/embedded/apps/chef/lib/chef/application.rb:225:in `block in run_chef_client'
/opt/chef/embedded/apps/chef/lib/chef/local_mode.rb:38:in `with_server_connectivity'
/opt/chef/embedded/apps/chef/lib/chef/application.rb:213:in `run_chef_client'
/opt/chef/embedded/apps/chef/lib/chef/application/client.rb:392:in `block in interval_run_chef_client'
/opt/chef/embedded/apps/chef/lib/chef/application/client.rb:382:in `loop'
/opt/chef/embedded/apps/chef/lib/chef/application/client.rb:382:in `interval_run_chef_client'
/opt/chef/embedded/apps/chef/lib/chef/application/client.rb:372:in `run_application'
/opt/chef/embedded/apps/chef/lib/chef/application.rb:60:in `run'
/opt/chef/embedded/apps/chef/bin/chef-client:26:in `<top (required)>'
/bin/chef-client:51:in `load'
/bin/chef-client:51:in `<main>'
[2015-04-14T12:44:06-07:00] DEBUG: Server doesn't support resource history, skipping resource report.
[2015-04-14T12:44:06-07:00] DEBUG: Audit Reports are disabled. Skipping sending reports.
[2015-04-14T12:44:06-07:00] ERROR: machine_image[zookeeper-test] (tests::machine_image_test line 3) had an error: NoMethodError: undefined method `id' for nil:NilClass
[2015-04-14T12:44:06-07:00] FATAL: Chef::Exceptions::ChildConvergeError: Chef run process exited unsuccessfully (exit code 1)

After the recipe fails, I can see in the output of "docker images" that the image was created and tagged as chef:zookeeper-test, but when I run the container the chef-client executable is nowhere to be found.

I spent some time yesterday inserting debug statements into the code for the chef-provisioning and chef-provisioning-docker gems to see if I could figure out what might be causing this, and I noticed that the docker driver's allocate_image method (on line 65 of the machine_image provider in the chef-provisioning gem) doesn't appear to actually get called, which is what I would expect to happen based on what I've read of the code so far. If any of this is in error, I would be happy to learn if there's something I've missed here and any suggestions would be much appreciated.

vardaofthevalier avatar Apr 14 '15 20:04 vardaofthevalier

According to your logs

[2015-04-14T12:44:05-07:00] DEBUG: Allocated Docker::Image { :id => d0955f21bf24, :info => {"id"=>"d0955f21bf24", :headers=>{}}, :connection => Docker::Connection { :url => unix:///, :options => {:socket=>"/var/run/docker.sock"} } })

allocate_image was called. But it happened here, due current version of chef-provisioning-docker doesn't support latest changes from chef-provisioning. The only difference from my run I can spot is that you have remote chef server:

[0m  chef_server {:chef_server_url=>"https://chef-server-centos.com/organizations/tcga", :options=>{:client_name=>"kube-master", :signing_key_filename=>"/etc/chef/client.pem"}}
[0m  driver "docker"

Can you try to run it with chef-zero or chef-client -z? It might be permissions issue, chef-provisioning needs write access to data_bags.

marc- avatar Apr 15 '15 18:04 marc-

Here is the relevant part of the output of "chef-client -z -l debug ...":

[2015-04-22T09:52:15-07:00] INFO: Processing machine_image[zookeeper-test] action create (tests::machine_image_test line 3)
[2015-04-22T09:52:15-07:00] DEBUG: providers for generic machine_image resource enabled on node include: []
[2015-04-22T09:52:15-07:00] DEBUG: providers that refused resource machine_image[zookeeper-test] were: []
[2015-04-22T09:52:15-07:00] DEBUG: providers that support resource machine_image[zookeeper-test] include: []
[2015-04-22T09:52:15-07:00] DEBUG: no providers supported the resource, falling back to enabled handlers
[2015-04-22T09:52:15-07:00] DEBUG: providers that survived replacement include: []
[2015-04-22T09:52:15-07:00] DEBUG: dynamic provider resolver FAILED to resolve a provider
[2015-04-22T09:52:15-07:00] DEBUG: Platform ubuntu version 14.04 found
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONInput#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONOutput#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::CookieManager#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Decompressor#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Authenticator#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Signing the request as admin
[2015-04-22T09:52:15-07:00] DEBUG: String to sign: 'Method:GET
Hashed Path:Th2lbOz6dkSTVH6HuDbS2/Tw4DU=
X-Ops-Content-Hash:2jmj7l5rSw0yVb/vlWAYkK/YBwk=
X-Ops-Timestamp:2015-04-22T16:52:15Z
X-Ops-UserId:admin'
Header hash: {"X-Ops-Sign"=>"algorithm=sha1;version=1.0;", "X-Ops-Userid"=>"admin", "X-Ops-Timestamp"=>"2015-04-22T16:52:15Z", "X-Ops-Content-Hash"=>"2jmj7l5rSw0yVb/vlWAYkK/YBwk=", "X-Ops-Authorization-1"=>"S1eYM8f1JBkcmyC90261NvJV21nBII80uSWxKaFrjWjHP8xrG3T2DS1Acz/H", "X-Ops-Authorization-2"=>"hg6oN77b60WLuHVUnTLygC6ZFQlxW/bDe1aOJwhYGUzfjJ0eNZZ0M0rlEHBk", "X-Ops-Authorization-3"=>"/IJQKub9tMbt3To5cOwuXyZY13++Xlyeugr53XzkwfZQHfwegfFpk6vcERt2", "X-Ops-Authorization-4"=>"trkbjwkUdYTLN7X54/SDQMAHbF1kohHeSY7kdVg4c3IZlq0J9rXU5/ZnFiTQ", "X-Ops-Authorization-5"=>"7Z34HKgqQKn+JeGp8YLGe5UOfXrbSsr1/V6nSzG/NKfP/Lggc0JaOB+SQIKj", "X-Ops-Authorization-6"=>"vZbEUX0Ch8ntCpCTXhkKF1neCa98HQsKk5vy9YtMaw=="}
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::RemoteRequestID#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Initiating GET to http://localhost:8889/data/machine_image/zookeeper-test
[2015-04-22T09:52:15-07:00] DEBUG: ---- HTTP Request Header Data: ----
[2015-04-22T09:52:15-07:00] DEBUG: Accept: application/json
[2015-04-22T09:52:15-07:00] DEBUG: Accept-Encoding: gzip;q=1.0,deflate;q=0.6,identity;q=0.3
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-SIGN: algorithm=sha1;version=1.0;
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-USERID: admin
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-TIMESTAMP: 2015-04-22T16:52:15Z
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-CONTENT-HASH: 2jmj7l5rSw0yVb/vlWAYkK/YBwk=
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-1: S1eYM8f1JBkcmyC90261NvJV21nBII80uSWxKaFrjWjHP8xrG3T2DS1Acz/H
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-2: hg6oN77b60WLuHVUnTLygC6ZFQlxW/bDe1aOJwhYGUzfjJ0eNZZ0M0rlEHBk
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-3: /IJQKub9tMbt3To5cOwuXyZY13++Xlyeugr53XzkwfZQHfwegfFpk6vcERt2
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-4: trkbjwkUdYTLN7X54/SDQMAHbF1kohHeSY7kdVg4c3IZlq0J9rXU5/ZnFiTQ
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-5: 7Z34HKgqQKn+JeGp8YLGe5UOfXrbSsr1/V6nSzG/NKfP/Lggc0JaOB+SQIKj
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-6: vZbEUX0Ch8ntCpCTXhkKF1neCa98HQsKk5vy9YtMaw==
[2015-04-22T09:52:15-07:00] DEBUG: HOST: localhost:8889
[2015-04-22T09:52:15-07:00] DEBUG: X-REMOTE-REQUEST-ID: 44180b3f-c436-44c5-90cd-dc0145e2e183
[2015-04-22T09:52:15-07:00] DEBUG: ---- End HTTP Request Header Data ----
[2015-04-22T09:52:15-07:00] DEBUG: #<ChefZero::RestRequest:0x000000038bd690 @env={"GATEWAY_INTERFACE"=>"CGI/1.1", "PATH_INFO"=>"/data/machine_image/zookeeper-test", "QUERY_STRING"=>"", "REMOTE_ADDR"=>"::1", "REMOTE_HOST"=>"localhost", "REQUEST_METHOD"=>"GET", "REQUEST_URI"=>"http://localhost:8889/data/machine_image/zookeeper-test", "SCRIPT_NAME"=>"", "SERVER_NAME"=>"localhost", "SERVER_PORT"=>"8889", "SERVER_PROTOCOL"=>"HTTP/1.1", "SERVER_SOFTWARE"=>"WEBrick/1.3.1 (Ruby/2.1.4/2014-10-27) OpenSSL/1.0.1k", "HTTP_ACCEPT"=>"application/json", "HTTP_ACCEPT_ENCODING"=>"gzip;q=1.0,deflate;q=0.6,identity;q=0.3", "HTTP_X_OPS_SIGN"=>"algorithm=sha1;version=1.0;", "HTTP_X_OPS_USERID"=>"admin", "HTTP_X_OPS_TIMESTAMP"=>"2015-04-22T16:52:15Z", "HTTP_X_OPS_CONTENT_HASH"=>"2jmj7l5rSw0yVb/vlWAYkK/YBwk=", "HTTP_X_OPS_AUTHORIZATION_1"=>"S1eYM8f1JBkcmyC90261NvJV21nBII80uSWxKaFrjWjHP8xrG3T2DS1Acz/H", "HTTP_X_OPS_AUTHORIZATION_2"=>"hg6oN77b60WLuHVUnTLygC6ZFQlxW/bDe1aOJwhYGUzfjJ0eNZZ0M0rlEHBk", "HTTP_X_OPS_AUTHORIZATION_3"=>"/IJQKub9tMbt3To5cOwuXyZY13++Xlyeugr53XzkwfZQHfwegfFpk6vcERt2", "HTTP_X_OPS_AUTHORIZATION_4"=>"trkbjwkUdYTLN7X54/SDQMAHbF1kohHeSY7kdVg4c3IZlq0J9rXU5/ZnFiTQ", "HTTP_X_OPS_AUTHORIZATION_5"=>"7Z34HKgqQKn+JeGp8YLGe5UOfXrbSsr1/V6nSzG/NKfP/Lggc0JaOB+SQIKj", "HTTP_X_OPS_AUTHORIZATION_6"=>"vZbEUX0Ch8ntCpCTXhkKF1neCa98HQsKk5vy9YtMaw==", "HTTP_HOST"=>"localhost:8889", "HTTP_X_REMOTE_REQUEST_ID"=>"44180b3f-c436-44c5-90cd-dc0145e2e183", "HTTP_X_CHEF_VERSION"=>"12.1.1", "HTTP_USER_AGENT"=>"Chef Knife/12.1.1 (ruby-2.1.4-p265; ohai-8.1.1; x86_64-linux; +http://opscode.com)", "HTTP_CONNECTION"=>"close", "rack.version"=>[1, 2], "rack.input"=>#<StringIO:0x000000038be7c0>, "rack.errors"=>#<IO:<STDERR>>, "rack.multithread"=>true, "rack.multiprocess"=>false, "rack.run_once"=>false, "rack.url_scheme"=>"http", "HTTP_VERSION"=>"HTTP/1.1", "REQUEST_PATH"=>"/data/machine_image/zookeeper-test"}, @rest_base_prefix=["organizations", "chef"]>
[2015-04-22T09:52:15-07:00] DEBUG: 
[2015-04-22T09:52:15-07:00] DEBUG: #<ChefZero::RestErrorResponse: ChefZero::RestErrorResponse>
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-zero-4.0/lib/chef_zero/rest_base.rb:59:in `rescue in get_data'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-zero-4.0/lib/chef_zero/rest_base.rb:51:in `get_data'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-zero-4.0/lib/chef_zero/endpoints/rest_object_endpoint.rb:18:in `get'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-zero-4.0/lib/chef_zero/rest_base.rb:30:in `call'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-zero-4.0/lib/chef_zero/rest_router.rb:24:in `call'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-zero-4.0/lib/chef_zero/server.rb:555:in `block in app'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/rack-1.5.2/lib/rack/handler/webrick.rb:60:in `call'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/rack-1.5.2/lib/rack/handler/webrick.rb:60:in `service'
/opt/chef/embedded/lib/ruby/2.1.0/webrick/httpserver.rb:138:in `service'
/opt/chef/embedded/lib/ruby/2.1.0/webrick/httpserver.rb:94:in `run'
/opt/chef/embedded/lib/ruby/2.1.0/webrick/server.rb:295:in `block in start_thread'
[2015-04-22T09:52:15-07:00] DEBUG: 
--- RESPONSE (404) ---
{
  "error": [
    "Object not found: http://localhost:8889/data/machine_image/zookeeper-test"
  ]
}

--- END RESPONSE ---
[2015-04-22T09:52:15-07:00] DEBUG: ---- HTTP Status and Header Data: ----
[2015-04-22T09:52:15-07:00] DEBUG: HTTP 1.1 404 Not Found 
[2015-04-22T09:52:15-07:00] DEBUG: content-type: application/json
[2015-04-22T09:52:15-07:00] DEBUG: server: chef-zero
[2015-04-22T09:52:15-07:00] DEBUG: access-control-allow-origin: *
[2015-04-22T09:52:15-07:00] DEBUG: date: Wed, 22 Apr 2015 16:52:15 GMT
[2015-04-22T09:52:15-07:00] DEBUG: content-length: 101
[2015-04-22T09:52:15-07:00] DEBUG: connection: close
[2015-04-22T09:52:15-07:00] DEBUG: ---- End HTTP Status/Header Data ----
[2015-04-22T09:52:15-07:00] DEBUG: ---- HTTP Response Body ----
[2015-04-22T09:52:15-07:00] DEBUG: {
  "error": [
    "Object not found: http://localhost:8889/data/machine_image/zookeeper-test"
  ]
}

[2015-04-22T09:52:15-07:00] DEBUG: ---- End HTTP Response Body -----
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::RemoteRequestID#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Authenticator#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Decompressor#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::CookieManager#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONOutput#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONInput#handle_response
[2015-04-22T09:52:15-07:00] INFO: HTTP Request Returned 404 Not Found : Object not found: http://localhost:8889/data/machine_image/zookeeper-test
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONInput#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONOutput#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::CookieManager#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Decompressor#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Authenticator#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Signing the request as admin
[2015-04-22T09:52:15-07:00] DEBUG: String to sign: 'Method:GET
Hashed Path:X8lk1PkCc4nuCdujJ9Rv2hHSH0M=
X-Ops-Content-Hash:2jmj7l5rSw0yVb/vlWAYkK/YBwk=
X-Ops-Timestamp:2015-04-22T16:52:15Z
X-Ops-UserId:admin'
Header hash: {"X-Ops-Sign"=>"algorithm=sha1;version=1.0;", "X-Ops-Userid"=>"admin", "X-Ops-Timestamp"=>"2015-04-22T16:52:15Z", "X-Ops-Content-Hash"=>"2jmj7l5rSw0yVb/vlWAYkK/YBwk=", "X-Ops-Authorization-1"=>"YcPxfj6oXxBGFUFP9ge8qCLRwUCyH3qKUJVRm4VKk0qCXOAqr1o8XfRp3YL0", "X-Ops-Authorization-2"=>"GrqE1oaZ/6gWUcP9k7ZBRCE8LOUSE1eewGAgVgmnWBAsKT/4mJLI0VbJnE42", "X-Ops-Authorization-3"=>"8VTXslszcWNemiyH/D6SDmsybzyDymSrhlSIEvUZN4pyrcWE5oBM7FCDo41A", "X-Ops-Authorization-4"=>"bwsPx+UXy/RrdWwDD+eAqjhfcqnAeZJOxHMVSovIsoOHqMxc3XzPIrmKY20u", "X-Ops-Authorization-5"=>"kBf54rgVzQDPS3q8WB08srPdHjSBst0/f6T73+Yxxh6/b/FrzsZ+WXtIPGtd", "X-Ops-Authorization-6"=>"JmZWGMDpWhGbEltge5EzVqeYch2Htn9X5neoyOlEZg=="}
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::RemoteRequestID#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Initiating GET to http://localhost:8889/data/images/zookeeper-test
[2015-04-22T09:52:15-07:00] DEBUG: ---- HTTP Request Header Data: ----
[2015-04-22T09:52:15-07:00] DEBUG: Accept: application/json
[2015-04-22T09:52:15-07:00] DEBUG: Accept-Encoding: gzip;q=1.0,deflate;q=0.6,identity;q=0.3
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-SIGN: algorithm=sha1;version=1.0;
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-USERID: admin
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-TIMESTAMP: 2015-04-22T16:52:15Z
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-CONTENT-HASH: 2jmj7l5rSw0yVb/vlWAYkK/YBwk=
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-1: YcPxfj6oXxBGFUFP9ge8qCLRwUCyH3qKUJVRm4VKk0qCXOAqr1o8XfRp3YL0
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-2: GrqE1oaZ/6gWUcP9k7ZBRCE8LOUSE1eewGAgVgmnWBAsKT/4mJLI0VbJnE42
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-3: 8VTXslszcWNemiyH/D6SDmsybzyDymSrhlSIEvUZN4pyrcWE5oBM7FCDo41A
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-4: bwsPx+UXy/RrdWwDD+eAqjhfcqnAeZJOxHMVSovIsoOHqMxc3XzPIrmKY20u
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-5: kBf54rgVzQDPS3q8WB08srPdHjSBst0/f6T73+Yxxh6/b/FrzsZ+WXtIPGtd
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-6: JmZWGMDpWhGbEltge5EzVqeYch2Htn9X5neoyOlEZg==
[2015-04-22T09:52:15-07:00] DEBUG: HOST: localhost:8889
[2015-04-22T09:52:15-07:00] DEBUG: X-REMOTE-REQUEST-ID: 44180b3f-c436-44c5-90cd-dc0145e2e183
[2015-04-22T09:52:15-07:00] DEBUG: ---- End HTTP Request Header Data ----
[2015-04-22T09:52:15-07:00] DEBUG: #<ChefZero::RestRequest:0x0000000383f088 @env={"GATEWAY_INTERFACE"=>"CGI/1.1", "PATH_INFO"=>"/data/images/zookeeper-test", "QUERY_STRING"=>"", "REMOTE_ADDR"=>"::1", "REMOTE_HOST"=>"localhost", "REQUEST_METHOD"=>"GET", "REQUEST_URI"=>"http://localhost:8889/data/images/zookeeper-test", "SCRIPT_NAME"=>"", "SERVER_NAME"=>"localhost", "SERVER_PORT"=>"8889", "SERVER_PROTOCOL"=>"HTTP/1.1", "SERVER_SOFTWARE"=>"WEBrick/1.3.1 (Ruby/2.1.4/2014-10-27) OpenSSL/1.0.1k", "HTTP_ACCEPT"=>"application/json", "HTTP_ACCEPT_ENCODING"=>"gzip;q=1.0,deflate;q=0.6,identity;q=0.3", "HTTP_X_OPS_SIGN"=>"algorithm=sha1;version=1.0;", "HTTP_X_OPS_USERID"=>"admin", "HTTP_X_OPS_TIMESTAMP"=>"2015-04-22T16:52:15Z", "HTTP_X_OPS_CONTENT_HASH"=>"2jmj7l5rSw0yVb/vlWAYkK/YBwk=", "HTTP_X_OPS_AUTHORIZATION_1"=>"YcPxfj6oXxBGFUFP9ge8qCLRwUCyH3qKUJVRm4VKk0qCXOAqr1o8XfRp3YL0", "HTTP_X_OPS_AUTHORIZATION_2"=>"GrqE1oaZ/6gWUcP9k7ZBRCE8LOUSE1eewGAgVgmnWBAsKT/4mJLI0VbJnE42", "HTTP_X_OPS_AUTHORIZATION_3"=>"8VTXslszcWNemiyH/D6SDmsybzyDymSrhlSIEvUZN4pyrcWE5oBM7FCDo41A", "HTTP_X_OPS_AUTHORIZATION_4"=>"bwsPx+UXy/RrdWwDD+eAqjhfcqnAeZJOxHMVSovIsoOHqMxc3XzPIrmKY20u", "HTTP_X_OPS_AUTHORIZATION_5"=>"kBf54rgVzQDPS3q8WB08srPdHjSBst0/f6T73+Yxxh6/b/FrzsZ+WXtIPGtd", "HTTP_X_OPS_AUTHORIZATION_6"=>"JmZWGMDpWhGbEltge5EzVqeYch2Htn9X5neoyOlEZg==", "HTTP_HOST"=>"localhost:8889", "HTTP_X_REMOTE_REQUEST_ID"=>"44180b3f-c436-44c5-90cd-dc0145e2e183", "HTTP_X_CHEF_VERSION"=>"12.1.1", "HTTP_USER_AGENT"=>"Chef Knife/12.1.1 (ruby-2.1.4-p265; ohai-8.1.1; x86_64-linux; +http://opscode.com)", "HTTP_CONNECTION"=>"close", "rack.version"=>[1, 2], "rack.input"=>#<StringIO:0x00000003844470>, "rack.errors"=>#<IO:<STDERR>>, "rack.multithread"=>true, "rack.multiprocess"=>false, "rack.run_once"=>false, "rack.url_scheme"=>"http", "HTTP_VERSION"=>"HTTP/1.1", "REQUEST_PATH"=>"/data/images/zookeeper-test"}, @rest_base_prefix=["organizations", "chef"]>
[2015-04-22T09:52:15-07:00] DEBUG: 
[2015-04-22T09:52:15-07:00] DEBUG: #<ChefZero::RestErrorResponse: ChefZero::RestErrorResponse>
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-zero-4.0/lib/chef_zero/rest_base.rb:59:in `rescue in get_data'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-zero-4.0/lib/chef_zero/rest_base.rb:51:in `get_data'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-zero-4.0/lib/chef_zero/endpoints/rest_object_endpoint.rb:18:in `get'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-zero-4.0/lib/chef_zero/rest_base.rb:30:in `call'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-zero-4.0/lib/chef_zero/rest_router.rb:24:in `call'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-zero-4.0/lib/chef_zero/server.rb:555:in `block in app'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/rack-1.5.2/lib/rack/handler/webrick.rb:60:in `call'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/rack-1.5.2/lib/rack/handler/webrick.rb:60:in `service'
/opt/chef/embedded/lib/ruby/2.1.0/webrick/httpserver.rb:138:in `service'
/opt/chef/embedded/lib/ruby/2.1.0/webrick/httpserver.rb:94:in `run'
/opt/chef/embedded/lib/ruby/2.1.0/webrick/server.rb:295:in `block in start_thread'
[2015-04-22T09:52:15-07:00] DEBUG: 
--- RESPONSE (404) ---
{
  "error": [
    "Object not found: http://localhost:8889/data/images/zookeeper-test"
  ]
}

--- END RESPONSE ---
[2015-04-22T09:52:15-07:00] DEBUG: ---- HTTP Status and Header Data: ----
[2015-04-22T09:52:15-07:00] DEBUG: HTTP 1.1 404 Not Found 
[2015-04-22T09:52:15-07:00] DEBUG: content-type: application/json
[2015-04-22T09:52:15-07:00] DEBUG: server: chef-zero
[2015-04-22T09:52:15-07:00] DEBUG: access-control-allow-origin: *
[2015-04-22T09:52:15-07:00] DEBUG: date: Wed, 22 Apr 2015 16:52:15 GMT
[2015-04-22T09:52:15-07:00] DEBUG: content-length: 94
[2015-04-22T09:52:15-07:00] DEBUG: connection: close
[2015-04-22T09:52:15-07:00] DEBUG: ---- End HTTP Status/Header Data ----
[2015-04-22T09:52:15-07:00] DEBUG: ---- HTTP Response Body ----
[2015-04-22T09:52:15-07:00] DEBUG: {
  "error": [
    "Object not found: http://localhost:8889/data/images/zookeeper-test"
  ]
}

[2015-04-22T09:52:15-07:00] DEBUG: ---- End HTTP Response Body -----
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::RemoteRequestID#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Authenticator#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Decompressor#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::CookieManager#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONOutput#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONInput#handle_response
[2015-04-22T09:52:15-07:00] INFO: HTTP Request Returned 404 Not Found : Object not found: http://localhost:8889/data/images/zookeeper-test
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONInput#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONOutput#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::CookieManager#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Decompressor#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Authenticator#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Signing the request as admin
[2015-04-22T09:52:15-07:00] DEBUG: String to sign: 'Method:GET
Hashed Path:YEQSqayJZdXhdQJraX41DByGx9I=
X-Ops-Content-Hash:2jmj7l5rSw0yVb/vlWAYkK/YBwk=
X-Ops-Timestamp:2015-04-22T16:52:15Z
X-Ops-UserId:admin'
Header hash: {"X-Ops-Sign"=>"algorithm=sha1;version=1.0;", "X-Ops-Userid"=>"admin", "X-Ops-Timestamp"=>"2015-04-22T16:52:15Z", "X-Ops-Content-Hash"=>"2jmj7l5rSw0yVb/vlWAYkK/YBwk=", "X-Ops-Authorization-1"=>"XanUAzf7PTG8zhpb2pLs5rGNAWW9eniP8TsgG3hIbq3SdSbNWMP+tLBOXOrB", "X-Ops-Authorization-2"=>"nq7s3s0drcwUHsb5ouSbb1M7auJ0LGqEusj6hwDcq+97u7bpifwHWXHJ2zVs", "X-Ops-Authorization-3"=>"ip1NOccNvFIMpAgbky6hYVz3FNUC/F0xXjLd11WmWykdvySS5ifsWyXdMcGt", "X-Ops-Authorization-4"=>"9z16r9uwsNSbFft5M/aaUULRBbQYXIQWGqWJ3qy4G/cJxwKiAcJ7sVVBY3/I", "X-Ops-Authorization-5"=>"IZh4/yuLPd4QdXMcFzOazk9yOc1p2ltnzS8CsP6ASLhWg+KN2o3WfS8ZHcA2", "X-Ops-Authorization-6"=>"g9gu6bfbjyrUql1B+ppApEouQkL5i7jVlDbrnwIhyw=="}
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::RemoteRequestID#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Initiating GET to http://localhost:8889/nodes/zookeeper-test
[2015-04-22T09:52:15-07:00] DEBUG: ---- HTTP Request Header Data: ----
[2015-04-22T09:52:15-07:00] DEBUG: Accept: application/json
[2015-04-22T09:52:15-07:00] DEBUG: Accept-Encoding: gzip;q=1.0,deflate;q=0.6,identity;q=0.3
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-SIGN: algorithm=sha1;version=1.0;
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-USERID: admin
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-TIMESTAMP: 2015-04-22T16:52:15Z
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-CONTENT-HASH: 2jmj7l5rSw0yVb/vlWAYkK/YBwk=
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-1: XanUAzf7PTG8zhpb2pLs5rGNAWW9eniP8TsgG3hIbq3SdSbNWMP+tLBOXOrB
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-2: nq7s3s0drcwUHsb5ouSbb1M7auJ0LGqEusj6hwDcq+97u7bpifwHWXHJ2zVs
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-3: ip1NOccNvFIMpAgbky6hYVz3FNUC/F0xXjLd11WmWykdvySS5ifsWyXdMcGt
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-4: 9z16r9uwsNSbFft5M/aaUULRBbQYXIQWGqWJ3qy4G/cJxwKiAcJ7sVVBY3/I
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-5: IZh4/yuLPd4QdXMcFzOazk9yOc1p2ltnzS8CsP6ASLhWg+KN2o3WfS8ZHcA2
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-6: g9gu6bfbjyrUql1B+ppApEouQkL5i7jVlDbrnwIhyw==
[2015-04-22T09:52:15-07:00] DEBUG: HOST: localhost:8889
[2015-04-22T09:52:15-07:00] DEBUG: X-REMOTE-REQUEST-ID: 44180b3f-c436-44c5-90cd-dc0145e2e183
[2015-04-22T09:52:15-07:00] DEBUG: ---- End HTTP Request Header Data ----
[2015-04-22T09:52:15-07:00] DEBUG: #<ChefZero::RestRequest:0x000000037705f8 @env={"GATEWAY_INTERFACE"=>"CGI/1.1", "PATH_INFO"=>"/nodes/zookeeper-test", "QUERY_STRING"=>"", "REMOTE_ADDR"=>"::1", "REMOTE_HOST"=>"localhost", "REQUEST_METHOD"=>"GET", "REQUEST_URI"=>"http://localhost:8889/nodes/zookeeper-test", "SCRIPT_NAME"=>"", "SERVER_NAME"=>"localhost", "SERVER_PORT"=>"8889", "SERVER_PROTOCOL"=>"HTTP/1.1", "SERVER_SOFTWARE"=>"WEBrick/1.3.1 (Ruby/2.1.4/2014-10-27) OpenSSL/1.0.1k", "HTTP_ACCEPT"=>"application/json", "HTTP_ACCEPT_ENCODING"=>"gzip;q=1.0,deflate;q=0.6,identity;q=0.3", "HTTP_X_OPS_SIGN"=>"algorithm=sha1;version=1.0;", "HTTP_X_OPS_USERID"=>"admin", "HTTP_X_OPS_TIMESTAMP"=>"2015-04-22T16:52:15Z", "HTTP_X_OPS_CONTENT_HASH"=>"2jmj7l5rSw0yVb/vlWAYkK/YBwk=", "HTTP_X_OPS_AUTHORIZATION_1"=>"XanUAzf7PTG8zhpb2pLs5rGNAWW9eniP8TsgG3hIbq3SdSbNWMP+tLBOXOrB", "HTTP_X_OPS_AUTHORIZATION_2"=>"nq7s3s0drcwUHsb5ouSbb1M7auJ0LGqEusj6hwDcq+97u7bpifwHWXHJ2zVs", "HTTP_X_OPS_AUTHORIZATION_3"=>"ip1NOccNvFIMpAgbky6hYVz3FNUC/F0xXjLd11WmWykdvySS5ifsWyXdMcGt", "HTTP_X_OPS_AUTHORIZATION_4"=>"9z16r9uwsNSbFft5M/aaUULRBbQYXIQWGqWJ3qy4G/cJxwKiAcJ7sVVBY3/I", "HTTP_X_OPS_AUTHORIZATION_5"=>"IZh4/yuLPd4QdXMcFzOazk9yOc1p2ltnzS8CsP6ASLhWg+KN2o3WfS8ZHcA2", "HTTP_X_OPS_AUTHORIZATION_6"=>"g9gu6bfbjyrUql1B+ppApEouQkL5i7jVlDbrnwIhyw==", "HTTP_HOST"=>"localhost:8889", "HTTP_X_REMOTE_REQUEST_ID"=>"44180b3f-c436-44c5-90cd-dc0145e2e183", "HTTP_X_CHEF_VERSION"=>"12.1.1", "HTTP_USER_AGENT"=>"Chef Knife/12.1.1 (ruby-2.1.4-p265; ohai-8.1.1; x86_64-linux; +http://opscode.com)", "HTTP_CONNECTION"=>"close", "rack.version"=>[1, 2], "rack.input"=>#<StringIO:0x00000003770d78>, "rack.errors"=>#<IO:<STDERR>>, "rack.multithread"=>true, "rack.multiprocess"=>false, "rack.run_once"=>false, "rack.url_scheme"=>"http", "HTTP_VERSION"=>"HTTP/1.1", "REQUEST_PATH"=>"/nodes/zookeeper-test"}, @rest_base_prefix=["organizations", "chef"]>
[2015-04-22T09:52:15-07:00] DEBUG: 
[2015-04-22T09:52:15-07:00] DEBUG: 
--- RESPONSE (200) ---
{
  "name": "zookeeper-test",
  "normal": {
    "tags": null,
    "chef_provisioning": {
      "reference": {
        "driver_url": "docker:unix:///var/run/docker.sock",
        "driver_version": "0.5.2",
        "allocated_at": "2015-04-22 16:50:38 UTC",
        "host_node": "http://localhost:8889/nodes/",
        "container_name": "zookeeper-test",
        "image_id": null
      }
    }
  },
  "run_list": [
    "recipe[zookeeper]"
  ],
  "json_class": "Chef::Node",
  "chef_type": "node",
  "chef_environment": "_default",
  "override": {

  },
  "default": {

  },
  "automatic": {

  }
}

--- END RESPONSE ---
[2015-04-22T09:52:15-07:00] DEBUG: ---- HTTP Status and Header Data: ----
[2015-04-22T09:52:15-07:00] DEBUG: HTTP 1.1 200 OK 
[2015-04-22T09:52:15-07:00] DEBUG: content-type: application/json
[2015-04-22T09:52:15-07:00] DEBUG: server: chef-zero
[2015-04-22T09:52:15-07:00] DEBUG: access-control-allow-origin: *
[2015-04-22T09:52:15-07:00] DEBUG: date: Wed, 22 Apr 2015 16:52:15 GMT
[2015-04-22T09:52:15-07:00] DEBUG: content-length: 596
[2015-04-22T09:52:15-07:00] DEBUG: connection: close
[2015-04-22T09:52:15-07:00] DEBUG: ---- End HTTP Status/Header Data ----
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::RemoteRequestID#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Authenticator#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Decompressor#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::CookieManager#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONOutput#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONInput#handle_response
[2015-04-22T09:52:15-07:00] INFO: Processing chef_node[zookeeper-test] action create (basic_chef_client::block line 57)
[2015-04-22T09:52:15-07:00] DEBUG: providers for generic chef_node resource enabled on node include: []
[2015-04-22T09:52:15-07:00] DEBUG: providers that refused resource chef_node[zookeeper-test] were: []
[2015-04-22T09:52:15-07:00] DEBUG: providers that support resource chef_node[zookeeper-test] include: []
[2015-04-22T09:52:15-07:00] DEBUG: no providers supported the resource, falling back to enabled handlers
[2015-04-22T09:52:15-07:00] DEBUG: providers that survived replacement include: []
[2015-04-22T09:52:15-07:00] DEBUG: dynamic provider resolver FAILED to resolve a provider
[2015-04-22T09:52:15-07:00] DEBUG: Platform basic_chef_client not found, using all defaults. (Unsupported platform?)
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONInput#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONOutput#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::CookieManager#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Decompressor#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Authenticator#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Signing the request as admin
[2015-04-22T09:52:15-07:00] DEBUG: String to sign: 'Method:GET
Hashed Path:YEQSqayJZdXhdQJraX41DByGx9I=
X-Ops-Content-Hash:2jmj7l5rSw0yVb/vlWAYkK/YBwk=
X-Ops-Timestamp:2015-04-22T16:52:15Z
X-Ops-UserId:admin'
Header hash: {"X-Ops-Sign"=>"algorithm=sha1;version=1.0;", "X-Ops-Userid"=>"admin", "X-Ops-Timestamp"=>"2015-04-22T16:52:15Z", "X-Ops-Content-Hash"=>"2jmj7l5rSw0yVb/vlWAYkK/YBwk=", "X-Ops-Authorization-1"=>"XanUAzf7PTG8zhpb2pLs5rGNAWW9eniP8TsgG3hIbq3SdSbNWMP+tLBOXOrB", "X-Ops-Authorization-2"=>"nq7s3s0drcwUHsb5ouSbb1M7auJ0LGqEusj6hwDcq+97u7bpifwHWXHJ2zVs", "X-Ops-Authorization-3"=>"ip1NOccNvFIMpAgbky6hYVz3FNUC/F0xXjLd11WmWykdvySS5ifsWyXdMcGt", "X-Ops-Authorization-4"=>"9z16r9uwsNSbFft5M/aaUULRBbQYXIQWGqWJ3qy4G/cJxwKiAcJ7sVVBY3/I", "X-Ops-Authorization-5"=>"IZh4/yuLPd4QdXMcFzOazk9yOc1p2ltnzS8CsP6ASLhWg+KN2o3WfS8ZHcA2", "X-Ops-Authorization-6"=>"g9gu6bfbjyrUql1B+ppApEouQkL5i7jVlDbrnwIhyw=="}
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::RemoteRequestID#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Initiating GET to http://localhost:8889/nodes/zookeeper-test
[2015-04-22T09:52:15-07:00] DEBUG: ---- HTTP Request Header Data: ----
[2015-04-22T09:52:15-07:00] DEBUG: Accept: application/json
[2015-04-22T09:52:15-07:00] DEBUG: Accept-Encoding: gzip;q=1.0,deflate;q=0.6,identity;q=0.3
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-SIGN: algorithm=sha1;version=1.0;
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-USERID: admin
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-TIMESTAMP: 2015-04-22T16:52:15Z
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-CONTENT-HASH: 2jmj7l5rSw0yVb/vlWAYkK/YBwk=
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-1: XanUAzf7PTG8zhpb2pLs5rGNAWW9eniP8TsgG3hIbq3SdSbNWMP+tLBOXOrB
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-2: nq7s3s0drcwUHsb5ouSbb1M7auJ0LGqEusj6hwDcq+97u7bpifwHWXHJ2zVs
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-3: ip1NOccNvFIMpAgbky6hYVz3FNUC/F0xXjLd11WmWykdvySS5ifsWyXdMcGt
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-4: 9z16r9uwsNSbFft5M/aaUULRBbQYXIQWGqWJ3qy4G/cJxwKiAcJ7sVVBY3/I
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-5: IZh4/yuLPd4QdXMcFzOazk9yOc1p2ltnzS8CsP6ASLhWg+KN2o3WfS8ZHcA2
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-6: g9gu6bfbjyrUql1B+ppApEouQkL5i7jVlDbrnwIhyw==
[2015-04-22T09:52:15-07:00] DEBUG: HOST: localhost:8889
[2015-04-22T09:52:15-07:00] DEBUG: X-REMOTE-REQUEST-ID: 44180b3f-c436-44c5-90cd-dc0145e2e183
[2015-04-22T09:52:15-07:00] DEBUG: ---- End HTTP Request Header Data ----
[2015-04-22T09:52:15-07:00] DEBUG: #<ChefZero::RestRequest:0x000000036e6880 @env={"GATEWAY_INTERFACE"=>"CGI/1.1", "PATH_INFO"=>"/nodes/zookeeper-test", "QUERY_STRING"=>"", "REMOTE_ADDR"=>"::1", "REMOTE_HOST"=>"localhost", "REQUEST_METHOD"=>"GET", "REQUEST_URI"=>"http://localhost:8889/nodes/zookeeper-test", "SCRIPT_NAME"=>"", "SERVER_NAME"=>"localhost", "SERVER_PORT"=>"8889", "SERVER_PROTOCOL"=>"HTTP/1.1", "SERVER_SOFTWARE"=>"WEBrick/1.3.1 (Ruby/2.1.4/2014-10-27) OpenSSL/1.0.1k", "HTTP_ACCEPT"=>"application/json", "HTTP_ACCEPT_ENCODING"=>"gzip;q=1.0,deflate;q=0.6,identity;q=0.3", "HTTP_X_OPS_SIGN"=>"algorithm=sha1;version=1.0;", "HTTP_X_OPS_USERID"=>"admin", "HTTP_X_OPS_TIMESTAMP"=>"2015-04-22T16:52:15Z", "HTTP_X_OPS_CONTENT_HASH"=>"2jmj7l5rSw0yVb/vlWAYkK/YBwk=", "HTTP_X_OPS_AUTHORIZATION_1"=>"XanUAzf7PTG8zhpb2pLs5rGNAWW9eniP8TsgG3hIbq3SdSbNWMP+tLBOXOrB", "HTTP_X_OPS_AUTHORIZATION_2"=>"nq7s3s0drcwUHsb5ouSbb1M7auJ0LGqEusj6hwDcq+97u7bpifwHWXHJ2zVs", "HTTP_X_OPS_AUTHORIZATION_3"=>"ip1NOccNvFIMpAgbky6hYVz3FNUC/F0xXjLd11WmWykdvySS5ifsWyXdMcGt", "HTTP_X_OPS_AUTHORIZATION_4"=>"9z16r9uwsNSbFft5M/aaUULRBbQYXIQWGqWJ3qy4G/cJxwKiAcJ7sVVBY3/I", "HTTP_X_OPS_AUTHORIZATION_5"=>"IZh4/yuLPd4QdXMcFzOazk9yOc1p2ltnzS8CsP6ASLhWg+KN2o3WfS8ZHcA2", "HTTP_X_OPS_AUTHORIZATION_6"=>"g9gu6bfbjyrUql1B+ppApEouQkL5i7jVlDbrnwIhyw==", "HTTP_HOST"=>"localhost:8889", "HTTP_X_REMOTE_REQUEST_ID"=>"44180b3f-c436-44c5-90cd-dc0145e2e183", "HTTP_X_CHEF_VERSION"=>"12.1.1", "HTTP_USER_AGENT"=>"Chef Knife/12.1.1 (ruby-2.1.4-p265; ohai-8.1.1; x86_64-linux; +http://opscode.com)", "HTTP_CONNECTION"=>"close", "rack.version"=>[1, 2], "rack.input"=>#<StringIO:0x000000036e7118>, "rack.errors"=>#<IO:<STDERR>>, "rack.multithread"=>true, "rack.multiprocess"=>false, "rack.run_once"=>false, "rack.url_scheme"=>"http", "HTTP_VERSION"=>"HTTP/1.1", "REQUEST_PATH"=>"/nodes/zookeeper-test"}, @rest_base_prefix=["organizations", "chef"]>
[2015-04-22T09:52:15-07:00] DEBUG: 
[2015-04-22T09:52:15-07:00] DEBUG: 
--- RESPONSE (200) ---
{
  "name": "zookeeper-test",
  "normal": {
    "tags": null,
    "chef_provisioning": {
      "reference": {
        "driver_url": "docker:unix:///var/run/docker.sock",
        "driver_version": "0.5.2",
        "allocated_at": "2015-04-22 16:50:38 UTC",
        "host_node": "http://localhost:8889/nodes/",
        "container_name": "zookeeper-test",
        "image_id": null
      }
    }
  },
  "run_list": [
    "recipe[zookeeper]"
  ],
  "json_class": "Chef::Node",
  "chef_type": "node",
  "chef_environment": "_default",
  "override": {

  },
  "default": {

  },
  "automatic": {

  }
}

--- END RESPONSE ---
[2015-04-22T09:52:15-07:00] DEBUG: ---- HTTP Status and Header Data: ----
[2015-04-22T09:52:15-07:00] DEBUG: HTTP 1.1 200 OK 
[2015-04-22T09:52:15-07:00] DEBUG: content-type: application/json
[2015-04-22T09:52:15-07:00] DEBUG: server: chef-zero
[2015-04-22T09:52:15-07:00] DEBUG: access-control-allow-origin: *
[2015-04-22T09:52:15-07:00] DEBUG: date: Wed, 22 Apr 2015 16:52:15 GMT
[2015-04-22T09:52:15-07:00] DEBUG: content-length: 596
[2015-04-22T09:52:15-07:00] DEBUG: connection: close
[2015-04-22T09:52:15-07:00] DEBUG: ---- End HTTP Status/Header Data ----
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::RemoteRequestID#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Authenticator#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Decompressor#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::CookieManager#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONOutput#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONInput#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONInput#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONOutput#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::CookieManager#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Decompressor#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Authenticator#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Signing the request as admin
[2015-04-22T09:52:15-07:00] DEBUG: String to sign: 'Method:PUT
Hashed Path:YEQSqayJZdXhdQJraX41DByGx9I=
X-Ops-Content-Hash:lYai71qgVY8ug2End1321uGrybA=
X-Ops-Timestamp:2015-04-22T16:52:15Z
X-Ops-UserId:admin'
Header hash: {"X-Ops-Sign"=>"algorithm=sha1;version=1.0;", "X-Ops-Userid"=>"admin", "X-Ops-Timestamp"=>"2015-04-22T16:52:15Z", "X-Ops-Content-Hash"=>"lYai71qgVY8ug2End1321uGrybA=", "X-Ops-Authorization-1"=>"r4JXuhG977xyuKbTgP8P5q9v7X4gDySlo7pFdY8y4f5fU5DIa3oRjPjJEsN8", "X-Ops-Authorization-2"=>"AD0jzK9csc2D2cOlaFtgmp4WoNiSNljpqYtaLiTiSW73v1ipm9gHbt/qVIYh", "X-Ops-Authorization-3"=>"ezn6pHsC26/Q+9ltOsYBo5Suco7b9+JnBpy3eADFYnRp9w0rHwVES8GTFQeN", "X-Ops-Authorization-4"=>"+E8LOf42k+rdVTRJIHImYPI10Z9+Uc1spHnUT2bBdBOS9LmrXg3FMzRpgaDZ", "X-Ops-Authorization-5"=>"3C3BGVOaNXBmVp55Dmbtlt26Wc3LCLINLu6dn3+9sCTM0Pn5TreWoRZxtP/N", "X-Ops-Authorization-6"=>"k1OsxJcz+0aGLhlgUn/RJVjqTlVLS8U+4fnEPX16Pw=="}
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::RemoteRequestID#handle_request
[2015-04-22T09:52:15-07:00] DEBUG: Initiating PUT to http://localhost:8889/nodes/zookeeper-test
[2015-04-22T09:52:15-07:00] DEBUG: ---- HTTP Request Header Data: ----
[2015-04-22T09:52:15-07:00] DEBUG: Content-Type: application/json
[2015-04-22T09:52:15-07:00] DEBUG: Accept: application/json
[2015-04-22T09:52:15-07:00] DEBUG: Accept-Encoding: gzip;q=1.0,deflate;q=0.6,identity;q=0.3
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-SIGN: algorithm=sha1;version=1.0;
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-USERID: admin
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-TIMESTAMP: 2015-04-22T16:52:15Z
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-CONTENT-HASH: lYai71qgVY8ug2End1321uGrybA=
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-1: r4JXuhG977xyuKbTgP8P5q9v7X4gDySlo7pFdY8y4f5fU5DIa3oRjPjJEsN8
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-2: AD0jzK9csc2D2cOlaFtgmp4WoNiSNljpqYtaLiTiSW73v1ipm9gHbt/qVIYh
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-3: ezn6pHsC26/Q+9ltOsYBo5Suco7b9+JnBpy3eADFYnRp9w0rHwVES8GTFQeN
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-4: +E8LOf42k+rdVTRJIHImYPI10Z9+Uc1spHnUT2bBdBOS9LmrXg3FMzRpgaDZ
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-5: 3C3BGVOaNXBmVp55Dmbtlt26Wc3LCLINLu6dn3+9sCTM0Pn5TreWoRZxtP/N
[2015-04-22T09:52:15-07:00] DEBUG: X-OPS-AUTHORIZATION-6: k1OsxJcz+0aGLhlgUn/RJVjqTlVLS8U+4fnEPX16Pw==
[2015-04-22T09:52:15-07:00] DEBUG: HOST: localhost:8889
[2015-04-22T09:52:15-07:00] DEBUG: X-REMOTE-REQUEST-ID: 44180b3f-c436-44c5-90cd-dc0145e2e183
[2015-04-22T09:52:15-07:00] DEBUG: Content-Length: 443
[2015-04-22T09:52:15-07:00] DEBUG: ---- End HTTP Request Header Data ----
[2015-04-22T09:52:15-07:00] DEBUG: #<ChefZero::RestRequest:0x0000000363ffa8 @env={"CONTENT_LENGTH"=>"443", "CONTENT_TYPE"=>"application/json", "GATEWAY_INTERFACE"=>"CGI/1.1", "PATH_INFO"=>"/nodes/zookeeper-test", "QUERY_STRING"=>"", "REMOTE_ADDR"=>"::1", "REMOTE_HOST"=>"localhost", "REQUEST_METHOD"=>"PUT", "REQUEST_URI"=>"http://localhost:8889/nodes/zookeeper-test", "SCRIPT_NAME"=>"", "SERVER_NAME"=>"localhost", "SERVER_PORT"=>"8889", "SERVER_PROTOCOL"=>"HTTP/1.1", "SERVER_SOFTWARE"=>"WEBrick/1.3.1 (Ruby/2.1.4/2014-10-27) OpenSSL/1.0.1k", "HTTP_ACCEPT"=>"application/json", "HTTP_ACCEPT_ENCODING"=>"gzip;q=1.0,deflate;q=0.6,identity;q=0.3", "HTTP_X_OPS_SIGN"=>"algorithm=sha1;version=1.0;", "HTTP_X_OPS_USERID"=>"admin", "HTTP_X_OPS_TIMESTAMP"=>"2015-04-22T16:52:15Z", "HTTP_X_OPS_CONTENT_HASH"=>"lYai71qgVY8ug2End1321uGrybA=", "HTTP_X_OPS_AUTHORIZATION_1"=>"r4JXuhG977xyuKbTgP8P5q9v7X4gDySlo7pFdY8y4f5fU5DIa3oRjPjJEsN8", "HTTP_X_OPS_AUTHORIZATION_2"=>"AD0jzK9csc2D2cOlaFtgmp4WoNiSNljpqYtaLiTiSW73v1ipm9gHbt/qVIYh", "HTTP_X_OPS_AUTHORIZATION_3"=>"ezn6pHsC26/Q+9ltOsYBo5Suco7b9+JnBpy3eADFYnRp9w0rHwVES8GTFQeN", "HTTP_X_OPS_AUTHORIZATION_4"=>"+E8LOf42k+rdVTRJIHImYPI10Z9+Uc1spHnUT2bBdBOS9LmrXg3FMzRpgaDZ", "HTTP_X_OPS_AUTHORIZATION_5"=>"3C3BGVOaNXBmVp55Dmbtlt26Wc3LCLINLu6dn3+9sCTM0Pn5TreWoRZxtP/N", "HTTP_X_OPS_AUTHORIZATION_6"=>"k1OsxJcz+0aGLhlgUn/RJVjqTlVLS8U+4fnEPX16Pw==", "HTTP_HOST"=>"localhost:8889", "HTTP_X_REMOTE_REQUEST_ID"=>"44180b3f-c436-44c5-90cd-dc0145e2e183", "HTTP_X_CHEF_VERSION"=>"12.1.1", "HTTP_USER_AGENT"=>"Chef Knife/12.1.1 (ruby-2.1.4-p265; ohai-8.1.1; x86_64-linux; +http://opscode.com)", "HTTP_CONNECTION"=>"close", "rack.version"=>[1, 2], "rack.input"=>#<StringIO:0x00000003650bc8>, "rack.errors"=>#<IO:<STDERR>>, "rack.multithread"=>true, "rack.multiprocess"=>false, "rack.run_once"=>false, "rack.url_scheme"=>"http", "HTTP_VERSION"=>"HTTP/1.1", "REQUEST_PATH"=>"/nodes/zookeeper-test"}, @rest_base_prefix=["organizations", "chef"]>
[2015-04-22T09:52:15-07:00] DEBUG: {"name":"zookeeper-test","json_class":"Chef::Node","chef_type":"node","chef_environment":"_default","override":{},"normal":{"tags":null,"chef_provisioning":{"reference":{"driver_url":"docker:unix:///var/run/docker.sock","driver_version":"0.5.2","allocated_at":"2015-04-22 16:52:15 UTC","host_node":"http://localhost:8889/nodes/","container_name":"zookeeper-test","image_id":null}}},"default":{},"automatic":{},"run_list":["recipe[zookeeper]"]}
[2015-04-22T09:52:15-07:00] DEBUG: 
--- RESPONSE (200) ---
{
  "name": "zookeeper-test",
  "json_class": "Chef::Node",
  "chef_type": "node",
  "chef_environment": "_default",
  "override": {

  },
  "normal": {
    "tags": null,
    "chef_provisioning": {
      "reference": {
        "driver_url": "docker:unix:///var/run/docker.sock",
        "driver_version": "0.5.2",
        "allocated_at": "2015-04-22 16:52:15 UTC",
        "host_node": "http://localhost:8889/nodes/",
        "container_name": "zookeeper-test",
        "image_id": null
      }
    }
  },
  "default": {

  },
  "automatic": {

  },
  "run_list": [
    "recipe[zookeeper]"
  ]
}

--- END RESPONSE ---
[2015-04-22T09:52:15-07:00] DEBUG: ---- HTTP Status and Header Data: ----
[2015-04-22T09:52:15-07:00] DEBUG: HTTP 1.1 200 OK 
[2015-04-22T09:52:15-07:00] DEBUG: content-type: application/json
[2015-04-22T09:52:15-07:00] DEBUG: server: chef-zero
[2015-04-22T09:52:15-07:00] DEBUG: access-control-allow-origin: *
[2015-04-22T09:52:15-07:00] DEBUG: date: Wed, 22 Apr 2015 16:52:15 GMT
[2015-04-22T09:52:15-07:00] DEBUG: content-length: 596
[2015-04-22T09:52:15-07:00] DEBUG: connection: close
[2015-04-22T09:52:15-07:00] DEBUG: ---- End HTTP Status/Header Data ----
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::RemoteRequestID#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Authenticator#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::Decompressor#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::CookieManager#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONOutput#handle_response
[2015-04-22T09:52:15-07:00] DEBUG: Chef::HTTP calling Chef::HTTP::JSONInput#handle_response
[0m
================================================================================[0m
[31mError executing action `create` on resource 'machine_image[zookeeper-test]'[0m
================================================================================[0m

[0mDocker::Error::NotFoundError[0m
----------------------------[0m
Expected([200, 201, 202, 203, 204, 304]) <=> Actual(404 Not Found)
[0m
[0mResource Declaration:[0m
---------------------[0m
# In /home/abby/docker-prototyping/chef-repo/.chef/local-mode-cache/cache/cookbooks/tests/recipes/machine_image_test.rb
[0m
[0m  3: machine_image 'zookeeper-test' do
[0m  4:    recipe 'zookeeper'
[0m  5:    driver 'docker'
[0m  6:    machine_options :docker_options => {
[0m  7:        :base_image => {
[0m  8:            :name => 'ubuntu',
[0m  9:            :repository => 'ubuntu',
[0m 10:            :tag => '14.04'
[0m 11:        }
[0m 12:    }
[0m 13: end
[0m
[0mCompiled Resource:[0m
------------------[0m
# Declared in /home/abby/docker-prototyping/chef-repo/.chef/local-mode-cache/cache/cookbooks/tests/recipes/machine_image_test.rb:3:in `from_file'
[0m
[0mmachine_image("zookeeper-test") do
[0m  action :create
[0m  retries 0
[0m  retry_delay 2
[0m  default_guard_interpreter :default
[0m  chef_server {:chef_server_url=>"http://localhost:8889", :options=>{:client_name=>"admin", :signing_key_filename=>"/home/abby/docker-prototyping/chef-repo/.chef/admin.pem"}}
[0m  driver "docker"
[0m  machine_options {:docker_options=>{:base_image=>{:name=>"ubuntu", :repository=>"ubuntu", :tag=>"14.04"}}}
[0m  declared_type :machine_image
[0m  cookbook_name "tests"
[0m  recipe_name "machine_image_test"
[0m  run_list_modifiers [#<Chef::RunList::RunListItem:0x0000000265fa48 @version=nil, @type=:recipe, @name="zookeeper">]
[0mend
[0m
[0m[2015-04-22T09:52:15-07:00] INFO: Running queued delayed notifications before re-raising exception
[2015-04-22T09:52:15-07:00] ERROR: Converge failed with error message machine_image[zookeeper-test] (tests::machine_image_test line 3) had an error: Docker::Error::NotFoundError: Expected([200, 201, 202, 203, 204, 304]) <=> Actual(404 Not Found)

[2015-04-22T09:52:15-07:00] DEBUG: Re-raising exception: Chef::Exceptions::RunFailedWrappingError - Found 1 errors, they are stored in the backtrace
1) Docker::Error::NotFoundError -  machine_image[zookeeper-test] (tests::machine_image_test line 3) had an error: Docker::Error::NotFoundError: Expected([200, 201, 202, 203, 204, 304]) <=> Actual(404 Not Found)

  /opt/chef/embedded/lib/ruby/gems/2.1.0/gems/docker-api-1.21.0/lib/docker/connection.rb:50:in `rescue in request'
  /opt/chef/embedded/lib/ruby/gems/2.1.0/gems/docker-api-1.21.0/lib/docker/connection.rb:38:in `request'
  /opt/chef/embedded/lib/ruby/gems/2.1.0/gems/docker-api-1.21.0/lib/docker/connection.rb:61:in `block (2 levels) in <class:Connection>'
  /opt/chef/embedded/lib/ruby/gems/2.1.0/gems/docker-api-1.21.0/lib/docker/image.rb:168:in `all'
  /opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-docker-0.5.2/lib/chef/provisioning/docker_driver/driver.rb:181:in `find_image'
  /opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-docker-0.5.2/lib/chef/provisioning/docker_driver/driver.rb:108:in `build_container'
  /opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-docker-0.5.2/lib/chef/provisioning/docker_driver/driver.rb:87:in `ready_machine'
  /opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-0.20.1/lib/chef/provider/machine.rb:38:in `block in <class:Machine>'
  /opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:60:in `instance_eval'
  /opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:60:in `recipe_eval_with_update_check'
  /opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:45:in `block in action'
  /opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-0.20.1/lib/chef/provider/machine.rb:55:in `block in <class:Machine>'
  /opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:60:in `instance_eval'
  /opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:60:in `recipe_eval_with_update_check'
  /opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:45:in `block in action'
  /opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-0.20.1/lib/chef/provider/machine_image.rb:60:in `create_image'
  /opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-0.20.1/lib/chef/provider/machine_image.rb:35:in `block in <class:MachineImage>'
  /opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:138:in `instance_eval'
  /opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:138:in `block in action'
  /opt/chef/embedded/apps/chef/lib/chef/provider.rb:149:in `run_action'
  /opt/chef/embedded/apps/chef/lib/chef/resource.rb:561:in `run_action'
  /opt/chef/embedded/apps/chef/lib/chef/runner.rb:49:in `run_action'
  /opt/chef/embedded/apps/chef/lib/chef/runner.rb:81:in `block (2 levels) in converge'
  /opt/chef/embedded/apps/chef/lib/chef/runner.rb:81:in `each'
  /opt/chef/embedded/apps/chef/lib/chef/runner.rb:81:in `block in converge'
  /opt/chef/embedded/apps/chef/lib/chef/resource_collection/resource_list.rb:83:in `block in execute_each_resource'
  /opt/chef/embedded/apps/chef/lib/chef/resource_collection/stepable_iterator.rb:116:in `call'
  /opt/chef/embedded/apps/chef/lib/chef/resource_collection/stepable_iterator.rb:116:in `call_iterator_block'
  /opt/chef/embedded/apps/chef/lib/chef/resource_collection/stepable_iterator.rb:85:in `step'
  /opt/chef/embedded/apps/chef/lib/chef/resource_collection/stepable_iterator.rb:104:in `iterate'
  /opt/chef/embedded/apps/chef/lib/chef/resource_collection/stepable_iterator.rb:55:in `each_with_index'
  /opt/chef/embedded/apps/chef/lib/chef/resource_collection/resource_list.rb:81:in `execute_each_resource'
  /opt/chef/embedded/apps/chef/lib/chef/runner.rb:80:in `converge'
  /opt/chef/embedded/apps/chef/lib/chef/client.rb:331:in `block in converge'
  /opt/chef/embedded/apps/chef/lib/chef/client.rb:326:in `catch'
  /opt/chef/embedded/apps/chef/lib/chef/client.rb:326:in `converge'
  /opt/chef/embedded/apps/chef/lib/chef/client.rb:345:in `converge_and_save'
  /opt/chef/embedded/apps/chef/lib/chef/client.rb:448:in `run'
  /opt/chef/embedded/apps/chef/lib/chef/application.rb:271:in `block in fork_chef_client'
  /opt/chef/embedded/apps/chef/lib/chef/application.rb:259:in `fork'
  /opt/chef/embedded/apps/chef/lib/chef/application.rb:259:in `fork_chef_client'
  /opt/chef/embedded/apps/chef/lib/chef/application.rb:225:in `block in run_chef_client'
  /opt/chef/embedded/apps/chef/lib/chef/local_mode.rb:38:in `with_server_connectivity'
  /opt/chef/embedded/apps/chef/lib/chef/application.rb:213:in `run_chef_client'
  /opt/chef/embedded/apps/chef/lib/chef/application/client.rb:392:in `block in interval_run_chef_client'
  /opt/chef/embedded/apps/chef/lib/chef/application/client.rb:382:in `loop'
  /opt/chef/embedded/apps/chef/lib/chef/application/client.rb:382:in `interval_run_chef_client'
  /opt/chef/embedded/apps/chef/lib/chef/application/client.rb:372:in `run_application'
  /opt/chef/embedded/apps/chef/lib/chef/application.rb:60:in `run'
  /opt/chef/embedded/apps/chef/bin/chef-client:26:in `<top (required)>'
  /usr/bin/chef-client:52:in `load'
  /usr/bin/chef-client:52:in `<main>'

[2015-04-22T09:52:15-07:00] ERROR: Running exception handlers
[2015-04-22T09:52:15-07:00] ERROR: Exception handlers complete
[2015-04-22T09:52:15-07:00] FATAL: Stacktrace dumped to /home/abby/docker-prototyping/chef-repo/.chef/local-mode-cache/cache/chef-stacktrace.out
[2015-04-22T09:52:15-07:00] DEBUG: Chef::Exceptions::RunFailedWrappingError: Found 1 errors, they are stored in the backtrace
1) Docker::Error::NotFoundError -  machine_image[zookeeper-test] (tests::machine_image_test line 3) had an error: Docker::Error::NotFoundError: Expected([200, 201, 202, 203, 204, 304]) <=> Actual(404 Not Found)

/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/docker-api-1.21.0/lib/docker/connection.rb:50:in `rescue in request'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/docker-api-1.21.0/lib/docker/connection.rb:38:in `request'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/docker-api-1.21.0/lib/docker/connection.rb:61:in `block (2 levels) in <class:Connection>'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/docker-api-1.21.0/lib/docker/image.rb:168:in `all'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-docker-0.5.2/lib/chef/provisioning/docker_driver/driver.rb:181:in `find_image'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-docker-0.5.2/lib/chef/provisioning/docker_driver/driver.rb:108:in `build_container'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-docker-0.5.2/lib/chef/provisioning/docker_driver/driver.rb:87:in `ready_machine'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-0.20.1/lib/chef/provider/machine.rb:38:in `block in <class:Machine>'
/opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:60:in `instance_eval'
/opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:60:in `recipe_eval_with_update_check'
/opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:45:in `block in action'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-0.20.1/lib/chef/provider/machine.rb:55:in `block in <class:Machine>'
/opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:60:in `instance_eval'
/opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:60:in `recipe_eval_with_update_check'
/opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:45:in `block in action'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-0.20.1/lib/chef/provider/machine_image.rb:60:in `create_image'
/opt/chef/embedded/lib/ruby/gems/2.1.0/gems/chef-provisioning-0.20.1/lib/chef/provider/machine_image.rb:35:in `block in <class:MachineImage>'
/opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:138:in `instance_eval'
/opt/chef/embedded/apps/chef/lib/chef/provider/lwrp_base.rb:138:in `block in action'
/opt/chef/embedded/apps/chef/lib/chef/provider.rb:149:in `run_action'
/opt/chef/embedded/apps/chef/lib/chef/resource.rb:561:in `run_action'
/opt/chef/embedded/apps/chef/lib/chef/runner.rb:49:in `run_action'
/opt/chef/embedded/apps/chef/lib/chef/runner.rb:81:in `block (2 levels) in converge'
/opt/chef/embedded/apps/chef/lib/chef/runner.rb:81:in `each'
/opt/chef/embedded/apps/chef/lib/chef/runner.rb:81:in `block in converge'
/opt/chef/embedded/apps/chef/lib/chef/resource_collection/resource_list.rb:83:in `block in execute_each_resource'
/opt/chef/embedded/apps/chef/lib/chef/resource_collection/stepable_iterator.rb:116:in `call'
/opt/chef/embedded/apps/chef/lib/chef/resource_collection/stepable_iterator.rb:116:in `call_iterator_block'
/opt/chef/embedded/apps/chef/lib/chef/resource_collection/stepable_iterator.rb:85:in `step'
/opt/chef/embedded/apps/chef/lib/chef/resource_collection/stepable_iterator.rb:104:in `iterate'
/opt/chef/embedded/apps/chef/lib/chef/resource_collection/stepable_iterator.rb:55:in `each_with_index'
/opt/chef/embedded/apps/chef/lib/chef/resource_collection/resource_list.rb:81:in `execute_each_resource'
/opt/chef/embedded/apps/chef/lib/chef/runner.rb:80:in `converge'
/opt/chef/embedded/apps/chef/lib/chef/client.rb:331:in `block in converge'
/opt/chef/embedded/apps/chef/lib/chef/client.rb:326:in `catch'
/opt/chef/embedded/apps/chef/lib/chef/client.rb:326:in `converge'
/opt/chef/embedded/apps/chef/lib/chef/client.rb:345:in `converge_and_save'
/opt/chef/embedded/apps/chef/lib/chef/client.rb:448:in `run'
/opt/chef/embedded/apps/chef/lib/chef/application.rb:271:in `block in fork_chef_client'
/opt/chef/embedded/apps/chef/lib/chef/application.rb:259:in `fork'
/opt/chef/embedded/apps/chef/lib/chef/application.rb:259:in `fork_chef_client'
/opt/chef/embedded/apps/chef/lib/chef/application.rb:225:in `block in run_chef_client'
/opt/chef/embedded/apps/chef/lib/chef/local_mode.rb:38:in `with_server_connectivity'
/opt/chef/embedded/apps/chef/lib/chef/application.rb:213:in `run_chef_client'
/opt/chef/embedded/apps/chef/lib/chef/application/client.rb:392:in `block in interval_run_chef_client'
/opt/chef/embedded/apps/chef/lib/chef/application/client.rb:382:in `loop'
/opt/chef/embedded/apps/chef/lib/chef/application/client.rb:382:in `interval_run_chef_client'
/opt/chef/embedded/apps/chef/lib/chef/application/client.rb:372:in `run_application'
/opt/chef/embedded/apps/chef/lib/chef/application.rb:60:in `run'
/opt/chef/embedded/apps/chef/bin/chef-client:26:in `<top (required)>'
/usr/bin/chef-client:52:in `load'
/usr/bin/chef-client:52:in `<main>'

[2015-04-22T09:52:15-07:00] DEBUG: Server doesn't support resource history, skipping resource report.
[2015-04-22T09:52:15-07:00] DEBUG: Audit Reports are disabled. Skipping sending reports.
[2015-04-22T09:52:15-07:00] ERROR: Found 1 errors, they are stored in the backtrace
[2015-04-22T09:52:17-07:00] FATAL: Chef::Exceptions::ChildConvergeError: Chef run process exited unsuccessfully (exit code 1)

I'm still not convinced that the allocate_image method is running for the following reasons:

  1. The line of debug output you mentioned above ("Allocated Docker::Image...") appears to have actually come from line 116 of driver.rb, which is in the build_container method. It's the only reference to the word "Allocated" in the entire repository when I do a simple text search. Correct me if I'm wrong, but this method appears to run independently of allocate_image.
  2. The warning message that is supposed to be printed in the rescue block that you linked to above isn't printed in the output of "chef-client -l warn ..." at all when running in either local or server mode.
  3. I've placed debug statements in the following locations which resulted in the following behaviors, respectively:
    machine_image.rb, line 56 (very beginning of create_image): prints to the debug log as expected machine_image.rb, line 72 (just after machine_provider.action_converge): does not print to the debug log driver.rb, line 126 (very beginning of allocate_image): does not print to the debug log

Hopefully this helps. Sorry for the delayed response, and thanks again for looking into it.

vardaofthevalier avatar Apr 22 '15 17:04 vardaofthevalier

I would suggest to try chef-provisioning version 0.19 . Later versions have major code changes which are not supported yet by chef-provisioning-docker.

marc- avatar Apr 22 '15 18:04 marc-