No DHCP record for MAC

Problem:
Upon Create Host submission, getting “No DHCP record for MAC” from the proxy.log

Expected outcome:

Foreman and Proxy versions:
foreman-2.0.3-1.el7.noarch

Foreman and Proxy plugin versions:
katello-3.15.3-1.el7.noarch

Distribution and version:
On CentOS 7 3.10.0-1127.el7.x86_64

Other relevant data:
(Names, IPs has been changed)

  1. error from /var/log/foreman-proxy/proxy.log: -
    2021-02-18T02:28:50 a0035bd6 [I] Started GET /tftp/serverName
    2021-02-18T02:28:50 a0035bd6 [I] Finished GET /tftp/serverName with 200 (0.84 ms)
    2021-02-18T02:28:50 a0035bd6 [I] Started GET /dhcp/100.100.10.64/mac/00:00:1c:09:f7:dc
    2021-02-18T02:28:50 a0035bd6 [E] No DHCP record for MAC 100.100.10.64/00:00:1c:09:f7:dc found
    2021-02-18T02:28:50 a0035bd6 [W] No DHCP record for MAC 100.100.10.64/00:00:1c:09:f7:dc found
    Exception: No DHCP record for MAC 100.100.10.64/00:00:1c:09:f7:dc found
    2021-02-18T02:28:50 a0035bd6 [I] Finished GET /dhcp/100.100.10.64/mac/00:00:1c:09:f7:dc with 404 (0.87 ms)
    2021-02-18T02:28:50 a0035bd6 [I] Started GET /dhcp/100.100.10.64/ip/100.100.10.72
    2021-02-18T02:28:50 a0035bd6 [E] No DHCP records for IP 100.100.10.64/100.100.10.72 found
    2021-02-18T02:28:50 a0035bd6 [W] No DHCP records for IP 100.100.10.64/100.100.10.72 found
    Exception: No DHCP records for IP 100.100.10.64/100.100.10.72 found
    2021-02-18T02:28:50 a0035bd6 [I] Finished GET /dhcp/100.100.10.64/ip/100.100.10.72 with 404 (0.94 ms)
    2021-02-18T02:28:50 a0035bd6 [I] Started POST /dhcp/100.100.10.64
    2021-02-18T02:28:51 a0035bd6 [I] Finished POST /dhcp/100.100.10.64 with 200 (28.76 ms)
    2021-02-18T02:28:51 a0035bd6 [I] Started GET /unattended/templateServer
    2021-02-18T02:28:51 a0035bd6 [I] Finished GET /unattended/templateServer with 200 (0.33 ms)
    2021-02-18T02:28:51 a0035bd6 [I] Started POST /tftp/PXELinux/00:00:1c:09:f7:dc
    2021-02-18T02:28:51 a0035bd6 [I] Finished POST /tftp/PXELinux/00:00:1c:09:f7:dc with 200 (0.87 ms)
    2021-02-18T02:28:51 a0035bd6 [I] Started GET /unattended/templateServer
    2021-02-18T02:28:51 a0035bd6 [I] Finished GET /unattended/templateServer with 200 (0.35 ms)
    2021-02-18T02:28:51 a0035bd6 [I] Started GET /unattended/templateServer
    2021-02-18T02:28:51 a0035bd6 [I] Finished GET /unattended/templateServer with 200 (0.43 ms)
    2021-02-18T02:28:51 a0035bd6 [I] Started POST /tftp/PXEGrub2/00:00:1c:09:f7:dc
    2021-02-18T02:28:51 a0035bd6 [I] Finished POST /tftp/PXEGrub2/00:00:1c:09:f7:dc with 200 (1.12 ms)
    2021-02-18T02:28:51 a0035bd6 [I] Started GET /unattended/templateServer
    2021-02-18T02:28:51 a0035bd6 [I] Finished GET /unattended/templateServer with 200 (0.32 ms)
    2021-02-18T02:28:51 a0035bd6 [I] Started POST /tftp/PXEGrub/00:00:1c:09:f7:dc
    2021-02-18T02:28:51 a0035bd6 [I] Finished POST /tftp/PXEGrub/00:00:1c:09:f7:dc with 200 (0.94 ms)
    2021-02-18T02:28:51 a0035bd6 [I] Started POST /tftp/fetch_boot_file
    2021-02-18T02:28:51 a0035bd6 [I] Finished POST /tftp/fetch_boot_file with 200 (0.93 ms)
    2021-02-18T02:28:51 a0035bd6 [I] Started POST /tftp/fetch_boot_file
    2021-02-18T02:28:51 a0035bd6 [I] Finished POST /tftp/fetch_boot_file with 200 (0.74 ms)
    2021-02-18T02:28:51 a0035bd6 [I] Started DELETE /puppet/ca/toweiie.company
    2021-02-18T02:28:51 a0035bd6 [I] Finished DELETE /puppet/ca/toweiie.company with 200 (74.87 ms)
    2021-02-18T02:28:51 a0035bd6 [I] Started POST /puppet/ca/autosign/toweiie.company
    2021-02-18T02:28:51 a0035bd6 [I] Finished POST /puppet/ca/autosign/toweiie.company with 200 (0.69 ms)

  2. Smart Proxies all on single Foreman instance, except DNS is using external configured through named: -

