Foreman can't connect to PuppetDB

Problem:

Foreman can’t connect to PuppetDB. Running node.rb reports this error:

During fact upload occured an exception: SSL_connect returned=1 errno=0 state=error: certificate verify failed (unable to get local issuer certificate)
/etc/puppetlabs/puppet/node.rb:414: warning: constant ::TimeoutError is deprecated
Serving cached ENC: Could not send facts to Foreman: SSL_connect returned=1 errno=0 state=error: certificate verify failed (unable to get local issuer certificate)

Expected outcome:

Normal connection. Facts become visible, hosts are deleted from PuppetDB when deleted in Foreman.

Foreman and Proxy versions:

Foreman 1.24.2

Foreman and Proxy plugin versions:

PuppetDB plugin, the version that came with 1.24.2 :slight_smile:

Distribution and version:

Debian Buster amd64

Other relevant data:

Puppet itself is happily adding new hosts to PuppetDB after their initial run. The whole Puppet/Foreman combo was installed on a fresh Debian Buster machine by the Foreman-installer, PuppetDB is on a separate machine not under Foreman control.

Puppet and Foreman use exactly the same certs/keys, yet Puppet can and Foreman can’t connect. PuppetDB uses the same cert/key for the puppet agent and the puppetdb service.

1 Like

I’m pretty sure it’s an SSL problem, but I have no idea where to look anymore. All settings seem to be fine: everything in Foreman uses the same cert, key and ca: the ones under /etc/puppetlabs/puppet/ssl. The only exception is port 443, which uses a letsencrypt-cert for obvious reasons.

PuppetDB is configured to use the exact same cert, key and ca as the puppet agent: again, the ones under /etc/puppetlabs/puppet/ssl. The setup of puppetdb copies those files to a directory readable by the puppetdb user. I checked: they’re exactly the same. But that cert doesn’t include the ca, which gives this error:

# echo | openssl s_client -connect puppetdb.my.domain:8081 | openssl x509 -noout
Can't use SSL_get_servername
depth=0 CN = puppetdb.my.domain
verify error:num=20:unable to get local issuer certificate
verify return:1
depth=0 CN = puppetdb.my.domain
verify error:num=21:unable to verify the first certificate
verify return:1
139948533306496:error:141A318A:SSL routines:tls_process_ske_dhe:dh key too small:../ssl/statem/statem_clnt.c:2150:

So I manually added the chain to the cert and ran the check again, but to no avail:

# echo | openssl s_client -connect puppetdb.my.domain:8081 | openssl x509 -noout
depth=2 CN = Puppet Root CA: b4f58877353935
verify error:num=19:self signed certificate in certificate chain
verify return:1
depth=2 CN = Puppet Root CA: b4f58877353935
verify return:1
depth=1 CN = Puppet CA: foreman.my.domain
verify return:1
depth=0 CN = puppetdb.my.domain
verify return:1
139945597060224:error:141A318A:SSL routines:tls_process_ske_dhe:dh key too small:../ssl/statem/statem_clnt.c:2150:

If I do a puppetrun, most of it seems to go just fine. This is what the puppetserver logs:

2020-03-29T17:06:04.765+02:00 INFO  [qtp804520826-47] [puppetserver] Puppet Not using expired facts for client1.my.domain from cache; expired at 2020-03-29 17:02:21 +0200
2020-03-29T17:06:05.041+02:00 INFO  [qtp804520826-47] [puppetserver] Puppet Caching facts for client1.my.domain
2020-03-29T17:06:06.787+02:00 INFO  [qtp804520826-47] [puppetserver] Puppet 'replace_facts' command for client1.my.domain submitted to PuppetDB with UUID c2472f15-f648-45f3-8163-c1a18baa3724
2020-03-29T17:06:07.009+02:00 WARN  [qtp804520826-47] [c.p.p.ShellUtils] Executed an external process which logged to STDERR: During fact upload occured an exception: SSL_connect returned=1 errno=0 state=error: certificate verify failed (unable to get local issuer certificate)
/etc/puppetlabs/puppet/node.rb:414: warning: constant ::TimeoutError is deprecated
Serving cached ENC: Could not send facts to Foreman: SSL_connect returned=1 errno=0 state=error: certificate verify failed (unable to get local issuer certificate)

    2020-03-29T17:06:07.238+02:00 INFO  [qtp804520826-47] [puppetserver] Puppet Compiled catalog for client1.my.domain in environment production in 0.19 seconds
    2020-03-29T17:06:07.240+02:00 INFO  [qtp804520826-47] [puppetserver] Puppet Caching catalog for client1.my.domain
    2020-03-29T17:06:07.292+02:00 INFO  [qtp804520826-47] [puppetserver] Puppet 'replace_catalog' command for client1.my.domain submitted to PuppetDB with UUID 40e4dcf3-4d6d-4845-b381-fe02f2632c20

