From 21f7a796ffe09cfb306792c3c50a2729d6a4848b Mon Sep 17 00:00:00 2001 From: Darragh Bailey Date: Sat, 5 Dec 2020 15:24:42 +0000 Subject: [PATCH] Reduce start domain unnecessary domain redefines (#1178) Various checks in the start domain action were accidentally causing a redefine right after initial create. Update to provide debug output when the domain needs to be changed to allow capture of the redefines occurring in the future and to make it easy for the tests to pick up where the redefine was triggered by setting an expectation on the log output. Include a small fix to avoid running strip on what might be a nil object returned for elements without any text attributes. Fix a bug where changes to tpm settings made to the config after an initial domain creation where there was previously no tpm defined, would be ignored. Adds a logger double and updates other tests that trigger log calls. should fix #1176 --- lib/vagrant-libvirt/action/start_domain.rb | 53 +++++++++++++++---- spec/support/libvirt_context.rb | 2 + spec/support/sharedcontext.rb | 4 ++ spec/unit/action/create_domain_spec.rb | 1 + spec/unit/action/start_domain_spec.rb | 27 +++++++++- .../unit/action/start_domain_spec/default.xml | 4 +- .../default_added_tpm_path.xml | 48 +++++++++++++++++ spec/unit/action/wait_till_up_spec.rb | 6 ++- 8 files changed, 130 insertions(+), 15 deletions(-) create mode 100644 spec/unit/action/start_domain_spec/default_added_tpm_path.xml diff --git a/lib/vagrant-libvirt/action/start_domain.rb b/lib/vagrant-libvirt/action/start_domain.rb index 73cfabd..7fa6ab4 100644 --- a/lib/vagrant-libvirt/action/start_domain.rb +++ b/lib/vagrant-libvirt/action/start_domain.rb @@ -43,6 +43,7 @@ module VagrantPlugins bus = disk[:bus] REXML::XPath.each(xml_descr, '/domain/devices/disk[@device="disk"]/target[@dev="' + device + '"]') do |disk_target| next unless disk_target.attributes['bus'] != bus + @logger.debug "disk #{device} bus updated from '#{disk_target.attributes['bus']}' to '#{bus}'" descr_changed = true disk_target.attributes['bus'] = bus disk_target.parent.delete_element("#{disk_target.parent.xpath}/address") @@ -52,6 +53,7 @@ module VagrantPlugins # disk_bus REXML::XPath.each(xml_descr, '/domain/devices/disk[@device="disk"]/target[@dev="vda"]') do |disk_target| next unless disk_target.attributes['bus'] != config.disk_bus + @logger.debug "domain disk bus updated from '#{disk_target.attributes['bus']}' to '#{bus}'" descr_changed = true disk_target.attributes['bus'] = config.disk_bus disk_target.parent.delete_element("#{disk_target.parent.xpath}/address") @@ -61,6 +63,7 @@ module VagrantPlugins unless config.nic_model_type.nil? REXML::XPath.each(xml_descr, '/domain/devices/interface/model') do |iface_model| if iface_model.attributes['type'] != config.nic_model_type + @logger.debug "network type updated from '#{iface_model.attributes['type']}' to '#{config.nic_model_type}'" descr_changed = true iface_model.attributes['type'] = config.nic_model_type end @@ -68,7 +71,9 @@ module VagrantPlugins end # vCpu count - if config.cpus.to_i != libvirt_domain.num_vcpus(0) + vcpus_count = libvirt_domain.num_vcpus(0) + if config.cpus.to_i != vcpus_count + @logger.debug "cpu count updated from '#{vcpus_count}' to '#{config.cpus}'" descr_changed = true REXML::XPath.first(xml_descr, '/domain/vcpu').text = config.cpus end @@ -76,11 +81,13 @@ module VagrantPlugins # cpu_mode cpu = REXML::XPath.first(xml_descr, '/domain/cpu') if cpu.nil? + @logger.debug "cpu_mode updated from not set to '#{config.cpu_mode}'" descr_changed = true cpu = REXML::Element.new('cpu', REXML::XPath.first(xml_descr, '/domain')) cpu.attributes['mode'] = config.cpu_mode else if cpu.attributes['mode'] != config.cpu_mode + @logger.debug "cpu_mode updated from '#{cpu.attributes['mode']}' to '#{config.cpu_mode}'" descr_changed = true cpu.attributes['mode'] = config.cpu_mode end @@ -89,16 +96,19 @@ module VagrantPlugins if config.cpu_mode != 'host-passthrough' cpu_model = REXML::XPath.first(xml_descr, '/domain/cpu/model') if cpu_model.nil? + @logger.debug "cpu_model updated from not set to '#{config.cpu_model}'" descr_changed = true cpu_model = REXML::Element.new('model', REXML::XPath.first(xml_descr, '/domain/cpu')) cpu_model.attributes['fallback'] = 'allow' cpu_model.text = config.cpu_model else - if cpu_model.text.strip != config.cpu_model.strip + if (cpu_model.text or '').strip != config.cpu_model.strip + @logger.debug "cpu_model text updated from #{cpu_model.text} to '#{config.cpu_model}'" descr_changed = true cpu_model.text = config.cpu_model end if cpu_model.attributes['fallback'] != config.cpu_fallback + @logger.debug "cpu_model fallback attribute updated from #{cpu_model.attributes['fallback']} to '#{config.cpu_fallback}'" descr_changed = true cpu_model.attributes['fallback'] = config.cpu_fallback end @@ -107,12 +117,14 @@ module VagrantPlugins svm_feature = REXML::XPath.first(xml_descr, '/domain/cpu/feature[@name="svm"]') if config.nested if vmx_feature.nil? + @logger.debug "nested mode enabled from unset by setting cpu vmx feature" descr_changed = true vmx_feature = REXML::Element.new('feature', REXML::XPath.first(xml_descr, '/domain/cpu')) vmx_feature.attributes['policy'] = 'optional' vmx_feature.attributes['name'] = 'vmx' end if svm_feature.nil? + @logger.debug "nested mode enabled from unset by setting cpu svm feature" descr_changed = true svm_feature = REXML::Element.new('feature', REXML::XPath.first(xml_descr, '/domain/cpu')) svm_feature.attributes['policy'] = 'optional' @@ -120,16 +132,19 @@ module VagrantPlugins end else unless vmx_feature.nil? + @logger.debug "nested mode disabled for cpu by removing vmx feature" descr_changed = true cpu.delete_element(vmx_feature) end unless svm_feature.nil? + @logger.debug "nested mode disabled for cpu by removing svm feature" descr_changed = true cpu.delete_element(svm_feature) end end elsif config.numa_nodes == nil unless cpu.elements.to_a.empty? + @logger.debug "switching cpu_mode to host-passthrough and removing emulated cpu features" descr_changed = true cpu.elements.each do |elem| cpu.delete_element(elem) @@ -183,8 +198,9 @@ module VagrantPlugins tpm = REXML::XPath.first(xml_descr, '/domain/devices/tpm') if tpm.nil? + @logger.debug "tpm created from previously not defined" descr_changed = true - tpm = REXML::Element.new('tpm', REXML::XPath.first(xml_descr, '/domain/devices/tpm/model')) + tpm = REXML::Element.new('tpm', REXML::XPath.first(xml_descr, '/domain/devices')) tpm.attributes['model'] = config.tpm_model tpm_backend_type = tpm.add_element('backend') tpm_backend_type.attributes['type'] = config.tpm_type @@ -192,16 +208,20 @@ module VagrantPlugins tpm_device_path.attributes['path'] = config.tpm_path else if tpm.attributes['model'] != config.tpm_model + @logger.debug "tpm model updated from '#{tpm.attributes['model']}' to '#{config.tpm_model}'" descr_changed = true tpm.attributes['model'] = config.tpm_model end - if tpm.elements['backend'].attributes['type'] != config.tpm_type + backend = tpm.elements['backend'] + if backend.attributes['type'] != config.tpm_type + @logger.debug "tpm type updated from '#{backend.attributes['type']}' to '#{config.tpm_type}'" descr_changed = true - tpm.elements['backend'].attributes['type'] = config.tpm_type + backend.attributes['type'] = config.tpm_type end - if tpm.elements['backend'].elements['device'].attributes['path'] != config.tpm_path + if backend.elements['device'].attributes['path'] != config.tpm_path + @logger.debug "tpm path updated from '#{backend.elements['device'].attributes['path']}' to '#{config.tpm_path}'" descr_changed = true - tpm.elements['backend'].elements['device'].attributes['path'] = config.tpm_path + backend.elements['device'].attributes['path'] = config.tpm_path end end end @@ -210,16 +230,21 @@ module VagrantPlugins video = REXML::XPath.first(xml_descr, '/domain/devices/video') if !video.nil? && (config.graphics_type == 'none') # graphics_type = none, video devices are removed since there is no possible output + @logger.debug "deleting video elements as config.graphics_type is none" descr_changed = true video.parent.delete_element(video) else video_model = REXML::XPath.first(xml_descr, '/domain/devices/video/model') if video_model.nil? + @logger.debug "video updated from not set to type '#{config.video_type}' and vram '#{config.video_vram}'" + descr_changed = true video_model = REXML::Element.new('model', REXML::XPath.first(xml_descr, '/domain/devices/video')) video_model.attributes['type'] = config.video_type video_model.attributes['vram'] = config.video_vram else - if video_model.attributes['type'] != config.video_type || video_model.attributes['vram'] != config.video_vram + if video_model.attributes['type'] != config.video_type || video_model.attributes['vram'] != config.video_vram.to_s + @logger.debug "video type updated from '#{video_model.attributes['type']}' to '#{config.video_type}'" + @logger.debug "video vram updated from '#{video_model.attributes['vram']}' to '#{config.video_vram}'" descr_changed = true video_model.attributes['type'] = config.video_type video_model.attributes['vram'] = config.video_vram @@ -237,11 +262,13 @@ module VagrantPlugins if config.dtb dtb = REXML::XPath.first(xml_descr, '/domain/os/dtb') if dtb.nil? + @logger.debug "dtb updated from not set to '#{config.dtb}'" descr_changed = true dtb = REXML::Element.new('dtb', REXML::XPath.first(xml_descr, '/domain/os')) dtb.text = config.dtb else - if dtb.text != config.dtb + if (dtb.text or '') != config.dtb + @logger.debug "dtb updated from '#{dtb.text}' to '#{config.dtb}'" descr_changed = true dtb.text = config.dtb end @@ -252,11 +279,13 @@ module VagrantPlugins if config.kernel kernel = REXML::XPath.first(xml_descr, '/domain/os/kernel') if kernel.nil? + @logger.debug "kernel updated from not set to '#{config.kernel}'" descr_changed = true kernel = REXML::Element.new('kernel', REXML::XPath.first(xml_descr, '/domain/os')) kernel.text = config.kernel else - if kernel.text != config.kernel + if (kernel.text or '').strip != config.kernel + @logger.debug "kernel updated from '#{kernel.text}' to '#{config.kernel}'" descr_changed = true kernel.text = config.kernel end @@ -265,11 +294,13 @@ module VagrantPlugins if config.initrd initrd = REXML::XPath.first(xml_descr, '/domain/os/initrd') if initrd.nil? + @logger.debug "initrd updated from not set to '#{config.initrd}'" descr_changed = true initrd = REXML::Element.new('initrd', REXML::XPath.first(xml_descr, '/domain/os')) initrd.text = config.initrd else - if initrd.text != config.initrd + if (initrd.text or '').strip != config.initrd + @logger.debug "initrd updated from '#{initrd.text}' to '#{config.initrd}'" descr_changed = true initrd.text = config.initrd end diff --git a/spec/support/libvirt_context.rb b/spec/support/libvirt_context.rb index 68de1c8..fb34116 100644 --- a/spec/support/libvirt_context.rb +++ b/spec/support/libvirt_context.rb @@ -7,6 +7,7 @@ shared_context 'libvirt' do let(:id) { 'dummy-vagrant_dummy' } let(:connection) { double('connection') } let(:domain) { double('domain') } + let(:logger) { double('logger') } def connection_result(options = {}) result = options.fetch(:result, nil) @@ -26,5 +27,6 @@ shared_context 'libvirt' do allow(domain).to receive(:mac).and_return('9C:D5:53:F1:5A:E7') allow(machine).to receive(:id).and_return(id) + allow(Log4r::Logger).to receive(:new).and_return(logger) end end diff --git a/spec/support/sharedcontext.rb b/spec/support/sharedcontext.rb index 264fc3b..1d736e1 100644 --- a/spec/support/sharedcontext.rb +++ b/spec/support/sharedcontext.rb @@ -3,10 +3,14 @@ require 'spec_helper' shared_context 'unit' do include_context 'vagrant-unit' + let(:vagrantfile_providerconfig) { '' } let(:vagrantfile) do <<-EOF Vagrant.configure('2') do |config| config.vm.define :test + config.vm.provider :libvirt do |libvirt| + #{vagrantfile_providerconfig} + end end EOF end diff --git a/spec/unit/action/create_domain_spec.rb b/spec/unit/action/create_domain_spec.rb index dedecde..56c389f 100644 --- a/spec/unit/action/create_domain_spec.rb +++ b/spec/unit/action/create_domain_spec.rb @@ -26,6 +26,7 @@ describe VagrantPlugins::ProviderLibvirt::Action::CreateDomain do allow(connection).to receive(:servers).and_return(servers) allow(connection).to receive(:volumes).and_return(volumes) + allow(logger).to receive(:info) end context 'default pool' do diff --git a/spec/unit/action/start_domain_spec.rb b/spec/unit/action/start_domain_spec.rb index dacccd7..31cc635 100644 --- a/spec/unit/action/start_domain_spec.rb +++ b/spec/unit/action/start_domain_spec.rb @@ -16,6 +16,7 @@ describe VagrantPlugins::ProviderLibvirt::Action::StartDomain do let(:servers) { double('servers') } let(:domain_xml) { File.read(File.join(File.dirname(__FILE__), File.basename(__FILE__, '.rb'), test_file)) } + let(:updated_domain_xml) { File.read(File.join(File.dirname(__FILE__), File.basename(__FILE__, '.rb'), updated_test_file)) } describe '#call' do before do @@ -26,6 +27,7 @@ describe VagrantPlugins::ProviderLibvirt::Action::StartDomain do allow(connection).to receive(:servers).and_return(servers) allow(servers).to receive(:get).and_return(domain) + expect(logger).to receive(:info) end context 'default config' do @@ -38,12 +40,35 @@ describe VagrantPlugins::ProviderLibvirt::Action::StartDomain do allow(libvirt_domain).to receive(:num_vcpus).and_return(1) end - it 'should execute correctly' do + it 'should execute without changing' do + allow(libvirt_domain).to receive(:undefine) + expect(logger).to_not receive(:debug) expect(libvirt_domain).to receive(:autostart=) expect(domain).to receive(:start) expect(subject.call(env)).to be_nil end + + context 'tpm_path added' do + let(:updated_test_file) { 'default_added_tpm_path.xml' } + let(:vagrantfile_providerconfig) do + <<-EOF + libvirt.tpm_path = '/dev/tpm0' + libvirt.tpm_type = 'passthrough' + libvirt.tpm_model = 'tpm-tis' + EOF + end + + it 'should modify the domain tpm_path' do + expect(libvirt_domain).to receive(:undefine) + expect(logger).to receive(:debug).with('tpm created from previously not defined') + expect(servers).to receive(:create).with(xml: updated_domain_xml) + expect(libvirt_domain).to receive(:autostart=) + expect(domain).to receive(:start) + + expect(subject.call(env)).to be_nil + end + end end end end diff --git a/spec/unit/action/start_domain_spec/default.xml b/spec/unit/action/start_domain_spec/default.xml index 1e134c2..4be9d05 100644 --- a/spec/unit/action/start_domain_spec/default.xml +++ b/spec/unit/action/start_domain_spec/default.xml @@ -8,14 +8,14 @@ - + hvm - + diff --git a/spec/unit/action/start_domain_spec/default_added_tpm_path.xml b/spec/unit/action/start_domain_spec/default_added_tpm_path.xml new file mode 100644 index 0000000..3d09012 --- /dev/null +++ b/spec/unit/action/start_domain_spec/default_added_tpm_path.xml @@ -0,0 +1,48 @@ + + + + <description/> + <uuid/> + <memory/> + <vcpu>1</vcpu> + + + <cpu mode='host-model'> + <model fallback='allow'/> + </cpu> + + + <os> + <type>hvm</type> + <kernel/> + <initrd/> + <cmdline/> + </os> + <features> + <acpi/> + <apic/> + <pae/> + </features> + <clock offset='utc'/> + <devices> + + + <serial type='pty'> + <target port='0'/> + </serial> + <console type='pty'> + <target port='0'/> + </console> + + + <input bus='ps2' type='mouse'/> + + <graphics autoport='yes' keymap='en-us' listen='127.0.0.1' port='-1' type='vnc'/> + <video> + <model heads='1' type='cirrus' vram='9216'/> + </video> + + + <tpm model='tpm-tis'><backend type='passthrough'><device path='/dev/tpm0'/></backend></tpm></devices> + +</domain> diff --git a/spec/unit/action/wait_till_up_spec.rb b/spec/unit/action/wait_till_up_spec.rb index 01e9419..a6acf4a 100644 --- a/spec/unit/action/wait_till_up_spec.rb +++ b/spec/unit/action/wait_till_up_spec.rb @@ -41,6 +41,7 @@ describe VagrantPlugins::ProviderLibvirt::Action::WaitTillUp do it 'should exit' do expect(app).to_not receive(:call) expect(ui).to receive(:info).with('Waiting for domain to get an IP address...') + expect(logger).to receive(:debug).with(/Searching for IP for MAC address: .*/) expect(subject.call(env)).to be_nil end end @@ -56,7 +57,6 @@ describe VagrantPlugins::ProviderLibvirt::Action::WaitTillUp do expect(app).to_not receive(:call) expect(ui).to receive(:info).with('Waiting for domain to get an IP address...') expect(ui).to receive(:info).with('Waiting for SSH to become available...') - logger = subject.instance_variable_get(:@logger) expect(logger).to receive(:debug).with(/Searching for IP for MAC address: .*/) expect(logger).to receive(:info).with('Got IP address 192.168.121.2') expect(logger).to receive(:info).with(/Time for getting IP: .*/) @@ -77,6 +77,10 @@ describe VagrantPlugins::ProviderLibvirt::Action::WaitTillUp do expect(app).to receive(:call) expect(ui).to receive(:info).with('Waiting for domain to get an IP address...') expect(ui).to receive(:info).with('Waiting for SSH to become available...') + expect(logger).to receive(:debug).with(/Searching for IP for MAC address: .*/) + expect(logger).to receive(:info).with('Got IP address 192.168.121.2') + expect(logger).to receive(:info).with(/Time for getting IP: .*/) + expect(logger).to receive(:info).with(/Time for SSH ready: .*/) expect(env[:machine].communicate).to receive(:ready?).and_return(true) expect(subject.call(env)).to be_nil end