Bug #25051
closedCreating an bond interface with slaves results in "Unable to set DHCP entry ([RestClient::Conflict]: 409 Conflict)"
Description
Running Foreman 1.18.2 on CentOS 7.5.1804
When I setup an host with an 802.3ad bond interface and 2 slaves I end up with
Failed to save: Create DHCP Settings for problem_machine.example.local task failed with the following error: ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::Conflict]: 409 Conflict) for proxy https://foreman.example.local:8443/dhcp
Log (a snippet of production log - hopefully enough):
2018-09-27T07:42:10 [I|app|8705b] Processing by ForemanSalt::MinionsController#node as YML 2018-09-27T07:42:10 [I|app|8705b] Parameters: {"id"=>"unrelevant_machine_4.example.local"} 2018-09-27T07:42:10 [I|app|8705b] Current user: foreman_api_admin (administrator) 2018-09-27T07:42:11 [I|app|8705b] Rendering text template 2018-09-27T07:42:11 [I|app|8705b] Rendered text template (0.0ms) 2018-09-27T07:42:11 [I|app|8705b] Completed 200 OK in 337ms (Views: 0.9ms | ActiveRecord: 30.5ms) 2018-09-27T07:42:11 [I|app|] Started POST "/subnets/freeip" for 192.168.1.200 at 2018-09-27 07:42:11 +0200 2018-09-27T07:42:11 [I|app|] Started GET "/interfaces/random_name?mac=A0:36:9F:0E:89:28" for 192.168.1.200 at 2018-09-27 07:42:11 +0200 2018-09-27T07:42:11 [I|app|ea071] Processing by SubnetsController#freeip as JSON 2018-09-27T07:42:11 [I|app|ea071] Parameters: {"subnet_id"=>"2", "host_mac"=>"A0:36:9F:0E:89:28", "taken_ips"=>["10.28.229.152", "10.245.207.73", "", "", ""]} 2018-09-27T07:42:11 [I|app|511dd] Processing by InterfacesController#random_name as */* 2018-09-27T07:42:11 [I|app|511dd] Parameters: {"mac"=>"A0:36:9F:0E:89:28"} 2018-09-27T07:42:11 [I|app|ea071] Current user: localadmin (administrator) 2018-09-27T07:42:11 [I|app|511dd] Current user: localadmin (administrator) 2018-09-27T07:42:11 [I|app|511dd] Completed 200 OK in 13ms (Views: 0.3ms | ActiveRecord: 2.3ms) 2018-09-27T07:42:12 [I|app|] Started GET "/notification_recipients" for 192.168.1.200 at 2018-09-27 07:42:12 +0200 2018-09-27T07:42:12 [I|app|c4f46] Processing by NotificationRecipientsController#index as JSON 2018-09-27T07:42:12 [I|app|c4f46] Current user: localadmin (administrator) 2018-09-27T07:42:12 [I|app|c4f46] Completed 200 OK in 12ms (Views: 0.2ms | ActiveRecord: 1.6ms) 2018-09-27T07:42:13 [I|app|ea071] Completed 200 OK in 2103ms (Views: 0.6ms | ActiveRecord: 3.7ms) 2018-09-27T07:42:14 [I|app|] Started GET "/interfaces/random_name?mac=A0:36:9F:0E:89:28" for 192.168.1.200 at 2018-09-27 07:42:14 +0200 2018-09-27T07:42:14 [I|app|e2a30] Processing by InterfacesController#random_name as */* 2018-09-27T07:42:14 [I|app|e2a30] Parameters: {"mac"=>"A0:36:9F:0E:89:28"} 2018-09-27T07:42:14 [I|app|e2a30] Current user: localadmin (administrator) 2018-09-27T07:42:14 [I|app|e2a30] Completed 200 OK in 13ms (Views: 0.4ms | ActiveRecord: 1.9ms) 2018-09-27T07:42:17 [I|app|] Started GET "/" for 10.28.230.10 at 2018-09-27 07:42:17 +0200 2018-09-27T07:42:17 [I|app|edc6e] Processing by DashboardController#index as */* 2018-09-27T07:42:17 [I|app|edc6e] Redirected to https://foreman.example.local/users/login 2018-09-27T07:42:17 [I|app|edc6e] Filter chain halted as :require_login rendered or redirected 2018-09-27T07:42:17 [I|app|edc6e] Completed 302 Found in 8ms (ActiveRecord: 2.2ms) 2018-09-27T07:42:17 [I|app|] Started GET "/users/login" for 10.28.230.10 at 2018-09-27 07:42:17 +0200 2018-09-27T07:42:17 [I|app|545e6] Processing by UsersController#login as */* 2018-09-27T07:42:17 [I|app|545e6] Rendering users/login.html.erb within layouts/login 2018-09-27T07:42:17 [I|app|545e6] Rendered users/_welcome_box.html.erb (3.3ms) 2018-09-27T07:42:17 [I|app|545e6] Rendered users/login.html.erb within layouts/login (5.2ms) 2018-09-27T07:42:17 [I|app|545e6] Rendering layouts/base.html.erb 2018-09-27T07:42:17 [I|app|545e6] Rendered layouts/base.html.erb (1.7ms) 2018-09-27T07:42:17 [I|app|545e6] Completed 200 OK in 11ms (Views: 8.2ms | ActiveRecord: 0.5ms) 2018-09-27T07:42:32 [I|app|] Started GET "/interfaces/random_name?mac=A0:36:9F:0E:8A:74" for 192.168.1.200 at 2018-09-27 07:42:32 +0200 2018-09-27T07:42:32 [I|app|b1aea] Processing by InterfacesController#random_name as */* 2018-09-27T07:42:32 [I|app|b1aea] Parameters: {"mac"=>"A0:36:9F:0E:8A:74"} 2018-09-27T07:42:32 [I|app|b1aea] Current user: localadmin (administrator) 2018-09-27T07:42:32 [I|app|b1aea] Completed 200 OK in 13ms (Views: 0.3ms | ActiveRecord: 2.1ms) 2018-09-27T07:42:33 [I|app|] Started GET "/notification_recipients" for 192.168.1.200 at 2018-09-27 07:42:33 +0200 2018-09-27T07:42:33 [I|app|5e1d4] Processing by NotificationRecipientsController#index as JSON 2018-09-27T07:42:33 [I|app|5e1d4] Current user: localadmin (administrator) 2018-09-27T07:42:33 [I|app|5e1d4] Completed 200 OK in 10ms (Views: 0.2ms | ActiveRecord: 1.3ms) 2018-09-27T07:42:34 [I|app|] Started POST "/api/hosts/facts" for 10.28.230.253 at 2018-09-27 07:42:34 +0200 2018-09-27T07:42:34 [I|app|6635f] Processing by Api::V2::HostsController#facts as JSON 2018-09-27T07:42:34 [I|app|6635f] Parameters: {"name"=>"unrelevant_machine_1.example.local", "facts"=>"[FILTERED]", "apiv"=>"v2", "host"=>{"name"=>"unrelevant_machine_1.example.local"}} 2018-09-27T07:42:34 [I|app|6635f] Current user: foreman_api_admin (administrator) 2018-09-27T07:42:35 [I|app|6635f] Import facts for 'unrelevant_machine_1.example.local' completed. Added: 0, Updated: 1, Deleted 0 facts 2018-09-27T07:42:35 [W|app|6635f] Not queueing Nic::Managed: ["Identifier has already been taken", "Ip has already been taken"] 2018-09-27T07:42:35 [W|app|6635f] Not queueing Nic::Managed: ["Identifier has already been taken", "Ip has already been taken"] 2018-09-27T07:42:35 [W|app|6635f] Not queueing Nic::Managed: ["Identifier has already been taken", "Ip has already been taken"] 2018-09-27T07:42:35 [W|app|6635f] Saving docker0 NIC for host unrelevant_machine_1.example.local failed, skipping because: 2018-09-27T07:42:35 [W|app|6635f] Identifier has already been taken 2018-09-27T07:42:35 [W|app|6635f] Ip has already been taken 2018-09-27T07:42:35 [I|app|6635f] Completed 201 Created in 362ms (Views: 1.6ms | ActiveRecord: 66.6ms) 2018-09-27T07:42:35 [I|app|] Started GET "/salt/node/unrelevant_machine_1.example.local?format=yml" for 10.28.230.253 at 2018-09-27 07:42:35 +0200 2018-09-27T07:42:35 [I|app|58354] Processing by ForemanSalt::MinionsController#node as YML 2018-09-27T07:42:35 [I|app|58354] Parameters: {"id"=>"unrelevant_machine_1.example.local"} 2018-09-27T07:42:35 [I|app|58354] Current user: foreman_api_admin (administrator) 2018-09-27T07:42:35 [I|app|58354] Rendering text template 2018-09-27T07:42:35 [I|app|58354] Rendered text template (0.0ms) 2018-09-27T07:42:35 [I|app|58354] Completed 200 OK in 316ms (Views: 0.9ms | ActiveRecord: 28.6ms) 2018-09-27T07:42:37 [I|app|] Started POST "/api/hosts/facts" for 10.28.230.253 at 2018-09-27 07:42:37 +0200 2018-09-27T07:42:37 [I|app|aa4fa] Processing by Api::V2::HostsController#facts as JSON 2018-09-27T07:42:37 [I|app|aa4fa] Parameters: {"name"=>"unrelevant_machine_3.example.local", "facts"=>"[FILTERED]", "apiv"=>"v2", "host"=>{"name"=>"unrelevant_machine_3.example.local"}} 2018-09-27T07:42:37 [I|app|aa4fa] Current user: foreman_api_admin (administrator) 2018-09-27T07:42:37 [I|app|aa4fa] Import facts for 'unrelevant_machine_3.example.local' completed. Added: 0, Updated: 1, Deleted 0 facts 2018-09-27T07:42:37 [I|app|aa4fa] Completed 201 Created in 432ms (Views: 1.4ms | ActiveRecord: 88.8ms) 2018-09-27T07:42:37 [I|app|] Started GET "/salt/node/unrelevant_machine_3.example.local?format=yml" for 10.28.230.253 at 2018-09-27 07:42:37 +0200 2018-09-27T07:42:37 [I|app|95984] Processing by ForemanSalt::MinionsController#node as YML 2018-09-27T07:42:37 [I|app|95984] Parameters: {"id"=>"unrelevant_machine_3.example.local"} 2018-09-27T07:42:37 [I|app|95984] Current user: foreman_api_admin (administrator) 2018-09-27T07:42:38 [I|app|95984] Rendering text template 2018-09-27T07:42:38 [I|app|95984] Rendered text template (0.0ms) 2018-09-27T07:42:38 [I|app|95984] Completed 200 OK in 327ms (Views: 0.7ms | ActiveRecord: 28.7ms) 2018-09-27T07:42:40 [I|app|] Started POST "/api/hosts/facts" for 10.28.230.253 at 2018-09-27 07:42:40 +0200 2018-09-27T07:42:40 [I|app|35913] Processing by Api::V2::HostsController#facts as JSON 2018-09-27T07:42:40 [I|app|35913] Parameters: {"name"=>"unrelevant_machine_1.example.local", "facts"=>"[FILTERED]", "apiv"=>"v2", "host"=>{"name"=>"unrelevant_machine_1.example.local"}} 2018-09-27T07:42:40 [I|app|35913] Current user: foreman_api_admin (administrator) 2018-09-27T07:42:40 [I|app|35913] Import facts for 'unrelevant_machine_1.example.local' completed. Added: 0, Updated: 1, Deleted 0 facts 2018-09-27T07:42:40 [W|app|35913] Not queueing Nic::Managed: ["Identifier has already been taken", "Ip has already been taken"] 2018-09-27T07:42:40 [W|app|35913] Not queueing Nic::Managed: ["Identifier has already been taken", "Ip has already been taken"] 2018-09-27T07:42:40 [W|app|35913] Not queueing Nic::Managed: ["Identifier has already been taken", "Ip has already been taken"] 2018-09-27T07:42:40 [W|app|35913] Saving docker0 NIC for host unrelevant_machine_1.example.local failed, skipping because: 2018-09-27T07:42:40 [W|app|35913] Identifier has already been taken 2018-09-27T07:42:40 [W|app|35913] Ip has already been taken 2018-09-27T07:42:40 [I|app|35913] Completed 201 Created in 333ms (Views: 1.4ms | ActiveRecord: 67.4ms) 2018-09-27T07:42:40 [I|app|] Started GET "/salt/node/unrelevant_machine_1.example.local?format=yml" for 10.28.230.253 at 2018-09-27 07:42:40 +0200 2018-09-27T07:42:40 [I|app|bf59b] Processing by ForemanSalt::MinionsController#node as YML 2018-09-27T07:42:40 [I|app|bf59b] Parameters: {"id"=>"unrelevant_machine_1.example.local"} 2018-09-27T07:42:40 [I|app|bf59b] Current user: foreman_api_admin (administrator) 2018-09-27T07:42:40 [I|app|bf59b] Rendering text template 2018-09-27T07:42:40 [I|app|bf59b] Rendered text template (0.0ms) 2018-09-27T07:42:40 [I|app|bf59b] Completed 200 OK in 223ms (Views: 0.9ms | ActiveRecord: 21.3ms) 2018-09-27T07:42:42 [I|app|] Started POST "/hosts" for 192.168.1.200 at 2018-09-27 07:42:42 +0200 2018-09-27T07:42:42 [I|app|103e4] Processing by HostsController#create as */* 2018-09-27T07:42:42 [I|app|103e4] Parameters: {"utf8"=>"✓", "authenticity_token"=>"P0uQsF8bYSklH5d+zHkq8ExZaYsFopZduYkR16czfdKVGWgUd0TxGczHOGlmL5Sx75yQP44IHWTpASLlGy7Z3Q==", "host"=>{"salt_module_ids"=>["", "48"], "name"=>"problem_machine", "hostgroup_id"=>"2", "compute_resource_id"=>"", "compute_profile_id"=>"8", "environment_id"=>"1", "realm_id"=>"1", "salt_environment_id"=>"1", "salt_proxy_id"=>"2", "puppetclass_ids"=>[""], "managed"=>"true", "progress_report_id"=>"[FILTERED]", "type"=>"Host::Managed", "interfaces_attributes"=>{"0"=>{"_destroy"=>"0", "type"=>"Nic::Bond", "mac"=>"A0:36:9F:0E:89:28", "identifier"=>"bond0", "name"=>"problem_machine", "domain_id"=>"1", "subnet_id"=>"2", "ip"=>"10.28.229.217", "ip6"=>"", "managed"=>"1", "primary"=>"1", "provision"=>"0", "mode"=>"802.3ad", "attached_devices"=>"p2p1,p3p1", "bond_options"=>""}, "1"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"BC:30:5B:F5:3F:4C", "identifier"=>"em1", "name"=>"problem_machine", "domain_id"=>"2", "subnet_id"=>"4", "ip"=>"10.245.207.73", "ip6"=>"", "managed"=>"1", "primary"=>"0", "provision"=>"1", "virtual"=>"0", "tag"=>"", "attached_to"=>""}, "2"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"A0:36:9F:0E:89:28", "identifier"=>"p2p1", "name"=>"", "domain_id"=>"", "subnet_id"=>"", "ip"=>"", "ip6"=>"", "managed"=>"1", "primary"=>"0", "provision"=>"0", "virtual"=>"0", "tag"=>"", "attached_to"=>""}, "3"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"A0:36:9F:0E:8A:74", "identifier"=>"p3p1", "name"=>"", "domain_id"=>"", "subnet_id"=>"", "ip"=>"", "ip6"=>"", "managed"=>"1", "primary"=>"0", "provision"=>"0", "virtual"=>"0", "tag"=>"", "attached_to"=>""}}, "architecture_id"=>"1", "operatingsystem_id"=>"4", "provision_method"=>"build", "build"=>"1", "medium_id"=>"10", "ptable_id"=>"413", "pxe_loader"=>"None", "disk"=>"", "root_pass"=>"[FILTERED]", "is_owned_by"=>"4-Users", "enabled"=>"1", "model_id"=>"5", "comment"=>"", "overwrite"=>"false"}} 2018-09-27T07:42:42 [I|app|103e4] Current user: localadmin (administrator) 2018-09-27T07:42:42 [I|app|] Started POST "/api/hosts/facts" for 10.28.230.253 at 2018-09-27 07:42:42 +0200 2018-09-27T07:42:42 [I|app|f4bc6] Processing by Api::V2::HostsController#facts as JSON 2018-09-27T07:42:42 [I|app|f4bc6] Parameters: {"name"=>"unrelevant_machine_3.example.local", "facts"=>"[FILTERED]", "apiv"=>"v2", "host"=>{"name"=>"unrelevant_machine_3.example.local"}} 2018-09-27T07:42:42 [I|app|f4bc6] Current user: foreman_api_admin (administrator) 2018-09-27T07:42:42 [I|app|f4bc6] Import facts for 'unrelevant_machine_3.example.local' completed. Added: 0, Updated: 1, Deleted 0 facts 2018-09-27T07:42:42 [I|app|f4bc6] Completed 201 Created in 534ms (Views: 1.8ms | ActiveRecord: 105.8ms) 2018-09-27T07:42:42 [I|app|] Started GET "/salt/node/unrelevant_machine_3.example.local?format=yml" for 10.28.230.253 at 2018-09-27 07:42:42 +0200 2018-09-27T07:42:42 [I|app|9dfde] Processing by ForemanSalt::MinionsController#node as YML 2018-09-27T07:42:42 [I|app|9dfde] Parameters: {"id"=>"unrelevant_machine_3.example.local"} 2018-09-27T07:42:42 [I|app|9dfde] Current user: foreman_api_admin (administrator) 2018-09-27T07:42:42 [I|app|103e4] Create DHCP reservation problem_machine.example.local-01 for problem_machine.example.local-a0:36:9f:0e:89:28/10.28.229.217 2018-09-27T07:42:42 [I|app|103e4] Create DHCP reservation problem_machine.example.local-02 for problem_machine.example.local-A0:36:9F:0E:89:28/10.28.229.217 2018-09-27T07:42:42 [W|app|103e4] Create DHCP Settings for problem_machine.example.local task failed with the following error: ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::Conflict]: 409 Conflict) for proxy https://foreman.example.local:8443/dhcp | ProxyAPI::ProxyException: ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::Conflict]: 409 Conflict) for proxy https://foreman.example.local:8443/dhcp | /usr/share/foreman/lib/proxy_api/dhcp.rb:89:in `rescue in set' | /usr/share/foreman/lib/proxy_api/dhcp.rb:84:in `set' | /usr/share/foreman/lib/net/dhcp/record.rb:43:in `create' | /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:57:in `block in set_dhcp' | /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:57:in `each' | /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:57:in `all?' | /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:57:in `set_dhcp' | /usr/share/foreman/app/models/concerns/orchestration.rb:222:in `execute' | /usr/share/foreman/app/models/concerns/orchestration.rb:145:in `block in process' | /usr/share/foreman/app/models/concerns/orchestration.rb:137:in `each' | /usr/share/foreman/app/models/concerns/orchestration.rb:137:in `process' | /usr/share/foreman/app/models/concerns/orchestration.rb:44:in `around_save_orchestration' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117:in `block in run_callbacks' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:135:in `run_callbacks' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:827:in `_run_save_callbacks' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/callbacks.rb:336:in `create_or_update' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/persistence.rb:129:in `save' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/validations.rb:44:in `save' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/attribute_methods/dirty.rb:35:in `save' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/transactions.rb:308:in `block (2 levels) in save' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/transactions.rb:384:in `block in with_transaction_returning_status' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/database_statements.rb:235:in `block in transaction' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/transaction.rb:194:in `block in within_new_transaction' | /opt/rh/rh-ruby24/root/usr/share/ruby/monitor.rb:214:in `mon_synchronize' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/transaction.rb:191:in `within_new_transaction' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/database_statements.rb:235:in `transaction' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/transactions.rb:210:in `transaction' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/transactions.rb:381:in `with_transaction_returning_status' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/transactions.rb:308:in `block in save' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/transactions.rb:323:in `rollback_active_record_state!' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/transactions.rb:307:in `save' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/suppressor.rb:42:in `save' | /usr/share/foreman/app/models/concerns/foreman/sti.rb:26:in `save' | /usr/share/foreman/app/controllers/hosts_controller.rb:104:in `create' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal/basic_implicit_render.rb:4:in `send_action' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/abstract_controller/base.rb:186:in `process_action' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal/rendering.rb:30:in `process_action' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/abstract_controller/callbacks.rb:20:in `block in process_action' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:108:in `block in run_callbacks' | /usr/share/foreman/app/controllers/concerns/application_shared.rb:15:in `set_timezone' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117:in `block in run_callbacks' | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117:in `block in run_callbacks' | /usr/share/foreman/app/controllers/concerns/foreman/controller/topbar_sweeper.rb:12:in `set_topbar_sweeper_controller' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117:in `block in run_callbacks' | /opt/theforeman/tfm/root/usr/share/gems/gems/audited-4.7.0/lib/audited/sweeper.rb:14:in `around' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117:in `block in run_callbacks' | /opt/theforeman/tfm/root/usr/share/gems/gems/audited-4.7.0/lib/audited/sweeper.rb:14:in `around' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117:in `block in run_callbacks' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:135:in `run_callbacks' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/abstract_controller/callbacks.rb:19:in `process_action' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal/rescue.rb:20:in `process_action' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/notifications.rb:166:in `block in instrument' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/notifications/instrumenter.rb:21:in `instrument' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/notifications.rb:166:in `instrument' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal/instrumentation.rb:30:in `process_action' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal/params_wrapper.rb:252:in `process_action' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/railties/controller_runtime.rb:22:in `process_action' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/abstract_controller/base.rb:124:in `process' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionview-5.1.6/lib/action_view/rendering.rb:30:in `process' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal.rb:189:in `dispatch' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal.rb:253:in `dispatch' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/routing/route_set.rb:49:in `dispatch' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/routing/route_set.rb:31:in `serve' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/journey/router.rb:50:in `block in serve' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/journey/router.rb:33:in `each' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/journey/router.rb:33:in `serve' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/routing/route_set.rb:844:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.9/lib/apipie/static_dispatcher.rb:65:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.9/lib/apipie/extractor/recorder.rb:136:in `call' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in `call' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in `call' | /usr/share/foreman/lib/middleware/telemetry.rb:9:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.9/lib/apipie/middleware/checksum_in_headers.rb:27:in `call' | /usr/share/foreman/lib/middleware/catch_json_parse_errors.rb:8:in `call' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/etag.rb:25:in `call' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/conditional_get.rb:38:in `call' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/head.rb:12:in `call' | /usr/share/foreman/lib/middleware/logging_context.rb:23:in `call' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/session/abstract/id.rb:232:in `context' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/session/abstract/id.rb:226:in `call' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/cookies.rb:613:in `call' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/callbacks.rb:26:in `block in call' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:97:in `run_callbacks' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/callbacks.rb:24:in `call' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/debug_exceptions.rb:59:in `call' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/show_exceptions.rb:31:in `call' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/railties-5.1.6/lib/rails/rack/logger.rb:36:in `call_app' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/railties-5.1.6/lib/rails/rack/logger.rb:26:in `call' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/sprockets-rails-3.2.1/lib/sprockets/rails/quiet_assets.rb:13:in `call' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/remote_ip.rb:79:in `call' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/request_id.rb:25:in `call' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/method_override.rb:22:in `call' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/runtime.rb:22:in `call' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/cache/strategy/local_cache_middleware.rb:27:in `call' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/executor.rb:12:in `call' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in `call' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/sendfile.rb:111:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/secure_headers-5.0.5/lib/secure_headers/middleware.rb:13:in `call' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/railties-5.1.6/lib/rails/engine.rb:522:in `call' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/railties-5.1.6/lib/rails/railtie.rb:185:in `public_send' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/railties-5.1.6/lib/rails/railtie.rb:185:in `method_missing' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/urlmap.rb:68:in `block in call' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/urlmap.rb:53:in `each' | /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/urlmap.rb:53:in `call' | /usr/share/passenger/phusion_passenger/rack/thread_handler_extension.rb:74:in `process_request' | /usr/share/passenger/phusion_passenger/request_handler/thread_handler.rb:141:in `accept_and_process_next_request' | /usr/share/passenger/phusion_passenger/request_handler/thread_handler.rb:109:in `main_loop' | /usr/share/passenger/phusion_passenger/request_handler.rb:455:in `block (3 levels) in start_threads' | /opt/theforeman/tfm/root/usr/share/gems/gems/logging-2.2.2/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context' 2018-09-27T07:42:42 [W|app|103e4] Rolling back due to a problem: [#<Orchestration::Task:0x00007f69815376f8 @name="Create DHCP Settings for problem_machine.example.local", @id="dhcp_create_a0:36:9f:0e:89:28", @status="failed", @priority=10, @action=[#<Nic::Bond id: nil, mac: "a0:36:9f:0e:89:28", ip: "10.28.229.217", type: "Nic::Bond", name: "problem_machine.example.local", host_id: nil, subnet_id: 2, domain_id: 1, attrs: {}, created_at: nil, updated_at: nil, provider: nil, username: nil, password: nil, virtual: true, link: true, identifier: "bond0", tag: "", attached_to: "", managed: true, mode: "802.3ad", attached_devices: "p2p1,p3p1", bond_options: "", primary: true, provision: false, compute_attributes: {}, ip6: "", subnet6_id: nil>, :set_dhcp], @created=1538026962.5201287, @timestamp=2018-09-27 05:42:42 UTC>] 2018-09-27T07:42:42 [E|app|103e4] Failed to save: Create DHCP Settings for problem_machine.example.local task failed with the following error: ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::Conflict]: 409 Conflict) for proxy https://foreman.example.local:8443/dhcp 2018-09-27T07:42:42 [I|app|103e4] Rendering hosts/new.html.erb within layouts/application 2018-09-27T07:42:42 [I|app|103e4] Rendered hosts/_progress.html.erb (0.3ms) 2018-09-27T07:42:42 [I|app|103e4] Rendered hosts/puppet/_main_tab_fields.html.erb (2.4ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered collection of puppetclasses/_selectedClasses.html.erb [0 times] (0.0ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered collection of puppetclasses/_classes_in_groups.html.erb [0 times] (0.0ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered puppetclasses/_classes.html.erb (0.1ms) 2018-09-27T07:42:43 [I|app|9dfde] Rendering text template 2018-09-27T07:42:43 [I|app|103e4] Rendered puppetclasses/_class_selection.html.erb (42.0ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered hosts/puppet/_puppet_classes_tab.html.erb (42.4ms) 2018-09-27T07:42:43 [I|app|9dfde] Rendered text template (0.0ms) 2018-09-27T07:42:43 [I|app|9dfde] Completed 200 OK in 355ms (Views: 1.0ms | ActiveRecord: 27.1ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered nic/_base_form.html.erb (15.3ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered nic/_provider_specific_form.html.erb (0.1ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered nic/bonds/_bond.html.erb (17.6ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered nic/_base_form.html.erb (12.0ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered nic/_virtual_form.html.erb (1.0ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered nic/_provider_specific_form.html.erb (0.1ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered nic/manageds/_managed.html.erb (14.6ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered nic/_base_form.html.erb (11.8ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered nic/_virtual_form.html.erb (1.0ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered nic/_provider_specific_form.html.erb (0.1ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered nic/manageds/_managed.html.erb (14.1ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered nic/_base_form.html.erb (12.7ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered nic/_virtual_form.html.erb (1.1ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered nic/_provider_specific_form.html.erb (0.1ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered nic/manageds/_managed.html.erb (15.2ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered nic/_base_form.html.erb (12.1ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered nic/_virtual_form.html.erb (1.0ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered nic/_provider_specific_form.html.erb (0.1ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered nic/manageds/_managed.html.erb (14.4ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered hosts/_interfaces.html.erb (78.3ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered common/os_selection/_architecture.html.erb (4.4ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered common/os_selection/_pxe_loader.html.erb (0.7ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered common/os_selection/_operatingsystem.html.erb (8.8ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered hosts/provision_method/build/_form.html.erb (9.9ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered hosts/provision_method/image/_form.html.erb (0.1ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered hosts/_operating_system.html.erb (18.0ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered hosts/_unattended.html.erb (18.3ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered collection of puppetclasses/_class_parameters.html.erb [0 times] (0.0ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered puppetclasses/_classes_parameters.html.erb (8.1ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered common_parameters/_inherited_parameters.html.erb (4.2ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered common_parameters/_parameter.html.erb (11.9ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered common_parameters/_parameters.html.erb (13.9ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered hosts/_form.html.erb (235.2ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered hosts/new.html.erb within layouts/application (235.8ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered layouts/_application_content.html.erb (1.3ms) 2018-09-27T07:42:43 [I|app|103e4] Rendering layouts/base.html.erb 2018-09-27T07:42:43 [I|app|103e4] Rendered home/_org_switcher.html.erb (0.1ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered home/_user_dropdown.html.erb (1.3ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered home/_topbar.html.erb (2.2ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered home/_vertical_menu.html.erb (2.4ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered home/_vertical_menu.html.erb (2.7ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered home/_vertical_menu.html.erb (2.8ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered home/_vertical_menu.html.erb (2.3ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered home/_vertical_menu.html.erb (2.1ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered home/_vertical_menu.html.erb (0.9ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered home/_navbar.html.erb (17.3ms) 2018-09-27T07:42:43 [I|app|103e4] Rendered layouts/base.html.erb (22.9ms) 2018-09-27T07:42:43 [I|app|103e4] Completed 200 OK in 1170ms (Views: 242.8ms | ActiveRecord: 51.2ms) 2018-09-27T07:42:43 [I|app|] Started PUT "/salt/minions/salt_environment_selected" for 192.168.1.200 at 2018-09-27 07:42:43 +0200 2018-09-27T07:42:43 [I|app|7848c] Processing by ForemanSalt::MinionsController#salt_environment_selected as */* 2018-09-27T07:42:43 [I|app|7848c] Parameters: {"utf8"=>"✓", "authenticity_token"=>"6MtdJlhjVnktNR4BmjRKPkpVYwa9ekFl2b/otS14ywRCmaWCcDzGScTtsRYwYvR/6ZCasjbQylyJN9uHkWVvCw==", "host"=>{"salt_module_ids"=>["", "48"], "name"=>"problem_machine", "hostgroup_id"=>"2", "compute_resource_id"=>"", "compute_profile_id"=>"8", "environment_id"=>"1", "realm_id"=>"1", "salt_environment_id"=>"1", "salt_proxy_id"=>"2", "puppetclass_ids"=>[""], "managed"=>"true", "progress_report_id"=>"[FILTERED]", "type"=>"Host::Managed", "interfaces_attributes"=>{"0"=>{"_destroy"=>"0", "type"=>"Nic::Bond", "mac"=>"a0:36:9f:0e:89:28", "identifier"=>"bond0", "name"=>"problem_machine", "domain_id"=>"1", "subnet_id"=>"2", "ip"=>"10.28.229.217", "ip6"=>"", "managed"=>"1", "primary"=>"1", "provision"=>"0", "mode"=>"802.3ad", "attached_devices"=>"p2p1,p3p1", "bond_options"=>""}, "1"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"bc:30:5b:f5:3f:4c", "identifier"=>"em1", "name"=>"problem_machine", "domain_id"=>"2", "subnet_id"=>"4", "ip"=>"10.245.207.73", "ip6"=>"", "managed"=>"1", "primary"=>"0", "provision"=>"1", "virtual"=>"0", "tag"=>"", "attached_to"=>""}, "2"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"a0:36:9f:0e:89:28", "identifier"=>"p2p1", "name"=>"", "domain_id"=>"", "subnet_id"=>"", "ip"=>"", "ip6"=>"", "managed"=>"1", "primary"=>"0", "provision"=>"0", "virtual"=>"0", "tag"=>"", "attached_to"=>""}, "3"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"a0:36:9f:0e:8a:74", "identifier"=>"p3p1", "name"=>"", "domain_id"=>"", "subnet_id"=>"", "ip"=>"", "ip6"=>"", "managed"=>"1", "primary"=>"0", "provision"=>"0", "virtual"=>"0", "tag"=>"", "attached_to"=>""}, "new_interfaces"=>{"_destroy"=>"1", "type"=>"Nic::Managed", "mac"=>"", "identifier"=>"", "name"=>"", "domain_id"=>"", "subnet_id"=>"", "ip"=>"", "ip6"=>"", "managed"=>"1", "primary"=>"0", "provision"=>"0", "virtual"=>"0", "tag"=>"", "attached_to"=>""}}, "architecture_id"=>"1", "operatingsystem_id"=>"4", "provision_method"=>"build", "build"=>"1", "medium_id"=>"10", "ptable_id"=>"413", "pxe_loader"=>"None", "disk"=>"", "root_pass"=>"[FILTERED]", "is_owned_by"=>"4-Users", "enabled"=>"1", "model_id"=>"5", "comment"=>"", "overwrite"=>"false"}, "fakepassword"=>"[FILTERED]", "host_id"=>"undefined"} 2018-09-27T07:42:43 [I|app|7848c] Current user: localadmin (administrator) 2018-09-27T07:42:43 [I|app|7848c] Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_salt-10.1.0/app/views/foreman_salt/salt_modules/_host_tab_pane.html.erb (6.1ms) 2018-09-27T07:42:43 [I|app|7848c] Completed 200 OK in 88ms (Views: 7.2ms | ActiveRecord: 16.0ms) 2018-09-27T07:42:43 [I|app|] Started GET "/notification_recipients" for 192.168.1.200 at 2018-09-27 07:42:43 +0200 2018-09-27T07:42:43 [I|app|f2b62] Processing by NotificationRecipientsController#index as JSON 2018-09-27T07:42:43 [I|app|f2b62] Current user: localadmin (administrator) 2018-09-27T07:42:43 [I|app|f2b62] Completed 200 OK in 10ms (Views: 0.2ms | ActiveRecord: 1.1ms) 2018-09-27T07:42:43 [I|app|] Started GET "/tasks/59966982-06b4-4fee-8477-5ee7f4074654" for 192.168.1.200 at 2018-09-27 07:42:43 +0200 2018-09-27T07:42:43 [I|app|e4d7a] Processing by TasksController#show as */* 2018-09-27T07:42:43 [I|app|e4d7a] Parameters: {"id"=>"59966982-06b4-4fee-8477-5ee7f4074654"} 2018-09-27T07:42:43 [I|app|e4d7a] Current user: localadmin (administrator) 2018-09-27T07:42:43 [I|app|e4d7a] Rendered tasks/_list.html.erb (1.0ms) 2018-09-27T07:42:43 [I|app|e4d7a] Completed 200 OK in 15ms (Views: 1.7ms | ActiveRecord: 2.2ms) 2018-09-27T07:42:44 [I|app|] Started POST "/api/hosts/facts" for 10.28.230.253 at 2018-09-27 07:42:44 +0200 2018-09-27T07:42:44 [I|app|9d47b] Processing by Api::V2::HostsController#facts as JSON 2018-09-27T07:42:44 [I|app|9d47b] Parameters: {"name"=>"unrelevant_machine_2.example.local", "facts"=>"[FILTERED]", "apiv"=>"v2", "host"=>{"name"=>"unrelevant_machine_2.example.local"}} 2018-09-27T07:42:44 [I|app|9d47b] Current user: foreman_api_admin (administrator) 2018-09-27T07:42:44 [I|app|9d47b] Import facts for 'unrelevant_machine_2.example.local' completed. Added: 0, Updated: 1, Deleted 0 facts 2018-09-27T07:42:45 [I|app|9d47b] Completed 201 Created in 418ms (Views: 2.4ms | ActiveRecord: 83.2ms) 2018-09-27T07:42:45 [I|app|] Started GET "/salt/node/unrelevant_machine_2.example.local?format=yml" for 10.28.230.253 at 2018-09-27 07:42:45 +0200 2018-09-27T07:42:45 [I|app|97855] Processing by ForemanSalt::MinionsController#node as YML 2018-09-27T07:42:45 [I|app|97855] Parameters: {"id"=>"unrelevant_machine_2.example.local"} 2018-09-27T07:42:45 [I|app|97855] Current user: foreman_api_admin (administrator) 2018-09-27T07:42:45 [I|app|97855] Rendering text template 2018-09-27T07:42:45 [I|app|97855] Rendered text template (0.0ms) 2018-09-27T07:42:45 [I|app|97855] Completed 200 OK in 320ms (Views: 1.2ms | ActiveRecord: 30.7ms) 2018-09-27T07:42:47 [I|app|] Started POST "/api/hosts/facts" for 10.28.230.253 at 2018-09-27 07:42:47 +0200 2018-09-27T07:42:47 [I|app|d8781] Processing by Api::V2::HostsController#facts as JSON 2018-09-27T07:42:47 [I|app|d8781] Parameters: {"name"=>"unrelevant_machine_2.example.local", "facts"=>"[FILTERED]", "apiv"=>"v2", "host"=>{"name"=>"unrelevant_machine_2.example.local"}} 2018-09-27T07:42:47 [I|app|d8781] Current user: foreman_api_admin (administrator) 2018-09-27T07:42:47 [I|app|d8781] Import facts for 'unrelevant_machine_2.example.local' completed. Added: 0, Updated: 1, Deleted 0 facts 2018-09-27T07:42:47 [I|app|d8781] Completed 201 Created in 456ms (Views: 1.9ms | ActiveRecord: 91.3ms) 2018-09-27T07:42:47 [I|app|] Started GET "/salt/node/unrelevant_machine_2.example.local?format=yml" for 10.28.230.253 at 2018-09-27 07:42:47 +0200 2018-09-27T07:42:47 [I|app|153f5] Processing by ForemanSalt::MinionsController#node as YML 2018-09-27T07:42:47 [I|app|153f5] Parameters: {"id"=>"unrelevant_machine_2.example.local"} 2018-09-27T07:42:47 [I|app|153f5] Current user: foreman_api_admin (administrator) 2018-09-27T07:42:47 [I|app|153f5] Rendering text template 2018-09-27T07:42:47 [I|app|153f5] Rendered text template (0.0ms) 2018-09-27T07:42:47 [I|app|153f5] Completed 200 OK in 358ms (Views: 0.9ms | ActiveRecord: 32.7ms) 2018-09-27T07:42:53 [I|app|] Started GET "/notification_recipients" for 192.168.1.200 at 2018-09-27 07:42:53 +0200 2018-09-27T07:42:53 [I|app|d3d11] Processing by NotificationRecipientsController#index as JSON 2018-09-27T07:42:53 [I|app|d3d11] Current user: localadmin (administrator) 2018-09-27T07:42:53 [I|app|d3d11] Completed 200 OK in 12ms (Views: 0.3ms | ActiveRecord: 1.7ms) 2018-09-27T07:42:59 [I|app|] Started GET "/users/login" for 10.28.230.10 at 2018-09-27 07:42:59 +0200 2018-09-27T07:42:59 [I|app|5cfa9] Processing by UsersController#login as */* 2018-09-27T07:42:59 [I|app|5cfa9] Rendering users/login.html.erb within layouts/login 2018-09-27T07:42:59 [I|app|5cfa9] Rendered users/_welcome_box.html.erb (3.6ms) 2018-09-27T07:42:59 [I|app|5cfa9] Rendered users/login.html.erb within layouts/login (6.0ms) 2018-09-27T07:42:59 [I|app|5cfa9] Rendering layouts/base.html.erb 2018-09-27T07:42:59 [I|app|5cfa9] Rendered layouts/base.html.erb (2.1ms) 2018-09-27T07:42:59 [I|app|5cfa9] Completed 200 OK in 19ms (Views: 9.5ms | ActiveRecord: 2.9ms) 2018-09-27T07:43:00 [I|app|] Started POST "/hosts" for 192.168.1.200 at 2018-09-27 07:43:00 +0200 2018-09-27T07:43:00 [I|app|34b9c] Processing by HostsController#create as */* 2018-09-27T07:43:00 [I|app|34b9c] Parameters: {"utf8"=>"✓", "authenticity_token"=>"6MtdJlhjVnktNR4BmjRKPkpVYwa9ekFl2b/otS14ywRCmaWCcDzGScTtsRYwYvR/6ZCasjbQylyJN9uHkWVvCw==", "host"=>{"salt_module_ids"=>["", "48"], "name"=>"problem_machine", "hostgroup_id"=>"2", "compute_resource_id"=>"", "compute_profile_id"=>"8", "environment_id"=>"1", "realm_id"=>"1", "salt_environment_id"=>"1", "salt_proxy_id"=>"2", "puppetclass_ids"=>[""], "managed"=>"true", "progress_report_id"=>"[FILTERED]", "type"=>"Host::Managed", "interfaces_attributes"=>{"0"=>{"_destroy"=>"0", "type"=>"Nic::Bond", "mac"=>"a0:36:9f:0e:89:28", "identifier"=>"bond0", "name"=>"problem_machine", "domain_id"=>"1", "subnet_id"=>"2", "ip"=>"10.28.229.217", "ip6"=>"", "managed"=>"1", "primary"=>"1", "provision"=>"0", "mode"=>"802.3ad", "attached_devices"=>"p2p1,p3p1", "bond_options"=>""}, "1"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"bc:30:5b:f5:3f:4c", "identifier"=>"em1", "name"=>"problem_machine", "domain_id"=>"2", "subnet_id"=>"4", "ip"=>"10.245.207.73", "ip6"=>"", "managed"=>"1", "primary"=>"0", "provision"=>"1", "virtual"=>"0", "tag"=>"", "attached_to"=>""}, "2"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"a0:36:9f:0e:89:28", "identifier"=>"p2p1", "name"=>"", "domain_id"=>"", "subnet_id"=>"", "ip"=>"", "ip6"=>"", "managed"=>"1", "primary"=>"0", "provision"=>"0", "virtual"=>"0", "tag"=>"", "attached_to"=>""}, "3"=>{"_destroy"=>"0", "type"=>"Nic::Managed", "mac"=>"a0:36:9f:0e:8a:74", "identifier"=>"p3p1", "name"=>"", "domain_id"=>"", "subnet_id"=>"", "ip"=>"", "ip6"=>"", "managed"=>"1", "primary"=>"0", "provision"=>"0", "virtual"=>"0", "tag"=>"", "attached_to"=>""}}, "architecture_id"=>"1", "operatingsystem_id"=>"4", "provision_method"=>"build", "build"=>"1", "medium_id"=>"10", "ptable_id"=>"413", "pxe_loader"=>"None", "disk"=>"", "root_pass"=>"[FILTERED]", "is_owned_by"=>"4-Users", "enabled"=>"1", "model_id"=>"5", "comment"=>"", "overwrite"=>"false"}} 2018-09-27T07:43:00 [I|app|34b9c] Current user: localadmin (administrator) 2018-09-27T07:43:01 [I|app|34b9c] Create DHCP reservation problem_machine.example.local-01 for problem_machine.example.local-a0:36:9f:0e:89:28/10.28.229.217 2018-09-27T07:43:01 [I|app|34b9c] Create DHCP reservation problem_machine.example.local-02 for problem_machine.example.local-a0:36:9f:0e:8a:74/10.28.229.217 2018-09-27T07:43:01 [I|app|34b9c] Add DNS A record for problem_machine.example.local/10.28.229.217 2018-09-27T07:43:02 [I|app|34b9c] Add DNS PTR record for 10.28.229.217/problem_machine.example.local 2018-09-27T07:43:02 [I|app|34b9c] Create DHCP reservation problem_machine.prov.example.local for problem_machine.prov.example.local-bc:30:5b:f5:3f:4c/10.245.207.73 2018-09-27T07:43:02 [I|app|34b9c] Add DNS A record for problem_machine.prov.example.local/10.245.207.73 2018-09-27T07:43:02 [I|app|34b9c] Add DNS PTR record for 10.245.207.73/problem_machine.prov.example.local 2018-09-27T07:43:02 [I|tem|34b9c] Rendering template 'Kickstart default PXELinux' 2018-09-27T07:43:02 [I|blo|34b9c] Unattended render of 'Kickstart default PXELinux' = '7e1ca8b87cc39d5d0b494b9a01c9f4ebf679d711f3f059563842c1fb5a36d17e' | | # | # This file was deployed via 'Kickstart default PXELinux' template | # | # Supported host/hostgroup parameters: | # | # blacklist = module1, module2 | # Blacklisted kernel modules | # | | DEFAULT linux | | LABEL linux | KERNEL boot/CentOS-7.5.1804-x86_64-vmlinuz | APPEND initrd=boot/CentOS-7.5.1804-x86_64-initrd.img ks=http://foreman.example.local/unattended/provision network ks.sendmac | IPAPPEND 2 | 2018-09-27T07:43:02 [I|app|34b9c] Deploying TFTP PXELinux configuration for problem_machine.example.local 2018-09-27T07:43:02 [I|app|34b9c] Skipping TFTP PXEGrub2 configuration for problem_machine.example.local 2018-09-27T07:43:02 [I|app|34b9c] Skipping TFTP PXEGrub configuration for problem_machine.example.local 2018-09-27T07:43:02 [I|app|34b9c] Fetching required TFTP boot files for problem_machine.example.local 2018-09-27T07:43:02 [I|app|] Started GET "/tasks/59966982-06b4-4fee-8477-5ee7f4074654" for 192.168.1.200 at 2018-09-27 07:43:02 +0200 2018-09-27T07:43:02 [I|app|5510d] Processing by TasksController#show as */* 2018-09-27T07:43:02 [I|app|5510d] Parameters: {"id"=>"59966982-06b4-4fee-8477-5ee7f4074654"} 2018-09-27T07:43:02 [I|app|5510d] Current user: localadmin (administrator) 2018-09-27T07:43:02 [I|app|5510d] Rendered tasks/_list.html.erb (0.8ms) 2018-09-27T07:43:02 [I|app|5510d] Completed 200 OK in 10ms (Views: 1.3ms | ActiveRecord: 1.5ms) 2018-09-27T07:43:02 [I|app|34b9c] Add realm entry for new host problem_machine.example.local 2018-09-27T07:43:02 [I|app|34b9c] Processed 11 tasks from queue 'Host::Managed Main', completed 11/11 2018-09-27T07:43:03 [I|aud|34b9c] create event for Nic::Bond with id 820 2018-09-27T07:43:03 [I|aud|34b9c] create event for Nic::Managed with id 821 2018-09-27T07:43:03 [I|aud|34b9c] create event for Nic::Managed with id 822 2018-09-27T07:43:03 [I|aud|34b9c] create event for Nic::Managed with id 823 2018-09-27T07:43:03 [I|aud|34b9c] create event for Host::Base with id 282 2018-09-27T07:43:03 [I|app|] Started GET "/notification_recipients" for 192.168.1.200 at 2018-09-27 07:43:03 +0200 2018-09-27T07:43:03 [I|app|bf595] Processing by NotificationRecipientsController#index as JSON 2018-09-27T07:43:03 [I|app|bf595] Current user: localadmin (administrator) 2018-09-27T07:43:03 [I|app|bf595] Completed 200 OK in 13ms (Views: 0.4ms | ActiveRecord: 2.1ms) 2018-09-27T07:43:03 [I|app|34b9c] Redirected to https://foreman.example.local/hosts/problem_machine.example.local 2018-09-27T07:43:03 [I|app|34b9c] Completed 302 Found in 2732ms (ActiveRecord: 107.2ms) 2018-09-27T07:43:03 [I|app|] Started POST "/api/hosts/facts" for 10.28.230.253 at 2018-09-27 07:43:03 +0200 2018-09-27T07:43:03 [I|app|] Started GET "/hosts/problem_machine.example.local" for 192.168.1.200 at 2018-09-27 07:43:03 +0200 2018-09-27T07:43:03 [I|app|e4f70] Processing by Api::V2::HostsController#facts as JSON 2018-09-27T07:43:03 [I|app|e4f70] Parameters: {"name"=>"unrelevant_machine_3.example.local", "facts"=>"[FILTERED]", "apiv"=>"v2", "host"=>{"name"=>"unrelevant_machine_3.example.local"}} 2018-09-27T07:43:03 [I|app|4de62] Processing by HostsController#show as */* 2018-09-27T07:43:03 [I|app|4de62] Parameters: {"id"=>"problem_machine.example.local"} 2018-09-27T07:43:03 [I|app|4de62] Current user: localadmin (administrator) 2018-09-27T07:43:03 [I|app|e4f70] Current user: foreman_api_admin (administrator) 2018-09-27T07:43:03 [I|app|4de62] Rendering hosts/show.html.erb within layouts/application 2018-09-27T07:43:03 [I|app|4de62] Rendered hosts/show.html.erb within layouts/application (40.4ms) 2018-09-27T07:43:03 [I|app|4de62] Rendered layouts/_application_content.html.erb (1.9ms) 2018-09-27T07:43:03 [I|app|4de62] Rendering layouts/base.html.erb 2018-09-27T07:43:03 [I|app|4de62] Rendered home/_org_switcher.html.erb (0.9ms) 2018-09-27T07:43:03 [I|app|4de62] Rendered home/_user_dropdown.html.erb (2.8ms) 2018-09-27T07:43:03 [I|app|4de62] Rendered home/_topbar.html.erb (6.8ms) 2018-09-27T07:43:03 [I|app|4de62] Rendered home/_vertical_menu.html.erb (4.8ms) 2018-09-27T07:43:03 [I|app|4de62] Rendered home/_vertical_menu.html.erb (3.4ms) 2018-09-27T07:43:03 [I|app|4de62] Rendered home/_vertical_menu.html.erb (3.6ms) 2018-09-27T07:43:03 [I|app|4de62] Rendered home/_vertical_menu.html.erb (2.8ms) 2018-09-27T07:43:03 [I|app|4de62] Rendered home/_vertical_menu.html.erb (2.4ms) 2018-09-27T07:43:03 [I|app|4de62] Rendered home/_vertical_menu.html.erb (1.0ms) 2018-09-27T07:43:03 [I|app|4de62] Rendered home/_navbar.html.erb (24.7ms) 2018-09-27T07:43:03 [I|app|4de62] Rendered layouts/base.html.erb (38.6ms) 2018-09-27T07:43:03 [I|app|4de62] Completed 200 OK in 108ms (Views: 80.7ms | ActiveRecord: 8.1ms) 2018-09-27T07:43:04 [I|app|e4f70] Import facts for 'unrelevant_machine_3.example.local' completed. Added: 0, Updated: 1, Deleted 0 facts 2018-09-27T07:43:04 [I|app|e4f70] Completed 201 Created in 492ms (Views: 1.5ms | ActiveRecord: 96.6ms) 2018-09-27T07:43:04 [I|app|] Started GET "/salt/node/unrelevant_machine_3.example.local?format=yml" for 10.28.230.253 at 2018-09-27 07:43:04 +0200 2018-09-27T07:43:04 [I|app|34357] Processing by ForemanSalt::MinionsController#node as YML 2018-09-27T07:43:04 [I|app|34357] Parameters: {"id"=>"unrelevant_machine_3.example.local"} 2018-09-27T07:43:04 [I|app|34357] Current user: foreman_api_admin (administrator) 2018-09-27T07:43:04 [I|app|34357] Rendering text template 2018-09-27T07:43:04 [I|app|34357] Rendered text template (0.0ms) 2018-09-27T07:43:04 [I|app|34357] Completed 200 OK in 341ms (Views: 0.9ms | ActiveRecord: 25.1ms) 2018-09-27T07:43:06 [I|app|] Started POST "/api/hosts/facts" for 10.28.230.253 at 2018-09-27 07:43:06 +0200 2018-09-27T07:43:06 [I|app|f05b6] Processing by Api::V2::HostsController#facts as JSON 2018-09-27T07:43:06 [I|app|f05b6] Parameters: {"name"=>"unrelevant_machine_3.example.local", "facts"=>"[FILTERED]", "apiv"=>"v2", "host"=>{"name"=>"unrelevant_machine_3.example.local"}} 2018-09-27T07:43:06 [I|app|f05b6] Current user: foreman_api_admin (administrator) 2018-09-27T07:43:07 [I|app|f05b6] Import facts for 'unrelevant_machine_3.example.local' completed. Added: 0, Updated: 1, Deleted 0 facts 2018-09-27T07:43:07 [I|app|f05b6] Completed 201 Created in 423ms (Views: 1.2ms | ActiveRecord: 82.3ms) 2018-09-27T07:43:07 [I|app|] Started GET "/salt/node/unrelevant_machine_3.example.local?format=yml" for 10.28.230.253 at 2018-09-27 07:43:07 +0200 2018-09-27T07:43:07 [I|app|14b17] Processing by ForemanSalt::MinionsController#node as YML 2018-09-27T07:43:07 [I|app|14b17] Parameters: {"id"=>"unrelevant_machine_3.example.local"} 2018-09-27T07:43:07 [I|app|14b17] Current user: foreman_api_admin (administrator) 2018-09-27T07:43:07 [I|app|] Started GET "/hosts" for 192.168.1.200 at 2018-09-27 07:43:07 +0200 2018-09-27T07:43:07 [I|app|7ce19] Processing by HostsController#index as HTML 2018-09-27T07:43:07 [I|app|7ce19] Current user: localadmin (administrator) 2018-09-27T07:43:07 [I|app|7ce19] Rendering hosts/index.html.erb within layouts/application 2018-09-27T07:43:07 [I|app|14b17] Rendering text template 2018-09-27T07:43:07 [I|app|14b17] Rendered text template (0.0ms) 2018-09-27T07:43:07 [I|app|14b17] Completed 200 OK in 384ms (Views: 0.9ms | ActiveRecord: 24.9ms) 2018-09-27T07:43:07 [I|app|7ce19] Rendered common/_pagination.html.erb (1.7ms) 2018-09-27T07:43:07 [I|app|7ce19] Rendered hosts/_list.html.erb (498.2ms) 2018-09-27T07:43:07 [I|app|7ce19] Rendered hosts/index.html.erb within layouts/application (516.9ms) 2018-09-27T07:43:07 [I|app|7ce19] Rendered common/_searchbar.html.erb (1.4ms) 2018-09-27T07:43:07 [I|app|7ce19] Rendered layouts/_application_content.html.erb (2.5ms) 2018-09-27T07:43:07 [I|app|7ce19] Rendering layouts/base.html.erb 2018-09-27T07:43:07 [I|app|7ce19] Rendered home/_org_switcher.html.erb (0.1ms) 2018-09-27T07:43:07 [I|app|7ce19] Rendered home/_user_dropdown.html.erb (1.0ms) 2018-09-27T07:43:07 [I|app|7ce19] Rendered home/_topbar.html.erb (1.8ms) 2018-09-27T07:43:07 [I|app|7ce19] Rendered home/_vertical_menu.html.erb (2.1ms) 2018-09-27T07:43:07 [I|app|7ce19] Rendered home/_vertical_menu.html.erb (2.1ms) 2018-09-27T07:43:07 [I|app|7ce19] Rendered home/_vertical_menu.html.erb (2.4ms) 2018-09-27T07:43:07 [I|app|7ce19] Rendered home/_vertical_menu.html.erb (1.7ms) 2018-09-27T07:43:07 [I|app|7ce19] Rendered home/_vertical_menu.html.erb (1.8ms) 2018-09-27T07:43:07 [I|app|7ce19] Rendered home/_vertical_menu.html.erb (0.7ms) 2018-09-27T07:43:07 [I|app|7ce19] Rendered home/_navbar.html.erb (14.0ms) 2018-09-27T07:43:07 [I|app|7ce19] Rendered layouts/base.html.erb (18.9ms) 2018-09-27T07:43:07 [I|app|7ce19] Completed 200 OK in 695ms (Views: 527.7ms | ActiveRecord: 60.7ms) 2018-09-27T07:43:07 [I|app|] Started GET "/hosts" for 192.168.1.200 at 2018-09-27 07:43:07 +0200 2018-09-27T07:43:07 [I|app|6d4e2] Processing by HostsController#index as HTML 2018-09-27T07:43:07 [I|app|6d4e2] Current user: localadmin (administrator) 2018-09-27T07:43:08 [I|app|6d4e2] Rendering hosts/index.html.erb within layouts/application 2018-09-27T07:43:08 [I|app|6d4e2] Rendered common/_pagination.html.erb (0.6ms) 2018-09-27T07:43:08 [I|app|6d4e2] Rendered hosts/_list.html.erb (453.2ms) 2018-09-27T07:43:08 [I|app|6d4e2] Rendered hosts/index.html.erb within layouts/application (464.7ms) 2018-09-27T07:43:08 [I|app|6d4e2] Rendered common/_searchbar.html.erb (0.5ms) 2018-09-27T07:43:08 [I|app|6d4e2] Rendered layouts/_application_content.html.erb (1.4ms) 2018-09-27T07:43:08 [I|app|6d4e2] Rendering layouts/base.html.erb 2018-09-27T07:43:08 [I|app|6d4e2] Rendered home/_org_switcher.html.erb (0.1ms) 2018-09-27T07:43:08 [I|app|6d4e2] Rendered home/_user_dropdown.html.erb (0.9ms) 2018-09-27T07:43:08 [I|app|6d4e2] Rendered home/_topbar.html.erb (1.5ms) 2018-09-27T07:43:08 [I|app|6d4e2] Rendered home/_vertical_menu.html.erb (1.8ms) 2018-09-27T07:43:08 [I|app|6d4e2] Rendered home/_vertical_menu.html.erb (1.8ms) 2018-09-27T07:43:08 [I|app|6d4e2] Rendered home/_vertical_menu.html.erb (2.1ms) 2018-09-27T07:43:08 [I|app|6d4e2] Rendered home/_vertical_menu.html.erb (1.4ms) 2018-09-27T07:43:08 [I|app|6d4e2] Rendered home/_vertical_menu.html.erb (1.5ms) 2018-09-27T07:43:08 [I|app|6d4e2] Rendered home/_vertical_menu.html.erb (0.6ms) 2018-09-27T07:43:08 [I|app|6d4e2] Rendered home/_navbar.html.erb (12.0ms) 2018-09-27T07:43:08 [I|app|6d4e2] Rendered layouts/base.html.erb (16.2ms) 2018-09-27T07:43:08 [I|app|6d4e2] Completed 200 OK in 596ms (Views: 477.5ms | ActiveRecord: 33.1ms) 2018-09-27T07:43:09 [I|app|] Started GET "/notification_recipients" for 192.168.1.200 at 2018-09-27 07:43:09 +0200 2018-09-27T07:43:09 [I|app|bb0cc] Processing by NotificationRecipientsController#index as JSON 2018-09-27T07:43:09 [I|app|bb0cc] Current user: localadmin (administrator) 2018-09-27T07:43:09 [I|app|bb0cc] Completed 200 OK in 12ms (Views: 0.3ms | ActiveRecord: 1.6ms) 2018-09-27T07:43:09 [I|app|] Started GET "/api/bookmarks?search=controller%3Dhosts&per_page=100" for 192.168.1.200 at 2018-09-27 07:43:09 +0200 2018-09-27T07:43:09 [I|app|735d5] Processing by Api::V2::BookmarksController#index as JSON 2018-09-27T07:43:09 [I|app|735d5] Parameters: {"search"=>"controller=hosts", "per_page"=>"100", "apiv"=>"v2"} 2018-09-27T07:43:09 [I|app|735d5] Current user: localadmin (administrator) 2018-09-27T07:43:09 [I|app|735d5] Rendering api/v2/bookmarks/index.json.rabl within api/v2/layouts/index_layout 2018-09-27T07:43:09 [I|app|] Started GET "/hosts/244/power" for 192.168.1.200 at 2018-09-27 07:43:09 +0200 2018-09-27T07:43:09 [I|app|735d5] Rendered api/v2/bookmarks/index.json.rabl within api/v2/layouts/index_layout (6.6ms) 2018-09-27T07:43:09 [I|app|735d5] Completed 200 OK in 22ms (Views: 8.8ms | ActiveRecord: 3.4ms) 2018-09-27T07:43:09 [I|app|5066f] Processing by HostsController#get_power_state as JSON 2018-09-27T07:43:09 [I|app|5066f] Parameters: {"id"=>"244"} 2018-09-27T07:43:09 [I|app|] Started GET "/hosts/243/power" for 192.168.1.200 at 2018-09-27 07:43:09 +0200 2018-09-27T07:43:09 [I|app|] Started GET "/hosts/245/power" for 192.168.1.200 at 2018-09-27 07:43:09 +0200
Right after 2018-09-27T07:42:42 in the log I removed the following config (nothing more was generated for problem_machine.example.local);
vim /var/lib/dhcpd/dhcpd.leases ... host problem_machine.example.local-01 { dynamic; hardware ethernet a0:36:9f:0e:89:28; fixed-address 10.28.229.191; supersede host-name = "problem_machine.example.local"; }
Restart DHCPD
$ systemctl restart dhcpd
Hit submit in Foreman UI again - log @ 2018-09-27T07:43:00 (see above)
DHCP config successfully created;
cat /var/lib/dhcpd/dhcpd.leases ... host problem_machine.example.local-01 { dynamic; hardware ethernet a0:36:9f:0e:89:28; fixed-address 10.28.229.191; supersede host-name = "problem_machine.example.local"; } host problem_machine.example.local-02 { dynamic; hardware ethernet a0:36:9f:0e:8a:74; fixed-address 10.28.229.191; supersede host-name = "problem_machine.example.local"; } host problem_machine.prov.example.local { dynamic; hardware ethernet bc:30:5b:f5:3f:4c; fixed-address 10.245.207.77; supersede server.next-server = 0a:1c:e6:fc; supersede host-name = "problem_machine.prov.example.local"; }
Updated by Anonymous about 6 years ago
Forgot to add that it works after doing the steps mentioned above
Updated by Anonymous about 6 years ago
Forgot to add the relevant parts of foreman-proxy log,
D, [2018-09-27T07:42:42.679255 a02b1adf] DEBUG -- : verifying remote client 10.28.230.252 against trusted_hosts ["foreman.example.local"] E, [2018-09-27T07:42:42.680034 a02b1adf] ERROR -- : No DHCP records for IP 10.245.207.0/10.245.207.73 found D, [2018-09-27T07:42:42.680113 a02b1adf] DEBUG -- : No DHCP records for IP 10.245.207.0/10.245.207.73 found I, [2018-09-27T07:42:42.680545 a02b1adf] INFO -- : 10.28.230.252 - - [27/Sep/2018:07:42:42 +0200] "GET /dhcp/10.245.207.0/ip/10.245.207.73 HTTP/1.1" 404 55 0.0015 D, [2018-09-27T07:42:42.723128 ] DEBUG -- : close: 10.28.230.252:49574 D, [2018-09-27T07:42:42.799416 ] DEBUG -- : accept: 10.28.230.252:49576 D, [2018-09-27T07:42:42.802435 ] DEBUG -- : Rack::Handler::WEBrick is invoked. D, [2018-09-27T07:42:42.804241 a02b1adf] DEBUG -- : verifying remote client 10.28.230.252 against trusted_hosts ["foreman.example.local"] D, [2018-09-27T07:42:42.804914 a02b1adf] DEBUG -- : Ignoring duplicates for macs: ["A0:36:9F:0E:89:28", "A0:36:9F:0E:8A:74"] D, [2018-09-27T07:42:42.809893 a02b1adf] DEBUG -- : omshell: executed - set name = "problem_machine.example.local-01" D, [2018-09-27T07:42:42.810123 a02b1adf] DEBUG -- : nil D, [2018-09-27T07:42:42.810330 a02b1adf] DEBUG -- : omshell: executed - set ip-address = 10.28.229.217 D, [2018-09-27T07:42:42.810470 a02b1adf] DEBUG -- : nil D, [2018-09-27T07:42:42.810624 a02b1adf] DEBUG -- : omshell: executed - set hardware-address = a0:36:9f:0e:89:28 D, [2018-09-27T07:42:42.810702 a02b1adf] DEBUG -- : nil D, [2018-09-27T07:42:42.810895 a02b1adf] DEBUG -- : omshell: executed - set hardware-type = 1 D, [2018-09-27T07:42:42.810980 a02b1adf] DEBUG -- : nil D, [2018-09-27T07:42:42.811128 a02b1adf] DEBUG -- : omshell: executed - set statements = "option host-name = \"problem_machine.example.local\";" D, [2018-09-27T07:42:42.811280 a02b1adf] DEBUG -- : nil D, [2018-09-27T07:42:42.811378 a02b1adf] DEBUG -- : omshell: executed - create D, [2018-09-27T07:42:42.811480 a02b1adf] DEBUG -- : nil D, [2018-09-27T07:42:42.828994 ] DEBUG -- : caught :modify event on /var/lib/dhcpd/dhcpd.leases. D, [2018-09-27T07:42:42.857133 ] DEBUG -- : Added a reservation: 10.28.229.217:a0:36:9f:0e:89:28:problem_machine.example.local-01 D, [2018-09-27T07:42:42.857546 a02b1adf] DEBUG -- : Added DHCP reservation for problem_machine.example.local-01 (10.28.229.217 / a0:36:9f:0e:89:28) I, [2018-09-27T07:42:42.858730 a02b1adf] INFO -- : 10.28.230.252 - - [27/Sep/2018:07:42:42 +0200] "POST /dhcp/10.28.229.0 HTTP/1.1" 200 - 0.0552 D, [2018-09-27T07:42:42.861307 ] DEBUG -- : close: 10.28.230.252:49576 D, [2018-09-27T07:42:42.875151 ] DEBUG -- : accept: 10.28.230.252:49580 D, [2018-09-27T07:42:42.879982 ] DEBUG -- : Rack::Handler::WEBrick is invoked. D, [2018-09-27T07:42:42.882100 a02b1adf] DEBUG -- : verifying remote client 10.28.230.252 against trusted_hosts ["foreman.example.local"] D, [2018-09-27T07:42:42.882795 a02b1adf] DEBUG -- : Ignoring duplicates for macs: ["a0:36:9f:0e:89:28", "A0:36:9F:0E:8A:74"] D, [2018-09-27T07:42:42.887539 a02b1adf] DEBUG -- : omshell: executed - set name = "problem_machine.example.local-02" D, [2018-09-27T07:42:42.887805 a02b1adf] DEBUG -- : nil D, [2018-09-27T07:42:42.887961 a02b1adf] DEBUG -- : omshell: executed - set ip-address = 10.28.229.217 D, [2018-09-27T07:42:42.888256 a02b1adf] DEBUG -- : nil D, [2018-09-27T07:42:42.888465 a02b1adf] DEBUG -- : omshell: executed - set hardware-address = a0:36:9f:0e:89:28 D, [2018-09-27T07:42:42.888553 a02b1adf] DEBUG -- : nil D, [2018-09-27T07:42:42.888662 a02b1adf] DEBUG -- : omshell: executed - set hardware-type = 1 D, [2018-09-27T07:42:42.888767 a02b1adf] DEBUG -- : nil D, [2018-09-27T07:42:42.889077 a02b1adf] DEBUG -- : omshell: executed - set statements = "option host-name = \"problem_machine.example.local\";" D, [2018-09-27T07:42:42.889176 a02b1adf] DEBUG -- : nil D, [2018-09-27T07:42:42.889293 a02b1adf] DEBUG -- : omshell: executed - create D, [2018-09-27T07:42:42.889383 a02b1adf] DEBUG -- : nil E, [2018-09-27T07:42:42.908076 a02b1adf] ERROR -- : Omshell failed: > > > > obj: <null> , > obj: host , > obj: host , name = "problem_machine.example.local-02" , > obj: host , name = "problem_machine.example.local-02" , ip-address = 0a:1c:e5:d9 , > obj: host name = "problem_machine.example.local-02" , ip-address = 0a:1c:e5:d9 , hardware-address = a0:36:9f:0e:89:28 , > obj: host , name = "problem_machine.example.local-02" , ip-address = 0a:1c:e5:d9 , hardware-address = a0:36:9f:0e:89:28 , hardware-type = 1 , > obj: host , name = "problem_machine.example.local-02" , ip-address = 0a:1c:e5:d9 , hardware-address = a0:36:9f:0e:89:28 , hardware-type = 1 , statements = "option host-name = "problem_machine.example.local";" , > can't open object: key conflict , obj: host , name = "problem_machine.example.local-02" , ip-address = 0a:1c:e5:d9 , hardware-address = a0:36:9f:0e:89:28 , hardware-type = 1 , statements = "option host-name = "problem_machine.example.local";" , > E, [2018-09-27T07:42:42.908697 a02b1adf] ERROR -- : Hardware address conflict. D, [2018-09-27T07:42:42.908795 a02b1adf] DEBUG -- : Hardware address conflict. (Proxy::DHCP::Collision) /usr/share/foreman-proxy/modules/dhcp_common/isc/omapi_provider.rb:95:in `report' /usr/share/foreman-proxy/modules/dhcp_common/isc/omapi_provider.rb:80:in `om_disconnect' /usr/share/foreman-proxy/modules/dhcp_common/isc/omapi_provider.rb:54:in `om_add_record' /usr/share/foreman-proxy/modules/dhcp_common/isc/omapi_provider.rb:30:in `add_record' /usr/share/foreman-proxy/modules/dhcp/dhcp_api.rb:98:in `block in <class:DhcpApi>' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1611:in `call' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1611:in `block in compile!' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:975:in `[]' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:975:in `block (3 levels) in route!' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:994:in `route_eval' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:975:in `block (2 levels) in route!' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1015:in `block in process_route' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1013:in `catch' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1013:in `process_route' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:973:in `block in route!' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:972:in `each' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:972:in `route!' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1085:in `block in dispatch!' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1067:in `block in invoke' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1067:in `catch' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1067:in `invoke' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1082:in `dispatch!' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:907:in `block in call!' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1067:in `block in invoke' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1067:in `catch' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1067:in `invoke' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:907:in `call!' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:895:in `call' /usr/share/gems/gems/rack-1.6.4/lib/rack/methodoverride.rb:22:in `call' /usr/share/gems/gems/rack-1.6.4/lib/rack/commonlogger.rb:33:in `call' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:219:in `call' /usr/share/foreman-proxy/lib/proxy/log.rb:109:in `call' /usr/share/foreman-proxy/lib/proxy/request_id_middleware.rb:9:in `call' /usr/share/gems/gems/rack-protection-1.5.3/lib/rack/protection/xss_header.rb:18:in `call' /usr/share/gems/gems/rack-protection-1.5.3/lib/rack/protection/path_traversal.rb:16:in `call' /usr/share/gems/gems/rack-protection-1.5.3/lib/rack/protection/json_csrf.rb:18:in `call' /usr/share/gems/gems/rack-protection-1.5.3/lib/rack/protection/base.rb:49:in `call' /usr/share/gems/gems/rack-protection-1.5.3/lib/rack/protection/base.rb:49:in `call' /usr/share/gems/gems/rack-protection-1.5.3/lib/rack/protection/frame_options.rb:31:in `call' /usr/share/gems/gems/rack-1.6.4/lib/rack/nulllogger.rb:9:in `call' /usr/share/gems/gems/rack-1.6.4/lib/rack/head.rb:13:in `call' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/show_exceptions.rb:25:in `call' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:182:in `call' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:2013:in `call' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1487:in `block in call' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1787:in `synchronize' /usr/share/gems/gems/sinatra-1.4.8/lib/sinatra/base.rb:1487:in `call' /usr/share/gems/gems/rack-1.6.4/lib/rack/urlmap.rb:66:in `block in call' /usr/share/gems/gems/rack-1.6.4/lib/rack/urlmap.rb:50:in `each' /usr/share/gems/gems/rack-1.6.4/lib/rack/urlmap.rb:50:in `call' /usr/share/gems/gems/rack-1.6.4/lib/rack/builder.rb:153:in `call' /usr/share/gems/gems/rack-1.6.4/lib/rack/handler/webrick.rb:88:in `service' /usr/share/ruby/webrick/httpserver.rb:138:in `service' /usr/share/ruby/webrick/httpserver.rb:94:in `run' /usr/share/ruby/webrick/server.rb:295:in `block in start_thread' I, [2018-09-27T07:42:42.910059 a02b1adf] INFO -- : 10.28.230.252 - - [27/Sep/2018:07:42:42 +0200] "POST /dhcp/10.28.229.0 HTTP/1.1" 409 26 0.0289
Updated by Lukas Zapletal about 6 years ago
Hey, how do you fill those forms? Because Foreman attempts to create IP reservation for two different IP addresses.
Updated by Lukas Zapletal about 6 years ago
- Related to Bug #21184: Bonded provision and primary interface causes DHCP duplication added
Updated by Lukas Zapletal about 6 years ago
- Status changed from New to Duplicate
I believe this is dupe of #21184 - known issue. Upvote the bug, we need to take a look.
Updated by Anonymous about 6 years ago
Lukas Zapletal wrote:
I believe this is dupe of #21184 - known issue. Upvote the bug, we need to take a look.
Thanks Lukas, I have upvoted. I'd like to just mention that this bug effectively kills any "automated" provision, one needs to fix dhcpd + dchpd.leases everytime one provisions a host.