Bug #16093
openDHCP deletion is scheduled twice on MAC change
Description
Attempted to change MAC address for existing host from 52:54:00:f9:56:db to 52:54:00:f9:56:da and UI failed with:
Create DHCP Settings for rrtrte.nested.lan task failed with the following error: ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::BadRequest]: 400 Bad Request) for proxy https://fseven.zzz.lan:8443/dhcp
Failed to perform rollback on Remove DHCP Settings for rrtrte.nested.lan - ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::BadRequest]: 400 Bad Request) for proxy https://fseven.zzz.lan:8443/dhcp
This is 1.13 develop version build. The DHCP reservation seems to be present and correct:
# cat /var/lib/dhcpd/dhcpd.leases # The format of this file is documented in the dhcpd.leases(5) manual page. # This lease file was written by isc-dhcp-4.2.5 host rrtrte.nested.lan { dynamic; hardware ethernet 52:54:00:f9:56:db; fixed-address 192.168.222.100; supersede server.filename = "pxelinux.0"; supersede server.next-server = c0:a8:de:01; supersede host-name = "rrtrte.nested.lan"; } server-duid "\000\001\000\001\037>\3465RT\304\236\023\005";
Here is complete log of the transaction:
==> /var/log/foreman/production.log <== 2016-08-12 08:48:04 f7334e9f [app] [I] Started GET "/hosts/rrtrte.nested.lan/edit" for 192.168.122.1 at 2016-08-12 08:48:04 -0400 2016-08-12 08:48:04 f7334e9f [app] [I] Processing by HostsController#edit as HTML 2016-08-12 08:48:04 f7334e9f [app] [I] Parameters: {"id"=>"rrtrte.nested.lan"} 2016-08-12 08:48:04 f7334e9f [app] [D] Setting current user thread-local variable to admin 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered hosts/_progress.html.erb (0.2ms) 2016-08-12 08:48:04 f7334e9f [app] [D] Setting current organization thread-local variable to none 2016-08-12 08:48:04 f7334e9f [app] [D] Setting current location thread-local variable to none 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered puppetclasses/_selectedClasses.html.erb (0.0ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered puppetclasses/_classes_in_groups.html.erb (0.0ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered puppetclasses/_classes.html.erb (0.1ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered puppetclasses/_class_selection.html.erb (38.0ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered nic/_base_form.html.erb (17.6ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered nic/_virtual_form.html.erb (1.1ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered nic/_provider_specific_form.html.erb (0.2ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered nic/manageds/_managed.html.erb (20.3ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered nic/_base_form.html.erb (13.4ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered nic/_virtual_form.html.erb (1.0ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered nic/_provider_specific_form.html.erb (0.1ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered nic/manageds/_managed.html.erb (15.9ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered hosts/_interfaces.html.erb (38.1ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered common/os_selection/_architecture.html.erb (4.3ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered common/os_selection/_operatingsystem.html.erb (9.5ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered hosts/provision_method/build/_form.html.erb (10.3ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered hosts/provision_method/image/_form.html.erb (0.1ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered hosts/_operating_system.html.erb (18.5ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered hosts/_unattended.html.erb (18.7ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered puppetclasses/_class_parameters.html.erb (0.0ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered puppetclasses/_classes_parameters.html.erb (11.5ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered common_parameters/_inherited_parameters.html.erb (0.1ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered common_parameters/_parameter.html.erb (1.4ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered common_parameters/_parameters.html.erb (4.4ms) 2016-08-12 08:48:04 f7334e9f [app] [D] Setting current location thread-local variable to none 2016-08-12 08:48:04 f7334e9f [app] [D] Setting current organization thread-local variable to none 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered hosts/_form.html.erb (206.2ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered hosts/edit.html.erb within layouts/application (208.7ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered layouts/_application_content.html.erb (0.2ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered home/_user_dropdown.html.erb (1.7ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Read fragment views/tabs_and_title_records-3 (0.1ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered home/_topbar.html.erb (5.5ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Rendered layouts/base.html.erb (6.4ms) 2016-08-12 08:48:04 f7334e9f [app] [I] Completed 200 OK in 248ms (Views: 204.1ms | ActiveRecord: 15.2ms) ==> /var/log/foreman-proxy/proxy.log <== I, [2016-08-12T08:48:15.576464 #1512] INFO -- : 192.168.122.180 - - [12/Aug/2016:08:48:15 -0400] "GET /tftp/serverName HTTP/1.1" 200 30 0.0006 E, [2016-08-12T08:48:15.662449 #1512] ERROR -- : DHCP record 192.168.222.0/52:54:00:f9:56:da not found I, [2016-08-12T08:48:15.662848 #1512] INFO -- : 192.168.122.180 - - [12/Aug/2016:08:48:15 -0400] "GET /dhcp/192.168.222.0/52:54:00:f9:56:da HTTP/1.1" 404 53 0.0012 E, [2016-08-12T08:48:15.746353 #1512] ERROR -- : DHCP record 192.168.222.0/192.168.222.100 not found I, [2016-08-12T08:48:15.746731 #1512] INFO -- : 192.168.122.180 - - [12/Aug/2016:08:48:15 -0400] "GET /dhcp/192.168.222.0/192.168.222.100 HTTP/1.1" 404 51 0.0009 ==> /var/log/foreman/production.log <== 2016-08-12 08:48:15 f7334e9f [app] [I] Started PATCH "/hosts/rrtrte.nested.lan" for 192.168.122.1 at 2016-08-12 08:48:15 -0400 2016-08-12 08:48:15 f7334e9f [app] [I] Processing by HostsController#update as */* 2016-08-12 08:48:15 f7334e9f [app] [I] Parameters: {"utf8"=>"✓", "authenticity_token"=>"/TzOsRalUJQ/ESOXbairvsU0Xs6zY6CkPNK/Y3NvgvuGgK4i5QELa5Ac4zyC2jGJxTErOUrTL4H3d3O+gHrYcA==", "host"=>{"name"=>"rrtrte", "hostgroup_id"=>"1", "environment_id"=>"1", "puppet_ca_proxy_id"=>"1", "puppet_proxy_id"=>"1", "puppetclass_ids"=>[""], "managed"=>"true", "progress_report_id"=>"[FILTERED]", "interfaces_attributes"=>{"0"=>{"_destroy"=>"0", "mac"=>"52:54:00:f9:56:da", "identifier"=>"", "name"=>"rrtrte", "domain_id"=>"2", "subnet_id"=>"1", "ip"=>"192.168.222.100", "ip6"=>"", "managed"=>"1", "primary"=>"1", "provision"=>"1", "tag"=>"", "attached_to"=>"", "id"=>"6"}}, "architecture_id"=>"1", "operatingsystem_id"=>"1", "medium_id"=>"1", "ptable_id"=>"68", "disk"=>"", "is_owned_by"=>"3-Users", "enabled"=>"1", "model_id"=>"", "comment"=>"", "overwrite"=>"false"}, "bare_metal_capabilities"=>"build", "id"=>"rrtrte.nested.lan"} 2016-08-12 08:48:15 f7334e9f [app] [D] Setting current user thread-local variable to admin 2016-08-12 08:48:15 f7334e9f [app] [D] Setting current organization thread-local variable to none 2016-08-12 08:48:15 f7334e9f [app] [D] Setting current location thread-local variable to none ==> /var/log/httpd/foreman-ssl_access_ssl.log <== 192.168.122.1 - - [12/Aug/2016:08:48:15 -0400] "POST /hosts/rrtrte.nested.lan HTTP/1.1" 200 9783 "https://fseven.zzz.lan/hosts/rrtrte.nested.lan/edit" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/52.0.2743.116 Safari/537.36" ==> /var/log/foreman-proxy/proxy.log <== I, [2016-08-12T08:48:16.005333 #1512] INFO -- : 192.168.122.180 - - [12/Aug/2016:08:48:16 -0400] "GET /tftp/serverName HTTP/1.1" 200 30 0.0006 E, [2016-08-12T08:48:16.089534 #1512] ERROR -- : DHCP record 192.168.222.0/52:54:00:f9:56:db not found I, [2016-08-12T08:48:16.089878 #1512] INFO -- : 192.168.122.180 - - [12/Aug/2016:08:48:16 -0400] "DELETE /dhcp/192.168.222.0/52:54:00:f9:56:db HTTP/1.1" 404 53 0.0009 E, [2016-08-12T08:48:16.199522 #1512] ERROR -- : Omshell failed: > > > obj: <null> , > obj: host , > obj: host , name = "rrtrte.nested.lan" , > obj: host , name = "rrtrte.nested.lan" , ip-address = c0:a8:de:64 , > obj: host , name = "rrtrte.nested.lan" , ip-address = c0:a8:de:64 , hardware-address = 52:54:00:f9:56:da , > obj: host , name = "rrtrte.nested.lan" , ip-address = c0:a8:de:64 , hardware-address = 52:54:00:f9:56:da , hardware-type = 1 , > obj: host , name = "rrtrte.nested.lan" , ip-address = c0:a8:de:64 , hardware-address = 52:54:00:f9:56:da , hardware-type = 1 , statements = "filename = "pxelinux.0"; next-server = c0:a8:de:01; option host-name = "rrtrte.nested.lan";" , > can't open object: already exists , obj: host , name = "rrtrte.nested.lan" , ip-address = c0:a8:de:64 , hardware-address = 52:54:00:f9:56:da , hardware-type = 1 , statements = "filename = "pxelinux.0"; next-server = c0:a8:de:01; option host-name = "rrtrte.nested.lan";" , > E, [2016-08-12T08:48:16.200100 #1512] ERROR -- : Failed to add DHCP reservation for rrtrte.nested.lan (192.168.222.100 / 52:54:00:f9:56:da): Entry already exists I, [2016-08-12T08:48:16.200751 #1512] INFO -- : 192.168.122.180 - - [12/Aug/2016:08:48:16 -0400] "POST /dhcp/192.168.222.0 HTTP/1.1" 400 112 0.0268 E, [2016-08-12T08:48:16.319306 #1512] ERROR -- : Omshell failed: > > > obj: <null> , > obj: host , > obj: host , name = "rrtrte.nested.lan" , > obj: host , name = "rrtrte.nested.lan" , ip-address = c0:a8:de:64 , > obj: host , name = "rrtrte.nested.lan" , ip-address = c0:a8:de:64 , hardware-address = 52:54:00:f9:56:db , > obj: host , name = "rrtrte.nested.lan" , ip-address = c0:a8:de:64 , hardware-address = 52:54:00:f9:56:db , hardware-type = 1 , > obj: host , name = "rrtrte.nested.lan" , ip-address = c0:a8:de:64 , hardware-address = 52:54:00:f9:56:db , hardware-type = 1 , statements = "filename = "pxelinux.0"; next-server = c0:a8:de:01; option host-name = "rrtrte.nested.lan";" , > can't open object: already exists , obj: host , name = "rrtrte.nested.lan" , ip-address = c0:a8:de:64 , hardware-address = 52:54:00:f9:56:db , hardware-type = 1 , statements = "filename = "pxelinux.0"; next-server = c0:a8:de:01; option host-name = "rrtrte.nested.lan";" , > E, [2016-08-12T08:48:16.319822 #1512] ERROR -- : Failed to add DHCP reservation for rrtrte.nested.lan (192.168.222.100 / 52:54:00:f9:56:db): Entry already exists I, [2016-08-12T08:48:16.320441 #1512] INFO -- : 192.168.122.180 - - [12/Aug/2016:08:48:16 -0400] "POST /dhcp/192.168.222.0 HTTP/1.1" 400 112 0.0298 ==> /var/log/foreman/production.log <== 2016-08-12 08:48:16 f7334e9f [app] [I] Delete DHCP reservation for rrtrte.nested.lan-52:54:00:f9:56:db/192.168.222.100 2016-08-12 08:48:16 f7334e9f [app] [I] Create DHCP reservation for rrtrte.nested.lan-52:54:00:f9:56:da/192.168.222.100 2016-08-12 08:48:16 f7334e9f [app] [D] DHCP reservation on net 192.168.222.0 with attrs: {:hostname=>"rrtrte.nested.lan", :mac=>"52:54:00:f9:56:da", :ip=>"192.168.222.100", :network=>"192.168.222.0", :nextServer=>"192.168.222.1", :filename=>"pxelinux.0"} 2016-08-12 08:48:16 f7334e9f [app] [W] Create DHCP Settings for rrtrte.nested.lan task failed with the following error: ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::BadRequest]: 400 Bad Request) for proxy https://fseven.zzz.lan:8443/dhcp | ProxyAPI::ProxyException: ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::BadRequest]: 400 Bad Request) for proxy https://fseven.zzz.lan:8443/dhcp | /usr/share/foreman/lib/proxy_api/dhcp.rb:66:in `rescue in set' | /usr/share/foreman/lib/proxy_api/dhcp.rb:62:in `set' | /usr/share/foreman/lib/net/dhcp/record.rb:29:in `create' | /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:57:in `set_dhcp' | /usr/share/foreman/app/models/concerns/orchestration.rb:191:in `execute' | /usr/share/foreman/app/models/concerns/orchestration.rb:131:in `block in process' | /usr/share/foreman/app/models/concerns/orchestration.rb:123:in `each' | /usr/share/foreman/app/models/concerns/orchestration.rb:123:in `process' | /usr/share/foreman/app/models/concerns/orchestration.rb:35:in `around_save_orchestration' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:432:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:92:in `__run_callbacks__' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:778:in `_run_save_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/callbacks.rb:302:in `create_or_update' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/persistence.rb:120:in `save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/validations.rb:37:in `save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/attribute_methods/dirty.rb:21:in `save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:286:in `block (2 levels) in save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:351:in `block in with_transaction_returning_status' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:211:in `transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:220:in `transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:348:in `with_transaction_returning_status' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:286:in `block in save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:301:in `rollback_active_record_state!' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:285:in `save' | /usr/share/foreman/app/models/concerns/foreman/sti.rb:29:in `save_with_type' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/persistence.rb:252:in `block in update' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:351:in `block in with_transaction_returning_status' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `block in transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/transaction.rb:184:in `within_new_transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:220:in `transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:348:in `with_transaction_returning_status' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/persistence.rb:250:in `update' | /usr/share/foreman/app/controllers/hosts_controller.rb:110:in `block in update' | /usr/share/foreman/app/models/taxonomy.rb:59:in `block in no_taxonomy_scope' | /usr/share/foreman/app/models/taxonomy.rb:66:in `block (2 levels) in as_taxonomy' | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:147:in `as_location' | /usr/share/foreman/app/models/taxonomy.rb:65:in `block in as_taxonomy' | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:112:in `as_org' | /usr/share/foreman/app/models/taxonomy.rb:64:in `as_taxonomy' | /usr/share/foreman/app/models/taxonomy.rb:58:in `no_taxonomy_scope' | /usr/share/foreman/app/controllers/hosts_controller.rb:107:in `update' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/implicit_render.rb:4:in `send_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/base.rb:198:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/rendering.rb:10:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/callbacks.rb:20:in `block in process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:117:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:117:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:555:in `block (2 levels) in compile' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:in `block (2 levels) in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `block (2 levels) in halting' | /opt/theforeman/tfm/root/usr/share/gems/gems/rails-observers-0.1.2/lib/rails/observers/action_controller/caching/sweeping.rb:73:in `around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:455:in `public_send' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:455:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:in `block (2 levels) in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `block (2 levels) in halting' | /usr/share/foreman/app/controllers/concerns/application_shared.rb:14:in `set_timezone' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:432:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:in `block (2 levels) in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `block (2 levels) in halting' | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:432:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:in `block (2 levels) in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `block (2 levels) in halting' | /opt/theforeman/tfm/root/usr/share/gems/gems/rails-observers-0.1.2/lib/rails/observers/action_controller/caching/sweeping.rb:73:in `around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:455:in `public_send' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:455:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:92:in `__run_callbacks__' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:778:in `_run_process_action_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:81:in `run_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/callbacks.rb:19:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/rescue.rb:29:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/notifications.rb:164:in `block in instrument' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/notifications/instrumenter.rb:20:in `instrument' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/notifications.rb:164:in `instrument' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/instrumentation.rb:30:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/params_wrapper.rb:250:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/railties/controller_runtime.rb:18:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/base.rb:137:in `process' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionview-4.2.5.1/lib/action_view/rendering.rb:30:in `process' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal.rb:196:in `dispatch' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/rack_delegation.rb:13:in `dispatch' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal.rb:237:in `block in action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/route_set.rb:74:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/route_set.rb:74:in `dispatch' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/route_set.rb:43:in `serve' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/journey/router.rb:43:in `block in serve' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/journey/router.rb:30:in `each' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/journey/router.rb:30:in `serve' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/route_set.rb:815:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.3.6/lib/apipie/static_dispatcher.rb:65:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.3.6/lib/apipie/extractor/recorder.rb:132:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.3.6/lib/apipie/middleware/checksum_in_headers.rb:27:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/etag.rb:24:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/conditionalget.rb:38:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/head.rb:13:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/params_parser.rb:27:in `call' | /usr/share/foreman/lib/middleware/catch_json_parse_errors.rb:9:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/flash.rb:260:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/session/abstract/id.rb:225:in `context' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/session/abstract/id.rb:220:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/cookies.rb:560:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/query_cache.rb:36:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:653:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/callbacks.rb:29:in `block in call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:88:in `__run_callbacks__' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:778:in `_run_call_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:81:in `run_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/callbacks.rb:27:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/remote_ip.rb:78:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/debug_exceptions.rb:17:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/show_exceptions.rb:30:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/rack/logger.rb:38:in `call_app' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/rack/logger.rb:22:in `call' | /usr/share/foreman/lib/middleware/tagged_logging.rb:18:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/request_id.rb:21:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/methodoverride.rb:22:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/runtime.rb:18:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/static.rb:116:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/sendfile.rb:113:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/engine.rb:518:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/application.rb:165:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/railtie.rb:194:in `public_send' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/railtie.rb:194:in `method_missing' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/urlmap.rb:66:in `block in call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/urlmap.rb:50:in `each' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/urlmap.rb:50:in `call' | /usr/share/passenger/phusion_passenger/rack/thread_handler_extension.rb:74:in `process_request' | /usr/share/passenger/phusion_passenger/request_handler/thread_handler.rb:141:in `accept_and_process_next_request' | /usr/share/passenger/phusion_passenger/request_handler/thread_handler.rb:109:in `main_loop' | /usr/share/passenger/phusion_passenger/request_handler.rb:455:in `block (3 levels) in start_threads' | /opt/theforeman/tfm/root/usr/share/gems/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context' 2016-08-12 08:48:16 f7334e9f [app] [I] Create DHCP reservation for rrtrte.nested.lan-52:54:00:f9:56:db/192.168.222.100 2016-08-12 08:48:16 f7334e9f [app] [D] DHCP reservation on net 192.168.222.0 with attrs: {:hostname=>"rrtrte.nested.lan", :mac=>"52:54:00:f9:56:db", :ip=>"192.168.222.100", :network=>"192.168.222.0", :nextServer=>"192.168.222.1", :filename=>"pxelinux.0"} 2016-08-12 08:48:16 f7334e9f [app] [W] Failed to perform rollback on Remove DHCP Settings for rrtrte.nested.lan - ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::BadRequest]: 400 Bad Request) for proxy https://fseven.zzz.lan:8443/dhcp | ProxyAPI::ProxyException: ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::BadRequest]: 400 Bad Request) for proxy https://fseven.zzz.lan:8443/dhcp | /usr/share/foreman/lib/proxy_api/dhcp.rb:66:in `rescue in set' | /usr/share/foreman/lib/proxy_api/dhcp.rb:62:in `set' | /usr/share/foreman/lib/net/dhcp/record.rb:29:in `create' | /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:57:in `set_dhcp' | /usr/share/foreman/app/models/concerns/orchestration.rb:191:in `execute' | /usr/share/foreman/app/models/concerns/orchestration.rb:161:in `block in fail_queue' | /usr/share/foreman/app/models/concerns/orchestration.rb:157:in `reverse_each' | /usr/share/foreman/app/models/concerns/orchestration.rb:157:in `fail_queue' | /usr/share/foreman/app/models/concerns/orchestration.rb:147:in `process' | /usr/share/foreman/app/models/concerns/orchestration.rb:35:in `around_save_orchestration' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:432:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:92:in `__run_callbacks__' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:778:in `_run_save_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/callbacks.rb:302:in `create_or_update' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/persistence.rb:120:in `save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/validations.rb:37:in `save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/attribute_methods/dirty.rb:21:in `save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:286:in `block (2 levels) in save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:351:in `block in with_transaction_returning_status' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:211:in `transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:220:in `transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:348:in `with_transaction_returning_status' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:286:in `block in save' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:301:in `rollback_active_record_state!' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:285:in `save' | /usr/share/foreman/app/models/concerns/foreman/sti.rb:29:in `save_with_type' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/persistence.rb:252:in `block in update' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:351:in `block in with_transaction_returning_status' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `block in transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/transaction.rb:184:in `within_new_transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:220:in `transaction' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:348:in `with_transaction_returning_status' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/persistence.rb:250:in `update' | /usr/share/foreman/app/controllers/hosts_controller.rb:110:in `block in update' | /usr/share/foreman/app/models/taxonomy.rb:59:in `block in no_taxonomy_scope' | /usr/share/foreman/app/models/taxonomy.rb:66:in `block (2 levels) in as_taxonomy' | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:147:in `as_location' | /usr/share/foreman/app/models/taxonomy.rb:65:in `block in as_taxonomy' | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:112:in `as_org' | /usr/share/foreman/app/models/taxonomy.rb:64:in `as_taxonomy' | /usr/share/foreman/app/models/taxonomy.rb:58:in `no_taxonomy_scope' | /usr/share/foreman/app/controllers/hosts_controller.rb:107:in `update' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/implicit_render.rb:4:in `send_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/base.rb:198:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/rendering.rb:10:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/callbacks.rb:20:in `block in process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:117:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:117:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:555:in `block (2 levels) in compile' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:in `block (2 levels) in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `block (2 levels) in halting' | /opt/theforeman/tfm/root/usr/share/gems/gems/rails-observers-0.1.2/lib/rails/observers/action_controller/caching/sweeping.rb:73:in `around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:455:in `public_send' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:455:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:in `block (2 levels) in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `block (2 levels) in halting' | /usr/share/foreman/app/controllers/concerns/application_shared.rb:14:in `set_timezone' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:432:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:in `block (2 levels) in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `block (2 levels) in halting' | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:432:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:498:in `block (2 levels) in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:313:in `block (2 levels) in halting' | /opt/theforeman/tfm/root/usr/share/gems/gems/rails-observers-0.1.2/lib/rails/observers/action_controller/caching/sweeping.rb:73:in `around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:455:in `public_send' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:455:in `block in make_lambda' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:312:in `block in halting' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:497:in `block in around' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:505:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:92:in `__run_callbacks__' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:778:in `_run_process_action_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:81:in `run_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/callbacks.rb:19:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/rescue.rb:29:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/notifications.rb:164:in `block in instrument' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/notifications/instrumenter.rb:20:in `instrument' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/notifications.rb:164:in `instrument' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/instrumentation.rb:30:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/params_wrapper.rb:250:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/railties/controller_runtime.rb:18:in `process_action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/abstract_controller/base.rb:137:in `process' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionview-4.2.5.1/lib/action_view/rendering.rb:30:in `process' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal.rb:196:in `dispatch' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal/rack_delegation.rb:13:in `dispatch' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_controller/metal.rb:237:in `block in action' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/route_set.rb:74:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/route_set.rb:74:in `dispatch' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/route_set.rb:43:in `serve' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/journey/router.rb:43:in `block in serve' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/journey/router.rb:30:in `each' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/journey/router.rb:30:in `serve' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/routing/route_set.rb:815:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.3.6/lib/apipie/static_dispatcher.rb:65:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.3.6/lib/apipie/extractor/recorder.rb:132:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.3.6/lib/apipie/middleware/checksum_in_headers.rb:27:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/etag.rb:24:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/conditionalget.rb:38:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/head.rb:13:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/params_parser.rb:27:in `call' | /usr/share/foreman/lib/middleware/catch_json_parse_errors.rb:9:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/flash.rb:260:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/session/abstract/id.rb:225:in `context' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/session/abstract/id.rb:220:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/cookies.rb:560:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/query_cache.rb:36:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:653:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/callbacks.rb:29:in `block in call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:88:in `__run_callbacks__' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:778:in `_run_call_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:81:in `run_callbacks' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/callbacks.rb:27:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/remote_ip.rb:78:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/debug_exceptions.rb:17:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/show_exceptions.rb:30:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/rack/logger.rb:38:in `call_app' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/rack/logger.rb:22:in `call' | /usr/share/foreman/lib/middleware/tagged_logging.rb:18:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/request_id.rb:21:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/methodoverride.rb:22:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/runtime.rb:18:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/actionpack-4.2.5.1/lib/action_dispatch/middleware/static.rb:116:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/sendfile.rb:113:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/engine.rb:518:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/application.rb:165:in `call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/railtie.rb:194:in `public_send' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/railties-4.2.5.1/lib/rails/railtie.rb:194:in `method_missing' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/urlmap.rb:66:in `block in call' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/urlmap.rb:50:in `each' | /opt/rh/sclo-ror42/root/usr/share/gems/gems/rack-1.6.2/lib/rack/urlmap.rb:50:in `call' | /usr/share/passenger/phusion_passenger/rack/thread_handler_extension.rb:74:in `process_request' | /usr/share/passenger/phusion_passenger/request_handler/thread_handler.rb:141:in `accept_and_process_next_request' | /usr/share/passenger/phusion_passenger/request_handler/thread_handler.rb:109:in `main_loop' | /usr/share/passenger/phusion_passenger/request_handler.rb:455:in `block (3 levels) in start_threads' | /opt/theforeman/tfm/root/usr/share/gems/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `call' | /opt/theforeman/tfm/root/usr/share/gems/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context' 2016-08-12 08:48:16 f7334e9f [app] [I] Failed to save: Create DHCP Settings for rrtrte.nested.lan task failed with the following error: ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::BadRequest]: 400 Bad Request) for proxy https://fseven.zzz.lan:8443/dhcp, Failed to perform rollback on Remove DHCP Settings for rrtrte.nested.lan - ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::BadRequest]: 400 Bad Request) for proxy https://fseven.zzz.lan:8443/dhcp 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered hosts/_progress.html.erb (0.5ms) 2016-08-12 08:48:16 f7334e9f [app] [D] Setting current organization thread-local variable to none 2016-08-12 08:48:16 f7334e9f [app] [D] Setting current location thread-local variable to none 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered puppetclasses/_selectedClasses.html.erb (0.0ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered puppetclasses/_classes_in_groups.html.erb (0.0ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered puppetclasses/_classes.html.erb (0.9ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered puppetclasses/_class_selection.html.erb (58.3ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered nic/_base_form.html.erb (21.4ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered nic/_virtual_form.html.erb (1.8ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered nic/_provider_specific_form.html.erb (0.6ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered nic/manageds/_managed.html.erb (33.1ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered nic/_base_form.html.erb (14.0ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered nic/_virtual_form.html.erb (1.1ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered nic/_provider_specific_form.html.erb (0.1ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered nic/manageds/_managed.html.erb (19.5ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered hosts/_interfaces.html.erb (58.7ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered common/os_selection/_architecture.html.erb (4.9ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered common/os_selection/_operatingsystem.html.erb (12.1ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered hosts/provision_method/build/_form.html.erb (13.7ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered hosts/provision_method/image/_form.html.erb (0.5ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered hosts/_operating_system.html.erb (31.0ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered hosts/_unattended.html.erb (33.2ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered puppetclasses/_class_parameters.html.erb (0.0ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered puppetclasses/_classes_parameters.html.erb (8.9ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered common_parameters/_inherited_parameters.html.erb (0.1ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered common_parameters/_parameter.html.erb (1.5ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered common_parameters/_parameters.html.erb (3.4ms) 2016-08-12 08:48:16 f7334e9f [app] [D] Setting current location thread-local variable to none 2016-08-12 08:48:16 f7334e9f [app] [D] Setting current organization thread-local variable to none 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered hosts/_form.html.erb (216.2ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered hosts/edit.html.erb within layouts/application (220.7ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered layouts/_application_content.html.erb (0.2ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered home/_user_dropdown.html.erb (1.8ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Read fragment views/tabs_and_title_records-3 (0.1ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered home/_topbar.html.erb (5.8ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered layouts/base.html.erb (6.8ms) 2016-08-12 08:48:16 f7334e9f [app] [D] Setting current location thread-local variable to none 2016-08-12 08:48:16 f7334e9f [app] [D] Setting current organization thread-local variable to none 2016-08-12 08:48:16 f7334e9f [app] [I] Completed 200 OK in 1144ms (Views: 219.2ms | ActiveRecord: 28.6ms) ==> /var/log/httpd/foreman-ssl_access_ssl.log <== 192.168.122.1 - - [12/Aug/2016:08:48:16 -0400] "GET /tasks/a506440f-8722-46fc-9d01-d71879a94dc0 HTTP/1.1" 200 208 "https://fseven.zzz.lan/hosts/rrtrte.nested.lan/edit" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/52.0.2743.116 Safari/537.36" ==> /var/log/foreman/production.log <== 2016-08-12 08:48:16 f7334e9f [app] [I] Started GET "/tasks/a506440f-8722-46fc-9d01-d71879a94dc0" for 192.168.122.1 at 2016-08-12 08:48:16 -0400 2016-08-12 08:48:16 f7334e9f [app] [I] Processing by TasksController#show as */* 2016-08-12 08:48:16 f7334e9f [app] [I] Parameters: {"id"=>"a506440f-8722-46fc-9d01-d71879a94dc0"} 2016-08-12 08:48:16 f7334e9f [app] [D] Setting current user thread-local variable to admin 2016-08-12 08:48:16 f7334e9f [app] [I] Rendered tasks/_list.html.erb (0.6ms) 2016-08-12 08:48:16 f7334e9f [app] [I] Completed 200 OK in 10ms (Views: 1.4ms | ActiveRecord: 1.3ms)
The workaround is to exit build mode, make necessary changes and enter build mode again.