Closed wheeskers closed 7 years ago
timogoebel
commented
7 years ago @wheeskers : Thanks for the report. I'll have to look into that in more detail, but as a hotfix you can change
/usr/share/foreman/app/models/concerns/orchestration/compute.rb:29
to
def compute_provides?(attr)
compute? && compute_resource && compute_resource.provided_attributes.keys.include?(attr)
end
wheeskers
commented
7 years ago @timogoebel, thank you for the fast reply!
I've applied this hotfix and it partially worked because initial exception changed.
Now the task stops at mail method (log contents below).
It seems that notifiable_hosts array collects all expiring/expired hosts (Host::Managed subclass instances if I understand this correctly) and is OK but then hosts_by_user block fails on iteration.
Log:
rake aborted!
NoMethodError: undefined method `mail' for nil:NilClass
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_expire_hosts-3.0.0/lib/expire_hosts_notifications.rb:100:in `block in hosts_by_user'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_expire_hosts-3.0.0/lib/expire_hosts_notifications.rb:94:in `each'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_expire_hosts-3.0.0/lib/expire_hosts_notifications.rb:94:in `hosts_by_user'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_expire_hosts-3.0.0/lib/expire_hosts_notifications.rb:34:in `delete_expired_hosts'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_expire_hosts-3.0.0/lib/tasks/expired_hosts.rake:5:in `block (2 levels) in <top (required)>'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:240:in `call'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:240:in `block in execute'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:235:in `each'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:235:in `execute'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:179:in `block in invoke_with_call_chain'
/opt/rh/rh-ruby22/root/usr/share/ruby/monitor.rb:211:in `mon_synchronize'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:172:in `invoke_with_call_chain'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:165:in `invoke'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:150:in `invoke_task'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:106:in `block (2 levels) in top_level'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:106:in `each'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:106:in `block in top_level'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:115:in `run_with_threads'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:100:in `top_level'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:78:in `block in run'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:176:in `standard_exception_handling'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:75:in `run'
/opt/rh/rh-ruby22/root/usr/bin/rake:33:in `<main>'
Tasks: TOP => expired_hosts:deliver_notifications
Host object: #<Host::Managed id: 353, name: "host05.domain.com", last_compile: nil, last_report: "2017-08-07 08:07:02", updated_at: "2017-08-07 08:07:20", created_at: "2017-01-17 15:00:49", root_pass: "<...>...", architecture_id: 1, operatingsystem_id: 4, environment_id: 2, ptable_id: 92, medium_id: 9, build: false, comment: "", disk: "", installed_at: "2017-01-17 15:18:20", model_id: 1, hostgroup_id: 1, owner_id: 68, owner_type: "User", enabled: true, puppet_ca_proxy_id: 8, managed: true, use_image: nil, image_file: nil, uuid: nil, compute_resource_id: nil, puppet_proxy_id: 7, certname: "host05@domain.com", image_id: nil, organization_id: nil, location_id: 9, type: "Host::Managed", otp: nil, realm_id: nil, compute_profile_id: 4, provision_method: "build", grub_pass: "<...>...", global_status: 2, lookup_value_matcher: "fqdn=host05.domain.c...", pxe_loader: "PXELinux BIOS", discovery_rule_id: nil, expired_on: "2017-07-03">
Owner object:nil
Emails object:["adm@domain.com"]Note: I substituted some sensitive data in log above (hostnames, emails etc) but everything else is intact.
timogoebel
commented
7 years ago @wheeskers: I'm sorry, this wasn't a quick fix. But it revealed the actually error happening here. I have looked at the error and have a pretty good understanding, what's causing this. I will get back to you with a fix asap.
wheeskers
commented
7 years ago @timogoebel, thanks!
timogoebel
commented
7 years ago This is really weird and although I have an idea what is happening, I have no clue as to why this happens.
The code builds an array of host objects that should be deleted. It then iterates over these hosts and calls .destroy on them. Somehow this host object doesn't seem to have any associations.
The first stack trace shows, that although compute_resource_id is set, compute_resource is nil. It should be the compute resource object that has the id compute_resource_id. The second stack shows, that owner_type and owner_id is set, but owner is nil.
My initial thought was, that this was a permissions related. But I wasn't able to actually reproduce this behavior. Trust me, I've tried.
I have a couple of questions. Maybe this helps us find the issue.
lib/expire_hosts_notifications.rb? Can you provide the output of another run? Together with SQL logger enabled on debug level this should help us find the issue.diff --git a/lib/expire_hosts_notifications.rb b/lib/expire_hosts_notifications.rb
index defd467..ea033b5 100644
--- a/lib/expire_hosts_notifications.rb
+++ b/lib/expire_hosts_notifications.rb
@@ -24,11 +24,25 @@ module ExpireHostsNotifications
deletable_hosts.each do |deletable_host|
Rails.logger.info "Deleting expired host #{deletable_host}"
deletable_host.audit_comment = _('Destroyed since it got expired on %s') % deletable_host.expired_on
+ puts "Before destroy"
+ puts "Current User: #{User.current}"
+ puts "User Tax: Loc: #{User.current.try(:locations)} - Orgs: #{User.current.try(:organizations)}"
+ puts "Host: #{deletable_host.inspect}"
+ puts "Tax: Location: #{deletable_host.location} Organization: #{deletable_host.organization}"
+ puts "Compute Resource: ID: #{deletable_host.compute_resource_id} Record: #{deletable_host.compute_resource}"
+ puts "Owner: ID: #{deletable_host.owner_id} Type: #{deletable_host.owner_type} Record: #{deletable_host.owner}"
if deletable_host.destroy
deleted_hosts << deletable_host
else
failed_delete_hosts << deletable_host
end
+ puts "After destroy"
+ puts "Current User: #{User.current}"
+ puts "User Tax: Loc: #{User.current.try(:locations)} - Orgs: #{User.current.try(:organizations)}"
+ puts "Host: #{deletable_host.inspect}"
+ puts "Tax: Location: #{deletable_host.location} Organization: #{deletable_host.organization}"
+ puts "Compute Resource: ID: #{deletable_host.compute_resource_id} Record: #{deletable_host.compute_resource}"
+ puts "Owner: ID: #{deletable_host.owner_id} Type: #{deletable_host.owner_type} Record: #{deletable_host.owner}"
end
unless deleted_hosts.empty?
ExpireHostsNotifications.hosts_by_user(deleted_hosts).each do |user_id, hosts_hash|diff --git a/lib/tasks/expired_hosts.rake b/lib/tasks/expired_hosts.rake
index 7af8092..f822f24 100644
--- a/lib/tasks/expired_hosts.rake
+++ b/lib/tasks/expired_hosts.rake
@@ -2,10 +2,12 @@
namespace :expired_hosts do
desc 'Delete all expired hosts, send notification email about expiring hosts'
task :deliver_notifications => :environment do
- ExpireHostsNotifications.delete_expired_hosts
- ExpireHostsNotifications.stop_expired_hosts
- ExpireHostsNotifications.deliver_expiry_warning_notification(1)
- ExpireHostsNotifications.deliver_expiry_warning_notification(2)
+ User.as_anonymous_admin do
+ ExpireHostsNotifications.delete_expired_hosts
+ ExpireHostsNotifications.stop_expired_hosts
+ ExpireHostsNotifications.deliver_expiry_warning_notification(1)
+ ExpireHostsNotifications.deliver_expiry_warning_notification(2)
+ end
end
end@timogoebel,
Do you have Taxonomies (Locations, Organizations) enabled?
Currently there are multiple Foreman Locations in use with "relations" (i.e. Names are PLACE, PLACE/SUB1, PLACE/SUB2 and so on). Hosts are bound to "sub-locations" (SUB1 etc).
I couldn't find any mentions about "Organizations" in admin interface or searching in our task history so I guess this feature is not used at all.
Can you add some debugging code to lib/expire_hosts_notifications.rb? Can you provide the output of another run?
Yes, sure. Can't do this right now because we are crating a large group of VMs today so I'll have to wait some time until most of the operations complete.
Thanks again for the help, I'll try this as soon as possible and post new log output.
wheeskers
commented
7 years ago @timogoebel, it seems that the problem is more complex. I have added debug code to expire_hosts_notifications.rb but somehow running notifications task yields a different error now.
As far as I know this is already happened before I were tasked to review this problem in our environment. I suppose this may be related to some specific hosts (i.e. "bare metal" provisioned) that are periodically deleted manually by VM users and then this exception goes away on its own. This is just an assumption though because there were no code modifications on TFM host (except the debug code from this issue).
Launch command is still the same:
# /usr/sbin/foreman-rake --backtrace --rules -v expired_hosts:deliver_notifications > logfile 2>&1
Log lines are below. I've substituted some sensitive data (person names, locations, host names, etc) by simple placeholder values but they are still consistent (same hostname = same substitute through log file). Null or empty values are not modified and left 'as is'.
Before destroy
Current User:
User Tax: Loc: - Orgs:
Host: #<Host::Managed id: 662, name: "4a4cf823.com", last_compile: nil, last_report: "2017-08-12 03:29:15", updated_at: "2017-08-12 03:29:36", created_at: "2017-05-29 11:45:13", root_pass: "...", architecture_id: 1, operatingsystem_id: 4, environment_id: 2, ptable_id: 92, medium_id: 9, build: false, comment: "", disk: "", installed_at: "2017-05-29 11:59:39", model_id: 1, hostgroup_id: 1, owner_id: 68, owner_type: "User", enabled: true, puppet_ca_proxy_id: 8, managed: true, use_image: nil, image_file: nil, uuid: "6d58d0dd", compute_resource_id: 1, puppet_proxy_id: 7, certname: "4a4cf823.com", image_id: nil, organization_id: nil, location_id: 4, type: "Host::Managed", otp: nil, realm_id: nil, compute_profile_id: 4, provision_method: "build", grub_pass: "...", global_status: 2, lookup_value_matcher: "fqdn=4a4cf823.com", pxe_loader: "PXELinux BIOS", discovery_rule_id: nil, expired_on: "2017-07-03">
Tax: Location: 437910f1 Organization:
Compute Resource: ID: 1 Record:
Owner: ID: 68 Type: User Record:
After destroy
Current User:
User Tax: Loc: - Orgs:
Host: #<Host::Managed id: 662, name: "4a4cf823.com", last_compile: nil, last_report: "2017-08-12 03:29:15", updated_at: "2017-08-12 03:29:36", created_at: "2017-05-29 11:45:13", root_pass: "...", architecture_id: 1, operatingsystem_id: 4, environment_id: 2, ptable_id: 92, medium_id: 9, build: false, comment: "", disk: "", installed_at: "2017-05-29 11:59:39", model_id: 1, hostgroup_id: 1, owner_id: 68, owner_type: "User", enabled: true, puppet_ca_proxy_id: 8, managed: true, use_image: nil, image_file: nil, uuid: "6d58d0dd", compute_resource_id: 1, puppet_proxy_id: 7, certname: "4a4cf823.com", image_id: nil, organization_id: nil, location_id: 4, type: "Host::Managed", otp: nil, realm_id: nil, compute_profile_id: 4, provision_method: "build", grub_pass: "...", global_status: 2, lookup_value_matcher: "fqdn=4a4cf823.com", pxe_loader: "PXELinux BIOS", discovery_rule_id: nil, expired_on: "2017-07-03">
Tax: Location: 437910f1 Organization:
Compute Resource: ID: 1 Record:
Owner: ID: 68 Type: User Record:
# -----------------------------------------------------------------------------------------------------
# Removed large amount of log lines with similar content for readability, first and last hosts are left
# -----------------------------------------------------------------------------------------------------
Before destroy
Current User:
User Tax: Loc: - Orgs:
Host: #<Host::Managed id: 506, name: "74824212.com", last_compile: nil, last_report: "2017-06-22 17:40:44", updated_at: "2017-06-29 16:53:28", created_at: "2017-03-14 14:34:29", root_pass: "...", architecture_id: 1, operatingsystem_id: 4, environment_id: 2, ptable_id: 92, medium_id: 9, build: false, comment: "", disk: "", installed_at: "2017-03-14 16:43:14", model_id: 1, hostgroup_id: 1, owner_id: 46, owner_type: "User", enabled: true, puppet_ca_proxy_id: 8, managed: true, use_image: nil, image_file: nil, uuid: "af156cbe", compute_resource_id: 1, puppet_proxy_id: 7, certname: "74824212.com", image_id: nil, organization_id: nil, location_id: 5, type: "Host::Managed", otp: nil, realm_id: nil, compute_profile_id: 4, provision_method: "build", grub_pass: "...", global_status: 2, lookup_value_matcher: "fqdn=74824212.com", pxe_loader: "PXELinux BIOS", discovery_rule_id: nil, expired_on: "2017-07-20">
Tax: Location: d5f06d5f Organization:
Compute Resource: ID: 1 Record:
Owner: ID: 46 Type: User Record:
After destroy
Current User:
User Tax: Loc: - Orgs:
Host: #<Host::Managed id: 506, name: "74824212.com", last_compile: nil, last_report: "2017-06-22 17:40:44", updated_at: "2017-06-29 16:53:28", created_at: "2017-03-14 14:34:29", root_pass: "...", architecture_id: 1, operatingsystem_id: 4, environment_id: 2, ptable_id: 92, medium_id: 9, build: false, comment: "", disk: "", installed_at: "2017-03-14 16:43:14", model_id: 1, hostgroup_id: 1, owner_id: 46, owner_type: "User", enabled: true, puppet_ca_proxy_id: 8, managed: true, use_image: nil, image_file: nil, uuid: "af156cbe", compute_resource_id: 1, puppet_proxy_id: 7, certname: "74824212.com", image_id: nil, organization_id: nil, location_id: 5, type: "Host::Managed", otp: nil, realm_id: nil, compute_profile_id: 4, provision_method: "build", grub_pass: "...", global_status: 2, lookup_value_matcher: "fqdn=74824212.com", pxe_loader: "PXELinux BIOS", discovery_rule_id: nil, expired_on: "2017-07-20">rake aborted!
Foreman::Exception: ERF42-1251 [Foreman::Exception]: Error has occurred while communicating with : undefined method `find_vm_by_uuid' for nil:NilClass
/usr/share/foreman/app/services/power_manager/virt.rb:15:in `rescue in initialize'
/usr/share/foreman/app/services/power_manager/virt.rb:7:in `initialize'
/usr/share/foreman/app/models/concerns/hostext/power_interface.rb:8:in `new'
/usr/share/foreman/app/models/concerns/hostext/power_interface.rb:8:in `power'
/usr/share/foreman/app/models/concerns/hostext/power_interface.rb:22:in `supports_power_and_running?'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_expire_hosts-3.0.0/lib/expire_hosts_notifications.rb:66:in `block in stop_expired_hosts'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/relation/delegation.rb:46:in `each'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/relation/delegation.rb:46:in `each'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_expire_hosts-3.0.0/lib/expire_hosts_notifications.rb:65:in `stop_expired_hosts'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_expire_hosts-3.0.0/lib/tasks/expired_hosts.rake:6:in `block (2 levels) in <top (required)>'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:240:in `call'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:240:in `block in execute'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:235:in `each'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:235:in `execute'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:179:in `block in invoke_with_call_chain'
/opt/rh/rh-ruby22/root/usr/share/ruby/monitor.rb:211:in `mon_synchronize'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:172:in `invoke_with_call_chain'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:165:in `invoke'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:150:in `invoke_task'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:106:in `block (2 levels) in top_level'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:106:in `each'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:106:in `block in top_level'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:115:in `run_with_threads'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:100:in `top_level'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:78:in `block in run'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:176:in `standard_exception_handling'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:75:in `run'
/opt/rh/rh-ruby22/root/usr/bin/rake:33:in `<main>'
NoMethodError: undefined method `find_vm_by_uuid' for nil:NilClass
/usr/share/foreman/app/services/power_manager/virt.rb:9:in `block in initialize'
/opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:89:in `block in timeout'
/opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:34:in `block in catch'
/opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:34:in `catch'
/opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:34:in `catch'
/opt/rh/rh-ruby22/root/usr/share/ruby/timeout.rb:104:in `timeout'
/usr/share/foreman/app/services/power_manager/virt.rb:8:in `initialize'
/usr/share/foreman/app/models/concerns/hostext/power_interface.rb:8:in `new'
/usr/share/foreman/app/models/concerns/hostext/power_interface.rb:8:in `power'
/usr/share/foreman/app/models/concerns/hostext/power_interface.rb:22:in `supports_power_and_running?'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_expire_hosts-3.0.0/lib/expire_hosts_notifications.rb:66:in `block in stop_expired_hosts'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/relation/delegation.rb:46:in `each'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/relation/delegation.rb:46:in `each'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_expire_hosts-3.0.0/lib/expire_hosts_notifications.rb:65:in `stop_expired_hosts'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_expire_hosts-3.0.0/lib/tasks/expired_hosts.rake:6:in `block (2 levels) in <top (required)>'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:240:in `call'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:240:in `block in execute'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:235:in `each'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:235:in `execute'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:179:in `block in invoke_with_call_chain'
/opt/rh/rh-ruby22/root/usr/share/ruby/monitor.rb:211:in `mon_synchronize'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:172:in `invoke_with_call_chain'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:165:in `invoke'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:150:in `invoke_task'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:106:in `block (2 levels) in top_level'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:106:in `each'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:106:in `block in top_level'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:115:in `run_with_threads'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:100:in `top_level'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:78:in `block in run'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:176:in `standard_exception_handling'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:75:in `run'
/opt/rh/rh-ruby22/root/usr/bin/rake:33:in `<main>'
Tasks: TOP => expired_hosts:deliver_notifications
Tax: Location: d5f06d5f Organization:
Compute Resource: ID: 1 Record:
Owner: ID: 46 Type: User Record:
Before destroy
Current User:
User Tax: Loc: - Orgs:
Host: #<Host::Managed id: 475, name: "ccff701d.c...", last_compile: nil, last_report: "2017-06-22 17:51:27", updated_at: "2017-06-29 16:53:29", created_at: "2017-02-27 12:20:04", root_pass: "...", architecture_id: 1, operatingsystem_id: 4, environment_id: 2, ptable_id: 92, medium_id: 9, build: false, comment: "", disk: "", installed_at: "2017-02-27 12:32:49", model_id: 1, hostgroup_id: 1, owner_id: 7, owner_type: "User", enabled: true, puppet_ca_proxy_id: 8, managed: true, use_image: nil, image_file: nil, uuid: "07b1a770", compute_resource_id: 1, puppet_proxy_id: 7, certname: "ccff701d.c...", image_id: nil, organization_id: nil, location_id: 5, type: "Host::Managed", otp: nil, realm_id: nil, compute_profile_id: 4, provision_method: "build", grub_pass: "...", global_status: 2, lookup_value_matcher: "fqdn=534221d7", pxe_loader: "PXELinux BIOS", discovery_rule_id: nil, expired_on: "2017-07-20">
Tax: Location: d5f06d5f Organization:
Compute Resource: ID: 1 Record:
Owner: ID: 7 Type: User Record:
After destroy
Current User:
User Tax: Loc: - Orgs:
Host: #<Host::Managed id: 475, name: "ccff701d.c...", last_compile: nil, last_report: "2017-06-22 17:51:27", updated_at: "2017-06-29 16:53:29", created_at: "2017-02-27 12:20:04", root_pass: "...", architecture_id: 1, operatingsystem_id: 4, environment_id: 2, ptable_id: 92, medium_id: 9, build: false, comment: "", disk: "", installed_at: "2017-02-27 12:32:49", model_id: 1, hostgroup_id: 1, owner_id: 7, owner_type: "User", enabled: true, puppet_ca_proxy_id: 8, managed: true, use_image: nil, image_file: nil, uuid: "07b1a770", compute_resource_id: 1, puppet_proxy_id: 7, certname: "ccff701d.c...", image_id: nil, organization_id: nil, location_id: 5, type: "Host::Managed", otp: nil, realm_id: nil, compute_profile_id: 4, provision_method: "build", grub_pass: "...", global_status: 2, lookup_value_matcher: "fqdn=534221d7", pxe_loader: "PXELinux BIOS", discovery_rule_id: nil, expired_on: "2017-07-20">
Tax: Location: d5f06d5f Organization:
Compute Resource: ID: 1 Record:
Owner: ID: 7 Type: User Record:
Before destroy
Current User:
User Tax: Loc: - Orgs:
Host: #<Host::Managed id: 142, name: "dd4f9963.com", last_compile: nil, last_report: "2017-08-22 11:24:36", updated_at: "2017-08-22 11:24:55", created_at: "2016-12-03 13:03:02", root_pass: "...", architecture_id: 1, operatingsystem_id: 3, environment_id: 2, ptable_id: 92, medium_id: 9, build: false, comment: "", disk: "", installed_at: nil, model_id: 1, hostgroup_id: 1, owner_id: 130, owner_type: "User", enabled: true, puppet_ca_proxy_id: 8, managed: true, use_image: nil, image_file: nil, uuid: "406e169a", compute_resource_id: 1, puppet_proxy_id: 7, certname: "dd4f9963.com", image_id: nil, organization_id: nil, location_id: 5, type: "Host::Managed", otp: nil, realm_id: nil, compute_profile_id: 4, provision_method: nil, grub_pass: "...", global_status: 2, lookup_value_matcher: "fqdn=dd4f9963.com", pxe_loader: "PXELinux BIOS", discovery_rule_id: nil, expired_on: "2017-07-15">
Tax: Location: d5f06d5f Organization:
Compute Resource: ID: 1 Record:
Owner: ID: 130 Type: User Record:
After destroy
Current User:
User Tax: Loc: - Orgs:
Host: #<Host::Managed id: 142, name: "dd4f9963.com", last_compile: nil, last_report: "2017-08-22 11:24:36", updated_at: "2017-08-22 11:24:55", created_at: "2016-12-03 13:03:02", root_pass: "...", architecture_id: 1, operatingsystem_id: 3, environment_id: 2, ptable_id: 92, medium_id: 9, build: false, comment: "", disk: "", installed_at: nil, model_id: 1, hostgroup_id: 1, owner_id: 130, owner_type: "User", enabled: true, puppet_ca_proxy_id: 8, managed: true, use_image: nil, image_file: nil, uuid: "406e169a", compute_resource_id: 1, puppet_proxy_id: 7, certname: "dd4f9963.com", image_id: nil, organization_id: nil, location_id: 5, type: "Host::Managed", otp: nil, realm_id: nil, compute_profile_id: 4, provision_method: nil, grub_pass: "...", global_status: 2, lookup_value_matcher: "fqdn=dd4f9963.com", pxe_loader: "PXELinux BIOS", discovery_rule_id: nil, expired_on: "2017-07-15">
Tax: Location: d5f06d5f Organization:
Compute Resource: ID: 1 Record:
Owner: ID: 130 Type: User Record:
Before destroy
Current User:
User Tax: Loc: - Orgs:
Host: #<Host::Managed id: 109, name: "b088d54f.com", last_compile: nil, last_report: "2017-06-22 17:45:38", updated_at: "2017-06-29 17:10:36", created_at: "2016-12-03 12:55:31", root_pass: "...", architecture_id: 1, operatingsystem_id: 3, environment_id: 2, ptable_id: 92, medium_id: 9, build: false, comment: "", disk: "", installed_at: nil, model_id: 1, hostgroup_id: 1, owner_id: 3, owner_type: "User", enabled: true, puppet_ca_proxy_id: 8, managed: true, use_image: nil, image_file: nil, uuid: "57529ca1", compute_resource_id: 1, puppet_proxy_id: 7, certname: "b088d54f.com", image_id: nil, organization_id: nil, location_id: 6, type: "Host::Managed", otp: nil, realm_id: nil, compute_profile_id: 4, provision_method: nil, grub_pass: "...", global_status: 2, lookup_value_matcher: "fqdn=b088d54f.com", pxe_loader: "PXELinux BIOS", discovery_rule_id: nil, expired_on: "2017-07-20">
Tax: Location: b15b5c62 Organization:
Compute Resource: ID: 1 Record:
Owner: ID: 3 Type: User Record:
After destroy
Current User:
User Tax: Loc: - Orgs:
Host: #<Host::Managed id: 109, name: "b088d54f.com", last_compile: nil, last_report: "2017-06-22 17:45:38", updated_at: "2017-06-29 17:10:36", created_at: "2016-12-03 12:55:31", root_pass: "...", architecture_id: 1, operatingsystem_id: 3, environment_id: 2, ptable_id: 92, medium_id: 9, build: false, comment: "", disk: "", installed_at: nil, model_id: 1, hostgroup_id: 1, owner_id: 3, owner_type: "User", enabled: true, puppet_ca_proxy_id: 8, managed: true, use_image: nil, image_file: nil, uuid: "57529ca1", compute_resource_id: 1, puppet_proxy_id: 7, certname: "b088d54f.com", image_id: nil, organization_id: nil, location_id: 6, type: "Host::Managed", otp: nil, realm_id: nil, compute_profile_id: 4, provision_method: nil, grub_pass: "...", global_status: 2, lookup_value_matcher: "fqdn=b088d54f.com", pxe_loader: "PXELinux BIOS", discovery_rule_id: nil, expired_on: "2017-07-20">
Tax: Location: b15b5c62 Organization:
Compute Resource: ID: 1 Record:
Owner: ID: 3 Type: User Record: @wheeskers : Thanks for providing the data. This helps a lot. In the data you can see, that even before deletion the associations cannot be resolved properly.
I seriously suspect, that this is related to a permissions problem.
Could you try next with this patch applied? This sets the current user to an anonymous admin and should at least rule out any permissions problem.
diff --git a/lib/tasks/expired_hosts.rake b/lib/tasks/expired_hosts.rake
index 7af8092..f822f24 100644
--- a/lib/tasks/expired_hosts.rake
+++ b/lib/tasks/expired_hosts.rake
@@ -2,10 +2,12 @@
namespace :expired_hosts do
desc 'Delete all expired hosts, send notification email about expiring hosts'
task :deliver_notifications => :environment do
- ExpireHostsNotifications.delete_expired_hosts
- ExpireHostsNotifications.stop_expired_hosts
- ExpireHostsNotifications.deliver_expiry_warning_notification(1)
- ExpireHostsNotifications.deliver_expiry_warning_notification(2)
+ User.as_anonymous_admin do
+ ExpireHostsNotifications.delete_expired_hosts
+ ExpireHostsNotifications.stop_expired_hosts
+ ExpireHostsNotifications.deliver_expiry_warning_notification(1)
+ ExpireHostsNotifications.deliver_expiry_warning_notification(2)
+ end
end
end@timogoebel, I've applied this patch to .../foreman_expire_hosts-3.0.0/lib/tasks/expired_hosts.rake, user is now set to Anonymous Admin.
Log output:
rake aborted!
ActiveRecord::RecordNotDestroyed: Failed to destroy the record
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/persistence.rb:185:in `destroy!'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/associations/has_many_association.rb:171:in `each'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/associations/has_many_association.rb:171:in `delete_records'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/associations/collection_association.rb:525:in `remove_records'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/associations/collection_association.rb:518:in `block in delete_or_destroy'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/associations/collection_association.rb:183:in `block in transaction'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:211:in `transaction'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:220:in `transaction'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/associations/collection_association.rb:182:in `transaction'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/associations/collection_association.rb:518:in `delete_or_destroy'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/associations/collection_association.rb:279:in `destroy'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/associations/collection_association.rb:223:in `destroy_all'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/associations/has_many_association.rb:27:in `handle_dependency'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/associations/builder/association.rb:146:in `block in add_destroy_callbacks'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:448:in `instance_exec'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:448:in `block in make_lambda'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:164:in `call'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:164:in `block in halting'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:504:in `call'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:504:in `block in call'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:504:in `each'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:504:in `call'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:92:in `__run_callbacks__'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activesupport-4.2.5.1/lib/active_support/callbacks.rb:778:in `_run_destroy_callbacks'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/callbacks.rb:292:in `destroy'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:281:in `block in destroy'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:351:in `block in with_transaction_returning_status'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `block in transaction'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/transaction.rb:184:in `within_new_transaction'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `transaction'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:220:in `transaction'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:348:in `with_transaction_returning_status'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/transactions.rb:281:in `destroy'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_expire_hosts-3.0.0/lib/expire_hosts_notifications.rb:35:in `block in delete_expired_hosts'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/relation/delegation.rb:46:in `each'
/opt/rh/sclo-ror42/root/usr/share/gems/gems/activerecord-4.2.5.1/lib/active_record/relation/delegation.rb:46:in `each'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_expire_hosts-3.0.0/lib/expire_hosts_notifications.rb:24:in `delete_expired_hosts'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_expire_hosts-3.0.0/lib/tasks/expired_hosts.rake:6:in `block (3 levels) in <top (required)>'
/usr/share/foreman/app/models/concerns/foreman/thread_session.rb:75:in `as'
/usr/share/foreman/app/models/concerns/foreman/thread_session.rb:81:in `as_anonymous_admin'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman_expire_hosts-3.0.0/lib/tasks/expired_hosts.rake:5:in `block (2 levels) in <top (required)>'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:240:in `call'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:240:in `block in execute'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:235:in `each'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:235:in `execute'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:179:in `block in invoke_with_call_chain'
/opt/rh/rh-ruby22/root/usr/share/ruby/monitor.rb:211:in `mon_synchronize'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:172:in `invoke_with_call_chain'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/task.rb:165:in `invoke'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:150:in `invoke_task'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:106:in `block (2 levels) in top_level'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:106:in `each'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:106:in `block in top_level'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:115:in `run_with_threads'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:100:in `top_level'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:78:in `block in run'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:176:in `standard_exception_handling'
/opt/rh/rh-ruby22/root/usr/share/gems/gems/rake-10.4.2/lib/rake/application.rb:75:in `run'
/opt/rh/rh-ruby22/root/usr/bin/rake:33:in `<main>'
Tasks: TOP => expired_hosts:deliver_notifications
Before destroy
Current User: Anonymous Admin
User Tax: Loc: #<Taxonomy::ActiveRecord_Associations_CollectionProxy:0x0000000d5fb4c0> - Orgs: #<Taxonomy::ActiveRecord_Associations_CollectionProxy:0x0000000d7caf58>
Host: #<Host::Managed id: 594, name: "ce27ee5c.com", last_compile: nil, last_report: nil, updated_at: "2017-06-27 10:08:14", created_at: "2017-04-11 09:04:05", root_pass: "...", architecture_id: 1, operatingsystem_id: 4, environment_id: 2, ptable_id: 92, medium_id: 9, build: false, comment: "", disk: "", installed_at: nil, model_id: nil, hostgroup_id: 1, owner_id: 8, owner_type: "Usergroup", enabled: true, puppet_ca_proxy_id: 8, managed: true, use_image: nil, image_file: nil, uuid: "92c2bcac", compute_resource_id: 1, puppet_proxy_id: 7, certname: nil, image_id: nil, organization_id: nil, location_id: 5, type: "Host::Managed", otp: nil, realm_id: nil, compute_profile_id: 4, provision_method: "build", grub_pass: "...", global_status: 0, lookup_value_matcher: "fqdn=ce27ee5c.com", pxe_loader: "PXELinux BIOS", discovery_rule_id: nil, expired_on: "2017-07-10">
Tax: Location: d5f06d5f Organization:
Compute Resource: ID: 1 Record: vSphere (VMware)
Owner: ID: 8 Type: Usergroup Record: a92ca1b0@wheeskers: We're getting somewhere. The associations are now resolved properly. I'll open a PR with a fix for the permissions soon. I'll look into the other error soon and let you know what we can do about that. I might ask you to add more debug code for this. Have you already checked if Foreman's production log reveals anything out of the ordinary? Thanks.
wheeskers
commented
7 years ago @timogoebel,
I might ask you to add more debug code for this.
No problem, I'll try to add it ASAP when I'm at the office.
Have you already checked if Foreman's production log reveals anything out of the ordinary?
I did some basic review of existing logs. Do you have any ideas what to look for? May be there is something specific that I am missing out.
timogoebel
commented
7 years ago @wheeskers: Can you delete the host manually via the UI? This error should only occur when the host cannot be deleted properly. One reason for this could be that for example a DNS record could not be deleted on the smart-proxy. You should check the logs for that.
However, this plugin should still continue to delete other hosts and not stop at the first failure. This should prevent this from happening:
diff --git a/lib/expire_hosts_notifications.rb b/lib/expire_hosts_notifications.rb
index 233294e..91d8745 100644
--- a/lib/expire_hosts_notifications.rb
+++ b/lib/expire_hosts_notifications.rb
@@ -23,7 +23,7 @@ module ExpireHostsNotifications
deletable_hosts.each do |deletable_host|
Rails.logger.info "Deleting expired host #{deletable_host}"
deletable_host.audit_comment = _('Destroyed since it got expired on %s') % deletable_host.expired_on
- if deletable_host.destroy
+ if safe_destroy(deletable_host)
deleted_hosts << deletable_host
else
failed_delete_hosts << deletable_host
@@ -115,5 +115,17 @@ module ExpireHostsNotifications
end
hosts_hash
end
+
+ def safe_destroy(host)
+ host.destroy!
+ rescue ActiveRecord::RecordNotDestroyed => invalid
+ message = _("Failed to delete Host %{host}: %{message} - Errors: %{errors}") % {
+ :host => host,
+ :message => invalid.message,
+ :errors => invalid.record.errors.full_messages.to_sentence
+ }
+ Foreman::Logging.exception(message, invalid)
+ false
+ end
end
end@timogoebel,
Can you delete the host manually via the UI? This error should only occur when the host cannot be deleted properly. One reason for this could be that for example a DNS record could not be deleted on the smart-proxy.
Errors regarding one of our smart-proxies are not very common because majority of hosts are located in "normal" environment. This specific proxy is located in "nonstandard" environment and may be problematic. We are planning to remove it or migrate it to different platform/environment.
However, this plugin should still continue to delete other hosts and not stop at the first failure. This should prevent this from happening: <...>
Thank you! I'll add this code soon and report back results.
wheeskers
commented
7 years ago @timogoebel, sorry for the delayed reply.
I've tested this on small group of expired hosts today and it worked. Thanks! I'll run this on bigger group of hosts this week and reply back results.
Will this hotfix skip all/any other hosts with "bad" permissions (i.e. insufficient vSphere account permissions)?
timogoebel
commented
7 years ago Will this hotfix skip all/any other hosts with "bad" permissions (i.e. insufficient vSphere account permissions)?
Yes. That's the aim. I'll close this for now. Thanks for your reply. The next plugin release will contain all the fixes and UI notifications.
vladimirsafronov1251
commented
7 years ago The next plugin release will contain all the fixes and UI notifications.
Thanks @timogoebel, I can confirm that at least notifications are working with your fix. We are waiting for grace period ending for test hosts to ensure that hosts will be really deleted. This plugin was the real relief and allowed us to start managing lifecycle of VMs in our environment. Hovewer, I'm going to open one more bug and one feature request regarding notifications. I'll mention this ticket there.
timogoebel
commented
7 years ago @vladimirsafronov1251: Sure, go ahead and let me know if you need anything. Happy to help.
wheeskers
commented
7 years ago Hi @timogoebel, It seems that problem is fixed for common hosts (no vSphere permission problems, etc).
Can you please clarify:
expire hosts plugin is released?expire hosts plugin is expected to include this fix out of the box?Thanks!
timogoebel
commented
7 years ago @wheeskers: Updates to Foreman core in the 1.15 branch should have no impact to the hotfix. We are currently preparing Foreman 1.16 for release. I will release a new version of this plugin (probably 4.0.0) that will require 1.16 with all the fixes and features we discussed. Sorry for not backporting this to 1.15, I didn't have the time.
wheeskers
commented
7 years ago @timogoebel, thanks again for the detailed reply and your help.
Hi TFM team,
We have an issue with
foreman_expire_hostsplugin: hosts' owners no longer receive notifications about host expiration and entering grace period.I'll try to provide as many details as I can but I must say that I am not very familiar with Rails framework so please excuse me if my understanding of the situation isn't complete. I was not involved in this TFM configuration but I will try to contact any person who may have any useful information if needed.
Versions:
1.15.2;foreman_expire_hostsplugin –3.0.0.Running
rakecommand:Produces the same error as in system logs (see below).
Please share any ideas if there's a way to fix this without major downtime or TFM instance reinstalling. If this is not a bug but configuration/installation flaw -- comments on what is wrong would be great.
Thanks!
Log lines from
/var/log/foreman/expired_hosts.logfile: