Bug #31412: virt-who can't update the VMs-to-ESXi Host mapping since the last update - Katello - Foreman

Actions

Copy link

Bug #31412

closed

virt-who can't update the VMs-to-ESXi Host mapping since the last update

Added by Mario K over 3 years ago. Updated over 3 years ago.

Status:

Resolved

Priority:

Normal

Assignee:

Category:

Hosts

Target version:

Katello Recycle Bin

Difficulty:

Triaged:

Yes

Bugzilla link:

Pull request:

Fixed in Releases:

Found in Releases:

Red Hat JIRA:

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

Actions

Copy link

Updated by Mario K over 3 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

Actions

Copy link

Updated by Tomer Brisker over 3 years ago

Project changed from Foreman to Katello

Actions

Copy link

Updated by Mario K over 3 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

Actions

Copy link

Updated by Mario K over 3 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.

Actions

Copy link

Updated by Mario K over 3 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

Actions

Copy link

Updated by Mario K over 3 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

Actions

Copy link

Updated by Chris Roberts over 3 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

Actions

Copy link

Also available in: Atom PDF

Project

General

Profile

Plugins » Katello

Custom queries

Bug #31412

virt-who can't update the VMs-to-ESXi Host mapping since the last update

Updated by Mario K over 3 years ago

Updated by Tomer Brisker over 3 years ago

Updated by Mario K over 3 years ago

Updated by Mario K over 3 years ago

Updated by Mario K over 3 years ago

Updated by Mario K over 3 years ago

Updated by Chris Roberts over 3 years ago