Bug #33754
closed
puppet runs fail after Foreman 3.0.0 upgrade from 2.5.3
Description
I successfully upgraded our DEV foreman instance from 2.5.3 to 3.0.0 after uninstalling the "tfm-rubygem-foreman_expire_hosts" plugin that caused the db:migrate script to fail however, the same was not true on our production server. The Upgrade appeared to work and the UI was accessible but 74 hosts reported puppet run errors...
Warning: Error 500 on SERVER: Server Error: Failed to find ${NODE} via exec: Execution of '/etc/puppetlabs/puppet/node.rb ${NODE}' returned 1:
"foreman-rake config" produced
ActiveRecord::SubclassNotFound: The single-table inheritance mechanism failed to locate the subclass: 'Setting::ExpireHosts'. This error is raised because the column 'category' is reserved for storing the class in case of inheritance. Please rename this column if you didn't intend it to be used for storing the inheritance class or overwrite Setting.inheritance_column to use another column for that information.
I ran...
"delete from settings where category='Setting::ExpireHosts';"
on the database and this allowed "foreman-rake config" to return successfully, unfortunately it did not fix the puppet client error.
Looking at the production.log I see... (full stack attached to this ticket.)
2021-10-20T14:20:22 [I|app|e022815c] Backtrace for 'Failed to generate external nodes for ${NODE}' error (TypeError): no implicit conversion of nil into Array
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.7/lib/active_record/relation/delegation.rb:87:in `+'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.7/lib/active_record/relation/delegation.rb:87:in `+'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_puppet-1.0.3/app/services/foreman_puppet/host_info_providers/config_groups_info.rb:7:in `host_info'
/usr/share/foreman/app/models/concerns/host_info_extensions.rb:27:in `block in info'
/usr/share/foreman/app/models/concerns/host_info_extensions.rb:25:in `each'
/usr/share/foreman/app/models/concerns/host_info_extensions.rb:25:in `info'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_puppet-1.0.3/app/controllers/concerns/foreman_puppet/extensions/hosts_controller_extensions.rb:100:in `block in externalNodes'
I am unsure what the difference is between our DEV and PROD instances are as DEV was originally copied from PROD, obviously they have drifted somewhat now but not from a foreman rpm or plugin perspective.
I have reverted PROD back to the 2.5.3 snapshot but I could do with some help on trying to understand and fix the issue.
Please let me know what additional information you require.
Current production foreman packages and plugins
foreman-2.5.3-1.el7.noarch
foreman-cli-2.5.3-1.el7.noarch
foreman-debug-2.5.3-1.el7.noarch
foreman-dynflow-sidekiq-2.5.3-1.el7.noarch
foreman-ec2-2.5.3-1.el7.noarch
foreman-installer-2.5.3-1.el7.noarch
foreman-postgresql-2.5.3-1.el7.noarch
foreman-proxy-2.5.3-1.el7.noarch
foreman-release-2.5.3-1.el7.noarch
foreman-service-2.5.3-1.el7.noarch
foreman-vmware-2.5.3-1.el7.noarch
rubygem-foreman_maintain-0.8.6-1.el7.noarch
tfm-rubygem-foreman_bootdisk-17.1.0-1.fm2_5.el7.noarch
tfm-rubygem-foreman_column_view-0.4.0-5.fm2_5.el7.noarch
tfm-rubygem-foreman_default_hostgroup-6.0.0-1.fm2_5.el7.noarch
tfm-rubygem-foreman_dhcp_browser-0.0.8-5.fm2_5.el7.noarch
tfm-rubygem-foreman_discovery-17.0.1-1.fm2_5.el7.noarch
tfm-rubygem-foreman_expire_hosts-7.0.4-2.fm2_5.el7.noarch # This is what I removed on our DEV server to complete the DB migration.
tfm-rubygem-foreman_hooks-0.3.17-2.fm2_5.el7.noarch
tfm-rubygem-foreman_memcache-0.1.1-4.fm2_5.el7.noarch
tfm-rubygem-foreman_remote_execution-4.5.6-1.fm2_5.el7.noarch
tfm-rubygem-foreman_remote_execution_core-1.4.8-1.el7.noarch
tfm-rubygem-foreman_setup-7.0.0-3.fm2_5.el7.noarch
tfm-rubygem-foreman-tasks-4.1.5-1.fm2_5.el7.noarch
tfm-rubygem-foreman-tasks-core-0.3.6-1.fm2_5.el7.noarch
tfm-rubygem-hammer_cli_foreman-2.5.1-1.el7.noarch
Thanks in advance.
Files
Updated by Mark Gargiulo over 2 years ago
Some additional info.
I pointed one of the failing nodes to the foreman DEV server (it was a copy of PROD originally so still had the same puppet certificates) and the puppet run was successful, so it appears to be something unique to the database in production though both have been through the same version upgrades over the past 18 months.
Updated by Mark Gargiulo over 2 years ago
- Found in Releases 3.0.1 added
I tried something different this time in an effort to fix the issue in our production foreman server.
I removed the offending tfm-rubygem-foreman_expire_hosts-7.0.4-2.fm2_5.el7.noarch rpm and then upgraded successfully to 2.5.4.
When logging into the UI I saw a message about cleaning up the DB due to orphaned entries in host_status, I clicked delete and had a functional system.
I then tried to perform the 3.0.1 upgrade. All appeared to go smoothly until a ran the puppet agent from a registered host and got this on the agent side...
Error: Could not retrieve catalog from remote server: Error 500 on SERVER: Server Error: Failed when searching for node ${host}: Failed to find ${host} via exec: Execution of '/etc/puppetlabs/puppet/node.rb ${host}' returned 1:
Looking in the production.log I see...
2021-11-03T10:40:46 [W|app|6a4916f4] Failed to generate external nodes for ${host}
2021-11-03T10:40:46 [I|app|6a4916f4] Backtrace for 'Failed to generate external nodes for ${host}' error (TypeError): no implicit conversion of nil into Array
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.7/lib/active_record/relation/delegation.rb:87:in `+'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.7/lib/active_record/relation/delegation.rb:87:in `+'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_puppet-1.0.4/app/services/foreman_puppet/host_info_providers/config_groups_info.rb:7:in `host_info'
/usr/share/foreman/app/models/concerns/host_info_extensions.rb:27:in `block in info'
/usr/share/foreman/app/models/concerns/host_info_extensions.rb:25:in `each'
/usr/share/foreman/app/models/concerns/host_info_extensions.rb:25:in `info'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_puppet-1.0.4/app/controllers/concerns/foreman_puppet/extensions/hosts_controller_extensions.rb:100:in `block in externalNodes'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_controller/metal/mime_responds.rb:205:in `respond_to'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_puppet-1.0.4/app/controllers/concerns/foreman_puppet/extensions/hosts_controller_extensions.rb:96:in `externalNodes'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/abstract_controller/base.rb:195:in `process_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_controller/metal/rendering.rb:30:in `process_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/abstract_controller/callbacks.rb:42:in `block in process_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/callbacks.rb:112:in `block in run_callbacks'
/usr/share/foreman/app/controllers/concerns/foreman/controller/timezone.rb:10:in `set_timezone'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
/usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
/usr/share/foreman/app/controllers/concerns/foreman/controller/topbar_sweeper.rb:12:in `set_topbar_sweeper_controller'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
/opt/theforeman/tfm/root/usr/share/gems/gems/audited-4.9.0/lib/audited/sweeper.rb:14:in `around'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
/opt/theforeman/tfm/root/usr/share/gems/gems/audited-4.9.0/lib/audited/sweeper.rb:14:in `around'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/callbacks.rb:139:in `run_callbacks'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/abstract_controller/callbacks.rb:41:in `process_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_controller/metal/rescue.rb:22:in `process_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_controller/metal/instrumentation.rb:33:in `block in process_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/notifications.rb:180:in `block in instrument'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/notifications.rb:180:in `instrument'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_controller/metal/instrumentation.rb:32:in `process_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_controller/metal/params_wrapper.rb:245:in `process_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/activerecord-6.0.3.7/lib/active_record/railties/controller_runtime.rb:27:in `process_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/abstract_controller/base.rb:136:in `process'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionview-6.0.3.7/lib/action_view/rendering.rb:39:in `process'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_controller/metal.rb:190:in `dispatch'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_controller/metal.rb:254:in `dispatch'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_dispatch/routing/route_set.rb:50:in `dispatch'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_dispatch/routing/route_set.rb:33:in `serve'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_dispatch/journey/router.rb:49:in `block in serve'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_dispatch/journey/router.rb:32:in `each'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_dispatch/journey/router.rb:32:in `serve'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_dispatch/routing/route_set.rb:834:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/apipie-dsl-2.4.0/lib/apipie_dsl/static_dispatcher.rb:67:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.17/lib/apipie/static_dispatcher.rb:66:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.17/lib/apipie/extractor/recorder.rb:137:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_dispatch/middleware/static.rb:126:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_dispatch/middleware/static.rb:126:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_dispatch/middleware/static.rb:126:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_dispatch/middleware/static.rb:126:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_dispatch/middleware/static.rb:126:in `call'
/usr/share/foreman/lib/foreman/middleware/telemetry.rb:10:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.17/lib/apipie/middleware/checksum_in_headers.rb:27:in `call'
/usr/share/foreman/lib/foreman/middleware/catch_json_parse_errors.rb:9:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/tempfile_reaper.rb:15:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/etag.rb:27:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/conditional_get.rb:27: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/actionpack-6.0.3.7/lib/action_dispatch/http/content_security_policy.rb:18:in `call'
/usr/share/foreman/lib/foreman/middleware/logging_context_session.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/session/abstract/id.rb:266:in `context'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/session/abstract/id.rb:260:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_dispatch/middleware/cookies.rb:648:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_dispatch/middleware/callbacks.rb:27:in `block in call'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/callbacks.rb:101:in `run_callbacks'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_dispatch/middleware/callbacks.rb:26:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_dispatch/middleware/actionable_exceptions.rb:18:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_dispatch/middleware/debug_exceptions.rb:32:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_dispatch/middleware/show_exceptions.rb:33:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.7/lib/rails/rack/logger.rb:37:in `call_app'
/opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.7/lib/rails/rack/logger.rb:28:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/sprockets-rails-3.2.1/lib/sprockets/rails/quiet_assets.rb:13:in `call'
/usr/share/foreman/lib/foreman/middleware/logging_context_request.rb:11:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_dispatch/middleware/remote_ip.rb:81:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_dispatch/middleware/request_id.rb:27:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/method_override.rb:24:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/runtime.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/cache/strategy/local_cache_middleware.rb:29:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_dispatch/middleware/executor.rb:14:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_dispatch/middleware/static.rb:126:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/rack-2.2.3/lib/rack/sendfile.rb:110:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/actionpack-6.0.3.7/lib/action_dispatch/middleware/host_authorization.rb:76:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/secure_headers-6.3.0/lib/secure_headers/middleware.rb:11:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.7/lib/rails/engine.rb:527:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.7/lib/rails/railtie.rb:190:in `public_send'
/opt/theforeman/tfm/root/usr/share/gems/gems/railties-6.0.3.7/lib/rails/railtie.rb:190:in `method_missing'
/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/puma-5.3.2/lib/puma/configuration.rb:249:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/puma-5.3.2/lib/puma/request.rb:77:in `block in handle_request'
/opt/theforeman/tfm/root/usr/share/gems/gems/puma-5.3.2/lib/puma/thread_pool.rb:338:in `with_force_shutdown'
/opt/theforeman/tfm/root/usr/share/gems/gems/puma-5.3.2/lib/puma/request.rb:76:in `handle_request'
/opt/theforeman/tfm/root/usr/share/gems/gems/puma-5.3.2/lib/puma/server.rb:438:in `process_client'
/opt/theforeman/tfm/root/usr/share/gems/gems/puma-5.3.2/lib/puma/thread_pool.rb:145:in `block in spawn_thread'
/opt/theforeman/tfm/root/usr/share/gems/gems/logging-2.3.0/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
I am unable to complete the upgrade to version 3 even though it seems to complete without error.
Updated by Mark Gargiulo over 2 years ago
- Category changed from Database to Plugin integration
Updated by Mark Gargiulo over 2 years ago
Further information.
I edited the offending line from the stack trace in /opt/theforeman/tfm/root/usr/share/gems/gems/foreman_puppet-1.0.4/app/services/foreman_puppet/host_info_providers/config_groups_info.rb to remove "+ host.puppet.parent_config_groups" from line "config_groups = (host.puppet.config_groups + host.puppet.parent_config_groups).uniq.map(&:name)" and this allowed the problem hosts to retrieve their node definitions.
Oddly, I do not use config groups and that table has 0 rows on both the failing Prod server and working Dev instance though I realize that parent_config_groups is a defined function and may not be directly related.
I am unsure how to categorize this issue now as it appears not to be related to the tfm-rubygem-foreman_expire_hosts-7.0.4-2.fm2_5.el7.noarch plugin at this point.
Updated by Mark Gargiulo over 2 years ago
- Status changed from New to Resolved
So as I have had no response in 22 days, with some in house help I have fixed the issue and am closing this ticket.
For anyone reading this that might have a similar issue here was the problem, well 2 different problems which were not obvious at first.
1. Remove the tfm-rubygem-foreman_expire_hosts plugin as this caused the DB migration to fail. Remove the expire_on column from the hosts table.
2. The puppet run issues after the "successful" upgrade where the node could not find itself in the ENC was related to the new hostgroup_puppet_facets table which had 46 rows but our hostgroups table had 66 rows. We ran this insert statement to fix the missing entries.
insert into hostgroup_puppet_facets select nextval('hostgroup_puppet_facets_id_seq'), id from hostgroups where id not in (select hostgroup_id from hostgroup_puppet_facets);
This then allowed all previously failing puppet runs (75 hosts) to succeed.
Turns out my Foreman Dev instance also had this issue but none of the hosts registered with it belonged to a missing hostgroup so it appeared functional. I can only assume this is a problem with the DB migration scripts.