Script execution failed - fresh install of foreman, new client

Support
1

Problem:
Added a new client to my new foreman 3.6.1 instance, and cannot Run Puppet Once from the clients menu.

Expected outcome:
Puppet runs successfully.

Foreman and Proxy versions:
Latest. Installed 3.5.2 yesterday, upgraded this morning to 3.6.1 immediately before adding new client.

Foreman and Proxy plugin versions:
Latest 3.6.1

Distribution and version:
Foreman on Almalinux 8.7, puppet client on freebsd 13.1

Other relevant data:

SSH from foreman server to the client works fine manually:

sudo -u foreman-proxy ssh root@host -i /var/lib/foreman-proxy/ssh/id_rsa_foreman_proxy

Remote directory /var/tmp is executable:

ls -ltr /var/ | grep tmp
drwxrwxrwt   3 root     wheel    512 Mar 29 14:41 tmp

I created a test.sh script in the tmp dir and I’m able to SSH in as above, and run the script sucessfully.

Here is what shows up in the proxy.log on the foreman server when i try to Run Puppet Once:

2023-03-29T13:46:51 c56842bb [I] Started GET /dynflow/tasks/count state=running
2023-03-29T13:46:51 c56842bb [I] Finished GET /dynflow/tasks/count with 200 (1.05 ms)
2023-03-29T13:46:51 c56842bb [I] Started POST /dynflow/tasks/launch 
2023-03-29T13:46:51 c56842bb [I] Finished POST /dynflow/tasks/launch with 200 (9.28 ms)
2023-03-29T13:46:55 c56842bb [E] Script execution failed
2023-03-29T13:47:01 c56842bb [E] <Dynflow::Action::WithSubPlans::SubtaskFailedException> A sub task failed
2

Confirmed I’m configured to use the foreman-proxy user:
–foreman-proxy-plugin-remote-execution-script-ssh-identity-file Provide an alternative name for the SSH keys (current: “id_rsa_foreman_proxy”)

3

What does the webui say? If you go to Monitor > Jobs > $job and click a hostname of the host in the table at the bottom.

Could you bump log_level to debug in /etc/foreman-proxy/settings.yaml, restart foreman-proxy service, run the job again and then check /var/log/foreman-proxy/proxy.log? It should print the exact commands it is running and you could try following along.

1 Like
4

Thanks for the kind timely reply @aruzicka ! :grinning:

I only have /etc/foreman/settings.yaml, there is no /etc/foreman-proxy/settings.yaml. It looks like it’s the right file however, I have this snippet in there:

# Log settings for the current environment can be adjusted by adding them
# here. For example, if you want to increase the log level.
:logging:
  :level: info   <== debug?
  :production:
    :type: file
    :layout: multiline_request_pattern

It would be nice to see the various logging levels listed in the comment, I guess it’s safe to assume ‘level:debug’ is a valid option.

Bounced foreman-proxy: systemctl restart foreman-proxy

Same proxy.log entries - is debug level incorrect?:

2023-03-30T08:45:13 c0b68fb9 [I] Started GET /dynflow/tasks/count state=running
2023-03-30T08:45:13 c0b68fb9 [I] Finished GET /dynflow/tasks/count with 200 (3.88 ms)
2023-03-30T08:45:13 c0b68fb9 [I] Started POST /dynflow/tasks/launch 
2023-03-30T08:45:13 c0b68fb9 [I] Finished POST /dynflow/tasks/launch with 200 (10.3 ms)
2023-03-30T08:45:16 c0b68fb9 [E] Script execution failed
2023-03-30T08:45:23 c0b68fb9 [E] <Dynflow::Action::WithSubPlans::SubtaskFailedException> A sub task failed

As far as the web gui, it gives me also the same as before:

Actions::RemoteExecution::RunHostsJob

Input:

{"job_invocation"=>
  {"id"=>16, "name"=>"Puppet", "description"=>"Run Puppet once with \"''\""},
 "job_category"=>"Puppet",
 "job_invocation_id"=>16,
 "proxy_batch_size"=>100,
 "trigger_run_step_id"=>5,
 "current_request_id"=>"c0b68fb9-c8e6-4949-b556-18edc4fa84eb",
 "current_timezone"=>"America/New_York",
 "current_organization_id"=>1,
 "current_location_id"=>2,
 "current_user_id"=>4}

Output:

{"host_count"=>1,
 "remote_triggered_count"=>0,
 "planned_count"=>1,
 "cancelled_count"=>0,
 "total_count"=>1,
 "failed_count"=>1,
 "pending_count"=>0,
 "success_count"=>0}

Exception:

Dynflow::Action::WithSubPlans::SubtaskFailedException: A sub task failed

And this:

Actions::RemoteExecution::RunHostsJob

Input:

{"job_invocation"=>
  {"id"=>16, "name"=>"Puppet", "description"=>"Run Puppet once with \"''\""},
 "job_category"=>"Puppet",
 "job_invocation_id"=>16,
 "proxy_batch_size"=>100,
 "trigger_run_step_id"=>5,
 "current_request_id"=>"c0b68fb9-c8e6-4949-b556-18edc4fa84eb",
 "current_timezone"=>"America/New_York",
 "current_organization_id"=>1,
 "current_location_id"=>2,
 "current_user_id"=>4}

Output:

{"host_count"=>1,
 "remote_triggered_count"=>0,
 "planned_count"=>1,
 "cancelled_count"=>0,
 "total_count"=>1,
 "failed_count"=>1,
 "pending_count"=>0,
 "success_count"=>0}
5

Oh, sorry. It is /etc/foreman-proxy/settings.yml (yml vs yaml always trips me up). /etc/foreman/settings.yaml controls foreman, /etc/foreman-proxy/settings.yml controls foreman proxy and we want to bump the log level on the proxy.

That looks like details of a job-level task, you really shouldn’t be seeing that if you go to Monitor > Jobs > $job and click a hostname of the host in the table at the bottom.