Found the following trace in dc logs... Processing /api/instances/de3c032f-818d-436e-9664-61a81e9d4e8f/start (for 127.0.0.1 at Thu Oct 06 08:33:13 -0400 2011) [POST] [RHEVM] /usr/bin/deltacloudd[29749]: Parameters: {} /usr/bin/deltacloudd[29749]: Provider: https://rhevm30.virt.bos.redhat.com:8443/api /usr/bin/deltacloudd[29749]: Authentication: Basic /usr/bin/deltacloudd[29749]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[29749]: Accept: application/xml /usr/bin/deltacloudd[29749]: RestClient::BadRequest:400 Bad Request /usr/lib/ruby/gems/1.8/gems/rest-client-1.6.1/lib/restclient/abstract_response.rb:48:in `return!' /usr/lib/ruby/gems/1.8/gems/rest-client-1.6.1/lib/restclient/request.rb:220:in `process_result' /usr/lib/ruby/gems/1.8/gems/rest-client-1.6.1/lib/restclient/request.rb:169:in `transmit' /usr/lib/ruby/1.8/net/http.rb:543:in `start' /usr/lib/ruby/gems/1.8/gems/rest-client-1.6.1/lib/restclient/request.rb:166:in `transmit' /usr/lib/ruby/gems/1.8/gems/rest-client-1.6.1/lib/restclient/request.rb:60:in `execute' /usr/lib/ruby/gems/1.8/gems/rest-client-1.6.1/lib/restclient/request.rb:31:in `execute' /usr/lib/ruby/gems/1.8/gems/rest-client-1.6.1/lib/restclient/resource.rb:63:in `post' /usr/share/deltacloud-core/bin/../lib/deltacloud/drivers/rhevm/rhevm_client.rb:79:in `vm_action' /usr/share/deltacloud-core/bin/../lib/deltacloud/drivers/rhevm/rhevm_driver.rb:151:in `start_instance' /usr/share/deltacloud-core/bin/../lib/deltacloud/base_driver/exceptions.rb:151:in `call' /usr/share/deltacloud-core/bin/../lib/deltacloud/base_driver/exceptions.rb:151:in `safely' /usr/share/deltacloud-core/bin/../lib/deltacloud/drivers/rhevm/rhevm_driver.rb:150:in `start_instance' /usr/share/deltacloud-core/bin/../lib/deltacloud/helpers/application_helper.rb:128:in `send' /usr/share/deltacloud-core/bin/../lib/deltacloud/helpers/application_helper.rb:128:in `instance_action' /usr/share/deltacloud-core/bin/../server.rb:475 /usr/share/deltacloud-core/bin/../lib/sinatra/rabbit.rb:125:in `instance_eval' /usr/share/deltacloud-core/bin/../lib/sinatra/rabbit.rb:125:in `POST /api/instances/:id/start' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:1057:in `call' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:1057:in `compile!' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:643:in `instance_eval' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:643:in `route_eval' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:627:in `route!' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:675:in `process_route' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:672:in `catch' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:672:in `process_route' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:626:in `route!' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:625:in `each' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:625:in `route!' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:760:in `dispatch!' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:553:in `call!' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:725:in `instance_eval' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:725:in `invoke' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:725:in `catch' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:725:in `invoke' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:553:in `call!' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:538:in `call' /usr/share/deltacloud-core/bin/../lib/sinatra/rack_syslog.rb:48:in `call' /usr/share/deltacloud-core/bin/../lib/sinatra/rack_date.rb:31:in `call' /usr/share/deltacloud-core/bin/../lib/sinatra/rack_accept.rb:149:in `call' /usr/share/deltacloud-core/bin/../lib/sinatra/rack_driver_select.rb:45:in `call' /usr/share/deltacloud-core/bin/../lib/sinatra/rack_matrix_params.rb:102:in `call' /usr/share/deltacloud-core/bin/../lib/sinatra/rack_runtime.rb:36:in `call' /usr/share/deltacloud-core/bin/../lib/sinatra/rack_etag.rb:41:in `call' /usr/lib/ruby/gems/1.8/gems/rack-accept-0.4.3/lib/rack/accept/context.rb:22:in `call' /usr/lib/ruby/gems/1.8/gems/rack-1.3.0/lib/rack/methodoverride.rb:24:in `call' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:1167:in `call' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:1193:in `synchronize' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:1167:in `call' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/connection.rb:84:in `pre_process' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/connection.rb:82:in `catch' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/connection.rb:82:in `pre_process' /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:1060:in `call' /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:1060:in `spawn_threadpool' /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:1057:in `initialize' /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:1057:in `new' /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:1057:in `spawn_threadpool' /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:1049:in `defer' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/connection.rb:54:in `process' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/connection.rb:42:in `receive_data' /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:256:in `run_machine' /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:256:in `run' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/backends/base.rb:61:in `start' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/server.rb:159:in `start' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/controllers/controller.rb:86:in `start' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/runner.rb:185:in `send' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/runner.rb:185:in `run_command' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/runner.rb:151:in `run!' /usr/share/deltacloud-core/bin/deltacloudd:223 /usr/bin/deltacloudd:5:in `load' /usr/bin/deltacloudd:5 /usr/bin/deltacloudd[29749]: Completed in 0.000000 | 0.000000 | 400 | application/xml | http://localhost:3002/api/instances/de3c032f-818d-436e-9664-61a81e9d4e8f/start recreate rhevm_nfs_server: virtlab108.virt.bos.redhat.com rhevm_nfs_export: /export/export_domain rhevm_nfs_mount_point: /mnt/rhevm-nfs rhevm_deltacloud_username: rhevadmin.bos.redhat.com rhevm_deltacloud_password: snip rhevm_deltacloud_provider: https://rhevm30.virt.bos.redhat.com:8443/api catalog entry <deployable name='ce-cmjx3'> <description>auto description</description> <assemblies> <assembly name='testRHEVM' hwp='rhevmHWP'> <image id='7c9aed04-f9f6-4dae-80f1-fac9da659949' build='8f103bfe-e722-4142-9278-ca915756be42' /> </assembly> </assemblies> </deployable>
In RHEV-M when you create a new instance it goes from CREATE -> PENDING -> STOPPED, Conductor is trying to 'start' the new instance when it is in 'PENDING' state. I fixed DC state machine to disable 'start' operation when the instance is in PENDING state. However you still need to check your code. (patch sent to deltacloud-dev list)
recreated... Starting Deltacloud API :: mock :: http://localhost:3002/api /usr/bin/deltacloudd[24564]: >> Thin web server (v1.2.11 codename Bat-Shit Crazy) /usr/bin/deltacloudd[24564]: >> Debugging ON /usr/bin/deltacloudd[24564]: >> Maximum connections set to 1024 /usr/bin/deltacloudd[24564]: >> Listening on localhost:3002, CTRL+C to stop /usr/bin/deltacloudd[24564]: Processing /api (for 127.0.0.1 at Thu Oct 06 18:39:20 -0400 2011) [GET] [Mock] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: Completed in 0.000000 | 0.000000 | 200 | application/xml | http://localhost:3002/api /usr/bin/deltacloudd[24564]: Processing /api (for 127.0.0.1 at Thu Oct 06 18:39:20 -0400 2011) [GET] [RHEVM] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: Completed in 0.000000 | 0.000000 | 200 | application/xml | http://localhost:3002/api /usr/bin/deltacloudd[24564]: Processing /api (for 127.0.0.1 at Thu Oct 06 18:39:21 -0400 2011) [GET] [Mock] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: Completed in 0.000000 | 0.000000 | 200 | application/xml | http://localhost:3002/api /usr/bin/deltacloudd[24564]: Processing /api (for 127.0.0.1 at Thu Oct 06 18:39:21 -0400 2011) [GET] [RHEVM] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: Completed in 0.000000 | 0.000000 | 200 | application/xml | http://localhost:3002/api /usr/bin/deltacloudd[24564]: Processing /api/instances (for 127.0.0.1 at Thu Oct 06 18:39:21 -0400 2011) [POST] [RHEVM] /usr/bin/deltacloudd[24564]: Parameters: {"realm_id"=>"7c8a7614-b950-11e0-86c5-001a4a104801", "name"=>"asdfg2-frontend", "hwp_memory"=>"512", "image_id"=>"4de45618-73f0-4485-8a4f-1c8bbd0785a2", "keyname"=>"", "hwp_id"=>"SERVER", "hwp_cpu"=>"1", "hwp_storage"=>"1"} /usr/bin/deltacloudd[24564]: Provider: https://rhevm30.virt.bos.redhat.com:8443/api /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: Completed in 0.000000 | 0.000000 | 201 | application/xml | http://localhost:3002/api/instances /usr/bin/deltacloudd[24564]: Processing /api (for 127.0.0.1 at Thu Oct 06 18:39:59 -0400 2011) [GET] [Mock] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: Completed in 0.000000 | 0.000000 | 200 | application/xml | http://localhost:3002/api /usr/bin/deltacloudd[24564]: Processing /api (for 127.0.0.1 at Thu Oct 06 18:39:59 -0400 2011) [GET] [RHEVM] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: Completed in 0.000000 | 0.000000 | 200 | application/xml | http://localhost:3002/api /usr/bin/deltacloudd[24564]: Processing /api/instances/167b0675-869b-444c-b9b1-3c7696a3b2d4 (for 127.0.0.1 at Thu Oct 06 18:39:59 -0400 2011) [GET] [RHEVM] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Provider: https://rhevm30.virt.bos.redhat.com:8443/api /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: Completed in 0.383139 | 0.000000 | 200 | application/xml | http://localhost:3002/api/instances/167b0675-869b-444c-b9b1-3c7696a3b2d4 /usr/bin/deltacloudd[24564]: Processing /api (for 127.0.0.1 at Thu Oct 06 18:40:00 -0400 2011) [GET] [Mock] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: Completed in 0.000000 | 0.000000 | 200 | application/xml | http://localhost:3002/api /usr/bin/deltacloudd[24564]: Processing /api (for 127.0.0.1 at Thu Oct 06 18:40:00 -0400 2011) [GET] [RHEVM] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: Completed in 0.000000 | 0.000000 | 200 | application/xml | http://localhost:3002/api /usr/bin/deltacloudd[24564]: Processing /api/instance_states (for 127.0.0.1 at Thu Oct 06 18:40:00 -0400 2011) [GET] [RHEVM] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Provider: https://rhevm30.virt.bos.redhat.com:8443/api /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: Completed in 0.000000 | 0.000000 | 200 | application/xml | http://localhost:3002/api/instance_states /usr/bin/deltacloudd[24564]: Processing /api (for 127.0.0.1 at Thu Oct 06 18:40:00 -0400 2011) [GET] [Mock] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: Completed in 0.000000 | 0.000000 | 200 | application/xml | http://localhost:3002/api /usr/bin/deltacloudd[24564]: Processing /api (for 127.0.0.1 at Thu Oct 06 18:40:00 -0400 2011) [GET] [RHEVM] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: Completed in 0.000000 | 0.000000 | 200 | application/xml | http://localhost:3002/api /usr/bin/deltacloudd[24564]: Processing /api/instances/167b0675-869b-444c-b9b1-3c7696a3b2d4 (for 127.0.0.1 at Thu Oct 06 18:40:00 -0400 2011) [GET] [RHEVM] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Provider: https://rhevm30.virt.bos.redhat.com:8443/api /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: Completed in 0.408241 | 0.000000 | 200 | application/xml | http://localhost:3002/api/instances/167b0675-869b-444c-b9b1-3c7696a3b2d4 /usr/bin/deltacloudd[24564]: Processing /api/instances/167b0675-869b-444c-b9b1-3c7696a3b2d4/start (for 127.0.0.1 at Thu Oct 06 18:40:01 -0400 2011) [POST] [RHEVM] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Provider: https://rhevm30.virt.bos.redhat.com:8443/api /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: RestClient::BadRequest:400 Bad Request /usr/lib/ruby/gems/1.8/gems/rest-client-1.6.1/lib/restclient/abstract_response.rb:48:in `return!' /usr/lib/ruby/gems/1.8/gems/rest-client-1.6.1/lib/restclient/request.rb:220:in `process_result' /usr/lib/ruby/gems/1.8/gems/rest-client-1.6.1/lib/restclient/request.rb:169:in `transmit' /usr/lib/ruby/1.8/net/http.rb:543:in `start' /usr/lib/ruby/gems/1.8/gems/rest-client-1.6.1/lib/restclient/request.rb:166:in `transmit' /usr/lib/ruby/gems/1.8/gems/rest-client-1.6.1/lib/restclient/request.rb:60:in `execute' /usr/lib/ruby/gems/1.8/gems/rest-client-1.6.1/lib/restclient/request.rb:31:in `execute' /usr/lib/ruby/gems/1.8/gems/rest-client-1.6.1/lib/restclient/resource.rb:63:in `post' /usr/share/deltacloud-core/bin/../lib/deltacloud/drivers/rhevm/rhevm_client.rb:79:in `vm_action' /usr/share/deltacloud-core/bin/../lib/deltacloud/drivers/rhevm/rhevm_driver.rb:151:in `start_instance' /usr/share/deltacloud-core/bin/../lib/deltacloud/base_driver/exceptions.rb:151:in `call' /usr/share/deltacloud-core/bin/../lib/deltacloud/base_driver/exceptions.rb:151:in `safely' /usr/share/deltacloud-core/bin/../lib/deltacloud/drivers/rhevm/rhevm_driver.rb:150:in `start_instance' /usr/share/deltacloud-core/bin/../lib/deltacloud/helpers/application_helper.rb:128:in `send' /usr/share/deltacloud-core/bin/../lib/deltacloud/helpers/application_helper.rb:128:in `instance_action' /usr/share/deltacloud-core/bin/../server.rb:475 /usr/share/deltacloud-core/bin/../lib/sinatra/rabbit.rb:125:in `instance_eval' /usr/share/deltacloud-core/bin/../lib/sinatra/rabbit.rb:125:in `POST /api/instances/:id/start' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:1057:in `call' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:1057:in `compile!' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:643:in `instance_eval' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:643:in `route_eval' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:627:in `route!' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:675:in `process_route' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:672:in `catch' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:672:in `process_route' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:626:in `route!' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:625:in `each' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:625:in `route!' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:760:in `dispatch!' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:553:in `call!' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:725:in `instance_eval' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:725:in `invoke' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:725:in `catch' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:725:in `invoke' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:553:in `call!' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:538:in `call' /usr/share/deltacloud-core/bin/../lib/sinatra/rack_syslog.rb:48:in `call' /usr/share/deltacloud-core/bin/../lib/sinatra/rack_date.rb:31:in `call' /usr/share/deltacloud-core/bin/../lib/sinatra/rack_accept.rb:149:in `call' /usr/share/deltacloud-core/bin/../lib/sinatra/rack_driver_select.rb:45:in `call' /usr/share/deltacloud-core/bin/../lib/sinatra/rack_matrix_params.rb:102:in `call' /usr/share/deltacloud-core/bin/../lib/sinatra/rack_runtime.rb:36:in `call' /usr/share/deltacloud-core/bin/../lib/sinatra/rack_etag.rb:41:in `call' /usr/lib/ruby/gems/1.8/gems/rack-accept-0.4.3/lib/rack/accept/context.rb:22:in `call' /usr/lib/ruby/gems/1.8/gems/rack-1.3.0/lib/rack/methodoverride.rb:24:in `call' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:1167:in `call' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:1193:in `synchronize' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:1167:in `call' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/connection.rb:84:in `pre_process' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/connection.rb:82:in `catch' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/connection.rb:82:in `pre_process' /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:1060:in `call' /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:1060:in `spawn_threadpool' /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:1057:in `initialize' /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:1057:in `new' /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:1057:in `spawn_threadpool' /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:1049:in `defer' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/connection.rb:54:in `process' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/connection.rb:42:in `receive_data' /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:256:in `run_machine' /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:256:in `run' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/backends/base.rb:61:in `start' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/server.rb:159:in `start' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/controllers/controller.rb:86:in `start' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/runner.rb:185:in `send' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/runner.rb:185:in `run_command' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/runner.rb:151:in `run!' /usr/share/deltacloud-core/bin/deltacloudd:223 /usr/bin/deltacloudd:5:in `load' /usr/bin/deltacloudd:5 /usr/bin/deltacloudd[24564]: Completed in 0.000000 | 0.000000 | 400 | application/xml | http://localhost:3002/api/instances/167b0675-869b-444c-b9b1-3c7696a3b2d4/start /usr/bin/deltacloudd[24564]: 127.0.0.1 - - [06/Oct/2011 18:40:01] "POST /api/instances/167b0675-869b-444c-b9b1-3c7696a3b2d4/start HTTP/1.1" 400 191 0.8166 /usr/bin/deltacloudd[24564]: Processing /api/instances/167b0675-869b-444c-b9b1-3c7696a3b2d4 (for 127.0.0.1 at Thu Oct 06 18:40:01 -0400 2011) [GET] [RHEVM] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Provider: https://rhevm30.virt.bos.redhat.com:8443/api /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: Completed in 0.341358 | 0.000000 | 200 | application/xml | http://localhost:3002/api/instances/167b0675-869b-444c-b9b1-3c7696a3b2d4 /usr/bin/deltacloudd[24564]: Processing /api/instances/ccf602f7-7ef7-476e-857a-f205956ba95c (for 127.0.0.1 at Thu Oct 06 18:40:02 -0400 2011) [GET] [RHEVM] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Provider: https://rhevm30.virt.bos.redhat.com:8443/api /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: Completed in 0.327879 | 0.000000 | 200 | application/xml | http://localhost:3002/api/instances/ccf602f7-7ef7-476e-857a-f205956ba95c /usr/bin/deltacloudd[24564]: Processing /api/instances/ccf602f7-7ef7-476e-857a-f205956ba95c (for 127.0.0.1 at Thu Oct 06 18:40:02 -0400 2011) [GET] [RHEVM] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Provider: https://rhevm30.virt.bos.redhat.com:8443/api /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: Completed in 0.400129 | 0.000000 | 200 | application/xml | http://localhost:3002/api/instances/ccf602f7-7ef7-476e-857a-f205956ba95c /usr/bin/deltacloudd[24564]: Processing /api (for 127.0.0.1 at Thu Oct 06 18:40:03 -0400 2011) [GET] [Mock] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: Completed in 0.000000 | 0.000000 | 200 | application/xml | http://localhost:3002/api /usr/bin/deltacloudd[24564]: Processing /api (for 127.0.0.1 at Thu Oct 06 18:40:03 -0400 2011) [GET] [RHEVM] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: Completed in 0.000000 | 0.000000 | 200 | application/xml | http://localhost:3002/api /usr/bin/deltacloudd[24564]: Processing /api/instance_states (for 127.0.0.1 at Thu Oct 06 18:40:03 -0400 2011) [GET] [RHEVM] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Provider: https://rhevm30.virt.bos.redhat.com:8443/api /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: Completed in 0.000000 | 0.000000 | 200 | application/xml | http://localhost:3002/api/instance_states /usr/bin/deltacloudd[24564]: Processing /api (for 127.0.0.1 at Thu Oct 06 18:40:03 -0400 2011) [GET] [Mock] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: Completed in 0.000000 | 0.000000 | 200 | application/xml | http://localhost:3002/api /usr/bin/deltacloudd[24564]: Processing /api (for 127.0.0.1 at Thu Oct 06 18:40:03 -0400 2011) [GET] [RHEVM] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: Completed in 0.000000 | 0.000000 | 200 | application/xml | http://localhost:3002/api /usr/bin/deltacloudd[24564]: Processing /api/instances/ccf602f7-7ef7-476e-857a-f205956ba95c (for 127.0.0.1 at Thu Oct 06 18:40:03 -0400 2011) [GET] [RHEVM] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Provider: https://rhevm30.virt.bos.redhat.com:8443/api /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: Completed in 0.361476 | 0.000000 | 200 | application/xml | http://localhost:3002/api/instances/ccf602f7-7ef7-476e-857a-f205956ba95c /usr/bin/deltacloudd[24564]: Processing /api/instances/ccf602f7-7ef7-476e-857a-f205956ba95c/start (for 127.0.0.1 at Thu Oct 06 18:40:03 -0400 2011) [POST] [RHEVM] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Provider: https://rhevm30.virt.bos.redhat.com:8443/api /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: RestClient::BadRequest:400 Bad Request /usr/lib/ruby/gems/1.8/gems/rest-client-1.6.1/lib/restclient/abstract_response.rb:48:in `return!' /usr/lib/ruby/gems/1.8/gems/rest-client-1.6.1/lib/restclient/request.rb:220:in `process_result' /usr/lib/ruby/gems/1.8/gems/rest-client-1.6.1/lib/restclient/request.rb:169:in `transmit' /usr/lib/ruby/1.8/net/http.rb:543:in `start' /usr/lib/ruby/gems/1.8/gems/rest-client-1.6.1/lib/restclient/request.rb:166:in `transmit' /usr/lib/ruby/gems/1.8/gems/rest-client-1.6.1/lib/restclient/request.rb:60:in `execute' /usr/lib/ruby/gems/1.8/gems/rest-client-1.6.1/lib/restclient/request.rb:31:in `execute' /usr/lib/ruby/gems/1.8/gems/rest-client-1.6.1/lib/restclient/resource.rb:63:in `post' /usr/share/deltacloud-core/bin/../lib/deltacloud/drivers/rhevm/rhevm_client.rb:79:in `vm_action' /usr/share/deltacloud-core/bin/../lib/deltacloud/drivers/rhevm/rhevm_driver.rb:151:in `start_instance' /usr/share/deltacloud-core/bin/../lib/deltacloud/base_driver/exceptions.rb:151:in `call' /usr/share/deltacloud-core/bin/../lib/deltacloud/base_driver/exceptions.rb:151:in `safely' /usr/share/deltacloud-core/bin/../lib/deltacloud/drivers/rhevm/rhevm_driver.rb:150:in `start_instance' /usr/share/deltacloud-core/bin/../lib/deltacloud/helpers/application_helper.rb:128:in `send' /usr/share/deltacloud-core/bin/../lib/deltacloud/helpers/application_helper.rb:128:in `instance_action' /usr/share/deltacloud-core/bin/../server.rb:475 /usr/share/deltacloud-core/bin/../lib/sinatra/rabbit.rb:125:in `instance_eval' /usr/share/deltacloud-core/bin/../lib/sinatra/rabbit.rb:125:in `POST /api/instances/:id/start' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:1057:in `call' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:1057:in `compile!' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:643:in `instance_eval' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:643:in `route_eval' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:627:in `route!' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:675:in `process_route' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:672:in `catch' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:672:in `process_route' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:626:in `route!' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:625:in `each' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:625:in `route!' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:760:in `dispatch!' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:553:in `call!' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:725:in `instance_eval' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:725:in `invoke' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:725:in `catch' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:725:in `invoke' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:553:in `call!' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:538:in `call' /usr/share/deltacloud-core/bin/../lib/sinatra/rack_syslog.rb:48:in `call' /usr/share/deltacloud-core/bin/../lib/sinatra/rack_date.rb:31:in `call' /usr/share/deltacloud-core/bin/../lib/sinatra/rack_accept.rb:149:in `call' /usr/share/deltacloud-core/bin/../lib/sinatra/rack_driver_select.rb:45:in `call' /usr/share/deltacloud-core/bin/../lib/sinatra/rack_matrix_params.rb:102:in `call' /usr/share/deltacloud-core/bin/../lib/sinatra/rack_runtime.rb:36:in `call' /usr/share/deltacloud-core/bin/../lib/sinatra/rack_etag.rb:41:in `call' /usr/lib/ruby/gems/1.8/gems/rack-accept-0.4.3/lib/rack/accept/context.rb:22:in `call' /usr/lib/ruby/gems/1.8/gems/rack-1.3.0/lib/rack/methodoverride.rb:24:in `call' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:1167:in `call' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:1193:in `synchronize' /usr/lib/ruby/gems/1.8/gems/sinatra-1.1.2/lib/sinatra/base.rb:1167:in `call' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/connection.rb:84:in `pre_process' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/connection.rb:82:in `catch' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/connection.rb:82:in `pre_process' /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:1060:in `call' /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:1060:in `spawn_threadpool' /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:1057:in `initialize' /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:1057:in `new' /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:1057:in `spawn_threadpool' /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:1049:in `defer' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/connection.rb:54:in `process' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/connection.rb:42:in `receive_data' /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:256:in `run_machine' /usr/lib/ruby/gems/1.8/gems/eventmachine-0.12.10/lib/eventmachine.rb:256:in `run' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/backends/base.rb:61:in `start' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/server.rb:159:in `start' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/controllers/controller.rb:86:in `start' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/runner.rb:185:in `send' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/runner.rb:185:in `run_command' /usr/lib/ruby/gems/1.8/gems/thin-1.2.11/lib/thin/runner.rb:151:in `run!' /usr/share/deltacloud-core/bin/deltacloudd:223 /usr/bin/deltacloudd:5:in `load' /usr/bin/deltacloudd:5 /usr/bin/deltacloudd[24564]: Completed in 0.000000 | 0.000000 | 400 | application/xml | http://localhost:3002/api/instances/ccf602f7-7ef7-476e-857a-f205956ba95c/start /usr/bin/deltacloudd[24564]: 127.0.0.1 - - [06/Oct/2011 18:40:04] "POST /api/instances/ccf602f7-7ef7-476e-857a-f205956ba95c/start HTTP/1.1" 400 191 0.8439 /usr/bin/deltacloudd[24564]: Processing /api/instances/ccf602f7-7ef7-476e-857a-f205956ba95c (for 127.0.0.1 at Thu Oct 06 18:40:04 -0400 2011) [GET] [RHEVM] /usr/bin/deltacloudd[24564]: Parameters: {} /usr/bin/deltacloudd[24564]: Provider: https://rhevm30.virt.bos.redhat.com:8443/api /usr/bin/deltacloudd[24564]: Authentication: Basic /usr/bin/deltacloudd[24564]: Server: thin 1.2.11 codename Bat-Shit Crazy /usr/bin/deltacloudd[24564]: Accept: application/xml /usr/bin/deltacloudd[24564]: Completed in 0.344318 | 0.000000 | 200 | application/xml | http://localhost:3002/api/instances/ccf602f7-7ef7-476e-857a-f205956ba95c
[root@qeblade5 ~]# rpm -qa | egrep 'deltacloud|aeolus' deltacloud-core-ec2-0.5.0-0.2.1317167702git.fc15.noarch rubygem-aeolus-image-0.1.0-3.20111003170706git8f23238.fc15.noarch aeolus-conductor-0.4.0-0.20111005200518gitf9deb7f.fc15.noarch rubygem-deltacloud-client-0.4.0-3.fc15.noarch deltacloud-core-vsphere-0.5.0-0.2.1317167702git.fc15.noarch deltacloud-core-rhevm-0.5.0-0.2.1317167702git.fc15.noarch rubygem-aeolus-cli-0.1.0-3.20111003133323git9451323.fc15.noarch aeolus-conductor-doc-0.4.0-0.20111005200518gitf9deb7f.fc15.noarch aeolus-all-0.4.0-0.20111005200518gitf9deb7f.fc15.noarch deltacloud-core-0.5.0-0.2.1317167702git.fc15.noarch aeolus-configure-2.0.2-4.20111005095819gitaf7e59a.fc15.noarch aeolus-conductor-daemons-0.4.0-0.20111005200518gitf9deb7f.fc15.noarch
So dbomatic continues to try to start the instance from its 'stopped' condition. One bug is that it tries forever to start the instance. However the bug here is that it calls 'start' on the instance and DC gives the backtrace above. The error doesn't seem to be reported to dbomatic/taskomatic/deltacloud client and the instance fails to start.
*** This bug has been marked as a duplicate of bug 744289 ***
removing bugs from tracker as part of 0.6 release