Foreman 1.15 - ISC DHCP issues, duplicate addresses and overwrites

Matt_Darcy · May 14, 2017, 4:03pm

I've hit a problem with a clean foreman 1.15 install. I've used the same
installer settings as a working 1.13 and 1.14 box as this is just a test
system.

The system is a current patched CentOS 7.3 host,

The installer options for the DHCP config are as follows.

–foreman-proxy-dhcp-interface=enp2s0 \

–foreman-proxy-dns-interface=enp2s0 \

–foreman-proxy-dns="true" \

–foreman-proxy-dns-reverse="216.11.10.in-addr.arpa" \

–foreman-proxy-dns-server="10.11.216.8" \

–foreman-proxy-dhcp-gateway="10.11.216.1" \

–foreman-proxy-dhcp-range="10.11.216.30 10.11.216.254" \

–foreman-proxy-dhcp-key-name=jarvis_omapi.key \

–foreman-proxy-dhcp-key-secret="keydata" \

–foreman-proxy-dhcp=true \

–foreman-proxy-dhcp-nameservers=10.11.216.1

This creates a valid dhcpd.conf configuration file, it matches it perfectly
and I can successfully import this into foreman.

I can successfully add hosts to foreman and it builds them, excellent, no
problems.

IP management is set to dhcp

Certain host I am unable to add to foreman.

The first problem is caused when foreman tries to suggest an IP address for
a host, sometimes it suggests an IP address that is already allocated to a
host.

the example situation I have at the moment is that foreman is suggesting
10.11.216.44

However, 10.11.216.44 already has an entry in the lease file

lease 10.11.216.44 {

starts 0 2017/05/14 14:42:31;

ends 1 2017/05/15 02:42:31;

tstp 1 2017/05/15 02:42:31;

cltt 0 2017/05/14 14:42:31;

binding state active;

next binding state free;

rewind binding state free;

hardware ethernet 40:8d:5c:56:58:86;

The odd thing is this is for the host I'm trying to add is this mac address 40:8d:5c:56:58:86
so it's the same.

I have however (not at this time an example) had problems with this install
where it allocates an IP address of an existing host NOT the one I'm trying
to add.

This would however be no problem as I would normally click "suggest new ip"
and get a new IP, however, it appears to attempt to action this but returns
with the same IP. (I assume because there is an entry in the lease file for
this it's got no choice but to return this iP ?)

I see it trying in the proxy log foreman trying to request a new IP, so I
know it is actually trying.

I, [2017-05-14T16:33:36.345557 ] INFO – : 10.11.216.4 - -
[14/May/2017:16:33:36 +0100] "GET
/dhcp/10.11.216.0/unused_ip?mac=40:8d:5c:56:58:86&from=10.11.216.30&to=10.11.216.250
HTTP/1.1" 200 21 0.0018

The parts I'm not sure around this are

a.) why is foreman getting IP from the dhcp server that already have hosts
allocated to them ?

b.) is the suggest new button expected to return the same address only if
the host already has a lease/ip assigned to it, or should it get a new one
and update the lease on commit of the host ?

If I try to continue with adding the host in question, the creation of the
host in foreman fails with the error

Create DHCP Settings for riker.no-dns.co.uk task failed with the following
error: ERF12-6899 [ProxyAPI::ProxyException]: Unable to set DHCP entry
([RestClient::Conflict]: 409 Conflict) for proxy
https://jarvis.no-dns.co.uk:8443/dhcp

which makes sense - as there is already an entry there, but normally this
offers an option to override, in this case it doesn't

The production log for adding this host shows the conflict and exception

2017-05-14 16:54:44 ad4bcde6 [app] [I] Started POST
"/hosts/medium_selected" for 10.11.216.43 at 2017-05-14 16:54:44 +0100

2017-05-14 16:54:44 ad4bcde6 [app] [I] Processing by
HostsController#medium_selected as /

2017-05-14 16:54:44 ad4bcde6 [app] [I] Parameters:
{"host"=>{"medium_id"=>"1", "operatingsystem_id"=>"1",
"architecture_id"=>"1", "use_image"=>"false"}}

2017-05-14 16:54:44 ad4bcde6 [app] [I] Current user: admin (administrator)

2017-05-14 16:54:44 ad4bcde6 [app] [I] Rendered
common/os_selection/_image_details.html.erb (4.6ms)

2017-05-14 16:54:44 ad4bcde6 [app] [I] Completed 200 OK in 22ms (Views:
7.3ms | ActiveRecord: 0.5ms)

