Discovery Auto Provisioning Not Working

fresh-pie · September 23, 2020, 1:53pm

Hi guys,

I feel like I’m probably overlooking something, but I’m having issues with the Discovery plugin automatically provisioning systems using rules.

Here is my scenario:

I have a custom Organization and Location created.
I have a known working host group created.
I have the Discovery plugin and image installed on my Foreman server.
I have a Discovery Rule created that will match a particular system.
My Discovery Rule has its Organization and Location set to my custom objects.
In the Discovery settings, I have “Auto provisioning” set to “Yes”.
In the Discovery settings, I have “Discovery organization” set to my custom organization.
In the Discovery settings, I have “Discovery location” set to my custom location.

The below is what happens during the discovery process:

System PXE boots, loads the ‘discovery’ block in the default pxelinux configuration.
System boots into the discovery image.
System is successfully discovered, but never automatically provisions.
I can find the discovered host in Foreman and select “Auto Provision”, it successfully begins to provision the host. This would mean that the host group, subnet and all other components are successfully setup, right?

I grabbed the below out of my production.log. This is what is logged once the system is initially discovered:

2020-09-23T08:21:51 [I|app|517198a9] Processing by Api::V2::DiscoveredHostsController#facts as JSON
2020-09-23T08:21:51 [I|app|517198a9]   Parameters: {"facts"=>"[FILTERED]", "apiv"=>"v2", "discovered_host"=>{"facts"=>"[FILTERED]"}}
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on mac
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on ip
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on type Nic::Managed
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on name mac40f2e9d65067
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on host_id 6
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on subnet_id
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on domain_id
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on attrs {}
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on provider
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on username
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on password [redacted]
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on virtual false
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on link true
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on identifier
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on tag
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on attached_to
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on managed true
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on mode balance-rr
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on attached_devices
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on bond_options
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on primary true
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on provision true
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on compute_attributes {}
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on ip6
2020-09-23T08:21:51 [I|aud|517198a9] Nic::Managed (14) create event on subnet6_id
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on name mac40f2e9d65067
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on last_compile
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on root_pass
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on architecture_id
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on operatingsystem_id
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on environment_id
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on ptable_id
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on medium_id
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on build false
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on comment
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on disk
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on installed_at
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on model_id
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on hostgroup_id
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on owner_id
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on owner_type
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on enabled true
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on puppet_ca_proxy_id
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on managed false
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on use_image
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on image_file
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on uuid
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on compute_resource_id
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on puppet_proxy_id
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on certname
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on image_id
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on organization_id
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on location_id
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on otp
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on realm_id
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on compute_profile_id
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on provision_method
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on grub_pass
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on global_status 0
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on lookup_value_matcher
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on pxe_loader
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on initiated_at
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on build_errors
2020-09-23T08:21:51 [I|aud|517198a9] Host::Base (6) create event on discovery_rule_id
2020-09-23T08:21:51 [I|app|77c058a6] Started GET "/notification_recipients" for 127.0.0.1 at 2020-09-23 08:21:51 -0400
2020-09-23T08:21:51 [I|app|77c058a6] Processing by NotificationRecipientsController#index as JSON
2020-09-23T08:21:51 [I|app|77c058a6] Completed 200 OK in 21ms (Views: 0.1ms | ActiveRecord: 4.4ms | Allocations: 4682)
2020-09-23T08:21:52 [I|app|517198a9] Import facts for 'mac40f2e9d65067' completed. Added: 192, Updated: 0, Deleted 0 facts
2020-09-23T08:21:52 [I|aud|517198a9] Nic::Managed (14) update event on mac , 40:f2:e9:d6:50:67
2020-09-23T08:21:52 [I|aud|517198a9] Nic::Managed (14) update event on identifier , enp6s0
2020-09-23T08:21:52 [I|app|517198a9] Detected IPv4 subnet: 00712_OpsNet with taxonomy ["MyOrg"]/["MyLocation"]
2020-09-23T08:21:52 [I|app|517198a9] Assigned location: MyLocation
2020-09-23T08:21:52 [I|app|517198a9] Assigned organization: MyOrg
2020-09-23T08:21:52 [I|aud|517198a9] Host::Base (6) update event on model_id , 2
2020-09-23T08:21:52 [I|aud|517198a9] Host::Base (6) update event on owner_id , 1
2020-09-23T08:21:52 [I|aud|517198a9] Host::Base (6) update event on owner_type , User
2020-09-23T08:21:52 [I|aud|517198a9] Host::Base (6) update event on organization_id , 3
2020-09-23T08:21:52 [I|aud|517198a9] Host::Base (6) update event on location_id , 4
2020-09-23T08:21:52 [I|aud|517198a9] Nic::Managed (14) update event on subnet_id , 3
2020-09-23T08:21:52 [I|app|517198a9] Completed 201 Created in 933ms (Views: 1.3ms | ActiveRecord: 284.0ms | Allocations: 310169)

Any ideas would be greatly appreciated.

Thanks!

lzap · September 23, 2020, 3:01pm

Hello, enable debug mode. There are many messages in logs in debug level, you should see Finding auto discovery rule for host... etc. Rule must exist, must be enabled and must match something. What is your condition?

fresh-pie · September 23, 2020, 4:14pm

Hey lzap!

Ok, I turned on debug logging. See my results below.

In regards to the rule:

It is enabled.
The rule’s condition/query is: facts.ipaddress=10.59.24.175
The hosts IP is indeed 10.59.24.175. This IP is assigned via a DHCP reservation.
If I select the Discovered Hosts action for the rule, it finds the host that I would expect to auto-provision. This makes me think the rule is correctly configured.
If I select Auto-Provision for the discovered host, it builds just fine.

Here is the debug log:

2020-09-23T12:02:43 [I|app|9ce1f894] Started POST "/api/v2/discovered_hosts/facts" for 127.0.0.1 at 2020-09-23 12:02:43 -0400
2020-09-23T12:02:43 [I|app|9ce1f894] Processing by Api::V2::DiscoveredHostsController#facts as JSON
2020-09-23T12:02:43 [I|app|9ce1f894]   Parameters: {"facts"=>"[FILTERED]", "apiv"=>"v2", "discovered_host"=>{"facts"=>"[FILTERED]"}}
2020-09-23T12:02:43 [W|app|9ce1f894] One or more existing managed hosts found: ods00712w10.example.net/40:f2:e9:d6:50:67
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on mac
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on ip
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on type Nic::Managed
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on name mac40f2e9d65067
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on host_id 9
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on subnet_id
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on domain_id
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on attrs {}
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on provider
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on username
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on password [redacted]
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on virtual false
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on link true
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on identifier
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on tag
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on attached_to
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on managed true
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on mode balance-rr
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on attached_devices
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on bond_options
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on primary true
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on provision true
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on compute_attributes {}
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on ip6
2020-09-23T12:02:43 [I|aud|9ce1f894] Nic::Managed (22) create event on subnet6_id
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on name mac40f2e9d65067
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on last_compile
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on root_pass
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on architecture_id
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on operatingsystem_id
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on environment_id
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on ptable_id
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on medium_id
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on build false
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on comment
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on disk
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on installed_at
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on model_id
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on hostgroup_id
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on owner_id
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on owner_type
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on enabled true
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on puppet_ca_proxy_id
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on managed false
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on use_image
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on image_file
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on uuid
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on compute_resource_id
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on puppet_proxy_id
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on certname
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on image_id
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on organization_id
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on location_id
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on otp
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on realm_id
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on compute_profile_id
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on provision_method
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on grub_pass
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on global_status 0
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on lookup_value_matcher
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on pxe_loader
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on initiated_at
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on build_errors
2020-09-23T12:02:43 [I|aud|9ce1f894] Host::Base (9) create event on discovery_rule_id
2020-09-23T12:02:44 [I|app|9ce1f894] Import facts for 'mac40f2e9d65067' completed. Added: 192, Updated: 0, Deleted 0 facts
2020-09-23T12:02:44 [D|tax|9ce1f894] Current location set to Default Location
2020-09-23T12:02:44 [D|tax|9ce1f894] Current organization set to Default Organization
2020-09-23T12:02:44 [D|app|9ce1f894] skipping interface with identifier 'lo' since it was matched by 'ignored_interface_identifiers' setting
2020-09-23T12:02:44 [D|app|9ce1f894] We have following interfaces 'enp11s0, enp6s0' based on facts
2020-09-23T12:02:44 [D|app|9ce1f894] Interface enp11s0 facts: {"macaddress"=>"40:f2:e9:d6:50:68", "mtu"=>1500, "duplex"=>"unknown! (255)", "port"=>"Twisted Pair", "auto_negotiation"=>"true", "wol"=>true, "link"=>"false"}
2020-09-23T12:02:44 [D|app|9ce1f894] Interface enp6s0 facts: {"ipaddress"=>"10.59.24.175", "macaddress"=>"40:f2:e9:d6:50:67", "netmask"=>"255.255.255.0", "mtu"=>1500, "network"=>"10.59.24.0", "speed"=>"1000", "duplex"=>"full", "port"=>"Twisted Pair", "auto_negotiation"=>"true", "wol"=>true, "link"=>"true"}
2020-09-23T12:02:44 [D|app|9ce1f894] Discovery fact parser detected primary interface: ["enp6s0", {"ipaddress"=>"10.59.24.175", "macaddress"=>"40:f2:e9:d6:50:67", "netmask"=>"255.255.255.0", "mtu"=>1500, "network"=>"10.59.24.0", "speed"=>"1000", "duplex"=>"full", "port"=>"Twisted Pair", "auto_negotiation"=>"true", "wol"=>true, "link"=>"true", "keep_subnet"=>true, "virtual"=>false}]
2020-09-23T12:02:44 [D|app|9ce1f894] Discovery fact parser detected primary interface: ["enp6s0", {"ipaddress"=>"10.59.24.175", "macaddress"=>"40:f2:e9:d6:50:67", "netmask"=>"255.255.255.0", "mtu"=>1500, "network"=>"10.59.24.0", "speed"=>"1000", "duplex"=>"full", "port"=>"Twisted Pair", "auto_negotiation"=>"true", "wol"=>true, "link"=>"true", "keep_subnet"=>true, "virtual"=>false}]
2020-09-23T12:02:44 [D|app|9ce1f894] Suggested enp6s0 NIC as a primary interface.
2020-09-23T12:02:44 [I|aud|9ce1f894] Nic::Managed (22) update event on mac , 40:f2:e9:d6:50:67
2020-09-23T12:02:44 [I|aud|9ce1f894] Nic::Managed (22) update event on identifier , enp6s0
2020-09-23T12:02:44 [D|app|9ce1f894] Saving enp11s0 NIC for host mac40f2e9d65067
2020-09-23T12:02:44 [D|app|9ce1f894] Saving enp6s0 NIC for host mac40f2e9d65067
2020-09-23T12:02:44 [D|app|9ce1f894] Saving ipmi NIC for host mac40f2e9d65067
2020-09-23T12:02:44 [I|app|9ce1f894] Detected IPv4 subnet: 00712_OpsNet with taxonomy ["MyOrg"]/["MyLoc"]
2020-09-23T12:02:44 [I|app|9ce1f894] Assigned location: MyOrg
2020-09-23T12:02:44 [I|app|9ce1f894] Assigned organization: MyLoc
2020-09-23T12:02:44 [I|aud|9ce1f894] Host::Base (9) update event on model_id , 2
2020-09-23T12:02:44 [I|aud|9ce1f894] Host::Base (9) update event on owner_id , 1
2020-09-23T12:02:44 [I|aud|9ce1f894] Host::Base (9) update event on owner_type , User
2020-09-23T12:02:44 [I|aud|9ce1f894] Host::Base (9) update event on organization_id , 3
2020-09-23T12:02:44 [I|aud|9ce1f894] Host::Base (9) update event on location_id , 4
2020-09-23T12:02:44 [I|aud|9ce1f894] Nic::Managed (22) update event on subnet_id , 3
2020-09-23T12:02:44 [D|not|9ce1f894] Notification event: UINotifications::NewHost - checking for notifications
2020-09-23T12:02:44 [D|not|9ce1f894] Clearing Cache: notification, clearing cache for notification-4
2020-09-23T12:02:44 [D|app|9ce1f894] Finding auto discovery rule for host mac40f2e9d65067 (9)
2020-09-23T12:02:44 [D|app|9ce1f894] Body: {"id":9,"name":"mac40f2e9d65067","last_compile":null,"last_report":"2020-09-23T16:02:43.807Z","updated_at":"2020-09-23T16:02:44.592Z","created_at":"2020-09-23T16:02:43.767Z","root_pass":null,"architecture_id":null,"operatingsystem_id":null,"environment_id":null,"ptable_id":null,"medium_id":null,"build":false,"comment":null,"disk":null,"installed_at":null,"model_id":2,"hostgroup_id":null,"owner_id":1,"owner_type":"User","enabled":true,"puppet_ca_proxy_id":null,"managed":false,"use_image":null,"image_file":null,"uuid":null,"compute_resource_id":null,"puppet_proxy_id":null,"certname":null,"image_id":null,"organization_id":3,"location_id":4,"otp":null,"realm_id":null,"compute_profile_id":null,"provision_method":null,"grub_pass":"","global_status":0,"lookup_value_matcher":null,"pxe_loader":null,"initiated_at":null,"build_errors":null,"discovery_rule_id":null}
2020-09-23T12:02:44 [I|app|9ce1f894] Completed 201 Created in 974ms (Views: 1.3ms | ActiveRecord: 300.5ms | Allocations: 316758)

As you can see, it does log the Finding auto discovery rule for host part you mentioned, but I can’t tell if it is doing anything beyond that.

I have a feeling its something dumb I’m doing. Could it possibly be some kind of Organization or Location permission thing? I am using non-default Org and Locs. I’ve had an older version Foreman lab server with this working before, and I was just using everything in the default Organization and Location. That is the only thing different I can think of, besides it being a newer version of Foreman and the Discovery plugin (I think I had 15 on that system).

