Candlepin SSL errors and foreman-installer failures

metalcated · March 29, 2021, 3:24am

Problem:
Yes I am using custom certs but those are new and these errors all existed before adding those. I was hoping that would solve some of the issues with candlepin but it seems not lol.

Looks like this issue is back (relating to the keystore and candlepin - removing the keystore and running foreman-installer did not help this time.)l: Couldn’t connect to the server: undefined method `to_sym’ for nil:NilClass - Support - TheForeman

Few things going on here:

Running foreman-installer I always get this Error:

[ERROR 2021-03-28T22:57:44 verbose] foreman-maintain packages is-locked --assumeyes failed! Check the output for error!

And this Error:

[ INFO 2021-03-28T23:00:18 verbose] Class[Candlepin::Database::Postgresql]: Scheduling refresh of Class[Candlepin::Service]
[ INFO 2021-03-28T23:00:18 verbose] Class[Candlepin::Service]: Scheduling refresh of Service[tomcat]
[ WARN 2021-03-28T23:00:19 verbose] /Service[tomcat]: Triggered ‘refresh’ from 1 event
[ WARN 2021-03-28T23:00:21 verbose] /Stage[main]/Foreman::Database/Foreman::Rake[db:migrate]/Exec[foreman-rake-db:migrate]/returns: rake aborted!
[ WARN 2021-03-28T23:00:21 verbose] /Stage[main]/Foreman::Database/Foreman::Rake[db:migrate]/Exec[foreman-rake-db:migrate]/returns: LoadError: cannot load such file – apipie/middleware/checksum_in_headers
[ WARN 2021-03-28T23:00:21 verbose] /Stage[main]/Foreman::Database/Foreman::Rake[db:migrate]/Exec[foreman-rake-db:migrate]/returns: /usr/share/foreman/config/application.rb:5:in <top (required)>' [ WARN 2021-03-28T23:00:21 verbose] /Stage[main]/Foreman::Database/Foreman::Rake[db:migrate]/Exec[foreman-rake-db:migrate]/returns: /usr/share/foreman/Rakefile:1:in <top (required)>’
[ WARN 2021-03-28T23:00:21 verbose] /Stage[main]/Foreman::Database/Foreman::Rake[db:migrate]/Exec[foreman-rake-db:migrate]/returns: /opt/rh/rh-ruby25/root/usr/share/gems/gems/rake-12.3.0/exe/rake:27:in `<top (required)>’
[ WARN 2021-03-28T23:00:21 verbose] /Stage[main]/Foreman::Database/Foreman::Rake[db:migrate]/Exec[foreman-rake-db:migrate]/returns: (See full trace by running task with --trace)
[ERROR 2021-03-28T23:00:21 verbose] ‘/usr/sbin/foreman-rake db:migrate’ returned 1 instead of one of [0]
[ERROR 2021-03-28T23:00:21 verbose] /Stage[main]/Foreman::Database/Foreman::Rake[db:migrate]/Exec[foreman-rake-db:migrate]/returns: change from ‘notrun’ to [‘0’] failed: ‘/usr/sbin/foreman-rake db:migrate’ returned 1 instead of one of [0]
[ WARN 2021-03-28T23:00:22 verbose] /Stage[main]/Foreman::Database/Foreman_config_entry[db_pending_seed]: Dependency Exec[foreman-rake-db:migrate] has failures: true
[ WARN 2021-03-28T23:00:22 verbose] /Stage[main]/Foreman::Database/Foreman_config_entry[db_pending_seed]: Skipping because of failed dependencies
[ WARN 2021-03-28T23:00:22 verbose] /Stage[main]/Foreman::Database/Foreman::Rake[db:seed]/Exec[foreman-rake-db:seed]: Skipping because of failed dependencies
[ INFO 2021-03-28T23:00:22 verbose] Class[Apache::Service]: Unscheduling all events on Class[Apache::Service]
[ WARN 2021-03-28T23:00:22 verbose] /Service[httpd]: Skipping because of failed dependencies

Trying to perform the pulp 2 to 3 migration also gives an Error:
Foreman :: Plugin Manuals (theforeman.org)

