Foreman 2.4 / Katello 4 - iPXE not working

Support
,
1

Problem:
I’m currently testing upgrading a Katello 3.18 server to 4.0 (it’s a Lab VM so I can retry this upgrade a lot :wink: )

After the upgrade has completed (and for completeness sake, I use my Foreman role GitHub - Thulium-Drake/ansible-role-foreman at foreman_24_katello_4 for this)

Systems can no longer boot via iPXE. The DHCP server still sends them towards http://foreman.example.com:8000/unattended/iPXE?bootstrap=1, but the result is always the following:

#!ipxe

# Skips booting from network and continues booting from next device
exit

Which makes sense for known systems that do not have a pending build, but not so much for unknown systems that need to boot the FDI or systems that need to build :wink:

Expected outcome:
Systems booting via iPXE

Foreman and Proxy versions:
Foreman 2.4.0
Katello 4.0.0

Foreman and Proxy plugin versions:

Distribution and version: CentOS 7.9.2009

Other relevant data:

I’m not sure where to look, if you have any ideas, let me know! :slight_smile:

2

Oh, and before I forget to mention this, the whole iPXE thing did work on Foreman 2.3.3/Katello 3.18.2…

3

The plot thickens, when I install a fresh system with CentOS 8.2.2004, this issue does not present itself! So something, somewhere is broken when the system is upgraded on EL7 (I will attempt a fresh install on EL7 next)

4

This is weird, the code should render “Global iPXE template” for unknown hosts, it cntains discovery, local boot, shell and reboot menu items. Here is the method from our unattended_controller:

  # Returns true if a template was rendered, false otherwise
  def render_ipxe_template
    return false unless ipxe_request?

    if @host.nil? && params[:bootstrap]
      render_intermediate_template
      return true
    end

    if @host.nil?
      render_default_global_template
      return true
    end

    unless @host.try(:build?)
      render_local_boot_template
      return true
    end

    false
  end

Are you sure there is no host (or NIC with provisioning flag) in the database? Perhaps a discovered host oculd actually make a difference too.

Can you investigate why are you getting this? Perhaps add some logger.debug statements in the method, I’d be intersted in seeing @host variable.

5

