gistfile1.txt

Seeing a problem where after creating a few VMs on RHEV through ComputeResource of Satellite we hit a conflict where further VMs do not get created, creation of VM triggers an immediate deletion which yields an error of "disk locked".


[W] mac 00:1a:4a:16:01:51 is already used by dgao-ose-dep-2-ose-master1.example.com

[I] Removing Compute instance for dgao-ose-dep-3-ose-master1.example.com














2016-03-29 11:37:28 [D]   ^[[1m^[[36mSubnet Load (0.2ms)^[[0m  ^[[1mSELECT "subnets".* FROM "subnets" WHERE "subnets"."id" = 1 ORDER BY vlanid LIMIT 1^[[0m
2016-03-29 11:37:28 [D]   ^[[1m^[[35mSmartProxy Load (0.2ms)^[[0m  SELECT "smart_proxies".* FROM "smart_proxies" WHERE "smart_proxies"."id" = 1 ORDER BY smart_proxies.name LIMIT 1


2016-03-29 11:37:28 [D] Asking https://sat61devg.example.com:9090 for free IP


2016-03-29 11:37:38 [D]   ^[[1m^[[36mHost::Managed Load (0.6ms)^[[0m  ^[[1mSELECT "hosts".* FROM "hosts" WHERE "hosts"."uuid" = '1f325a91-0b7e-42c8-aec3-1ac796c18eec' LIMIT 1^[[0m
2016-03-29 11:37:38 [D]   ^[[1m^[[35mHost::Managed Load (0.3ms)^[[0m  SELECT "hosts".* FROM "hosts" WHERE "hosts"."mac" = '00:1a:4a:16:01:51' LIMIT 1


2016-03-29 11:37:38 [I] Removing Compute instance for dgao-ose-dep-3-ose-master1.example.com
2016-03-29 11:37:39 [W] Failed to destroy a compute dgao_ose_dep_3-RHEV (RHEV) instance dgao-ose-dep-3-ose-master1.example.com: Cannot remove VM: The following disks are locked: dgao-ose-dep-3-ose-master1-example-com_Disk1, dgao-ose-dep-3-ose-master1-example-com_Disk2. Please try again in a few minutes./home/vagrant/.rvm/gems/ruby-1.9.3-p448/gems/rbovirt-0.0.36/lib/rbovirt.rb:210:in `handle_fault'
/home/vagrant/.rvm/gems/ruby-1.9.3-p448/gems/rbovirt-0.0.36/lib/rbovirt.rb:148:in `rescue in http_delete'
/home/vagrant/.rvm/gems/ruby-1.9.3-p448/gems/rbovirt-0.0.36/lib/rbovirt.rb:143:in `http_delete'
/home/vagrant/.rvm/gems/ruby-1.9.3-p448/gems/rbovirt-0.0.36/lib/client/vm_api.rb:133:in `destroy_vm'
/home/dgao/Work/rhci/new/rubygem-fog/lib/fog/ovirt/requests/compute/destroy_vm.rb:7:in `destroy_vm'
/home/dgao/Work/rhci/new/rubygem-fog/lib/fog/ovirt/models/compute/server.rb:111:in `destroy'
/home/dgao/Work/rhci/new/foreman/app/models/compute_resources/foreman/model/ovirt.rb:185:in `destroy_vm'
/home/dgao/Work/rhci/new/foreman/app/models/concerns/orchestration/compute.rb:150:in `delCompute'
/home/dgao/Work/rhci/new/foreman/app/models/concerns/orchestration/compute.rb:115:in `block in setComputeDetails'
/home/dgao/Work/rhci/new/foreman/app/models/concerns/orchestration/compute.rb:107:in `each'
/home/dgao/Work/rhci/new/foreman/app/models/concerns/orchestration/compute.rb:107:in `setComputeDetails'
/home/dgao/Work/rhci/new/foreman/app/models/concerns/orchestration.rb:137:in `execute'
/home/dgao/Work/rhci/new/foreman/app/models/concerns/orchestration.rb:85:in `block in process'
/home/dgao/Work/rhci/new/foreman/app/models/concerns/orchestration.rb:77:in `each'
/home/dgao/Work/rhci/new/foreman/app/models/concerns/orchestration.rb:77:in `process'
/home/dgao/Work/rhci/new/foreman/app/models/concerns/orchestration.rb:18:in `on_save'
/home/vagrant/.rvm/gems/ruby-1.9.3-p448/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:671:in `_run__3908651486669926223__save__868454727812342048__callbacks'
/home/vagrant/.rvm/gems/ruby-1.9.3-p448/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:405:in `__run_callback'
/home/vagrant/.rvm/gems/ruby-1.9.3-p448/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:385:in `_run_save_callbacks'
/home/vagrant/.rvm/gems/ruby-1.9.3-p448/gems/activesupport-3.2.21/lib/active_support/callbacks.rb:81:in `run_callbacks'
/home/vagrant/.rvm/gems/ruby-1.9.3-p448/gems/activerecord-3.2.21/lib/active_record/callbacks.rb:264:in `create_or_update'
/home/vagrant/.rvm/gems/ruby-1.9.3-p448/gems/activerecord-3.2.21/lib/active_record/persistence.rb:84:in `save'
/home/vagrant/.rvm/gems/ruby-1.9.3-p448/gems/activerecord-3.2.21/lib/active_record/validations.rb:50:in `save'



["dgao-ose-dep-2-ose-master1.example.com", "00:1a:4a:16:01:51"]





> hosts.map(&:mac)
 => ["52:54:00:37:73:a0", "52:54:00:b3:df:a4", "52:54:00:aa:d4:6a", "52:54:00:5b:f8:e9", "52:54:00:25:1b:6f", "52:54:00:b6:5d:0e", "00:1a:4a:16:01:51", "52:54:00:c8:ce:29"] 
1.9.3-p448 :012 > hosts.map { |h| [h.name, h.mac]}
 => [["mac5254003773a0.example.com", "52:54:00:37:73:a0"], ["mac525400b3dfa4.example.com", "52:54:00:b3:df:a4"], ["sat61devg.example.com", "52:54:00:aa:d4:6a"], ["mac5254005bf8e9.example.com", "52:54:00:5b:f8:e9"], ["mac525400251b6f.example.com", "52:54:00:25:1b:6f"], ["mac525400b65d0e.example.com", "52:54:00:b6:5d:0e"], ["dgao-ose-dep-2-ose-master1.example.com", "00:1a:4a:16:01:51"], ["mac525400c8ce29.example.com", "52:54:00:c8:ce:29"]] 



https://gitlab.sat.lab.tlv.redhat.com/satellite6/foreman/blob/SATELLITE-6.1.0/app/models/concerns/orchestration/compute.rb#L115





]# grep -r "dgao-ose-dep-2-ose-master1.example.com" *
Binary file candlepin/hornetq/journal/hornetq-data-1.hq matches
dhcpd/dhcpd.leases~:host dgao-ose-dep-2-ose-master1.example.com {
dhcpd/dhcpd.leases~:        supersede host-name = "dgao-ose-dep-2-ose-master1.example.com";
dhcpd/dhcpd.leases:host dgao-ose-dep-2-ose-master1.example.com {
dhcpd/dhcpd.leases:        supersede host-name = "dgao-ose-dep-2-ose-master1.example.com";
Binary file elasticsearch/elasticsearch/nodes/0/indices/katello_katello::system/2/index/_7.cfs matches


# cat dhcpd/dhcpd.leases
host dgao-ose-dep-2-ose-master1.example.com {
  dynamic;
  hardware ethernet 00:1a:4a:16:01:51;
  fixed-address 192.168.52.13;
        supersede server.filename = "pxelinux.0";
        supersede server.next-server = c0:a8:34:0a;
        supersede host-name = "dgao-ose-dep-2-ose-master1.example.com";
}

2016-03-28 23:23:36 [D] Asking https://sat61devg.example.com:9090 for free IP
2016-03-28 23:23:38 [D] Found 192.168.52.13
2016-03-28 23:23:38 [D] Scheduling new DHCP reservations for dgao-ose-dep-2-ose-master1.example.com
2016-03-28 23:23:38 [D] Scheduling new DNS entries
2016-03-28 23:23:38 [I] Adding Compute instance for dgao-ose-dep-2-ose-master1.example.com
2016-03-28 23:23:38 [D]   ^[[1m^[[35mSetting Load (0.8ms)^[[0m  SELECT "settings".* FROM "settings" WHERE "settings"."name" = 'use_shortname_for_vms' ORDER BY name LIMIT 1
2016-03-28 23:23:38 [D] creating VM with the following options: {"name"=>"dgao-ose-dep-2-ose-master1-example-com", "first_boot_dev"=>"network", "quota"=>nil, "start"=>"1", "cluster"=>"00000002-0002-0002-0002-000000000290", "cores"=>2, "memory"=>17179869184, "interfaces_attributes"=>{"new_interfaces"=>{"name"=>"", "network"=>"00000000-0000-0000-0000-000000000009", "delete"=>""}, "0"=>{"name"=>"eth0", "network"=>"00000000-0000-0000-0000-000000000009", "delete"=>""}}, "volumes_attributes"=>{"new_volumes"=>{"size_gb"=>"", "storage_domain"=>"56f5cbc6-e99f-4ec7-b6c4-100279fb0e99", "_delete"=>"", "id"=>"", "preallocate"=>"0"}, "0"=>{"size_gb"=>100, "storage_domain"=>"56f5cbc6-e99f-4ec7-b6c4-100279fb0e99", "_delete"=>"", "id"=>"", "bootable"=>"1", "preallocate"=>"0"}, "1"=>{"size_gb"=>20, "storage_domain"=>"56f5cbc6-e99f-4ec7-b6c4-100279fb0e99", "_delete"=>"", "id"=>"", "preallocate"=>"0"}}}
2016-03-28 23:23:38 [D] String does not start with the prefix 'encrypted-', so Foreman::Model::Ovirt dgao_ose_dep_2-RHEV was not decrypted
2016-03-28 23:23:45 [D]   ^[[1m^[[36mHost::Managed Load (0.6ms)^[[0m  ^[[1mSELECT "hosts".* FROM "hosts" WHERE "hosts"."uuid" = '65c6ce6d-b00e-4a35-b7a8-b99eed5a6bcd' LIMIT 1^[[0m
2016-03-28 23:23:45 [D]   ^[[1m^[[35mHost::Managed Load (0.3ms)^[[0m  SELECT "hosts".* FROM "hosts" WHERE "hosts"."mac" = '00:1a:4a:16:01:51' LIMIT 1
2016-03-28 23:23:45 [I] Create DHCP reservation for dgao-ose-dep-2-ose-master1.example.com-00:1a:4a:16:01:51/192.168.52.13
2016-03-28 23:23:45 [I] Add DNS A record for dgao-ose-dep-2-ose-master1.example.com/192.168.52.13
2016-03-28 23:23:45 [I] Add DNS PTR record for 192.168.52.13/dgao-ose-dep-2-ose-master1.example.com
2016-03-28 23:23:46 [I] Add the TFTP configuration for dgao-ose-dep-2-ose-master1.example.com


2016-03-28 23:37:54 [I] unattended: dgao-ose-dep-2-ose-master1.example.com is Built!


[^[[31mERROR^[[0m ^[[34m2016-03-29 10:20:27^[[0m ^[[36mcp_proxy^[[0m] Errno::EMFILE: Too many open files - getaddrinfo
2016-03-29 10:20:28 [I] Completed 500 Internal Server Error in 423.8ms (Views: 26.2ms | ActiveRecord: 1.0ms)
2016-03-29 10:20:28 [D] With body: {"displayMessage":"Too many open files - /home/dgao/Work/rhci/new/foreman/tmp/cache/authorize_login_delegation20160329-4280-1gzryvg","errors":["Too many open files - /home/dgao/Work/rhci/new/foreman/tmp/cache/authorize_login_delegation20160329-4280-1gzryvg"]}










2016-03-28 23:37:54 [I] Delete the autosign entry for dgao-ose-dep-2-ose-master1.example.com
2016-03-28 23:37:54 [D]   ^[[1m^[[35mHost::Managed Load (0.6ms)^[[0m  SELECT "hosts".* FROM "hosts" WHERE "hosts"."type" IN ('Host::Managed') AND "hosts"."id" = 6 LIMIT 1
2016-03-28 23:37:54 [D]   ^[[1m^[[36m (0.3ms)^[[0m  ^[[1mSELECT MAX("audits"."version") AS max_id FROM "audits" WHERE "audits"."auditable_id" = 6 AND "audits"."auditable_type" = 'Host'^[[0m
2016-03-28 23:37:54 [D]   ^[[1m^[[35mSQL (0.4ms)^[[0m  INSERT INTO "audits" ("action", "associated_id", "associated_name", "associated_type", "auditable_id", "auditable_name", "auditable_type", "audited_changes", "comment", "created_at", "remote_address", "user_id", "user_type", "username", "version") VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13, $14, $15) RETURNING "id"  [["action", "update"], ["associated_id", nil], ["associated_name", nil], ["associated_type", nil], ["auditable_id", 6], ["auditable_name", "dgao-ose-dep-2-ose-master1.example.com"], ["auditable_type", "Host"], ["audited_changes", "---\nbuild:\n- true\n- false\ninstalled_at:\n- \n- 2016-03-29 03:37:54.409039456 Z\nowner_type:\n- \n- User\nowner_id:\n- \n- 2\n"], ["comment", nil], ["created_at", Tue, 29 Mar 2016 03:37:54 UTC +00:00], ["remote_address", "sat61devg.example.com"], ["user_id", nil], ["user_type", nil], ["username", "API Admin"], ["version", 3]]
2016-03-28 23:37:54 [D]   ^[[1m^[[36m (0.4ms)^[[0m  ^[[1mUPDATE "hosts" SET "build" = 'f', "installed_at" = '2016-03-29 03:37:54.409039', "owner_type" = 'User', "owner_id" = 2, "updated_at" = '2016-03-29 03:37:54.668387' WHERE "hosts"."type" IN ('Host::Managed') AND "hosts"."id" = 6^[[0m
2016-03-28 23:37:54 [D]   ^[[1m^[[35m (42.3ms)^[[0m  COMMIT
2016-03-28 23:37:54 [E] undefined method `values_at' for nil:NilClass
2016-03-28 23:37:54 [I] Completed 201 Created in 314.0ms (ActiveRecord: 55.8ms)