foreman-rake katello:pulp3_migration --trace
Rubocop not loaded.
** Invoke katello:pulp3_migration (first_time)
** Invoke environment (first_time)
** Execute environment
** Invoke katello:disable_dynflow (first_time)
** Execute katello:disable_dynflow
** Invoke katello:check_ping (first_time)
** Invoke environment
** Execute katello:check_ping
{:services=>
{:candlepin=>{:status=>“ok”, :duration_ms=>“64”},
:candlepin_auth=>{:status=>“ok”, :duration_ms=>“83”},
:foreman_tasks=>{:status=>“ok”, :duration_ms=>“5”},
:katello_events=>
{:status=>“ok”, :message=>“0 Processed, 0 Failed”, :duration_ms=>“0”},
:candlepin_events=>
{:status=>“FAIL”, :message=>“Not running”, :duration_ms=>“1”},
:pulp3=>{:status=>“ok”, :duration_ms=>“151”},
:pulp=>{:status=>“ok”, :duration_ms=>“176”},
:pulp_auth=>{:status=>“ok”, :duration_ms=>“140”}},
:status=>“FAIL”}
rake aborted!
Not all the services have been started. Check the status report above and try again.
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.17.3/lib/katello/tasks/reimport.rake:10:in block (2 levels) in <top (required)>' /opt/rh/rh-ruby25/root/usr/share/gems/gems/rake-12.3.0/lib/rake/task.rb:251:in block in execute’
/opt/rh/rh-ruby25/root/usr/share/gems/gems/rake-12.3.0/lib/rake/task.rb:251:in each' /opt/rh/rh-ruby25/root/usr/share/gems/gems/rake-12.3.0/lib/rake/task.rb:251:in execute’
/opt/rh/rh-ruby25/root/usr/share/gems/gems/rake-12.3.0/lib/rake/task.rb:195:in block in invoke_with_call_chain' /opt/rh/rh-ruby25/root/usr/share/ruby/monitor.rb:226:in mon_synchronize’
/opt/rh/rh-ruby25/root/usr/share/gems/gems/rake-12.3.0/lib/rake/task.rb:188:in invoke_with_call_chain' /opt/rh/rh-ruby25/root/usr/share/gems/gems/rake-12.3.0/lib/rake/task.rb:217:in block in invoke_prerequisites’
/opt/rh/rh-ruby25/root/usr/share/gems/gems/rake-12.3.0/lib/rake/task.rb:215:in each' /opt/rh/rh-ruby25/root/usr/share/gems/gems/rake-12.3.0/lib/rake/task.rb:215:in invoke_prerequisites’
/opt/rh/rh-ruby25/root/usr/share/gems/gems/rake-12.3.0/lib/rake/task.rb:194:in block in invoke_with_call_chain' /opt/rh/rh-ruby25/root/usr/share/ruby/monitor.rb:226:in mon_synchronize’
/opt/rh/rh-ruby25/root/usr/share/gems/gems/rake-12.3.0/lib/rake/task.rb:188:in invoke_with_call_chain' /opt/rh/rh-ruby25/root/usr/share/gems/gems/rake-12.3.0/lib/rake/task.rb:181:in invoke’
/opt/rh/rh-ruby25/root/usr/share/gems/gems/rake-12.3.0/lib/rake/application.rb:160:in invoke_task' /opt/rh/rh-ruby25/root/usr/share/gems/gems/rake-12.3.0/lib/rake/application.rb:116:in block (2 levels) in top_level’
/opt/rh/rh-ruby25/root/usr/share/gems/gems/rake-12.3.0/lib/rake/application.rb:116:in each' /opt/rh/rh-ruby25/root/usr/share/gems/gems/rake-12.3.0/lib/rake/application.rb:116:in block in top_level’
/opt/rh/rh-ruby25/root/usr/share/gems/gems/rake-12.3.0/lib/rake/application.rb:125:in run_with_threads' /opt/rh/rh-ruby25/root/usr/share/gems/gems/rake-12.3.0/lib/rake/application.rb:110:in top_level’
/opt/rh/rh-ruby25/root/usr/share/gems/gems/rake-12.3.0/lib/rake/application.rb:83:in block in run' /opt/rh/rh-ruby25/root/usr/share/gems/gems/rake-12.3.0/lib/rake/application.rb:186:in standard_exception_handling’
/opt/rh/rh-ruby25/root/usr/share/gems/gems/rake-12.3.0/lib/rake/application.rb:80:in run' /opt/rh/rh-ruby25/root/usr/share/gems/gems/rake-12.3.0/exe/rake:27:in <top (required)>’
/opt/rh/rh-ruby25/root/usr/bin/rake:23:in load' /opt/rh/rh-ruby25/root/usr/bin/rake:23:in ’
Tasks: TOP => katello:pulp3_migration => katello:check_ping

