OS controller fails to deploy: Deployment has failed. Error occurred while running method 'deploy'. Inspect Orchestrator logs for the details.

[Igor Marnat]

{"build_id": "2014-04-25_15-35-37", "mirantis": "yes", "build_number": "141", "nailgun_sha": "6b156d7434d0a70efe288cd8064d0ca90fed0737", "production": "prod", "ostf_sha": "134765fcb5a07dce0cd1bb399b2290c988c3c63b", "fuelmain_sha": "9939570720729dce22e635b0b9c9465e9d80661f", "astute_sha": "6e8fa4cc12968d7b468fc590b2f06bb59bf74511", "release": "5.0", "fuellib_sha": "8bc334409296a55e8e5e0252cd973ddfaa393156"}

1. Create new cluster, CentOS, simple mode
2. Enable all the platform products (Sahara, Murano, Ceilometer)
3. Networking - GRE
4. Add 3 nodes, start deployment (virtual box, Linux host)

Deployment of OS controller fails with error:
Deployment has failed. Error occurred while running method 'deploy'. Inspect Orchestrator logs for the details.

Snippet from orchestrator logs:
2014-04-25 13:38:51 ERR
[5356] Error running RPC method deploy: Upload cirros "TestVM" image failed, trace: ["/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/post_deploy_actions/upload_cirros_image.rb:90:in `process'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/post_deploy_actions.rb:29:in `block in process'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/post_deploy_actions.rb:29:in `each'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/post_deploy_actions.rb:29:in `process'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/orchestrator.rb:46:in `deploy'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/server/dispatcher.rb:103:in `deploy'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/server/server.rb:126:in `dispatch_message'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/server/server.rb:89:in `block in dispatch'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/server/task_queue.rb:64:in `call'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/server/task_queue.rb:64:in `block in each'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/server/task_queue.rb:56:in `each'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/server/task_queue.rb:56:in `each'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/server/server.rb:87:in `each_with_index'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/server/server.rb:87:in `dispatch'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/server/server.rb:72:in `block in perform_main_job'"]
2014-04-25 13:38:51 INFO
[5356] Casting message to fuel: {"method"=>"deploy_resp", "args"=>{"task_uuid"=>"ca0da17c-7a1c-4c10-afe4-2d799e6da9ce", "nodes"=>[{"uid"=>"2", "status"=>"error", "error_type"=>"deploy", "role"=>"controller"}]}}
2014-04-25 13:38:51 ERR
[5356] ca0da17c-7a1c-4c10-afe4-2d799e6da9ce: Upload cirros "TestVM" image failed

[Igor Marnat (imarnat)]

Same thing in 142.

[Artem Panchenko (apanchenko-8)]

Reproduced on ISO # 147 (Ubuntu + KVM):

api: '1.0'
astute_sha: 3cffebde1e5452f5dbf8f744c6525fc36c7afbf3
build_id: 2014-04-28_01-00-26
build_number: '147'
fuellib_sha: 10d2775b21102b1dcda00e355cc364895d230236
fuelmain_sha: 68bed4f785ff045be6ef16de19213c9a36a42fce
mirantis: 'yes'
nailgun_sha: 4ad5fe676fd7acac83310e97bc84cfa30f8418b4
ostf_sha: 134765fcb5a07dce0cd1bb399b2290c988c3c63b
production: prod
release: '5.0'

Deployment failed with the following error:

"Error occurred while running method 'deploy'. Inspect Orchestrator logs for the details."

Here is the part of Orchestrator logs:

