Actions
Bug #38390
open
Creating RHEL-Host fails due to additional tasks being spawned: Rolling back due to a problem: []
Status:
Ready For Testing
Priority:
High
Assignee:
-
Category:
Host creation
Target version:
-
Description
We have a system running foreman-3.11.2 that fails to deploy RHEL9-hosts. It fails with empty error message though.
Through some printf-debugging we managed to analyze: while processing the host-creation queue, additional tasks are added to the queue.
This results in the guard-clause to be false (q.pending.empty?) and therefore rollbacking the tasks .
Deploying an Ubuntu host works just fine.
The request with additional log-messages can be found below, the state of my analyzation is as follows:
Theory: during execution of the host-create queue at some point (after the VSphere VM is created) something triggers a validation of the Host-object, which runs the queue_compute_update-method.
That method IMHO erroneously adds a setComputeUpdate-task to the queue because the compute-attribute returned from fog is a Proc and not the actual String:
cluster changed it's value from '#<Proc:0x0000564638929418 /usr/share/gems/gems/fog-vsphere-3.6.5/lib/fog/vsphere/compute.rb:236>' (Proc) to 'testcluster' (String)
Also two DHCP-tasks are triggered in the same way.
Is there any special handling for RedHat hosts in foreman itself or within a plugin that can cause this behavior?
Plugins installed:- foreman_virt_who_configure
- katello
- foreman_discovery
- foreman_bootdisk
- foreman_default_hostgroup
- foreman_ansible, foreman_puppet
- foreman_leapp
- foreman_templates
- foreman_webhooks
2025-04-24T16:19:38 [I|app|352b1df3] Started POST "/api/hosts" for 192.168.1.1 at 2025-04-24 16:19:38 +0200
2025-04-24T16:19:38 [I|app|352b1df3] Processing by Api::V2::HostsController#create as JSON
2025-04-24T16:19:38 [I|app|352b1df3] Parameters: {"location_id"=>2, "organization_id"=>3, "host"=>{"name"=>"rhel9", "location_id"=>2, "organization_id"=>3, "ip"=>"192.168.1.80", "domain_id"=>124, "operatingsystem_id"=>145, "medium_id"=>26, "ptable_id"=>68, "subnet_id"=>2, "compute_resource_id"=>1, "hostgroup_id"=>58, "enabled"=>true, "provision_method"=>"bootdisk", "compute_profile_id"=>12, "compute_attributes"=>{"start"=>"1", "annotation"=>"\"#something#\"", "path"=>"/Datacenters/Test", "volumes_attributes"=>{}}, "content_facet_attributes"=>{"content_view_id"=>74}, "subscription_facet_attributes"=>{}, "overwrite"=>true, "puppet_attributes"=>{}, "build"=>true, "managed"=>true, "interfaces_attributes"=>[], "root_pass"=>"[FILTERED]"}, "apiv"=>"v2"}
2025-04-24T16:19:39 [W|app|352b1df3] Scoped order is ignored, it's forced to be batch order.
2025-04-24T16:19:39 [W|app|352b1df3] q.all.count: 13
2025-04-24T16:19:39 [I|app|352b1df3] Processing task 'Set up compute instance rhel9.example.com' from 'Host::Managed Main'
2025-04-24T16:19:39 [I|app|352b1df3] Adding Compute instance for rhel9.example.com
2025-04-24T16:19:39 [I|app|352b1df3] Create VM with {"cpus"=>"2", "corespersocket"=>"1", "memory_mb"=>"4096", "firmware"=>"bios", "cluster"=>"testcluster", "resource_pool"=>"Resources", "path"=>"/Datacenters/Test", "guest_id"=>"rhel7_64Guest", "hardware_version"=>"Default", "memoryHotAddEnabled"=>"1", "cpuHotAddEnabled"=>"1", "add_cdrom"=>"0", "boot_order"=>["network", "disk"], "annotation"=>"\"#something#\"", "scsi_controllers"=>[{"type"=>"ParaVirtualSCSIController", "key"=>1000}], "volumes_attributes"=>{"0"=>{"thin"=>true, "name"=>"Hard disk", "mode"=>"persistent", "controller_key"=>1000, "size_gb"=>50, "storage_pod"=>"Netapp-NMCluster", "datastore"=>nil}}, "start"=>"1", "name"=>"rhel9.example.com", "provision_method"=>"bootdisk", "firmware_type"=>:bios, "interfaces_attributes"=>{"0"=>{"type"=>"VirtualVmxnet3", "network"=>"dvportgroup-342425", "from_profile"=>"profile1", "ip"=>"192.168.1.80", "ip6"=>nil, "virtualswitch"=>"EN123"}}}
2025-04-24T16:19:41 [W|app|352b1df3] q.all.count - Set up compute instance rhel9.example.com: 13
2025-04-24T16:19:41 [I|app|352b1df3] Processing task 'DHCP conflicts removal for rhel9.example.com' from 'Host::Managed Main'
2025-04-24T16:19:41 [W|app|352b1df3] q.all.count - DHCP conflicts removal for rhel9.example.com: 13
2025-04-24T16:19:41 [I|app|352b1df3] Processing task 'Query instance details for rhel9.example.com' from 'Host::Managed Main'
2025-04-24T16:19:41 [W|app|352b1df3] q.all.count - Query instance details for rhel9.example.com: 13
2025-04-24T16:19:41 [I|app|352b1df3] Processing task 'Generating ISO image for rhel9.example.com' from 'Host::Managed Main'
2025-04-24T16:19:41 [I|app|352b1df3] Generating FULL HOST ISO image for rhel9.example.com
2025-04-24T16:19:41 [W|app|352b1df3] Using TFTP Smart Proxy hostname as the boot server name: smartproxy.example.com
2025-04-24T16:19:41 [W|app|352b1df3] Scoped order is ignored, it's forced to be batch order.
2025-04-24T16:19:42 [I|app|352b1df3] Scheduling compute instance update because cluster changed it's value from '#<Proc:0x0000564638929418 /usr/share/gems/gems/fog-vsphere-3.6.5/lib/fog/vsphere/compute.rb:236>' (Proc) to 'testcluster' (String)
2025-04-24T16:19:42 [I|app|352b1df3] Detected a change is required for compute resource
2025-04-24T16:19:42 [I|for|352b1df3] Retrieved http://foreman.example.com/pulp/content/myorg/Library/content/dist/rhel9/9.1/x86_64/baseos/kickstart/images/pxeboot/vmlinuz from local cache (use foreman-rake tmp:cache:clear to empty)
2025-04-24T16:19:42 [I|for|352b1df3] Retrieved http://foreman.example.com/pulp/content/myorg/Library/content/dist/rhel9/9.1/x86_64/baseos/kickstart/images/pxeboot/initrd.img from local cache (use foreman-rake tmp:cache:clear to empty)
2025-04-24T16:19:43 [W|app|352b1df3] q.all.count - Generating ISO image for rhel9.example.com: 16
2025-04-24T16:19:43 [I|app|352b1df3] Processing task 'Upload ISO image to datastore for rhel9.example.com' from 'Host::Managed Main'
2025-04-24T16:19:43 [I|app|352b1df3] Uploading ISO image /tmp/d20250424-120655-238qcj/rhel9.example.com.iso for rhel9.example.com
2025-04-24T16:19:46 [W|app|352b1df3] q.all.count - Upload ISO image to datastore for rhel9.example.com: 16
2025-04-24T16:19:46 [I|app|352b1df3] Processing task 'Create DHCP Settings for rhel9.example.com' from 'Host::Managed Main'
2025-04-24T16:19:46 [I|app|352b1df3] Create DHCP reservation rhel9.example.com for rhel9.example.com-00:aa:bb:cc:dd:ee/192.168.1.80
2025-04-24T16:19:46 [W|app|352b1df3] q.all.count - Create DHCP Settings for rhel9.example.com: 16
2025-04-24T16:19:46 [I|app|352b1df3] Processing task 'Deploy TFTP PXELinux config for rhel9.example.com' from 'Host::Managed Main'
2025-04-24T16:19:47 [I|app|352b1df3] Deploying TFTP PXELinux configuration for rhel9.example.com
2025-04-24T16:19:47 [W|app|352b1df3] q.all.count - Deploy TFTP PXELinux config for rhel9.example.com: 16
2025-04-24T16:19:47 [I|app|352b1df3] Processing task 'Deploy TFTP PXEGrub2 config for rhel9.example.com' from 'Host::Managed Main'
2025-04-24T16:19:47 [I|app|352b1df3] Deploying TFTP PXEGrub2 configuration for rhel9.example.com
2025-04-24T16:19:47 [W|app|352b1df3] q.all.count - Deploy TFTP PXEGrub2 config for rhel9.example.com: 16
2025-04-24T16:19:47 [I|app|352b1df3] Processing task 'Deploy TFTP PXEGrub config for rhel9.example.com' from 'Host::Managed Main'
2025-04-24T16:19:47 [I|app|352b1df3] Deploying TFTP PXEGrub configuration for rhel9.example.com
2025-04-24T16:19:47 [W|app|352b1df3] q.all.count - Deploy TFTP PXEGrub config for rhel9.example.com: 16
2025-04-24T16:19:47 [I|app|352b1df3] Processing task 'Deploy TFTP iPXE config for rhel9.example.com' from 'Host::Managed Main'
2025-04-24T16:19:47 [I|app|352b1df3] Deploying TFTP iPXE configuration for rhel9.example.com
2025-04-24T16:19:47 [W|app|352b1df3] q.all.count - Deploy TFTP iPXE config for rhel9.example.com: 16
2025-04-24T16:19:47 [I|app|352b1df3] Processing task 'Fetch TFTP boot files for rhel9.example.com' from 'Host::Managed Main'
2025-04-24T16:19:47 [I|app|352b1df3] Fetching required TFTP boot files for rhel9.example.com
2025-04-24T16:19:47 [W|app|352b1df3] q.all.count - Fetch TFTP boot files for rhel9.example.com: 16
2025-04-24T16:19:47 [I|app|352b1df3] Processing task 'Power up compute instance rhel9.example.com' from 'Host::Managed Main'
2025-04-24T16:19:47 [I|app|352b1df3] Powering up Compute instance for rhel9.example.com
2025-04-24T16:19:48 [W|app|352b1df3] q.all.count - Power up compute instance rhel9.example.com: 16
2025-04-24T16:19:48 [I|app|352b1df3] Processing task 'Attach ISO image to CDROM drive for rhel9.example.com' from 'Host::Managed Main'
2025-04-24T16:19:48 [I|app|352b1df3] Attaching ISO image to CDROM drive for rhel9.example.com
2025-04-24T16:19:52 [W|app|352b1df3] q.all.count - Attach ISO image to CDROM drive for rhel9.example.com: 16
2025-04-24T16:19:52 [W|app|352b1df3] Rolling back due to a problem: []
2025-04-24T16:19:52 [W|app|352b1df3] orchestration_errors?= true
2025-04-24T16:19:52 [W|app|352b1df3] q.pending= [#<Orchestration::Task:0x00005646390ac8c0 @name="DHCP conflicts removal for rhel9.example.com", @id="dhcp_conflicts_remove_00:aa:bb:cc:dd:ee", @status="pending", @priority=5, @action=[#<Nic::Managed id: nil, mac: "00:aa:bb:cc:dd:ee", ip: "192.168.1.80", type: "Nic::Managed", name: "rhel9.example.com", host_id: nil, subnet_id: 2, domain_id: 124, attrs: {}, created_at: nil, updated_at: nil, provider: nil, username: nil, password: nil, virtual: false, link: true, identifier: nil, tag: "", attached_to: "", managed: true, mode: "balance-rr", attached_devices: "", bond_options: "", primary: true, provision: true, compute_attributes: {"type"=>"VirtualVmxnet3", "network"=>"dvportgroup-342425", "from_profile"=>"profile1"}, ip6: nil, subnet6_id: nil, execution: true>, :del_dhcp_conflicts], @created=1745504381.9402971, @timestamp=2025-04-24 14:19:41.940299898 UTC>, #<Orchestration::Task:0x00005646379f4f10 @name="Compute resource update for ", @id="Compute resource update for ", @status="pending", @priority=7, @action=[#<Host::Managed id: nil, name: "rhel9.example.com", last_compile: nil, last_report: nil, updated_at: nil, created_at: nil, root_pass: [FILTERED], architecture_id: 1, operatingsystem_id: 145, ptable_id: 68, medium_id: 26, build: true, comment: "", disk: nil, installed_at: nil, model_id: nil, hostgroup_id: 58, owner_id: 2, owner_type: "Usergroup", enabled: true, puppet_ca_proxy_id: 13, managed: true, use_image: nil, image_file: nil, uuid: "50014fff-0332-e6e1-ca39-d6b1c9f222f6", compute_resource_id: 1, puppet_proxy_id: 13, certname: nil, image_id: nil, organization_id: 3, location_id: 2, type: "Host::Managed", otp: nil, realm_id: nil, compute_profile_id: 12, provision_method: "bootdisk", grub_pass: nil, global_status: 0, lookup_value_matcher: [FILTERED], pxe_loader: "PXELinux BIOS", discovery_rule_id: nil, initiated_at: nil, build_errors: nil, creator_id: nil>, :setComputeUpdate], @created=1745504382.2001345, @timestamp=2025-04-24 14:19:42.200137555 UTC>, #<Orchestration::Task:0x00005646390ab1c8 @name="Create DHCP Settings for rhel9.example.com", @id="dhcp_create_00:aa:bb:cc:dd:ee", @status="pending", @priority=10, @action=[#<Nic::Managed id: nil, mac: "00:aa:bb:cc:dd:ee", ip: "192.168.1.80", type: "Nic::Managed", name: "rhel9.example.com", host_id: nil, subnet_id: 2, domain_id: 124, attrs: {}, created_at: nil, updated_at: nil, provider: nil, username: nil, password: nil, virtual: false, link: true, identifier: nil, tag: "", attached_to: "", managed: true, mode: "balance-rr", attached_devices: "", bond_options: "", primary: true, provision: true, compute_attributes: {"type"=>"VirtualVmxnet3", "network"=>"dvportgroup-342425", "from_profile"=>"profile1"}, ip6: nil, subnet6_id: nil, execution: true>, :set_dhcp], @created=1745504381.9404767, @timestamp=2025-04-24 14:19:41.940477676 UTC>]
2025-04-24T16:19:52 [I|app|352b1df3] Powering down Compute instance for rhel9.example.com
2025-04-24T16:19:52 [I|app|352b1df3] Delete the TFTP configuration for rhel9.example.com
2025-04-24T16:19:52 [I|app|352b1df3] Delete the TFTP configuration for rhel9.example.com
2025-04-24T16:19:52 [I|app|352b1df3] Delete the TFTP configuration for rhel9.example.com
2025-04-24T16:19:52 [I|app|352b1df3] Delete the TFTP configuration for rhel9.example.com
2025-04-24T16:19:52 [I|app|352b1df3] Delete DHCP reservation rhel9.example.com for rhel9.example.com-00:aa:bb:cc:dd:ee/192.168.1.80
2025-04-24T16:19:53 [I|app|352b1df3] Removing Compute instance for rhel9.example.com
2025-04-24T16:19:53 [I|app|352b1df3] Processed 13 tasks from queue 'Host::Managed Main', completed 0/16
2025-04-24T16:19:53 [E|app|352b1df3] Task 'Set up compute instance rhel9.example.com' *rollbacked*
2025-04-24T16:19:53 [E|app|352b1df3] Task 'DHCP conflicts removal for rhel9.example.com' *rollbacked*
2025-04-24T16:19:53 [E|app|352b1df3] Task 'Query instance details for rhel9.example.com' *rollbacked*
2025-04-24T16:19:53 [E|app|352b1df3] Task 'Generating ISO image for rhel9.example.com' *rollbacked*
2025-04-24T16:19:53 [E|app|352b1df3] Task 'DHCP conflicts removal for rhel9.example.com' *canceled*
2025-04-24T16:19:53 [E|app|352b1df3] Task 'Upload ISO image to datastore for rhel9.example.com' *rollbacked*
2025-04-24T16:19:53 [E|app|352b1df3] Task 'Compute resource update for ' *canceled*
2025-04-24T16:19:53 [E|app|352b1df3] Task 'Create DHCP Settings for rhel9.example.com' *rollbacked*
2025-04-24T16:19:53 [E|app|352b1df3] Task 'Create DHCP Settings for rhel9.example.com' *canceled*
2025-04-24T16:19:53 [E|app|352b1df3] Task 'Deploy TFTP PXELinux config for rhel9.example.com' *rollbacked*
2025-04-24T16:19:53 [E|app|352b1df3] Task 'Deploy TFTP PXEGrub2 config for rhel9.example.com' *rollbacked*
2025-04-24T16:19:53 [E|app|352b1df3] Task 'Deploy TFTP PXEGrub config for rhel9.example.com' *rollbacked*
2025-04-24T16:19:53 [E|app|352b1df3] Task 'Deploy TFTP iPXE config for rhel9.example.com' *rollbacked*
2025-04-24T16:19:53 [E|app|352b1df3] Task 'Fetch TFTP boot files for rhel9.example.com' *rollbacked*
2025-04-24T16:19:53 [E|app|352b1df3] Task 'Power up compute instance rhel9.example.com' *rollbacked*
2025-04-24T16:19:53 [E|app|352b1df3] Task 'Attach ISO image to CDROM drive for rhel9.example.com' *rollbacked*
2025-04-24T16:19:53 [W|app|352b1df3] Action failed
2025-04-24T16:19:53 [I|app|352b1df3] Backtrace for 'Action failed' error (RuntimeError): resource have no errors
352b1df3 | /usr/share/foreman/app/controllers/api/base_controller.rb:155:in `process_resource_error'
352b1df3 | /usr/share/foreman/app/controllers/api/base_controller.rb:175:in `process_response'
352b1df3 | /usr/share/foreman/app/controllers/api/v2/hosts_controller.rb:148:in `create'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/abstract_controller/base.rb:228:in `process_action'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_controller/metal/rendering.rb:30:in `process_action'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/abstract_controller/callbacks.rb:42:in `block in process_action'
352b1df3 | /usr/share/gems/gems/activesupport-6.1.7.8/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
352b1df3 | /usr/share/foreman/app/controllers/concerns/foreman/controller/timezone.rb:10:in `set_timezone'
352b1df3 | /usr/share/gems/gems/activesupport-6.1.7.8/lib/active_support/callbacks.rb:126:in `block in run_callbacks'
352b1df3 | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread'
352b1df3 | /usr/share/gems/gems/activesupport-6.1.7.8/lib/active_support/callbacks.rb:126:in `block in run_callbacks'
352b1df3 | /usr/share/foreman/app/controllers/concerns/foreman/controller/topbar_sweeper.rb:12:in `set_topbar_sweeper_controller'
352b1df3 | /usr/share/gems/gems/activesupport-6.1.7.8/lib/active_support/callbacks.rb:126:in `block in run_callbacks'
352b1df3 | /usr/share/gems/gems/audited-5.6.0/lib/audited/sweeper.rb:16:in `around'
352b1df3 | /usr/share/gems/gems/activesupport-6.1.7.8/lib/active_support/callbacks.rb:126:in `block in run_callbacks'
352b1df3 | /usr/share/gems/gems/audited-5.6.0/lib/audited/sweeper.rb:16:in `around'
352b1df3 | /usr/share/gems/gems/activesupport-6.1.7.8/lib/active_support/callbacks.rb:126:in `block in run_callbacks'
352b1df3 | /usr/share/gems/gems/activesupport-6.1.7.8/lib/active_support/callbacks.rb:137:in `run_callbacks'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/abstract_controller/callbacks.rb:41:in `process_action'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_controller/metal/rescue.rb:22:in `process_action'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_controller/metal/instrumentation.rb:34:in `block in process_action'
352b1df3 | /usr/share/gems/gems/activesupport-6.1.7.8/lib/active_support/notifications.rb:203:in `block in instrument'
352b1df3 | /usr/share/gems/gems/activesupport-6.1.7.8/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
352b1df3 | /usr/share/gems/gems/activesupport-6.1.7.8/lib/active_support/notifications.rb:203:in `instrument'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_controller/metal/instrumentation.rb:33:in `process_action'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_controller/metal/params_wrapper.rb:249:in `process_action'
352b1df3 | /usr/share/gems/gems/activerecord-6.1.7.8/lib/active_record/railties/controller_runtime.rb:27:in `process_action'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/abstract_controller/base.rb:165:in `process'
352b1df3 | /usr/share/gems/gems/actionview-6.1.7.8/lib/action_view/rendering.rb:39:in `process'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_controller/metal.rb:190:in `dispatch'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_controller/metal.rb:254:in `dispatch'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/routing/route_set.rb:50:in `dispatch'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/routing/route_set.rb:33:in `serve'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/routing/mapper.rb:19:in `block in <class:Constraints>'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/routing/mapper.rb:49:in `serve'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/journey/router.rb:50:in `block in serve'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/journey/router.rb:32:in `each'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/journey/router.rb:32:in `serve'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/routing/route_set.rb:842:in `call'
352b1df3 | /usr/share/gems/gems/katello-4.13.1/lib/katello/middleware/organization_created_enforcer.rb:18:in `call'
352b1df3 | /usr/share/gems/gems/katello-4.13.1/lib/katello/middleware/event_daemon.rb:10:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/static.rb:24:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/static.rb:24:in `call'
352b1df3 | /usr/share/gems/gems/apipie-dsl-2.6.2/lib/apipie_dsl/static_dispatcher.rb:67:in `call'
352b1df3 | /usr/share/gems/gems/apipie-rails-1.3.0/lib/apipie/static_dispatcher.rb:74:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/static.rb:24:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/static.rb:24:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/static.rb:24:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/static.rb:24:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/static.rb:24:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/static.rb:24:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/static.rb:24:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/static.rb:24:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/static.rb:24:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/static.rb:24:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/static.rb:24:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/static.rb:24:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/static.rb:24:in `call'
352b1df3 | /usr/share/foreman/lib/foreman/middleware/libvirt_connection_cleaner.rb:9:in `call'
352b1df3 | /usr/share/foreman/lib/foreman/middleware/telemetry.rb:10:in `call'
352b1df3 | /usr/share/gems/gems/apipie-rails-1.3.0/lib/apipie/middleware/checksum_in_headers.rb:27:in `call'
352b1df3 | /usr/share/gems/gems/prometheus-client-4.2.2/lib/prometheus/middleware/exporter.rb:33:in `call'
352b1df3 | /usr/share/gems/gems/rack-2.2.9/lib/rack/tempfile_reaper.rb:15:in `call'
352b1df3 | /usr/share/gems/gems/rack-2.2.9/lib/rack/etag.rb:27:in `call'
352b1df3 | /usr/share/gems/gems/rack-2.2.9/lib/rack/conditional_get.rb:40:in `call'
352b1df3 | /usr/share/gems/gems/rack-2.2.9/lib/rack/head.rb:12:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/http/permissions_policy.rb:22:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/http/content_security_policy.rb:19:in `call'
352b1df3 | /usr/share/foreman/lib/foreman/middleware/logging_context_session.rb:22:in `call'
352b1df3 | /usr/share/gems/gems/rack-2.2.9/lib/rack/session/abstract/id.rb:266:in `context'
352b1df3 | /usr/share/gems/gems/rack-2.2.9/lib/rack/session/abstract/id.rb:260:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/cookies.rb:697:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/callbacks.rb:27:in `block in call'
352b1df3 | /usr/share/gems/gems/activesupport-6.1.7.8/lib/active_support/callbacks.rb:98:in `run_callbacks'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/callbacks.rb:26:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/actionable_exceptions.rb:18:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/debug_exceptions.rb:29:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
352b1df3 | /usr/share/gems/gems/railties-6.1.7.8/lib/rails/rack/logger.rb:37:in `call_app'
352b1df3 | /usr/share/gems/gems/railties-6.1.7.8/lib/rails/rack/logger.rb:28:in `call'
352b1df3 | /usr/share/gems/gems/sprockets-rails-3.4.2/lib/sprockets/rails/quiet_assets.rb:13:in `call'
352b1df3 | /usr/share/foreman/lib/foreman/middleware/logging_context_request.rb:11:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/request_id.rb:26:in `call'
352b1df3 | /usr/share/gems/gems/katello-4.13.1/lib/katello/prevent_json_parsing.rb:12:in `call'
352b1df3 | /usr/share/gems/gems/rack-2.2.9/lib/rack/method_override.rb:24:in `call'
352b1df3 | /usr/share/gems/gems/rack-2.2.9/lib/rack/runtime.rb:22:in `call'
352b1df3 | /usr/share/gems/gems/activesupport-6.1.7.8/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/executor.rb:14:in `call'
352b1df3 | /usr/share/gems/gems/rack-2.2.9/lib/rack/sendfile.rb:110:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/ssl.rb:77:in `call'
352b1df3 | /usr/share/gems/gems/actionpack-6.1.7.8/lib/action_dispatch/middleware/host_authorization.rb:142:in `call'
352b1df3 | /usr/share/gems/gems/secure_headers-6.5.0/lib/secure_headers/middleware.rb:11:in `call'
352b1df3 | /usr/share/gems/gems/railties-6.1.7.8/lib/rails/engine.rb:539:in `call'
352b1df3 | /usr/share/gems/gems/railties-6.1.7.8/lib/rails/railtie.rb:207:in `public_send'
352b1df3 | /usr/share/gems/gems/railties-6.1.7.8/lib/rails/railtie.rb:207:in `method_missing'
352b1df3 | /usr/share/gems/gems/rack-2.2.9/lib/rack/urlmap.rb:74:in `block in call'
352b1df3 | /usr/share/gems/gems/rack-2.2.9/lib/rack/urlmap.rb:58:in `each'
352b1df3 | /usr/share/gems/gems/rack-2.2.9/lib/rack/urlmap.rb:58:in `call'
352b1df3 | /usr/share/gems/gems/puma-6.4.2/lib/puma/configuration.rb:272:in `call'
352b1df3 | /usr/share/gems/gems/puma-6.4.2/lib/puma/request.rb:100:in `block in handle_request'
352b1df3 | /usr/share/gems/gems/puma-6.4.2/lib/puma/thread_pool.rb:378:in `with_force_shutdown'
352b1df3 | /usr/share/gems/gems/puma-6.4.2/lib/puma/request.rb:99:in `handle_request'
352b1df3 | /usr/share/gems/gems/puma-6.4.2/lib/puma/server.rb:464:in `process_client'
352b1df3 | /usr/share/gems/gems/puma-6.4.2/lib/puma/server.rb:245:in `block in run'
352b1df3 | /usr/share/gems/gems/puma-6.4.2/lib/puma/thread_pool.rb:155:in `block in spawn_thread'
352b1df3 | /usr/share/gems/gems/logging-2.3.1/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
2025-04-24T16:19:53 [I|app|352b1df3] Rendered api/v2/errors/standard_error.json.rabl within api/v2/layouts/error_layout (Duration: 1.1ms | Allocations: 308)
2025-04-24T16:19:53 [I|app|352b1df3] Rendered layout api/v2/layouts/error_layout.json.erb (Duration: 1.7ms | Allocations: 522)
2025-04-24T16:19:53 [I|app|352b1df3] Completed 500 Internal Server Error in 14582ms (Views: 2.8ms | ActiveRecord: 202.3ms | Allocations: 3515921)
Updated by The Foreman Bot 4 days ago
- Status changed from New to Ready For Testing
- Pull request https://github.com/theforeman/foreman/pull/10534 added
Updated by Markus Bucher 4 days ago
Found the issue:¶
We had SafeModeRendering disabled and a GlobalParameter with the following value: <%= host.valid? %>.
- during Host creation the PXELinux template gets rendered. For Kickstart this template evaluates the
pxe_kernel_options-macro.
The Ubuntu-template does not call the macro, which explains why Ubuntu does not run into this issue. pxe_kernel_optionscallshost.params. And that renders all params, so alsohost.valid?.- the host-validator then triggers the
queue_compute_update-method and so on.
Fun fact: If I add a Parameter Override for the Parameter that evaluates host.valid?, this does not fix the issue. As far as I could find out, parameters overridden for the host are not reported by host.params. At least not when rendering the PXELinux-template.
This means that even if I change a Host-Parameter when saving a host, the inherited value is used! Is that a bug or expected behaviour?
I have created an MR to make it more visible, if the host-creation queue still has pending actions after it has been processed. I cannot think of a way to reliantly prevent the issue to happen in the first time unless we want to lock the queue, when we start processing it.
Actions