Failed to list certificates: Execution of puppetca failed, check log files

saguet · March 23, 2021, 2:45pm

Problem
Foreman fails to retrieve the certificates from the Puppet CA. I get error message
Foreman also fails to create hosts through the API due to not being able to communicate with the Puppet CA properly.
All other proxy functions I have enabled work as expected.

Failure: ERF50-5345 [Foreman::WrappedException]: Unable to connect ([ProxyAPI::ProxyException]: ERF12-5356 [ProxyAPI::ProxyException]: Unable to get PuppetCA certificates ([RestClient::NotAcceptable]: 406 Not Acceptable) for proxy https://puppet:8443/puppet/ca)

Expected outcome:
Foreman retrieves and lists all certificates from the Puppet CA under Smart Proxies > [proxy] > Puppet CA > Certificates

Foreman and Proxy versions:
Foreman: 2.3.3
Foreman Proxy: 2.3.3

Distribution and version:
Foreman Server: RHEL 7.9
Puppet Server: RHEL 7.5

Other relevant data:
This worked before I updated to Foreman and Foreman-Proxy 2.3.3. Nothing else has changed on the Puppet CA besides updating the Foreman-Proxy related packages.

Here is my /etc/forman-proxy/settings.d/puppetca_puppet_cert.yaml:

---
:ssldir: /etc/puppetlabs/puppet/ssl
#:puppetca_use_sudo: true
#:sudo_command: /usr/bin/sudo

Here is some log output:

2021-03-23T10:43:16 0f736fb4 [W] Failed to list certificates: Execution of puppetca failed, check log files: <Runti
meError>: Execution of puppetca failed, check log files
/usr/share/foreman-proxy/modules/puppetca_puppet_cert/puppetca_impl.rb:26:in `list'
/usr/share/foreman-proxy/modules/puppetca/puppetca_api.rb:14:in `block in <class:Api>'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:1635:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:1635:in `block in compile!'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:992:in `block (3 levels) in route!'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:1011:in `route_eval'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:992:in `block (2 levels) in route!'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:1040:in `block in process_route'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:1038:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:1038:in `process_route'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:990:in `block in route!'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:989:in `each'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:989:in `route!'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:1097:in `block in dispatch!'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:1076:in `block in invoke'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:1076:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:1076:in `invoke'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:1094:in `dispatch!'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:924:in `block in call!'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:1076:in `block in invoke'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:1076:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:1076:in `invoke'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:924:in `call!'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:913:in `call'
/usr/share/foreman-proxy/lib/proxy/log.rb:105:in `call'
/usr/share/foreman-proxy/lib/proxy/request_id_middleware.rb:11:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-protection-2.0.3/lib/rack/protection/xss_header.rb:18:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-protection-2.0.3/lib/rack/protection/path_traversal.rb:16:in `cal
l'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-protection-2.0.3/lib/rack/protection/json_csrf.rb:26:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-protection-2.0.3/lib/rack/protection/base.rb:50:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-protection-2.0.3/lib/rack/protection/base.rb:50:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-protection-2.0.3/lib/rack/protection/frame_options.rb:31:in `call
'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/null_logger.rb:11:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/head.rb:12:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/show_exceptions.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:194:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:1958:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:1502:in `block in call'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:1729:in `synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/sinatra-2.0.3/lib/sinatra/base.rb:1502:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/urlmap.rb:74:in `block in call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/urlmap.rb:58:in `each'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/urlmap.rb:58:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/builder.rb:244:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/handler/webrick.rb:95:in `service'
/opt/rh/rh-ruby25/root/usr/share/ruby/webrick/httpserver.rb:140:in `service'
/opt/rh/rh-ruby25/root/usr/share/ruby/webrick/httpserver.rb:96:in `run'
/opt/rh/rh-ruby25/root/usr/share/ruby/webrick/server.rb:307:in `block in start_thread'
/opt/theforeman/tfm/root/usr/share/gems/gems/logging-2.3.0/lib/logging/diagnostic_context.rb:474:in `block in creat
e_with_logging_context'
2021-03-23T10:43:16 0f736fb4 [I] Finished GET /puppet/ca with 406 (147.91 ms)

Please let me know if any more info is needed. All and any help is much appreciated as this has been a huge problem for me for the last 3 days.

saguet · March 23, 2021, 6:04pm

I also noticed this in /var/log/messages:

Mar 23 13:43:30 puppet smart-proxy: /opt/rh/rh-ruby25/root/usr/share/gems/gems/openssl-2.1.2/lib/openssl/ssl.rb:20:in `class:SSLContext’: uninitialized constant OpenSSL::SSL::TLS1_VERSION (NameError)

ekohl · March 26, 2021, 12:52pm

That’s surprising.

I took the liberty of editing your post to add code tags to make it readable.

First of all, from the traceback it looks like you’re using Puppetserver 5. Is that correct?

It appears the call to puppet cert --list --all fails. I’d execute that manually.

Do you have a traceback from that? I can’t see from the code where that would be called.

saguet · March 26, 2021, 2:19pm

Thanks for looking into this.
I think this would be a traceback of the puppet ca call:

Mar 22 10:37:10 puppet smart-proxy: 10.99.202.164 - - [22/Mar/2021:10:37:10 EDT] "GET /puppet/ca HTTP/1.1" 406 74
Mar 22 10:37:10 puppet smart-proxy: - -> /puppet/ca
Mar 22 10:37:10 puppet smart-proxy: /opt/rh/rh-ruby25/root/usr/share/gems/gems/openssl-2.1.2/lib/openssl/ssl.rb:20:in `<class:SSLContext>': uninitialized constant OpenSSL::SSL::TLS1_VERSION (NameError)
Mar 22 10:37:10 puppet smart-proxy: from /opt/rh/rh-ruby25/root/usr/share/gems/gems/openssl-2.1.2/lib/openssl/ssl.rb:18:in `<module:SSL>'
Mar 22 10:37:10 puppet smart-proxy: from /opt/rh/rh-ruby25/root/usr/share/gems/gems/openssl-2.1.2/lib/openssl/ssl.rb:17:in `<module:OpenSSL>'
Mar 22 10:37:10 puppet smart-proxy: from /opt/rh/rh-ruby25/root/usr/share/gems/gems/openssl-2.1.2/lib/openssl/ssl.rb:16:in `<top (required)>'
Mar 22 10:37:10 puppet smart-proxy: from /opt/puppetlabs/puppet/lib/ruby/2.4.0/rubygems/core_ext/kernel_require.rb:55:in `require'
Mar 22 10:37:10 puppet smart-proxy: from /opt/puppetlabs/puppet/lib/ruby/2.4.0/rubygems/core_ext/kernel_require.rb:55:in `require'
Mar 22 10:37:10 puppet smart-proxy: from /opt/rh/rh-ruby25/root/usr/share/gems/gems/openssl-2.1.2/lib/openssl.rb:21:in `<top (required)>'
Mar 22 10:37:10 puppet smart-proxy: from /opt/puppetlabs/puppet/lib/ruby/2.4.0/rubygems/core_ext/kernel_require.rb:55:in `require'
Mar 22 10:37:10 puppet smart-proxy: from /opt/puppetlabs/puppet/lib/ruby/2.4.0/rubygems/core_ext/kernel_require.rb:55:in `require'
Mar 22 10:37:10 puppet smart-proxy: from /opt/puppetlabs/puppet/lib/ruby/2.4.0/securerandom.rb:4:in `<top (required)>'
Mar 22 10:37:10 puppet smart-proxy: from /opt/puppetlabs/puppet/lib/ruby/2.4.0/rubygems/core_ext/kernel_require.rb:55:in `require'
Mar 22 10:37:10 puppet smart-proxy: from /opt/puppetlabs/puppet/lib/ruby/2.4.0/rubygems/core_ext/kernel_require.rb:55:in `require'
Mar 22 10:37:10 puppet smart-proxy: from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:12:in `<top (required)>'
Mar 22 10:37:10 puppet smart-proxy: from /opt/puppetlabs/puppet/lib/ruby/2.4.0/rubygems/core_ext/kernel_require.rb:55:in `require'
Mar 22 10:37:10 puppet smart-proxy: from /opt/puppetlabs/puppet/lib/ruby/2.4.0/rubygems/core_ext/kernel_require.rb:55:in `require'
Mar 22 10:37:10 puppet smart-proxy: from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet.rb:14:in `<top (required)>'
Mar 22 10:37:10 puppet smart-proxy: from /opt/puppetlabs/puppet/lib/ruby/2.4.0/rubygems/core_ext/kernel_require.rb:55:in `require'
Mar 22 10:37:10 puppet smart-proxy: from /opt/puppetlabs/puppet/lib/ruby/2.4.0/rubygems/core_ext/kernel_require.rb:55:in `require'
Mar 22 10:37:10 puppet smart-proxy: from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/command_line.rb:12:in `<top (required)>'
Mar 22 10:37:10 puppet smart-proxy: from /opt/puppetlabs/puppet/lib/ruby/2.4.0/rubygems/core_ext/kernel_require.rb:55:in `require'
Mar 22 10:37:10 puppet smart-proxy: from /opt/puppetlabs/puppet/lib/ruby/2.4.0/rubygems/core_ext/kernel_require.rb:55:in `require'
Mar 22 10:37:10 puppet smart-proxy: from /opt/puppetlabs/puppet/bin/puppet:4:in `<main>'

My suspicion is that the problem is rooted somewhere in the ruby packages which are pulled in from the SCL repo starting at version 2.0 of the proxy package.
I reverted back to v1.24.3 of the proxy without the SCL ruby packages and everything started working again.