I’m pretty sure the DB was empty as it was a freshly installed VM (the upgrade itself not, but as I also see it on a freshly installed system, I didn’t look into that yet.

Silly question perhaps, but where do I put the debug statements? :slight_smile:

I did change the iPXE global default template a bit (I removed the proxy.url arguments. But that shouldn’t break it like this. For reference, the full diff is below:

4c4
< name: iPXE global default custom
---
> name: iPXE global default
7,10d6
< <%#
< Managed by Ansible, your changed will be lost
< This Template is based on iPXE Global Default, the only change made it the removal of proxy.url in favor of using SRV records in DNS. And the countdown for FDI has been reduced to 10 seconds
< -%>
13,14c9,10
< echo Opening global default menu in 5 seconds...
< sleep 5
---
> echo Opening global default menu in 15 seconds...
> sleep 15
53c49
< kernel http://${next-server}:8000/httpboot/boot/fdi-image/vmlinuz0 initrd=initrd0.img rootflags=loop root=live:/fdi.iso rootfstype=auto ro rd.live.image acpi=force rd.luks=0 rd.md=0 rd.dm=0 rd.lvm=0 rd.bootif=0 rd.neednet=0 nomodeset nokaslr proxy.type=foreman BOOTIF=01-${net0/mac} fdi.countdown=10
---
> kernel http://${next-server}:8000/httpboot/boot/fdi-image/vmlinuz0 initrd=initrd0.img rootflags=loop root=live:/fdi.iso rootfstype=auto ro rd.live.image acpi=force rd.luks=0 rd.md=0 rd.dm=0 rd.lvm=0 rd.bootif=0 rd.neednet=0 nomodeset nokaslr proxy.url=<%= foreman_server_url %> proxy.type=foreman BOOTIF=01-${net0/mac}
62c58
< kernel http://${next-server}:${port}/httpboot/boot/fdi-image/vmlinuz0 initrd=initrd0.img rootflags=loop root=live:/fdi.iso rootfstype=auto ro rd.live.image acpi=force rd.luks=0 rd.md=0 rd.dm=0 rd.lvm=0 rd.bootif=0 rd.neednet=0 nomodeset nokaslr proxy.type=foreman BOOTIF=01-${net0/mac} fdi.countdown=10
---
> kernel http://${next-server}:${port}/httpboot/boot/fdi-image/vmlinuz0 initrd=initrd0.img rootflags=loop root=live:/fdi.iso rootfstype=auto ro rd.live.image acpi=force rd.luks=0 rd.md=0 rd.dm=0 rd.lvm=0 rd.bootif=0 rd.neednet=0 nomodeset nokaslr proxy.url=<%= foreman_server_url %> proxy.type=foreman BOOTIF=01-${net0/mac}

But I don’t fully rule out it has anything to do with configuration I do within my role. So I’m going to do that step by step now to see when it breaks and go from there.

I’ll keep you posted :slight_smile:

6

@lzap

So, I have more information. The reason it worked is because the VM I had running (which kept rebooting due to it having no bootable disk and it was set to PXE boot) got PXEbooted from TFTP without iPXE. Once I enable iPXE it does no longer PXEboot. So TFTP (let’s say ‘normal’) PXEbooting still works :slight_smile:

I also found the ruby script that you mentioned. I added the following line in /usr/share/foreman/app/controllers/unattended_controller.rb:

logger.warn { "#banana #{@host}" }

(I use banana as it really stands out in the logs when searching for it :wink: )

And it produced the following logline:

2021-05-04T17:23:20 [W|app|2847af18] #banana foreman.lbhr.htm.lan

So am I correct to assume it doesn’t boot because the unattended_controller thinks that the unknown host booting is actually itself?

7

I also tried creating the node beforehand, same result… So #{@host} does not seem to contain the actual host (or null when there is no known host)

8

I did the same change on Foreman 2.3.3 / Katello 3.18, and there the #{@host} is empty (as it should! :slight_smile: )

9

At this point I can say that Foreman have found a host according to the MAC address provided by iPXE and it rendered it the iPXE template associated for that host. That lbhr.htm.lan is your offender, but why it would find itself? Can you try again but now tail the production.log and give me the unattended request or dig out all the lines with 2847af18. In the URL we should see the MAC address.

One thing that smells is our unattended controller actually falls back to finding host by REMOTE_IP reported by the HTTP server. If there is a HTTP proxy and MAC address is not sent, it could actually fallback to this. This smells like bug. See the load_host_details method there.

10

So these are all the logs for the request you mentioned from the Foreman 2.4 server

2021-05-04T17:23:20 [I|app|2847af18] Started GET "/unattended/iPXE?bootstrap=1&url=http%3A%2F%2Fforeman.lbhr.htm.lan%3A8000" for 192.168.255.15 at 2021-05-04 17:23:20 -0400
2021-05-04T17:23:20 [I|app|2847af18] Processing by UnattendedController#host_template as TEXT
2021-05-04T17:23:20 [I|app|2847af18]   Parameters: {"bootstrap"=>"1", "url"=>"http://foreman.lbhr.htm.lan:8000", "kind"=>"iPXE", "unattended"=>{}}
2021-05-04T17:23:20 [W|app|2847af18] #banana foreman.lbhr.htm.lan
2021-05-04T17:23:20 [W|app|2847af18] Could not find a provider for foreman.lbhr.htm.lan. Providers returned {"Katello::ManagedContentMediumProvider"=>["Kickstart repository was not set for host 'foreman.lbhr.htm.lan'", "Content source was not set for host 'foreman.lbhr.htm.lan'"], "MediumProviders::Default"=>["CentOS 8.2.2004 medium was not set for host 'foreman.lbhr.htm.lan'", "Invalid medium '' for 'CentOS 8.2.2004'"]}
2021-05-04T17:23:20 [I|app|2847af18]   Rendering text template
2021-05-04T17:23:20 [I|app|2847af18]   Rendered text template (Duration: 0.0ms | Allocations: 2)
2021-05-04T17:23:20 [I|app|2847af18] Completed 200 OK in 89ms (Views: 0.8ms | ActiveRecord: 32.5ms | Allocations: 15199)

And these come from Foreman 2.3.3 (the unupgraded VM I have running), I also included the same line in the scripting.

2021-05-05T11:27:43 [I|app|5896c9bb] Started GET "/unattended/iPXE?bootstrap=1&url=http%3A%2F%2Fforeman.lbhr.htm.lan%3A8000" for 127.0.0.1 at 2021-05-05 11:27:43 -0400
2021-05-05T11:27:43 [I|app|5896c9bb] Katello event daemon started process=2452
2021-05-05T11:27:43 [I|app|5896c9bb] Processing by UnattendedController#host_template as TEXT
2021-05-05T11:27:43 [I|app|5896c9bb]   Parameters: {"bootstrap"=>"1", "url"=>"http://foreman.lbhr.htm.lan:8000", "kind"=>"iPXE", "unattended"=>{}}
2021-05-05T11:27:44 [W|app|5896c9bb] #banana 
2021-05-05T11:27:44 [I|app|5896c9bb]   Rendering text template
2021-05-05T11:27:44 [I|app|5896c9bb]   Rendered text template (Duration: 0.0ms | Allocations: 4)
2021-05-05T11:27:44 [I|app|5896c9bb] Completed 200 OK in 432ms (Views: 13.8ms | ActiveRecord: 209.7ms | Allocations: 78626)
2021-05-05T11:27:44 [I|app|5896c9bb] Subscribed to katello.candlepin.candlepin_events
2021-05-05T11:27:44 [I|kat|5896c9bb] Polling Katello Event Queue

For completeness sake, this is all in my lab environment:

System info:
  hostname  : foreman.lbhr.htm.lan
  IP address: 192.168.255.15

I have 2 VMs with the same IP (I rotate between them by switching them on and off), one is running Foreman 2.3.3 on CentOS7 and the other is running Foreman 2.4 on CentOS8. Both are configured using Ansible and are AFAICT the same (except the obvious).

I’ll dig in the other method now :slight_smile:

11

So I enabled DEBUG logging on Foreman-proxy, which produces the following lines on each request:

Foreman 2.4:

2021-05-05T12:05:31 71c0b4d5 [I] Started GET /unattended/iPXE bootstrap=1
2021-05-05T12:05:31 71c0b4d5 [D] Template: request for unattended/iPXE using {"bootstrap"=>"1", "url"=>"http://foreman.lbhr.htm.lan:8000"} at foreman.lbhr.htm.lan
2021-05-05T12:05:31 71c0b4d5 [D] Retrieving a template from https://foreman.lbhr.htm.lan//unattended/iPXE?bootstrap=1&url=http%3A%2F%2Fforeman.lbhr.htm.lan%3A8000
2021-05-05T12:05:31 71c0b4d5 [D] HTTP headers: {"CONNECTION"=>"keep-alive", "USER_AGENT"=>"iPXE/1.20.1+ (g4bd0)", "X-Forwarded-For"=>"192.168.255.151, foreman.lbhr.htm.lan"}
2021-05-05T12:05:31 71c0b4d5 [I] Finished GET /unattended/iPXE with 200 (112.4 ms)

Foreman 2.3:

2021-05-05T12:15:23 a5c13976 [I] Started GET /unattended/iPXE bootstrap=1
2021-05-05T12:15:23 a5c13976 [D] Template: request for unattended/iPXE using {"bootstrap"=>"1", "url"=>"http://foreman.lbhr.htm.lan:8000"} at foreman.lbhr.htm.lan
2021-05-05T12:15:23 a5c13976 [D] Retrieving a template from https://foreman.lbhr.htm.lan//unattended/iPXE?bootstrap=1&url=http%3A%2F%2Fforeman.lbhr.htm.lan%3A8000
2021-05-05T12:15:23 a5c13976 [D] HTTP headers: {"CONNECTION"=>"keep-alive", "USER_AGENT"=>"iPXE/1.20.1+ (g4bd0)", "X-Forwarded-For"=>"192.168.255.154, foreman.lbhr.htm.lan"}
2021-05-05T12:15:23 a5c13976 [I] Finished GET /unattended/iPXE with 200 (416.47 ms)

And shortly after this, a second request (which makes sense)

2021-05-05T12:15:26 d0795d4c [I] Started GET /unattended/iPXE mac=82%3A96%3A86%3Acf%3A26%3A71
2021-05-05T12:15:26 d0795d4c [D] Template: request for unattended/iPXE using {"mac"=>"82:96:86:cf:26:71", "url"=>"http://foreman.lbhr.htm.lan:8000"} at foreman.lbhr.htm.lan
2021-05-05T12:15:26 d0795d4c [D] Retrieving a template from https://foreman.lbhr.htm.lan//unattended/iPXE?mac=82%3A96%3A86%3Acf%3A26%3A71&url=http%3A%2F%2Fforeman.lbhr.htm.lan%3A8000
2021-05-05T12:15:26 d0795d4c [D] HTTP headers: {"CONNECTION"=>"keep-alive", "USER_AGENT"=>"iPXE/1.20.1+ (g4bd0)", "X-Forwarded-For"=>"192.168.255.154, foreman.lbhr.htm.lan"}
2021-05-05T12:15:27 d0795d4c [I] Finished GET /unattended/iPXE with 200 (284.99 ms)

I also added the following to the load_host_details function:

logger.warn "mango #{query_params}"

Which prints the following on Foreman 2.4:

2021-05-05T12:07:42 [W|app|a6f512f0] mango {"bootstrap"=>"1", "url"=>"http://foreman.lbhr.htm.lan:8000", "format"=>"text", "controller"=>"unattended", "action"=>"host_template", "kind"=>"iPXE", "unattended"=>{}, "locale"=>nil, "ip"=>"192.168.255.15", "mac_list"=>[], "built"=>false}

And the following on Foreman 2.3:

2021-05-05T12:15:27 [W|app|1439d0c6] mango {"mac"=>"82:96:86:cf:26:71", "url"=>"http://foreman.lbhr.htm.lan:8000", "format"=>"text", "controller"=>"unattended", "action"=>"host_template", "kind"=>"iPXE", "unattended"=>{}, "locale"=>nil, "ip"=>"192.168.255.154, foreman.lbhr.htm.lan, 192.168.255.15", "mac_list"=>["82:96:86:cf:26:71"], "built"=>false}

So there is quite a bit of missing information in the request handled by Foreman 2.4.

Digging a bit futher into that, query_params[:mac_list] is derived from the request.env variable and that looks like this (rather big…):

2021-05-05T12:28:18 [W|app|abd70c47] mango request.env 
{
"rack.version"=>[1, 6], 
"rack.errors"=>#<IO:<STDERR>>, 
"rack.multithread"=>true, 
"rack.multiprocess"=>false, 
"rack.run_once"=>false, 
"SCRIPT_NAME"=>"", 
"QUERY_STRING"=>"bootstrap=1&url=http%3A%2F%2Fforeman.lbhr.htm.lan%3A8000", 
"SERVER_PROTOCOL"=>"HTTP/1.1", 
"SERVER_SOFTWARE"=>"puma 5.1.1 At Your Service", 
"GATEWAY_INTERFACE"=>"CGI/1.2", 
"REMOTE_ADDR"=>"127.0.0.1", 
"REQUEST_METHOD"=>"GET", 
"REQUEST_PATH"=>"/unattended/iPXE", 
"REQUEST_URI"=>"/unattended/iPXE?bootstrap=1&url=http%3A%2F%2Fforeman.lbhr.htm.lan%3A8000", 
"HTTP_VERSION"=>"HTTP/1.1", 
"HTTP_HOST"=>"foreman.lbhr.htm.lan", 
"HTTP_ACCEPT_ENCODING"=>"gzip;q=1.0,deflate;q=0.6,identity;q=0.3", 
"HTTP_ACCEPT"=>"*/*, application/json,version=2", 
"HTTP_USER_AGENT"=>"iPXE/1.20.1+ (g4bd0)", 
"CONTENT_TYPE"=>"application/json", 
"HTTP_X_FORWARDED_FOR"=>"192.168.255.151, foreman.lbhr.htm.lan, 192.168.255.15", 
"HTTP_VIA"=>"1.1 foreman.lbhr.htm.lan", 
"HTTP_X_FORWARDED_HOST"=>"foreman.lbhr.htm.lan", 
"HTTP_X_FORWARDED_SERVER"=>"foreman.lbhr.htm.lan", 
"HTTP_CONNECTION"=>"Keep-Alive", "puma.request_body_wait"=>0, 
"SERVER_NAME"=>"foreman.lbhr.htm.lan", 
"SERVER_PORT"=>"80", 
"PATH_INFO"=>"/unattended/iPXE", 
"puma.socket"=>#<TCPSocket:fd 25, AF_UNIX, localhost, /run/foreman.sock>, 
"rack.hijack?"=>true, 
"rack.hijack"=>#<Puma::Client:0x2b0062c2c06c @ready=true>, 
"rack.input"=>#<Puma::NullIO:0x00005600c24c5798>, "rack.url_scheme"=>"http", 
"HTTP_X_FORWARDED_PROTO"=>"https", 
"HTTP_SSL_CLIENT_S_DN"=>"CN=foreman.lbhr.htm.lan,OU=FOREMAN_PROXY,O=FOREMAN,ST=North Carolina,C=US", 
"HTTP_SSL_CLIENT_CERT"=>"-----BEGIN CERTIFICATE----- -----END CERTIFICATE-----", 
"HTTP_SSL_CLIENT_VERIFY"=>"SUCCESS", 
"rack.after_reply"=>[], 
"puma.config"=> trimmed
"action_dispatch.http_auth_salt"=>"http authentication", "action_dispatch.signed_cookie_salt"=>"signed cookie", "action_dispatch.encrypted_cookie_salt"=>"encrypted cookie", 
"action_dispatch.encrypted_signed_cookie_salt"=>"signed encrypted cookie", 
"action_dispatch.authenticated_encrypted_cookie_salt"=>"authenticated encrypted cookie", 
"action_dispatch.use_authenticated_cookie_encryption"=>false, 
"action_dispatch.encrypted_cookie_cipher"=>nil, "action_dispatch.signed_cookie_digest"=>nil, 
"action_dispatch.cookies_serializer"=>nil, "action_dispatch.cookies_digest"=>nil, 
"action_dispatch.cookies_rotations"=>#<ActiveSupport::Messages::RotationConfiguration:0x00005600b29c23a0 @signed=[], @encrypted=[]>, 
"action_dispatch.use_cookies_with_metadata"=>false, "action_dispatch.content_security_policy"=>nil, 
"action_dispatch.content_security_policy_report_only"=>false, 
"action_dispatch.content_security_policy_nonce_generator"=>nil, 
"action_dispatch.content_security_policy_nonce_directives"=>nil, "action_dispatch.routes"=>#<ActionDispatch::Routing::RouteSet:0x00005600b8949eb8>, 
"ROUTES_47280548368220_SCRIPT_NAME"=>"", 
"ORIGINAL_FULLPATH"=>"/unattended/iPXE?bootstrap=1&url=http%3A%2F%2Fforeman.lbhr.htm.lan%3A8000", 
"ORIGINAL_SCRIPT_NAME"=>"", 
... trimmed a lot of what seemed related to what is above here ... 
"action_dispatch.request.parameters"=>
{"bootstrap"=>"1", 
"url"=>"http://foreman.lbhr.htm.lan:8000", 
"format"=>"text",
"controller"=>"unattended",
"action"=>"host_template", 
"kind"=>"iPXE", 
"unattended"=>{}}, 
"action_dispatch.request.formats"=>[#<Mime::Type:0x00005600b4cc8fc0 @synonyms=[], @symbol=:text, @string="text/plain", @hash=-282735470319125783>], 
"action_dispatch.cookies"=>#<ActionDispatch::Cookies::CookieJar:0x00007fac846876c0 @set_cookies={}, @delete_cookies={}, @request=#<ActionDispatch::Request:0x00007fac844b3ad8 @env={...}, @filtered_parameters={"bootstrap"=>"1", 
"url"=>"http://foreman.lbhr.htm.lan:8000", 
"format"=>"text", 
"controller"=>"unattended", 
"action"=>"host_template", 
"kind"=>"iPXE", 
"unattended"=>{}}, @filtered_env=nil, @filtered_path=nil, @protocol=nil, @port=nil, @method=nil, @request_method="GET", @remote_ip="192.168.255.15", @original_fullpath=nil, @fullpath="/unattended/iPXE?bootstrap=1&url=http%3A%2F%2Fforeman.lbhr.htm.lan%3A8000", @ip=nil, @headers=#<ActionDispatch::Http::Headers:0x00007fac844c1c28 @req=#<ActionDispatch::Request:0x00007fac844b3ad8 ...>>>, @cookies={}, @committed=false>, "rack.session.record"=>#<ActiveRecord::SessionStore::Session id: 2097, session_id: "dc4ec97748482b4f85fb91773192476a", data: "BAh7AA==\n", created_at: "2021-05-05 16:28:18", updated_at: "2021-05-05 16:28:18">}
12

This is likely the culprit. Do you happen have a reverse proxy in front of Apache? See Foreman :: Manual

This reminds me, we should really add that as an installer option now.

1 Like
13

Sadly no, I installed this using the new foreman.operations.installer role, I ran it with the following, mostly default, options:

- name: 'Set versions'
  set_fact:
    foreman_repositories_version: 2.4
    foreman_repositories_katello_version: 4.0
    foreman_installer_package: 'foreman-installer-katello'
    foreman_installer_scenario: 'katello'

- name: 'Set installer options'
  set_fact:
    foreman_installer_options:
      - "--foreman-initial-admin-password {{ foreman_admin_password | quote }}"`

# Some other steps to setup repos, but those are not relevant now

- name: 'Run Foreman/Katello installer'
  include_role:
    name: 'theforeman.operations.installer'

The full playbook is here: ansible-role-foreman/install_foreman.yml at foreman_24_katello_4 · Thulium-Drake/ansible-role-foreman · GitHub

14

Is this an answer to Ewoud question? Because I was gonna ask the same.

The unattended controller tries to find a host via REMOTE_IP from Rails stack which also takes X-Forwarded-For headers into consideration.

One thing that looks like a bug is this line:

if @host.nil? && params[:bootstrap]

I think it should be:

if params[:bootstrap]

because the bootstap parameter should take precedence over a host found in the database, which can be actually the HTTP proxy host. For bootstrap there is no MAC so the controller fallsback to IP, if you do this change that could help your use case.

If you confirm, file an issue and we have a nice bugfix :slight_smile:

15

Well it certainly fixes something!

So booting a unknown machine works, these are the log entries in /var/log/foreman/production.log:

2021-05-06T19:03:45 [I|app|1b1973d5] Started GET "/unattended/iPXE?bootstrap=1&url=http%3A%2F%2Fforeman.lbhr.htm.lan%3A8000" for 192.168.255.15 at 2021-05-06 19:03:45 -0400
2021-05-06T19:03:45 [I|app|1b1973d5] Processing by UnattendedController#host_template as TEXT
2021-05-06T19:03:45 [I|app|1b1973d5]   Parameters: {"bootstrap"=>"1", "url"=>"http://foreman.lbhr.htm.lan:8000", "kind"=>"iPXE", "unattended"=>{}}
2021-05-06T19:03:45 [W|app|1b1973d5] #banana foreman.lbhr.htm.lan
2021-05-06T19:03:45 [W|app|1b1973d5] Could not find a provider for foreman.lbhr.htm.lan. Providers returned {"Katello::ManagedContentMediumProvider"=>["Kickstart repository was not set for host 'foreman.lbhr.htm.lan'", "Content source was not set for host 'foreman.lbhr.htm.lan'"], "MediumProviders::Default"=>["CentOS 8.2.2004 medium was not set for host 'foreman.lbhr.htm.lan'", "Invalid medium '' for 'CentOS 8.2.2004'"]}
2021-05-06T19:03:45 [I|app|1b1973d5]   Rendering text template
2021-05-06T19:03:45 [I|app|1b1973d5]   Rendered text template (Duration: 0.0ms | Allocations: 3)
2021-05-06T19:03:45 [I|app|1b1973d5] Completed 200 OK in 68ms (Views: 0.8ms | ActiveRecord: 22.4ms | Allocations: 33663)
2021-05-06T19:03:49 [I|app|e6b11323] Started GET "/unattended/iPXE?mac=82%3A96%3A86%3Acf%3A26%3A71&url=http%3A%2F%2Fforeman.lbhr.htm.lan%3A8000" for 192.168.255.15 at 2021-05-06 19:03:49 -0400
2021-05-06T19:03:49 [I|app|e6b11323] Processing by UnattendedController#host_template as TEXT
2021-05-06T19:03:49 [I|app|e6b11323]   Parameters: {"mac"=>"82:96:86:cf:26:71", "url"=>"http://foreman.lbhr.htm.lan:8000", "kind"=>"iPXE", "unattended"=>{}}
2021-05-06T19:03:49 [W|app|e6b11323] #banana 
2021-05-06T19:03:49 [I|app|e6b11323]   Rendering text template
2021-05-06T19:03:49 [I|app|e6b11323]   Rendered text template (Duration: 0.0ms | Allocations: 2)
2021-05-06T19:03:49 [I|app|e6b11323] Completed 200 OK in 31ms (Views: 0.7ms | ActiveRecord: 6.8ms | Allocations: 8202)

The VM successfully boots the FDI, gets registered in Foreman and can be set up to install itself with an OS.

However, something weird happens after I have installed CentOS7 on it (there’s also something odd in the setup itself, but it seems only cosmetic, I’ll investigate that later).

So after installing, the system still wants to do PXE boot, however, the template provided to the system doesn’t really work:

image
image713×264 5.08 KB

It will boot, eventually, but it takes longer then it needs to. So it’s not a problem, but I’d still consider it a regression. As the boot up in Foreman 2.3.3 is so fast I can’t even screenshot it :slight_smile:

16

Forgot to add these… :

2021-05-06T19:50:32 [I|app|6822739b] Started GET "/unattended/iPXE?bootstrap=1&url=http%3A%2F%2Fforeman.lbhr.htm.lan%3A8000" for 192.168.255.15 at 2021-05-06 19:50:32 -0400
2021-05-06T19:50:32 [I|app|6822739b] Processing by UnattendedController#host_template as TEXT
2021-05-06T19:50:32 [I|app|6822739b]   Parameters: {"bootstrap"=>"1", "url"=>"http://foreman.lbhr.htm.lan:8000", "kind"=>"iPXE", "unattended"=>{}}
2021-05-06T19:50:32 [W|app|6822739b] #banana foreman.lbhr.htm.lan
2021-05-06T19:50:32 [W|app|6822739b] Could not find a provider for foreman.lbhr.htm.lan. Providers returned {"Katello::ManagedContentMediumProvider"=>["Kickstart repository was not set for host 'foreman.lbhr.htm.lan'", "Content source was not set for host 'foreman.lbhr.htm.lan'"], "MediumProviders::Default"=>["CentOS 8.2.2004 medium was not set for host 'foreman.lbhr.htm.lan'", "Invalid medium '' for 'CentOS 8.2.2004'"]}
2021-05-06T19:50:32 [I|app|6822739b]   Rendering text template
2021-05-06T19:50:32 [I|app|6822739b]   Rendered text template (Duration: 0.0ms | Allocations: 3)
2021-05-06T19:50:32 [I|app|6822739b] Completed 200 OK in 83ms (Views: 0.7ms | ActiveRecord: 25.0ms | Allocations: 33426)
2021-05-06T19:50:35 [I|app|cb304c2f] Started GET "/unattended/iPXE?mac=82%3A96%3A86%3Acf%3A26%3A71&url=http%3A%2F%2Fforeman.lbhr.htm.lan%3A8000" for 192.168.255.15 at 2021-05-06 19:50:35 -0400
2021-05-06T19:50:35 [I|app|cb304c2f] Processing by UnattendedController#host_template as TEXT
2021-05-06T19:50:35 [I|app|cb304c2f]   Parameters: {"mac"=>"82:96:86:cf:26:71", "url"=>"http://foreman.lbhr.htm.lan:8000", "kind"=>"iPXE", "unattended"=>{}}
2021-05-06T19:50:35 [W|app|cb304c2f] #banana mac829686cf2671.lbhr.htm.lan
2021-05-06T19:50:35 [I|app|cb304c2f]   Rendering text template
2021-05-06T19:50:35 [I|app|cb304c2f]   Rendered text template (Duration: 0.0ms | Allocations: 4)
2021-05-06T19:50:35 [I|app|cb304c2f] Completed 200 OK in 179ms (Views: 2.0ms | ActiveRecord: 44.5ms | Allocations: 62973)

Just a check, this is basically the ‘false’ rendered by the controller, right?
As the host at the second attempt is:

  • not empty
  • does not have the build flag set

And as the fix you suggested does work for the most important part, this is how the function now looks on my system (I removed the debugging stuff)

  def render_ipxe_template
    return false unless ipxe_request?

    if params[:bootstrap]
      render_intermediate_template
      return true
    end

    if @host.nil?
      render_default_global_template
      return true
    end

    unless @host.try(:build?)
      render_local_boot_template
      return true
    end

    false
  end
17

Let me describe how this should work:

  • A host request a iPXE with boostrap option, Foreman reply with the bootstrap template (same for all hosts).
  • The host reads it and makes another call now with iPXE?mac=MAC_ADDRESS. It should loop this for every single NIC adapter available.
  • If Foreman find a host with NIC, it returns its iPXE template (associated with the host) if in build mode.
  • If the host is not in build mode it returns local boot template (same for all hosts).
  • If host is not found, then it returns global template (same for all hosts).

Now, the first step looks good in your case. However immediately after that I see a request /unattended/iPXE without any mac= argument. This is not correct, can you investigate what is in your intermediate template? You should see something like this:

See it rendered, it uses foreman_url which received some changes in argument handling recently. Maybe this renders incorrectly. When I render it with nightly it looks okay to me:

https://gist.github.com/lzap/7488b7f09da914c23301a87d3ca67c3d

Oh in the screenshot I did not see mac argument, however in the log paste I do see it. Let’s continue then.

If you enabled debug mode, we would see more details I am pretty sure there are some “found host XYZ” messages. Now I think I see a bug there.

The second statement in the method only tests on host presence: @host.nil?. If you have a server with multiple NICs and the first NIC is not the one that is active, the first query could actually resolve to @host being nil, Foreman should skip it returning 404 which makes the bootstrap script to continue the loop. But the current code, which has been recently (2.1/2.3) changed does return global template. This is incorrect.

Here is a patch that should correct this, multiple mistakes were made:

18

This is what I do think is the problem. Note how it recognizes 192.168.255.15. Then if we remember this line:

That indicates it should really use 192.168.255.151. It doesn’t recognize that 192.168.255.15 is a valid reverse proxy. That means it detects the remote IP incorrectly.

Can you try adding this to /etc/foreman/settings.yaml:

---
# ... existing config
:trusted_proxies:
  - "127.0.0.0/8"
  - "::1"
  - "192.168.255.15"

Then run systemctl restart foreman and try again.

19

Hmmm then I think how better we could this communicate to users? This is such pain to figure out.

20

Thanks for the explanation! :slight_smile:

@lzap So to dig into the templates I used a known and a different, unknown VM:

The intermediate looks good on both:

#!ipxe
# Intermediate iPXE script to report MAC address to Foreman

:net0
isset ${net0/mac} || goto no_nic
dhcp net0 || goto net1
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net0/mac} || goto net1

:net1
isset ${net1/mac} || goto no_nic
dhcp net1 || goto net2
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net1/mac} || goto net2

:net2
isset ${net2/mac} || goto no_nic
dhcp net2 || goto net3
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net2/mac} || goto net3

:net3
isset ${net3/mac} || goto no_nic
dhcp net3 || goto net4
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net3/mac} || goto net4

:net4
isset ${net4/mac} || goto no_nic
dhcp net4 || goto net5
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net4/mac} || goto net5

:net5
isset ${net5/mac} || goto no_nic
dhcp net5 || goto net6
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net5/mac} || goto net6

:net6
isset ${net6/mac} || goto no_nic
dhcp net6 || goto net7
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net6/mac} || goto net7

:net7
isset ${net7/mac} || goto no_nic
dhcp net7 || goto net8
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net7/mac} || goto net8

:net8
isset ${net8/mac} || goto no_nic
dhcp net8 || goto net9
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net8/mac} || goto net9

:net9
isset ${net9/mac} || goto no_nic
dhcp net9 || goto net10
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net9/mac} || goto net10

:net10
isset ${net10/mac} || goto no_nic
dhcp net10 || goto net11
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net10/mac} || goto net11

:net11
isset ${net11/mac} || goto no_nic
dhcp net11 || goto net12
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net11/mac} || goto net12

:net12
isset ${net12/mac} || goto no_nic
dhcp net12 || goto net13
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net12/mac} || goto net13

:net13
isset ${net13/mac} || goto no_nic
dhcp net13 || goto net14
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net13/mac} || goto net14

:net14
isset ${net14/mac} || goto no_nic
dhcp net14 || goto net15
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net14/mac} || goto net15

:net15
isset ${net15/mac} || goto no_nic
dhcp net15 || goto net16
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net15/mac} || goto net16

:net16
isset ${net16/mac} || goto no_nic
dhcp net16 || goto net17
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net16/mac} || goto net17

:net17
isset ${net17/mac} || goto no_nic
dhcp net17 || goto net18
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net17/mac} || goto net18

:net18
isset ${net18/mac} || goto no_nic
dhcp net18 || goto net19
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net18/mac} || goto net19

:net19
isset ${net19/mac} || goto no_nic
dhcp net19 || goto net20
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net19/mac} || goto net20

:net20
isset ${net20/mac} || goto no_nic
dhcp net20 || goto net21
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net20/mac} || goto net21

:net21
isset ${net21/mac} || goto no_nic
dhcp net21 || goto net22
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net21/mac} || goto net22

:net22
isset ${net22/mac} || goto no_nic
dhcp net22 || goto net23
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net22/mac} || goto net23

:net23
isset ${net23/mac} || goto no_nic
dhcp net23 || goto net24
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net23/mac} || goto net24

:net24
isset ${net24/mac} || goto no_nic
dhcp net24 || goto net25
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net24/mac} || goto net25

:net25
isset ${net25/mac} || goto no_nic
dhcp net25 || goto net26
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net25/mac} || goto net26

:net26
isset ${net26/mac} || goto no_nic
dhcp net26 || goto net27
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net26/mac} || goto net27

:net27
isset ${net27/mac} || goto no_nic
dhcp net27 || goto net28
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net27/mac} || goto net28

:net28
isset ${net28/mac} || goto no_nic
dhcp net28 || goto net29
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net28/mac} || goto net29

:net29
isset ${net29/mac} || goto no_nic
dhcp net29 || goto net30
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net29/mac} || goto net30

:net30
isset ${net30/mac} || goto no_nic
dhcp net30 || goto net31
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net30/mac} || goto net31

:net31
isset ${net31/mac} || goto no_nic
dhcp net31 || goto net32
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net31/mac} || goto net32

:net32
isset ${net32/mac} || goto no_nic
dhcp net32 || goto net33
chain http://foreman.lbhr.htm.lan:8000/unattended/iPXE?mac=${net32/mac} || goto net33

:net33
goto no_nic

exit 0

:no_nic
echo Failed to chainload from any network interface
sleep 30
exit 1

So far, so good.

For the unkown VM, when I call the URL mentioned in the template (but I set the MAC myself) it looks like this:

#!ipxe

echo Opening global default menu in 5 seconds...
sleep 5

set menu-default discovery
set menu-timeout 5000
set port 8448

:start
menu iPXE global boot menu
item --key l local     Local boot (next entry)
item shell             Drop into iPXE shell
item reboot            Reboot system
item
item --key d discovery Discovery from ${next-server}:8000 (httpboot module)
item discovery_custom Discovery from ${next-server}:${port} (httpboot module)
choose --timeout ${menu-timeout} --default ${menu-default} selected || goto cancel
set menu-timeout 0
goto ${selected}

:cancel
echo Menu canceled, dropping to shell

:shell
echo Use the command 'exit' to return to menu
shell
set menu-timeout 0
goto start

:failed
echo Boot failed, dropping to shell
goto shell

:reboot
reboot

:local
exit 1

:discovery
dhcp
kernel http://${next-server}:8000/httpboot/boot/fdi-image/vmlinuz0 initrd=initrd0.img rootflags=loop root=live:/fdi.iso rootfstype=auto ro rd.live.image acpi=force rd.luks=0 rd.md=0 rd.dm=0 rd.lvm=0 rd.bootif=0 rd.neednet=0 nomodeset nokaslr proxy.type=foreman BOOTIF=01-${net0/mac} fdi.countdown=10
initrd http://${next-server}:8000/httpboot/boot/fdi-image/initrd0.img
imgstat
sleep 2
boot || goto failed
goto start

:discovery_custom
dhcp
kernel http://${next-server}:${port}/httpboot/boot/fdi-image/vmlinuz0 initrd=initrd0.img rootflags=loop root=live:/fdi.iso rootfstype=auto ro rd.live.image acpi=force rd.luks=0 rd.md=0 rd.dm=0 rd.lvm=0 rd.bootif=0 rd.neednet=0 nomodeset nokaslr proxy.type=foreman BOOTIF=01-${net0/mac} fdi.countdown=10
initrd http://${next-server}:${port}/httpboot/boot/fdi-image/initrd0.img
imgstat
sleep 2
boot || goto failed

And for the known VM like this:

#!ipxe

# Skips booting from network and continues booting from next device
exit 1

This is the corresponding /var/log/foreman-proxy/proxy.log for the unknown VM:

2021-05-08T05:21:47 5138cea0 [I] Started GET /unattended/iPXE bootstrap=1
2021-05-08T05:21:47 5138cea0 [D] Template: request for unattended/iPXE using {"bootstrap"=>"1", "url"=>"http://foreman.lbhr.htm.lan:8000"} at foreman.lbhr.htm.lan
2021-05-08T05:21:47 5138cea0 [D] Retrieving a template from https://foreman.lbhr.htm.lan//unattended/iPXE?bootstrap=1&url=http%3A%2F%2Fforeman.lbhr.htm.lan%3A8000
2021-05-08T05:21:47 5138cea0 [D] HTTP headers: {"USER_AGENT"=>"curl/7.64.0", "ACCEPT"=>"*/*", "X-Forwarded-For"=>"192.168.255.11, foreman.lbhr.htm.lan"}
2021-05-08T05:21:48 5138cea0 [I] Finished GET /unattended/iPXE with 200 (82.77 ms)
2021-05-08T05:22:20  [D] Starting allocated ip addresses cleanup pass...
2021-05-08T05:23:20  [D] Starting allocated ip addresses cleanup pass...
2021-05-08T05:24:20  [D] Starting allocated ip addresses cleanup pass...
2021-05-08T05:24:22 e772d329 [I] Started GET /unattended/iPXE mac=52:d6:61:a8:05:b1
2021-05-08T05:24:22 e772d329 [D] Template: request for unattended/iPXE using {"mac"=>"52:d6:61:a8:05:b1", "url"=>"http://foreman.lbhr.htm.lan:8000"} at foreman.lbhr.htm.lan
2021-05-08T05:24:22 e772d329 [D] Retrieving a template from https://foreman.lbhr.htm.lan//unattended/iPXE?mac=52%3Ad6%3A61%3Aa8%3A05%3Ab1&url=http%3A%2F%2Fforeman.lbhr.htm.lan%3A8000
2021-05-08T05:24:22 e772d329 [D] HTTP headers: {"USER_AGENT"=>"curl/7.64.0", "ACCEPT"=>"*/*", "X-Forwarded-For"=>"192.168.255.11, foreman.lbhr.htm.lan"}
2021-05-08T05:24:22 e772d329 [I] Finished GET /unattended/iPXE with 200 (69.94 ms)

And this is /var/log/foreman/production.log for the unknown VM:

2021-05-08T05:21:48 [I|app|c2d043f0] Started GET "/unattended/iPXE?bootstrap=1&url=http%3A%2F%2Fforeman.lbhr.htm.lan%3A8000" for 192.168.255.15 at 2021-05-08 05:21:48 -0400
2021-05-08T05:21:48 [I|app|c2d043f0] Processing by UnattendedController#host_template as TEXT
2021-05-08T05:21:48 [I|app|c2d043f0]   Parameters: {"bootstrap"=>"1", "url"=>"http://foreman.lbhr.htm.lan:8000", "kind"=>"iPXE", "unattended"=>{}}
2021-05-08T05:21:48 [W|app|c2d043f0] Could not find a provider for foreman.lbhr.htm.lan. Providers returned {"Katello::ManagedContentMediumProvider"=>["Kickstart repository was not set for host 'foreman.lbhr.htm.lan'", "Content source was not set for host 'foreman.lbhr.htm.lan'"], "MediumProviders::Default"=>["CentOS 8.2.2004 medium was not set for host 'foreman.lbhr.htm.lan'", "Invalid medium '' for 'CentOS 8.2.2004'"]}
2021-05-08T05:21:48 [I|app|c2d043f0]   Rendering text template
2021-05-08T05:21:48 [I|app|c2d043f0]   Rendered text template (Duration: 0.0ms | Allocations: 3)
2021-05-08T05:21:48 [I|app|c2d043f0] Completed 200 OK in 51ms (Views: 0.5ms | ActiveRecord: 7.3ms | Allocations: 33580)
2021-05-08T05:24:22 [I|app|442d7285] Started GET "/unattended/iPXE?mac=52%3Ad6%3A61%3Aa8%3A05%3Ab1&url=http%3A%2F%2Fforeman.lbhr.htm.lan%3A8000" for 192.168.255.15 at 2021-05-08 05:24:22 -0400
2021-05-08T05:24:22 [I|app|442d7285] Processing by UnattendedController#host_template as TEXT
2021-05-08T05:24:22 [I|app|442d7285]   Parameters: {"mac"=>"52:d6:61:a8:05:b1", "url"=>"http://foreman.lbhr.htm.lan:8000", "kind"=>"iPXE", "unattended"=>{}}
2021-05-08T05:24:22 [I|app|442d7285]   Rendering text template
2021-05-08T05:24:22 [I|app|442d7285]   Rendered text template (Duration: 0.0ms | Allocations: 3)
2021-05-08T05:24:22 [I|app|442d7285] Completed 200 OK in 40ms (Views: 0.7ms | ActiveRecord: 18.0ms | Allocations: 11504)

This is the corresponding /var/log/foreman-proxy/proxy.log for the known VM:

2021-05-08T05:30:44 300144df [I] Started GET /unattended/iPXE bootstrap=1
2021-05-08T05:30:44 300144df [D] Template: request for unattended/iPXE using {"bootstrap"=>"1", "url"=>"http://foreman.lbhr.htm.lan:8000"} at foreman.lbhr.htm.lan
2021-05-08T05:30:44 300144df [D] Retrieving a template from https://foreman.lbhr.htm.lan//unattended/iPXE?bootstrap=1&url=http%3A%2F%2Fforeman.lbhr.htm.lan%3A8000
2021-05-08T05:30:44 300144df [D] HTTP headers: {"USER_AGENT"=>"curl/7.29.0", "ACCEPT"=>"*/*", "X-Forwarded-For"=>"192.168.255.152, foreman.lbhr.htm.lan"}
2021-05-08T05:30:44 300144df [I] Finished GET /unattended/iPXE with 200 (80.43 ms)
2021-05-08T05:30:59 eecfe533 [I] Started GET /unattended/iPXE mac=82:96:86:cf:26:71
2021-05-08T05:30:59 eecfe533 [D] Template: request for unattended/iPXE using {"mac"=>"82:96:86:cf:26:71", "url"=>"http://foreman.lbhr.htm.lan:8000"} at foreman.lbhr.htm.lan
2021-05-08T05:30:59 eecfe533 [D] Retrieving a template from https://foreman.lbhr.htm.lan//unattended/iPXE?mac=82%3A96%3A86%3Acf%3A26%3A71&url=http%3A%2F%2Fforeman.lbhr.htm.lan%3A8000
2021-05-08T05:30:59 eecfe533 [D] HTTP headers: {"USER_AGENT"=>"curl/7.29.0", "ACCEPT"=>"*/*", "X-Forwarded-For"=>"192.168.255.152, foreman.lbhr.htm.lan"}
2021-05-08T05:30:59 eecfe533 [I] Finished GET /unattended/iPXE with 200 (129.11 ms)

And this is /var/log/foreman/production.log for the known VM:

2021-05-08T05:30:44 [I|app|e7103b1c] Started GET "/unattended/iPXE?bootstrap=1&url=http%3A%2F%2Fforeman.lbhr.htm.lan%3A8000" for 192.168.255.15 at 2021-05-08 05:30:44 -0400
2021-05-08T05:30:44 [I|app|e7103b1c] Processing by UnattendedController#host_template as TEXT
2021-05-08T05:30:44 [I|app|e7103b1c]   Parameters: {"bootstrap"=>"1", "url"=>"http://foreman.lbhr.htm.lan:8000", "kind"=>"iPXE", "unattended"=>{}}
2021-05-08T05:30:44 [W|app|e7103b1c] Could not find a provider for foreman.lbhr.htm.lan. Providers returned {"Katello::ManagedContentMediumProvider"=>["Kickstart repository was not set for host 'foreman.lbhr.htm.lan'", "Content source was not set for host 'foreman.lbhr.htm.lan'"], "MediumProviders::Default"=>["CentOS 8.2.2004 medium was not set for host 'foreman.lbhr.htm.lan'", "Invalid medium '' for 'CentOS 8.2.2004'"]}
2021-05-08T05:30:44 [I|app|e7103b1c]   Rendering text template
2021-05-08T05:30:44 [I|app|e7103b1c]   Rendered text template (Duration: 0.0ms | Allocations: 3)
2021-05-08T05:30:44 [I|app|e7103b1c] Completed 200 OK in 48ms (Views: 0.5ms | ActiveRecord: 6.7ms | Allocations: 33546)
2021-05-08T05:30:59 [I|app|9228e5d3] Started GET "/unattended/iPXE?mac=82%3A96%3A86%3Acf%3A26%3A71&url=http%3A%2F%2Fforeman.lbhr.htm.lan%3A8000" for 192.168.255.15 at 2021-05-08 05:30:59 -0400
2021-05-08T05:30:59 [I|app|9228e5d3] Processing by UnattendedController#host_template as TEXT
2021-05-08T05:30:59 [I|app|9228e5d3]   Parameters: {"mac"=>"82:96:86:cf:26:71", "url"=>"http://foreman.lbhr.htm.lan:8000", "kind"=>"iPXE", "unattended"=>{}}
2021-05-08T05:30:59 [I|app|9228e5d3]   Rendering text template
2021-05-08T05:30:59 [I|app|9228e5d3]   Rendered text template (Duration: 0.0ms | Allocations: 2)
2021-05-08T05:30:59 [I|app|9228e5d3] Completed 200 OK in 96ms (Views: 0.5ms | ActiveRecord: 28.8ms | Allocations: 25589)