This is what puppetdb logs:

2020-03-29T17:06:06.820+02:00 INFO  [p.p.command] [215-1585494366766] [40 ms] 'replace facts' command processed for client1.my.domain
2020-03-29T17:06:07.302+02:00 INFO  [p.p.command] [216-1585494367281] [11 ms] 'replace catalog' command processed for client1.my.domain

And finally foreman’s logs:

2020-03-29T17:06:07 [I|app|57b58773] Started POST "/api/config_reports" for client1.ip.address at 2020-03-29 17:06:07 +0200
2020-03-29T17:06:07 [I|app|57b58773] Processing by Api::V2::ConfigReportsController#create as JSON
2020-03-29T17:06:07 [I|app|57b58773]   Parameters: {"config_report"=>"[FILTERED]", "apiv"=>"v2"}
2020-03-29T17:06:07 [I|app|57b58773] Scanning report with: Foreman::PuppetReportScanner
2020-03-29T17:06:07 [I|app|57b58773] Imported report for client1.my.domain in 45.2 ms, status refreshed in 11.0 ms
2020-03-29T17:06:07 [I|app|57b58773]   Rendering api/v2/config_reports/create.json.rabl
2020-03-29T17:06:07 [I|app|57b58773]   Rendered api/v2/config_reports/create.json.rabl (14.1ms)
2020-03-29T17:06:07 [I|app|57b58773] Completed 201 Created in 98ms (Views: 13.1ms | ActiveRecord: 35.7ms)

So far, so good, it seems. Only thing that seems off, is this recurring bit of poetry in Foreman’s production.log:

2020-03-29T17:06:27 [W|app|] Creating scope :completer_scope. Overwriting existing method Location.completer_scope.

