Foreman installation certificates broken (3.6.1 w Katello 4.8.3), Likely Proxy

Problem:
Sometime after updating certificates I executed a remote job (via ssh) from the foreman server. Although the jobs executed successfully on the hosts, the jobs never returned a status to the foreman server and eventually timed out.

Looking at the logs, I came across this message:

/var/log/foreman-proxy/proxy.log:

2023-07-21T15:40:21 8abd0f6f [I] Finished GET /dynflow/tasks/d313f2d3-b519-4ac7-91dd-f00a70cd45d7/status with 200 (10.21 ms)
2023-07-21T15:40:21 9224a45b [E] <RuntimeError> Failed performing callback to Foreman server: 403 {
  "error": {"message":"Access denied","details":"Missing one of the required permissions: ","missing_permissions":[]}

I have search google and tried many things, all of which have failed to resolve the issue. I believe the most significant thing I found was around the client ca cert:

related to: SSL Errors with proxy and installer - #12 by madmahdi

[root@foreman ~]# openssl verify -CAfile /etc/foreman/proxy_ca.pem /etc/foreman/client_cert.pem
C = US, ST = North Carolina, O = FOREMAN, OU = PUPPET, CN = foreman.ivenix.net
error 20 at 0 depth lookup: unable to get local issuer certificate
error /etc/foreman/client_cert.pem: verification failed

[root@foreman ~]# openssl verify -CAfile /etc/pki/katello/certs/katello-default-ca.crt /etc/foreman/client_cert.pem
/etc/foreman/client_cert.pem: OK

I thought updating the client ca cert to katello-default-ca.crt:

foreman-installer --scenario katello --foreman-client-ssl-ca /etc/pki/katello/certs/katello-default-ca.crt

would resolve the issue, but only resulted in:

RuntimeError: The only applicable proxy foreman.ivenix.net is down.

Been trying to get this working for the past week, but I have hit a wall on trying things. I do have a snaphot to get me back to the original issue ("Missing one of the required permissions).

Expected outcome:
Remote job returns success status, foreman displays success status on web page.

Foreman and Proxy versions:
3.6.1
Foreman and Proxy plugin versions:

nstalled Packages

  • candlepin-4.2.13-1.el8.noarch
  • candlepin-selinux-4.2.13-1.el8.noarch
  • foreman-3.6.1-1.el8.noarch
  • foreman-cli-3.6.1-1.el8.noarch
  • foreman-debug-3.6.1-1.el8.noarch
  • foreman-dynflow-sidekiq-3.6.1-1.el8.noarch
  • foreman-installer-3.6.1-1.el8.noarch
  • foreman-installer-katello-3.6.1-1.el8.noarch
  • foreman-postgresql-3.6.1-1.el8.noarch
  • foreman-proxy-3.6.1-1.el8.noarch
  • foreman-release-3.6.1-1.el8.noarch
  • foreman-selinux-3.6.1-1.el8.noarch
  • foreman-service-3.6.1-1.el8.noarch
  • katello-4.8.3-1.el8.noarch
  • katello-ca-consumer-foreman.ivenix.net-1.0-2.noarch
  • katello-certs-tools-2.9.0-1.el8.noarch
  • katello-client-bootstrap-1.7.9-1.el8.noarch
  • katello-common-4.8.3-1.el8.noarch
  • katello-debug-4.8.3-1.el8.noarch
  • katello-repos-4.8.3-1.el8.noarch
  • katello-selinux-4.0.2-3.el8.noarch
  • pulpcore-selinux-1.3.2-1.el8.x86_64
  • python39-pulp-ansible-0.16.0-1.el8.noarch
  • python39-pulp-certguard-1.5.6-1.el8.noarch
  • python39-pulp-cli-0.14.0-4.el8.noarch
  • python39-pulp-container-2.14.6-1.el8.noarch
  • python39-pulp-deb-2.20.2-1.el8.noarch
  • python39-pulp-file-1.12.0-1.el8.noarch
  • python39-pulp-python-3.8.0-1.el8.noarch
  • python39-pulp-rpm-3.19.8-1.el8.noarch
  • python39-pulpcore-3.22.7-1.el8.noarch
  • qpid-proton-c-0.37.0-1.el8.x86_64
  • rubygem-foreman-tasks-7.2.1-2.fm3_6.el8.noarch
  • rubygem-foreman_maintain-1.3.0-1.el8.noarch
  • rubygem-foreman_remote_execution-9.1.0-1.fm3_6.el8.noarch
  • rubygem-hammer_cli-3.6.0-1.el8.noarch
  • rubygem-hammer_cli_foreman-3.6.0-1.el8.noarch
  • rubygem-hammer_cli_foreman_remote_execution-0.2.2-1.fm3_0.el8.noarch
  • rubygem-hammer_cli_foreman_tasks-0.0.18-1.fm3_5.el8.noarch
  • rubygem-hammer_cli_katello-1.8.3-1.el8.noarch
  • rubygem-katello-4.8.3-1.el8.noarch
  • rubygem-pulp_ansible_client-0.16.0-1.el8.noarch
  • rubygem-pulp_certguard_client-1.5.7-1.el8.noarch
  • rubygem-pulp_container_client-2.14.3-1.el8.noarch
  • rubygem-pulp_deb_client-2.20.2-1.el8.noarch
  • rubygem-pulp_file_client-1.12.0-1.el8.noarch
  • rubygem-pulp_ostree_client-2.0.0-1.el8.noarch
  • rubygem-pulp_python_client-3.8.0-1.el8.noarch
  • rubygem-pulp_rpm_client-3.19.0-1.el8.noarch
  • rubygem-pulpcore_client-3.22.2-1.el8.noarch
  • rubygem-qpid_proton-0.37.0-1.el8.x86_64
  • rubygem-smart_proxy_pulp-3.2.0-3.fm3_3.el8.noarch

Distribution and version:

Other relevant data:

I will add that I also tried the following:

foreman-installer --certs-reset

and

foreman-installer --certs-update-all

Neither of which worked. With my knowledge, it feels like the only step left is to setup and a new VM and do a fresh install. I don’t mind doing that, but all the reconfiguration is something I really don’t want to do.

Does anyone have any suggestions? Pretty much exhausted any ideas I have had. Am I down to just a new install and reconfiguring everything?

Trying random commands like --certs-reset or --foreman-client-ssl-ca will just do more damage than good.

katello-default-ca.crt is the internal CA for communication between foreman components/proxies. That’s not the one used for --foreman-client-ssl-ca. So basically you made it worse.

Thus set --foreman-client-ssl-ca back to the value you had before the change. I hope you didn’t make other random changes.

And follow the docs to use or update custom certificates: Installing Foreman 3.6 Server with Katello 4.8 Plugin on RHEL/CentOS

The docs will work, if you didn’t break it before with other changes…

So I agree commands (I’d like to believe that I have a logical reason for trying and are not totally random) can make things worse; however, I do have a snaphot to get me back to the original issue. So I have been trying things, failing, and then reverting to back to the original failure point.

I do not have a snapshot prior to things breaking as things appeared to be working fine until several weeks later when I tried to execute a remote job. This is when I discovered things were broken. Everything else appears to be working with the exception of execution remove (ssh) jobs. The commands ARE executed on the remote host successfully; however the foreman server is unable to determine the status from the host due to the error logged in the proxy.log.

Having done many google searches, it seem others have gotten into a “broken state” and there are no docs to resolve this. Some issues I’ve seen were self inflicted and some due to software bugs. I am willing to accept I screwed up somehow; however, as I don’t have a time machine, I am where I am, and I am trying to get remote execution to work.

Everything else is working fine with the custom certs I had updated (they were already installed and expired so I was updating them).

Thanks,

Robert

So rolling everything back to the point of the initial error (with the VM snapshot), if I execute a remote command on a single command, theses are the errors I see in the foreman logs. Any suggestions on steps I can try to resolve this issue would be greatly appreciated:

==> /var/log/foreman/production.log <==
2023-08-07T08:52:35 [I|app|893f1ba2] Started POST "/foreman_tasks/api/tasks/callback" for 10.5.23.252 at 2023-08-07 08:52:35 -0400
2023-08-07T08:52:35 [I|app|893f1ba2] Processing by ForemanTasks::Api::TasksController#callback as HTML
2023-08-07T08:52:35 [I|app|893f1ba2]   Parameters: {"callback"=>{"task_id"=>"975bcb79-c278-494d-b852-cbfa44b789fb", "step_id"=>3}, "data"=>{"result"=>[{"output_type"=>"stdout", "output"=>"Mon 07 Aug 2023 08:52:34 AM EDT\n", "timestamp"=>1691412754.1092706}, {"output_type"=>"stdout", "output"=>" 08:52:34 up 17 days, 28 min,  1 user,  load average: 0.20, 0.28, 0.31\n", "timestamp"=>1691412755.1155863}], "runner_id"=>"e9075502-68fb-43eb-9bfd-db704b79a25b", "exit_status"=>0}, "task"=>{}}
2023-08-07T08:52:35 [I|app|893f1ba2] Client certificate is invalid: FAILED:unable to verify the first certificate
2023-08-07T08:52:35 [W|app|893f1ba2] SSL cert has not been verified (FAILED:unable to verify the first certificate) - request from 10.5.23.252, foreman.ivenix.net
2023-08-07T08:52:35 [I|app|893f1ba2]   Rendered api/v2/errors/access_denied.json.rabl within api/v2/layouts/error_layout (Duration: 2.3ms | Allocations: 284)
2023-08-07T08:52:35 [I|app|893f1ba2]   Rendered layout api/v2/layouts/error_layout.json.erb (Duration: 3.7ms | Allocations: 499)
2023-08-07T08:52:35 [I|app|893f1ba2] Filter chain halted as #<Proc:0x0000562c955eff98 /usr/share/foreman/app/controllers/concerns/foreman/controller/smart_proxy_auth.rb:14> rendered or redirected
2023-08-07T08:52:35 [I|app|893f1ba2] Completed 403 Forbidden in 22ms (Views: 7.6ms | ActiveRecord: 5.2ms | Allocations: 2552)
2023-08-07T08:52:35 [I|app|56351b7a] Started GET "/job_invocations/1268?hosts_needs_refresh=&_=1691412759165" for 172.16.50.15 at 2023-08-07 08:52:35 -0400

And…

==> /var/log/foreman-proxy/proxy.log <==
2023-08-07T08:52:38 e055c915 [E] <RuntimeError> Failed performing callback to Foreman server: 403 {
  "error": {"message":"Access denied","details":"Missing one of the required permissions: ","missing_permissions":[]}
}

        /usr/share/gems/gems/smart_proxy_dynflow-0.9.0/lib/smart_proxy_dynflow/callback.rb:16:in `callback'
        /usr/share/gems/gems/smart_proxy_dynflow-0.9.0/lib/smart_proxy_dynflow/callback.rb:7:in `send_to_foreman_tasks'
        /usr/share/gems/gems/smart_proxy_dynflow-0.9.0/lib/smart_proxy_dynflow/callback.rb:28:in `run'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/action.rb:582:in `block (3 levels) in execute_run'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/middleware/stack.rb:27:in `pass'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/middleware.rb:19:in `pass'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/action/progress.rb:31:in `with_progress_calculation'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/action/progress.rb:17:in `run'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/middleware/stack.rb:23:in `call'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/middleware/stack.rb:27:in `pass'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/middleware.rb:19:in `pass'
        /usr/share/gems/gems/smart_proxy_dynflow-0.9.0/lib/smart_proxy_dynflow/middleware/keep_current_request_id.rb:15:in `block in run'
        /usr/share/gems/gems/smart_proxy_dynflow-0.9.0/lib/smart_proxy_dynflow/middleware/keep_current_request_id.rb:49:in `restore_current_request_id'
        /usr/share/gems/gems/smart_proxy_dynflow-0.9.0/lib/smart_proxy_dynflow/middleware/keep_current_request_id.rb:15:in `run'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/middleware/stack.rb:23:in `call'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/middleware/stack.rb:27:in `pass'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/middleware.rb:19:in `pass'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/middleware.rb:32:in `run'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/middleware/stack.rb:23:in `call'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/middleware/world.rb:31:in `execute'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/action.rb:581:in `block (2 levels) in execute_run'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/action.rb:580:in `catch'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/action.rb:580:in `block in execute_run'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/action.rb:483:in `block in with_error_handling'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/action.rb:483:in `catch'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/action.rb:483:in `with_error_handling'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/action.rb:575:in `execute_run'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/action.rb:296:in `execute'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:18:in `block (2 levels) in execute'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/execution_plan/steps/abstract.rb:167:in `with_meta_calculation'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:17:in `block in execute'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:32:in `open_action'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:16:in `execute'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/director.rb:69:in `execute'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/executors/parallel/worker.rb:15:in `block in on_message'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/executors.rb:18:in `run_user_code'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/executors/parallel/worker.rb:14:in `on_message'
        /usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/context.rb:46:in `on_envelope'
        /usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/executes_context.rb:7:in `on_envelope'
        /usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/actor.rb:122:in `on_envelope'
        /usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
        /usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/awaits.rb:15:in `on_envelope'
        /usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
        /usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
        /usr/share/gems/gems/dynflow-1.6.8/lib/dynflow/actor.rb:56:in `on_envelope'
        /usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
        /usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/buffer.rb:38:in `process_envelope'
        /usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/buffer.rb:31:in `process_envelopes?'
        /usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/buffer.rb:20:in `on_envelope'
        /usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
        /usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/termination.rb:55:in `on_envelope'
        /usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
        /usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/removes_child.rb:10:in `on_envelope'
        /usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/abstract.rb:25:in `pass'
        /usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
        /usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/core.rb:162:in `process_envelope'
        /usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/core.rb:96:in `block in on_envelope'
        /usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/core.rb:119:in `block (2 levels) in schedule_execution'
        /usr/share/gems/gems/concurrent-ruby-1.1.10/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:47:in `block in synchronize'
        /usr/share/gems/gems/concurrent-ruby-1.1.10/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:47:in `synchronize'
        /usr/share/gems/gems/concurrent-ruby-1.1.10/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:47:in `synchronize'
        /usr/share/gems/gems/concurrent-ruby-edge-0.6.0/lib/concurrent-ruby-edge/concurrent/actor/core.rb:116:in `block in schedule_execution'
        /usr/share/gems/gems/concurrent-ruby-1.1.10/lib/concurrent-ruby/concurrent/executor/serialized_execution.rb:18:in `call'
        /usr/share/gems/gems/concurrent-ruby-1.1.10/lib/concurrent-ruby/concurrent/executor/serialized_execution.rb:96:in `work'
        /usr/share/gems/gems/concurrent-ruby-1.1.10/lib/concurrent-ruby/concurrent/executor/serialized_execution.rb:77:in `block in call_job'
        /usr/share/gems/gems/concurrent-ruby-1.1.10/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:352:in `run_task'
        /usr/share/gems/gems/concurrent-ruby-1.1.10/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:343:in `block (3 levels) in create_worker'
        /usr/share/gems/gems/concurrent-ruby-1.1.10/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:334:in `loop'
        /usr/share/gems/gems/concurrent-ruby-1.1.10/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:334:in `block (2 levels) in create_worker'
        /usr/share/gems/gems/concurrent-ruby-1.1.10/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:333:in `catch'
        /usr/share/gems/gems/concurrent-ruby-1.1.10/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:333:in `block in create_worker'
        /usr/share/gems/gems/logging-2.3.1/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'

It still looks to me like you did not follow the docs to update the certificates… Not knowing what you did exactly to update the certificates before it’s kind of futile trying to fix the problems wherever you may notice them.

I have never had problems after updating certificates following the docs…

I had to put this to the side and am getting back to it now. If anyone else has suggestions on how to resolve this issue I would greatly appreciate it. I am willing to accept “I did not follow the docs to update the certificates”; however, other than shaming me (which is fine, whatever), I’m looking for any ideas to move me forward. It seems a fresh install and re-configuring the foreman server is my only option at this point. Thanks.

I don’t know what is unclear about my advice: follow the docs. I have linked to the docs before. The docs explain how to check your custom certificate and how to deploy it. So just do it: follow the docs. foreman-installer should configure everything in the right places.

Once you do that, there are two possible outcomes: either foreman-installer sets everything correctly and you didn’t break it beyond what foreman-installer handles.

Or it still doesn’t work. Then it would be necessary to look at the logs again, but at least the system is in a state closer to normal than now. Possibly, the --foreman-client-ssl-ca needs to be fixed then, if that’s all you have manually modified before. But until then, I would hope that foreman-installer sets everything right again if you use the procedure from the docs.

So please follow the docs. I don’t really see the point in copying those commands from the docs in here…