Also, I forgot to add my versions:

Foreman: 2.1.2
Discovery: 16.1.0

fresh-pie · September 23, 2020, 5:04pm

Ah, I think I figured it out!

It looks like this same host already existed in my Default Org. The below line in the log hinted me towards that:

One or more existing managed hosts found

After removing that host from the Default Org, it looks like auto-provisioning is working!

Thanks for the guidance!

fresh-pie · September 23, 2020, 8:34pm

Errr, I may have spoken too soon.

It is so odd, as it seemed that once I deleted that “duplicate” in the Default Org, my system automatically provisioned itself…

I just deleted it and tried again, but same results… The logs appear the same (besides the “One or more existing managed hosts found”.

2020-09-23T16:29:32 [I|app|0c37d93d] Started POST "/api/v2/discovered_hosts/facts" for 127.0.0.1 at 2020-09-23 16:29:32 -0400
2020-09-23T16:29:32 [I|app|0c37d93d] Processing by Api::V2::DiscoveredHostsController#facts as JSON
2020-09-23T16:29:32 [I|app|0c37d93d]   Parameters: {"facts"=>"[FILTERED]", "apiv"=>"v2", "discovered_host"=>{"facts"=>"[FILTERED]"}}
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on mac
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on ip
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on type Nic::Managed
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on name mac40f2e9d65067
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on host_id 11
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on subnet_id
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on domain_id
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on attrs {}
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on provider
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on username
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on password [redacted]
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on virtual false
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on link true
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on identifier
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on tag
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on attached_to
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on managed true
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on mode balance-rr
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on attached_devices
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on bond_options
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on primary true
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on provision true
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on compute_attributes {}
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on ip6
2020-09-23T16:29:32 [I|aud|0c37d93d] Nic::Managed (28) create event on subnet6_id
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on name mac40f2e9d65067
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on last_compile
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on root_pass
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on architecture_id
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on operatingsystem_id
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on environment_id
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on ptable_id
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on medium_id
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on build false
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on comment
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on disk
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on installed_at
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on model_id
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on hostgroup_id
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on owner_id
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on owner_type
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on enabled true
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on puppet_ca_proxy_id
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on managed false
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on use_image
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on image_file
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on uuid
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on compute_resource_id
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on puppet_proxy_id
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on certname
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on image_id
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on organization_id
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on location_id
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on otp
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on realm_id
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on compute_profile_id
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on provision_method
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on grub_pass
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on global_status 0
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on lookup_value_matcher
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on pxe_loader
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on initiated_at
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on build_errors
2020-09-23T16:29:32 [I|aud|0c37d93d] Host::Base (11) create event on discovery_rule_id
2020-09-23T16:29:33 [I|app|0c37d93d] Import facts for 'mac40f2e9d65067' completed. Added: 192, Updated: 0, Deleted 0 facts
2020-09-23T16:29:33 [D|tax|0c37d93d] Current location set to Default Location
2020-09-23T16:29:33 [D|tax|0c37d93d] Current organization set to Default Organization
2020-09-23T16:29:33 [D|app|0c37d93d] skipping interface with identifier 'lo' since it was matched by 'ignored_interface_identifiers' setting
2020-09-23T16:29:33 [D|app|0c37d93d] We have following interfaces 'enp11s0, enp6s0' based on facts
2020-09-23T16:29:33 [D|app|0c37d93d] Interface enp11s0 facts: {"macaddress"=>"40:f2:e9:d6:50:68", "mtu"=>1500, "duplex"=>"unknown! (255)", "port"=>"Twisted Pair", "auto_negotiation"=>"true", "wol"=>true, "link"=>"false"}
2020-09-23T16:29:33 [D|app|0c37d93d] Interface enp6s0 facts: {"ipaddress"=>"10.59.24.175", "macaddress"=>"40:f2:e9:d6:50:67", "netmask"=>"255.255.255.0", "mtu"=>1500, "network"=>"10.59.24.0", "speed"=>"1000", "duplex"=>"full", "port"=>"Twisted Pair", "auto_negotiation"=>"true", "wol"=>true, "link"=>"true"}
2020-09-23T16:29:33 [D|app|0c37d93d] Discovery fact parser detected primary interface: ["enp6s0", {"ipaddress"=>"10.59.24.175", "macaddress"=>"40:f2:e9:d6:50:67", "netmask"=>"255.255.255.0", "mtu"=>1500, "network"=>"10.59.24.0", "speed"=>"1000", "duplex"=>"full", "port"=>"Twisted Pair", "auto_negotiation"=>"true", "wol"=>true, "link"=>"true", "keep_subnet"=>true, "virtual"=>false}]
2020-09-23T16:29:33 [D|app|0c37d93d] Discovery fact parser detected primary interface: ["enp6s0", {"ipaddress"=>"10.59.24.175", "macaddress"=>"40:f2:e9:d6:50:67", "netmask"=>"255.255.255.0", "mtu"=>1500, "network"=>"10.59.24.0", "speed"=>"1000", "duplex"=>"full", "port"=>"Twisted Pair", "auto_negotiation"=>"true", "wol"=>true, "link"=>"true", "keep_subnet"=>true, "virtual"=>false}]
2020-09-23T16:29:33 [D|app|0c37d93d] Suggested enp6s0 NIC as a primary interface.
2020-09-23T16:29:33 [I|aud|0c37d93d] Nic::Managed (28) update event on mac , 40:f2:e9:d6:50:67
2020-09-23T16:29:33 [I|aud|0c37d93d] Nic::Managed (28) update event on identifier , enp6s0
2020-09-23T16:29:33 [D|app|0c37d93d] Saving enp11s0 NIC for host mac40f2e9d65067
2020-09-23T16:29:33 [D|app|0c37d93d] Saving enp6s0 NIC for host mac40f2e9d65067
2020-09-23T16:29:33 [D|app|0c37d93d] Saving ipmi NIC for host mac40f2e9d65067
2020-09-23T16:29:33 [I|app|0c37d93d] Detected IPv4 subnet: 00712_OpsNet with taxonomy ["MyOrg"]/["MyLoc"]
2020-09-23T16:29:33 [I|app|0c37d93d] Assigned location: MyLoc
2020-09-23T16:29:33 [I|app|0c37d93d] Assigned organization: MyOrg
2020-09-23T16:29:33 [I|aud|0c37d93d] Host::Base (11) update event on model_id , 2
2020-09-23T16:29:33 [I|aud|0c37d93d] Host::Base (11) update event on owner_id , 1
2020-09-23T16:29:33 [I|aud|0c37d93d] Host::Base (11) update event on owner_type , User
2020-09-23T16:29:33 [I|aud|0c37d93d] Host::Base (11) update event on organization_id , 3
2020-09-23T16:29:33 [I|aud|0c37d93d] Host::Base (11) update event on location_id , 4
2020-09-23T16:29:33 [I|aud|0c37d93d] Nic::Managed (28) update event on subnet_id , 3
2020-09-23T16:29:33 [D|not|0c37d93d] Notification event: UINotifications::NewHost - checking for notifications
2020-09-23T16:29:33 [D|not|0c37d93d] Clearing Cache: notification, clearing cache for notification-4
2020-09-23T16:29:33 [D|app|0c37d93d] Finding auto discovery rule for host mac40f2e9d65067 (11)
2020-09-23T16:29:33 [D|app|0c37d93d] Body: {"id":11,"name":"mac40f2e9d65067","last_compile":null,"last_report":"2020-09-23T20:29:32.696Z","updated_at":"2020-09-23T20:29:33.498Z","created_at":"2020-09-23T20:29:32.652Z","root_pass":null,"architecture_id":null,"operatingsystem_id":null,"environment_id":null,"ptable_id":null,"medium_id":null,"build":false,"comment":null,"disk":null,"installed_at":null,"model_id":2,"hostgroup_id":null,"owner_id":1,"owner_type":"User","enabled":true,"puppet_ca_proxy_id":null,"managed":false,"use_image":null,"image_file":null,"uuid":null,"compute_resource_id":null,"puppet_proxy_id":null,"certname":null,"image_id":null,"organization_id":3,"location_id":4,"otp":null,"realm_id":null,"compute_profile_id":null,"provision_method":null,"grub_pass":"","global_status":0,"lookup_value_matcher":null,"pxe_loader":null,"initiated_at":null,"build_errors":null,"discovery_rule_id":null}
2020-09-23T16:29:33 [I|app|0c37d93d] Completed 201 Created in 931ms (Views: 1.1ms | ActiveRecord: 260.2ms | Allocations: 305703)

fresh-pie · September 23, 2020, 10:52pm

Apologies for filling up my own post with replies, but I’ve found something odd…

It seems like its just taking awhile for Foreman to finally find the discovery rule match and begin provisioning.

I had my system boot into the discovery environment and it was discovered. The host sat on the “Success” screen and in Foreman, it sat in the “Discovered Hosts” screen for at least 15 minutes before it finally auto-provisioned.

Here is the logs from when it finally started:

2020-09-23T16:56:26 [I|app|e3984894] Started POST "/api/v2/discovered_hosts/facts" for 127.0.0.1 at 2020-09-23 16:56:26 -0400
2020-09-23T16:56:26 [I|app|e3984894] Processing by Api::V2::DiscoveredHostsController#facts as JSON
2020-09-23T16:56:26 [I|app|e3984894]   Parameters: {"facts"=>"[FILTERED]", "apiv"=>"v2", "discovered_host"=>{"facts"=>"[FILTERED]"}}
2020-09-23T16:56:26 [I|app|e3984894] Import facts for 'mac40f2e9d65067' completed. Added: 0, Updated: 1, Deleted 0 facts
2020-09-23T16:56:26 [D|tax|e3984894] Current location set to MyLoc
2020-09-23T16:56:26 [D|tax|e3984894] Current organization set to MyOrg
2020-09-23T16:56:26 [D|app|e3984894] skipping interface with identifier 'lo' since it was matched by 'ignored_interface_identifiers' setting
2020-09-23T16:56:26 [D|app|e3984894] We have following interfaces 'enp11s0, enp6s0' based on facts
2020-09-23T16:56:26 [D|app|e3984894] Interface enp11s0 facts: {"macaddress"=>"40:f2:e9:d6:50:68", "mtu"=>1500, "duplex"=>"unknown! (255)", "port"=>"Twisted Pair", "auto_negotiation"=>"true", "wol"=>true, "link"=>"false"}
2020-09-23T16:56:26 [D|app|e3984894] Interface enp6s0 facts: {"ipaddress"=>"10.59.24.175", "macaddress"=>"40:f2:e9:d6:50:67", "netmask"=>"255.255.255.0", "mtu"=>1500, "network"=>"10.59.24.0", "speed"=>"1000", "duplex"=>"full", "port"=>"Twisted Pair", "auto_negotiation"=>"true", "wol"=>true, "link"=>"true"}
2020-09-23T16:56:26 [D|app|e3984894] Discovery fact parser detected primary interface: ["enp6s0", {"ipaddress"=>"10.59.24.175", "macaddress"=>"40:f2:e9:d6:50:67", "netmask"=>"255.255.255.0", "mtu"=>1500, "network"=>"10.59.24.0", "speed"=>"1000", "duplex"=>"full", "port"=>"Twisted Pair", "auto_negotiation"=>"true", "wol"=>true, "link"=>"true", "keep_subnet"=>true, "virtual"=>false}]
2020-09-23T16:56:26 [I|app|e3984894] Detected IPv4 subnet: 00712_OpsNet with taxonomy ["MyOrg"]/["MyLoc"]
2020-09-23T16:56:26 [I|app|e3984894] Assigned location: MyLoc
2020-09-23T16:56:26 [I|app|e3984894] Assigned organization: MyOrg
2020-09-23T16:56:26 [D|not|e3984894] Notification event: UINotifications::NewHost - checking for notifications
2020-09-23T16:56:26 [D|app|e3984894] Finding auto discovery rule for host mac40f2e9d65067 (13)
2020-09-23T16:56:26 [D|app|e3984894] Found rule 00712_W10 (1) [0/0]
2020-09-23T16:56:26 [I|app|e3984894] Match found for host mac40f2e9d65067 (13) rule 00712_W10 (1)
2020-09-23T16:56:26 [D|app|e3984894] Auto-provisioning via rule 00712_W10 hostgroup 00712_Servers subnet 00712_OpsNet
2020-09-23T16:56:26 [W|app|e3984894] Could not find a provider for mac40f2e9d65067. Providers returned {"Katello::ManagedContentMediumProvider"=>["Kickstart repository was not set for host 'mac40f2e9d65067'", "Content source was not set for host 'mac40f2e9d65067'"], "MediumProviders::Default"=>["Operating system was not set for host 'mac40f2e9d65067'", " medium was not set for host 'mac40f2e9d65067'", "Invalid medium '' for ''", "Invalid architecture '' for ''"]}
2020-09-23T16:56:26 [D|app|e3984894] Not suggesting IP Address for 00712_OpsNet as IPAM is disabled
2020-09-23T16:56:26 [D|tax|e3984894] Current organization set to MyOrg
2020-09-23T16:56:26 [D|tax|e3984894] Current location set to MyLoc
2020-09-23T16:56:26 [D|tax|e3984894] Current location set to MyLoc
2020-09-23T16:56:26 [D|tax|e3984894] Current organization set to MyOrg
2020-09-23T16:56:26 [D|app|e3984894] Enqueued task 'Deploy TFTP PXELinux config for ods00712w10.example.net' to 'Host::Managed Main' queue
2020-09-23T16:56:26 [D|app|e3984894] Enqueued task 'Deploy TFTP PXEGrub2 config for ods00712w10.example.net' to 'Host::Managed Main' queue
2020-09-23T16:56:26 [D|app|e3984894] Enqueued task 'Deploy TFTP PXEGrub config for ods00712w10.example.net' to 'Host::Managed Main' queue
2020-09-23T16:56:26 [D|app|e3984894] Enqueued task 'Deploy TFTP iPXE config for ods00712w10.example.net' to 'Host::Managed Main' queue
2020-09-23T16:56:26 [D|app|e3984894] Enqueued task 'Fetch TFTP boot files for ods00712w10.example.net' to 'Host::Managed Main' queue
2020-09-23T16:56:26 [D|app|e3984894] Processing task 'Deploy TFTP PXELinux config for ods00712w10.example.net' from 'Host::Managed Main'
2020-09-23T16:56:26 [D|tax|e3984894] Current organization set to MyOrg
2020-09-23T16:56:26 [D|tax|e3984894] Current location set to MyLoc
2020-09-23T16:56:26 [D|tax|e3984894] Current location set to MyLoc
2020-09-23T16:56:26 [D|tax|e3984894] Current organization set to MyOrg
2020-09-23T16:56:26 [I|app|e3984894] Deploying TFTP PXELinux configuration for ods00712w10.example.net
2020-09-23T16:56:26 [D|app|e3984894] Processing task 'Deploy TFTP PXEGrub2 config for ods00712w10.example.net' from 'Host::Managed Main'
2020-09-23T16:56:26 [D|tax|e3984894] Current organization set to MyOrg
2020-09-23T16:56:26 [D|tax|e3984894] Current location set to MyLoc
2020-09-23T16:56:26 [D|tax|e3984894] Current location set to MyLoc
2020-09-23T16:56:26 [D|tax|e3984894] Current organization set to MyOrg
2020-09-23T16:56:27 [I|app|e3984894] Deploying TFTP PXEGrub2 configuration for ods00712w10.example.net
2020-09-23T16:56:27 [D|app|e3984894] Processing task 'Deploy TFTP PXEGrub config for ods00712w10.example.net' from 'Host::Managed Main'
2020-09-23T16:56:27 [D|tax|e3984894] Current organization set to MyOrg
2020-09-23T16:56:27 [D|tax|e3984894] Current location set to MyLoc
2020-09-23T16:56:27 [D|tax|e3984894] Current location set to MyLoc
2020-09-23T16:56:27 [D|tax|e3984894] Current organization set to MyOrg
2020-09-23T16:56:27 [I|app|e3984894] Deploying TFTP PXEGrub configuration for ods00712w10.example.net
2020-09-23T16:56:27 [D|app|e3984894] Processing task 'Deploy TFTP iPXE config for ods00712w10.example.net' from 'Host::Managed Main'
2020-09-23T16:56:27 [D|tax|e3984894] Current organization set to MyOrg
2020-09-23T16:56:27 [D|tax|e3984894] Current location set to MyLoc
2020-09-23T16:56:27 [D|tax|e3984894] Current location set to MyLoc
2020-09-23T16:56:27 [D|tax|e3984894] Current organization set to MyOrg
2020-09-23T16:56:27 [I|app|e3984894] Deploying TFTP iPXE configuration for ods00712w10.example.net
2020-09-23T16:56:27 [D|app|e3984894] Processing task 'Fetch TFTP boot files for ods00712w10.example.net' from 'Host::Managed Main'
2020-09-23T16:56:27 [I|app|e3984894] Fetching required TFTP boot files for ods00712w10.example.net
2020-09-23T16:56:27 [I|app|e3984894] Processed 5 tasks from queue 'Host::Managed Main', completed 5/5
2020-09-23T16:56:27 [D|app|e3984894] Task 'Deploy TFTP PXELinux config for ods00712w10.example.net' *completed*
2020-09-23T16:56:27 [D|app|e3984894] Task 'Deploy TFTP PXEGrub2 config for ods00712w10.example.net' *completed*
2020-09-23T16:56:27 [D|app|e3984894] Task 'Deploy TFTP PXEGrub config for ods00712w10.example.net' *completed*
2020-09-23T16:56:27 [D|app|e3984894] Task 'Deploy TFTP iPXE config for ods00712w10.example.net' *completed*
2020-09-23T16:56:27 [D|app|e3984894] Task 'Fetch TFTP boot files for ods00712w10.example.net' *completed*
2020-09-23T16:56:27 [I|aud|e3984894] Nic::Managed (34) update event on name mac40f2e9d65067, ods00712w10.example.net
2020-09-23T16:56:27 [I|aud|e3984894] Nic::Managed (34) update event on domain_id , 1
2020-09-23T16:56:27 [D|app|e3984894] Enqueued task 'Disable PuppetCA autosigning for ods00712w10.example.net' to 'Host::Managed Post' queue
2020-09-23T16:56:27 [D|app|e3984894] Enqueued task 'Cleanup PuppetCA certificates for ods00712w10.example.net' to 'Host::Managed Post' queue
2020-09-23T16:56:27 [D|app|e3984894] Enqueued task 'Enable PuppetCA autosigning for ods00712w10.example.net' to 'Host::Managed Post' queue
2020-09-23T16:56:27 [D|tax|e3984894] Current organization set to MyOrg
2020-09-23T16:56:27 [D|tax|e3984894] Current location set to MyLoc
2020-09-23T16:56:27 [D|tax|e3984894] Current location set to MyLoc
2020-09-23T16:56:27 [D|tax|e3984894] Current organization set to MyOrg
2020-09-23T16:56:27 [D|app|e3984894] Task 'Deploy TFTP PXELinux config for ods00712w10.example.net' already in 'Host::Managed Main' queue
2020-09-23T16:56:27 [D|app|e3984894] Task 'Deploy TFTP PXEGrub2 config for ods00712w10.example.net' already in 'Host::Managed Main' queue
2020-09-23T16:56:27 [D|app|e3984894] Task 'Deploy TFTP PXEGrub config for ods00712w10.example.net' already in 'Host::Managed Main' queue
2020-09-23T16:56:27 [D|app|e3984894] Task 'Deploy TFTP iPXE config for ods00712w10.example.net' already in 'Host::Managed Main' queue
2020-09-23T16:56:27 [D|app|e3984894] Task 'Fetch TFTP boot files for ods00712w10.example.net' already in 'Host::Managed Main' queue
2020-09-23T16:56:27 [D|app|e3984894] Enqueued task 'Rebooting ods00712w10.example.net' to 'Host::Managed Post' queue
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (13) update event on build false, true
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (13) update event on name mac40f2e9d65067, ods00712w10.example.net
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (13) update event on root_pass , $5$GC6Yq6Mo9DlOBgLL$OTB075auHNkA1zvfc4IsBOndhbjQ059eLQBbq3u7SV5
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (13) update event on architecture_id , 1
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (13) update event on operatingsystem_id , 3
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (13) update event on environment_id , 2
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (13) update event on ptable_id , 116
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (13) update event on comment , Auto-discovered and provisioned via rule '00712_W10'
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (13) update event on hostgroup_id , 2
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (13) update event on puppet_ca_proxy_id , 1
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (13) update event on managed false, true
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (13) update event on puppet_proxy_id , 1
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (13) update event on grub_pass , $5$GC6Yq6Mo9DlOBgLL$OTB075auHNkA1zvfc4IsBOndhbjQ059eLQBbq3u7SV5
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (13) update event on discovery_rule_id , 1
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (10) create event on host_id 13
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (10) create event on uuid
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (10) create event on content_view_id 17
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (10) create event on lifecycle_environment_id 3
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (10) create event on kickstart_repository_id 182
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (10) create event on content_source_id 1
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (10) create event on installable_security_errata_count 0
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (10) create event on installable_enhancement_errata_count 0
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (10) create event on installable_bugfix_errata_count 0
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (10) create event on applicable_rpm_count 0
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (10) create event on upgradable_rpm_count 0
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (10) create event on applicable_module_stream_count 0
2020-09-23T16:56:27 [I|aud|e3984894] Host::Base (10) create event on upgradable_module_stream_count 0
2020-09-23T16:56:27 [D|not|e3984894] Notification event: UINotifications::DestroyHost - checking for notifications
2020-09-23T16:56:27 [D|app|e3984894] Processing task 'Disable PuppetCA autosigning for ods00712w10.example.net' from 'Host::Managed Post'
2020-09-23T16:56:27 [I|app|e3984894] Delete the autosign entry for ods00712w10.example.net
2020-09-23T16:56:27 [D|app|e3984894] Processing task 'Cleanup PuppetCA certificates for ods00712w10.example.net' from 'Host::Managed Post'
2020-09-23T16:56:27 [I|app|e3984894] Remove puppet certificate for ods00712w10.example.net
2020-09-23T16:56:28 [D|app|e3984894] Processing task 'Enable PuppetCA autosigning for ods00712w10.example.net' from 'Host::Managed Post'
2020-09-23T16:56:28 [I|app|e3984894] Adding autosign entry for ods00712w10.example.net
2020-09-23T16:56:28 [D|app|e3984894] Processing task 'Rebooting ods00712w10.example.net' from 'Host::Managed Post'
2020-09-23T16:56:28 [D|app|e3984894] Performing reboot call against https://hqret-foreman.example.net:9090/discovery/10.59.24.175
2020-09-23T16:56:28 [D|app|e3984894] Connecting to proxy, setting up SSL client cert
2020-09-23T16:56:28 [D|app|e3984894] Image API PUT https://hqret-foreman.example.net:9090/discovery/10.59.24.175/power (path=/reboot, payload={})
2020-09-23T16:56:28 [I|app|e3984894] Processed 4 tasks from queue 'Host::Managed Post', completed 4/4
2020-09-23T16:56:28 [D|app|e3984894] Task 'Disable PuppetCA autosigning for ods00712w10.example.net' *completed*
2020-09-23T16:56:28 [D|app|e3984894] Task 'Cleanup PuppetCA certificates for ods00712w10.example.net' *completed*
2020-09-23T16:56:28 [D|app|e3984894] Task 'Enable PuppetCA autosigning for ods00712w10.example.net' *completed*
2020-09-23T16:56:28 [D|app|e3984894] Task 'Rebooting ods00712w10.example.net' *completed*
2020-09-23T16:56:28 [D|app|e3984894] custom hook after_build on ods00712w10.example.net will be executed if defined.
2020-09-23T16:56:28 [D|not|e3984894] Clearing Cache: notification, clearing cache for notification-1
2020-09-23T16:56:28 [D|not|e3984894] Clearing Cache: notification, clearing cache for notification-2
2020-09-23T16:56:28 [D|not|e3984894] Clearing Cache: notification, clearing cache for notification-3
2020-09-23T16:56:28 [D|not|e3984894] Clearing Cache: notification, clearing cache for notification-4
2020-09-23T16:56:28 [D|app|e3984894] Body: {"last_report":null,"build":true,"id":13,"name":"ods00712w10.example.net","last_compile":null,"updated_at":"2020-09-23T20:56:27.681Z","created_at":"2020-09-23T20:43:55.381Z","root_pass":"$5$GC6Yq6Mo9DlOBgLL$OTB075auHNkA1zvfc4IsBOndhbjQ059eLQBbq3u7SV5","architecture_id":1,"operatingsystem_id":3,"environment_id":2,"ptable_id":116,"medium_id":null,"comment":"Auto-discovered and provisioned via rule '00712_W10'","disk":null,"installed_at":null,"model_id":2,"hostgroup_id":2,"owner_id":1,"owner_type":"User","enabled":true,"puppet_ca_proxy_id":1,"managed":true,"use_image":null,"image_file":null,"uuid":null,"compute_resource_id":null,"puppet_proxy_id":1,"certname":null,"image_id":null,"organization_id":3,"location_id":4,"otp":null,"realm_id":null,"compute_profile_id":null,"provision_method":null,"grub_pass":"$5$GC6Yq6Mo9DlOBgLL$OTB075auHNkA1zvfc4IsBOndhbjQ059eLQBbq3u7SV5","global_status":0,"lookup_value_matcher":"fqdn=ods00712w10.example.net","pxe_loader":null,"initiated_at":null,"build_errors":null,"discovery_rule_id":1}
2020-09-23T16:56:28 [I|app|e3984894] Completed 201 Created in 2219ms (Views: 1.1ms | ActiveRecord: 157.0ms | Allocations: 748030)

I’m going to walk through the whole process, grabbing the logs as I go so that I can paint a complete picture of what is going on.

lzap · September 24, 2020, 7:04am

Discovery sends facts every 15 minutes. The first send added 192 facts:

The rule was not success match. But the second upload it looks like one fact was updated:

That indicates that something was initialized slowly. I think you have some race condition, likely DHCP or NetworkManager is not setting up network fast enough. I’d be curious if you could do this (turn off auto provisioning setting):

foreman-rake console
> Host::Discovered.unscoped.find_by_name("mac40f2e9d65067").facts.to_json

Run that command quickly after host is discovered and then after resend and compare the output in some JSON diff.

Anyway, to prevent this misbehavior you can change your search condition to simply ip = 1.2.3.4. Some hardware info is stored in separate database columns, these are: ip address, cpu, memory and disk size. You can use these in rules too. It looks like the IP address is detected correctly, I think it’s just a bug or race condition in facter in regard to default route which causes ipaddress fact to be set incorrectly.

fresh-pie · September 24, 2020, 5:07pm

Hey lzap,

Thank you for the continued assistance!

So I walked through what you advised:

Turned off the auto-provision setting.
Made sure the host was completely deleted from Foreman.
Began the discovery process on the host.
Ran the formake-rake console and executed the requested command as soon as the host was discovered. See the JSON output below:

{
  "lib": "/usr/share/fdi/facts:/opt/extension/facts",
  "virtual": "physical",
  "is_virtual": "false",
  "id": "root",
  "netmask": "255.255.255.0",
  "selinux": "false",
  "interfaces": "enp11s0,enp6s0,lo",
  "macaddress_enp11s0": "40:f2:e9:d6:50:68",
  "mtu_enp11s0": "1500",
  "ipaddress_enp6s0": "10.59.24.175",
  "macaddress_enp6s0": "40:f2:e9:d6:50:67",
  "netmask_enp6s0": "255.255.255.0",
  "mtu_enp6s0": "1500",
  "boardmanufacturer": "IBM",
  "boardproductname": "81Y7071",
  "boardserialnumber": "4B908Y",
  "bios_vendor": "IBM Corp.",
  "bios_version": "-[JQE168BUS-1.09]-",
  "bios_release_date": "09/17/2014",
  "manufacturer": "IBM",
  "productname": "IBM System x3100 M4 -[2582AC1]-",
  "serialnumber": "E2N7985",
  "uuid": "1a0c4069-68f2-35e8-af29-b5a8e33f746a",
  "type": "Tower",
  "physicalprocessorcount": "1",
  "architecture": "x86_64",
  "hardwaremodel": "x86_64",
  "os::name": "CentOS",
  "os::family": "RedHat",
  "os::release::major": "7",
  "os::release::minor": "7",
  "os::release::full": "7.7.1908",
  "macaddress": "40:f2:e9:d6:50:68",
  "ipaddress": "10.59.24.175",
  "hostname": "fdi",
  "uniqueid": "3b0aaf18",
  "gid": "root",
  "processors::models": "[\"Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz\", \"Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz\", \"Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz\", \"Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz\"]",
  "processors::count": "4",
  "processors::physicalcount": "1",
  "processor0": "Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz",
  "processor1": "Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz",
  "processor2": "Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz",
  "processor3": "Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz",
  "processorcount": "4",
  "memorysize": "7.75 GB",
  "memorysize_mb": "7938.83",
  "dhcp_servers::system": "10.254.52.34",
  "dhcp_servers::enp6s0": "10.254.52.34",
  "fqdn": "fdi.example.com",
  "hardwareisa": "x86_64",
  "ps": "ps -ef",
  "partitions::sda1::uuid": "daafe133-7c32-48fe-92b5-40f06bac711d",
  "partitions::sda1::size": "2097152",
  "partitions::sda1::filesystem": "ext4",
  "partitions::sda2::size": "581883904",
  "partitions::sda2::filesystem": "LVM2_member",
  "blockdevice_sda_size": "298999349248",
  "blockdevice_sda_vendor": "IBM",
  "blockdevice_sda_model": "ServeRAID M1015",
  "blockdevice_sr0_size": "1073741312",
  "blockdevice_sr0_vendor": "IBM SATA",
  "blockdevice_sr0_model": "DEVICE 81Y3675",
  "blockdevices": "sda,sr0",
  "network_enp6s0": "10.59.24.0",
  "domain": "example.com",
  "facterversion": "2.4.1",
  "discovery_version": "3.5.7",
  "discovery_release": "20191021.1",
  "discovery_bootif": "40:f2:e9:d6:50:67",
  "discovery_bootip": "10.59.24.175",
  "duplex_enp11s0": "unknown! (255)",
  "port_enp11s0": "Twisted Pair",
  "auto_negotiation_enp11s0": "true",
  "wol_enp11s0": "true",
  "link_enp11s0": "false",
  "speed_enp6s0": "1000",
  "duplex_enp6s0": "full",
  "port_enp6s0": "Twisted Pair",
  "auto_negotiation_enp6s0": "true",
  "wol_enp6s0": "true",
  "link_enp6s0": "true",
  "ipmi_enabled": "true",
  "ipmi_ipaddress_source": "Other",
  "ipmi_ipaddress": "10.59.24.215",
  "ipmi_subnet_mask": "255.255.255.0",
  "ipmi_macaddress": "40:f2:e9:d6:50:6b",
  "ipmi_gateway": "10.59.24.1",
  "ipmi_1_ipaddress_source": "Other",
  "ipmi_1_ipaddress": "10.59.24.215",
  "ipmi_1_subnet_mask": "255.255.255.0",
  "ipmi_1_macaddress": "40:f2:e9:d6:50:6b",
  "ipmi_1_gateway": "10.59.24.1",
  "nmprimary_connection_id": "primary",
  "nmprimary_connection_uuid": "53e71b0e-fe83-11ea-bcc8-40f2e9d65067",
  "nmprimary_connection_type": "802-3-ethernet",
  "nmprimary_connection_autoconnect": "yes",
  "nmprimary_connection_autoconnect-priority": "1",
  "nmprimary_connection_autoconnect-retries": "-1",
  "nmprimary_connection_multi-connect": "0",
  "nmprimary_connection_auth-retries": "-1",
  "nmprimary_connection_read-only": "no",
  "nmprimary_connection_autoconnect-slaves": "-1",
  "nmprimary_connection_metered": "unknown",
  "nmprimary_connection_lldp": "default",
  "nmprimary_connection_mdns": "-1",
  "nmprimary_connection_llmnr": "-1",
  "nmprimary_802-3-ethernet_speed": "0",
  "nmprimary_802-3-ethernet_auto-negotiate": "no",
  "nmprimary_802-3-ethernet_mac-address": "40:F2:E9:D6:50:67",
  "nmprimary_802-3-ethernet_mtu": "auto",
  "nmprimary_802-3-ethernet_wake-on-lan": "default",
  "nmprimary_ipv4_method": "auto",
  "nmprimary_ipv4_dns-options": "",
  "nmprimary_ipv4_dns-priority": "0",
  "nmprimary_ipv4_route-metric": "-1",
  "nmprimary_ipv4_route-table": "0",
  "nmprimary_ipv4_ignore-auto-routes": "no",
  "nmprimary_ipv4_ignore-auto-dns": "no",
  "nmprimary_ipv4_dhcp-send-hostname": "no",
  "nmprimary_ipv4_never-default": "no",
  "nmprimary_ipv4_may-fail": "yes",
  "nmprimary_ipv6_method": "ignore",
  "nmprimary_ipv6_dns-options": "",
  "nmprimary_ipv6_dns-priority": "0",
  "nmprimary_ipv6_route-metric": "-1",
  "nmprimary_ipv6_route-table": "0",
  "nmprimary_ipv6_ignore-auto-routes": "no",
  "nmprimary_ipv6_ignore-auto-dns": "no",
  "nmprimary_ipv6_never-default": "no",
  "nmprimary_ipv6_may-fail": "yes",
  "nmprimary_ipv6_ip6-privacy": "-1",
  "nmprimary_ipv6_addr-gen-mode": "eui64",
  "nmprimary_ipv6_dhcp-send-hostname": "yes",
  "nmprimary_vlan_id": "0",
  "nmprimary_vlan_flags": "1",
  "nmprimary_proxy_method": "none",
  "nmprimary_proxy_browser-only": "no",
  "nmprimary_general_name": "primary",
  "nmprimary_general_uuid": "53e71b0e-fe83-11ea-bcc8-40f2e9d65067",
  "nmprimary_general_devices": "enp6s0",
  "nmprimary_general_state": "activated",
  "nmprimary_general_default": "yes",
  "nmprimary_general_default6": "no",
  "nmprimary_general_vpn": "no",
  "nmprimary_ip4_address": "10.59.24.175/24",
  "nmprimary_ip4_gateway": "10.59.24.1",
  "nmprimary_ip4_route": "dst = 0.0.0.0/0, nh = 10.59.24.1, mt = 100",
  "nmprimary_ip4_dns": "10.92.128.40",
  "nmprimary_ip4_domain": "example.com",
  "nmprimary_dhcp4_option_broadcast_address": "10.59.24.255",
  "nmprimary_dhcp4_option_dhcp_message_type": "5",
  "nmprimary_dhcp4_option_dhcp_server_identifier": "10.254.52.34",
  "nmprimary_dhcp4_option_domain_name": "example.com",
  "nmprimary_dhcp4_option_domain_name_servers": "10.92.128.40 10.92.128.41 10.20.17.25 10.20.17.26 10.95.65.34 10.95.131.30",
  "nmprimary_dhcp4_option_expiry": "1600965364",
  "nmprimary_dhcp4_option_filename": "/pxelinux.0",
  "nmprimary_dhcp4_option_ip_address": "10.59.24.175",
  "nmprimary_dhcp4_option_network_number": "10.59.24.0",
  "nmprimary_dhcp4_option_next_server": "10.11.184.93",
  "nmprimary_dhcp4_option_ntp_servers": "10.92.128.40",
  "nmprimary_dhcp4_option_requested_broadcast_address": "1",
  "nmprimary_dhcp4_option_requested_classless_static_routes": "1",
  "nmprimary_dhcp4_option_requested_domain_name": "1",
  "nmprimary_dhcp4_option_requested_domain_name_servers": "1",
  "nmprimary_dhcp4_option_requested_domain_search": "1",
  "nmprimary_dhcp4_option_requested_host_name": "1",
  "nmprimary_dhcp4_option_requested_interface_mtu": "1",
  "nmprimary_dhcp4_option_requested_ms_classless_static_routes": "1",
  "nmprimary_dhcp4_option_requested_nis_domain": "1",
  "nmprimary_dhcp4_option_requested_nis_servers": "1",
  "nmprimary_dhcp4_option_requested_ntp_servers": "1",
  "nmprimary_dhcp4_option_requested_rfc3442_classless_static_routes": "1",
  "nmprimary_dhcp4_option_requested_routers": "1",
  "nmprimary_dhcp4_option_requested_static_routes": "1",
  "nmprimary_dhcp4_option_requested_subnet_mask": "1",
  "nmprimary_dhcp4_option_requested_wpad": "1",
  "nmprimary_dhcp4_option_routers": "10.59.24.1",
  "nmprimary_dhcp4_option_subnet_mask": "255.255.255.0",
  "nmprimary_dhcp4_option_wpad": "a:0",
  "nmprimary_ip6_address": "fe80::42f2:e9ff:fed6:5067/64",
  "nmprimary_ip6_route": "dst = ff00::/8, nh = ::, mt = 256, table=255",
  "nmprimary_ptr": "ods00712w10.example.com",
  "discovery_proxy_uri": "https://hqret-foreman.example.com",
  "discovery_proxy_type": "foreman",
  "os": null,
  "os::release": null,
  "processors": null,
  "dhcp_servers": null,
  "partitions::sda1": null,
  "partitions": null,
  "partitions::sda2": null
}

I also pulled the production log of this event, shown below:

2020-09-24T12:31:55 [I|app|6ea75b35] Started POST "/api/v2/discovered_hosts/facts" for 127.0.0.1 at 2020-09-24 12:31:55 -0400
2020-09-24T12:31:55 [I|app|6ea75b35] Processing by Api::V2::DiscoveredHostsController#facts as JSON
2020-09-24T12:31:55 [I|app|6ea75b35]   Parameters: {"facts"=>"[FILTERED]", "apiv"=>"v2", "discovered_host"=>{"facts"=>"[FILTERED]"}}
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on mac
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on ip
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on type Nic::Managed
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on name mac40f2e9d65067
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on host_id 22
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on subnet_id
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on domain_id
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on attrs {}
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on provider
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on username
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on password [redacted]
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on virtual false
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on link true
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on identifier
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on tag
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on attached_to
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on managed true
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on mode balance-rr
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on attached_devices
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on bond_options
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on primary true
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on provision true
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on compute_attributes {}
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on ip6
2020-09-24T12:31:55 [I|aud|6ea75b35] Nic::Managed (61) create event on subnet6_id
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on name mac40f2e9d65067
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on last_compile
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on root_pass
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on architecture_id
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on operatingsystem_id
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on environment_id
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on ptable_id
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on medium_id
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on build false
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on comment
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on disk
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on installed_at
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on model_id
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on hostgroup_id
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on owner_id
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on owner_type
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on enabled true
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on puppet_ca_proxy_id
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on managed false
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on use_image
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on image_file
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on uuid
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on compute_resource_id
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on puppet_proxy_id
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on certname
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on image_id
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on organization_id
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on location_id
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on otp
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on realm_id
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on compute_profile_id
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on provision_method
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on grub_pass
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on global_status 0
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on lookup_value_matcher
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on pxe_loader
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on initiated_at
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on build_errors
2020-09-24T12:31:55 [I|aud|6ea75b35] Host::Base (22) create event on discovery_rule_id
2020-09-24T12:31:56 [I|app|6ea75b35] Import facts for 'mac40f2e9d65067' completed. Added: 192, Updated: 0, Deleted 0 facts
2020-09-24T12:31:56 [D|tax|6ea75b35] Current location set to Default Location
2020-09-24T12:31:56 [D|tax|6ea75b35] Current organization set to Default Organization
2020-09-24T12:31:56 [D|app|6ea75b35] skipping interface with identifier 'lo' since it was matched by 'ignored_interface_identifiers' setting
2020-09-24T12:31:56 [D|app|6ea75b35] We have following interfaces 'enp11s0, enp6s0' based on facts
2020-09-24T12:31:56 [D|app|6ea75b35] Interface enp11s0 facts: {"macaddress"=>"40:f2:e9:d6:50:68", "mtu"=>1500, "duplex"=>"unknown! (255)", "port"=>"Twisted Pair", "auto_negotiation"=>"true", "wol"=>true, "link"=>"false"}
2020-09-24T12:31:56 [D|app|6ea75b35] Interface enp6s0 facts: {"ipaddress"=>"10.59.24.175", "macaddress"=>"40:f2:e9:d6:50:67", "netmask"=>"255.255.255.0", "mtu"=>1500, "network"=>"10.59.24.0", "speed"=>"1000", "duplex"=>"full", "port"=>"Twisted Pair", "auto_negotiation"=>"true", "wol"=>true, "link"=>"true"}
2020-09-24T12:31:56 [D|app|6ea75b35] Discovery fact parser detected primary interface: ["enp6s0", {"ipaddress"=>"10.59.24.175", "macaddress"=>"40:f2:e9:d6:50:67", "netmask"=>"255.255.255.0", "mtu"=>1500, "network"=>"10.59.24.0", "speed"=>"1000", "duplex"=>"full", "port"=>"Twisted Pair", "auto_negotiation"=>"true", "wol"=>true, "link"=>"true", "keep_subnet"=>true, "virtual"=>false}]
2020-09-24T12:31:56 [D|app|6ea75b35] Discovery fact parser detected primary interface: ["enp6s0", {"ipaddress"=>"10.59.24.175", "macaddress"=>"40:f2:e9:d6:50:67", "netmask"=>"255.255.255.0", "mtu"=>1500, "network"=>"10.59.24.0", "speed"=>"1000", "duplex"=>"full", "port"=>"Twisted Pair", "auto_negotiation"=>"true", "wol"=>true, "link"=>"true", "keep_subnet"=>true, "virtual"=>false}]
2020-09-24T12:31:56 [D|app|6ea75b35] Suggested enp6s0 NIC as a primary interface.
2020-09-24T12:31:56 [I|aud|6ea75b35] Nic::Managed (61) update event on mac , 40:f2:e9:d6:50:67
2020-09-24T12:31:56 [I|aud|6ea75b35] Nic::Managed (61) update event on identifier , enp6s0
2020-09-24T12:31:56 [D|app|6ea75b35] Saving enp11s0 NIC for host mac40f2e9d65067
2020-09-24T12:31:56 [D|app|6ea75b35] Saving enp6s0 NIC for host mac40f2e9d65067
2020-09-24T12:31:56 [D|app|6ea75b35] Saving ipmi NIC for host mac40f2e9d65067
2020-09-24T12:31:56 [I|app|6ea75b35] Detected IPv4 subnet: 00712_OpsNet with taxonomy ["MyOrg"]/["MyLoc"]
2020-09-24T12:31:56 [I|app|6ea75b35] Assigned location: MyLoc
2020-09-24T12:31:56 [I|app|6ea75b35] Assigned organization: MyOrg
2020-09-24T12:31:56 [I|aud|6ea75b35] Host::Base (22) update event on model_id , 2
2020-09-24T12:31:56 [I|aud|6ea75b35] Host::Base (22) update event on owner_id , 1
2020-09-24T12:31:56 [I|aud|6ea75b35] Host::Base (22) update event on owner_type , User
2020-09-24T12:31:56 [I|aud|6ea75b35] Host::Base (22) update event on organization_id , 3
2020-09-24T12:31:56 [I|aud|6ea75b35] Host::Base (22) update event on location_id , 4
2020-09-24T12:31:56 [I|aud|6ea75b35] Nic::Managed (61) update event on subnet_id , 3
2020-09-24T12:31:56 [D|not|6ea75b35] Notification event: UINotifications::NewHost - checking for notifications
2020-09-24T12:31:56 [D|not|6ea75b35] Clearing Cache: notification, clearing cache for notification-4
2020-09-24T12:31:56 [D|app|6ea75b35] Body: {"id":22,"name":"mac40f2e9d65067","last_compile":null,"last_report":"2020-09-24T16:31:55.938Z","updated_at":"2020-09-24T16:31:56.686Z","created_at":"2020-09-24T16:31:55.899Z","root_pass":null,"architecture_id":null,"operatingsystem_id":null,"environment_id":null,"ptable_id":null,"medium_id":null,"build":false,"comment":null,"disk":null,"installed_at":null,"model_id":2,"hostgroup_id":null,"owner_id":1,"owner_type":"User","enabled":true,"puppet_ca_proxy_id":null,"managed":false,"use_image":null,"image_file":null,"uuid":null,"compute_resource_id":null,"puppet_proxy_id":null,"certname":null,"image_id":null,"organization_id":3,"location_id":4,"otp":null,"realm_id":null,"compute_profile_id":null,"provision_method":null,"grub_pass":"","global_status":0,"lookup_value_matcher":null,"pxe_loader":null,"initiated_at":null,"build_errors":null,"discovery_rule_id":null}
2020-09-24T12:31:56 [I|app|6ea75b35] Completed 201 Created in 875ms (Views: 1.1ms | ActiveRecord: 254.9ms | Allocations: 300565)

I then selected Resend and executed the foreman-rake console command again. See the JSON output below:

{
  "lib": "/usr/share/fdi/facts:/opt/extension/facts",
  "virtual": "physical",
  "is_virtual": "false",
  "id": "root",
  "netmask": "255.255.255.0",
  "selinux": "false",
  "interfaces": "enp11s0,enp6s0,lo",
  "macaddress_enp11s0": "40:f2:e9:d6:50:68",
  "mtu_enp11s0": "1500",
  "ipaddress_enp6s0": "10.59.24.175",
  "macaddress_enp6s0": "40:f2:e9:d6:50:67",
  "netmask_enp6s0": "255.255.255.0",
  "mtu_enp6s0": "1500",
  "boardmanufacturer": "IBM",
  "boardproductname": "81Y7071",
  "boardserialnumber": "4B908Y",
  "bios_vendor": "IBM Corp.",
  "bios_version": "-[JQE168BUS-1.09]-",
  "bios_release_date": "09/17/2014",
  "manufacturer": "IBM",
  "productname": "IBM System x3100 M4 -[2582AC1]-",
  "serialnumber": "E2N7985",
  "uuid": "1a0c4069-68f2-35e8-af29-b5a8e33f746a",
  "type": "Tower",
  "physicalprocessorcount": "1",
  "architecture": "x86_64",
  "hardwaremodel": "x86_64",
  "os::name": "CentOS",
  "os::family": "RedHat",
  "os::release::major": "7",
  "os::release::minor": "7",
  "os::release::full": "7.7.1908",
  "macaddress": "40:f2:e9:d6:50:68",
  "ipaddress": "10.59.24.175",
  "hostname": "fdi",
  "uniqueid": "3b0aaf18",
  "gid": "root",
  "processors::models": "[\"Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz\", \"Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz\", \"Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz\", \"Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz\"]",
  "processors::count": "4",
  "processors::physicalcount": "1",
  "processor0": "Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz",
  "processor1": "Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz",
  "processor2": "Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz",
  "processor3": "Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz",
  "processorcount": "4",
  "memorysize": "7.75 GB",
  "memorysize_mb": "7938.83",
  "dhcp_servers::system": "10.254.52.34",
  "dhcp_servers::enp6s0": "10.254.52.34",
  "fqdn": "fdi.example.com",
  "hardwareisa": "x86_64",
  "ps": "ps -ef",
  "partitions::sda1::uuid": "daafe133-7c32-48fe-92b5-40f06bac711d",
  "partitions::sda1::size": "2097152",
  "partitions::sda1::filesystem": "ext4",
  "partitions::sda2::size": "581883904",
  "partitions::sda2::filesystem": "LVM2_member",
  "blockdevice_sda_size": "298999349248",
  "blockdevice_sda_vendor": "IBM",
  "blockdevice_sda_model": "ServeRAID M1015",
  "blockdevice_sr0_size": "1073741312",
  "blockdevice_sr0_vendor": "IBM SATA",
  "blockdevice_sr0_model": "DEVICE 81Y3675",
  "blockdevices": "sda,sr0",
  "network_enp6s0": "10.59.24.0",
  "domain": "example.com",
  "facterversion": "2.4.1",
  "discovery_version": "3.5.7",
  "discovery_release": "20191021.1",
  "discovery_bootif": "40:f2:e9:d6:50:67",
  "discovery_bootip": "10.59.24.175",
  "duplex_enp11s0": "unknown! (255)",
  "port_enp11s0": "Twisted Pair",
  "auto_negotiation_enp11s0": "true",
  "wol_enp11s0": "true",
  "link_enp11s0": "false",
  "speed_enp6s0": "1000",
  "duplex_enp6s0": "full",
  "port_enp6s0": "Twisted Pair",
  "auto_negotiation_enp6s0": "true",
  "wol_enp6s0": "true",
  "link_enp6s0": "true",
  "ipmi_enabled": "true",
  "ipmi_ipaddress_source": "Other",
  "ipmi_ipaddress": "10.59.24.215",
  "ipmi_subnet_mask": "255.255.255.0",
  "ipmi_macaddress": "40:f2:e9:d6:50:6b",
  "ipmi_gateway": "10.59.24.1",
  "ipmi_1_ipaddress_source": "Other",
  "ipmi_1_ipaddress": "10.59.24.215",
  "ipmi_1_subnet_mask": "255.255.255.0",
  "ipmi_1_macaddress": "40:f2:e9:d6:50:6b",
  "ipmi_1_gateway": "10.59.24.1",
  "nmprimary_connection_id": "primary",
  "nmprimary_connection_uuid": "53e71b0e-fe83-11ea-bcc8-40f2e9d65067",
  "nmprimary_connection_type": "802-3-ethernet",
  "nmprimary_connection_autoconnect": "yes",
  "nmprimary_connection_autoconnect-priority": "1",
  "nmprimary_connection_autoconnect-retries": "-1",
  "nmprimary_connection_multi-connect": "0",
  "nmprimary_connection_auth-retries": "-1",
  "nmprimary_connection_read-only": "no",
  "nmprimary_connection_autoconnect-slaves": "-1",
  "nmprimary_connection_metered": "unknown",
  "nmprimary_connection_lldp": "default",
  "nmprimary_connection_mdns": "-1",
  "nmprimary_connection_llmnr": "-1",
  "nmprimary_802-3-ethernet_speed": "0",
  "nmprimary_802-3-ethernet_auto-negotiate": "no",
  "nmprimary_802-3-ethernet_mac-address": "40:F2:E9:D6:50:67",
  "nmprimary_802-3-ethernet_mtu": "auto",
  "nmprimary_802-3-ethernet_wake-on-lan": "default",
  "nmprimary_ipv4_method": "auto",
  "nmprimary_ipv4_dns-priority": "0",
  "nmprimary_ipv4_route-metric": "-1",
  "nmprimary_ipv4_route-table": "0",
  "nmprimary_ipv4_ignore-auto-routes": "no",
  "nmprimary_ipv4_ignore-auto-dns": "no",
  "nmprimary_ipv4_dhcp-send-hostname": "no",
  "nmprimary_ipv4_never-default": "no",
  "nmprimary_ipv4_may-fail": "yes",
  "nmprimary_ipv6_method": "ignore",
  "nmprimary_ipv6_dns-priority": "0",
  "nmprimary_ipv6_route-metric": "-1",
  "nmprimary_ipv6_route-table": "0",
  "nmprimary_ipv6_ignore-auto-routes": "no",
  "nmprimary_ipv6_ignore-auto-dns": "no",
  "nmprimary_ipv6_never-default": "no",
  "nmprimary_ipv6_may-fail": "yes",
  "nmprimary_ipv6_ip6-privacy": "-1",
  "nmprimary_ipv6_addr-gen-mode": "eui64",
  "nmprimary_ipv6_dhcp-send-hostname": "yes",
  "nmprimary_vlan_id": "0",
  "nmprimary_vlan_flags": "1",
  "nmprimary_proxy_method": "none",
  "nmprimary_proxy_browser-only": "no",
  "nmprimary_general_name": "primary",
  "nmprimary_general_uuid": "53e71b0e-fe83-11ea-bcc8-40f2e9d65067",
  "nmprimary_general_devices": "enp6s0",
  "nmprimary_general_state": "activated",
  "nmprimary_general_default": "yes",
  "nmprimary_general_default6": "no",
  "nmprimary_general_vpn": "no",
  "nmprimary_ip4_address": "10.59.24.175/24",
  "nmprimary_ip4_gateway": "10.59.24.1",
  "nmprimary_ip4_route": "dst = 0.0.0.0/0, nh = 10.59.24.1, mt = 100",
  "nmprimary_ip4_dns": "10.92.128.40",
  "nmprimary_ip4_domain": "example.com",
  "nmprimary_dhcp4_option_broadcast_address": "10.59.24.255",
  "nmprimary_dhcp4_option_dhcp_message_type": "5",
  "nmprimary_dhcp4_option_dhcp_server_identifier": "10.254.52.34",
  "nmprimary_dhcp4_option_domain_name": "example.com",
  "nmprimary_dhcp4_option_domain_name_servers": "10.92.128.40 10.92.128.41 10.20.17.25 10.20.17.26 10.95.65.34 10.95.131.30",
  "nmprimary_dhcp4_option_expiry": "1600965364",
  "nmprimary_dhcp4_option_filename": "/pxelinux.0",
  "nmprimary_dhcp4_option_ip_address": "10.59.24.175",
  "nmprimary_dhcp4_option_network_number": "10.59.24.0",
  "nmprimary_dhcp4_option_next_server": "10.11.184.93",
  "nmprimary_dhcp4_option_ntp_servers": "10.92.128.40",
  "nmprimary_dhcp4_option_requested_broadcast_address": "1",
  "nmprimary_dhcp4_option_requested_classless_static_routes": "1",
  "nmprimary_dhcp4_option_requested_domain_name": "1",
  "nmprimary_dhcp4_option_requested_domain_name_servers": "1",
  "nmprimary_dhcp4_option_requested_domain_search": "1",
  "nmprimary_dhcp4_option_requested_host_name": "1",
  "nmprimary_dhcp4_option_requested_interface_mtu": "1",
  "nmprimary_dhcp4_option_requested_ms_classless_static_routes": "1",
  "nmprimary_dhcp4_option_requested_nis_domain": "1",
  "nmprimary_dhcp4_option_requested_nis_servers": "1",
  "nmprimary_dhcp4_option_requested_ntp_servers": "1",
  "nmprimary_dhcp4_option_requested_rfc3442_classless_static_routes": "1",
  "nmprimary_dhcp4_option_requested_routers": "1",
  "nmprimary_dhcp4_option_requested_static_routes": "1",
  "nmprimary_dhcp4_option_requested_subnet_mask": "1",
  "nmprimary_dhcp4_option_requested_wpad": "1",
  "nmprimary_dhcp4_option_routers": "10.59.24.1",
  "nmprimary_dhcp4_option_subnet_mask": "255.255.255.0",
  "nmprimary_dhcp4_option_wpad": "a:0",
  "nmprimary_ip6_address": "fe80::42f2:e9ff:fed6:5067/64",
  "nmprimary_ip6_route": "dst = ff00::/8, nh = ::, mt = 256, table=255",
  "nmprimary_ptr": "ods00712w10.example.com",
  "discovery_proxy_uri": "https://hqret-foreman.example.com",
  "discovery_proxy_type": "foreman",
  "os": null,
  "os::release": null,
  "processors": null,
  "dhcp_servers": null,
  "partitions::sda1": null,
  "partitions": null,
  "partitions::sda2": null,
  "nmprimary_ipv4_dns-options": " ",
  "nmprimary_ipv6_dns-options": " "
}

I also gathered the production log of this even as well, see below:

2020-09-24T12:32:21 [I|app|e5c3c44f] Started POST "/api/v2/discovered_hosts/facts" for 127.0.0.1 at 2020-09-24 12:32:21 -0400
2020-09-24T12:32:21 [I|app|e5c3c44f] Processing by Api::V2::DiscoveredHostsController#facts as JSON
2020-09-24T12:32:21 [I|app|e5c3c44f]   Parameters: {"facts"=>"[FILTERED]", "apiv"=>"v2", "discovered_host"=>{"facts"=>"[FILTERED]"}}
2020-09-24T12:32:21 [I|app|e5c3c44f] Import facts for 'mac40f2e9d65067' completed. Added: 0, Updated: 2, Deleted 0 facts
2020-09-24T12:32:21 [D|tax|e5c3c44f] Current location set to MyLoc
2020-09-24T12:32:21 [D|tax|e5c3c44f] Current organization set to MyOrg
2020-09-24T12:32:21 [D|app|e5c3c44f] skipping interface with identifier 'lo' since it was matched by 'ignored_interface_identifiers' setting
2020-09-24T12:32:21 [D|app|e5c3c44f] We have following interfaces 'enp11s0, enp6s0' based on facts
2020-09-24T12:32:21 [D|app|e5c3c44f] Interface enp11s0 facts: {"macaddress"=>"40:f2:e9:d6:50:68", "mtu"=>1500, "duplex"=>"unknown! (255)", "port"=>"Twisted Pair", "auto_negotiation"=>"true", "wol"=>true, "link"=>"false"}
2020-09-24T12:32:21 [D|app|e5c3c44f] Interface enp6s0 facts: {"ipaddress"=>"10.59.24.175", "macaddress"=>"40:f2:e9:d6:50:67", "netmask"=>"255.255.255.0", "mtu"=>1500, "network"=>"10.59.24.0", "speed"=>"1000", "duplex"=>"full", "port"=>"Twisted Pair", "auto_negotiation"=>"true", "wol"=>true, "link"=>"true"}
2020-09-24T12:32:21 [D|app|e5c3c44f] Discovery fact parser detected primary interface: ["enp6s0", {"ipaddress"=>"10.59.24.175", "macaddress"=>"40:f2:e9:d6:50:67", "netmask"=>"255.255.255.0", "mtu"=>1500, "network"=>"10.59.24.0", "speed"=>"1000", "duplex"=>"full", "port"=>"Twisted Pair", "auto_negotiation"=>"true", "wol"=>true, "link"=>"true", "keep_subnet"=>true, "virtual"=>false}]
2020-09-24T12:32:21 [I|app|e5c3c44f] Detected IPv4 subnet: 00712_OpsNet with taxonomy ["MyOrg"]/["MyLoc"]
2020-09-24T12:32:21 [I|app|e5c3c44f] Assigned location: MyLoc
2020-09-24T12:32:21 [I|app|e5c3c44f] Assigned organization: MyOrg
2020-09-24T12:32:21 [D|not|e5c3c44f] Notification event: UINotifications::NewHost - checking for notifications
2020-09-24T12:32:21 [D|app|e5c3c44f] Body: {"last_report":"2020-09-24T16:32:21.448Z","build":false,"id":22,"name":"mac40f2e9d65067","last_compile":null,"updated_at":"2020-09-24T16:32:21.663Z","created_at":"2020-09-24T16:31:55.899Z","root_pass":null,"architecture_id":null,"operatingsystem_id":null,"environment_id":null,"ptable_id":null,"medium_id":null,"comment":null,"disk":null,"installed_at":null,"model_id":2,"hostgroup_id":null,"owner_id":1,"owner_type":"User","enabled":true,"puppet_ca_proxy_id":null,"managed":false,"use_image":null,"image_file":null,"uuid":null,"compute_resource_id":null,"puppet_proxy_id":null,"certname":null,"image_id":null,"organization_id":3,"location_id":4,"otp":null,"realm_id":null,"compute_profile_id":null,"provision_method":null,"grub_pass":"","global_status":0,"lookup_value_matcher":null,"pxe_loader":null,"initiated_at":null,"build_errors":null,"discovery_rule_id":null}
2020-09-24T12:32:21 [I|app|e5c3c44f] Completed 201 Created in 276ms (Views: 1.0ms | ActiveRecord: 64.6ms | Allocations: 103859)

I did a diff of the first and second attempt JSON and the differences are not much to be honest. It is just an extra space found in a couple of the options:

1st attempt / 2nd attempt:
“nmprimary_ipv4_dns-options”: “”, / “nmprimary_ipv4_dns-options”: " ",
“nmprimary_ipv6_dns-options”: “”, / “nmprimary_ipv4_dns-options”: " ",

After doing the above, I changed the Discovery Rule query to ip=10.59.24.175 from facts.ipaddress=10.59.24.175. I then turned on the auto-provision setting and tried again. However, I seem to have the same problem.

In both scenarios, it seems I either can hit Resend almost immediately and it will continue on provisioning, or I can wait and it will kick off eventually.

I hope I’ve collected the correct data you were looking for. Please let me know if anything else I can gather for you.

Thanks again for you efforts.

lzap · September 25, 2020, 6:57am

Hmmm I compared both JSONs and the only difference is nmprimary_ipv4_dns-options (and IPv6 variant) like you said. That should not cause auto provisioning to fail.

I see one problem tho. You appear to have two organizations: “Default Organization” and “MyOrg”. Discovery rules are subject of taxonomy, they do need to be assigned to organizations. Can you add all those rules into all organizations?

Discovered hosts are also assigned into organizations according to some baked-in statements, this is documented:

https://docs.theforeman.org/master/Provisioning_Guide/index-foreman.html#automatic-contexts-for-discovered-hosts

Rule no 1: If a discovered host uses a subnet defined in Foreman, the host uses the first organization and location associated with the subnet.

I know this is terrible design, we should have fixed this years ago but this will pick random Organization associated with the subnet. There is no order. There should be a field in the database for that.

fresh-pie · September 25, 2020, 2:53pm

Hello sir!

So I really think you are onto something. Just to see what would happen and try to narrow down the issue, I thought to my self that I will begin to configure everything to operate in the “Default Organization”, which is how I had it working on a previous, older version of Foreman in my lab.

After taking mostly everything out of my custom organization and putting them into the default one, I attempted to go through the discovery process with my host and sure enough, it matched the rule immediately upon discovery. It had some additional issues after that, but I think it is just because it couldn’t see or have the permissions to access certain resources in my “MyOrg” organization (such as the content sources).

2020-09-25T08:46:12 [D|app|01b8889e] Finding auto discovery rule for host mac40f2e9d65067 (27)
2020-09-25T08:46:12 [D|app|01b8889e] Found rule 00712_W10 (1) [0/0]
2020-09-25T08:46:12 [I|app|01b8889e] Match found for host mac40f2e9d65067 (27) rule 00712_W10 (1)
2020-09-25T08:46:12 [D|app|01b8889e] Auto-provisioning via rule 00712_W10 hostgroup 00712_Servers subnet 00712_OpsNet
2020-09-25T08:46:12 [W|app|01b8889e] Could not find a provider for mac40f2e9d65067. Providers returned {"Katello::ManagedContentMediumProvider"=>["Kickstart repository
was not set for host 'mac40f2e9d65067'", "Content source was not set for host 'mac40f2e9d65067'"], "MediumProviders::Default"=>["Operating system was not set for host '
mac40f2e9d65067'", " medium was not set for host 'mac40f2e9d65067'", "Invalid medium '' for ''", "Invalid architecture '' for ''"]}
2020-09-25T08:46:12 [D|app|01b8889e] Not suggesting IP Address for 00712_OpsNet as IPAM is disabled
2020-09-25T08:46:12 [D|tax|01b8889e] Current organization set to Default Organization
2020-09-25T08:46:12 [D|tax|01b8889e] Current location set to Default Location

This for sure make me more confident that my challenge has something to do with my custom Organization. So, I’m now putting everything back the way it was with my “MyOrg” organization and also following your advice of adding my discovery rule into all organizations.

Here is what I got:

Host group 00712_Server
- Organization: MyOrg (only)
- Location: MyLoc (only)
Subnet: 00712_OpsNet
- Organization: MyOrg (only)
- Location: MyLoc (only)
Discovery rule 00712_W10
- Host group: 00712_Server
- Query: ip=10.59.24.175
- Hostname: ods00712w10.example.com
- Organization(s): Default Organization, MyOrg
- Location(s): Default Location, MyLoc
“Discovered” plugin settings:
- Discovery location: MyLoc
- Discovery organization: MyOrg

Note that my 00712_W10 discovery rule only had my MyOrg and MyLoc assigned to it prior to your last reply. I just added Default Organization and Default Location to it per your recommendation.

So in regards to the documentation you shared (thank you for that), I just want to walk through the discovery sequence:

If a discovered host uses a subnet defined in Foreman, the host uses the first organization and location associated with the subnet. The 00712_OpsNet subnet does indeed have only the “MyOrg” and “MyLoc” assigned to it. See export from hammer below:

Id:                3
Name:              00712_OpsNet
Description:

Protocol:          IPv4
Priority:
Network Addr:      10.59.24.0
Network Prefix:    24
Network Mask:      255.255.255.0
Gateway Addr:      10.59.24.1
Primary DNS:       10.92.128.40
Secondary DNS:
Smart Proxies:
    DNS:
    TFTP: hqret-foreman.example.com (https://hqret-foreman.example.com:9090)
    DHCP:
IPAM:              None
Start of IP Range:
End of IP Range:
VLAN ID:
MTU:               1500
Boot Mode:         Static
Domains:
    example.com
Locations:
    MyLoc
Organizations:
    MyOrg
Parameters:

If the discovery_organization or discovery_location fact values are set, the discovered host uses these fact values as an organization and location. As shown above, these are set to “MyOrg” and “MyLoc” respectively.
If none of the previous conditions exists, Foreman assigns the first Organization and Location ordered by name. We should never get to this point, as this should get “caught” by one of the two points above.

OK, so now we know how everything is setup. Lets try the discovery process again. Interesting enough, we actually find the rule!

2020-09-25T10:41:07 [I|app|5d13ac23] Started POST "/api/v2/discovered_hosts/facts" for 127.0.0.1 at 2020-09-25 10:41:07 -0400
2020-09-25T10:41:07 [I|app|5d13ac23] Processing by Api::V2::DiscoveredHostsController#facts as JSON
2020-09-25T10:41:07 [I|app|5d13ac23]   Parameters: {"facts"=>"[FILTERED]", "apiv"=>"v2", "discovered_host"=>{"facts"=>"[FILTERED]"}}
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on mac
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on ip
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on type Nic::Managed
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on name mac40f2e9d65067
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on host_id 28
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on subnet_id
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on domain_id
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on attrs {}
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on provider
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on username
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on password [redacted]
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on virtual false
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on link true
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on identifier
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on tag
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on attached_to
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on managed true
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on mode balance-rr
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on attached_devices
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on bond_options
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on primary true
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on provision true
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on compute_attributes {}
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on ip6
2020-09-25T10:41:07 [I|aud|5d13ac23] Nic::Managed (79) create event on subnet6_id
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on name mac40f2e9d65067
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on last_compile
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on root_pass
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on architecture_id
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on operatingsystem_id
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on environment_id
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on ptable_id
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on medium_id
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on build false
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on comment
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on disk
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on installed_at
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on model_id
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on hostgroup_id
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on owner_id
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on owner_type
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on enabled true
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on puppet_ca_proxy_id
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on managed false
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on use_image
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on image_file
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on uuid
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on compute_resource_id
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on puppet_proxy_id
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on certname
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on image_id
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on organization_id
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on location_id
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on otp
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on realm_id
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on compute_profile_id
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on provision_method
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on grub_pass
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on global_status 0
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on lookup_value_matcher
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on pxe_loader
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on initiated_at
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on build_errors
2020-09-25T10:41:07 [I|aud|5d13ac23] Host::Base (28) create event on discovery_rule_id
2020-09-25T10:41:08 [I|app|5d13ac23] Import facts for 'mac40f2e9d65067' completed. Added: 192, Updated: 0, Deleted 0 facts
2020-09-25T10:41:08 [D|tax|5d13ac23] Current location set to Default Location
2020-09-25T10:41:08 [D|tax|5d13ac23] Current organization set to Default Organization
2020-09-25T10:41:08 [D|app|5d13ac23] skipping interface with identifier 'lo' since it was matched by 'ignored_interface_identifiers' setting
2020-09-25T10:41:08 [D|app|5d13ac23] We have following interfaces 'enp11s0, enp6s0' based on facts
2020-09-25T10:41:08 [D|app|5d13ac23] Interface enp11s0 facts: {"macaddress"=>"40:f2:e9:d6:50:68", "mtu"=>1500, "duplex"=>"unknown! (255)", "port"=>"Twisted Pair", "auto_negotiation"=>"true", "wol"=>true, "link"=>"false"}
2020-09-25T10:41:08 [D|app|5d13ac23] Interface enp6s0 facts: {"ipaddress"=>"10.59.24.175", "macaddress"=>"40:f2:e9:d6:50:67", "netmask"=>"255.255.255.0", "mtu"=>1500, "network"=>"10.59.24.0", "speed"=>"1000", "duplex"=>"full", "port"=>"Twisted Pair", "auto_negotiation"=>"true", "wol"=>true, "link"=>"true"}
2020-09-25T10:41:08 [D|app|5d13ac23] Discovery fact parser detected primary interface: ["enp6s0", {"ipaddress"=>"10.59.24.175", "macaddress"=>"40:f2:e9:d6:50:67", "netmask"=>"255.255.255.0", "mtu"=>1500, "network"=>"10.59.24.0", "speed"=>"1000", "duplex"=>"full", "port"=>"Twisted Pair", "auto_negotiation"=>"true", "wol"=>true, "link"=>"true", "keep_subnet"=>true, "virtual"=>false}]
2020-09-25T10:41:08 [D|app|5d13ac23] Discovery fact parser detected primary interface: ["enp6s0", {"ipaddress"=>"10.59.24.175", "macaddress"=>"40:f2:e9:d6:50:67", "netmask"=>"255.255.255.0", "mtu"=>1500, "network"=>"10.59.24.0", "speed"=>"1000", "duplex"=>"full", "port"=>"Twisted Pair", "auto_negotiation"=>"true", "wol"=>true, "link"=>"true", "keep_subnet"=>true, "virtual"=>false}]
2020-09-25T10:41:08 [D|app|5d13ac23] Suggested enp6s0 NIC as a primary interface.
2020-09-25T10:41:08 [I|aud|5d13ac23] Nic::Managed (79) update event on mac , 40:f2:e9:d6:50:67
2020-09-25T10:41:08 [I|aud|5d13ac23] Nic::Managed (79) update event on identifier , enp6s0
2020-09-25T10:41:08 [D|app|5d13ac23] Saving enp11s0 NIC for host mac40f2e9d65067
2020-09-25T10:41:08 [D|app|5d13ac23] Saving enp6s0 NIC for host mac40f2e9d65067
2020-09-25T10:41:08 [D|app|5d13ac23] Saving ipmi NIC for host mac40f2e9d65067
2020-09-25T10:41:08 [I|app|5d13ac23] Detected IPv4 subnet: 00712_OpsNet with taxonomy ["MyOrg"]/["MyLoc"]
2020-09-25T10:41:08 [I|app|5d13ac23] Assigned location: MyLoc
2020-09-25T10:41:08 [I|app|5d13ac23] Assigned organization: MyOrg
2020-09-25T10:41:08 [I|aud|5d13ac23] Host::Base (28) update event on model_id , 2
2020-09-25T10:41:08 [I|aud|5d13ac23] Host::Base (28) update event on owner_id , 1
2020-09-25T10:41:08 [I|aud|5d13ac23] Host::Base (28) update event on owner_type , User
2020-09-25T10:41:08 [I|aud|5d13ac23] Host::Base (28) update event on organization_id , 3
2020-09-25T10:41:08 [I|aud|5d13ac23] Host::Base (28) update event on location_id , 4
2020-09-25T10:41:08 [I|aud|5d13ac23] Nic::Managed (79) update event on subnet_id , 3
2020-09-25T10:41:08 [D|not|5d13ac23] Notification event: UINotifications::NewHost - checking for notifications
2020-09-25T10:41:08 [D|not|5d13ac23] Clearing Cache: notification, clearing cache for notification-5
2020-09-25T10:41:08 [D|not|5d13ac23] Clearing Cache: notification, clearing cache for notification-4
2020-09-25T10:41:08 [D|app|5d13ac23] Finding auto discovery rule for host mac40f2e9d65067 (28)
2020-09-25T10:41:08 [D|app|5d13ac23] Found rule 00712_W10 (1) [0/0]
2020-09-25T10:41:08 [D|app|5d13ac23] Body: {"id":28,"name":"mac40f2e9d65067","last_compile":null,"last_report":"2020-09-25T14:41:07.487Z","updated_at":"2020-09-25T14:41:08.267Z","created_at":"2020-09-25T14:41:07.448Z","root_pass":null,"architecture_id":null,"operatingsystem_id":null,"environment_id":null,"ptable_id":null,"medium_id":null,"build":false,"comment":null,"disk":null,"installed_at":null,"model_id":2,"hostgroup_id":null,"owner_id":1,"owner_type":"User","enabled":true,"puppet_ca_proxy_id":null,"managed":false,"use_image":null,"image_file":null,"uuid":null,"compute_resource_id":null,"puppet_proxy_id":null,"certname":null,"image_id":null,"organization_id":3,"location_id":4,"otp":null,"realm_id":null,"compute_profile_id":null,"provision_method":null,"grub_pass":"","global_status":0,"lookup_value_matcher":null,"pxe_loader":null,"initiated_at":null,"build_errors":null,"discovery_rule_id":null}
2020-09-25T10:41:08 [I|app|5d13ac23] Completed 201 Created in 911ms (Views: 1.2ms | ActiveRecord: 250.2ms | Allocations: 309893)

As you see, it logged Found rule 00712_W10 (1) [0/0] (which it doesn’t look like it had done before), but it never matched. Therefor, it didn’t automatically begin provisioning. It is just sitting at the Discovery status screen. The Auto provisioning setting is indeed set to “Yes”.

If I select Resend, it then works. And as you can see in the logs, it found the “match”:

2020-09-25T10:49:54 [I|app|cba9df68] Detected IPv4 subnet: 00712_OpsNet with taxonomy ["Office Depot"]/["Retail"]
2020-09-25T10:49:54 [I|app|cba9df68] Assigned location: MyLoc
2020-09-25T10:49:54 [I|app|cba9df68] Assigned organization: MyOrg
2020-09-25T10:49:54 [D|not|cba9df68] Notification event: UINotifications::NewHost - checking for notifications
2020-09-25T10:49:54 [D|app|cba9df68] Finding auto discovery rule for host mac40f2e9d65067 (28)
2020-09-25T10:49:54 [D|app|cba9df68] Found rule 00712_W10 (1) [0/0]
2020-09-25T10:49:54 [I|app|cba9df68] Match found for host mac40f2e9d65067 (28) rule 00712_W10 (1)
2020-09-25T10:49:54 [D|app|cba9df68] Auto-provisioning via rule 00712_W10 hostgroup 00712_Servers subnet 00712_OpsNet

We can see what the documentation referenced however. You see that the organization and locations are at first set to the “default” ones. But then, based on the subnet associated with the host, it changes it to “MyOrg” and “MyLoc” respectively.

I’m so confused. I’m 99.99% sure its some configuration issue on my part, but I just don’t know what it is.

Thank you for your patience with this…

jairelee · September 29, 2020, 12:52pm

Hello,

I have what seems to be the very same issue.
Until last week I was running Foreman 1.22, and just last Friday I upgraded the master foreman instance to 2.1 (going through all the middle versions, 1.23,1.24,2.0,2.1) along with the 5 foreman proxy servers.
Until this point my 5 discovery rules were working fine for the different proxy servers (Templates, TFTP, HTTPBoot, Discovery, Logs), using each proxy subnet as the conditional for the rule, so when building a laptop and it reaches the Foreman Discovery SUCCESS screen, after 2 seconds it was rebooting and generating the new GRUB menu for provisioning Linux, but now it has stopped working for all the proxies but one.
The only proxy where the auto provisioning is still happening automatically, is the one assigned to the default location, organisation matches for all the proxies. I have tried changing the default location to match one of the other proxy servers and then, its assigned discovery rule worked just fine and the laptop was automatically provisioned.
Doing the resend from the success screen also worked from any proxy, but only the one matching the default location did the auto provisioning automatically on the first try.
I don’t seem to be able to set the default location to “not set”.
Is any way to get around this issue?

Many thanks!

lzap · September 29, 2020, 1:44pm

The taxonomy assignment has a very clunky code:

      def suggested_organization
        Organization.find_by_title(facts["foreman_organization"] || facts["discovery_organization"]) ||
          Organization.find_by_title(Setting[:discovery_organization]) ||
          host.subnet.try(:organizations).try(:first) ||
          Organization.first
      end

In other words:

Pick organization from a fact (when present, not by default)
Pick organization from a setting (unset by default)
Pick organization randomly from the subnet it was discovered in
Pick random organization otherwise

Yes, it’s terrible. I know. Those first Ruby on Rails calls essentially picks randomly if there are multiple records. SQL server determines the order by itself, an upgrade to newer postgres can easily change behavior. It is essentially SELECT * FROM SUBNETS LIMIT 1.

Solution: Open the Subnet and only put it into a single organization, the one you want your hosts to be discovered in. Or use the discovery_organization setting instead.

The full solution would require adding new association and hacking Subnet page and API, since Discovery is a plugin this would require implementing an extension point. It’s a bit complicated, this is why this status-quo wins. I could probably sort organizations by name or ID and pick the first one in the meantime.

I am curious to find why you see this now, after upgrade. Have you renamed your organization? Created a new one?

fresh-pie · September 29, 2020, 1:55pm

Hi lzap,

In my case, I have my subnet only assigned to the organization it should be discovered in. I also do have the discovery_organization setting set to that organization as well. Based on the logic of the code, it should always be placing my system in the desired organization, right?

Thanks!

lzap · September 29, 2020, 2:05pm

This all appears to be correct. Can you try the search condition on the discovered hosts page? Just enter: ip=10.59.24.175 there and see if it finds the host.

Anyway, can you apply this patch:

diff --git a/app/controllers/concerns/foreman/controller/discovered_extensions.rb b/app/controllers/concerns/foreman/controller/discovered_extensions.rb
index 3d5b0b2..2cf7ef2 100644
--- a/app/controllers/concerns/foreman/controller/discovered_extensions.rb
+++ b/app/controllers/concerns/foreman/controller/discovered_extensions.rb
@@ -14,7 +14,7 @@ module Foreman::Controller::DiscoveredExtensions
       if max == 0 || usage < max
         # try to match the search
         begin
-          if Host::Discovered.where(:id => host.id).search_for(rule.search).size > 0
+          if Host::Discovered.unscoped.where(:id => host.id).search_for(rule.search).size > 0
             if validate_rule_by_taxonomy(rule, host)
               Rails.logger.info "Match found for host #{host.name} (#{host.id}) rule #{rule.name} (#{rule.id})"
               return rule

The file to patch will be on this patch, depending on the version: /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_discovery-16.1.2/app/controllers/concerns/foreman/controller/discovered_extensions.rb

jairelee · September 29, 2020, 3:26pm

Hi lzap,
Thanks for the suggested solution.
Regarding your question, I haven’t done any changes to the organisations.
I had few issues right after the upgrade because after upgrading the OS packages I missed running foreman-installer in the proxy servers, but once I realised of this everything was working, except the auto provision.
I’m still running PostgreSQL 10, but this package was also updated, since you mention it could have changed the behaviour.
Other than that I just did some changes to the provisioning templates, which still work and are common for all proxy servers.

Thank you!

fresh-pie · September 29, 2020, 3:47pm

Hey lzap,

I loaded the discovered hosts page and did the ip=10.59.24.175 search. My host was found.

I applied the patch, removed my host from Foreman and kicked off the discovery process again. However, I’m seeing the exact same behavior.

Thanks again for helping us with this.

lzap · September 30, 2020, 6:03am

Have you restarted Foreman app?

I am wondering if you can get me detail of the discovered host after the first discovery (the one which fail to provision:

foreman-rake console
> Host::Discovered.unscoped.find_by_name("macXXXXXXXX")

fresh-pie · September 30, 2020, 12:57pm

D’oh! I’m so sorry… I didn’t restart the application. I’m a dummy.

OK, after restarting the application, we do have some different behavior actually. Upon discovery, it throws up a “FAILURE” screen with the below error:

No hostgroup associated with rule '00712_W10'

Which means it actually did match the rule! However, for some reason it can’t find my 00712_Servers hostgroup, which is assigned in that rule.

Now if I select Resend, it does find the hostgroup and begins to provision.

Here is some of the production.log:

2020-09-30T08:30:43 [I|app|510570c9] Detected IPv4 subnet: 00712_OpsNet with taxonomy ["MyOrg"]/["MyLoc"]
2020-09-30T08:30:43 [I|app|510570c9] Assigned location: MyLoc
2020-09-30T08:30:43 [I|app|510570c9] Assigned organization: MyOrg
2020-09-30T08:30:43 [I|aud|510570c9] Host::Base (42) update event on model_id , 2
2020-09-30T08:30:43 [I|aud|510570c9] Host::Base (42) update event on owner_id , 1
2020-09-30T08:30:43 [I|aud|510570c9] Host::Base (42) update event on owner_type , User
2020-09-30T08:30:43 [I|aud|510570c9] Host::Base (42) update event on organization_id , 3
2020-09-30T08:30:43 [I|aud|510570c9] Host::Base (42) update event on location_id , 4
2020-09-30T08:30:44 [I|aud|510570c9] Nic::Managed (113) update event on subnet_id , 3
2020-09-30T08:30:44 [I|app|510570c9] Match found for host mac40f2e9d65067 (42) rule 00712_W10 (2)
2020-09-30T08:30:44 [W|app|510570c9] Host discovery failed, facts: {"lib"=>"/usr/share/fdi/facts:/opt/extension/facts", "virtual"=>"physical", "is_virtual"=>false, "id"=>"root", "netmask"=>"255.255.255.0", "selinux"=>false, "interfaces"=>"enp11s0,enp6s0,lo", "macaddress_enp11s0"=>"40:f2:e9:d6:50:68", "mtu_enp11s0"=>1500, "ipaddress_enp6s0"=>"10.59.24.175", "macaddress_enp6s0"=>"40:f2:e9:d6:50:67", "netmask_enp6s0"=>"255.255.255.0", "mtu_enp6s0"=>1500, "ipaddress_lo"=>"127.0.0.1", "netmask_lo"=>"255.0.0.0", "mtu_lo"=>65536, "boardmanufacturer"=>"IBM", "boardproductname"=>"81Y7071", "boardserialnumber"=>"4B908Y", "bios_vendor"=>"IBM Corp.", "bios_version"=>"-[JQE168BUS-1.09]-", "bios_release_date"=>"09/17/2014", "manufacturer"=>"IBM", "productname"=>"IBM System x3100 M4 -[2582AC1]-", "serialnumber"=>"E2N7985", "uuid"=>"1a0c4069-68f2-35e8-af29-b5a8e33f746a", "type"=>"Tower", "physicalprocessorcount"=>1, "architecture"=>"x86_64", "hardwaremodel"=>"x86_64", "os"=>{"name"=>"CentOS", "family"=>"RedHat", "release"=>{"major"=>"7", "minor"=>"7", "full"=>"7.7.1908"}}, "macaddress"=>"40:f2:e9:d6:50:68", "ipaddress"=>"10.59.24.175", "hostname"=>"fdi", "uniqueid"=>"3b0aaf18", "gid"=>"root", "processors"=>{"models"=>["Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz", "Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz", "Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz", "Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz"], "count"=>4, "physicalcount"=>1}, "processor0"=>"Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz", "processor1"=>"Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz", "processor2"=>"Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz", "processor3"=>"Intel(R) Core(TM) i3-3220 CPU @ 3.30GHz", "processorcount"=>4, "memorysize"=>"7.75 GB", "memorysize_mb"=>"7938.83", "dhcp_servers"=>{"system"=>"10.254.52.34", "enp6s0"=>"10.254.52.34"}, "fqdn"=>"fdi.example.com", "hardwareisa"=>"x86_64", "ps"=>"ps -ef", "partitions"=>{"sda1"=>{"uuid"=>"aac2e15a-e7d1-4996-83ae-e86085542dee", "size"=>"2097152", "filesystem"=>"ext4"}, "sda2"=>{"size"=>"581883904", "filesystem"=>"LVM2_member"}}, "blockdevice_sda_size"=>298999349248, "blockdevice_sda_vendor"=>"IBM", "blockdevice_sda_model"=>"ServeRAID M1015", "blockdevice_sr0_size"=>1073741312, "blockdevice_sr0_vendor"=>"IBM SATA", "blockdevice_sr0_model"=>"DEVICE 81Y3675", "blockdevices"=>"sda,sr0", "network_enp6s0"=>"10.59.24.0", "network_lo"=>"127.0.0.0", "domain"=>"example.com", "facterversion"=>"2.4.1", "discovery_version"=>"3.5.7", "discovery_release"=>"20191021.1", "discovery_bootif"=>"40:f2:e9:d6:50:67", "discovery_bootip"=>"10.59.24.175", "duplex_enp11s0"=>"unknown! (255)", "port_enp11s0"=>"Twisted Pair", "auto_negotiation_enp11s0"=>"true", "wol_enp11s0"=>true, "link_enp11s0"=>"false", "speed_enp6s0"=>"1000", "duplex_enp6s0"=>"full", "port_enp6s0"=>"Twisted Pair", "auto_negotiation_enp6s0"=>"true", "wol_enp6s0"=>true, "link_enp6s0"=>"true", "link_lo"=>"true", "ipmi_enabled"=>true, "ipmi_ipaddress_source"=>"Other", "ipmi_ipaddress"=>"10.59.24.215", "ipmi_subnet_mask"=>"255.255.255.0", "ipmi_macaddress"=>"40:f2:e9:d6:50:6b", "ipmi_gateway"=>"10.59.24.1", "ipmi_1_ipaddress_source"=>"Other", "ipmi_1_ipaddress"=>"10.59.24.215", "ipmi_1_subnet_mask"=>"255.255.255.0", "ipmi_1_macaddress"=>"40:f2:e9:d6:50:6b", "ipmi_1_gateway"=>"10.59.24.1", "nmprimary_connection_id"=>"primary", "nmprimary_connection_uuid"=>"9f9a465e-0318-11eb-a9e8-40f2e9d65067", "nmprimary_connection_stable-id"=>"", "nmprimary_connection_type"=>"802-3-ethernet", "nmprimary_connection_interface-name"=>"", "nmprimary_connection_autoconnect"=>"yes", "nmprimary_connection_autoconnect-priority"=>"1", "nmprimary_connection_autoconnect-retries"=>"-1", "nmprimary_connection_multi-connect"=>"0", "nmprimary_connection_auth-retries"=>"-1", "nmprimary_connection_read-only"=>"no", "nmprimary_connection_permissions"=>"", "nmprimary_connection_zone"=>"", "nmprimary_connection_master"=>"", "nmprimary_connection_slave-type"=>"", "nmprimary_connection_autoconnect-slaves"=>"-1", "nmprimary_connection_secondaries"=>"", "nmprimary_connection_metered"=>"unknown", "nmprimary_connection_lldp"=>"default", "nmprimary_connection_mdns"=>"-1", "nmprimary_connection_llmnr"=>"-1", "nmprimary_802-3-ethernet_port"=>"", "nmprimary_802-3-ethernet_speed"=>"0", "nmprimary_802-3-ethernet_duplex"=>"", "nmprimary_802-3-ethernet_auto-negotiate"=>"no", "nmprimary_802-3-ethernet_mac-address"=>"40:F2:E9:D6:50:67", "nmprimary_802-3-ethernet_cloned-mac-address"=>"", "nmprimary_802-3-ethernet_generate-mac-address-mask"=>"", "nmprimary_802-3-ethernet_mac-address-blacklist"=>"", "nmprimary_802-3-ethernet_mtu"=>"auto", "nmprimary_802-3-ethernet_s390-subchannels"=>"", "nmprimary_802-3-ethernet_s390-nettype"=>"", "nmprimary_802-3-ethernet_s390-options"=>"", "nmprimary_802-3-ethernet_wake-on-lan"=>"default", "nmprimary_802-3-ethernet_wake-on-lan-password"=>"", "nmprimary_ipv4_method"=>"auto", "nmprimary_ipv4_dns"=>"", "nmprimary_ipv4_dns-search"=>"", "nmprimary_ipv4_dns-options"=>" ", "nmprimary_ipv4_dns-priority"=>"0", "nmprimary_ipv4_addresses"=>"", "nmprimary_ipv4_gateway"=>"", "nmprimary_ipv4_routes"=>"", "nmprimary_ipv4_route-metric"=>"-1", "nmprimary_ipv4_route-table"=>"0", "nmprimary_ipv4_routing-rules"=>"", "nmprimary_ipv4_ignore-auto-routes"=>"no", "nmprimary_ipv4_ignore-auto-dns"=>"no", "nmprimary_ipv4_dhcp-client-id"=>"", "nmprimary_ipv4_dhcp-send-hostname"=>"no", "nmprimary_ipv4_dhcp-hostname"=>"", "nmprimary_ipv4_dhcp-fqdn"=>"", "nmprimary_ipv4_never-default"=>"no", "nmprimary_ipv4_may-fail"=>"yes", "nmprimary_ipv6_method"=>"ignore", "nmprimary_ipv6_dns"=>"", "nmprimary_ipv6_dns-search"=>"", "nmprimary_ipv6_dns-options"=>" ", "nmprimary_ipv6_dns-priority"=>"0", "nmprimary_ipv6_addresses"=>"", "nmprimary_ipv6_gateway"=>"", "nmprimary_ipv6_routes"=>"", "nmprimary_ipv6_route-metric"=>"-1", "nmprimary_ipv6_route-table"=>"0", "nmprimary_ipv6_routing-rules"=>"", "nmprimary_ipv6_ignore-auto-routes"=>"no", "nmprimary_ipv6_ignore-auto-dns"=>"no", "nmprimary_ipv6_never-default"=>"no", "nmprimary_ipv6_may-fail"=>"yes", "nmprimary_ipv6_ip6-privacy"=>"-1", "nmprimary_ipv6_addr-gen-mode"=>"eui64", "nmprimary_ipv6_dhcp-duid"=>"", "nmprimary_ipv6_dhcp-send-hostname"=>"yes", "nmprimary_ipv6_dhcp-hostname"=>"", "nmprimary_ipv6_token"=>"", "nmprimary_vlan_parent"=>"", "nmprimary_vlan_id"=>"0", "nmprimary_vlan_flags"=>"1", "nmprimary_vlan_ingress-priority-map"=>"", "nmprimary_vlan_egress-priority-map"=>"", "nmprimary_proxy_method"=>"none", "nmprimary_proxy_browser-only"=>"no", "nmprimary_proxy_pac-url"=>"", "nmprimary_proxy_pac-script"=>"", "nmprimary_general_name"=>"primary", "nmprimary_general_uuid"=>"9f9a465e-0318-11eb-a9e8-40f2e9d65067", "nmprimary_general_devices"=>"enp6s0", "nmprimary_general_state"=>"activated", "nmprimary_general_default"=>"yes", "nmprimary_general_default6"=>"no", "nmprimary_general_spec-object"=>"", "nmprimary_general_vpn"=>"no", "nmprimary_general_zone"=>"", "nmprimary_ip4_address"=>"10.59.24.175/24", "nmprimary_ip4_gateway"=>"10.59.24.1", "nmprimary_ip4_route"=>"dst = 0.0.0.0/0, nh = 10.59.24.1, mt = 100", "nmprimary_ip4_dns"=>"10.92.128.40", "nmprimary_ip4_domain"=>"example.com", "nmprimary_dhcp4_option_broadcast_address"=>"10.59.24.255", "nmprimary_dhcp4_option_dhcp_message_type"=>"5", "nmprimary_dhcp4_option_dhcp_server_identifier"=>"10.254.52.34", "nmprimary_dhcp4_option_domain_name"=>"example.com", "nmprimary_dhcp4_option_domain_name_servers"=>"10.92.128.40 10.92.128.41 10.20.17.25 10.20.17.26 10.95.65.34 10.95.131.30", "nmprimary_dhcp4_option_expiry"=>"1601469291", "nmprimary_dhcp4_option_filename"=>"/pxelinux.0", "nmprimary_dhcp4_option_ip_address"=>"10.59.24.175", "nmprimary_dhcp4_option_network_number"=>"10.59.24.0", "nmprimary_dhcp4_option_next_server"=>"10.11.184.93", "nmprimary_dhcp4_option_ntp_servers"=>"10.92.128.40", "nmprimary_dhcp4_option_requested_broadcast_address"=>"1", "nmprimary_dhcp4_option_requested_classless_static_routes"=>"1", "nmprimary_dhcp4_option_requested_domain_name"=>"1", "nmprimary_dhcp4_option_requested_domain_name_servers"=>"1", "nmprimary_dhcp4_option_requested_domain_search"=>"1", "nmprimary_dhcp4_option_requested_host_name"=>"1", "nmprimary_dhcp4_option_requested_interface_mtu"=>"1", "nmprimary_dhcp4_option_requested_ms_classless_static_routes"=>"1", "nmprimary_dhcp4_option_requested_nis_domain"=>"1", "nmprimary_dhcp4_option_requested_nis_servers"=>"1", "nmprimary_dhcp4_option_requested_ntp_servers"=>"1", "nmprimary_dhcp4_option_requested_rfc3442_classless_static_routes"=>"1", "nmprimary_dhcp4_option_requested_routers"=>"1", "nmprimary_dhcp4_option_requested_static_routes"=>"1", "nmprimary_dhcp4_option_requested_subnet_mask"=>"1", "nmprimary_dhcp4_option_requested_wpad"=>"1", "nmprimary_dhcp4_option_routers"=>"10.59.24.1", "nmprimary_dhcp4_option_subnet_mask"=>"255.255.255.0", "nmprimary_dhcp4_option_wpad"=>"a:0", "nmprimary_ip6_address"=>"fe80::42f2:e9ff:fed6:5067/64", "nmprimary_ip6_gateway"=>"", "nmprimary_ip6_route"=>"dst = ff00::/8, nh = ::, mt = 256, table=255", "nmprimary_ptr"=>"ods00712w10.example.com", "discovery_proxy_uri"=>"https://hqret-foreman.example.com", "discovery_proxy_type"=>"foreman", "_type"=>:foreman_discovery}

And as asked, the output of foreman-rake:

=> #<Host::Discovered id: 42, name: "mac40f2e9d65067", last_compile: nil, last_report: [FILTERED], updated_at: "2020-09-30 12:30:43", created_at: "2020-09-30 12:30:43", root_pass: nil, architecture_id: nil, operatingsystem_id: nil, environment_id: nil, ptable_id: nil, medium_id: nil, build: false, comment: nil, disk: nil, installed_at: nil, model_id: 2, hostgroup_id: nil, owner_id: 1, owner_type: "User", enabled: true, puppet_ca_proxy_id: nil, managed: false, use_image: nil, image_file: nil, uuid: nil, compute_resource_id: nil, puppet_proxy_id: nil, certname: nil, image_id: nil, organization_id: 3, location_id: 4, type: "Host::Discovered", otp: nil, realm_id: nil, compute_profile_id: nil, provision_method: nil, grub_pass: "", global_status: 0, lookup_value_matcher: nil, pxe_loader: nil, initiated_at: nil, build_errors: nil, discovery_rule_id: nil>

Thanks!

lzap · October 1, 2020, 10:24am

I was able to reproduce and fix the problem. Try this patch instead, it’s small. Make sure to restart the server.

https://github.com/theforeman/foreman_discovery/pull/509

fresh-pie · October 1, 2020, 1:29pm

Well Lukas, ya did it! I “undid” the original patch, applied your new one, restart the application and discovery auto provisioning is now working!

At this point, this will work great for us in our lab environment. Is there any additional testing or any assistance I can give to help out in anyway?