Bug #7053
closed
Cannot update IP address for existing host
Description
Foreman and foreman-proxy are both 1.5.2, along with isc-dhcp-server.
In the UI:
Select a host -> Edit -> Network -> Change the IP address to an available IP -> Receive error: "Unable to save\nCreate DHCP Settings for host.domain task failed with the following error: ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::Conflict]: 409 Conflict) for proxy https://dhcp.domain:8443/dhcp"
From foreman:/var/log/foreman/production.log:
Delete DHCP reservation for host.domain-00:1e:c9:2c:43:c3/xxx.xxx.xxx.193
Create DHCP reservation for host.domain-00:1e:c9:2c:43:c3/xxx.xxx.xxx.194
Create DHCP Settings for host.domain task failed with the following error: ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry ([RestClient::Conflict]: 409 Conflict) for proxy https://dhcp.domain:8443/dhcp/usr/share/foreman/lib/proxy_api/dhcp.rb:66:in `set'
/usr/share/foreman/lib/net/dhcp/record.rb:28:in `create'
/usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:22:in `set_dhcp'
/usr/share/foreman/app/models/concerns/orchestration.rb:137:in `send'
/usr/share/foreman/app/models/concerns/orchestration.rb:137:in `execute'
/usr/share/foreman/app/models/concerns/orchestration.rb:85:in `process'
/usr/share/foreman/app/models/concerns/orchestration.rb:77:in `each'
/usr/share/foreman/app/models/concerns/orchestration.rb:77:in `process'
/usr/share/foreman/app/models/concerns/orchestration.rb:18:in `on_save'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:660:in `_run__1120636067__save__4__callbacks'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:405:in `send'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:405:in `__run_callback'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:385:in `_run_save_callbacks'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:81:in `send'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:81:in `run_callbacks'
/usr/share/foreman/vendor/ruby/1.8/gems/activerecord-3.2.18/lib/active_record/callbacks.rb:264:in `create_or_update'
/usr/share/foreman/vendor/ruby/1.8/gems/activerecord-3.2.18/lib/active_record/persistence.rb:84:in `save'
/usr/share/foreman/vendor/ruby/1.8/gems/activerecord-3.2.18/lib/active_record/validations.rb:50:in `save'
/usr/share/foreman/vendor/ruby/1.8/gems/activerecord-3.2.18/lib/active_record/attribute_methods/dirty.rb:22:in `save'
/usr/share/foreman/vendor/ruby/1.8/gems/activerecord-3.2.18/lib/active_record/transactions.rb:259:in `save_without_type'
/usr/share/foreman/vendor/ruby/1.8/gems/activerecord-3.2.18/lib/active_record/transactions.rb:313:in `with_transaction_returning_status'
/usr/share/foreman/vendor/ruby/1.8/gems/activerecord-3.2.18/lib/active_record/connection_adapters/abstract/database_statements.rb:192:in `transaction'
/usr/share/foreman/vendor/ruby/1.8/gems/activerecord-3.2.18/lib/active_record/transactions.rb:208:in `transaction'
/usr/share/foreman/vendor/ruby/1.8/gems/activerecord-3.2.18/lib/active_record/transactions.rb:311:in `with_transaction_returning_status'
/usr/share/foreman/vendor/ruby/1.8/gems/activerecord-3.2.18/lib/active_record/transactions.rb:259:in `save_without_type'
/usr/share/foreman/vendor/ruby/1.8/gems/activerecord-3.2.18/lib/active_record/transactions.rb:270:in `rollback_active_record_state!'
/usr/share/foreman/vendor/ruby/1.8/gems/activerecord-3.2.18/lib/active_record/transactions.rb:258:in `save_without_type'
/usr/share/foreman/app/models/concerns/foreman/sti.rb:29:in `save'
/usr/share/foreman/vendor/ruby/1.8/gems/activerecord-3.2.18/lib/active_record/persistence.rb:217:in `update_attributes'
/usr/share/foreman/vendor/ruby/1.8/gems/activerecord-3.2.18/lib/active_record/transactions.rb:313:in `with_transaction_returning_status'
/usr/share/foreman/vendor/ruby/1.8/gems/activerecord-3.2.18/lib/active_record/connection_adapters/abstract/database_statements.rb:192:in `transaction'
/usr/share/foreman/vendor/ruby/1.8/gems/activerecord-3.2.18/lib/active_record/transactions.rb:208:in `transaction'
/usr/share/foreman/vendor/ruby/1.8/gems/activerecord-3.2.18/lib/active_record/transactions.rb:311:in `with_transaction_returning_status'
/usr/share/foreman/vendor/ruby/1.8/gems/activerecord-3.2.18/lib/active_record/persistence.rb:215:in `update_attributes'
/usr/share/foreman/app/controllers/hosts_controller.rb:113:in `update'
/usr/share/foreman/app/models/taxonomy.rb:41:in `no_taxonomy_scope'
/usr/share/foreman/app/models/taxonomy.rb:48:in `as_taxonomy'
/usr/share/foreman/app/models/concerns/foreman/thread_session.rb:143:in `as_location'
/usr/share/foreman/app/models/taxonomy.rb:47:in `as_taxonomy'
/usr/share/foreman/app/models/concerns/foreman/thread_session.rb:108:in `as_org'
/usr/share/foreman/app/models/taxonomy.rb:46:in `as_taxonomy'
/usr/share/foreman/app/models/taxonomy.rb:40:in `no_taxonomy_scope'
/usr/share/foreman/app/controllers/hosts_controller.rb:105:in `update'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_controller/metal/implicit_render.rb:4:in `send_action'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_controller/metal/implicit_render.rb:4:in `send_action'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/abstract_controller/base.rb:167:in `process_action'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_controller/metal/rendering.rb:10:in `process_action'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/abstract_controller/callbacks.rb:18:in `process_action'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:549:in `_run__1589944314__process_action__2067640602__callbacks'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:215:in `_conditional_callback_around_6381'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:326:in `around'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:310:in `send'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:310:in `_callback_around_5274'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_6381'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:526:in `_run__1589944314__process_action__2067640602__callbacks'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:215:in `_conditional_callback_around_6380'
/usr/share/foreman/app/models/concerns/foreman/thread_session.rb:33:in `clear_thread'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_6380'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:415:in `_run__1589944314__process_action__2067640602__callbacks'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:215:in `_conditional_callback_around_6379'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:326:in `around'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:310:in `send'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:310:in `_callback_around_13'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_6379'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:414:in `_run__1589944314__process_action__2067640602__callbacks'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:405:in `send'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:405:in `__run_callback'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:385:in `_run_process_action_callbacks'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:81:in `send'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:81:in `run_callbacks'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/abstract_controller/callbacks.rb:17:in `process_action'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_controller/metal/rescue.rb:29:in `process_action'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_controller/metal/instrumentation.rb:30:in `process_action'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/notifications.rb:123:in `instrument'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/notifications.rb:123:in `instrument'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_controller/metal/instrumentation.rb:29:in `process_action'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_controller/metal/params_wrapper.rb:207:in `process_action'
/usr/share/foreman/vendor/ruby/1.8/gems/activerecord-3.2.18/lib/active_record/railties/controller_runtime.rb:18:in `process_action'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/abstract_controller/base.rb:121:in `process'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/abstract_controller/rendering.rb:45:in `process'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_controller/metal.rb:203:in `dispatch'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_controller/metal/rack_delegation.rb:14:in `dispatch'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_controller/metal.rb:246:in `action'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_dispatch/routing/route_set.rb:73:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_dispatch/routing/route_set.rb:73:in `dispatch'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_dispatch/routing/route_set.rb:36:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/journey-1.0.4/lib/journey/router.rb:68:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/journey-1.0.4/lib/journey/router.rb:56:in `each'
/usr/share/foreman/vendor/ruby/1.8/gems/journey-1.0.4/lib/journey/router.rb:56:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_dispatch/routing/route_set.rb:608:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/apipie-rails-0.1.3/lib/apipie/static_dispatcher.rb:65:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/apipie-rails-0.1.3/lib/apipie/middleware/checksum_in_headers.rb:27:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_dispatch/middleware/best_standards_support.rb:17:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/rack-1.4.5/lib/rack/etag.rb:23:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/rack-1.4.5/lib/rack/conditionalget.rb:35:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_dispatch/middleware/head.rb:14:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_dispatch/middleware/params_parser.rb:21:in `call'
/usr/share/foreman/lib/middleware/catch_json_parse_errors.rb:9:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_dispatch/middleware/flash.rb:242:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/rack-1.4.5/lib/rack/session/abstract/id.rb:210:in `context'
/usr/share/foreman/vendor/ruby/1.8/gems/rack-1.4.5/lib/rack/session/abstract/id.rb:205:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_dispatch/middleware/cookies.rb:341:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/activerecord-3.2.18/lib/active_record/query_cache.rb:64:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/activerecord-3.2.18/lib/active_record/connection_adapters/abstract/connection_pool.rb:479:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_dispatch/middleware/callbacks.rb:28:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:405:in `_run__25082136__call__4__callbacks'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:405:in `send'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:405:in `__run_callback'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:385:in `_run_call_callbacks'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:81:in `send'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/callbacks.rb:81:in `run_callbacks'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_dispatch/middleware/callbacks.rb:27:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_dispatch/middleware/remote_ip.rb:31:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_dispatch/middleware/debug_exceptions.rb:16:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_dispatch/middleware/show_exceptions.rb:56:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/railties-3.2.18/lib/rails/rack/logger.rb:32:in `call_app'
/usr/share/foreman/vendor/ruby/1.8/gems/railties-3.2.18/lib/rails/rack/logger.rb:16:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/tagged_logging.rb:22:in `tagged'
/usr/share/foreman/vendor/ruby/1.8/gems/railties-3.2.18/lib/rails/rack/logger.rb:16:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_dispatch/middleware/request_id.rb:22:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/rack-1.4.5/lib/rack/methodoverride.rb:21:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/rack-1.4.5/lib/rack/runtime.rb:17:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/activesupport-3.2.18/lib/active_support/cache/strategy/local_cache.rb:72:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/rack-1.4.5/lib/rack/lock.rb:15:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/actionpack-3.2.18/lib/action_dispatch/middleware/static.rb:63:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/rack-cache-1.2/lib/rack/cache/context.rb:136:in `forward'
/usr/share/foreman/vendor/ruby/1.8/gems/rack-cache-1.2/lib/rack/cache/context.rb:143:in `pass'
/usr/share/foreman/vendor/ruby/1.8/gems/rack-cache-1.2/lib/rack/cache/context.rb:155:in `invalidate'
/usr/share/foreman/vendor/ruby/1.8/gems/rack-cache-1.2/lib/rack/cache/context.rb:71:in `call!'
/usr/share/foreman/vendor/ruby/1.8/gems/rack-cache-1.2/lib/rack/cache/context.rb:51:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/railties-3.2.18/lib/rails/engine.rb:484:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/railties-3.2.18/lib/rails/application.rb:231:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/railties-3.2.18/lib/rails/railtie/configurable.rb:30:in `send'
/usr/share/foreman/vendor/ruby/1.8/gems/railties-3.2.18/lib/rails/railtie/configurable.rb:30:in `method_missing'
/usr/share/foreman/vendor/ruby/1.8/gems/rack-1.4.5/lib/rack/urlmap.rb:64:in `call'
/usr/share/foreman/vendor/ruby/1.8/gems/rack-1.4.5/lib/rack/urlmap.rb:49:in `each'
/usr/share/foreman/vendor/ruby/1.8/gems/rack-1.4.5/lib/rack/urlmap.rb:49:in `call'
/usr/lib/ruby/1.8/phusion_passenger/rack/request_handler.rb:92:in `process_request'
/usr/lib/ruby/1.8/phusion_passenger/abstract_request_handler.rb:207:in `main_loop'
/usr/lib/ruby/1.8/phusion_passenger/rack/application_spawner.rb:118:in `run'
/usr/lib/ruby/1.8/phusion_passenger/rack/application_spawner.rb:65:in `spawn_application'
/usr/lib/ruby/1.8/phusion_passenger/utils.rb:184:in `safe_fork'
/usr/lib/ruby/1.8/phusion_passenger/rack/application_spawner.rb:58:in `spawn_application'
/usr/lib/ruby/1.8/phusion_passenger/rack/application_spawner.rb:41:in `spawn_application'
/usr/lib/ruby/1.8/phusion_passenger/spawn_manager.rb:159:in `spawn_application'
/usr/lib/ruby/1.8/phusion_passenger/spawn_manager.rb:287:in `handle_spawn_application'
/usr/lib/ruby/1.8/phusion_passenger/abstract_server.rb:352:in `__send__'
/usr/lib/ruby/1.8/phusion_passenger/abstract_server.rb:352:in `main_loop'
/usr/lib/ruby/1.8/phusion_passenger/abstract_server.rb:196:in `start_synchronously'
/usr/lib/phusion_passenger/passenger-spawn-server:61
Rolling back due to a problem: Create DHCP Settings for host.domain 9 failed host.domainset_dhcp
Create DHCP reservation for host.domain-00:1e:c9:2c:43:c3/xxx.xxx.xxx.193
From dhcp.domain:/var/log/foreman-proxy/foreman-proxy.log:
W, [2014-08-12T09:45:01.597397 #31129] WARN -- : Request to create a conflicting record
D, [2014-08-12T09:45:01.597521 #31129] DEBUG -- : request: {"mac"=>"00:1e:c9:2c:43:c3", "nextServer"=>"yyy.yyy.yyy.146", "hostname"=>"host.domain", "ip"=>"xxx.xxx.xxx.194", "filename"=>"pxelinux.0"}
D, [2014-08-12T09:45:01.597638 #31129] DEBUG -- : local: {:mac=>"00:1e:c9:2c:43:c3", :subnet=>xxx.xxx.xxx.0/255.255.255.0, :nextServer=>"yyy.yyy.yyy.146", :filename=>"pxelinux.0", :hostname=>"host.domain", :ip=>"xxx.xxx.xxx.193"}
E, [2014-08-12T09:45:01.598006 #31129] ERROR -- : Record xxx.xxx.xxx.0/128.101.154.194 already exists
D, [2014-08-12T09:45:01.598159 #31129] DEBUG -- : /usr/share/foreman-proxy/bin/../lib/proxy/dhcp/server.rb:110:in `addRecord'
/usr/share/foreman-proxy/bin/../lib/proxy/dhcp/server/isc.rb:27:in `addRecord'
/usr/share/foreman-proxy/bin/../lib/dhcp_api.rb:94:in `POST /dhcp/:network'
/usr/lib/ruby/vendor_ruby/sinatra/base.rb:1151:in `call'
/usr/lib/ruby/vendor_ruby/sinatra/base.rb:1151:in `compile!'
/usr/lib/ruby/vendor_ruby/sinatra/base.rb:724:in `instance_eval'
/usr/lib/ruby/vendor_ruby/sinatra/base.rb:724:in `route_eval'
/usr/lib/ruby/vendor_ruby/sinatra/base.rb:708:in `route!'
/usr/lib/ruby/vendor_ruby/sinatra/base.rb:758:in `process_route'
/usr/lib/ruby/vendor_ruby/sinatra/base.rb:755:in `catch'
/usr/lib/ruby/vendor_ruby/sinatra/base.rb:755:in `process_route'
/usr/lib/ruby/vendor_ruby/sinatra/base.rb:707:in `route!'
/usr/lib/ruby/vendor_ruby/sinatra/base.rb:706:in `each'
/usr/lib/ruby/vendor_ruby/sinatra/base.rb:706:in `route!'
/usr/lib/ruby/vendor_ruby/sinatra/base.rb:843:in `dispatch!'
/usr/lib/ruby/vendor_ruby/sinatra/base.rb:644:in `call!'
/usr/lib/ruby/vendor_ruby/sinatra/base.rb:808:in `instance_eval'
/usr/lib/ruby/vendor_ruby/sinatra/base.rb:808:in `invoke'
/usr/lib/ruby/vendor_ruby/sinatra/base.rb:808:in `catch'
/usr/lib/ruby/vendor_ruby/sinatra/base.rb:808:in `invoke'
/usr/lib/ruby/vendor_ruby/sinatra/base.rb:644:in `call!'
/usr/lib/ruby/vendor_ruby/sinatra/base.rb:629:in `call'
/usr/lib/ruby/vendor_ruby/rack/methodoverride.rb:24:in `call'
/usr/lib/ruby/vendor_ruby/rack/head.rb:9:in `call'
/usr/lib/ruby/vendor_ruby/rack/commonlogger.rb:20:in `call'
/usr/lib/ruby/vendor_ruby/sinatra/showexceptions.rb:21:in `call'
/usr/lib/ruby/vendor_ruby/sinatra/base.rb:1272:in `call'
/usr/lib/ruby/vendor_ruby/sinatra/base.rb:1303:in `synchronize'
/usr/lib/ruby/vendor_ruby/sinatra/base.rb:1272:in `call'
/usr/lib/ruby/vendor_ruby/rack/handler/webrick.rb:59:in `service'
/usr/lib/ruby/1.8/webrick/httpserver.rb:104:in `service'
/usr/lib/ruby/1.8/webrick/httpserver.rb:65:in `run'
/usr/lib/ruby/1.8/webrick/server.rb:173:in `start_thread'
/usr/lib/ruby/1.8/webrick/server.rb:162:in `start'
/usr/lib/ruby/1.8/webrick/server.rb:162:in `start_thread'
/usr/lib/ruby/1.8/webrick/server.rb:95:in `start'
/usr/lib/ruby/1.8/webrick/server.rb:92:in `each'
/usr/lib/ruby/1.8/webrick/server.rb:92:in `start'
/usr/lib/ruby/1.8/webrick/server.rb:23:in `start'
/usr/lib/ruby/1.8/webrick/server.rb:82:in `start'
/usr/lib/ruby/vendor_ruby/rack/handler/webrick.rb:13:in `run'
/usr/share/foreman-proxy/bin/../lib/sinatra-patch.rb:42:in `run!'
/usr/share/foreman-proxy/bin/smart-proxy:44
Excpectation: Changing a host's IP in the web UI should delete and re-create the dhcp lease in /var/lib/dhcp/dhcpd.leases
Reality: Errors and an unchanged entry in /var/lib/dhcp/dhcpd.leases
Files
Updated by Brian Auron almost 10 years ago
As an addition to this, I went looking for ways to see how the proxy as handling requests. I don't know how Foreman submits data to the dhcp proxy, but I can't reproduce it with curl despite having read this document: http://projects.theforeman.org/projects/smart-proxy/wiki/API
Additionally, I placed a logger.debug line in dhcpserver:/usr/share/foreman-proxy/bin/../lib/dhcp_api.rb such that:
...
# delete a record from a network
delete "/dhcp/:network/:record" do
begin
record = load_subnet.reservation_for(params[:record])
log_halt 404, "Record #{params[:network]}/#{params[:record]} not found" unless record
@server.delRecord @subnet, record
record = load_subnet.reservation_for(params[:record])
logger.debug "DHCP record after @server.delRecord: #{record.inspect}"
if request.accept? 'application/json'
content_type :json
{}
else
redirect "/dhcp/#{params[:network]}"
end
rescue Proxy::DHCP::InvalidRecord
log_halt 404, "Record #{params[:network]}/#{params[:record]} not found"
rescue Exception => e
log_halt 400, e
end
end
because, allegedly, Foreman deletes a reservation then creates it again when you change a host's IP address in the Foreman UI (according to #theforeman IRC). However, after placing said debug line and reproducing my original error (409 response, etc), no such line was present in foreman-proxy.log. This leads me to believe that Foreman is not attempting to delete the reservation correctly.
Updated by Dominic Cleal almost 10 years ago
I'm unsure what to suggest, since the production.log snippet shows this:
Delete DHCP reservation for host.domain-00:1e:c9:2c:43:c3/xxx.xxx.xxx.193
This is logged from lib/net/dhcp/record.rb#destroy, which is called by the orchestration code (app/models/concerns/orchestration/dhcp.rb, the usual suspect when records aren't deleted etc). That DHCP record code then calls the proxy API wrapper in lib/proxy_api/dhcp.rb, which is simply making that request to the proxy.
Perhaps double check if the log_halt 404 at the start of the delete method is returning, moving the debug line up could help. This would be consistent with Foreman logging nothing else, as it deliberately ignores 404s on deletion. (If this is the case, clearly the issue is within the reservation_for searching.)
Updated by Brian Auron almost 10 years ago
Hi Dominic, thanks for responding.
I added a debug line above log_halt 404 and above log_halt 400:
rescue Proxy::DHCP::InvalidRecord
logger.debug "DHCP record after @server.delRecord NOT FOUND, 404 #{record.inspect}"
log_halt 404, "Record #{params[:network]}/#{params[:record]} not found"
rescue Exception => e
logger.debug "DHCP record after @server.delRecord OTHER ERROR, 400 #{record.inspect}"
log_halt 400, e
and using the DHCP proxy's API via web browser, deleted the reservation. In foreman-proxy.log, I correctly see:
I, [2014-08-15T10:39:06.813626 #14697] INFO -- : Removed DHCP reservation for xt14.domain => xt14.domain (xxx.xxx.xxx.194 / 00:1e:c9:2c:43:c3) D, [2014-08-15T10:39:06.813937 #14697] DEBUG -- : DHCP record after @server.delRecord: false
I then submit an IP change in Foreman's UI which 'just works'. Then I changed the IP again and in foreman-proxy.log:
I, [2014-08-15T10:44:42.506601 #14697] INFO -- : Enumerated hosts on xxx.xxx.xxx.0 D, [2014-08-15T10:44:42.506711 #14697] DEBUG -- : Lazy loaded xxx.xxx.xxx.0/255.255.255.0 records E, [2014-08-15T10:44:42.507808 #14697] ERROR -- : Record xxx.xxx.xxx.0/00:1e:c9:2c:43:c3 not found
The strings "NOT FOUND" and "OTHER ERROR" does not exist in the log:
root@dhcp:/var/lib/dhcp# grep "NOT FOUND" !$ grep "NOT FOUND" /var/log/foreman-proxy/foreman-proxy.log root@dhcp:/var/lib/dhcp# echo $? 1 root@dhcp:/var/lib/dhcp# grep "OTHER ERROR" /var/log/foreman-proxy/foreman-proxy.log root@dhcp:/var/lib/dhcp# echo $? 1 root@dhcp:/var/lib/dhcp# grep "DHCP record after" /var/log/foreman-proxy/foreman-proxy.log D, [2014-08-15T10:39:06.813937 #14697] DEBUG -- : DHCP record after @server.delRecord: false root@dhcp:/var/lib/dhcp#
Updated by Dominic Cleal over 9 years ago
Ok, so this is pointing to the problem - it's the first log_halt up at the top of the method that's returning, as record is false.
I, [2014-08-15T10:44:42.506601 #14697] INFO -- : Enumerated hosts on xxx.xxx.xxx.0 D, [2014-08-15T10:44:42.506711 #14697] DEBUG -- : Lazy loaded xxx.xxx.xxx.0/255.255.255.0 records E, [2014-08-15T10:44:42.507808 #14697] ERROR -- : Record xxx.xxx.xxx.0/00:1e:c9:2c:43:c3 not found
Are you able to see if the reservation exists with this MAC address before doing the rename? And ensure that's definitely in the reservations, not leases list.
Updated by Brian Auron over 9 years ago
- File dhcprecords.png dhcprecords.png added
Hi Dominic,
Actually, there are no reservations at all. As far as I can tell, reservations are supposed to exist in /etc/dhcp/dhcpd.conf, but it just has:
ddns-update-style none;
# option definitions common to all supported networks...
option domain-name "super.domain";
option domain-name-servers <server IPs>
default-lease-time 21600;
max-lease-time 43200;
allow booting;
allow bootp;
# If this DHCP server is the official DHCP server for the local
# network, the authoritative directive should be uncommented.
#authoritative;
# Use this to send dhcp log messages to a different log file (you also
# have to hack syslog.conf to complete the redirection).
log-facility local7;
omapi-port 7911;
key omapi_key {
algorithm HMAC-MD5;
secret "Base64 secret";
};
omapi-key omapi_key;
<subnets follow>
I'm not sure where else to look. In case it helps, here's the browser view of the dhcp proxy showing xt14 at least has a 'record':
Updated by Dominic Cleal over 9 years ago
- Related to Bug #7021: DHCP entires don't get deleted with the virsh provider added
Updated by Dominic Cleal over 9 years ago
The reservations should be stored in /var/lib/dhcp3/dhcpd.leases on a Debian system because we add them via dhcpd's OMAPI API, which writes both reservations and leases this file. The DHCP browser output looks correct though, so I think this remains a proxy bug where for some reason the "reservation_for" function is failing to find entries.. similar to #7021 which was on the libvirt DHCP provider.
I used to see #7021 on my development setup, but when I tried again to reproduce it this week, I couldn't, so am wondering if this has somehow been fixed in the 1.6 proxy. If you have the opportunity, it may be worth trying to upgrade the proxy.
Updated by Anonymous about 8 years ago
- Status changed from New to Resolved
no reaction and no related reports received, setting to resolved, maybe 1.6 simply fixed it.