Bug #16093
openDHCP deletion is scheduled twice on MAC change
Description
Attempted to change MAC address for existing host from 52:54:00:f9:56:db to 52:54:00:f9:56:da and UI failed with:
Create DHCP Settings for rrtrte.nested.lan task failed with the following error: ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::BadRequest]: 400 Bad Request) for proxy https://fseven.zzz.lan:8443/dhcp
Failed to perform rollback on Remove DHCP Settings for rrtrte.nested.lan - ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::BadRequest]: 400 Bad Request) for proxy https://fseven.zzz.lan:8443/dhcp
This is 1.13 develop version build. The DHCP reservation seems to be present and correct:
# cat /var/lib/dhcpd/dhcpd.leases # The format of this file is documented in the dhcpd.leases(5) manual page. # This lease file was written by isc-dhcp-4.2.5 host rrtrte.nested.lan { dynamic; hardware ethernet 52:54:00:f9:56:db; fixed-address 192.168.222.100; supersede server.filename = "pxelinux.0"; supersede server.next-server = c0:a8:de:01; supersede host-name = "rrtrte.nested.lan"; } server-duid "\000\001\000\001\037>\3465RT\304\236\023\005";
Here is complete log of the transaction:
==> /var/log/foreman/production.log <== 2016-08-12 08:48:04 f7334e9f [app] [I] Started GET "/hosts/rrtrte.nested.lan/edit" for 192.168.122.1 at 2016-08-12 08:48:04 -0400 2016-08-12 08:48:04 f7334e9f [app] [I] Processing by HostsController#edit as HTML 2016-08-12 08:48:04 f7334e9f [app] [I] Parameters: {"id"=>"rrtrte.nested.lan"} 2016-08-12 08:48:04 f7334e9f [app] [D] Setting current user thread-local variable to admin 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered hosts/_progress.html.erb (0.2ms) 2016-08-12 08:48:04 f7334e9f [app] [D] Setting current organization thread-local variable to none 2016-08-12 08:48:04 f7334e9f [app] [D] Setting current location thread-local variable to none 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered puppetclasses/_selectedClasses.html.erb (0.0ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered puppetclasses/_classes_in_groups.html.erb (0.0ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered puppetclasses/_classes.html.erb (0.1ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered puppetclasses/_class_selection.html.erb (38.0ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered nic/_base_form.html.erb (17.6ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered nic/_virtual_form.html.erb (1.1ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered nic/_provider_specific_form.html.erb (0.2ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered nic/manageds/_managed.html.erb (20.3ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered nic/_base_form.html.erb (13.4ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered nic/_virtual_form.html.erb (1.0ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered nic/_provider_specific_form.html.erb (0.1ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered nic/manageds/_managed.html.erb (15.9ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered hosts/_interfaces.html.erb (38.1ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered common/os_selection/_architecture.html.erb (4.3ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered common/os_selection/_operatingsystem.html.erb (9.5ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered hosts/provision_method/build/_form.html.erb (10.3ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered hosts/provision_method/image/_form.html.erb (0.1ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered hosts/_operating_system.html.erb (18.5ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered hosts/_unattended.html.erb (18.7ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered puppetclasses/_class_parameters.html.erb (0.0ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered puppetclasses/_classes_parameters.html.erb (11.5ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered common_parameters/_inherited_parameters.html.erb (0.1ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered common_parameters/_parameter.html.erb (1.4ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered common_parameters/_parameters.html.erb (4.4ms) 2016-08-12 08:48:04 f7334e9f [app] [D] Setting current location thread-local variable to none 2016-08-12 08:48:04 f7334e9f [app] [D] Setting current organization thread-local variable to none 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered hosts/_form.html.erb (206.2ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered hosts/edit.html.erb within layouts/application (208.7ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered layouts/_application_content.html.erb (0.2ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered home/_user_dropdown.html.erb (1.7ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Read fragment views/tabs_and_title_records-3 (0.1ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered home/_topbar.html.erb (5.5ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered layouts/base.html.erb (6.4ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Completed 200 OK in 248ms (Views: 204.1ms | ActiveRecord: 15.2ms) ==> /var/log/foreman-proxy/proxy.log <== I, [2016-08-12T08:48:15.576464 #1512] INFO -- : 192.168.122.180 - - [12/Aug/2016:08:48:15 -0400] "GET /tftp/serverName HTTP/1.1" 200 30 0.0006 E, [2016-08-12T08:48:15.662449 #1512] ERROR -- : DHCP record 192.168.222.0/52:54:00:f9:56:da not found I, [2016-08-12T08:48:15.662848 #1512] INFO -- : 192.168.122.180 - - [12/Aug/2016:08:48:15 -0400] "GET /dhcp/192.168.222.0/52:54:00:f9:56:da HTTP/1.1" 404 53 0.0012 E, [2016-08-12T08:48:15.746353 #1512] ERROR -- : DHCP record 192.168.222.0/192.168.222.100 not found I, [2016-08-12T08:48:15.746731 #1512] INFO -- : 192.168.122.180 - - [12/Aug/2016:08:48:15 -0400] "GET /dhcp/192.168.222.0/192.168.222.100 HTTP/1.1" 404 51 0.0009 ==> /var/log/foreman/production.log <== 2016-08-12 08:48:15 f7334e9f [app] [I] Started PATCH "/hosts/rrtrte.nested.lan" for 192.168.122.1 at 2016-08-12 08:48:15 -0400 2016-08-12 08:48:15 f7334e9f [app] [I] Processing by HostsController#update as */* 2016-08-12 08:48:15 f7334e9f [app] [I] Parameters: {"utf8"=>"✓", "authenticity_token"=>"/TzOsRalUJQ/ESOXbairvsU0Xs6zY6CkPNK/Y3NvgvuGgK4i5QELa5Ac4zyC2jGJxTErOUrTL4H3d3O+gHrYcA==", "host"=>{"name"=>"rrtrte", "hostgroup_id"=>"1", "environment_id"=>"1", "puppet_ca_proxy_id"=>"1", "puppet_proxy_id"=>"1", "puppetclass_ids"=>[""], "managed"=>"true", "progress_report_id"=>"[FILTERED]", "interfaces_attributes"=>{"0"=>{"_destroy"=>"0", "mac"=>"52:54:00:f9:56:da", "identifier"=>"", "name"=>"rrtrte", "domain_id"=>"2", "subnet_id"=>"1", "ip"=>"192.168.222.100", "ip6"=>"", "managed"=>"1", "primary"=>"1", "provision"=>"1", "tag"=>"", "attached_to"=>"", "id"=>"6"}}, "architecture_id"=>"1", "operatingsystem_id"=>"1", "medium_id"=>"1", "ptable_id"=>"68", "disk"=>"", "is_owned_by"=>"3-Users", "enabled"=>"1", "model_id"=>"", "comment"=>"", "overwrite"=>"false"}, "bare_metal_capabilities"=>"build", "id"=>"rrtrte.nested.lan"} 2016-08-12 08:48:15 f7334e9f [app] [D] Setting current user thread-local variable to admin 2016-08-12 08:48:15 f7334e9f [app] [D] Setting current organization thread-local variable to none 2016-08-12 08:48:15 f7334e9f [app] [D] Setting current location thread-local variable to none ==> /var/log/httpd/foreman-ssl_access_ssl.log <== 192.168.122.1 - - [12/Aug/2016:08:48:15 -0400] "POST /hosts/rrtrte.nested.lan HTTP/1.1" 200 9783 "https://fseven.zzz.lan/hosts/rrtrte.nested.lan/edit" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/52.0.2743.116 Safari/537.36" ==> /var/log/foreman-proxy/proxy.log <== I, [2016-08-12T08:48:16.005333 #1512] INFO -- : 192.168.122.180 - - [12/Aug/2016:08:48:16 -0400] "GET /tftp/serverName HTTP/1.1" 200 30 0.0006 E, [2016-08-12T08:48:16.089534 #1512] ERROR -- : DHCP record 192.168.222.0/52:54:00:f9:56:db not found I, [2016-08-12T08:48:16.089878 #1512] INFO -- : 192.168.122.180 - - [12/Aug/2016:08:48:16 -0400] "DELETE /dhcp/192.168.222.0/52:54:00:f9:56:db HTTP/1.1" 404 53 0.0009 E, [2016-08-12T08:48:16.199522 #1512] ERROR -- : Omshell failed: > > > obj: <null> , > obj: host , > obj: host , name = "rrtrte.nested.lan" , > obj: host , name = "rrtrte.nested.lan" , ip-address = c0:a8:de:64 , > obj: host , name = "rrtrte.nested.lan" , ip-address = c0:a8:de:64 , hardware-address = 52:54:00:f9:56:da , > obj: host , name = "rrtrte.nested.lan" , ip-address = c0:a8:de:64 , hardware-address = 52:54:00:f9:56:da , hardware-type = 1 , > obj: host , name = "rrtrte.nested.lan" , ip-address = c0:a8:de:64 , hardware-address = 52:54:00:f9:56:da , hardware-type = 1 , statements = "filename = "pxelinux.0"; next-server = c0:a8:de:01; option host-name = "rrtrte.nested.lan";" , > can't open object: already exists , obj: host , name = "rrtrte.nested.lan" , ip-address = c0:a8:de:64 , hardware-address = 52:54:00:f9:56:da , hardware-type = 1 , statements = "filename = "pxelinux.0"; next-server = c0:a8:de:01; option host-name = "rrtrte.nested.lan";" , > E, [2016-08-12T08:48:16.200100 #1512] ERROR -- : Failed to add DHCP reservation for rrtrte.nested.lan (192.168.222.100 / 52:54:00:f9:56:da): Entry already exists I, [2016-08-12T08:48:16.200751 #1512] INFO -- : 192.168.122.180 - - [12/Aug/2016:08:48:16 -0400] "POST /dhcp/192.168.222.0 HTTP/1.1" 400 112 0.0268 E, [2016-08-12T08:48:16.319306 #1512] ERROR -- : Omshell failed: > > > obj: <null> , > obj: host , > obj: host , name = "rrtrte.nested.lan" , > obj: host , name = "rrtrte.nested.lan" , ip-address = c0:a8:de:64 , > obj: host , name = "rrtrte.nested.lan" , ip-address = c0:a8:de:64 , hardware-address = 52:54:00:f9:56:db , > obj: host , name = "rrtrte.nested.lan" , ip-address = c0:a8:de:64 , hardware-address = 52:54:00:f9:56:db , hardware-type = 1 , > obj: host , name = "rrtrte.nested.lan" , ip-address = c0:a8:de:64 , hardware-address = 52:54:00:f9:56:db , hardware-type = 1 , statements = "filename = "pxelinux.0"; next-server = c0:a8:de:01; option host-name = "rrtrte.nested.lan";" , > can't open object: already exists , obj: host , name = "rrtrte.nested.lan" , ip-address = c0:a8:de:64 , hardware-address = 52:54:00:f9:56:db , hardware-type = 1 , statements = "filename = "pxelinux.0"; next-server = c0:a8:de:01; option host-name = "rrtrte.nested.lan";" , > E, [2016-08-12T08:48:16.319822 #1512] ERROR -- : Failed to add DHCP reservation for rrtrte.nested.lan (192.168.222.100 / 52:54:00:f9:56:db): Entry already exists I, [2016-08-12T08:48:16.320441 #1512] INFO -- : 192.168.122.180 - - [12/Aug/2016:08:48:16 -0400] "POST /dhcp/192.168.222.0 HTTP/1.1" 400 112 0.0298 ==> /var/log/foreman/production.log <== 2016-08-12 08:48:16 f7334e9f [app] [I] Delete DHCP reservation for rrtrte.nested.lan-52:54:00:f9:56:db/192.168.222.100 2016-08-12 08:48:16 f7334e9f [app] [I] Create DHCP reservation for rrtrte.nested.lan-52:54:00:f9:56:da/192.168.222.100 2016-08-12 08:48:16 f7334e9f [app] [D] DHCP reservation on net 192.168.222.0 with attrs: {:hostname=>"rrtrte.nested.lan", :mac=>"52:54:00:f9:56:da", :ip=>"192.168.222.100", :network=>"192.168.222.0", :nextServer=>"192.168.222.1", :filename=>"pxelinux.0"} 2016-08-12 08:48:16 f7334e9f [app] [W] Create DHCP Settings for rrtrte.nested.lan task failed with the following error: ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::BadRequest]: 400 Bad Request) for proxy https://fseven.zzz.lan:8443/dhcp | ProxyAPI::ProxyException: ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::BadRequest]: 400 Bad Request) for proxy https://fseven.zzz.lan:8443/dhcp | /usr/share/foreman/lib/proxy_api/dhcp.rb:66:in `rescue in set' | /usr/share/foreman/lib/proxy_api/dhcp.rb:62:in `set' | /usr/share/foreman/lib/net/dhcp/record.rb:29:in `create' | /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:57:in `set_dhcp' | /usr/share/foreman/app/models/concerns/orchestration.rb:191:in `execute' | /usr/share/foreman/app/models/concerns/orchestration.rb:131:in `block in process' | /usr/share/foreman/app/models/concerns/orchestration.rb:123:in `each' | /usr/share/foreman/app/models/concerns/orchestration.rb:123:in `process' | /usr/share/foreman/app/models/concerns/orchestration.rb:35:in `around_save_orchestration' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:432:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:92:in `__run_callbacks__' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:778:in `_run_save_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/callbacks.rb:302:in `create_or_update' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/persistence.rb:120:in `save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/validations.rb:37:in `save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/attribute_methods/dirty.rb:21:in `save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:286:in `block (2 levels) in save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:351:in `block in with_transaction_returning_status' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:211:in `transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:220:in `transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:348:in `with_transaction_returning_status' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:286:in `block in save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:301:in `rollback_active_record_state!' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:285:in `save' | /usr/share/foreman/app/models/concerns/foreman/sti.rb:29:in `save_with_type' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/persistence.rb:252:in `block in update' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:351:in `block in with_transaction_returning_status' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `block in transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/transaction.rb:184:in `within_new_transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:220:in `transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:348:in `with_transaction_returning_status' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/persistence.rb:250:in `update' | /usr/share/foreman/app/controllers/hosts_controller.rb:110:in `block in update' | /usr/share/foreman/app/models/taxonomy.rb:59:in `block in no_taxonomy_scope' | /usr/share/foreman/app/models/taxonomy.rb:66:in `block (2 levels) in as_taxonomy' | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:147:in `as_location' | /usr/share/foreman/app/models/taxonomy.rb:65:in `block in as_taxonomy' | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:112:in `as_org' | /usr/share/foreman/app/models/taxonomy.rb:64:in `as_taxonomy' | /usr/share/foreman/app/models/taxonomy.rb:58:in `no_taxonomy_scope' | /usr/share/foreman/app/controllers/hosts_controller.rb:107:in `update' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/implicit_render.rb:4:in `send_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/base.rb:198:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/rendering.rb:10:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/callbacks.rb:20:in `block in process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:117:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:117:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:555:in `block (2 levels) in compile' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:in `block (2 levels) in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `block (2 levels) in halting' | /opt/theforeman/tfm/root/usr/share/gems/gems/rails-observers-0.1.2/lib/rails/observers/action_controller/caching/sweeping.rb:73:in `around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:455:in `public_send' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:455:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:in `block (2 levels) in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `block (2 levels) in halting' | /usr/share/foreman/app/controllers/concerns/application_shared.rb:14:in `set_timezone' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:432:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:in `block (2 levels) in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `block (2 levels) in halting' | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:432:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:in `block (2 levels) in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `block (2 levels) in halting' | /opt/theforeman/tfm/root/usr/share/gems/gems/rails-observers-0.1.2/lib/rails/observers/action_controller/caching/sweeping.rb:73:in `around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:455:in `public_send' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:455:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:92:in `__run_callbacks__' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:778:in `_run_process_action_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:81:in `run_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/callbacks.rb:19:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/rescue.rb:29:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/notifications.rb:164:in `block in instrument' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/notifications/instrumenter.rb:20:in `instrument' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/notifications.rb:164:in `instrument' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/instrumentation.rb:30:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/params_wrapper.rb:250:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/railties/controller_runtime.rb:18:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/base.rb:137:in `process' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionview-4.2.5.1/lib/action_view/rendering.rb:30:in `process' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal.rb:196:in `dispatch' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/rack_delegation.rb:13:in `dispatch' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal.rb:237:in `block in action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/route_set.rb:74:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/route_set.rb:74:in `dispatch' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/route_set.rb:43:in `serve' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/journey/router.rb:43:in `block in serve' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/journey/router.rb:30:in `each' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/journey/router.rb:30:in `serve' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/route_set.rb:815:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.3.6/lib/apipie/static_dispatcher.rb:65:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.3.6/lib/apipie/extractor/recorder.rb:132:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.3.6/lib/apipie/middleware/checksum_in_headers.rb:27:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/etag.rb:24:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/conditionalget.rb:38:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/head.rb:13:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/params_parser.rb:27:in `call' | /usr/share/foreman/lib/middleware/catch_json_parse_errors.rb:9:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/flash.rb:260:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/session/abstract/id.rb:225:in `context' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/session/abstract/id.rb:220:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/cookies.rb:560:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/query_cache.rb:36:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:653:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/callbacks.rb:29:in `block in call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:88:in `__run_callbacks__' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:778:in `_run_call_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:81:in `run_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/callbacks.rb:27:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/remote_ip.rb:78:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/debug_exceptions.rb:17:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/show_exceptions.rb:30:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/rack/logger.rb:38:in `call_app' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/rack/logger.rb:22:in `call' | /usr/share/foreman/lib/middleware/tagged_logging.rb:18:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/request_id.rb:21:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/methodoverride.rb:22:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/runtime.rb:18:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/static.rb:116:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/sendfile.rb:113:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/engine.rb:518:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/application.rb:165:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/railtie.rb:194:in `public_send' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/railtie.rb:194:in `method_missing' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/urlmap.rb:66:in `block in call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/urlmap.rb:50:in `each' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/urlmap.rb:50: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-1.8.2/lib/logging/diagnostic_context.rb:323:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context' 2016-08-12 08:48:16 f7334e9f [app] [I] Create DHCP reservation for rrtrte.nested.lan-52:54:00:f9:56:db/192.168.222.100 2016-08-12 08:48:16 f7334e9f [app] [D] DHCP reservation on net 192.168.222.0 with attrs: {:hostname=>"rrtrte.nested.lan", :mac=>"52:54:00:f9:56:db", :ip=>"192.168.222.100", :network=>"192.168.222.0", :nextServer=>"192.168.222.1", :filename=>"pxelinux.0"} 2016-08-12 08:48:16 f7334e9f [app] [W] Failed to perform rollback on Remove DHCP Settings for rrtrte.nested.lan - ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::BadRequest]: 400 Bad Request) for proxy https://fseven.zzz.lan:8443/dhcp | ProxyAPI::ProxyException: ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::BadRequest]: 400 Bad Request) for proxy https://fseven.zzz.lan:8443/dhcp | /usr/share/foreman/lib/proxy_api/dhcp.rb:66:in `rescue in set' | /usr/share/foreman/lib/proxy_api/dhcp.rb:62:in `set' | /usr/share/foreman/lib/net/dhcp/record.rb:29:in `create' | /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:57:in `set_dhcp' | /usr/share/foreman/app/models/concerns/orchestration.rb:191:in `execute' | /usr/share/foreman/app/models/concerns/orchestration.rb:161:in `block in fail_queue' | /usr/share/foreman/app/models/concerns/orchestration.rb:157:in `reverse_each' | /usr/share/foreman/app/models/concerns/orchestration.rb:157:in `fail_queue' | /usr/share/foreman/app/models/concerns/orchestration.rb:147:in `process' | /usr/share/foreman/app/models/concerns/orchestration.rb:35:in `around_save_orchestration' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:432:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:92:in `__run_callbacks__' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:778:in `_run_save_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/callbacks.rb:302:in `create_or_update' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/persistence.rb:120:in `save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/validations.rb:37:in `save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/attribute_methods/dirty.rb:21:in `save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:286:in `block (2 levels) in save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:351:in `block in with_transaction_returning_status' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:211:in `transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:220:in `transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:348:in `with_transaction_returning_status' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:286:in `block in save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:301:in `rollback_active_record_state!' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:285:in `save' | /usr/share/foreman/app/models/concerns/foreman/sti.rb:29:in `save_with_type' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/persistence.rb:252:in `block in update' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:351:in `block in with_transaction_returning_status' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `block in transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/transaction.rb:184:in `within_new_transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:220:in `transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:348:in `with_transaction_returning_status' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/persistence.rb:250:in `update' | /usr/share/foreman/app/controllers/hosts_controller.rb:110:in `block in update' | /usr/share/foreman/app/models/taxonomy.rb:59:in `block in no_taxonomy_scope' | /usr/share/foreman/app/models/taxonomy.rb:66:in `block (2 levels) in as_taxonomy' | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:147:in `as_location' | /usr/share/foreman/app/models/taxonomy.rb:65:in `block in as_taxonomy' | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:112:in `as_org' | /usr/share/foreman/app/models/taxonomy.rb:64:in `as_taxonomy' | /usr/share/foreman/app/models/taxonomy.rb:58:in `no_taxonomy_scope' | /usr/share/foreman/app/controllers/hosts_controller.rb:107:in `update' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/implicit_render.rb:4:in `send_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/base.rb:198:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/rendering.rb:10:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/callbacks.rb:20:in `block in process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:117:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:117:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:555:in `block (2 levels) in compile' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:in `block (2 levels) in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `block (2 levels) in halting' | /opt/theforeman/tfm/root/usr/share/gems/gems/rails-observers-0.1.2/lib/rails/observers/action_controller/caching/sweeping.rb:73:in `around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:455:in `public_send' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:455:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:in `block (2 levels) in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `block (2 levels) in halting' | /usr/share/foreman/app/controllers/concerns/application_shared.rb:14:in `set_timezone' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:432:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:in `block (2 levels) in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `block (2 levels) in halting' | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:432:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:in `block (2 levels) in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `block (2 levels) in halting' | /opt/theforeman/tfm/root/usr/share/gems/gems/rails-observers-0.1.2/lib/rails/observers/action_controller/caching/sweeping.rb:73:in `around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:455:in `public_send' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:455:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:92:in `__run_callbacks__' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:778:in `_run_process_action_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:81:in `run_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/callbacks.rb:19:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/rescue.rb:29:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/notifications.rb:164:in `block in instrument' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/notifications/instrumenter.rb:20:in `instrument' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/notifications.rb:164:in `instrument' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/instrumentation.rb:30:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/params_wrapper.rb:250:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/railties/controller_runtime.rb:18:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/base.rb:137:in `process' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionview-4.2.5.1/lib/action_view/rendering.rb:30:in `process' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal.rb:196:in `dispatch' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/rack_delegation.rb:13:in `dispatch' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal.rb:237:in `block in action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/route_set.rb:74:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/route_set.rb:74:in `dispatch' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/route_set.rb:43:in `serve' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/journey/router.rb:43:in `block in serve' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/journey/router.rb:30:in `each' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/journey/router.rb:30:in `serve' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/route_set.rb:815:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.3.6/lib/apipie/static_dispatcher.rb:65:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.3.6/lib/apipie/extractor/recorder.rb:132:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.3.6/lib/apipie/middleware/checksum_in_headers.rb:27:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/etag.rb:24:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/conditionalget.rb:38:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/head.rb:13:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/params_parser.rb:27:in `call' | /usr/share/foreman/lib/middleware/catch_json_parse_errors.rb:9:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/flash.rb:260:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/session/abstract/id.rb:225:in `context' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/session/abstract/id.rb:220:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/cookies.rb:560:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/query_cache.rb:36:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:653:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/callbacks.rb:29:in `block in call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:88:in `__run_callbacks__' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:778:in `_run_call_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:81:in `run_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/callbacks.rb:27:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/remote_ip.rb:78:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/debug_exceptions.rb:17:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/show_exceptions.rb:30:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/rack/logger.rb:38:in `call_app' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/rack/logger.rb:22:in `call' | /usr/share/foreman/lib/middleware/tagged_logging.rb:18:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/request_id.rb:21:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/methodoverride.rb:22:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/runtime.rb:18:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/static.rb:116:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/sendfile.rb:113:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/engine.rb:518:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/application.rb:165:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/railtie.rb:194:in `public_send' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/railtie.rb:194:in `method_missing' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/urlmap.rb:66:in `block in call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/urlmap.rb:50:in `each' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/urlmap.rb:50: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-1.8.2/lib/logging/diagnostic_context.rb:323:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context' 2016-08-12 08:48:16 f7334e9f [app] [I] Failed to save: Create DHCP Settings for rrtrte.nested.lan task failed with the following error: ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::BadRequest]: 400 Bad Request) for proxy https://fseven.zzz.lan:8443/dhcp, Failed to perform rollback on Remove DHCP Settings for rrtrte.nested.lan - ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::BadRequest]: 400 Bad Request) for proxy https://fseven.zzz.lan:8443/dhcp 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered hosts/_progress.html.erb (0.5ms) 2016-08-12 08:48:16 f7334e9f [app] [D] Setting current organization thread-local variable to none 2016-08-12 08:48:16 f7334e9f [app] [D] Setting current location thread-local variable to none 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered puppetclasses/_selectedClasses.html.erb (0.0ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered puppetclasses/_classes_in_groups.html.erb (0.0ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered puppetclasses/_classes.html.erb (0.9ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered puppetclasses/_class_selection.html.erb (58.3ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered nic/_base_form.html.erb (21.4ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered nic/_virtual_form.html.erb (1.8ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered nic/_provider_specific_form.html.erb (0.6ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered nic/manageds/_managed.html.erb (33.1ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered nic/_base_form.html.erb (14.0ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered nic/_virtual_form.html.erb (1.1ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered nic/_provider_specific_form.html.erb (0.1ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered nic/manageds/_managed.html.erb (19.5ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered hosts/_interfaces.html.erb (58.7ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered common/os_selection/_architecture.html.erb (4.9ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered common/os_selection/_operatingsystem.html.erb (12.1ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered hosts/provision_method/build/_form.html.erb (13.7ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered hosts/provision_method/image/_form.html.erb (0.5ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered hosts/_operating_system.html.erb (31.0ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered hosts/_unattended.html.erb (33.2ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered puppetclasses/_class_parameters.html.erb (0.0ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered puppetclasses/_classes_parameters.html.erb (8.9ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered common_parameters/_inherited_parameters.html.erb (0.1ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered common_parameters/_parameter.html.erb (1.5ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered common_parameters/_parameters.html.erb (3.4ms) 2016-08-12 08:48:16 f7334e9f [app] [D] Setting current location thread-local variable to none 2016-08-12 08:48:16 f7334e9f [app] [D] Setting current organization thread-local variable to none 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered hosts/_form.html.erb (216.2ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered hosts/edit.html.erb within layouts/application (220.7ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered layouts/_application_content.html.erb (0.2ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered home/_user_dropdown.html.erb (1.8ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Read fragment views/tabs_and_title_records-3 (0.1ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered home/_topbar.html.erb (5.8ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered layouts/base.html.erb (6.8ms) 2016-08-12 08:48:16 f7334e9f [app] [D] Setting current location thread-local variable to none 2016-08-12 08:48:16 f7334e9f [app] [D] Setting current organization thread-local variable to none 2016-08-12 08:48:16 f7334e9f [app] [I] Completed 200 OK in 1144ms (Views: 219.2ms | ActiveRecord: 28.6ms) ==> /var/log/httpd/foreman-ssl_access_ssl.log <== 192.168.122.1 - - [12/Aug/2016:08:48:16 -0400] "GET /tasks/a506440f-8722-46fc-9d01-d71879a94dc0 HTTP/1.1" 200 208 "https://fseven.zzz.lan/hosts/rrtrte.nested.lan/edit" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/52.0.2743.116 Safari/537.36" ==> /var/log/foreman/production.log <== 2016-08-12 08:48:16 f7334e9f [app] [I] Started GET "/tasks/a506440f-8722-46fc-9d01-d71879a94dc0" for 192.168.122.1 at 2016-08-12 08:48:16 -0400 2016-08-12 08:48:16 f7334e9f [app] [I] Processing by TasksController#show as */* 2016-08-12 08:48:16 f7334e9f [app] [I] Parameters: {"id"=>"a506440f-8722-46fc-9d01-d71879a94dc0"} 2016-08-12 08:48:16 f7334e9f [app] [D] Setting current user thread-local variable to admin 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered tasks/_list.html.erb (0.6ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Completed 200 OK in 10ms (Views: 1.4ms | ActiveRecord: 1.3ms)
The workaround is to exit build mode, make necessary changes and enter build mode again.
Updated by Lukas Zapletal about 8 years ago
I enabled debug on proxy and tried again, it fails again but now I see the deletion to be queued twice:
==> /var/log/foreman-proxy/proxy.log <== D, [2016-08-12T09:07:22.292867 #30887] DEBUG -- : accept: 192.168.122.180:48295 D, [2016-08-12T09:07:22.295319 #30887] DEBUG -- : Rack::Handler::WEBrick is invoked. D, [2016-08-12T09:07:22.296245 #30887] DEBUG -- : verifying remote client 192.168.122.180 against trusted_hosts ["fseven.zzz.lan"] I, [2016-08-12T09:07:22.296896 #30887] INFO -- : 192.168.122.180 - - [12/Aug/2016:09:07:22 -0400] "GET /tftp/serverName HTTP/1.1" 200 30 0.0008 D, [2016-08-12T09:07:22.338510 #30887] DEBUG -- : close: 192.168.122.180:48295 D, [2016-08-12T09:07:22.377131 #30887] DEBUG -- : accept: 192.168.122.180:48296 D, [2016-08-12T09:07:22.378917 #30887] DEBUG -- : Rack::Handler::WEBrick is invoked. D, [2016-08-12T09:07:22.379519 #30887] DEBUG -- : verifying remote client 192.168.122.180 against trusted_hosts ["fseven.zzz.lan"] D, [2016-08-12T09:07:22.379765 #30887] DEBUG -- : Loading subnets for 127.0.0.1 D, [2016-08-12T09:07:22.379992 #30887] DEBUG -- : Loading subnet data for 192.168.222.0/255.255.255.0 E, [2016-08-12T09:07:22.380157 #30887] ERROR -- : DHCP record 192.168.222.0/52:54:00:f9:56:da not found D, [2016-08-12T09:07:22.380197 #30887] DEBUG -- : DHCP record 192.168.222.0/52:54:00:f9:56:da not found I, [2016-08-12T09:07:22.380453 #30887] INFO -- : 192.168.122.180 - - [12/Aug/2016:09:07:22 -0400] "GET /dhcp/192.168.222.0/52:54:00:f9:56:da HTTP/1.1" 404 53 0.0011 D, [2016-08-12T09:07:22.421060 #30887] DEBUG -- : close: 192.168.122.180:48296 D, [2016-08-12T09:07:22.457362 #30887] DEBUG -- : accept: 192.168.122.180:48297 D, [2016-08-12T09:07:22.459004 #30887] DEBUG -- : Rack::Handler::WEBrick is invoked. D, [2016-08-12T09:07:22.459529 #30887] DEBUG -- : verifying remote client 192.168.122.180 against trusted_hosts ["fseven.zzz.lan"] D, [2016-08-12T09:07:22.459712 #30887] DEBUG -- : Loading subnets for 127.0.0.1 D, [2016-08-12T09:07:22.459863 #30887] DEBUG -- : Loading subnet data for 192.168.222.0/255.255.255.0 I, [2016-08-12T09:07:22.460090 #30887] INFO -- : 192.168.122.180 - - [12/Aug/2016:09:07:22 -0400] "GET /dhcp/192.168.222.0/192.168.222.100 HTTP/1.1" 200 171 0.0007 D, [2016-08-12T09:07:22.500130 #30887] DEBUG -- : close: 192.168.122.180:48297 D, [2016-08-12T09:07:22.539841 #30887] DEBUG -- : accept: 192.168.122.180:48298 D, [2016-08-12T09:07:22.542049 #30887] DEBUG -- : Rack::Handler::WEBrick is invoked. D, [2016-08-12T09:07:22.542908 #30887] DEBUG -- : verifying remote client 192.168.122.180 against trusted_hosts ["fseven.zzz.lan"] D, [2016-08-12T09:07:22.543180 #30887] DEBUG -- : Loading subnets for 127.0.0.1 D, [2016-08-12T09:07:22.543443 #30887] DEBUG -- : Loading subnet data for 192.168.222.0/255.255.255.0 E, [2016-08-12T09:07:22.543654 #30887] ERROR -- : DHCP record 192.168.222.0/52:54:00:f9:56:da not found D, [2016-08-12T09:07:22.543715 #30887] DEBUG -- : DHCP record 192.168.222.0/52:54:00:f9:56:da not found I, [2016-08-12T09:07:22.544025 #30887] INFO -- : 192.168.122.180 - - [12/Aug/2016:09:07:22 -0400] "GET /dhcp/192.168.222.0/52:54:00:f9:56:da HTTP/1.1" 404 53 0.0012 D, [2016-08-12T09:07:22.584221 #30887] DEBUG -- : close: 192.168.122.180:48298 D, [2016-08-12T09:07:22.628746 #30887] DEBUG -- : accept: 192.168.122.180:48299 D, [2016-08-12T09:07:22.631080 #30887] DEBUG -- : Rack::Handler::WEBrick is invoked. D, [2016-08-12T09:07:22.631995 #30887] DEBUG -- : verifying remote client 192.168.122.180 against trusted_hosts ["fseven.zzz.lan"] D, [2016-08-12T09:07:22.632284 #30887] DEBUG -- : Loading subnets for 127.0.0.1 D, [2016-08-12T09:07:22.632564 #30887] DEBUG -- : Loading subnet data for 192.168.222.0/255.255.255.0 I, [2016-08-12T09:07:22.632951 #30887] INFO -- : 192.168.122.180 - - [12/Aug/2016:09:07:22 -0400] "GET /dhcp/192.168.222.0/192.168.222.100 HTTP/1.1" 200 171 0.0011 D, [2016-08-12T09:07:22.673160 #30887] DEBUG -- : close: 192.168.122.180:48299 ==> /var/log/foreman/production.log <== 2016-08-12 09:07:22 f7334e9f [app] [I] Started PATCH "/hosts/rrtrte.nested.lan" for 192.168.122.1 at 2016-08-12 09:07:22 -0400 2016-08-12 09:07:22 f7334e9f [app] [I] Processing by HostsController#update as */* 2016-08-12 09:07:22 f7334e9f [app] [I] Parameters: {"utf8"=>"✓", "authenticity_token"=>"rggeCHjEdeXc8f8XzQr8r16Wq1YpT6gTBepFtqNHRVHVtH6bi2AuGnP8P7wieGaYXpPeodD/JzbOT4lrUFIf2g==", "host"=>{"name"=>"rrtrte", "hostgroup_id"=>"1", "environment_id"=>"1", "puppet_ca_proxy_id"=>"1", "puppet_proxy_id"=>"1", "puppetclass_ids"=>[""], "managed"=>"true", "progress_report_id"=>"[FILTERED]", "interfaces_attributes"=>{"0"=>{"_destroy"=>"0", "mac"=>"52:54:00:f9:56:da", "identifier"=>"", "name"=>"rrtrte", "domain_id"=>"2", "subnet_id"=>"1", "ip"=>"192.168.222.100", "ip6"=>"", "managed"=>"1", "primary"=>"1", "provision"=>"1", "tag"=>"", "attached_to"=>"", "id"=>"6"}}, "architecture_id"=>"1", "operatingsystem_id"=>"2", "medium_id"=>"1", "ptable_id"=>"68", "disk"=>"", "is_owned_by"=>"3-Users", "enabled"=>"1", "model_id"=>"", "comment"=>"", "overwrite"=>"false"}, "bare_metal_capabilities"=>"build", "id"=>"rrtrte.nested.lan"} 2016-08-12 09:07:22 f7334e9f [app] [D] Setting current user thread-local variable to admin 2016-08-12 09:07:22 f7334e9f [app] [D] Setting current organization thread-local variable to none 2016-08-12 09:07:22 f7334e9f [app] [D] Setting current location thread-local variable to none ==> /var/log/httpd/foreman-ssl_access_ssl.log <== 192.168.122.1 - - [12/Aug/2016:09:07:22 -0400] "POST /hosts/rrtrte.nested.lan HTTP/1.1" 200 9895 "https://fseven.zzz.lan/hosts/rrtrte.nested.lan/edit" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/52.0.2743.116 Safari/537.36" 192.168.122.1 - - [12/Aug/2016:09:07:23 -0400] "GET /tasks/641ec5a8-2fc6-496e-993b-001947d24bef HTTP/1.1" 200 33 "https://fseven.zzz.lan/hosts/rrtrte.nested.lan/edit" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/52.0.2743.116 Safari/537.36" ==> /var/log/foreman/production.log <== 2016-08-12 09:07:22 f7334e9f [app] [I] Failed to save: Conflict DHCP records rrtrte.nested.lan-52:54:00:f9:56:db/192.168.222.100 already exists, Conflict DHCP records rrtrte.nested.lan-52:54:00:f9:56:db/192.168.222.100 already exists 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered hosts/_conflicts.html.erb (0.9ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered hosts/_progress.html.erb (0.2ms) 2016-08-12 09:07:22 f7334e9f [app] [D] Setting current organization thread-local variable to none 2016-08-12 09:07:22 f7334e9f [app] [D] Setting current location thread-local variable to none 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered puppetclasses/_selectedClasses.html.erb (0.0ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered puppetclasses/_classes_in_groups.html.erb (0.0ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered puppetclasses/_classes.html.erb (0.1ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered puppetclasses/_class_selection.html.erb (37.0ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered nic/_base_form.html.erb (20.0ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered nic/_virtual_form.html.erb (1.0ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered nic/_provider_specific_form.html.erb (0.1ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered nic/manageds/_managed.html.erb (22.3ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered nic/_base_form.html.erb (12.7ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered nic/_virtual_form.html.erb (1.0ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered nic/_provider_specific_form.html.erb (0.0ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered nic/manageds/_managed.html.erb (15.0ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered hosts/_interfaces.html.erb (39.3ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered common/os_selection/_architecture.html.erb (3.8ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered common/os_selection/_operatingsystem.html.erb (11.0ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered hosts/provision_method/build/_form.html.erb (12.1ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered hosts/provision_method/image/_form.html.erb (0.1ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered hosts/_operating_system.html.erb (20.4ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered hosts/_unattended.html.erb (20.6ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered puppetclasses/_class_parameters.html.erb (0.0ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered puppetclasses/_classes_parameters.html.erb (8.2ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered common_parameters/_inherited_parameters.html.erb (0.1ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered common_parameters/_parameter.html.erb (1.4ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered common_parameters/_parameters.html.erb (3.0ms) 2016-08-12 09:07:22 f7334e9f [app] [D] Setting current location thread-local variable to none 2016-08-12 09:07:22 f7334e9f [app] [D] Setting current organization thread-local variable to none 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered hosts/_form.html.erb (147.0ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered hosts/edit.html.erb within layouts/application (148.5ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered layouts/_application_content.html.erb (0.2ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered home/_user_dropdown.html.erb (1.7ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Read fragment views/tabs_and_title_records-3 (0.1ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered home/_topbar.html.erb (5.5ms) 2016-08-12 09:07:22 f7334e9f [app] [I] Rendered layouts/base.html.erb (6.5ms) 2016-08-12 09:07:22 f7334e9f [app] [D] Setting current location thread-local variable to none 2016-08-12 09:07:22 f7334e9f [app] [D] Setting current organization thread-local variable to none 2016-08-12 09:07:22 f7334e9f [app] [I] Completed 200 OK in 829ms (Views: 147.5ms | ActiveRecord: 23.3ms) 2016-08-12 09:07:23 f7334e9f [app] [I] Started GET "/tasks/641ec5a8-2fc6-496e-993b-001947d24bef" for 192.168.122.1 at 2016-08-12 09:07:23 -0400 2016-08-12 09:07:23 f7334e9f [app] [I] Processing by TasksController#show as */* 2016-08-12 09:07:23 f7334e9f [app] [I] Parameters: {"id"=>"641ec5a8-2fc6-496e-993b-001947d24bef"} 2016-08-12 09:07:23 f7334e9f [app] [D] Setting current user thread-local variable to admin 2016-08-12 09:07:23 f7334e9f [app] [I] Rendered tasks/_list.html.erb (0.1ms) 2016-08-12 09:07:23 f7334e9f [app] [I] Completed 200 OK in 7ms (Views: 0.9ms | ActiveRecord: 0.8ms) ==> /var/log/foreman-proxy/proxy.log <== D, [2016-08-12T09:07:52.869495 #30887] DEBUG -- : accept: 192.168.122.180:48300 D, [2016-08-12T09:07:52.871258 #30887] DEBUG -- : Rack::Handler::WEBrick is invoked. D, [2016-08-12T09:07:52.871839 #30887] DEBUG -- : verifying remote client 192.168.122.180 against trusted_hosts ["fseven.zzz.lan"] I, [2016-08-12T09:07:52.872188 #30887] INFO -- : 192.168.122.180 - - [12/Aug/2016:09:07:52 -0400] "GET /tftp/serverName HTTP/1.1" 200 30 0.0005 D, [2016-08-12T09:07:52.912126 #30887] DEBUG -- : close: 192.168.122.180:48300 D, [2016-08-12T09:07:52.952718 #30887] DEBUG -- : accept: 192.168.122.180:48301 D, [2016-08-12T09:07:52.954373 #30887] DEBUG -- : Rack::Handler::WEBrick is invoked. D, [2016-08-12T09:07:52.954944 #30887] DEBUG -- : verifying remote client 192.168.122.180 against trusted_hosts ["fseven.zzz.lan"] D, [2016-08-12T09:07:52.955139 #30887] DEBUG -- : Loading subnets for 127.0.0.1 D, [2016-08-12T09:07:52.955307 #30887] DEBUG -- : Loading subnet data for 192.168.222.0/255.255.255.0 E, [2016-08-12T09:07:52.955456 #30887] ERROR -- : DHCP record 192.168.222.0/52:54:00:f9:56:da not found D, [2016-08-12T09:07:52.955497 #30887] DEBUG -- : DHCP record 192.168.222.0/52:54:00:f9:56:da not found I, [2016-08-12T09:07:52.955716 #30887] INFO -- : 192.168.122.180 - - [12/Aug/2016:09:07:52 -0400] "GET /dhcp/192.168.222.0/52:54:00:f9:56:da HTTP/1.1" 404 53 0.0009 D, [2016-08-12T09:07:52.996168 #30887] DEBUG -- : close: 192.168.122.180:48301 D, [2016-08-12T09:07:53.036059 #30887] DEBUG -- : accept: 192.168.122.180:48302 D, [2016-08-12T09:07:53.037705 #30887] DEBUG -- : Rack::Handler::WEBrick is invoked. D, [2016-08-12T09:07:53.038170 #30887] DEBUG -- : verifying remote client 192.168.122.180 against trusted_hosts ["fseven.zzz.lan"] D, [2016-08-12T09:07:53.038327 #30887] DEBUG -- : Loading subnets for 127.0.0.1 D, [2016-08-12T09:07:53.038603 #30887] DEBUG -- : Loading subnet data for 192.168.222.0/255.255.255.0 I, [2016-08-12T09:07:53.038834 #30887] INFO -- : 192.168.122.180 - - [12/Aug/2016:09:07:53 -0400] "GET /dhcp/192.168.222.0/192.168.222.100 HTTP/1.1" 200 171 0.0007 D, [2016-08-12T09:07:53.078953 #30887] DEBUG -- : close: 192.168.122.180:48302 D, [2016-08-12T09:07:53.280631 #30887] DEBUG -- : accept: 192.168.122.180:48303 D, [2016-08-12T09:07:53.282694 #30887] DEBUG -- : Rack::Handler::WEBrick is invoked. D, [2016-08-12T09:07:53.283232 #30887] DEBUG -- : verifying remote client 192.168.122.180 against trusted_hosts ["fseven.zzz.lan"] D, [2016-08-12T09:07:53.283406 #30887] DEBUG -- : Loading subnets for 127.0.0.1 D, [2016-08-12T09:07:53.283591 #30887] DEBUG -- : Loading subnet data for 192.168.222.0/255.255.255.0 E, [2016-08-12T09:07:53.283712 #30887] ERROR -- : DHCP record 192.168.222.0/52:54:00:f9:56:da not found D, [2016-08-12T09:07:53.283747 #30887] DEBUG -- : DHCP record 192.168.222.0/52:54:00:f9:56:da not found I, [2016-08-12T09:07:53.283956 #30887] INFO -- : 192.168.122.180 - - [12/Aug/2016:09:07:53 -0400] "GET /dhcp/192.168.222.0/52:54:00:f9:56:da HTTP/1.1" 404 53 0.0008 D, [2016-08-12T09:07:53.324097 #30887] DEBUG -- : close: 192.168.122.180:48303 D, [2016-08-12T09:07:53.362299 #30887] DEBUG -- : accept: 192.168.122.180:48304 D, [2016-08-12T09:07:53.364839 #30887] DEBUG -- : Rack::Handler::WEBrick is invoked. D, [2016-08-12T09:07:53.365724 #30887] DEBUG -- : verifying remote client 192.168.122.180 against trusted_hosts ["fseven.zzz.lan"] D, [2016-08-12T09:07:53.366011 #30887] DEBUG -- : Loading subnets for 127.0.0.1 D, [2016-08-12T09:07:53.366275 #30887] DEBUG -- : Loading subnet data for 192.168.222.0/255.255.255.0 I, [2016-08-12T09:07:53.366717 #30887] INFO -- : 192.168.122.180 - - [12/Aug/2016:09:07:53 -0400] "GET /dhcp/192.168.222.0/192.168.222.100 HTTP/1.1" 200 171 0.0011 D, [2016-08-12T09:07:53.407159 #30887] DEBUG -- : close: 192.168.122.180:48304 D, [2016-08-12T09:07:53.447048 #30887] DEBUG -- : accept: 192.168.122.180:48305 D, [2016-08-12T09:07:53.449263 #30887] DEBUG -- : Rack::Handler::WEBrick is invoked. D, [2016-08-12T09:07:53.450055 #30887] DEBUG -- : verifying remote client 192.168.122.180 against trusted_hosts ["fseven.zzz.lan"] D, [2016-08-12T09:07:53.450310 #30887] DEBUG -- : Loading subnets for 127.0.0.1 D, [2016-08-12T09:07:53.450553 #30887] DEBUG -- : Loading subnet data for 192.168.222.0/255.255.255.0 D, [2016-08-12T09:07:53.454211 #30887] DEBUG -- : omshell: executed - set hardware-address = 52:54:00:f9:56:db D, [2016-08-12T09:07:53.454353 #30887] DEBUG -- : nil D, [2016-08-12T09:07:53.454473 #30887] DEBUG -- : omshell: executed - open D, [2016-08-12T09:07:53.454565 #30887] DEBUG -- : nil D, [2016-08-12T09:07:53.454656 #30887] DEBUG -- : omshell: executed - remove D, [2016-08-12T09:07:53.454737 #30887] DEBUG -- : nil D, [2016-08-12T09:07:53.576289 #30887] DEBUG -- : Removed DHCP reservation for rrtrte.nested.lan => rrtrte.nested.lan (192.168.222.100 / 52:54:00:f9:56:db) I, [2016-08-12T09:07:53.576936 #30887] INFO -- : 192.168.122.180 - - [12/Aug/2016:09:07:53 -0400] "DELETE /dhcp/192.168.222.0/52:54:00:f9:56:db HTTP/1.1" 200 - 0.1270 D, [2016-08-12T09:07:53.578162 #30887] DEBUG -- : close: 192.168.122.180:48305 D, [2016-08-12T09:07:53.624704 #30887] DEBUG -- : accept: 192.168.122.180:48307 D, [2016-08-12T09:07:53.627171 #30887] DEBUG -- : Rack::Handler::WEBrick is invoked. D, [2016-08-12T09:07:53.628179 #30887] DEBUG -- : verifying remote client 192.168.122.180 against trusted_hosts ["fseven.zzz.lan"] I, [2016-08-12T09:07:53.628794 #30887] INFO -- : 192.168.122.180 - - [12/Aug/2016:09:07:53 -0400] "GET /tftp/serverName HTTP/1.1" 200 30 0.0008 D, [2016-08-12T09:07:53.669185 #30887] DEBUG -- : close: 192.168.122.180:48307 D, [2016-08-12T09:07:53.712146 #30887] DEBUG -- : accept: 192.168.122.180:48308 D, [2016-08-12T09:07:53.714483 #30887] DEBUG -- : Rack::Handler::WEBrick is invoked. D, [2016-08-12T09:07:53.715364 #30887] DEBUG -- : verifying remote client 192.168.122.180 against trusted_hosts ["fseven.zzz.lan"] D, [2016-08-12T09:07:53.715745 #30887] DEBUG -- : Loading subnets for 127.0.0.1 D, [2016-08-12T09:07:53.715976 #30887] DEBUG -- : Loading subnet data for 192.168.222.0/255.255.255.0 D, [2016-08-12T09:07:53.719236 #30887] DEBUG -- : omshell: executed - set hardware-address = 52:54:00:f9:56:db D, [2016-08-12T09:07:53.719329 #30887] DEBUG -- : nil D, [2016-08-12T09:07:53.719390 #30887] DEBUG -- : omshell: executed - open D, [2016-08-12T09:07:53.719464 #30887] DEBUG -- : nil D, [2016-08-12T09:07:53.719522 #30887] DEBUG -- : omshell: executed - remove D, [2016-08-12T09:07:53.719595 #30887] DEBUG -- : nil ==> /var/log/foreman/production.log <== 2016-08-12 09:07:52 f7334e9f [app] [I] Started PATCH "/hosts/rrtrte.nested.lan" for 192.168.122.1 at 2016-08-12 09:07:52 -0400 2016-08-12 09:07:52 f7334e9f [app] [I] Processing by HostsController#update as */* 2016-08-12 09:07:52 f7334e9f [app] [I] Parameters: {"utf8"=>"✓", "authenticity_token"=>"J/8B/RWCOKIt7ok2SFNAQBXAQ0toVHXCazIOlDSrAflcQ2Fu5iZjXYLjSZ2nIdp3FcU2vJHk+uegl8JJx75bcg==", "host"=>{"name"=>"rrtrte", "hostgroup_id"=>"1", "environment_id"=>"1", "puppet_ca_proxy_id"=>"1", "puppet_proxy_id"=>"1", "puppetclass_ids"=>[""], "managed"=>"true", "progress_report_id"=>"[FILTERED]", "interfaces_attributes"=>{"0"=>{"_destroy"=>"0", "mac"=>"52:54:00:f9:56:da", "identifier"=>"", "name"=>"rrtrte", "domain_id"=>"2", "subnet_id"=>"1", "ip"=>"192.168.222.100", "ip6"=>"", "managed"=>"1", "primary"=>"1", "provision"=>"1", "tag"=>"", "attached_to"=>"", "id"=>"6"}}, "architecture_id"=>"1", "operatingsystem_id"=>"2", "medium_id"=>"1", "ptable_id"=>"68", "disk"=>"", "root_pass"=>"[FILTERED]", "is_owned_by"=>"3-Users", "enabled"=>"1", "model_id"=>"", "comment"=>"", "overwrite"=>"true"}, "bare_metal_capabilities"=>"build", "id"=>"rrtrte.nested.lan"} 2016-08-12 09:07:52 f7334e9f [app] [D] Setting current user thread-local variable to admin 2016-08-12 09:07:52 f7334e9f [app] [D] Setting current organization thread-local variable to none 2016-08-12 09:07:52 f7334e9f [app] [D] Setting current location thread-local variable to none 2016-08-12 09:07:53 f7334e9f [app] [I] Delete DHCP reservation for rrtrte.nested.lan-52:54:00:f9:56:db/192.168.222.100 2016-08-12 09:07:53 f7334e9f [app] [I] Delete DHCP reservation for rrtrte.nested.lan-52:54:00:f9:56:db/192.168.222.100 ==> /var/log/httpd/foreman-ssl_access_ssl.log <== 192.168.122.1 - - [12/Aug/2016:09:07:52 -0400] "POST /hosts/rrtrte.nested.lan HTTP/1.1" 200 9773 "https://fseven.zzz.lan/hosts/rrtrte.nested.lan/edit" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/52.0.2743.116 Safari/537.36" 192.168.122.1 - - [12/Aug/2016:09:07:54 -0400] "GET /tasks/641ec5a8-2fc6-496e-993b-001947d24bef HTTP/1.1" 200 221 "https://fseven.zzz.lan/hosts/rrtrte.nested.lan/edit" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/52.0.2743.116 Safari/537.36" ==> /var/log/foreman-proxy/proxy.log <== E, [2016-08-12T09:07:53.738804 #30887] ERROR -- : Omshell failed: > > > obj: <null> , > obj: host , > obj: host , hardware-address = 52:54:00:f9:56:db , > can't open object: not found , obj: host , hardware-address = 52:54:00:f9:56:db , > can't destroy object: not found , obj: host , hardware-address = 52:54:00:f9:56:db , > E, [2016-08-12T09:07:53.739284 #30887] ERROR -- : DHCP record 192.168.222.0/52:54:00:f9:56:db not found D, [2016-08-12T09:07:53.739356 #30887] DEBUG -- : DHCP record 192.168.222.0/52:54:00:f9:56:db not found I, [2016-08-12T09:07:53.739855 #30887] INFO -- : 192.168.122.180 - - [12/Aug/2016:09:07:53 -0400] "DELETE /dhcp/192.168.222.0/52:54:00:f9:56:db HTTP/1.1" 404 53 0.0246 D, [2016-08-12T09:07:53.780232 #30887] DEBUG -- : close: 192.168.122.180:48308 D, [2016-08-12T09:07:53.825776 #30887] DEBUG -- : accept: 192.168.122.180:48310 D, [2016-08-12T09:07:53.828207 #30887] DEBUG -- : Rack::Handler::WEBrick is invoked. D, [2016-08-12T09:07:53.829675 #30887] DEBUG -- : verifying remote client 192.168.122.180 against trusted_hosts ["fseven.zzz.lan"] D, [2016-08-12T09:07:53.829982 #30887] DEBUG -- : Loading subnets for 127.0.0.1 D, [2016-08-12T09:07:53.830227 #30887] DEBUG -- : Loading subnet data for 192.168.222.0/255.255.255.0 W, [2016-08-12T09:07:53.830506 #30887] WARN -- : Request to create a conflicting DHCP record D, [2016-08-12T09:07:53.830647 #30887] DEBUG -- : request: {"nextServer"=>"192.168.222.1", "filename"=>"pxelinux.0", :hostname=>"rrtrte.nested.lan", :subnet=>192.168.222.0/255.255.255.0, :ip=>"192.168.222.100", :mac=>"52:54:00:f9:56:da"} D, [2016-08-12T09:07:53.830763 #30887] DEBUG -- : local: {:hostname=>"rrtrte.nested.lan", :mac=>"52:54:00:f9:56:db", :ip=>"192.168.222.100", :filename=>"pxelinux.0", :nextServer=>"c0:a8:de:01", :subnet=>192.168.222.0/255.255.255.0} E, [2016-08-12T09:07:53.830953 #30887] ERROR -- : DHCP record 192.168.222.0/192.168.222.100 already exists D, [2016-08-12T09:07:53.831025 #30887] DEBUG -- : DHCP record 192.168.222.0/192.168.222.100 already exists (Proxy::DHCP::Collision) /usr/share/foreman-proxy/modules/dhcp_common/server.rb:127:in `add_record' /usr/share/foreman-proxy/modules/dhcp_isc/dhcp_isc_main.rb:31:in `add_record' /usr/share/foreman-proxy/modules/dhcp/dhcp_api.rb:88:in `block in <class:DhcpApi>' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:1293:in `call' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:1293:in `block in compile!' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:860:in `[]' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:860:in `block (3 levels) in route!' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:876:in `route_eval' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:860:in `block (2 levels) in route!' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:897:in `block in process_route' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:895:in `catch' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:895:in `process_route' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:859:in `block in route!' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:858:in `each' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:858:in `route!' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:963:in `block in dispatch!' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:946:in `block in invoke' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:946:in `catch' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:946:in `invoke' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:960:in `dispatch!' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:794:in `block in call!' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:946:in `block in invoke' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:946:in `catch' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:946:in `invoke' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:794:in `call!' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:780: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.3.5/lib/sinatra/base.rb:161:in `call' /usr/share/foreman-proxy/lib/proxy/log.rb:63: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.3.5/lib/sinatra/showexceptions.rb:21:in `call' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:124:in `call' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:1417:in `block in call' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:1499:in `synchronize' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:1417: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, [2016-08-12T09:07:53.831556 #30887] INFO -- : 192.168.122.180 - - [12/Aug/2016:09:07:53 -0400] "POST /dhcp/192.168.222.0 HTTP/1.1" 409 56 0.0024 D, [2016-08-12T09:07:53.872275 #30887] DEBUG -- : close: 192.168.122.180:48310 D, [2016-08-12T09:07:53.918199 #30887] DEBUG -- : accept: 192.168.122.180:48311 D, [2016-08-12T09:07:53.920440 #30887] DEBUG -- : Rack::Handler::WEBrick is invoked. D, [2016-08-12T09:07:53.921828 #30887] DEBUG -- : verifying remote client 192.168.122.180 against trusted_hosts ["fseven.zzz.lan"] D, [2016-08-12T09:07:53.922145 #30887] DEBUG -- : Loading subnets for 127.0.0.1 D, [2016-08-12T09:07:53.922360 #30887] DEBUG -- : Loading subnet data for 192.168.222.0/255.255.255.0 W, [2016-08-12T09:07:53.922627 #30887] WARN -- : Request to create a conflicting DHCP record D, [2016-08-12T09:07:53.922753 #30887] DEBUG -- : request: {"nextServer"=>"192.168.222.1", "filename"=>"pxelinux.0", :hostname=>"rrtrte.nested.lan", :subnet=>192.168.222.0/255.255.255.0, :ip=>"192.168.222.100", :mac=>"52:54:00:f9:56:db"} D, [2016-08-12T09:07:53.922880 #30887] DEBUG -- : local: {:hostname=>"rrtrte.nested.lan", :mac=>"52:54:00:f9:56:db", :ip=>"192.168.222.100", :filename=>"pxelinux.0", :nextServer=>"c0:a8:de:01", :subnet=>192.168.222.0/255.255.255.0} E, [2016-08-12T09:07:53.923070 #30887] ERROR -- : DHCP record 192.168.222.0/192.168.222.100 already exists D, [2016-08-12T09:07:53.923130 #30887] DEBUG -- : DHCP record 192.168.222.0/192.168.222.100 already exists (Proxy::DHCP::Collision) /usr/share/foreman-proxy/modules/dhcp_common/server.rb:127:in `add_record' /usr/share/foreman-proxy/modules/dhcp_isc/dhcp_isc_main.rb:31:in `add_record' /usr/share/foreman-proxy/modules/dhcp/dhcp_api.rb:88:in `block in <class:DhcpApi>' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:1293:in `call' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:1293:in `block in compile!' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:860:in `[]' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:860:in `block (3 levels) in route!' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:876:in `route_eval' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:860:in `block (2 levels) in route!' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:897:in `block in process_route' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:895:in `catch' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:895:in `process_route' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:859:in `block in route!' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:858:in `each' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:858:in `route!' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:963:in `block in dispatch!' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:946:in `block in invoke' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:946:in `catch' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:946:in `invoke' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:960:in `dispatch!' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:794:in `block in call!' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:946:in `block in invoke' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:946:in `catch' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:946:in `invoke' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:794:in `call!' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:780: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.3.5/lib/sinatra/base.rb:161:in `call' /usr/share/foreman-proxy/lib/proxy/log.rb:63: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.3.5/lib/sinatra/showexceptions.rb:21:in `call' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:124:in `call' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:1417:in `block in call' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:1499:in `synchronize' /usr/share/gems/gems/sinatra-1.3.5/lib/sinatra/base.rb:1417: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, [2016-08-12T09:07:53.923695 #30887] INFO -- : 192.168.122.180 - - [12/Aug/2016:09:07:53 -0400] "POST /dhcp/192.168.222.0 HTTP/1.1" 409 56 0.0023 D, [2016-08-12T09:07:53.964124 #30887] DEBUG -- : close: 192.168.122.180:48311 D, [2016-08-12T09:07:54.003586 #30887] DEBUG -- : accept: 192.168.122.180:48312 D, [2016-08-12T09:07:54.005270 #30887] DEBUG -- : Rack::Handler::WEBrick is invoked. D, [2016-08-12T09:07:54.005819 #30887] DEBUG -- : verifying remote client 192.168.122.180 against trusted_hosts ["fseven.zzz.lan"] D, [2016-08-12T09:07:54.005983 #30887] DEBUG -- : Loading subnets for 127.0.0.1 D, [2016-08-12T09:07:54.006138 #30887] DEBUG -- : Loading subnet data for 192.168.222.0/255.255.255.0 E, [2016-08-12T09:07:54.006260 #30887] ERROR -- : DHCP record 192.168.222.0/52:54:00:f9:56:da not found D, [2016-08-12T09:07:54.006297 #30887] DEBUG -- : DHCP record 192.168.222.0/52:54:00:f9:56:da not found I, [2016-08-12T09:07:54.006509 #30887] INFO -- : 192.168.122.180 - - [12/Aug/2016:09:07:54 -0400] "GET /dhcp/192.168.222.0/52:54:00:f9:56:da HTTP/1.1" 404 53 0.0008 D, [2016-08-12T09:07:54.047039 #30887] DEBUG -- : close: 192.168.122.180:48312 D, [2016-08-12T09:07:54.082583 #30887] DEBUG -- : accept: 192.168.122.180:48313 D, [2016-08-12T09:07:54.084200 #30887] DEBUG -- : Rack::Handler::WEBrick is invoked. D, [2016-08-12T09:07:54.084718 #30887] DEBUG -- : verifying remote client 192.168.122.180 against trusted_hosts ["fseven.zzz.lan"] D, [2016-08-12T09:07:54.084879 #30887] DEBUG -- : Loading subnets for 127.0.0.1 D, [2016-08-12T09:07:54.085019 #30887] DEBUG -- : Loading subnet data for 192.168.222.0/255.255.255.0 I, [2016-08-12T09:07:54.085248 #30887] INFO -- : 192.168.122.180 - - [12/Aug/2016:09:07:54 -0400] "GET /dhcp/192.168.222.0/192.168.222.100 HTTP/1.1" 200 171 0.0006 D, [2016-08-12T09:07:54.125846 #30887] DEBUG -- : close: 192.168.122.180:48313 D, [2016-08-12T09:07:54.158531 #30887] DEBUG -- : accept: 192.168.122.180:48314 D, [2016-08-12T09:07:54.160282 #30887] DEBUG -- : Rack::Handler::WEBrick is invoked. D, [2016-08-12T09:07:54.161273 #30887] DEBUG -- : verifying remote client 192.168.122.180 against trusted_hosts ["fseven.zzz.lan"] D, [2016-08-12T09:07:54.161470 #30887] DEBUG -- : Loading subnets for 127.0.0.1 D, [2016-08-12T09:07:54.161618 #30887] DEBUG -- : Loading subnet data for 192.168.222.0/255.255.255.0 D, [2016-08-12T09:07:54.161769 #30887] DEBUG -- : We already got the same DHCP record - skipping I, [2016-08-12T09:07:54.161998 #30887] INFO -- : 192.168.122.180 - - [12/Aug/2016:09:07:54 -0400] "POST /dhcp/192.168.222.0 HTTP/1.1" 200 - 0.0011 D, [2016-08-12T09:07:54.162869 #30887] DEBUG -- : close: 192.168.122.180:48314 ==> /var/log/foreman/production.log <== 2016-08-12 09:07:53 f7334e9f [app] [I] Create DHCP reservation for rrtrte.nested.lan-52:54:00:f9:56:da/192.168.222.100 2016-08-12 09:07:53 f7334e9f [app] [D] DHCP reservation on net 192.168.222.0 with attrs: {:hostname=>"rrtrte.nested.lan", :mac=>"52:54:00:f9:56:da", :ip=>"192.168.222.100", :network=>"192.168.222.0", :nextServer=>"192.168.222.1", :filename=>"pxelinux.0"} 2016-08-12 09:07:53 f7334e9f [app] [W] Create DHCP Settings for rrtrte.nested.lan task failed with the following error: ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::Conflict]: 409 Conflict) for proxy https://fseven.zzz.lan:8443/dhcp | ProxyAPI::ProxyException: ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::Conflict]: 409 Conflict) for proxy https://fseven.zzz.lan:8443/dhcp | /usr/share/foreman/lib/proxy_api/dhcp.rb:66:in `rescue in set' | /usr/share/foreman/lib/proxy_api/dhcp.rb:62:in `set' | /usr/share/foreman/lib/net/dhcp/record.rb:29:in `create' | /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:57:in `set_dhcp' | /usr/share/foreman/app/models/concerns/orchestration.rb:191:in `execute' | /usr/share/foreman/app/models/concerns/orchestration.rb:131:in `block in process' | /usr/share/foreman/app/models/concerns/orchestration.rb:123:in `each' | /usr/share/foreman/app/models/concerns/orchestration.rb:123:in `process' | /usr/share/foreman/app/models/concerns/orchestration.rb:35:in `around_save_orchestration' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:432:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:92:in `__run_callbacks__' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:778:in `_run_save_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/callbacks.rb:302:in `create_or_update' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/persistence.rb:120:in `save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/validations.rb:37:in `save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/attribute_methods/dirty.rb:21:in `save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:286:in `block (2 levels) in save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:351:in `block in with_transaction_returning_status' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:211:in `transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:220:in `transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:348:in `with_transaction_returning_status' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:286:in `block in save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:301:in `rollback_active_record_state!' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:285:in `save' | /usr/share/foreman/app/models/concerns/foreman/sti.rb:29:in `save_with_type' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/persistence.rb:252:in `block in update' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:351:in `block in with_transaction_returning_status' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `block in transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/transaction.rb:184:in `within_new_transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:220:in `transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:348:in `with_transaction_returning_status' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/persistence.rb:250:in `update' | /usr/share/foreman/app/controllers/hosts_controller.rb:110:in `block in update' | /usr/share/foreman/app/models/taxonomy.rb:59:in `block in no_taxonomy_scope' | /usr/share/foreman/app/models/taxonomy.rb:66:in `block (2 levels) in as_taxonomy' | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:147:in `as_location' | /usr/share/foreman/app/models/taxonomy.rb:65:in `block in as_taxonomy' | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:112:in `as_org' | /usr/share/foreman/app/models/taxonomy.rb:64:in `as_taxonomy' | /usr/share/foreman/app/models/taxonomy.rb:58:in `no_taxonomy_scope' | /usr/share/foreman/app/controllers/hosts_controller.rb:107:in `update' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/implicit_render.rb:4:in `send_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/base.rb:198:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/rendering.rb:10:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/callbacks.rb:20:in `block in process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:117:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:117:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:555:in `block (2 levels) in compile' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:in `block (2 levels) in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `block (2 levels) in halting' | /opt/theforeman/tfm/root/usr/share/gems/gems/rails-observers-0.1.2/lib/rails/observers/action_controller/caching/sweeping.rb:73:in `around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:455:in `public_send' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:455:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:in `block (2 levels) in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `block (2 levels) in halting' | /usr/share/foreman/app/controllers/concerns/application_shared.rb:14:in `set_timezone' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:432:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:in `block (2 levels) in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `block (2 levels) in halting' | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:432:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:in `block (2 levels) in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `block (2 levels) in halting' | /opt/theforeman/tfm/root/usr/share/gems/gems/rails-observers-0.1.2/lib/rails/observers/action_controller/caching/sweeping.rb:73:in `around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:455:in `public_send' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:455:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:92:in `__run_callbacks__' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:778:in `_run_process_action_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:81:in `run_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/callbacks.rb:19:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/rescue.rb:29:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/notifications.rb:164:in `block in instrument' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/notifications/instrumenter.rb:20:in `instrument' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/notifications.rb:164:in `instrument' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/instrumentation.rb:30:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/params_wrapper.rb:250:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/railties/controller_runtime.rb:18:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/base.rb:137:in `process' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionview-4.2.5.1/lib/action_view/rendering.rb:30:in `process' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal.rb:196:in `dispatch' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/rack_delegation.rb:13:in `dispatch' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal.rb:237:in `block in action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/route_set.rb:74:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/route_set.rb:74:in `dispatch' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/route_set.rb:43:in `serve' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/journey/router.rb:43:in `block in serve' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/journey/router.rb:30:in `each' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/journey/router.rb:30:in `serve' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/route_set.rb:815:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.3.6/lib/apipie/static_dispatcher.rb:65:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.3.6/lib/apipie/extractor/recorder.rb:132:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.3.6/lib/apipie/middleware/checksum_in_headers.rb:27:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/etag.rb:24:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/conditionalget.rb:38:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/head.rb:13:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/params_parser.rb:27:in `call' | /usr/share/foreman/lib/middleware/catch_json_parse_errors.rb:9:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/flash.rb:260:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/session/abstract/id.rb:225:in `context' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/session/abstract/id.rb:220:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/cookies.rb:560:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/query_cache.rb:36:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:653:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/callbacks.rb:29:in `block in call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:88:in `__run_callbacks__' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:778:in `_run_call_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:81:in `run_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/callbacks.rb:27:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/remote_ip.rb:78:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/debug_exceptions.rb:17:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/show_exceptions.rb:30:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/rack/logger.rb:38:in `call_app' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/rack/logger.rb:22:in `call' | /usr/share/foreman/lib/middleware/tagged_logging.rb:18:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/request_id.rb:21:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/methodoverride.rb:22:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/runtime.rb:18:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/static.rb:116:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/sendfile.rb:113:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/engine.rb:518:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/application.rb:165:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/railtie.rb:194:in `public_send' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/railtie.rb:194:in `method_missing' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/urlmap.rb:66:in `block in call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/urlmap.rb:50:in `each' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/urlmap.rb:50: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-1.8.2/lib/logging/diagnostic_context.rb:323:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context' 2016-08-12 09:07:53 f7334e9f [app] [I] Create DHCP reservation for rrtrte.nested.lan-52:54:00:f9:56:db/192.168.222.100 2016-08-12 09:07:53 f7334e9f [app] [D] DHCP reservation on net 192.168.222.0 with attrs: {:hostname=>"rrtrte.nested.lan", :mac=>"52:54:00:f9:56:db", :ip=>"192.168.222.100", :network=>"192.168.222.0", :nextServer=>"192.168.222.1", :filename=>"pxelinux.0"} 2016-08-12 09:07:53 f7334e9f [app] [W] Failed to perform rollback on Remove DHCP Settings for rrtrte.nested.lan - ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::Conflict]: 409 Conflict) for proxy https://fseven.zzz.lan:8443/dhcp | ProxyAPI::ProxyException: ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::Conflict]: 409 Conflict) for proxy https://fseven.zzz.lan:8443/dhcp | /usr/share/foreman/lib/proxy_api/dhcp.rb:66:in `rescue in set' | /usr/share/foreman/lib/proxy_api/dhcp.rb:62:in `set' | /usr/share/foreman/lib/net/dhcp/record.rb:29:in `create' | /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:57:in `set_dhcp' | /usr/share/foreman/app/models/concerns/orchestration.rb:191:in `execute' | /usr/share/foreman/app/models/concerns/orchestration.rb:161:in `block in fail_queue' | /usr/share/foreman/app/models/concerns/orchestration.rb:157:in `reverse_each' | /usr/share/foreman/app/models/concerns/orchestration.rb:157:in `fail_queue' | /usr/share/foreman/app/models/concerns/orchestration.rb:147:in `process' | /usr/share/foreman/app/models/concerns/orchestration.rb:35:in `around_save_orchestration' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:432:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:92:in `__run_callbacks__' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:778:in `_run_save_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/callbacks.rb:302:in `create_or_update' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/persistence.rb:120:in `save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/validations.rb:37:in `save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/attribute_methods/dirty.rb:21:in `save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:286:in `block (2 levels) in save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:351:in `block in with_transaction_returning_status' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:211:in `transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:220:in `transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:348:in `with_transaction_returning_status' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:286:in `block in save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:301:in `rollback_active_record_state!' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:285:in `save' | /usr/share/foreman/app/models/concerns/foreman/sti.rb:29:in `save_with_type' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/persistence.rb:252:in `block in update' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:351:in `block in with_transaction_returning_status' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `block in transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/transaction.rb:184:in `within_new_transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:220:in `transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:348:in `with_transaction_returning_status' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/persistence.rb:250:in `update' | /usr/share/foreman/app/controllers/hosts_controller.rb:110:in `block in update' | /usr/share/foreman/app/models/taxonomy.rb:59:in `block in no_taxonomy_scope' | /usr/share/foreman/app/models/taxonomy.rb:66:in `block (2 levels) in as_taxonomy' | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:147:in `as_location' | /usr/share/foreman/app/models/taxonomy.rb:65:in `block in as_taxonomy' | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:112:in `as_org' | /usr/share/foreman/app/models/taxonomy.rb:64:in `as_taxonomy' | /usr/share/foreman/app/models/taxonomy.rb:58:in `no_taxonomy_scope' | /usr/share/foreman/app/controllers/hosts_controller.rb:107:in `update' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/implicit_render.rb:4:in `send_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/base.rb:198:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/rendering.rb:10:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/callbacks.rb:20:in `block in process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:117:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:117:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:555:in `block (2 levels) in compile' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:in `block (2 levels) in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `block (2 levels) in halting' | /opt/theforeman/tfm/root/usr/share/gems/gems/rails-observers-0.1.2/lib/rails/observers/action_controller/caching/sweeping.rb:73:in `around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:455:in `public_send' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:455:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:in `block (2 levels) in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `block (2 levels) in halting' | /usr/share/foreman/app/controllers/concerns/application_shared.rb:14:in `set_timezone' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:432:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:in `block (2 levels) in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `block (2 levels) in halting' | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:432:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:in `block (2 levels) in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `block (2 levels) in halting' | /opt/theforeman/tfm/root/usr/share/gems/gems/rails-observers-0.1.2/lib/rails/observers/action_controller/caching/sweeping.rb:73:in `around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:455:in `public_send' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:455:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:92:in `__run_callbacks__' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:778:in `_run_process_action_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:81:in `run_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/callbacks.rb:19:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/rescue.rb:29:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/notifications.rb:164:in `block in instrument' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/notifications/instrumenter.rb:20:in `instrument' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/notifications.rb:164:in `instrument' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/instrumentation.rb:30:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/params_wrapper.rb:250:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/railties/controller_runtime.rb:18:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/base.rb:137:in `process' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionview-4.2.5.1/lib/action_view/rendering.rb:30:in `process' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal.rb:196:in `dispatch' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/rack_delegation.rb:13:in `dispatch' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal.rb:237:in `block in action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/route_set.rb:74:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/route_set.rb:74:in `dispatch' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/route_set.rb:43:in `serve' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/journey/router.rb:43:in `block in serve' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/journey/router.rb:30:in `each' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/journey/router.rb:30:in `serve' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/route_set.rb:815:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.3.6/lib/apipie/static_dispatcher.rb:65:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.3.6/lib/apipie/extractor/recorder.rb:132:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.3.6/lib/apipie/middleware/checksum_in_headers.rb:27:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/etag.rb:24:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/conditionalget.rb:38:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/head.rb:13:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/params_parser.rb:27:in `call' | /usr/share/foreman/lib/middleware/catch_json_parse_errors.rb:9:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/flash.rb:260:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/session/abstract/id.rb:225:in `context' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/session/abstract/id.rb:220:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/cookies.rb:560:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/query_cache.rb:36:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:653:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/callbacks.rb:29:in `block in call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:88:in `__run_callbacks__' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:778:in `_run_call_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:81:in `run_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/callbacks.rb:27:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/remote_ip.rb:78:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/debug_exceptions.rb:17:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/show_exceptions.rb:30:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/rack/logger.rb:38:in `call_app' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/rack/logger.rb:22:in `call' | /usr/share/foreman/lib/middleware/tagged_logging.rb:18:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/request_id.rb:21:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/methodoverride.rb:22:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/runtime.rb:18:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/static.rb:116:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/sendfile.rb:113:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/engine.rb:518:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/application.rb:165:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/railtie.rb:194:in `public_send' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/railtie.rb:194:in `method_missing' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/urlmap.rb:66:in `block in call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/urlmap.rb:50:in `each' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/urlmap.rb:50: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-1.8.2/lib/logging/diagnostic_context.rb:323:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context' 2016-08-12 09:07:54 f7334e9f [app] [I] Create DHCP reservation for rrtrte.nested.lan-52:54:00:f9:56:db/192.168.222.100 2016-08-12 09:07:54 f7334e9f [app] [D] DHCP reservation on net 192.168.222.0 with attrs: {:hostname=>"rrtrte.nested.lan", :mac=>"52:54:00:f9:56:db", :ip=>"192.168.222.100", :network=>"192.168.222.0", :nextServer=>"c0:a8:de:01", :filename=>"pxelinux.0"} 2016-08-12 09:07:54 f7334e9f [app] [I] Failed to save: Create DHCP Settings for rrtrte.nested.lan task failed with the following error: ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::Conflict]: 409 Conflict) for proxy https://fseven.zzz.lan:8443/dhcp, Failed to perform rollback on Remove DHCP Settings for rrtrte.nested.lan - ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::Conflict]: 409 Conflict) for proxy https://fseven.zzz.lan:8443/dhcp 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered hosts/_progress.html.erb (0.2ms) 2016-08-12 09:07:54 f7334e9f [app] [D] Setting current organization thread-local variable to none 2016-08-12 09:07:54 f7334e9f [app] [D] Setting current location thread-local variable to none 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered puppetclasses/_selectedClasses.html.erb (0.0ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered puppetclasses/_classes_in_groups.html.erb (0.0ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered puppetclasses/_classes.html.erb (0.1ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered puppetclasses/_class_selection.html.erb (35.4ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered nic/_base_form.html.erb (22.7ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered nic/_virtual_form.html.erb (1.3ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered nic/_provider_specific_form.html.erb (0.1ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered nic/manageds/_managed.html.erb (25.8ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered nic/_base_form.html.erb (12.7ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered nic/_virtual_form.html.erb (1.0ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered nic/_provider_specific_form.html.erb (0.1ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered nic/manageds/_managed.html.erb (15.2ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered hosts/_interfaces.html.erb (43.4ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered common/os_selection/_architecture.html.erb (5.1ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Started GET "/tasks/641ec5a8-2fc6-496e-993b-001947d24bef" for 192.168.122.1 at 2016-08-12 09:07:54 -0400 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered common/os_selection/_operatingsystem.html.erb (9.5ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered hosts/provision_method/build/_form.html.erb (10.3ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered hosts/provision_method/image/_form.html.erb (0.1ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered hosts/_operating_system.html.erb (20.1ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered hosts/_unattended.html.erb (20.3ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered puppetclasses/_class_parameters.html.erb (0.0ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered puppetclasses/_classes_parameters.html.erb (8.7ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered common_parameters/_inherited_parameters.html.erb (0.1ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered common_parameters/_parameter.html.erb (1.4ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered common_parameters/_parameters.html.erb (3.1ms) 2016-08-12 09:07:54 f7334e9f [app] [D] Setting current location thread-local variable to none 2016-08-12 09:07:54 f7334e9f [app] [D] Setting current organization thread-local variable to none 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered hosts/_form.html.erb (154.0ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered hosts/edit.html.erb within layouts/application (156.3ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered layouts/_application_content.html.erb (0.2ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered home/_user_dropdown.html.erb (1.7ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Read fragment views/tabs_and_title_records-3 (0.1ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered home/_topbar.html.erb (5.7ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered layouts/base.html.erb (6.6ms) 2016-08-12 09:07:54 f7334e9f [app] [D] Setting current location thread-local variable to none 2016-08-12 09:07:54 f7334e9f [app] [D] Setting current organization thread-local variable to none 2016-08-12 09:07:54 f7334e9f [app] [I] Completed 200 OK in 1590ms (Views: 154.4ms | ActiveRecord: 26.1ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Processing by TasksController#show as */* 2016-08-12 09:07:54 f7334e9f [app] [I] Parameters: {"id"=>"641ec5a8-2fc6-496e-993b-001947d24bef"} 2016-08-12 09:07:54 f7334e9f [app] [D] Setting current user thread-local variable to admin 2016-08-12 09:07:54 f7334e9f [app] [I] Rendered tasks/_list.html.erb (1.0ms) 2016-08-12 09:07:54 f7334e9f [app] [I] Completed 200 OK in 88ms (Views: 7.5ms | ActiveRecord: 5.8ms)
Note the two lines:
2016-08-12 09:07:53 f7334e9f [app] [I] Delete DHCP reservation for rrtrte.nested.lan-52:54:00:f9:56:db/192.168.222.100 2016-08-12 09:07:53 f7334e9f [app] [I] Delete DHCP reservation for rrtrte.nested.lan-52:54:00:f9:56:db/192.168.222.100
I'd only expect this to be called once, the second attempt fails, and the rollback too. This time, the entry was deleted (but not rollbacked):
[root@fseven ~]# cat /var/lib/dhcpd/dhcpd.leases # The format of this file is documented in the dhcpd.leases(5) manual page. # This lease file was written by isc-dhcp-4.2.5 host rrtrte.nested.lan { dynamic; hardware ethernet 52:54:00:f9:56:db; fixed-address 192.168.222.100; supersede server.filename = "pxelinux.0"; supersede server.next-server = c0:a8:de:01; supersede host-name = "rrtrte.nested.lan"; } server-duid "\000\001\000\001\037>\3465RT\304\236\023\005"; host rrtrte.nested.lan { dynamic; deleted; }
Since the behavior changed after I restarted proxy process, I suspect our DHCP parsing optimization code.
Updated by Lukas Zapletal about 8 years ago
I think the double removal might be consequence of queuing via queue_remove_dhcp_conflicts
(I used the Overwrite dialog the second time, the first time I was not asked). Might be combination of two bugs actually.
Updated by Lukas Zapletal about 8 years ago
- Related to Feature #12634: New HW Model flag pxe_loader in UI/API added
Updated by Anonymous about 8 years ago
- Related to Bug #16099: Running smart-proxy in daemon mode results in missed inotify events on isc leases file added
Updated by Lukas Zapletal almost 8 years ago
- Subject changed from Editing MAC address of existing host fails with Unable to set DHCP entry - 400 Bad Request to DHCP deletion is scheduled twice on MAC change
Dmitri cloned the bug into separate issue which is smart-proxy, but I am keeping this one for the record. I believe this is a valid bug (double DHCP deletion).