Project

General

Profile

Actions

Bug #25051

closed

Creating an bond interface with slaves results in "Unable to set DHCP entry ([RestClient::Conflict]: 409 Conflict)"

Added by Anonymous about 6 years ago. Updated about 6 years ago.

Status:
Duplicate
Priority:
Normal
Assignee:
-
Category:
DHCP
Target version:
-
Difficulty:
Triaged:
No
Fixed in Releases:
Found in Releases:

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";
}


Related issues 1 (1 open0 closed)

Related to Foreman - Bug #21184: Bonded provision and primary interface causes DHCP duplicationNewActions
Actions #1

Updated by Anonymous about 6 years ago

Forgot to add that it works after doing the steps mentioned above

Actions #2

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
Actions #3

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.

Actions #4

Updated by Lukas Zapletal about 6 years ago

  • Related to Bug #21184: Bonded provision and primary interface causes DHCP duplication added
Actions #5

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.

Actions #6

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.

Actions

Also available in: Atom PDF