Bug #16093: DHCP deletion is scheduled twice on MAC change - Foreman

Actions

Copy link

Bug #16093

open

DHCP deletion is scheduled twice on MAC change

Added by Lukas Zapletal over 7 years ago. Updated over 7 years ago.

Status:

New

Priority:

Normal

Assignee:

Category:

DHCP

Target version:

Difficulty:

Triaged:

Bugzilla link:

Pull request:

Fixed in Releases:

Found in Releases:

Red Hat JIRA:

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.

Related issues 2 (0 open — 2 closed)

Actions

Copy link

Updated by Lukas Zapletal over 7 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.

Actions

Copy link

Updated by Lukas Zapletal over 7 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.

Actions

Copy link

Updated by Lukas Zapletal over 7 years ago

Related to Feature #12634: New HW Model flag pxe_loader in UI/API added

Actions

Copy link

Updated by Anonymous over 7 years ago

Related to Bug #16099: Running smart-proxy in daemon mode results in missed inotify events on isc leases file added

Actions

Copy link

Updated by Lukas Zapletal over 7 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).

Actions

Copy link

Also available in: Atom PDF

	Related to Foreman - Feature #12634: New HW Model flag pxe_loader in UI/API	Closed	Lukas Zapletal	11/30/2015			Actions
	Related to Smart Proxy - Bug #16099: Running smart-proxy in daemon mode results in missed inotify events on isc leases file	Closed		08/12/2016			Actions

Project

General

Profile

Custom queries

Bug #16093

DHCP deletion is scheduled twice on MAC change

Updated by Lukas Zapletal over 7 years ago

Updated by Lukas Zapletal over 7 years ago

Updated by Lukas Zapletal over 7 years ago

Updated by Anonymous over 7 years ago

Updated by Lukas Zapletal over 7 years ago