Problem:
I adopted an existing foreman setup over multiple hosts (one foreman server and three foreman proxies). It seems the setup was done manually and unfortunately not with the foreman-installer.
I’m able to keep the foreman setup up-to-date, but troubleshooting is kind of complicated with our “dirty” foreman setup.
If I want to schedule a remote job (for example “run puppet once”), I get an error message “Request failed with status code 500” in the Web UI. In the production.log file appears the following message:
production.log
2023-04-05T10:44:23 [I|app|e86bf39f] Started POST “/job_invocations?feature=puppet_run_host&host_ids%5B%5D=39” for MY-CLIENT-IP at 2023-04-05 10:44:23 +0200
2023-04-05T10:44:23 [I|app|e86bf39f] Processing by JobInvocationsController#legacy_create as JSON
2023-04-05T10:44:23 [I|app|e86bf39f] Parameters: {“feature”=>“puppet_run_host”, “host_ids”=>[“39”], “job_invocation”=>{}}
2023-04-05T10:44:23 [I|per|e86bf39f] Current user set to maximilian.schmitz (admin)
2023-04-05T10:44:23 [I|aud|e86bf39f] JobInvocation (301) create event on job_category Puppet
2023-04-05T10:44:23 [I|aud|e86bf39f] JobInvocation (301) create event on description Run Puppet once with “‘’”
2023-04-05T10:44:23 [I|aud|e86bf39f] JobInvocation (301) create event on concurrency_level
2023-04-05T10:44:23 [I|aud|e86bf39f] JobInvocation (301) create event on time_span
2023-04-05T10:44:23 [I|aud|e86bf39f] JobInvocation (301) create event on execution_timeout_interval
2023-04-05T10:44:23 [I|aud|e86bf39f] JobInvocation (301) create event on password [redacted]
2023-04-05T10:44:23 [I|aud|e86bf39f] JobInvocation (301) create event on key_passphrase
2023-04-05T10:44:23 [I|aud|e86bf39f] JobInvocation (301) create event on remote_execution_feature_id 1
2023-04-05T10:44:23 [I|aud|e86bf39f] JobInvocation (301) create event on effective_user_password
2023-04-05T10:44:23 [I|aud|e86bf39f] JobInvocation (301) create event on ssh_user
2023-04-05T10:44:23 [I|aud|e86bf39f] JobInvocation (301) create event on time_to_pickup
2023-04-05T10:44:23 [D|per|e86bf39f] verifying the transaction by permission create_template_invocations for class TemplateInvocation
2023-04-05T10:44:23 [D|per|e86bf39f] verifying the transaction by permission create_job_invocations for class JobInvocation
2023-04-05T10:44:23 [D|per|e86bf39f] verifying the transaction by permission for class JobInvocation
2023-04-05T10:44:23 [W|app|e86bf39f] The Dynflow world was not initialized yet. If your plugin uses it, make sure to call Rails.application.dynflow.require! in some initializer
2023-04-05T10:44:23 [I|app|e86bf39f] Backtrace for ‘The Dynflow world was not initialized yet. If your plugin uses it, make sure to call Rails.application.dynflow.require! in some initializer’ error (RuntimeError): The Dynflow world was not initialized yet. If your plugin uses it, make sure to call Rails.application.dynflow.require! in some initializer
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/dynflow-1.6.10/lib/dynflow/rails.rb:78:inworld' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/foreman-tasks-7.2.1/lib/foreman_tasks.rb:20:intrigger’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/foreman-tasks-7.2.1/lib/foreman_tasks.rb:26:inblock in trigger_task' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/foreman-tasks-7.2.1/lib/foreman_tasks.rb:46:inblock in rails_safe_trigger_task’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/activesupport-6.1.7.3/lib/active_support/dependencies/interlock.rb:48:inblock in permit_concurrent_loads' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/activesupport-6.1.7.3/lib/active_support/concurrency/share_lock.rb:187:inyield_shares’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/activesupport-6.1.7.3/lib/active_support/dependencies/interlock.rb:47:inpermit_concurrent_loads' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/foreman-tasks-7.2.1/lib/foreman_tasks.rb:45:inrails_safe_trigger_task’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/foreman-tasks-7.2.1/lib/foreman_tasks.rb:24:intrigger_task' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/foreman-tasks-7.2.1/lib/foreman_tasks.rb:51:inasync_task’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/foreman-tasks-7.2.1/app/models/foreman_tasks/triggering.rb:67:intrigger' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/foreman_remote_execution-9.1.0/app/models/job_invocation_composer.rb:440:intrigger’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/foreman_remote_execution-9.1.0/app/controllers/job_invocations_controller.rb:45:inlegacy_create' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_controller/metal/basic_implicit_render.rb:6:insend_action’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/abstract_controller/base.rb:228:inprocess_action' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_controller/metal/rendering.rb:30:inprocess_action’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/abstract_controller/callbacks.rb:42:inblock in process_action' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/activesupport-6.1.7.3/lib/active_support/callbacks.rb:117:inblock in run_callbacks’
e86bf39f | /usr/share/foreman/app/controllers/concerns/foreman/controller/timezone.rb:10:inset_timezone' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/activesupport-6.1.7.3/lib/active_support/callbacks.rb:126:inblock in run_callbacks’
e86bf39f | /usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:inclear_thread' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/activesupport-6.1.7.3/lib/active_support/callbacks.rb:126:inblock in run_callbacks’
e86bf39f | /usr/share/foreman/app/controllers/concerns/foreman/controller/topbar_sweeper.rb:12:inset_topbar_sweeper_controller' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/activesupport-6.1.7.3/lib/active_support/callbacks.rb:126:inblock in run_callbacks’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/audited-5.3.2/lib/audited/sweeper.rb:16:inaround' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/activesupport-6.1.7.3/lib/active_support/callbacks.rb:126:inblock in run_callbacks’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/audited-5.3.2/lib/audited/sweeper.rb:16:inaround' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/activesupport-6.1.7.3/lib/active_support/callbacks.rb:126:inblock in run_callbacks’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/activesupport-6.1.7.3/lib/active_support/callbacks.rb:137:inrun_callbacks' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/abstract_controller/callbacks.rb:41:inprocess_action’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_controller/metal/rescue.rb:22:inprocess_action' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_controller/metal/instrumentation.rb:34:inblock in process_action’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/activesupport-6.1.7.3/lib/active_support/notifications.rb:203:inblock in instrument' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/activesupport-6.1.7.3/lib/active_support/notifications/instrumenter.rb:24:ininstrument’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/activesupport-6.1.7.3/lib/active_support/notifications.rb:203:ininstrument' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_controller/metal/instrumentation.rb:33:inprocess_action’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_controller/metal/params_wrapper.rb:249:inprocess_action' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/activerecord-6.1.7.3/lib/active_record/railties/controller_runtime.rb:27:inprocess_action’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/abstract_controller/base.rb:165:inprocess' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionview-6.1.7.3/lib/action_view/rendering.rb:39:inprocess’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_controller/metal.rb:190:indispatch' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_controller/metal.rb:254:indispatch’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_dispatch/routing/route_set.rb:50:indispatch' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_dispatch/routing/route_set.rb:33:inserve’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_dispatch/journey/router.rb:50:inblock in serve' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_dispatch/journey/router.rb:32:ineach’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_dispatch/journey/router.rb:32:inserve' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_dispatch/routing/route_set.rb:842:incall’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/apipie-dsl-2.5.0/lib/apipie_dsl/static_dispatcher.rb:67:incall' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/apipie-rails-0.8.2/lib/apipie/static_dispatcher.rb:68:incall’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/apipie-rails-0.8.2/lib/apipie/extractor/recorder.rb:137:incall' e86bf39f | /usr/share/foreman/lib/foreman/middleware/libvirt_connection_cleaner.rb:9:incall’
e86bf39f | /usr/share/foreman/lib/foreman/middleware/telemetry.rb:10:incall' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/apipie-rails-0.8.2/lib/apipie/middleware/checksum_in_headers.rb:27:incall’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/rack-2.2.6.4/lib/rack/tempfile_reaper.rb:15:incall' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/rack-2.2.6.4/lib/rack/etag.rb:27:incall’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/rack-2.2.6.4/lib/rack/conditional_get.rb:40:incall' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/rack-2.2.6.4/lib/rack/head.rb:12:incall’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_dispatch/http/permissions_policy.rb:22:incall' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_dispatch/http/content_security_policy.rb:19:incall’
e86bf39f | /usr/share/foreman/lib/foreman/middleware/logging_context_session.rb:22:incall' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/rack-2.2.6.4/lib/rack/session/abstract/id.rb:266:incontext’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/rack-2.2.6.4/lib/rack/session/abstract/id.rb:260:incall' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_dispatch/middleware/cookies.rb:697:incall’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_dispatch/middleware/callbacks.rb:27:inblock in call' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/activesupport-6.1.7.3/lib/active_support/callbacks.rb:98:inrun_callbacks’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_dispatch/middleware/callbacks.rb:26:incall' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_dispatch/middleware/actionable_exceptions.rb:18:incall’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_dispatch/middleware/debug_exceptions.rb:29:incall' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_dispatch/middleware/show_exceptions.rb:33:incall’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/railties-6.1.7.3/lib/rails/rack/logger.rb:37:incall_app' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/railties-6.1.7.3/lib/rails/rack/logger.rb:28:incall’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/sprockets-rails-3.4.2/lib/sprockets/rails/quiet_assets.rb:13:incall' e86bf39f | /usr/share/foreman/lib/foreman/middleware/logging_context_request.rb:11:incall’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_dispatch/middleware/remote_ip.rb:81:incall' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_dispatch/middleware/request_id.rb:26:incall’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/rack-2.2.6.4/lib/rack/method_override.rb:24:incall' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/rack-2.2.6.4/lib/rack/runtime.rb:22:incall’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/activesupport-6.1.7.3/lib/active_support/cache/strategy/local_cache_middleware.rb:29:incall' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_dispatch/middleware/executor.rb:14:incall’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/rack-2.2.6.4/lib/rack/sendfile.rb:110:incall' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_dispatch/middleware/ssl.rb:77:incall’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/actionpack-6.1.7.3/lib/action_dispatch/middleware/host_authorization.rb:142:incall' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/secure_headers-6.5.0/lib/secure_headers/middleware.rb:11:incall’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/railties-6.1.7.3/lib/rails/engine.rb:539:incall' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/railties-6.1.7.3/lib/rails/railtie.rb:207:inpublic_send’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/railties-6.1.7.3/lib/rails/railtie.rb:207:inmethod_missing' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/rack-2.2.6.4/lib/rack/urlmap.rb:74:inblock in call’
e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/rack-2.2.6.4/lib/rack/urlmap.rb:58:ineach' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/rack-2.2.6.4/lib/rack/urlmap.rb:58:incall’
e86bf39f | /usr/lib/ruby/vendor_ruby/phusion_passenger/rack/thread_handler_extension.rb:97:inprocess_request' e86bf39f | /usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler/thread_handler.rb:160:inaccept_and_process_next_request’
e86bf39f | /usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler/thread_handler.rb:113:inmain_loop' e86bf39f | /usr/lib/ruby/vendor_ruby/phusion_passenger/request_handler.rb:416:inblock (3 levels) in start_threads’
e86bf39f | /usr/lib/ruby/vendor_ruby/phusion_passenger/utils.rb:113:inblock in create_thread_and_abort_on_exception' e86bf39f | /usr/share/foreman/vendor/ruby/2.7.0/gems/logging-2.3.1/lib/logging/diagnostic_context.rb:474:inblock in create_with_logging_context’
2023-04-05T10:44:23 [D|app|e86bf39f] Rendering common/500.html.erb
2023-04-05T10:44:23 [I|app|e86bf39f] Rendered common/500.html.erb (Duration: 0.8ms | Allocations: 520)
2023-04-05T10:44:23 [I|app|e86bf39f] Completed 500 Internal Server Error in 53ms (Views: 1.3ms | ActiveRecord: 10.2ms | Allocations: 15160)
Expected outcome:
If a remote job is being scheduled, run the job and display results/progress as normal.
Foreman and Proxy versions:
Foreman: 3.6.1
Foreman Proxies: 3.6.1
Foreman and Proxy plugin versions:
Ansible: 3.5.4
DHCP: 3.6.1
DNS: 3.6.1
Dynflow: 0.9.0
Registration: 3.6.1
SSH: ? (loads like forever in the Web UI)
Script: 0.10.1
TFTP: 3.6.1
Templates: 3.6.1
ruby-foreman-remote-execution: 9.1.0-1
ruby-smart-proxy-remote-execution-ssh: 0.10.1-1
Distribution and version:
Debian 11.6
Other relevant data:
I can provide the output of foreman-debug, if desired.