Bug #31412
closed
virt-who can't update the VMs-to-ESXi Host mapping since the last update
Description
Hello guys,
On 2.11.2020 I did install all pending OS Updates of my CentOS7 system and did update Katello and foreman.
Foreman: from Version 1.24.3-1 to Version 2.1.4-1
Katello: from Version 3.14.1-1 to Version 3.16.1-1
Today I found that the virt-who service is unable to update the VMs-to-ESXi Host mapping. The Task that does the update ends with an Warning.
Debug output:
[root@katellohost ~]# alias hammer='hammer --config /data/usr/local/etc/hammer/cli_config.yml'
[root@katellohost ~]# hammer task info --id uniqe_uuid_string
ID: uniqe_uuid_string
Action: Hypervisors
State: stopped
Result: warning
Started at: 2020/11/02 17:18:37
Ended at: 2020/11/02 17:19:04
Owner:
Task errors: undefined method `[]' for nil:NilClass
[root@katellohost ~]#
Please let me know if you do need more debug output or logfile content.
sincerely yours
Mario
Updated by Mario K about 4 years ago
Hello guys,
On the Katelloserver in the /var/log/foreman/production.log I found this logentries:
2020-11-30T16:56:09 [I|bac|dc08d1fe] Task {label: Actions::Katello::Host::Hypervisors, id: hypervisor_uniqe_uuid, execution_plan_id: 52a011cb-d75
d-462e-a5db-10743bc7a477} state changed: planning
2020-11-30T16:56:09 [I|app|f0693e8e] Started GET "/notification_recipients" for 127.0.0.1 at 2020-11-30 16:56:09 +0100
2020-11-30T16:56:09 [I|app|f0693e8e] Processing by NotificationRecipientsController#index as JSON
2020-11-30T16:56:10 [I|app|f0693e8e] Completed 200 OK in 18ms (Views: 0.2ms | ActiveRecord: 7.7ms | Allocations: 5158)
2020-11-30T16:56:10 [W|app|3cd7277a] Scoped order is ignored, it's forced to be batch order.
2020-11-30T16:56:10 [I|app|3cd7277a] Authorized user myaduser(myaduser myaduser)
2020-11-30T16:56:10 [I|bac|] Task {label: Actions::Katello::Host::Hypervisors, id: hypervisor_uniqe_uuid, execution_plan_id: 52a011cb-d75d-462e-a5db-10743bc7a477} state changed: planned
2020-11-30T16:56:10 [I|app|] Completed 200 OK in 560ms (Views: 0.5ms | ActiveRecord: 56.1ms | Allocations: 116765)
2020-11-30T16:56:10 [I|bac|] Task {label: Actions::Katello::Host::Hypervisors, id: hypervisor_uniqe_uuid, execution_plan_id: 52a011cb-d75d-462e-a5db-10743bc7a477} state changed: running
2020-11-30T16:56:10 [I|app|3cd7277a] Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.16.1.2/app/views/katello/api/v2/products/index.json.rabl within katello/api/v2/layouts/collection
2020-11-30T16:56:10 [E|bac|] undefined method `[]' for nil:NilClass (NoMethodError)
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.16.1.2/app/lib/actions/katello/host/hypervisors.rb:27:in `block in parse_hypervisors'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.16.1.2/app/lib/actions/katello/host/hypervisors.rb:26:in `each'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.16.1.2/app/lib/actions/katello/host/hypervisors.rb:26:in `parse_hypervisors'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.16.1.2/app/lib/actions/candlepin/async_hypervisors.rb:12:in `poll_external_task'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.16.1.2/app/lib/actions/candlepin/async_hypervisors.rb:18:in `invoke_external_task'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/action/polling.rb:84:in `initiate_external_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/action/polling.rb:19:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.16.1.2/app/lib/actions/candlepin/abstract_async_task.rb:9:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/action.rb:571:in `block (3 levels) in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:27:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware.rb:19:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.16.1.2/app/lib/actions/middleware/keep_session_id.rb:11:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.16.1.2/app/lib/actions/middleware/keep_session_id.rb:23:in `with_session_id'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.16.1.2/app/lib/actions/middleware/keep_session_id.rb:11:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:23:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:27:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware.rb:19:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware.rb:32:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:23:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:27:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware.rb:19:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.16.1.2/app/lib/actions/middleware/propagate_candlepin_errors.rb:9:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.16.1.2/app/lib/actions/middleware/propagate_candlepin_errors.rb:19:in `propagate_candlepin_errors'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.16.1.2/app/lib/actions/middleware/propagate_candlepin_errors.rb:9:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:23:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:27:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware.rb:19:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.16.1.2/app/lib/actions/middleware/remote_action.rb:16:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.16.1.2/app/lib/actions/middleware/remote_action.rb:40:in `block in as_remote_user'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.16.1.2/app/models/katello/concerns/user_extensions.rb:21:in `cp_config'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.16.1.2/app/lib/actions/middleware/remote_action.rb:27:in `as_cp_user'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.16.1.2/app/lib/actions/middleware/remote_action.rb:39:in `as_remote_user'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.16.1.2/app/lib/actions/middleware/remote_action.rb:16:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:23:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:27:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware.rb:19:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-2.0.2/app/lib/actions/middleware/rails_executor_wrap.rb:14:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.1/lib/active_support/execution_wrapper.rb:88:in `wrap'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-2.0.2/app/lib/actions/middleware/rails_executor_wrap.rb:13:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:23:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:27:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware.rb:19:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/action/progress.rb:31:in `with_progress_calculation'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/action/progress.rb:17:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:23:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:27:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware.rb:19:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-2.0.2/app/lib/actions/middleware/keep_current_request_id.rb:15:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-2.0.2/app/lib/actions/middleware/keep_current_request_id.rb:49:in `restore_current_request_id'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-2.0.2/app/lib/actions/middleware/keep_current_request_id.rb:15:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:23:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:27:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware.rb:19:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-2.0.2/app/lib/actions/middleware/keep_current_timezone.rb:15:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-2.0.2/app/lib/actions/middleware/keep_current_timezone.rb:44:in `restore_curent_timezone'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-2.0.2/app/lib/actions/middleware/keep_current_timezone.rb:15:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:23:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:27:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware.rb:19:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-2.0.2/app/lib/actions/middleware/keep_current_user.rb:15:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-2.0.2/app/lib/actions/middleware/keep_current_user.rb:44:in `restore_curent_user'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-2.0.2/app/lib/actions/middleware/keep_current_user.rb:15:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:23:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:27:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware.rb:19:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-2.0.2/app/lib/actions/middleware/keep_current_taxonomies.rb:15:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-2.0.2/app/lib/actions/middleware/keep_current_taxonomies.rb:45:in `restore_current_taxonomies'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-2.0.2/app/lib/actions/middleware/keep_current_taxonomies.rb:15:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:23:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:27:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware.rb:19:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware.rb:32:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/stack.rb:23:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/middleware/world.rb:31:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/action.rb:570:in `block (2 levels) in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/action.rb:569:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/action.rb:569:in `block in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/action.rb:472:in `block in with_error_handling'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/action.rb:472:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/action.rb:472:in `with_error_handling'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/action.rb:564:in `execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/action.rb:285:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:18:in `block (2 levels) in execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/execution_plan/steps/abstract.rb:167:in `with_meta_calculation'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:17:in `block in execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:32:in `open_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:16:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/director.rb:68:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/executors/sidekiq/worker_jobs.rb:11:in `block (2 levels) in perform'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/executors.rb:18:in `run_user_code'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/executors/sidekiq/worker_jobs.rb:9:in `block in perform'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/executors/sidekiq/worker_jobs.rb:25:in `with_telemetry'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/executors/sidekiq/worker_jobs.rb:8:in `perform'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.7/lib/dynflow/executors/sidekiq/serialization.rb:27:in `perform'
[ sidekiq ]
[ concurrent-ruby ]
If you need more logoutput, then I can provide more. I tried to copy&paste just the lines that I think could be related to this case.
To provide the whole logfile is not possible because it's a huge file with about 400000 entries. And before I can copy any content in this public case it needs revewing and removing of sensitive data.
sincerely yours
Mario
Updated by Tomer Brisker about 4 years ago
- Project changed from Foreman to Katello
Updated by Mario K about 4 years ago
On 2.11.2020 there was also an update of candlepin
Candlepin from 3.1.7-1.el7 to 3.1.16-1.el7
Updated by Mario K about 4 years ago
On 2.11.2020 I did update virt-who
virt-who: from 0.21.6-1.el6 to 0.26.5-1.el7
Before the 2.11.2020 the virt-who did run on an RHEL6 system. On 2.11.2020 I installed virt-who on the Katello System, that os CentOS7.
Updated by Mario K about 4 years ago
Today someone on IRC told me that the root cause is a change in virt-who itself.
So I did test the Update with the old Version 0.21.6-1.el6 onthe RHEL6 system.
The result is the same:
hammer task info --id uniqe_uuid_string
ID: uniqe_uuid_string
Action: Hypervisors
State: stopped
Result: warning
Started at: 2020/12/01 15:42:06
Ended at: 2020/12/01 15:42:07
Owner:
Task errors: undefined method `[]' for nil:NilClass
sincerely yours
Mario
Updated by Mario K about 4 years ago
Hello,
Someone from the #theforeman channel on the Freenode IRC Server did help me to solve the issue.
Every time that virt-who tried to update the Hypervisor data in Katello the following line got written to the logfile /var/log/candlepin/candlepin.log
2020-12-04 00:43:10,678 [thread=http-bio-127.0.0.1-8443-exec-5] [req=some_uniqe_uuid, org=CompanyName, csid=some_uniqe_uuid] INFO org.candlepin.async.JobManager - Unable to queue job: Hypervisor Update; blocked by the following existing jobs: 32_digit_hexadecimal_number
the soloution is:
Stop virt-who and tomcat
systemctl stop virt-who.service
systemctl stop tomcat.service
then connect to the postgres database candlepin
su - postgres
psql
postgres=# \c candlepin
then look if there is a row with id=32_digit_hexadecimal_number in the table cp_async_jobs
select * from cp_async_jobs where id = '32_digit_hexadecimal_number';
if there is one row then delete this row
delete from cp_async_jobs where id = '32_digit_hexadecimal_number';
then close psql, exist the postgres shell
\q
exit
then start tomcat and virt-who
systemctl start tomcat.service
systemctl start virt-who.service
that did fix my issue. Thanks for helping me. You can close this case.
sincerely yours
Mario
Updated by Chris Roberts about 4 years ago
- Category set to Hosts
- Status changed from New to Resolved
- Target version set to Katello Recycle Bin
- Triaged changed from No to Yes