2014-04-28 10:24:08 ERR
[4882] Error running RPC method deploy: Upload cirros "TestVM" image failed, trace: ["/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/post_deploy_actions/upload_cirros_image.rb:90:in `process'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/post_deploy_actions.rb:29:in `block in process'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/post_deploy_actions.rb:29:in `each'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/post_deploy_actions.rb:29:in `process'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/orchestrator.rb:46:in `deploy'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/server/dispatcher.rb:103:in `deploy'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/server/server.rb:126:in `dispatch_message'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/server/server.rb:89:in `block in dispatch'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/server/task_queue.rb:64:in `call'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/server/task_queue.rb:64:in `block in each'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/server/task_queue.rb:56:in `each'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/server/task_queue.rb:56:in `each'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/server/server.rb:87:in `each_with_index'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/server/server.rb:87:in `dispatch'", "/usr/lib64/ruby/gems/2.1.0/gems/astute-0.0.2/lib/astute/server/server.rb:72:in `block in perform_main_job'"]
2014-04-28 10:24:08 ERR
[4882] f139c4e1-639d-450f-96bf-65cef5c15767: Upload cirros "TestVM" image failed

[Dmitry Ilyin (idv1985)]

This isn't the first bug about Cirros upload failure. How do you achive this? I never saw such an error on any of my deployments.

[Dmitry Ilyin (idv1985)]

2014-04-25T13:38:51 debug: [5356] ca0da17c-7a1c-4c10-afe4-2d799e6da9ce: MC agent 'execute_shell_command', method 'execute', results: {:sender=>"2", :statuscode=>0, :statusmsg=>"OK", :data=>{:stdout=>"", :exit_code=>127, :stderr=>"sh: /usr/bin/glance: No such file or directory\n"}}
2014-04-25T13:38:51 debug: [5356] ca0da17c-7a1c-4c10-afe4-2d799e6da9ce: cmd: /usr/bin/glance -N http://192.168.0.2:5000/v2.0/ -T admin -I admin -K admin image-create --name 'TestVM' --is-public true --container-format='bare' --disk-format='qcow2' --property murano_image_info='{"title": "Murano Demo", "type": "cirros.demo"}' --file '/opt/vm/cirros-x86_64-disk.img'
                                               stdout:
                                               stderr: sh: /usr/bin/glance: No such file or directory

                                               exit code: 127

WHY? There is no glance installed on your controller?

[Dmitry Ilyin (idv1985)]

I don't see glance installation even tried in your logs

[Dmitry Ilyin (idv1985)]

Oh, here it is:
eclare at /etc/puppet/modules/sahara/manifests/api.pp:132 on node node-2.domain.tld
2014-04-25T13:29:21.260955+00:00 err: /usr/lib/ruby/site_ruby/1.8/puppet/resource/catalog.rb:482:in `fail_on_duplicate_type_and_title'

We have duplicate between sahara and nova. Both are trying to set default scheduler.
Sahara's scheduler was added by me in commit ead6485fe08e735ae610f01990a91eb36f4d33f6
And nova's scheduler as added by Sergii Golovatiuk not long ago at 8d4b1a61e0da58af52a110cd667d0ba3d07369f3

This problem will always be with us untill we move to granular architecture that would cancel such influence between project parts.

As for now... I gues there is no need to set nova schedules in Sahara modules and my patch should be removed.

[Dmitry Ilyin (idv1985)]

Here is the fix https://review.openstack.org/#/c/90702/

[Dmitry Ilyin (idv1985)]

This fix by Sergeii is better https://review.openstack.org/#/c/90562/

[Sergii Golovatiuk (sgolovatiuk)]

Reviewed: https://review.openstack.org/90562
Committed: https://git.openstack.org/cgit/stackforge/fuel-library/commit/?id=2fe8e402fbe9d719a190a07b04d1fbff591a7364
Submitter: Jenkins
Branch: master

commit 2fe8e402fbe9d719a190a07b04d1fbff591a7364
Author: Sergii Golovatiuk <email address hidden>
Date: Sat Apr 26 18:45:54 2014 +0000

    Fixes bug in scheduler filter for Sahara

    Introducing schedulers in Nova compute competes with Sahara filters.
    Added logic verifies if Sahara is enabled to add some required filters

    Closes-Bug: 1312790

    Change-Id: I7c74904483ecee8174550c50d9122338e0e38c5a