Scenario:
1. Create cluster
2. Assign compute and virt roles to slave node
3. Upload configuration for two VMs
4. Spawn VMs
Actual:
AssertionError: Task 'spawn_vms' has incorrect status. error != ready, 'Deployment has failed. Check these nodes:
'slave-01_compute_virt''
---
astute log:
'''
2015-10-29T22:24:39 err: [647] Task '{"priority"=>600, "type"=>"puppet", "uids"=>["1", "1"], "parameters"=>{"puppet_modules"=>"/etc/puppet/modules", "puppet_manifest"=>"/etc/puppet/modules/osnailyfacter/modular/generate_vms/generate_vms.pp", "timeout"=>3600, "cwd"=>"/"}}' failed on node 1
'''
puppet-apply lig from node1:
'''
2015-10-29T22:24:36.755330+00:00 debug: (Service[libvirtd](provider=upstart)) Could not find libvirtd.conf in /etc/init
2015-10-29T22:24:36.755330+00:00 debug: (Service[libvirtd](provider=upstart)) Could not find libvirtd.conf in /etc/init.d
2015-10-29T22:24:36.755330+00:00 debug: (Service[libvirtd](provider=upstart)) Could not find libvirtd in /etc/init
2015-10-29T22:24:36.755330+00:00 debug: Executing '/etc/init.d/libvirtd status'
2015-10-29T22:24:36.782141+00:00 info: (/Stage[main]/Main/Service[libvirtd]) Evaluated in 0.03 seconds
2015-10-29T22:24:36.782675+00:00 info: (/Stage[main]/Main/File[/etc/libvirt/qemu/autostart]) Starting to evaluate the resource
2015-10-29T22:24:36.784179+00:00 notice: (/Stage[main]/Main/File[/etc/libvirt/qemu/autostart]/ensure) created
2015-10-29T22:24:36.784648+00:00 debug: (/Stage[main]/Main/File[/etc/libvirt/qemu/autostart]) The container Class[Main] will propagate my refresh event
2015-10-29T22:24:36.785301+00:00 info: (/Stage[main]/Main/File[/etc/libvirt/qemu/autostart]) Evaluated in 0.00 seconds
2015-10-29T22:24:36.785876+00:00 info: (/Stage[main]/Main/Exec[generate_vms]) Starting to evaluate the resource
2015-10-29T22:24:36.786897+00:00 debug: (Exec[generate_vms](provider=posix)) Executing '/usr/bin/generate_vms.sh /etc/libvirt/qemu /var/lib/nova'
2015-10-29T22:24:36.787543+00:00 debug: Executing '/usr/bin/generate_vms.sh /etc/libvirt/qemu /var/lib/nova'
2015-10-29T22:24:37.651600+00:00 notice: (/Stage[main]/Main/Exec[generate_vms]/returns) error: failed to get domain '1_vm'
2015-10-29T22:24:37.652072+00:00 notice: (/Stage[main]/Main/Exec[generate_vms]/returns) error: Domain not found: no domain with matching name '1_vm'
2015-10-29T22:24:37.652745+00:00 notice: (/Stage[main]/Main/Exec[generate_vms]/returns) Disks for 1_vm, total number 1
2015-10-29T22:24:37.652745+00:00 notice: (/Stage[main]/Main/Exec[generate_vms]/returns) Disk id: 1, disk type: file, disk format: qcow2, disk path: /var/lib/nova/1_vm.img, disk size: 60G
2015-10-29T22:24:37.652745+00:00 notice: (/Stage[main]/Main/Exec[generate_vms]/returns) Formatting '/var/lib/nova/1_vm.img', fmt=qcow2 size=64424509440 encryption=off cluster_size=65536 lazy_refcounts=off
2015-10-29T22:24:37.653240+00:00 notice: (/Stage[main]/Main/Exec[generate_vms]/returns) Domain 1_vm defined from /tmp/tmp.uCbNOIyaFY
2015-10-29T22:24:37.653977+00:00 notice: (/Stage[main]/Main/Exec[generate_vms]/returns) error: Failed to start domain 1_vm
2015-10-29T22:24:37.653977+00:00 notice: (/Stage[main]/Main/Exec[generate_vms]/returns) error: internal error: process exited while connecting to monitor: Could not access KVM kernel module: Permission denied
2015-10-29T22:24:37.654500+00:00 notice: (/Stage[main]/Main/Exec[generate_vms]/returns) failed to initialize KVM: Permission denied
2015-10-29T22:24:37.655858+00:00 err: /usr/bin/generate_vms.sh /etc/libvirt/qemu /var/lib/nova returned 1 instead of one of [0]
2015-10-29T22:24:37.655858+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/util/errors.rb:97:in `fail'
2015-10-29T22:24:37.655858+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/type/exec.rb:142:in `sync'
2015-10-29T22:24:37.655858+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:191:in `sync'
2015-10-29T22:24:37.656427+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:128:in `sync_if_needed'
2015-10-29T22:24:37.656427+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:89:in `block in perform_changes'
2015-10-29T22:24:37.656427+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:88:in `each'
2015-10-29T22:24:37.656427+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:88:in `perform_changes'
2015-10-29T22:24:37.656427+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/transaction/resource_harness.rb:20:in `evaluate'
2015-10-29T22:24:37.656427+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/transaction.rb:174:in `apply'
2015-10-29T22:24:37.656427+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/transaction.rb:187:in `eval_resource'
2015-10-29T22:24:37.656427+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/transaction.rb:117:in `call'
2015-10-29T22:24:37.656427+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/transaction.rb:117:in `block (2 levels) in evaluate'
2015-10-29T22:24:37.656427+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/util.rb:327:in `block in thinmark'
2015-10-29T22:24:37.656427+00:00 err: /usr/lib/ruby/1.9.1/benchmark.rb:295:in `realtime'
2015-10-29T22:24:37.656427+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/util.rb:326:in `thinmark'
2015-10-29T22:24:37.656427+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/transaction.rb:117:in `block in evaluate'
2015-10-29T22:24:37.656427+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/graph/relationship_graph.rb:118:in `traverse'
2015-10-29T22:24:37.656427+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/transaction.rb:108:in `evaluate'
2015-10-29T22:24:37.656427+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/resource/catalog.rb:164:in `block in apply'
2015-10-29T22:24:37.656427+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/util/log.rb:149:in `with_destination'
2015-10-29T22:24:37.657383+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/transaction/report.rb:108:in `as_logging_destination'
2015-10-29T22:24:37.657383+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/resource/catalog.rb:163:in `apply'
2015-10-29T22:24:37.657383+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/configurer.rb:125:in `block in apply_catalog'
2015-10-29T22:24:37.657383+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/util.rb:161:in `block in benchmark'
2015-10-29T22:24:37.657383+00:00 err: /usr/lib/ruby/1.9.1/benchmark.rb:295:in `realtime'
2015-10-29T22:24:37.657383+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/util.rb:160:in `benchmark'
2015-10-29T22:24:37.657383+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/configurer.rb:124:in `apply_catalog'
2015-10-29T22:24:37.657383+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/configurer.rb:192:in `run'
2015-10-29T22:24:37.657383+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/application/apply.rb:268:in `apply_catalog'
2015-10-29T22:24:37.657383+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/application/apply.rb:218:in `main'
2015-10-29T22:24:37.657383+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/application/apply.rb:146:in `run_command'
2015-10-29T22:24:37.657383+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/application.rb:364:in `block (2 levels) in run'
2015-10-29T22:24:37.657383+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/application.rb:470:in `plugin_hook'
2015-10-29T22:24:37.657383+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/application.rb:364:in `block in run'
2015-10-29T22:24:37.657383+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/util.rb:478:in `exit_on_fail'
2015-10-29T22:24:37.657383+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/application.rb:364:in `run'
2015-10-29T22:24:37.657383+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/util/command_line.rb:137:in `run'
2015-10-29T22:24:37.657383+00:00 err: /usr/lib/ruby/vendor_ruby/puppet/util/command_line.rb:91:in `execute'
2015-10-29T22:24:37.657383+00:00 err: /usr/bin/puppet:4:in `<main>'
2015-10-29T22:24:37.658324+00:00 err: (/Stage[main]/Main/Exec[generate_vms]/returns) change from notrun to 0 failed: /usr/bin/generate_vms.sh /etc/libvirt/qemu /var/lib/nova returned 1 instead of one of [0]
'''
From the history of test runs I can see that test failed on srv71 but works on srv18, srv19.
Env: 8.0-92
CI server srv71-bud.infra.mirantis.net https://product-ci.infra.mirantis.net/job/8.0.system_test.ubuntu.reduced_footprint/30/testReport/(root)/spawn_two_vms_on_one_virt_node/
This error is generated inside tested environment, it is not problem with kvm on CI slave.
Tests on srv18 and srv19 was executed on other version of ISO and maybe this error is caused by problem with deployment.
Last tests are also broken but executed on other servers. If you need to analyze this problem, please revert broken env and check problem there.