2020-03-29T17:06:27 [W|app|] Creating scope :completer_scope. Overwriting existing method Organization.completer_scope.
2020-03-29T17:06:30 [F|app|] Failed running Dynflow daemon
2020-03-29T17:06:30 [F|app|] superclass mismatch for class Command
/usr/share/foreman/vendor/ruby/2.5.0/gems/thor-1.0.1/lib/thor/command.rb:2:in <class:Thor>' /usr/share/foreman/vendor/ruby/2.5.0/gems/thor-1.0.1/lib/thor/command.rb:1:in <top (required)>’
/usr/share/foreman/vendor/ruby/2.5.0/gems/thor-1.0.1/lib/thor/base.rb:1:in require_relative' /usr/share/foreman/vendor/ruby/2.5.0/gems/thor-1.0.1/lib/thor/base.rb:1:in <top (required)>’
/usr/share/foreman/vendor/ruby/2.5.0/gems/thor-1.0.1/lib/thor/group.rb:1:in require_relative' /usr/share/foreman/vendor/ruby/2.5.0/gems/thor-1.0.1/lib/thor/group.rb:1:in <top (required)>’
/usr/share/foreman/vendor/ruby/2.5.0/gems/polyglot-0.3.5/lib/polyglot.rb:65:in require' /usr/share/foreman/vendor/ruby/2.5.0/gems/polyglot-0.3.5/lib/polyglot.rb:65:in require’
/usr/share/foreman/vendor/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/dependencies.rb:287:in block in require' /usr/share/foreman/vendor/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/dependencies.rb:253:in load_dependency’
/usr/share/foreman/vendor/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/dependencies.rb:287:in require' /usr/share/foreman/vendor/ruby/2.5.0/gems/railties-5.2.1/lib/rails/generators.rb:6:in <top (required)>’
/usr/share/foreman/vendor/ruby/2.5.0/gems/polyglot-0.3.5/lib/polyglot.rb:65:in require' /usr/share/foreman/vendor/ruby/2.5.0/gems/polyglot-0.3.5/lib/polyglot.rb:65:in require’
/usr/share/foreman/vendor/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/dependencies.rb:287:in block in require' /usr/share/foreman/vendor/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/dependencies.rb:253:in load_dependency’
/usr/share/foreman/vendor/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/dependencies.rb:287:in require' /usr/share/foreman/lib/generators/plugin/migration_generator.rb:1:in <top (required)>’
/usr/share/foreman/vendor/ruby/2.5.0/gems/polyglot-0.3.5/lib/polyglot.rb:65:in require' /usr/share/foreman/vendor/ruby/2.5.0/gems/polyglot-0.3.5/lib/polyglot.rb:65:in require’
/usr/share/foreman/vendor/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/dependencies.rb:287:in block in require' /usr/share/foreman/vendor/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/dependencies.rb:253:in load_dependency’
/usr/share/foreman/vendor/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/dependencies.rb:287:in require' /usr/share/foreman/vendor/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/dependencies.rb:374:in block in require_or_load’
/usr/share/foreman/vendor/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/dependencies.rb:37:in block in load_interlock' /usr/share/foreman/vendor/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/dependencies/interlock.rb:14:in block in loading’
/usr/share/foreman/vendor/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/concurrency/share_lock.rb:151:in exclusive' /usr/share/foreman/vendor/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/dependencies/interlock.rb:13:in loading’
/usr/share/foreman/vendor/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/dependencies.rb:37:in load_interlock' /usr/share/foreman/vendor/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/dependencies.rb:352:in require_or_load’
/usr/share/foreman/vendor/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/dependencies.rb:330:in depend_on' /usr/share/foreman/vendor/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/dependencies.rb:244:in require_dependency’
/usr/share/foreman/vendor/ruby/2.5.0/gems/railties-5.2.1/lib/rails/engine.rb:478:in block (2 levels) in eager_load!' /usr/share/foreman/vendor/ruby/2.5.0/gems/railties-5.2.1/lib/rails/engine.rb:477:in each’
/usr/share/foreman/vendor/ruby/2.5.0/gems/railties-5.2.1/lib/rails/engine.rb:477:in block in eager_load!' /usr/share/foreman/vendor/ruby/2.5.0/gems/railties-5.2.1/lib/rails/engine.rb:475:in each’
/usr/share/foreman/vendor/ruby/2.5.0/gems/railties-5.2.1/lib/rails/engine.rb:475:in eager_load!' /usr/share/foreman/vendor/ruby/2.5.0/gems/railties-5.2.1/lib/rails/engine.rb:356:in eager_load!’
/usr/share/foreman/vendor/ruby/2.5.0/gems/railties-5.2.1/lib/rails/application/finisher.rb:69:in each' /usr/share/foreman/vendor/ruby/2.5.0/gems/railties-5.2.1/lib/rails/application/finisher.rb:69:in block in module:Finisher
/usr/share/foreman/vendor/ruby/2.5.0/gems/railties-5.2.1/lib/rails/initializable.rb:32:in instance_exec' /usr/share/foreman/vendor/ruby/2.5.0/gems/railties-5.2.1/lib/rails/initializable.rb:32:in run’
/usr/share/foreman/vendor/ruby/2.5.0/gems/railties-5.2.1/lib/rails/initializable.rb:61:in block in run_initializers' /usr/lib/ruby/2.5.0/tsort.rb:228:in block in tsort_each’
/usr/lib/ruby/2.5.0/tsort.rb:350:in block (2 levels) in each_strongly_connected_component' /usr/lib/ruby/2.5.0/tsort.rb:431:in each_strongly_connected_component_from’
/usr/lib/ruby/2.5.0/tsort.rb:349:in block in each_strongly_connected_component' /usr/lib/ruby/2.5.0/tsort.rb:347:in each’
/usr/lib/ruby/2.5.0/tsort.rb:347:in call' /usr/lib/ruby/2.5.0/tsort.rb:347:in each_strongly_connected_component’
/usr/lib/ruby/2.5.0/tsort.rb:226:in tsort_each' /usr/lib/ruby/2.5.0/tsort.rb:205:in tsort_each’
/usr/share/foreman/vendor/ruby/2.5.0/gems/railties-5.2.1/lib/rails/initializable.rb:60:in run_initializers' /usr/share/foreman/vendor/ruby/2.5.0/gems/railties-5.2.1/lib/rails/application.rb:361:in initialize!’
/usr/share/foreman/vendor/ruby/2.5.0/gems/railties-5.2.1/lib/rails/railtie.rb:190:in public_send' /usr/share/foreman/vendor/ruby/2.5.0/gems/railties-5.2.1/lib/rails/railtie.rb:190:in method_missing’
/usr/share/foreman/config/environment.rb:5:in <top (required)>' /usr/share/foreman/vendor/ruby/2.5.0/gems/polyglot-0.3.5/lib/polyglot.rb:65:in require’
/usr/share/foreman/vendor/ruby/2.5.0/gems/polyglot-0.3.5/lib/polyglot.rb:65:in require' /usr/share/foreman/vendor/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/dependencies.rb:287:in block in require’
/usr/share/foreman/vendor/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/dependencies.rb:253:in load_dependency' /usr/share/foreman/vendor/ruby/2.5.0/gems/activesupport-5.2.1/lib/active_support/dependencies.rb:287:in require’
/usr/share/foreman/vendor/ruby/2.5.0/gems/dynflow-1.4.2/lib/dynflow/rails/daemon.rb:47:in run' /usr/share/foreman/vendor/ruby/2.5.0/gems/dynflow-1.4.2/lib/dynflow/rails/daemon.rb:79:in block (2 levels) in run_background’
/usr/share/foreman/vendor/ruby/2.5.0/gems/daemons-1.3.1/lib/daemons/application.rb:275:in block in start_proc' /usr/share/foreman/vendor/ruby/2.5.0/gems/daemons-1.3.1/lib/daemons/daemonize.rb:84:in call_as_daemon’
/usr/share/foreman/vendor/ruby/2.5.0/gems/daemons-1.3.1/lib/daemons/application.rb:279:in start_proc' /usr/share/foreman/vendor/ruby/2.5.0/gems/daemons-1.3.1/lib/daemons/application.rb:305:in start’
/usr/share/foreman/vendor/ruby/2.5.0/gems/daemons-1.3.1/lib/daemons/monitor.rb:50:in block (3 levels) in watch' /usr/share/foreman/vendor/ruby/2.5.0/gems/daemons-1.3.1/lib/daemons/monitor.rb:50:in fork’
/usr/share/foreman/vendor/ruby/2.5.0/gems/daemons-1.3.1/lib/daemons/monitor.rb:50:in block (2 levels) in watch' /usr/share/foreman/vendor/ruby/2.5.0/gems/daemons-1.3.1/lib/daemons/monitor.rb:44:in each’
/usr/share/foreman/vendor/ruby/2.5.0/gems/daemons-1.3.1/lib/daemons/monitor.rb:44:in block in watch' /usr/share/foreman/vendor/ruby/2.5.0/gems/daemons-1.3.1/lib/daemons/monitor.rb:43:in loop’
/usr/share/foreman/vendor/ruby/2.5.0/gems/daemons-1.3.1/lib/daemons/monitor.rb:43:in watch' /usr/share/foreman/vendor/ruby/2.5.0/gems/daemons-1.3.1/lib/daemons/monitor.rb:67:in block in start_with_pidfile’
/usr/share/foreman/vendor/ruby/2.5.0/gems/daemons-1.3.1/lib/daemons/monitor.rb:62:in fork' /usr/share/foreman/vendor/ruby/2.5.0/gems/daemons-1.3.1/lib/daemons/monitor.rb:62:in start_with_pidfile’
/usr/share/foreman/vendor/ruby/2.5.0/gems/daemons-1.3.1/lib/daemons/monitor.rb:93:in start' /usr/share/foreman/vendor/ruby/2.5.0/gems/daemons-1.3.1/lib/daemons/application_group.rb:153:in create_monitor’
/usr/share/foreman/vendor/ruby/2.5.0/gems/daemons-1.3.1/lib/daemons/application.rb:293:in start' /usr/share/foreman/vendor/ruby/2.5.0/gems/daemons-1.3.1/lib/daemons/controller.rb:56:in run’
/usr/share/foreman/vendor/ruby/2.5.0/gems/daemons-1.3.1/lib/daemons.rb:199:in block in run_proc' /usr/share/foreman/vendor/ruby/2.5.0/gems/daemons-1.3.1/lib/daemons/cmdline.rb:121:in catch_exceptions’
/usr/share/foreman/vendor/ruby/2.5.0/gems/daemons-1.3.1/lib/daemons.rb:198:in run_proc' /usr/share/foreman/vendor/ruby/2.5.0/gems/dynflow-1.4.2/lib/dynflow/rails/daemon.rb:73:in block in run_background’
/usr/share/foreman/vendor/ruby/2.5.0/gems/dynflow-1.4.2/lib/dynflow/rails/daemon.rb:72:in times' /usr/share/foreman/vendor/ruby/2.5.0/gems/dynflow-1.4.2/lib/dynflow/rails/daemon.rb:72:in run_background’
script/dynflowd:71:in block in <top (required)>' script/dynflowd:67:in chdir’
script/dynflowd:67:in <top (required)>' /usr/share/rubygems-integration/all/gems/bundler-1.17.3/lib/bundler/cli/exec.rb:74:in load’
/usr/share/rubygems-integration/all/gems/bundler-1.17.3/lib/bundler/cli/exec.rb:74:in kernel_load' /usr/share/rubygems-integration/all/gems/bundler-1.17.3/lib/bundler/cli/exec.rb:28:in run’
/usr/share/rubygems-integration/all/gems/bundler-1.17.3/lib/bundler/cli.rb:463:in exec' /usr/lib/ruby/vendor_ruby/thor/command.rb:27:in run’
/usr/lib/ruby/vendor_ruby/thor/invocation.rb:126:in invoke_command' /usr/lib/ruby/vendor_ruby/thor.rb:369:in dispatch’
/usr/share/rubygems-integration/all/gems/bundler-1.17.3/lib/bundler/cli.rb:27:in dispatch' /usr/lib/ruby/vendor_ruby/thor/base.rb:444:in start’
/usr/share/rubygems-integration/all/gems/bundler-1.17.3/lib/bundler/cli.rb:18:in start' /usr/share/rubygems-integration/all/gems/bundler-1.17.3/exe/bundle:30:in block in <top (required)>’
/usr/share/rubygems-integration/all/gems/bundler-1.17.3/lib/bundler/friendly_errors.rb:124:in with_friendly_errors' /usr/share/rubygems-integration/all/gems/bundler-1.17.3/exe/bundle:22:in <top (required)>’
/usr/bin/bundle:23:in load' /usr/bin/bundle:23:in

Not sure what to think of that, but I’m sure it will make sense to at least some of you out there :wink:

Problem solved. For now. Sort of.

Thanks to https://community.theforeman.org/t/node-rb-pushfacts-certificate-verify-failure/10362/6 I tried taking out the cafile

In /etc/puppelabs/puppet/foreman.yaml comment out the ca:

---
:url: "https://foreman.my.domain"
#:ssl_ca: "/etc/puppetlabs/puppet/ssl/ca/ca_crt.pem"
:ssl_cert: "/etc/puppetlabs/puppet/ssl/certs/foreman.my.domain.pem"
:ssl_key: "/etc/puppetlabs/puppet/ssl/private_keys/foreman.my.domain.pem"

That in itself wasn’t enough: I also “reverted” Debian’s OpenSSL-config to a looser setting. This is a Debian/OpenSSL thingy, other distros probably don’t have this problem.

In /etc/ssl/openssl.cnf, change

CipherString = DEFAULT@SECLEVEL=2

to

CipherString = DEFAULT

It’s not a pretty solution, but at least things work.

2 Likes

Same problem with Foreman 2.0rc3, same solution too.

This time the PuppetDB-server was installed with the PuppetLabs module.