Foreman shellhook cannot trigger on event "Build Entered" - HTTP Error 500

Problem:

Trying to work around issues regarding cloud-init (more on that in another thread), we have created hooks to generate directories and files on our Foreman server. A webhook is supposed to trigger a shellhook when a host enters build mode. The shellhook would then do its thing on the local filesystem (we adapted /etc/sudoers to allow this).

We were able to verify that the above works if we let the shellhook be triggered by another event. For easy testing, we used the event “Host Updated”. Every time we update a host, the shellhook executes. If we change the event to “Build Entered” and build that host, however, the exact same shellhook does nothing and the Webinterface shows a “500 Internal Server Error” message.

production log for “Host Updated” event

2022-10-10T13:04:57 [I|app|3c9b5b7b] Performing ForemanWebhooks::DeliverWebhookJob (Job ID: 72e1b9b3-ffd2-4e02-bdd8-cdc5cb401cca) from Dynflow(default) enqueued at 2022-10-10T11:
04:31Z with arguments: {:event_name=>"host_updated.event.foreman", :payload=>"", :headers=>"{\n  \"X-Shellhook-Arg-1\": \"MANAGEDHOST\"\n}", :url=>"https:/
/FOREMANSERVER:8443/shellhook/host_built_cloud-init.sh", :webhook_id=>8}
2022-10-10T13:04:57 [I|app|3c9b5b7b] Performing 'host built cloud-init' webhook request for event 'host_updated.event.foreman'
2022-10-10T13:04:57 [I|app|3c9b5b7b] POST response was 200
2022-10-10T13:04:57 [I|app|3c9b5b7b] Performed ForemanWebhooks::DeliverWebhookJob (Job ID: 72e1b9b3-ffd2-4e02-bdd8-cdc5cb401cca) from Dynflow(default) in 20.77ms
2022-10-10T13:04:57 [I|app|e4a730f1] Started GET "/apidoc/apipie_checksum" for IPADDRESS at 2022-10-10 13:04:57 +0200
2022-10-10T13:04:57 [I|app|e4a730f1] Processing by Apipie::ApipiesController#apipie_checksum as JSON
2022-10-10T13:04:57 [I|app|e4a730f1]   Parameters: {"apipy"=>{}}
2022-10-10T13:04:57 [I|app|e4a730f1]   Rendering /usr/share/gems/gems/apipie-rails-0.5.17/app/views/apipie/apipies/apipie_checksum.json.erb
2022-10-10T13:04:57 [I|app|e4a730f1]   Rendered /usr/share/gems/gems/apipie-rails-0.5.17/app/views/apipie/apipies/apipie_checksum.json.erb (Duration: 3.9ms | Allocations: 5255)
2022-10-10T13:04:57 [I|app|e4a730f1] Completed 200 OK in 5ms (Views: 4.7ms | ActiveRecord: 0.0ms | Allocations: 5717)

production.log for “Build Entered” event

2022-10-10T11:47:12 [I|app|c19674fc] ForemanWebhooks::EventSubscriber: build_entered.event.foreman event received
2022-10-10T11:47:12 [W|app|c19674fc] undefined method `name' for nil:NilClass
2022-10-10T11:47:12 [I|app|c19674fc] Backtrace for 'undefined method `name' for nil:NilClass' error (NoMethodError): undefined method `name' for nil:NilClass
[...] trace output [...]
2022-10-10T11:47:12 [I|app|c19674fc]   Rendering common/500.html.erb
2022-10-10T11:47:12 [I|app|c19674fc]   Rendered common/500.html.erb (Duration: 4.9ms | Allocations: 5673)
2022-10-10T11:47:12 [I|app|c19674fc] Completed 500 Internal Server Error in 503ms (Views: 5.6ms | ActiveRecord: 75.7ms | Allocations: 113654)

We noticed that the webhook argument “@object.name” resolves to the FQDN of the managed host for the “Host Updated” event, but logs as “undefined method” for the “Build Entered” event. Is that a bug or are we doing something wrong?

Expected outcome:

A webhook triggered by the “Build Entered” event executes in the same way as webhooks on other events do.

Foreman and Proxy versions:

foreman-3.3.0-1.el8.noarch
foreman-proxy-3.3.0-1.el8.noarch

Foreman and Proxy plugin versions:

rubygem-foreman_webhooks-3.0.3-1.fm3_3.el8.noarch

Distribution and version:

Red Hat Enterprise Linux 8.6 (Ootpa)

Other relevant data:

Hi folks, its us again.

Webhooks/Shellhooks are such a useful tool in adapting Foreman to our environment. Sadly, we are still suffering from what we now know is indeed a bug, as analysed here by @laugmanuel.

Even after upgrading to Foreman v3.4, we are still observing this behaviour: If we put a webhook on the “Build Entered” or “Build Exited” event (Both are affected; maybe others are, too?).

from /var/log/foreman/production.log:

2023-02-16T14:59:38 [I|app|2a8f1028] Processed 3 tasks from queue 'Host::Managed Post', completed 3/3
2023-02-16T14:59:38 [I|app|2a8f1028] ForemanWebhooks::EventSubscriber: build_entered.event.foreman event received
2023-02-16T14:59:38 [W|app|2a8f1028] undefined method `name' for nil:NilClass
2023-02-16T14:59:38 [I|app|2a8f1028] Backtrace for 'undefined method `name' for nil:NilClass' error (NoMethodError): undefined method `name' for nil:NilClass
[...]
2023-02-16T14:59:38 [I|app|2a8f1028]   Rendered common/500.html.erb (Duration: 5.1ms | Allocations: 844)
2023-02-16T14:59:38 [I|app|2a8f1028] Completed 500 Internal Server Error in 1084ms (Views: 7.5ms | ActiveRecord: 108.8ms | Allocations: 107756)
2023-02-16T16:53:58 [I|app|4b5975c6] Processed 1 tasks from queue 'Host::Managed Post', completed 1/1
2023-02-16T16:53:58 [I|app|4b5975c6] ForemanWebhooks::EventSubscriber: build_exited.event.foreman event received
2023-02-16T16:53:58 [W|app|4b5975c6] undefined method `name' for nil:NilClass
2023-02-16T16:53:58 [I|app|4b5975c6] Backtrace for 'undefined method `name' for nil:NilClass' error (NoMethodError): undefined method `name' for nil:NilClass
[...]
2023-02-16T16:53:58 [I|app|4b5975c6]   Rendered common/500.html.erb (Duration: 5.4ms | Allocations: 5689)
2023-02-16T16:53:58 [I|app|4b5975c6] Completed 500 Internal Server Error in 415ms (Views: 5.9ms | ActiveRecord: 60.2ms | Allocations: 103933)

May we kindly ask those mentioned as members on the related bug tracker (@lzap, @Marek_Hulan, @ofedoren) for a comment on this? We would be glad to see the issue fixed. Can we do anything to assist?

You are not alone. I am too having this issue with exactly the same error message.
As I could not create an issue on GitHub for the repository, I finally came around and signed up for the forum here.

I’m wondering if we can provide anything to solve this or if there is a proper way to report bugs other than in the forum.
I guess a workaround would be to use the Shell hooks instead?!

Well, for a start, I guess, someone should post the backtrace. Above the backtrace has been omitted. The backtrace shows the exact place in the code causing the error…

The issue tracker would be a good place for that Issues - Foreman

Not really. Shellhooks are a proxy-side plugin so if things are hanging on your foreman, having shellhooks on a proxy would not really help.

Thanks to all of you for the replies so far. As mentioned by @aruzicka, there is an official bug tracker. Our problem is already registered as Bug #35777.

To help narrow down the problem, here are our full backtraces. We simply left them out before because they did not tell us anything.

Backtrace of webhook “Build Entered”:

2023-02-16T14:59:38 [I|app|2a8f1028] Processed 3 tasks from queue 'Host::Managed Post', completed 3/3
2023-02-16T14:59:38 [I|app|2a8f1028] ForemanWebhooks::EventSubscriber: build_entered.event.foreman event received
2023-02-16T14:59:38 [W|app|2a8f1028] undefined method `name' for nil:NilClass
2023-02-16T14:59:38 [I|app|2a8f1028] Backtrace for 'undefined method `name' for nil:NilClass' error (NoMethodError): undefined method `name' for nil:NilClass
 2a8f1028 | HTTP header template:2:in `get_binding'
 2a8f1028 | /usr/share/ruby/erb.rb:905:in `eval'
 2a8f1028 | /usr/share/ruby/erb.rb:905:in `result'
 2a8f1028 | /usr/share/foreman/app/services/foreman/renderer/unsafe_mode_renderer.rb:7:in `render'
 2a8f1028 | /usr/share/foreman/app/services/foreman/renderer/base_renderer.rb:18:in `render'
 2a8f1028 | /usr/share/foreman/app/services/foreman/renderer.rb:46:in `render'
 2a8f1028 | /usr/share/gems/gems/foreman_webhooks-3.0.5/app/models/webhook.rb:117:in `render_source'
 2a8f1028 | /usr/share/gems/gems/foreman_webhooks-3.0.5/app/models/webhook.rb:128:in `rendered_headers'
 2a8f1028 | /usr/share/gems/gems/foreman_webhooks-3.0.5/app/models/webhook.rb:69:in `deliver'
 2a8f1028 | /usr/share/gems/gems/foreman_webhooks-3.0.5/app/models/webhook.rb:46:in `block in deliver'
 2a8f1028 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/relation/delegation.rb:88:in `each'
 2a8f1028 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/relation/delegation.rb:88:in `each'
 2a8f1028 | /usr/share/gems/gems/foreman_webhooks-3.0.5/app/models/webhook.rb:45:in `deliver'
 2a8f1028 | /usr/share/gems/gems/foreman_webhooks-3.0.5/app/subscribers/foreman_webhooks/event_subscriber.rb:6:in `call'
 2a8f1028 | /usr/share/foreman/app/subscribers/foreman/base_subscriber.rb:6:in `call'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/notifications/fanout.rb:186:in `finish'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/notifications/fanout.rb:63:in `block in finish'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/notifications/fanout.rb:63:in `each'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/notifications/fanout.rb:63:in `finish'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/notifications/instrumenter.rb:45:in `finish_with_state'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/notifications/instrumenter.rb:30:in `instrument'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/notifications.rb:203:in `instrument'
 2a8f1028 | /usr/share/foreman/app/services/foreman/observable.rb:10:in `trigger_hook'
 2a8f1028 | /usr/share/foreman/app/models/concerns/foreman/observable_model.rb:17:in `block in set_hook'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:427:in `instance_exec'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:427:in `block in make_lambda'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:260:in `block in conditional'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:516:in `block in invoke_after'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:516:in `each'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:516:in `invoke_after'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:107:in `run_callbacks'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:824:in `_run_commit_callbacks'
 2a8f1028 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/transactions.rb:321:in `committed!'
 2a8f1028 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/connection_adapters/abstract/transaction.rb:155:in `commit_records'
 2a8f1028 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/connection_adapters/abstract/transaction.rb:304:in `block in commit_transaction'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
 2a8f1028 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/connection_adapters/abstract/transaction.rb:294:in `commit_transaction'
 2a8f1028 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/connection_adapters/abstract/transaction.rb:351:in `block in within_new_transaction'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
 2a8f1028 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/connection_adapters/abstract/transaction.rb:317:in `within_new_transaction'
 2a8f1028 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/connection_adapters/abstract/database_statements.rb:320:in `transaction'
 2a8f1028 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/transactions.rb:350:in `with_transaction_returning_status'
 2a8f1028 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/transactions.rb:298:in `save'
 2a8f1028 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/suppressor.rb:44:in `save'
 2a8f1028 | /usr/share/foreman/app/models/concerns/foreman/sti.rb:26:in `save'
 2a8f1028 | /usr/share/foreman/app/models/host/managed.rb:484:in `setBuild'
 2a8f1028 | /usr/share/foreman/app/controllers/hosts_controller.rb:192:in `setBuild'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/abstract_controller/base.rb:228:in `process_action'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_controller/metal/rendering.rb:30:in `process_action'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/abstract_controller/callbacks.rb:42:in `block in process_action'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
 2a8f1028 | /usr/share/foreman/app/controllers/concerns/foreman/controller/timezone.rb:10:in `set_timezone'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:126:in `block in run_callbacks'
 2a8f1028 | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:126:in `block in run_callbacks'
 2a8f1028 | /usr/share/foreman/app/controllers/concerns/foreman/controller/topbar_sweeper.rb:12:in `set_topbar_sweeper_controller'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:126:in `block in run_callbacks'
 2a8f1028 | /usr/share/gems/gems/audited-4.10.0/lib/audited/sweeper.rb:14:in `around'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:126:in `block in run_callbacks'
 2a8f1028 | /usr/share/gems/gems/audited-4.10.0/lib/audited/sweeper.rb:14:in `around'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:126:in `block in run_callbacks'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:137:in `run_callbacks'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/abstract_controller/callbacks.rb:41:in `process_action'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_controller/metal/rescue.rb:22:in `process_action'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_controller/metal/instrumentation.rb:34:in `block in process_action'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/notifications.rb:203:in `block in instrument'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/notifications.rb:203:in `instrument'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_controller/metal/instrumentation.rb:33:in `process_action'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_controller/metal/params_wrapper.rb:249:in `process_action'
 2a8f1028 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/railties/controller_runtime.rb:27:in `process_action'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/abstract_controller/base.rb:165:in `process'
 2a8f1028 | /usr/share/gems/gems/actionview-6.1.6.1/lib/action_view/rendering.rb:39:in `process'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_controller/metal.rb:190:in `dispatch'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_controller/metal.rb:254:in `dispatch'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/routing/route_set.rb:50:in `dispatch'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/routing/route_set.rb:33:in `serve'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/journey/router.rb:50:in `block in serve'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/journey/router.rb:32:in `each'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/journey/router.rb:32:in `serve'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/routing/route_set.rb:842:in `call'
 2a8f1028 | /usr/share/gems/gems/apipie-dsl-2.5.0/lib/apipie_dsl/static_dispatcher.rb:67:in `call'
 2a8f1028 | /usr/share/gems/gems/apipie-rails-0.5.20/lib/apipie/static_dispatcher.rb:66:in `call'
 2a8f1028 | /usr/share/gems/gems/apipie-rails-0.5.20/lib/apipie/extractor/recorder.rb:137:in `call'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/static.rb:24:in `call'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/static.rb:24:in `call'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/static.rb:24:in `call'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/static.rb:24:in `call'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/static.rb:24:in `call'
 2a8f1028 | /usr/share/foreman/lib/foreman/middleware/libvirt_connection_cleaner.rb:9:in `call'
 2a8f1028 | /usr/share/foreman/lib/foreman/middleware/telemetry.rb:10:in `call'
 2a8f1028 | /usr/share/gems/gems/apipie-rails-0.5.20/lib/apipie/middleware/checksum_in_headers.rb:27:in `call'
 2a8f1028 | /usr/share/gems/gems/rack-2.2.4/lib/rack/tempfile_reaper.rb:15:in `call'
 2a8f1028 | /usr/share/gems/gems/rack-2.2.4/lib/rack/etag.rb:27:in `call'
 2a8f1028 | /usr/share/gems/gems/rack-2.2.4/lib/rack/conditional_get.rb:40:in `call'
 2a8f1028 | /usr/share/gems/gems/rack-2.2.4/lib/rack/head.rb:12:in `call'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/http/permissions_policy.rb:22:in `call'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/http/content_security_policy.rb:19:in `call'
 2a8f1028 | /usr/share/foreman/lib/foreman/middleware/logging_context_session.rb:22:in `call'
 2a8f1028 | /usr/share/gems/gems/rack-2.2.4/lib/rack/session/abstract/id.rb:266:in `context'
 2a8f1028 | /usr/share/gems/gems/rack-2.2.4/lib/rack/session/abstract/id.rb:260:in `call'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/cookies.rb:689:in `call'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/callbacks.rb:27:in `block in call'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:98:in `run_callbacks'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/callbacks.rb:26:in `call'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/actionable_exceptions.rb:18:in `call'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/debug_exceptions.rb:29:in `call'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
 2a8f1028 | /usr/share/gems/gems/railties-6.1.6.1/lib/rails/rack/logger.rb:37:in `call_app'
 2a8f1028 | /usr/share/gems/gems/railties-6.1.6.1/lib/rails/rack/logger.rb:28:in `call'
 2a8f1028 | /usr/share/gems/gems/sprockets-rails-3.4.2/lib/sprockets/rails/quiet_assets.rb:13:in `call'
 2a8f1028 | /usr/share/foreman/lib/foreman/middleware/logging_context_request.rb:11:in `call'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/request_id.rb:26:in `call'
 2a8f1028 | /usr/share/gems/gems/rack-2.2.4/lib/rack/method_override.rb:24:in `call'
 2a8f1028 | /usr/share/gems/gems/rack-2.2.4/lib/rack/runtime.rb:22:in `call'
 2a8f1028 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/executor.rb:14:in `call'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/static.rb:24:in `call'
 2a8f1028 | /usr/share/gems/gems/rack-2.2.4/lib/rack/sendfile.rb:110:in `call'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/ssl.rb:77:in `call'
 2a8f1028 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/host_authorization.rb:142:in `call'
 2a8f1028 | /usr/share/gems/gems/secure_headers-6.3.4/lib/secure_headers/middleware.rb:11:in `call'
 2a8f1028 | /usr/share/gems/gems/railties-6.1.6.1/lib/rails/engine.rb:539:in `call'
 2a8f1028 | /usr/share/gems/gems/railties-6.1.6.1/lib/rails/railtie.rb:207:in `public_send'
 2a8f1028 | /usr/share/gems/gems/railties-6.1.6.1/lib/rails/railtie.rb:207:in `method_missing'
 2a8f1028 | /usr/share/gems/gems/rack-2.2.4/lib/rack/urlmap.rb:74:in `block in call'
 2a8f1028 | /usr/share/gems/gems/rack-2.2.4/lib/rack/urlmap.rb:58:in `each'
 2a8f1028 | /usr/share/gems/gems/rack-2.2.4/lib/rack/urlmap.rb:58:in `call'
 2a8f1028 | /usr/share/gems/gems/puma-5.6.4/lib/puma/configuration.rb:252:in `call'
 2a8f1028 | /usr/share/gems/gems/puma-5.6.4/lib/puma/request.rb:77:in `block in handle_request'
 2a8f1028 | /usr/share/gems/gems/puma-5.6.4/lib/puma/thread_pool.rb:340:in `with_force_shutdown'
 2a8f1028 | /usr/share/gems/gems/puma-5.6.4/lib/puma/request.rb:76:in `handle_request'
 2a8f1028 | /usr/share/gems/gems/puma-5.6.4/lib/puma/server.rb:441:in `process_client'
 2a8f1028 | /usr/share/gems/gems/puma-5.6.4/lib/puma/thread_pool.rb:147:in `block in spawn_thread'
 2a8f1028 | /usr/share/gems/gems/logging-2.3.1/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
2023-02-16T14:59:38 [I|app|2a8f1028]   Rendered common/500.html.erb (Duration: 5.1ms | Allocations: 844)
2023-02-16T14:59:38 [I|app|2a8f1028] Completed 500 Internal Server Error in 1084ms (Views: 7.5ms | ActiveRecord: 108.8ms | Allocations: 107756)

Backtrace of webhook “Build Exited”:

2023-02-16T16:53:58 [I|app|4b5975c6] Processed 1 tasks from queue 'Host::Managed Post', completed 1/1
2023-02-16T16:53:58 [I|app|4b5975c6] ForemanWebhooks::EventSubscriber: build_exited.event.foreman event received
2023-02-16T16:53:58 [W|app|4b5975c6] undefined method `name' for nil:NilClass
2023-02-16T16:53:58 [I|app|4b5975c6] Backtrace for 'undefined method `name' for nil:NilClass' error (NoMethodError): undefined method `name' for nil:NilClass
 4b5975c6 | HTTP header template:2:in `get_binding'
 4b5975c6 | /usr/share/ruby/erb.rb:905:in `eval'
 4b5975c6 | /usr/share/ruby/erb.rb:905:in `result'
 4b5975c6 | /usr/share/foreman/app/services/foreman/renderer/unsafe_mode_renderer.rb:7:in `render'
 4b5975c6 | /usr/share/foreman/app/services/foreman/renderer/base_renderer.rb:18:in `render'
 4b5975c6 | /usr/share/foreman/app/services/foreman/renderer.rb:46:in `render'
 4b5975c6 | /usr/share/gems/gems/foreman_webhooks-3.0.5/app/models/webhook.rb:117:in `render_source'
 4b5975c6 | /usr/share/gems/gems/foreman_webhooks-3.0.5/app/models/webhook.rb:128:in `rendered_headers'
 4b5975c6 | /usr/share/gems/gems/foreman_webhooks-3.0.5/app/models/webhook.rb:69:in `deliver'
 4b5975c6 | /usr/share/gems/gems/foreman_webhooks-3.0.5/app/models/webhook.rb:46:in `block in deliver'
 4b5975c6 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/relation/delegation.rb:88:in `each'
 4b5975c6 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/relation/delegation.rb:88:in `each'
 4b5975c6 | /usr/share/gems/gems/foreman_webhooks-3.0.5/app/models/webhook.rb:45:in `deliver'
 4b5975c6 | /usr/share/gems/gems/foreman_webhooks-3.0.5/app/subscribers/foreman_webhooks/event_subscriber.rb:6:in `call'
 4b5975c6 | /usr/share/foreman/app/subscribers/foreman/base_subscriber.rb:6:in `call'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/notifications/fanout.rb:186:in `finish'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/notifications/fanout.rb:63:in `block in finish'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/notifications/fanout.rb:63:in `each'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/notifications/fanout.rb:63:in `finish'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/notifications/instrumenter.rb:45:in `finish_with_state'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/notifications/instrumenter.rb:30:in `instrument'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/notifications.rb:203:in `instrument'
 4b5975c6 | /usr/share/foreman/app/services/foreman/observable.rb:10:in `trigger_hook'
 4b5975c6 | /usr/share/foreman/app/models/concerns/foreman/observable_model.rb:17:in `block in set_hook'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:427:in `instance_exec'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:427:in `block in make_lambda'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:260:in `block in conditional'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:516:in `block in invoke_after'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:516:in `each'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:516:in `invoke_after'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:107:in `run_callbacks'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:824:in `_run_commit_callbacks'
 4b5975c6 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/transactions.rb:321:in `committed!'
 4b5975c6 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/connection_adapters/abstract/transaction.rb:155:in `commit_records'
 4b5975c6 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/connection_adapters/abstract/transaction.rb:304:in `block in commit_transaction'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
 4b5975c6 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/connection_adapters/abstract/transaction.rb:294:in `commit_transaction'
 4b5975c6 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/connection_adapters/abstract/transaction.rb:351:in `block in within_new_transaction'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
 4b5975c6 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/connection_adapters/abstract/transaction.rb:317:in `within_new_transaction'
 4b5975c6 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/connection_adapters/abstract/database_statements.rb:320:in `transaction'
 4b5975c6 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/transactions.rb:350:in `with_transaction_returning_status'
 4b5975c6 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/transactions.rb:298:in `save'
 4b5975c6 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/suppressor.rb:44:in `save'
 4b5975c6 | /usr/share/foreman/app/models/concerns/foreman/sti.rb:26:in `save'
 4b5975c6 | /usr/share/foreman/app/models/host/managed.rb:384:in `built'
 4b5975c6 | /usr/share/foreman/app/models/concerns/hostext/ui_notifications.rb:9:in `built'
 4b5975c6 | /usr/share/foreman/app/controllers/hosts_controller.rb:244:in `cancelBuild'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/abstract_controller/base.rb:228:in `process_action'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_controller/metal/rendering.rb:30:in `process_action'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/abstract_controller/callbacks.rb:42:in `block in process_action'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
 4b5975c6 | /usr/share/foreman/app/controllers/concerns/foreman/controller/timezone.rb:10:in `set_timezone'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:126:in `block in run_callbacks'
 4b5975c6 | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:126:in `block in run_callbacks'
 4b5975c6 | /usr/share/foreman/app/controllers/concerns/foreman/controller/topbar_sweeper.rb:12:in `set_topbar_sweeper_controller'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:126:in `block in run_callbacks'
 4b5975c6 | /usr/share/gems/gems/audited-4.10.0/lib/audited/sweeper.rb:14:in `around'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:126:in `block in run_callbacks'
 4b5975c6 | /usr/share/gems/gems/audited-4.10.0/lib/audited/sweeper.rb:14:in `around'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:126:in `block in run_callbacks'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:137:in `run_callbacks'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/abstract_controller/callbacks.rb:41:in `process_action'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_controller/metal/rescue.rb:22:in `process_action'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_controller/metal/instrumentation.rb:34:in `block in process_action'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/notifications.rb:203:in `block in instrument'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/notifications.rb:203:in `instrument'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_controller/metal/instrumentation.rb:33:in `process_action'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_controller/metal/params_wrapper.rb:249:in `process_action'
 4b5975c6 | /usr/share/gems/gems/activerecord-6.1.6.1/lib/active_record/railties/controller_runtime.rb:27:in `process_action'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/abstract_controller/base.rb:165:in `process'
 4b5975c6 | /usr/share/gems/gems/actionview-6.1.6.1/lib/action_view/rendering.rb:39:in `process'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_controller/metal.rb:190:in `dispatch'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_controller/metal.rb:254:in `dispatch'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/routing/route_set.rb:50:in `dispatch'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/routing/route_set.rb:33:in `serve'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/journey/router.rb:50:in `block in serve'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/journey/router.rb:32:in `each'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/journey/router.rb:32:in `serve'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/routing/route_set.rb:842:in `call'
 4b5975c6 | /usr/share/gems/gems/apipie-dsl-2.5.0/lib/apipie_dsl/static_dispatcher.rb:67:in `call'
 4b5975c6 | /usr/share/gems/gems/apipie-rails-0.5.20/lib/apipie/static_dispatcher.rb:66:in `call'
 4b5975c6 | /usr/share/gems/gems/apipie-rails-0.5.20/lib/apipie/extractor/recorder.rb:137:in `call'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/static.rb:24:in `call'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/static.rb:24:in `call'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/static.rb:24:in `call'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/static.rb:24:in `call'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/static.rb:24:in `call'
 4b5975c6 | /usr/share/foreman/lib/foreman/middleware/libvirt_connection_cleaner.rb:9:in `call'
 4b5975c6 | /usr/share/foreman/lib/foreman/middleware/telemetry.rb:10:in `call'
 4b5975c6 | /usr/share/gems/gems/apipie-rails-0.5.20/lib/apipie/middleware/checksum_in_headers.rb:27:in `call'
 4b5975c6 | /usr/share/gems/gems/rack-2.2.4/lib/rack/tempfile_reaper.rb:15:in `call'
 4b5975c6 | /usr/share/gems/gems/rack-2.2.4/lib/rack/etag.rb:27:in `call'
 4b5975c6 | /usr/share/gems/gems/rack-2.2.4/lib/rack/conditional_get.rb:27:in `call'
 4b5975c6 | /usr/share/gems/gems/rack-2.2.4/lib/rack/head.rb:12:in `call'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/http/permissions_policy.rb:22:in `call'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/http/content_security_policy.rb:19:in `call'
 4b5975c6 | /usr/share/foreman/lib/foreman/middleware/logging_context_session.rb:22:in `call'
 4b5975c6 | /usr/share/gems/gems/rack-2.2.4/lib/rack/session/abstract/id.rb:266:in `context'
 4b5975c6 | /usr/share/gems/gems/rack-2.2.4/lib/rack/session/abstract/id.rb:260:in `call'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/cookies.rb:689:in `call'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/callbacks.rb:27:in `block in call'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/callbacks.rb:98:in `run_callbacks'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/callbacks.rb:26:in `call'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/actionable_exceptions.rb:18:in `call'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/debug_exceptions.rb:29:in `call'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
 4b5975c6 | /usr/share/gems/gems/railties-6.1.6.1/lib/rails/rack/logger.rb:37:in `call_app'
 4b5975c6 | /usr/share/gems/gems/railties-6.1.6.1/lib/rails/rack/logger.rb:28:in `call'
 4b5975c6 | /usr/share/gems/gems/sprockets-rails-3.4.2/lib/sprockets/rails/quiet_assets.rb:13:in `call'
 4b5975c6 | /usr/share/foreman/lib/foreman/middleware/logging_context_request.rb:11:in `call'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/request_id.rb:26:in `call'
 4b5975c6 | /usr/share/gems/gems/rack-2.2.4/lib/rack/method_override.rb:24:in `call'
 4b5975c6 | /usr/share/gems/gems/rack-2.2.4/lib/rack/runtime.rb:22:in `call'
 4b5975c6 | /usr/share/gems/gems/activesupport-6.1.6.1/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/executor.rb:14:in `call'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/static.rb:24:in `call'
 4b5975c6 | /usr/share/gems/gems/rack-2.2.4/lib/rack/sendfile.rb:110:in `call'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/ssl.rb:77:in `call'
 4b5975c6 | /usr/share/gems/gems/actionpack-6.1.6.1/lib/action_dispatch/middleware/host_authorization.rb:142:in `call'
 4b5975c6 | /usr/share/gems/gems/secure_headers-6.3.4/lib/secure_headers/middleware.rb:11:in `call'
 4b5975c6 | /usr/share/gems/gems/railties-6.1.6.1/lib/rails/engine.rb:539:in `call'
 4b5975c6 | /usr/share/gems/gems/railties-6.1.6.1/lib/rails/railtie.rb:207:in `public_send'
 4b5975c6 | /usr/share/gems/gems/railties-6.1.6.1/lib/rails/railtie.rb:207:in `method_missing'
 4b5975c6 | /usr/share/gems/gems/rack-2.2.4/lib/rack/urlmap.rb:74:in `block in call'
 4b5975c6 | /usr/share/gems/gems/rack-2.2.4/lib/rack/urlmap.rb:58:in `each'
 4b5975c6 | /usr/share/gems/gems/rack-2.2.4/lib/rack/urlmap.rb:58:in `call'
 4b5975c6 | /usr/share/gems/gems/puma-5.6.4/lib/puma/configuration.rb:252:in `call'
 4b5975c6 | /usr/share/gems/gems/puma-5.6.4/lib/puma/request.rb:77:in `block in handle_request'
 4b5975c6 | /usr/share/gems/gems/puma-5.6.4/lib/puma/thread_pool.rb:340:in `with_force_shutdown'
 4b5975c6 | /usr/share/gems/gems/puma-5.6.4/lib/puma/request.rb:76:in `handle_request'
 4b5975c6 | /usr/share/gems/gems/puma-5.6.4/lib/puma/server.rb:441:in `process_client'
 4b5975c6 | /usr/share/gems/gems/puma-5.6.4/lib/puma/thread_pool.rb:147:in `block in spawn_thread'
 4b5975c6 | /usr/share/gems/gems/logging-2.3.1/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
2023-02-16T16:53:58 [I|app|4b5975c6]   Rendered common/500.html.erb (Duration: 5.4ms | Allocations: 5689)
2023-02-16T16:53:58 [I|app|4b5975c6] Completed 500 Internal Server Error in 415ms (Views: 5.9ms | ActiveRecord: 60.2ms | Allocations: 103933)

Re shellhooks, there is an old plugin called simply “hooks” which is no longer recommended. The new shellhooks plugin is the one we are currently using. But it depends on the new webhooks plugin. Therefore we need the bug fixed, or else the shellhook we want to activate will not trigger.

Again, we would appreciate any help in solving this issue.

Kind Regards

Until this gets fixed properly, accessing host’s id with @payload['id'] and name with @payload['hostname'] seems to work.

1 Like

Thanks for the hint, now we are one step further. We used @payload inside the “Additional” tab of the webhook edit dialog, as follows:

HTTP Content Type: application/json

Optional HTTP headers as JSON (ERB allowed):

{
  "X-Shellhook-Arg-1": "<%= @payload['hostname'] %>"
}

Maybe there is still something wrong about the syntax? Now the webhook does indeed trigger, but the POST response code is still 500 and our shellhook script does not get executed. Here are the logs (we replaced server names by: HOST_FQDN, CLIENT_IP, FOREMAN_FQDN).

2023-03-15T11:21:59 [I|app|cf9fe991] Started PUT "/hosts/HOST_FQDN/setBuild" for CLIENT_IP at 2023-03-15 11:21:59 +0100
2023-03-15T11:21:59 [I|app|cf9fe991] Processing by HostsController#setBuild as JSON
2023-03-15T11:21:59 [I|app|cf9fe991]   Parameters: {"id"=>"HOST_FQDN", "host"=>{}}
2023-03-15T11:22:00 [I|app|cf9fe991] Deploying TFTP PXELinux configuration for HOST_FQDN
2023-03-15T11:22:00 [I|app|cf9fe991] Skipping TFTP PXEGrub2 configuration for HOST_FQDN
2023-03-15T11:22:00 [I|app|cf9fe991] Skipping TFTP PXEGrub configuration for HOST_FQDN
2023-03-15T11:22:00 [I|app|cf9fe991] Skipping TFTP iPXE configuration for HOST_FQDN
2023-03-15T11:22:00 [I|app|cf9fe991] Fetching required TFTP boot files for HOST_FQDN
2023-03-15T11:22:00 [I|app|cf9fe991] Processed 5 tasks from queue 'Host::Managed Main', completed 5/5
2023-03-15T11:22:00 [I|aud|cf9fe991] Host::Base (3612) update event on build false, true
2023-03-15T11:22:00 [I|aud|cf9fe991] Host::Base (3612) update event on initiated_at 2023-03-15 11:12:02 +0100, 2023-03-15 11:21:59 +0100
2023-03-15T11:22:00 [I|app|cf9fe991] Delete the autosign entry for HOST_FQDN
2023-03-15T11:22:00 [I|app|cf9fe991] Remove puppet certificate for HOST_FQDN
2023-03-15T11:22:00 [I|app|cf9fe991] Adding autosign entry for HOST_FQDN
2023-03-15T11:22:00 [I|app|cf9fe991] Processed 3 tasks from queue 'Host::Managed Post', completed 3/3
2023-03-15T11:22:00 [I|app|cf9fe991] ForemanWebhooks::EventSubscriber: build_entered.event.foreman event received
2023-03-15T11:22:00 [I|app|cf9fe991] Enqueued ForemanWebhooks::DeliverWebhookJob (Job ID: f38a9d89-c7e4-4663-b97e-d47ab08c9fc5) to Dynflow(default) with arguments: {:event_name=>"build_entered.event.foreman", :payload=>"", :headers=>"{\n  \"X-Shellhook-Arg-1\": \"HOST_FQDN\"\n}", :url=>"https://FOREMAN_FQDN:8443/shellhook/host_built_cloud-init.sh", :webhook_id=>8}
2023-03-15T11:22:00 [I|app|cf9fe991] ForemanWebhooks::EventSubscriber: host_updated.event.foreman event received
2023-03-15T11:22:00 [I|app|cf9fe991] Completed 200 OK in 734ms (Views: 0.2ms | ActiveRecord: 84.9ms | Allocations: 123675)
2023-03-15T11:22:00 [I|app|cf9fe991] Performing ForemanWebhooks::DeliverWebhookJob (Job ID: f38a9d89-c7e4-4663-b97e-d47ab08c9fc5) from Dynflow(default) enqueued at 2023-03-15T10:22:00Z with arguments: {:event_name=>"build_entered.event.foreman", :payload=>"", :headers=>"{\n  \"X-Shellhook-Arg-1\": \"HOST_FQDN\"\n}", :url=>"https://FOREMAN_FQDN:8443/shellhook/host_built_cloud-init.sh", :webhook_id=>8}
2023-03-15T11:22:00 [I|app|cf9fe991] Performing 'host built cloud-init' webhook request for event 'build_entered.event.foreman'
2023-03-15T11:22:00 [E|app|cf9fe991] POST response was 500
2023-03-15T11:22:00 [I|app|cf9fe991] Performed ForemanWebhooks::DeliverWebhookJob (Job ID: f38a9d89-c7e4-4663-b97e-d47ab08c9fc5) from Dynflow(default) in 26.6ms
2023-03-15T11:22:00 [I|app|33591a2e] Started GET "/api/hosts/HOST_FQDN" for CLIENT_IP at 2023-03-15 11:22:00 +0100
2023-03-15T11:22:00 [I|app|33591a2e] Processing by Api::V2::HostsController#show as JSON
2023-03-15T11:22:00 [I|app|33591a2e]   Parameters: {"apiv"=>"v2", "id"=>"HOST_FQDN"}
2023-03-15T11:22:00 [I|app|33591a2e]   Rendered api/v2/hosts/show.json.rabl (Duration: 138.7ms | Allocations: 50722)
2023-03-15T11:22:00 [I|app|33591a2e] Completed 200 OK in 153ms (Views: 112.8ms | ActiveRecord: 30.4ms | Allocations: 54864)

What do the proxy logs (/var/log/foreman-proxy/proxy.log) say?

To be transparent, /var/log/foreman-proxy/proxy.log said before:

2023-03-15T11:22:00 cf9fe991 [I] Started POST /shellhook/host_built_cloud-init.sh
2023-03-15T11:22:00 cf9fe991 [E] Not a valid shellhook file
2023-03-15T11:22:00 cf9fe991 [W] Error details for Not a valid shellhook file: <Exception>: Not a valid shellhook file
2023-03-15T11:22:00 cf9fe991 [W] Not a valid shellhook file: <Exception>: Not a valid shellhook file
2023-03-15T11:22:00 cf9fe991 [I] Finished POST /shellhook/host_built_cloud-init.sh with 500 (0.81 ms)

Now that log says:

2023-03-15T12:04:26 7c0d4139 [I] Started POST /shellhook/host_built_cloudinit.sh
2023-03-15T12:04:26 7c0d4139 [I] Finished POST /shellhook/host_built_cloudinit.sh with 200 (0.62 ms)

That’s slightly embarrassing, but thank you for pointing me at it. In our desperate attempt to rule out other possible errors, we recently renamed the shell hook to get rid of the hyphen. So the webhook still called the old name of the script file, but I just fixed that.

Now we have a working webhook again! Great! (Still, this bug should be fixed some day.)

1 Like

Hi, @dpenguins, sorry for not responding earlier. I’m glad you figured things out and that @aruzicka for the help.

Just some additional notes:
In the documentation for webhooks there is an explicit list with events and the payloads that are available in a webhook template for each event [1]. build_entered as few others are a bit different and there is no @object variable available. Can’t quire remember why, but it is like this currently. I guess we can add @object variable containing the host object to comply with other payloads.

[1] - Administering Foreman

Hi @ofedoren,

thank you for your reply. We are looking forward to said implementation. As for now, we have a running environment.

Kind regards