2017-05-14 16:54:46 01276ad6 [app] [I] Started GET
"/notification_recipients" for 10.11.216.43 at 2017-05-14 16:54:46 +0100

2017-05-14 16:54:46 01276ad6 [app] [I] Processing by
NotificationRecipientsController#index as JSON

2017-05-14 16:54:46 01276ad6 [app] [I] Current user: admin (administrator)

2017-05-14 16:54:46 01276ad6 [app] [I] Completed 200 OK in 5ms (Views:
0.2ms | ActiveRecord: 0.5ms)

2017-05-14 16:55:26 4335f5d9 [app] [I] Started POST "/hosts" for
10.11.216.43 at 2017-05-14 16:55:26 +0100

2017-05-14 16:55:26 4335f5d9 [app] [I] Processing by HostsController#create
as /

2017-05-14 16:55:26 4335f5d9 [app] [I] Parameters: {"utf8"=>"✓",
"authenticity_token"=>"ggjQWxy8Umjc5Oxj+Mx7gw0NshrUhI6AE0iKBHFbSOtjXDGDtdJZaISRnk+7GJ6VZZ/X7cIFizk8eLCAW6kcbQ==",
"host"=>{"name"=>"riker", "hostgroup_id"=>"1", "compute_resource_id"=>"",
"ansible_role_ids"=>[""], "puppetclass_ids"=>[""], "managed"=>"true",
"progress_report_id"=>"[FILTERED]", "type"=>"Host::Managed",
"interfaces_attributes"=>{"0"=>{"_destroy"=>"0", "type"=>"Nic::Managed",
"mac"=>"40:8d:5c:56:58:86", "identifier"=>"enp0s31f6", "name"=>"riker",
"domain_id"=>"1", "subnet_id"=>"1", "ip"=>"10.11.216.44", "ip6"=>"",
"managed"=>"1", "primary"=>"1", "provision"=>"1", "execution"=>"1",
"virtual"=>"0", "tag"=>"", "attached_to"=>""}}, "architecture_id"=>"1",
"operatingsystem_id"=>"1", "provision_method"=>"build", "build"=>"1",
"medium_id"=>"1", "ptable_id"=>"101", "pxe_loader"=>"PXELinux BIOS",
"disk"=>"", "root_pass"=>"[FILTERED]", "is_owned_by"=>"3-Users",
"enabled"=>"1", "model_id"=>"", "comment"=>"", "overwrite"=>"false"},
"bare_metal_capabilities"=>"build"}

2017-05-14 16:55:26 4335f5d9 [app] [I] Current user: admin (administrator)

2017-05-14 16:55:26 4335f5d9 [app] [I] Create DHCP reservation
riker.no-dns.co.uk for riker.no-dns.co.uk-40:8d:5c:56:58:86/10.11.216.44

2017-05-14 16:55:27 4335f5d9 [app] [W] Create DHCP Settings for
riker.no-dns.co.uk task failed with the following error: ERF12-6899
[ProxyAPI::ProxyException]: Unable to set DHCP entry
([RestClient::Conflict]: 409 Conflict) for proxy
https://jarvis.no-dns.co.uk:8443/dhcp

> ProxyAPI::ProxyException: ERF12-6899 [ProxyAPI::ProxyException]: Unable
to set DHCP entry ([RestClient::Conflict]: 409 Conflict) for proxy
https://jarvis.no-dns.co.uk:8443/dhcp

> /usr/share/foreman/lib/proxy_api/dhcp.rb:86:in `rescue in set'

> /usr/share/foreman/lib/proxy_api/dhcp.rb:82:in `set'

> /usr/share/foreman/lib/net/dhcp/record.rb:30:in `create'

> /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:57:in
`block in set_dhcp'

> /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:57:in `each'

> /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:57:in `all?'

> /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:57:in
`set_dhcp'

> /usr/share/foreman/app/models/concerns/orchestration.rb:216:in `execute'

> /usr/share/foreman/app/models/concerns/orchestration.rb:144:in `block in
process'

> /usr/share/foreman/app/models/concerns/orchestration.rb:136:in `each'

> /usr/share/foreman/app/models/concerns/orchestration.rb:136:in `process'

> /usr/share/foreman/app/models/concerns/orchestration.rb:44: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: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: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/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'

> /usr/share/foreman/app/controllers/hosts_controller.rb:104:in `create'

>
/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: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: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:15:in
`set_timezone'