Problem:
I upgraded Foreman from 2.3 (through 2.4, 2.5) to 3.0.1 recently. After the upgrade, it was working correctly. I was able to provision some hosts. I started to check what changed and I went through settings and to be honest I wasn’t doing any changes except the “default local pxe” template in the Provision tab.
For a long time before, we were facing some issues with the Ansible callback plugin as it was throwing 403 exit code even when the playbook went good. Also, we weren’t able to gather facts when we run Ansible with the callback plugin outside of Foreman. So, I was trying to solve that and I noticed this issue:
2021-11-16T07:14:06 [I|app|ff3cee93] Rendering api/v2/errors/standard_error.json.rabl within api/v2/layouts/error_layout
2021-11-16T07:14:06 [I|app|ff3cee93] Rendered api/v2/errors/standard_error.json.rabl within api/v2/layouts/error_layout (Duration: 0.9ms | Allocations: 322)
2021-11-16T07:14:06 [I|app|ff3cee93] Completed 500 Internal Server Error in 37ms (Views: 3.2ms | ActiveRecord: 10.7ms | Allocations: 15309)
2021-11-16T07:14:06 [I|app|73c7b353] Started POST "/api/v2/hosts/facts" for 10.9.64.196 at 2021-11-16 07:14:06 -0600
2021-11-16T07:14:06 [I|app|73c7b353] Processing by Api::V2::HostsController#facts as JSON
2021-11-16T07:14:06 [I|app|73c7b353] Parameters: {"facts"=>"[FILTERED]", "name"=>"chd-dev-debrepo01", "apiv"=>"v2", "host"=>{"name"=>"chd-dev-debrepo01"}}
2021-11-16T07:14:06 [W|app|73c7b353] DefaultHostgroupMatch: Could not load :default_hostgroup map from Settings.
2021-11-16T07:14:06 [W|app|73c7b353] Action failed
2021-11-16T07:14:06 [I|app|73c7b353] Backtrace for 'Action failed' error (RuntimeError): resource have no errors
So, I decided to check what DefaultHostgroupMatch plugin is doing and how it is working. I also noticed that we don’t have default_hostgroup.yaml in /etc/foreman/plugins/ as it is described here https://github.com/theforeman/foreman_default_hostgroup
Anyway, I didn’t add this file and decided to run foreman-installer once again to see if it might solve some leftover issues after the upgrade.
And…foreman-installer failed and it is throwing errors as you can see below in
/var/log/foreman-installer/katello.log
2021-11-16 11:04:19 [ERROR ] [configure] -- Logs begin at Thu 2021-08-12 00:18:34 CDT, end at Tue 2021-11-16 11:04:19 CST. --
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:12 chd-prd-foreman02 systemd[1]: Starting Foreman...
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:17 chd-prd-foreman02 foreman[13317]: => Booting Puma
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:17 chd-prd-foreman02 foreman[13317]: => Rails 6.0.3.7 application starting in production
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:17 chd-prd-foreman02 foreman[13317]: => Run `rails server --help` for more startup options
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: API controllers newer than Apipie cache! Run apipie:cache rake task to regenerate cache.
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: Exiting
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-5.1.1/app/models/foreman_tasks/task.rb:66:in `block in <class:Task>': undefined method `id' for nil:NilClass (NoMethodError)
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/scoped_search-4.1.9/lib/scoped_search/query_builder.rb:184:in `map_value'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/scoped_search-4.1.9/lib/scoped_search/query_builder.rb:253:in `preprocess_parameters'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/scoped_search-4.1.9/lib/scoped_search/query_builder.rb:228:in `block in sql_test'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/scoped_search-4.1.9/lib/scoped_search/query_builder.rb:228:in `each'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/scoped_search-4.1.9/lib/scoped_search/query_builder.rb:228:in `sql_test'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/scoped_search-4.1.9/lib/scoped_search/query_builder.rb:562:in `sql_test'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/scoped_search-4.1.9/lib/scoped_search/query_builder.rb:509:in `to_single_field_sql'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/scoped_search-4.1.9/lib/scoped_search/query_builder.rb:521:in `to_sql'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/scoped_search-4.1.9/lib/scoped_search/query_builder.rb:54:in `build_find_params'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/scoped_search-4.1.9/lib/scoped_search/query_builder.rb:22:in `build_query'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/scoped_search-4.1.9/lib/scoped_search/definition.rb:328:in `block in register_named_scope!'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /usr/share/foreman/app/models/filter.rb:14:in `validate'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/callbacks.rb:428:in `block in make_lambda'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/callbacks.rb:200:in `block (2 levels) in halting'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/callbacks.rb:605:in `block (2 levels) in default_terminator'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/callbacks.rb:604:in `catch'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/callbacks.rb:604:in `block in default_terminator'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/callbacks.rb:201:in `block in halting'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/callbacks.rb:513:in `block in invoke_before'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/callbacks.rb:513:in `each'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/callbacks.rb:513:in `invoke_before'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/callbacks.rb:134:in `run_callbacks'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/callbacks.rb:825:in `_run_validate_callbacks'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activemodel-6.0.3.7/lib/active_model/validations.rb:406:in `run_validations!'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activemodel-6.0.3.7/lib/active_model/validations/callbacks.rb:117:in `block in run_validations!'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/callbacks.rb:135:in `run_callbacks'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/callbacks.rb:825:in `_run_validation_callbacks'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activemodel-6.0.3.7/lib/active_model/validations/callbacks.rb:117:in `run_validations!'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activemodel-6.0.3.7/lib/active_model/validations.rb:337:in `valid?'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.7/lib/active_record/validations.rb:68:in `valid?'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.7/lib/active_record/validations.rb:84:in `perform_validations'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.7/lib/active_record/validations.rb:53:in `save!'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.7/lib/active_record/transactions.rb:318:in `block in save!'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.7/lib/active_record/transactions.rb:375:in `block in with_transaction_returning_status'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.7/lib/active_record/connection_adapters/abstract/database_statements.rb:280:in `block in transaction'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.7/lib/active_record/connection_adapters/abstract/transaction.rb:280:in `block in within_new_transaction'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block (2 levels) in synchronize'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `handle_interrupt'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `handle_interrupt'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.7/lib/active_record/connection_adapters/abstract/transaction.rb:278:in `within_new_transaction'
2021-11-16 11:04:19 [ERROR ] [configure] Nov 16 11:04:19 chd-prd-foreman02 foreman[13317]: from /opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.7/lib/active_record/connection_adapters/abstract/database_statements.rb:280:in `transaction'
2021-11-16 11:04:19 [ERROR ] [configure] /Stage[main]/Foreman::Service/Service[foreman]/ensure: change from 'stopped' to 'running' failed: Systemd start for foreman failed!
Please let me know if you need more info
Foreman and Proxy versions:
3.0.1
Distribution and version:
LSB Version: :core-4.1-amd64:core-4.1-noarch
Distributor ID: CentOS
Description: CentOS Linux release 7.9.2009 (Core)
Release: 7.9.2009
Codename: Core
Linux chd-prd-foreman02 4.19.12-1.el7.elrepo.x86_64 #1 SMP Fri Dec 21 11:06:36 EST 2018 x86_64 x86_64 x86_64 GNU/Linux