Problem:
Schedule Remote Job using Salt Run state.highstate is pending forever (same for other commands, e.g. “test.ping”)
Expected outcome:
Job finishes and generates a report that can be imported.
Foreman and Proxy versions:
3.2-stable
Foreman and Proxy plugin versions:
latest available gems
Distribution and version:
Using official docker-compose.yml and image crated from Dockerfile at The Foreman · GitHub
Other relevant data:
I use the “official” Docker containers and the docker-compose file extended by two containers running a Salt master (together with Smart Proxy and plugins) and a Salt minion. The communication between Salt master and minion is fine, also the communication between Foreman and Salt works in most cases:
- Creating Salt proxy
- Checking Salt keys
- Importing states and grains
- Uploading reports
Yet if I want to start a remote job as documented in Managing Hosts the job is “pending” forever.
In the log of the “app” container the job is started without error messages:
foreman-app-1 | 2022-04-27T11:59:09 [I|app|dc6e5d4d] Started POST "/job_invocations" for 87.177.153.9 at 2022-04-27 11:59:09 +0000
foreman-app-1 | 2022-04-27T11:59:09 [I|app|dc6e5d4d] Processing by JobInvocationsController#create as HTML
foreman-app-1 | 2022-04-27T11:59:09 [I|app|dc6e5d4d] Parameters: {"utf8"=>"✓", "authenticity_token"=>"7KudPyGJ4DD7JYVaaUi3AN8X3QGKl6Osbv5sG0pXSwAJSPAvX365ngKocrM6O3SmEkmfkZ5HzARMM1xNFq/hLQ==", "job_invocation"=>{"job_category"=>"Salt", "remote_execution_feature_id"=>"", "providers"=>{"Salt"=>{"job_template_id"=>"153", "job_templates"=>{"153"=>{"effective_user"=>"", "execution_timeout_interval"=>""}, "152"=>{"inp
ut_values"=>"[FILTERED]", "effective_user"=>"", "execution_timeout_interval"=>""}, "155"=>{"input_values"=>"[FILTERED]", "effective_user"=>"", "execution_timeout_interval"=>""}}}}, "description"=>"Run Salt state.highstate on host", "description_override"=>"Run Salt state.highstate on host", "description_format"=>"Run Salt state.highstate on host", "password"=>"[FILTERED]", "key_passphrase"=>"", "effective_user_password"=>"[
FILTERED]", "concurrency_level"=>"", "time_span"=>""}, "targeting"=>{"bookmark_id"=>"", "search_query"=>"name ^ (docker-salt-minion)", "randomized_ordering"=>"false", "targeting_type"=>"static_query"}, "fakepassword"=>"[FILTERED]", "triggering"=>{"mode"=>"immediate", "start_at_raw"=>"2022-04-27 13:58", "start_before_raw"=>"", "input_type"=>"daily", "cronline"=>"", "days"=>"", "days_of_week"=>{"1"=>"0", "2"=>"0", "3"=>"0", "
4"=>"0", "5"=>"0", "6"=>"0", "7"=>"0"}, "time"=>{"time(1i)"=>"2022", "time(2i)"=>"4", "time(3i)"=>"27", "time(4i)"=>"13", "time(5i)"=>"59"}, "max_iteration"=>"", "end_time_limited"=>"false", "end_time"=>{"end_time(1i)"=>"2022", "end_time(2i)"=>"4", "end_time(3i)"=>"27", "end_time(4i)"=>"13", "end_time(5i)"=>"59"}, "purpose"=>""}, "commit"=>"Submit"}
[...]
foreman-app-1 | 2022-04-27T11:59:09 [D|dyn|] ExecutionPlan 7696a1b3-7475-410c-b23b-77b2fc35c89d pending >> planning
foreman-app-1 | 2022-04-27T11:59:09 [I|bac|] Task {label: Actions::RemoteExecution::RunHostsJob, id: 061e9d0f-470c-42ef-a4e9-1b5a0377e4a0, execution_plan_id: 7696a1b3-7475-410c-b23b-77b2fc35c89d} state changed: planning
foreman-app-1 | 2022-04-27T11:59:09 [D|dyn|] Step 7696a1b3-7475-410c-b23b-77b2fc35c89d: 1 pending >> running in phase Plan Actions::RemoteExecution::RunHostsJob
foreman-app-1 | 2022-04-27T11:59:10 [D|dyn|] Step 7696a1b3-7475-410c-b23b-77b2fc35c89d: 4 pending >> running in phase Plan Actions::TriggerProxyBatch
foreman-app-1 | 2022-04-27T11:59:10 [D|dyn|] Step 7696a1b3-7475-410c-b23b-77b2fc35c89d: 4 running >> success in phase Plan Actions::TriggerProxyBatch
foreman-app-1 | 2022-04-27T11:59:10 [D|dyn|] Step 7696a1b3-7475-410c-b23b-77b2fc35c89d: 1 running >> success in phase Plan Actions::RemoteExecution::RunHostsJob
foreman-app-1 | 2022-04-27T11:59:10 [D|dyn|] ExecutionPlan 7696a1b3-7475-410c-b23b-77b2fc35c89d planning >> planned
foreman-app-1 | 2022-04-27T11:59:10 [I|bac|] Task {label: Actions::RemoteExecution::RunHostsJob, id: 061e9d0f-470c-42ef-a4e9-1b5a0377e4a0, execution_plan_id: 7696a1b3-7475-410c-b23b-77b2fc35c89d} state changed: planned
I also see something in the log of the “orchestrator” container:
foreman-orchestrator-1 | 2022-04-27T11:59:10 [D|dyn|] ExecutionPlan 7696a1b3-7475-410c-b23b-77b2fc35c89d planned >> running
foreman-orchestrator-1 | 2022-04-27T11:59:10 [I|bac|] Task {label: Actions::RemoteExecution::RunHostsJob, id: 061e9d0f-470c-42ef-a4e9-1b5a0377e4a0, execution_plan_id: 7696a1b3-7475-410c-b23b-77b2fc35c89d} state changed: running
The log of the “worker” container does not show anything regarding this job. Also the Salt master and Smart proxy never receive any commands.
It would be nice if somebody could give me any hint on how to debug this further. Please let me know if I can provide any additional information.
Thank you very much in advance and best regards
Jannis
P.S.: Originally I got the error message “The Dynflow world was not initialized yet. If your plugin uses it, make sure to call Rails.application.dynflow.require! in some initializer” when trying to start a job from Foreman. I worked around this by inserting @dynflow.initialize! in function dynflow of config/application.rb.