I assume this issue is related to the SSL error within candlepin.

Expected outcome:

foreman-installer output with no errors and successfully run.
No more keystore issues and SSL errors using custom certs.

Foreman and Proxy versions:
foreman-2.2.3-1.el7.noarch
foreman-cli-2.2.3-1.el7.noarch
foreman-debug-2.2.3-1.el7.noarch
foreman-dynflow-sidekiq-2.2.3-1.el7.noarch
foreman-ec2-2.2.3-1.el7.noarch
foreman.domain.com-apache-1.0-46.noarch
foreman.domain.com-foreman-client-1.0-46.noarch
foreman.domain.com-foreman-proxy-1.0-46.noarch
foreman.domain.com-foreman-proxy-client-1.0-46.noarch
foreman.domain.com-puppet-client-1.0-46.noarch
foreman.domain.com-qpid-broker-1.0-46.noarch
foreman.domain.com-qpid-client-cert-1.0-46.noarch
foreman.domain.com-qpid-router-client-1.0-46.noarch
foreman.domain.com-qpid-router-server-1.0-46.noarch
foreman.domain.com-tomcat-1.0-29.noarch
foreman-installer-2.2.3-1.el7.noarch
foreman-installer-katello-2.2.3-1.el7.noarch
foreman-openstack-2.2.3-1.el7.noarch
foreman-postgresql-2.2.3-1.el7.noarch
foreman-proxy-2.2.3-1.el7.noarch
foreman-proxy-content-3.17.3-1.el7.noarch
foreman-release-2.2.3-1.el7.noarch
foreman-release-scl-7-3.el7.noarch
foreman-selinux-2.2.3-1.el7.noarch
foreman-service-2.2.3-1.el7.noarch
foreman-vmware-2.2.3-1.el7.noarch

Foreman and Proxy plugin versions:
katello-3.17.3-1.el7.noarch
katello-agent-3.3.5-4.el7.noarch
katello-certs-tools-2.7.1-2.el7.noarch
katello-client-bootstrap-1.7.5-1.el7.noarch
katello-common-3.17.3-1.el7.noarch
katello-debug-3.17.3-1.el7.noarch
katello-default-ca-1.0-1.noarch
katello-host-tools-3.3.5-4.el7.noarch
katello-host-tools-fact-plugin-3.3.5-4.el7.noarch
katello-repos-3.17.3-1.el7.noarch
katello-selinux-3.4.0-1.el7.noarch
katello-server-ca-1.0-3.noarch
katello-service-3.14.1-1.el7.noarch

Distribution and version:
Distributor ID: CentOS
Description: CentOS Linux release 7.9.2009 (Core)
Release: 7.9.2009
Codename: Core

Other relevant data:

/var/log/foreman/production.log
2021-03-28T23:12:33 [E|app|6c4c7143] Error occurred while starting Katello::CandlepinEventListener
2021-03-28T23:12:33 [E|app|6c4c7143] SSL_connect returned=1 errno=0 state=error: sslv3 alert certificate unknown
2021-03-28T23:12:33 [E|app|6c4c7143] /opt/theforeman/tfm/root/usr/share/gems/gems/stomp-1.4.9/lib/connection/netio.rb:465:in connect' 6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/stomp-1.4.9/lib/connection/netio.rb:465:in block in open_ssl_socket’
6c4c7143 | /opt/rh/rh-ruby25/root/usr/share/ruby/timeout.rb:76:in timeout' 6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/stomp-1.4.9/lib/connection/netio.rb:460:in open_ssl_socket’
6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/stomp-1.4.9/lib/connection/netio.rb:520:in open_socket' 6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/stomp-1.4.9/lib/connection/utils.rb:116:in block in socket’
6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/stomp-1.4.9/lib/connection/utils.rb:109:in synchronize' 6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/stomp-1.4.9/lib/connection/utils.rb:109:in socket’
6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/stomp-1.4.9/lib/stomp/connection.rb:173:in initialize' 6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/stomp-1.4.9/lib/stomp/client.rb:134:in new’
6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/stomp-1.4.9/lib/stomp/client.rb:134:in create_connection' 6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/stomp-1.4.9/lib/stomp/client.rb:101:in block in initialize’
6c4c7143 | /opt/rh/rh-ruby25/root/usr/share/ruby/timeout.rb:93:in block in timeout' 6c4c7143 | /opt/rh/rh-ruby25/root/usr/share/ruby/timeout.rb:33:in block in catch’
6c4c7143 | /opt/rh/rh-ruby25/root/usr/share/ruby/timeout.rb:33:in catch' 6c4c7143 | /opt/rh/rh-ruby25/root/usr/share/ruby/timeout.rb:33:in catch’
6c4c7143 | /opt/rh/rh-ruby25/root/usr/share/ruby/timeout.rb:108:in timeout' 6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/stomp-1.4.9/lib/stomp/client.rb:99:in initialize’
6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.17.3/app/lib/katello/messaging/stomp_connection.rb:69:in new' 6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.17.3/app/lib/katello/messaging/stomp_connection.rb:69:in client’
6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.17.3/app/lib/katello/messaging/stomp_connection.rb:43:in subscribe' 6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.17.3/app/services/katello/candlepin_event_listener.rb:37:in run’
6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.17.3/app/services/katello/event_daemon.rb:33:in block in check_services' 6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.17.3/app/services/katello/event_daemon.rb:23:in each’
6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.17.3/app/services/katello/event_daemon.rb:23:in check_services' 6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.17.3/app/services/katello/event_daemon.rb:16:in block (2 levels) in start’
6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/execution_wrapper.rb:88:in wrap' 6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.17.3/app/services/katello/event_daemon.rb:15:in block in start’
6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.17.3/app/services/katello/event_daemon.rb:14:in loop' 6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.17.3/app/services/katello/event_daemon.rb:14:in start’
6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.17.3/app/services/katello/event_daemon.rb:119:in block in start_monitor_thread' 6c4c7143 | /opt/theforeman/tfm/root/usr/share/gems/gems/logging-2.2.2/lib/logging/diagnostic_context.rb:474:in block in create_with_logging_context’

/var/log/candlepin/candlepin.log
2021-03-28 23:14:14,447 [thread=Thread-3 (ActiveMQ-scheduled-threads)] [=, org=, csid=] ERROR org.apache.activemq.artemis.core.server - AMQ224088: Timeout (10 seconds) on acceptor “stomp” during protocol handshake with /127.0.0.1:58772 has occurred.
2021-03-28 23:14:19,657 [thread=Thread-6 (activemq-netty-threads)] [=, org=, csid=] WARN org.apache.activemq.artemis.core.server - AMQ222208: SSL handshake failed for client from /127.0.0.1:58776: sun.security.validator.ValidatorException: Netscape cert type does not permit use for SSL client.

ehelms · March 29, 2021, 12:18pm

Howdy,

What was the action you took where you first saw things not working? Were you trying to upgrade? or change installer options?

metalcated · March 29, 2021, 2:12pm

Upgrade(s) at one point yes. I don’t 100% recall the version from which I was coming from and going to at this point since the foreman-installer errors have been persistent since then. I believe it was from 2.1 to 2.2 but the foreman-rake db:migrate error started at 1.24 -> 2.0 and has since not gone away.

ehelms · March 29, 2021, 3:39pm

This error is a misnomer and not a real error, we fixed in Bug #31135: foreman-maintain package lock check indicates false failure - Installer - Foreman which was delivered in Foreman 2.3.

Could you run this stand-alone and let us know the error?

# foreman-rake db:migrate

metalcated · March 29, 2021, 8:37pm

# foreman-rake db:migrate

This does not usually by itself produce an error other than this

Rubocop not loaded

ehelms · March 30, 2021, 12:32pm

So running db:migrate stand-alone you get no errors, but if you run the installer you see an error linked to db:migrate?

metalcated · March 30, 2021, 12:38pm

Yes correct and the installer fails in the end to complete the dependency tasks.

metalcated · March 31, 2021, 1:13am

Okay so, couple issues for anyone else tracking this.

The reason the truststore (candlepin_events) was having issues was due to the corrupt truststore from the incomplete foreman-installer runs. (This was the SSL errors above).

The reason foreman-installer would not complete and was throwing errors was due to having a /usr/bin/puppet as a symlink. In 2.2 and prior this has potential to cause issues (see above).

@ehelms suggested removing it, which I did and then was able to get past the migrate:db issue only to hit another error lol. db:seed threw an error.

That error was being caused by some plugin which I have yet to narrow down. In the meantime I have commented out the entire contents of this file:

/usr/share/foreman/db/seeds.d/070-provisioning_templates.rb

Once I commented out the above file completely, I ran foreman-installer again AND finally the run completed with success! All thanks to @ehelms

Now to fix the truststore “again”, I deleted /etc/candlepin/certs/truststore again, re-ran the foreman-installer and once and for all, everything succeeded and is now working as expected.

And finally, I need to upgrade to 2.3 then 2.4 to clear up some other bugs

Thanks to this community, you all are awesome!

ehelms · March 31, 2021, 1:27am

A final follow up for anyone tracking this, we do have issues filed and in some cases fixed for the Puppet symlink issue and the truststore issue:

Puppet symlink issue fixed in Kafo Bug #30365: Puppet bin scripts that exist outside AIO environment as symlinks to AIO puppet bin files break installation in SCL - Kafo - Foreman (released as part of 2.3)
Candlepin SSL errors from outdated truststore: Bug #31574: The Artemis client certificate is not updated in truststore if it changes - Installer - Foreman (not yet merged, aiming to release in Foreman 2.5)

For the seeds issue, the error was (which is similar to but not the same as Bug #30932: plugin installation fails with "ActiveRecord::RecordInvalid: Validation failed: Name has already been taken" - Foreman):

ActiveRecord::RecordInvalid: Validation failed: Name has already been taken
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/validations.rb:80:in `raise_validation_error'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/validations.rb:53:in `save!'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/transactions.rb:318:in `block in save!'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/transactions.rb:375:in `block in with_transaction_returning_status'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract/database_statements.rb:280:in `block in transaction'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract/transaction.rb:280:in `block in within_new_transaction'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract/transaction.rb:278:in `within_new_transaction'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/connection_adapters/abstract/database_statements.rb:280:in `transaction'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/transactions.rb:212:in `transaction'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/transactions.rb:366:in `with_transaction_returning_status'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/transactions.rb:318:in `save!'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.1/lib/active_record/suppressor.rb:48:in `save!'
/usr/share/foreman/lib/seed_helper.rb:134:in `block in import_raw_template'
/usr/share/foreman/app/models/template.rb:73:in `ignore_locking'
/usr/share/foreman/lib/seed_helper.rb:134:in `import_raw_template'
/usr/share/foreman/lib/seed_helper.rb:140:in `block in import_templates'
/usr/share/foreman/lib/seed_helper.rb:139:in `each'
/usr/share/foreman/lib/seed_helper.rb:139:in `import_templates'
/usr/share/foreman/db/seeds.d/070-provisioning_templates.rb:9:in `block in <top (required)>'

tbrisker · May 25, 2021, 4:04pm

Following up on this, the template error seems to be Bug #32657: Upgrade fails with error Validation failed: Name has already been taken at db:seed stage - Foreman