Details

Communication status

URL
https://butters.company:9090

Version
2.0.3

Active features

  • DHCP

  • HTTPBoot

  • Logs

  • Pulp

  • Pulpcore

  • Puppet

  • Puppet CA

  • Templates

  • TFTP

[Refresh features]

Hosts managed
[2]

Failed features
No Failed Features

  1. DHCP is reachable: -
    curl -kvs --cert /etc/foreman/client_cert.pem --key /etc/foreman/client_key.pem --cacert /etc/foreman/proxy_ca.pem https://butters.company:9090/dhcp
  • About to connect() to butters.company port 9090 (#0)
  • Trying 100.100.10.102…
  • Connected to butters.company (100.100.10.102) port 9090 (#0)
  • Initializing NSS with certpath: sql:/etc/pki/nssdb
  • skipping SSL peer certificate verification
  • NSS: client certificate from file
  •   subject: CN=butters.company,OU=PUPPET,O=FOREMAN,ST=North Carolina,C=US
    
  •   start date: Oct 20 02:57:52 2020 GMT
    
  •   expire date: Jan 18 02:57:52 2038 GMT
    
  •   common name: butters.company
    
  •   issuer: CN=butters.company,OU=SomeOrgUnit,O=Katello,L=Raleigh,ST=North Carolina,C=US
    
  • SSL connection using TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
  • Server certificate:
  •   subject: CN=butters.company,OU=SMART_PROXY,O=FOREMAN,ST=North Carolina,C=US
    
  •   start date: Oct 20 02:57:56 2020 GMT
    
  •   expire date: Jan 18 02:57:56 2038 GMT
    
  •   common name: butters.company
    
  •   issuer: CN=butters.company,OU=SomeOrgUnit,O=Katello,L=Raleigh,ST=North Carolina,C=US
    

GET /dhcp HTTP/1.1
User-Agent: curl/7.29.0
Host: butters.company:9090
Accept: /

< HTTP/1.1 200 OK
< Content-Type: application/json
< Content-Length: 193
< X-Content-Type-Options: nosniff
< Server: foreman-proxy/2.0.3
< Date: Thu, 18 Feb 2021 09:20:27 GMT
< Connection: Keep-Alive
<

  • Connection #0 to host butters.company left intact
    [{“network”:“100.100.10.96”,“netmask”:“255.255.255.224”,“options”:{“routers”:[“100.100.10.97”]}},{“network”:“100.100.10.64”,“netmask”:“255.255.255.224”,“options”:{“routers”:[“100.100.10.65”]}}]
  1. Subnets configured on dhcpd.conf and Foreman GUI: -

foreman-installer. Use custom-hiera.yaml for multiple subnets.

omapi-port 7911;

default-lease-time 43200;
max-lease-time 86400;

not authoritative;

ddns-update-style none;

option domain-name “company”;
option domain-name-servers 100.100.20.10, 100.100.21.25;
option ntp-servers none;

allow booting;
allow bootp;

option fqdn.no-client-update on; # set the “O” and “S” flag bits
option fqdn.rcode2 255;
option pxegrub code 150 = text ;

required for UEFI HTTP boot

if substring(option vendor-class-identifier, 0, 10) = “HTTPClient” {
option vendor-class-identifier “HTTPClient”;
}

promote vendor in dhcpd.leases

set vendor-string = option vendor-class-identifier;

next server and filename options

next-server 100.100.10.102;
option architecture code 93 = unsigned integer 16 ;
if option architecture = 00:06 {
filename “grub2/shim.efi”;
} elsif option architecture = 00:07 {
filename “grub2/shim.efi”;
} elsif option architecture = 00:09 {
filename “grub2/shim.efi”;
} else {
filename “pxelinux.0”;
}

log-facility local7;

include “/etc/dhcp/dhcpd.hosts”;

company

subnet 100.100.10.96 netmask 255.255.255.224 {
pool
{
range 100.100.10.122 100.100.10.126;
}

option subnet-mask 255.255.255.224;
option routers 100.100.10.97;
}
subnet 100.100.10.64 netmask 255.255.255.224 {
pool
{
range 100.100.10.70 100.100.10.79;
}

option subnet-mask 255.255.255.224;
option routers 100.100.10.65;
}

Welcome and please pay attention when pasting those bits, there is a formatting you can use to make it more readable.

What error do you see in the production.log?

Thank you lzap, apologies for the bad formatting.
From the looks of the production log, did not capture any errors during the same time frame: -

2021-02-18T02:28:50 [I|app|a0035bd6] Started POST “/hosts” for 100.100.124.121 at 2021-02-18 02:28:50 -0600
2021-02-18T02:28:50 [I|app|a0035bd6] Processing by HostsController#create as /
2021-02-18T02:28:50 [I|app|a0035bd6] Parameters: {“utf8”=>“✓”, “authenticity_token”=>“000mtatMgzC+bbt6qcenvvU6VgwhW9YnvQIbPYD7AR2D92VyMWXpDw1j2vaIGS4S0HHjyAcFiTitT5haIaHLn000”, “host”=>{“name”=>“toweiie”, “organization_id”=>“1”, “l
ocation_id”=>“2”, “hostgroup_id”=>“1”, “content_facet_attributes”=>{“lifecycle_environment_id”=>“11”, “content_view_id”=>“8”, “content_source_id”=>“1”}, “managed”=>“true”, “progress_report_id”=>"[FILTERED]", “type”=>“Host::Managed”,
“interfaces_attributes”=>{“0”=>{"_destroy"=>“0”, “type”=>“Nic::Managed”, “mac”=>“00:00:1c:09:f7:dc”, “identifier”=>“em1”, “name”=>“toweiie”, “domain_id”=>“1”, “subnet_id”=>“4”, “ip”=>“100.100.10.72”, “ip6”=>"", “managed”=>“1”, “prima
ry”=>“1”, “provision”=>“1”, “virtual”=>“0”, “tag”=>"", “attached_to”=>""}}, “architecture_id”=>“1”, “operatingsystem_id”=>“1”, “provision_method”=>“build”, “build”=>“1”, “medium_id”=>“1”, “ptable_id”=>“113”, “pxe_loader”=>“PXELinux B
IOS”, “disk”=>"", “root_pass”=>"[FILTERED]", “is_owned_by”=>“5-Users”, “enabled”=>“1”, “model_id”=>“4”, “comment”=>"", “overwrite”=>“false”}, “media_selector”=>“install_media”}
2021-02-18T02:28:50 [I|app|a0035bd6] Create DHCP reservation toweiie.company for toweiie.company-00:00:1c:09:f7:dc/100.100.10.72
2021-02-18T02:28:51 [I|app|a0035bd6] Deploying TFTP PXELinux configuration for toweiie.company
2021-02-18T02:28:51 [I|app|a0035bd6] Deploying TFTP PXEGrub2 configuration for toweiie.company
2021-02-18T02:28:51 [I|app|a0035bd6] Deploying TFTP PXEGrub configuration for toweiie.company
2021-02-18T02:28:51 [I|app|a0035bd6] Skipping TFTP iPXE configuration for toweiie.company
2021-02-18T02:28:51 [I|app|a0035bd6] Fetching required TFTP boot files for toweiie.company
2021-02-18T02:28:51 [I|app|a0035bd6] Processed 6 tasks from queue ‘Host::Managed Main’, completed 6/6
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on mac 00:00:1c:09:f7:dc
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on ip 100.100.10.72
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on type Nic::Managed
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on name toweiie.company
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on host_id 14
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on subnet_id 4
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on domain_id 1
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on attrs {}
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on provider
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on username
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on password [redacted]
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on virtual false
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on link true
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on identifier em1
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on tag
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on attached_to
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on managed true
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on mode balance-rr
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on attached_devices
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on bond_options
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on primary true
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on provision true
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on compute_attributes {}
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on ip6
2021-02-18T02:28:51 [I|aud|a0035bd6] Nic::Managed (15) create event on subnet6_id
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on name toweiie.company
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on root_pass 000i1GNOIXSVKwINOik$QyyvcXKCu9aJi5zFY4BMw87YI1TxhtPduYR000.8.05
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on architecture_id 1
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on operatingsystem_id 1
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on environment_id
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on ptable_id 113
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on medium_id 1
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on build true
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on comment
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on disk
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on installed_at
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on model_id 4
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on hostgroup_id 1
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on owner_id 5
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on owner_type User
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on enabled true
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on puppet_ca_proxy_id 1
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on managed true
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on use_image
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on image_file
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on uuid
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on compute_resource_id
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on puppet_proxy_id
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on certname
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on image_id
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on organization_id 1
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on location_id 2
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on otp
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on realm_id
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on compute_profile_id
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on provision_method build
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on grub_pass 000alp0Rv0SVzs8H5Sj$czBZF.NdBr11McCbNCAumThbokXIttX1hOkhYu5UPE/6n07dOZo1Oz1H1T000.ndTCy.3517xk8qCGyVfH2000
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on pxe_loader PXELinux BIOS
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on initiated_at
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on build_errors
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (14) create event on content_facet_attributes {“id”=>nil, “host_id”=>nil, “uuid”=>nil, “content_view_id”=>8, “lifecycle_environment_id”=>11, “kickstart_repository_id”=>nil, “content_source_id”=>1, “installable_security_errata_count”=>0, “installable_enhancement_errata_count”=>0, “installable_bugfix_errata_count”=>0, “applicable_rpm_count”=>0, “upgradable_rpm_count”=>0, “applicable_module_stream_count”=>0, “upgradable_module_stream_count”=>0}
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (13) create event on host_id 14
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (13) create event on uuid
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (13) create event on content_view_id 8
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (13) create event on lifecycle_environment_id 11
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (13) create event on kickstart_repository_id
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (13) create event on content_source_id 1
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (13) create event on installable_security_errata_count 0
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (13) create event on installable_enhancement_errata_count 0
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (13) create event on installable_bugfix_errata_count 0
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (13) create event on applicable_rpm_count 0
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (13) create event on upgradable_rpm_count 0
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (13) create event on applicable_module_stream_count 0
2021-02-18T02:28:51 [I|aud|a0035bd6] Host::Base (13) create event on upgradable_module_stream_count 0
2021-02-18T02:28:51 [I|app|a0035bd6] Remove puppet certificate for toweiie.company
2021-02-18T02:28:51 [I|app|a0035bd6] Adding autosign entry for toweiie.company
2021-02-18T02:28:51 [I|app|a0035bd6] Processed 2 tasks from queue ‘Host::Managed Post’, completed 2/2
2021-02-18T02:28:51 [I|app|a0035bd6] Redirected to https://butters.company/hosts/toweiie.company
2021-02-18T02:28:51 [I|app|a0035bd6] Completed 302 Found in 906ms (ActiveRecord: 51.0ms)
2021-02-18T02:28:51 [I|app|6b1b5696] Started GET “/tasks/000be63b-bfe0-4ee6-9c2a-daaffe555000” for 100.100.124.121 at 2021-02-18 02:28:51 -0600
2021-02-18T02:28:51 [I|app|6b1b5696] Processing by TasksController#show as /
2021-02-18T02:28:51 [I|app|6b1b5696] Parameters: {“id”=>“000be63b-bfe0-4ee6-9c2a-daaffe555000”}
2021-02-18T02:28:51 [I|app|6b1b5696] Rendered tasks/_list.html.erb (0.8ms)
2021-02-18T02:28:51 [I|app|6b1b5696] Completed 200 OK in 10ms (Views: 4.7ms | ActiveRecord: 1.0ms)
2021-02-18T02:28:52 [I|app|bbc87af0] Started GET “/hosts/toweiie.company” for 100.100.124.121 at 2021-02-18 02:28:52 -0600

This is not a bug or error, it’s intentional. Foreman tries to find a record by MAC and by IP so it knows if there was a conflict in advance.

OK, so the “No DHCP record for MAC” is intentional/normal for conflict checking (the E category in the logs is a little misleading then :sweat_smile:)

The reason I got to checking this was because the baremetal I was trying to PXELinux boot was reaching “No DHCP or proxyDHCP offers were received”

  • had the Network team change the primary NIC (on MAC 00:00:1c:09:f7:dc) to vlan 1311
  • also had the IP Helper on vlan 1311 set to look for the IP 100.100.10.102 (which is the foreman server with all the proxy services including DHCP)

My worst fear that this would still turn out to be a network setup problem.
With dhcp being accessible with curl (getting HTTP/1.1 200 OK) would you be able to give any advise on what else I should be looking into to resolve this?

I don’t understand.

It’s fine now, thank you.
As expected since the “No DHCP records for IP” was a normal validation check and not an error, it started to look more like a network matter.

The baremetal I was trying to PXE boot with Foreman was configured wrongly with vlan tagging enabled at the switch side, removed that and the server was able to reach DHCP on Foreman while tcpdump was catching response from dhcp ports.

Pls consider this matter closed, thanks again.

Same message, and omshell is hanging at 100%. No vlan tagging, so @maverick’s solution doesn’t apply. If “No DHCP record for MAC” is informational, Foreman shouldn’t categorise it as an error.

If you are on Ubuntu there is a bug in Ubuntu’s ISC DHCP, a regression, it’s been discussed here.

No DHCP record for MAC is a 404 error because smart proxy is a REST API and that is exactly how REST services are supposed to work. Foreman tries to find a record by looking up it in smart proxy API, 404 is a valid response (no such record exist) therefore Foreman does perform creation of a new one.

If we had a proper RPC API that would be another story, but REST is the de-facto standard these days. Don’t ask me why, I find REST awful.

Are you referring to this topic? Foreman-proxy Failed to add DHCP reservation for new_vm

I also got the same error as @gafferman: