Hammer host delete timed out

Ale · September 3, 2018, 9:51am

Problem:
when running hammer host delete --name HOST I get:

hammer host delete --name HOST
Could not delete the host:
  Error: Timed out reading data from server

Checking /var/log/foreman/production.log I see:

2018-09-03T18:25:57 [I|app|cfb95] Delete DHCP reservation HOST for HOST-52:54:00:66:6e:07/IP
2018-09-03T18:25:57 [I|app|cfb95] Processed 2 tasks from queue 'Host::Managed Main', completed 2/2
2018-09-03T18:25:58 [I|aud|cfb95] destroy event for Host::Base with id 92
2018-09-03T18:25:58 [I|app|cfb95] Remove puppet certificate for HOST
2018-09-03T18:26:00 [I|app|cfb95] Delete realm entry for HOST
2018-09-03T18:26:01 [I|app|cfb95] Delete the autosign entry for HOST
2018-09-03T18:26:01 [I|app|cfb95] Removing Compute instance for HOST
2018-09-03T18:27:47 [I|app|] Started DELETE "/api/hosts/92" for HAMMER_IP at 2018-09-03 18:27:47 +0900
2018-09-03T18:27:47 [I|app|44639] Processing by Api::V2::HostsController#destroy as JSON
2018-09-03T18:27:47 [I|app|44639]   Parameters: {"apiv"=>"v2", "id"=>"92", "host"=>{}}
2018-09-03T18:27:47 [I|app|44639] Current user: foreman_admin (administrator)
2018-09-03T18:27:47 [I|app|44639] Authorized user admin(Admin User)
2018-09-03T18:27:47 [I|app|44639] Current user: admin (administrator)
2018-09-03T18:27:48 [I|aud|44639] destroy event for Nic::Managed with id 94

and it just stays there. The only way to make it run is by restarting httpd

Expected outcome:

vm should be deleted

Foreman and Proxy versions:
foreman 1.18.1
katello 3.7.0
libvirt
realm

Foreman and Proxy plugin versions:

Other relevant data:
[e.g. logs from Foreman and/or the Proxy, modified templates, commands issued, etc]

lzap · September 3, 2018, 4:45pm

Hello, if you get a timeout there should be a stacktrace in production.log. You need to figure out what actually times out - is that libvirt connection? Or is that DHCP proxy module?

Ale · September 4, 2018, 2:24am

Hi @lzap

you are right, there were more logs:

Here is before restart httpd:

2018-09-04T11:03:19 [I|app|] Started GET "/api/hosts?search=name+%3D+%22HOSTNAME.DOMAIN%22" for IP_FOREMAN at 2018-09-04 11:03:19 +0900
2018-09-04T11:03:19 [I|app|eb676] Processing by Api::V2::HostsController#index as JSON
2018-09-04T11:03:19 [I|app|eb676]   Parameters: {"search"=>"name = \"HOSTNAME.DOMAIN\"", "apiv"=>"v2", "host"=>{}}
2018-09-04T11:03:19 [I|app|eb676] Current user: foreman_admin (administrator)
2018-09-04T11:03:19 [I|app|eb676] Authorized user admin(Admin User)
2018-09-04T11:03:19 [I|app|eb676] Current user: admin (administrator)
2018-09-04T11:03:20 [I|app|eb676]   Rendering api/v2/hosts/index.json.rabl within api/v2/layouts/index_layout
2018-09-04T11:03:20 [I|app|eb676]   Rendered api/v2/hosts/index.json.rabl within api/v2/layouts/index_layout (71.8ms)
2018-09-04T11:03:20 [I|app|eb676] Completed 200 OK in 257ms (Views: 77.0ms | ActiveRecord: 39.6ms)
2018-09-04T11:03:20 [I|app|] Started DELETE "/api/hosts/103" for IP_FOREMAN at 2018-09-04 11:03:20 +0900
2018-09-04T11:03:20 [I|app|1ce72] Processing by Api::V2::HostsController#destroy as JSON
2018-09-04T11:03:20 [I|app|1ce72]   Parameters: {"apiv"=>"v2", "id"=>"103", "host"=>{}}
2018-09-04T11:03:20 [I|app|1ce72] Current user: foreman_admin (administrator)
2018-09-04T11:03:20 [I|app|1ce72] Authorized user admin(Admin User)
2018-09-04T11:03:20 [I|app|1ce72] Current user: admin (administrator)
2018-09-04T11:03:20 [I|kat|1ce72] DELETE: https://FOREMAN.DOMAIN/pulp/api/v2/consumers/9417b8e2-02ce-47d0-aac4-ad85c04d9959/: {"content_type"=>"application/json", "accept"=>"application/json"}
Response: 200: null
2018-09-04T11:03:20 [I|aud|1ce72] destroy event for Host::Base with id 84
2018-09-04T11:03:20 [I|aud|1ce72] destroy event for Host::Base with id 101
2018-09-04T11:03:20 [I|aud|1ce72] destroy event for Nic::Managed with id 105
2018-09-04T11:03:20 [I|app|1ce72] Delete the DNS PTR record for IP_VM/HOSTNAME.DOMAIN
2018-09-03T20:58:48 [I|kat|] POST: https://FOREMAN.DOMAIN/pulp/api/v2/consumers/9417b8e2-02ce-47d0-aac4-ad85c04d9959/actions/content/regenerate_applicability/: {}: {"content_type"=>"application/json", "accept"=>"application/json"}
Response: 202: {"spawned_tasks": [{"_href": "/pulp/api/v2/tasks/1a2d19e9-1005-4048-afb1-56af80b5ff6f/", "task_id": "1a2d19e9-1005-4048-afb1-56af80b5ff6f"}], "result": null, "error": null}
2018-09-03T20:58:48 [I|kat|] GET: https://FOREMAN.DOMAIN/pulp/api/v2/tasks/1a2d19e9-1005-4048-afb1-56af80b5ff6f/: {"content_type"=>"application/json", "accept"=>"application/json"}
Response: 200: {"exception": null, "task_type": "pulp.server.managers.consumer.applicability.regenerate_applicability_for_consumers", "_href": "/pulp/api/v2/tasks/1a2d19e9-1005-4048-afb1-56af80b5ff6f/", "task_id": "1a2d19e9-1005-4048-afb1-56af80b5ff6f", "tags": ["pulp:action:consumer_content_applicability_regeneration"], "finish_time": null, "_ns": "task_status", "start_time": null, "traceback": null, "spawned_tasks": [], "progress_report": {}, "queue": "", "state": "waiting", "worker_name": null, "result": null, "error": null, "_id": {"$oid": "5b8d21f8a0719b8099dd05f5"}, "id": "5b8d21f8a0719b8099dd05f5"}
2018-09-03T20:58:48 [I|kat|] GET: https://FOREMAN.DOMAIN/pulp/api/v2/tasks/1a2d19e9-1005-4048-afb1-56af80b5ff6f/: {"content_type"=>"application/json", "accept"=>"application/json"}
Response: 200: {"exception": null, "task_type": "pulp.server.managers.consumer.applicability.regenerate_applicability_for_consumers", "_href": "/pulp/api/v2/tasks/1a2d19e9-1005-4048-afb1-56af80b5ff6f/", "task_id": "1a2d19e9-1005-4048-afb1-56af80b5ff6f", "tags": ["pulp:action:consumer_content_applicability_regeneration"], "finish_time": "2018-09-03T11:58:48Z", "_ns": "task_status", "start_time": "2018-09-03T11:58:48Z", "traceback": null, "spawned_tasks": [], "progress_report": {}, "queue": "reserved_resource_worker-2@FOREMAN.DOMAIN.dq2", "state": "finished", "worker_name": "reserved_resource_worker-2@FOREMAN.DOMAIN", "result": null, "error": null, "_id": {"$oid": "5b8d21f8a0719b8099dd05f5"}, "id": "5b8d21f8a0719b8099dd05f5"}
2018-09-03T20:58:48 [I|app|] Current user: foreman_admin (administrator)
2018-09-03T20:58:50 [I|app|] Current user: foreman_admin (administrator)
2018-09-03T20:58:50 [I|kat|] POST: https://FOREMAN.DOMAIN/pulp/api/v2/consumers/content/applicability/: {"criteria":{"filters":{"id":{"$in":["9417b8e2-02ce-47d0-aac4-ad85c04d9959"]}}},"content_types":["erratum"]}: {"content_type"=>"application/json", "accept"=>"application/json"}
Response: 200: []
2018-09-03T20:58:50 [I|kat|] POST: https://FOREMAN.DOMAIN/pulp/api/v2/consumers/content/applicability/: {"criteria":{"filters":{"id":{"$in":["9417b8e2-02ce-47d0-aac4-ad85c04d9959"]}}},"content_types":["rpm"]}: {"content_type"=>"application/json", "accept"=>"application/json"}
Response: 200: []
2018-09-03T21:43:13 [I|app|] Current user: foreman_admin (administrator)
2018-09-03T23:17:42 [I|app|] Current user: foreman_admin (administrator)
2018-09-03T23:49:28 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T06:19:50 [I|app|] Performing CreatePulpDiskSpaceNotifications (Job ID: fe24c3e6-1126-484b-bdc2-4c591249e9ed) from Dynflow(default)
2018-09-04T06:19:50 [I|app|] Performing SendExpireSoonNotifications (Job ID: d1b1267d-ef3d-4767-a1b4-a183eba467ad) from Dynflow(default)
2018-09-04T06:19:50 [I|app|] Enqueued SendExpireSoonNotifications (Job ID: 0e5412ed-bca9-4c29-924a-b08529cebe90) to Dynflow(default) at 2018-09-04 09:19:50 UTC
2018-09-04T06:19:50 [I|app|] Performed SendExpireSoonNotifications (Job ID: d1b1267d-ef3d-4767-a1b4-a183eba467ad) from Dynflow(default) in 108.63ms
2018-09-04T06:19:50 [I|app|] Enqueued CreatePulpDiskSpaceNotifications (Job ID: c0c72a77-7ec0-41d8-a3c5-b77b75bc5a4a) to Dynflow(default) at 2018-09-04 09:19:50 UTC
2018-09-04T06:19:50 [I|app|] Performed CreatePulpDiskSpaceNotifications (Job ID: fe24c3e6-1126-484b-bdc2-4c591249e9ed) from Dynflow(default) in 244.77ms
2018-09-04T06:22:52 [I|app|] Performing CreateRssNotifications (Job ID: df30495c-dda5-4af4-90a6-1f44973e5d24) from Dynflow(default)
2018-09-04T06:23:03 [I|app|] Enqueued CreateRssNotifications (Job ID: 6220bc11-2c5b-4316-9848-4f3da9c307c9) to Dynflow(default) at 2018-09-04 09:23:03 UTC
2018-09-04T06:23:03 [I|app|] Performed CreateRssNotifications (Job ID: df30495c-dda5-4af4-90a6-1f44973e5d24) from Dynflow(default) in 10726.67ms
2018-09-04T11:03:21 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T11:03:21 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T11:03:22 [E|dyn|] PG::UndefinedColumn: ERROR:  column katello_subscriptions.product_id does not exist
LINE 1: ...katello_subscriptions"."organization_id" = $1 AND "katello_s...
                                                             ^
: SELECT  "katello_subscriptions".* FROM "katello_subscriptions" WHERE "katello_subscriptions"."organization_id" = $1 AND "katello_subscriptions"."product_id" = $2 LIMIT $3
2018-09-04T11:03:22 [E|dyn|] /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/postgresql_adapter.rb:616:in `async_exec'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/postgresql_adapter.rb:616:in `block (2 levels) in exec_no_cache'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/dependencies/interlock.rb:46:in `block in permit_concurrent_loads'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/concurrency/share_lock.rb:185:in `yield_shares'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/dependencies/interlock.rb:45:in `permit_concurrent_loads'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/postgresql_adapter.rb:615:in `block in exec_no_cache'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract_adapter.rb:613:in `block (2 levels) in log'
/opt/rh/rh-ruby24/root/usr/share/ruby/monitor.rb:214:in `mon_synchronize'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract_adapter.rb:612:in `block in log'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/notifications/instrumenter.rb:21:in `instrument'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract_adapter.rb:604:in `log'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/postgresql_adapter.rb:614:in `exec_no_cache'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/postgresql_adapter.rb:603:in `execute_and_clear'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/postgresql/database_statements.rb:79:in `exec_query'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/database_statements.rb:371:in `select'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/database_statements.rb:42:in `select_all'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/query_cache.rb:95:in `block in select_all'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/query_cache.rb:118:in `block in cache_sql'
/opt/rh/rh-ruby24/root/usr/share/ruby/monitor.rb:214:in `mon_synchronize'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/query_cache.rb:104:in `cache_sql'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/query_cache.rb:95:in `select_all'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/querying.rb:39:in `find_by_sql'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/relation.rb:678:in `exec_queries'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/relation.rb:546:in `load'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/relation.rb:255:in `records'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/relation/finder_methods.rb:508:in `find_take'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/relation/finder_methods.rb:100:in `take'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/relation/finder_methods.rb:78:in `find_by'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/querying.rb:7:in `find_by'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/core.rb:208:in `find_by'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/models/katello/glue/candlepin/pool.rb:85:in `stacking_subscription'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/models/katello/glue/candlepin/pool.rb:104:in `import_data'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/core_ext/object/try.rb:17:in `public_send'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/core_ext/object/try.rb:17:in `try!'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/core_ext/object/try.rb:6:in `try'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/models/katello/events/import_pool.rb:11:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/katello/event_queue/monitor.rb:111:in `block in act_on_event'
/usr/share/foreman/app/models/concerns/foreman/thread_session.rb:94:in `as'
/usr/share/foreman/app/models/concerns/foreman/thread_session.rb:100:in `as_anonymous_admin'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/katello/event_queue/monitor.rb:109:in `act_on_event'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/katello/event_queue/monitor.rb:44:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:74:in `block in assigns'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:73:in `tap'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:73:in `assigns'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:56:in `match_value'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:36:in `block in match?'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:35:in `each'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:35:in `match?'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:23:in `match'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/katello/event_queue/monitor.rb:36:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:538:in `block (3 levels) in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/common/singleton.rb:15:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.13.4/app/lib/actions/middleware/rails_executor_wrap.rb:14:in `block in run'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/execution_wrapper.rb:85:in `wrap'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.13.4/app/lib/actions/middleware/rails_executor_wrap.rb:13:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action/progress.rb:30:in `with_progress_calculation'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action/progress.rb:16:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/middleware/keep_locale.rb:11:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/middleware/keep_locale.rb:22:in `with_locale'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/middleware/keep_locale.rb:11:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.13.4/app/lib/actions/middleware/keep_current_user.rb:15:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.13.4/app/lib/actions/middleware/keep_current_user.rb:43:in `restore_curent_user'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.13.4/app/lib/actions/middleware/keep_current_user.rb:15:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware.rb:31:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/world.rb:30:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:537:in `block (2 levels) in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:536:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:536:in `block in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:451:in `block in with_error_handling'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:451:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:451:in `with_error_handling'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:531:in `execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:278:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:17:in `block (2 levels) in execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/execution_plan/steps/abstract.rb:162:in `with_meta_calculation'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:16:in `block in execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:30:in `open_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:15:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/director.rb:56:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/executors/parallel/worker.rb:12:in `block in on_message'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/executors.rb:12:in `run_user_code'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/executors/parallel/worker.rb:11:in `on_message'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/context.rb:46:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/executes_context.rb:7:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/actor.rb:26:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/awaits.rb:15:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/buffer.rb:38:in `process_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/buffer.rb:31:in `process_envelopes?'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/buffer.rb:20:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/termination.rb:55:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/removes_child.rb:10:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/core.rb:161:in `process_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/core.rb:95:in `block in on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/core.rb:118:in `block (2 levels) in schedule_execution'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `block in synchronize'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `synchronize'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/core.rb:115:in `block in schedule_execution'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/serialized_execution.rb:18:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/serialized_execution.rb:96:in `work'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/serialized_execution.rb:77:in `block in call_job'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:348:in `run_task'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:337:in `block (3 levels) in create_worker'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in `loop'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in `block (2 levels) in create_worker'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in `catch'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in `block in create_worker'
/opt/theforeman/tfm/root/usr/share/gems/gems/logging-2.2.2/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
2018-09-04T11:03:35 [I|app|1ce72] Delete DHCP reservation HOSTNAME.DOMAIN for HOSTNAME.DOMAIN-52:54:00:13:44:a0/IP_VM
2018-09-04T11:03:36 [I|app|1ce72] Processed 2 tasks from queue 'Host::Managed Main', completed 2/2
2018-09-04T11:03:36 [I|aud|1ce72] destroy event for Host::Base with id 103
2018-09-04T11:03:36 [I|app|1ce72] Remove puppet certificate for HOSTNAME.DOMAIN
2018-09-04T11:03:38 [I|app|1ce72] Delete realm entry for HOSTNAME.DOMAIN
2018-09-04T11:03:39 [I|app|1ce72] Delete the autosign entry for HOSTNAME.DOMAIN
2018-09-04T11:03:39 [I|app|1ce72] Removing Compute instance for HOSTNAME.DOMAIN
2018-09-04T11:05:21 [I|app|] Started DELETE "/api/hosts/103" for IP_FOREMAN at 2018-09-04 11:05:21 +0900
2018-09-04T11:05:21 [I|app|c4bb7] Processing by Api::V2::HostsController#destroy as JSON
2018-09-04T11:05:21 [I|app|c4bb7]   Parameters: {"apiv"=>"v2", "id"=>"103", "host"=>{}}
2018-09-04T11:05:21 [I|app|c4bb7] Current user: foreman_admin (administrator)
2018-09-04T11:05:21 [I|app|c4bb7] Authorized user admin(Admin User)
2018-09-04T11:05:21 [I|app|c4bb7] Current user: admin (administrator)
2018-09-04T11:05:22 [I|aud|c4bb7] destroy event for Nic::Managed with id 105
2018-09-04T11:06:37 [I|app|] Started GET "/node/FOREMAN.DOMAIN?format=yml" for IP_FOREMAN at 2018-09-04 11:06:37 +0900
2018-09-04T11:06:37 [I|app|b7edf] Processing by HostsController#externalNodes as YML
2018-09-04T11:06:37 [I|app|b7edf]   Parameters: {"name"=>"FOREMAN.DOMAIN"}
2018-09-04T11:06:37 [I|app|b7edf] Current user: foreman_api_admin (administrator)
2018-09-04T11:06:38 [I|app|b7edf]   Rendering text template
2018-09-04T11:06:38 [I|app|b7edf]   Rendered text template (0.0ms)
2018-09-04T11:06:38 [I|app|b7edf] Completed 200 OK in 1524ms (Views: 4.8ms | ActiveRecord: 255.8ms)
2018-09-04T11:06:40 [I|app|] Started POST "/api/hosts/facts" for IP_FOREMAN at 2018-09-04 11:06:40 +0900
2018-09-04T11:06:40 [I|app|19605] Processing by Api::V2::HostsController#facts as JSON
2018-09-04T11:06:40 [I|app|19605]   Parameters: {"facts"=>"[FILTERED]", "name"=>"FOREMAN.DOMAIN", "certname"=>"FOREMAN.DOMAIN", "apiv"=>"v2", "host"=>{"certname"=>"FOREMAN.DOMAIN", "name"=>"FOREMAN.DOMAIN"}}
2018-09-04T11:06:40 [I|app|19605] Current user: foreman_api_admin (administrator)
2018-09-04T11:06:41 [I|app|19605] Import facts for 'FOREMAN.DOMAIN' completed. Added: 11, Updated: 24, Deleted 0 facts
2018-09-04T11:06:41 [I|app|19605] Completed 201 Created in 1551ms (Views: 11.2ms | ActiveRecord: 317.2ms)
2018-09-04T11:06:44 [I|app|] Started GET "/node/FOREMAN.DOMAIN?format=yml" for IP_FOREMAN at 2018-09-04 11:06:44 +0900
2018-09-04T11:06:44 [I|app|c71de] Processing by HostsController#externalNodes as YML
2018-09-04T11:06:44 [I|app|c71de]   Parameters: {"name"=>"FOREMAN.DOMAIN"}
2018-09-04T11:06:44 [I|app|c71de] Current user: foreman_api_admin (administrator)
2018-09-04T11:06:44 [I|app|c71de]   Rendering text template
2018-09-04T11:06:44 [I|app|c71de]   Rendered text template (0.0ms)
2018-09-04T11:06:44 [I|app|c71de] Completed 200 OK in 203ms (Views: 0.8ms | ActiveRecord: 26.6ms)
2018-09-04T11:06:45 [I|app|] Started POST "/api/config_reports" for IP_FOREMAN at 2018-09-04 11:06:45 +0900
2018-09-04T11:06:45 [I|app|048f6] Processing by Api::V2::ConfigReportsController#create as JSON
2018-09-04T11:06:45 [I|app|048f6]   Parameters: {"config_report"=>"[FILTERED]", "apiv"=>"v2"}
2018-09-04T11:06:45 [I|app|048f6] Current user: foreman_api_admin (administrator)
2018-09-04T11:06:45 [I|app|048f6] Scanning report with: Foreman::PuppetReportScanner
2018-09-04T11:06:45 [I|app|048f6] Imported report for FOREMAN.DOMAIN in 0.17 seconds, status refreshed in 0.12 seconds
2018-09-04T11:06:45 [I|app|048f6]   Rendering api/v2/config_reports/create.json.rabl
2018-09-04T11:06:45 [I|app|048f6]   Rendered api/v2/config_reports/create.json.rabl (21.0ms)
2018-09-04T11:06:45 [I|app|048f6] Completed 201 Created in 357ms (Views: 43.8ms | ActiveRecord: 78.2ms)

and after I restart httpd:

2018-09-04T11:11:57 [I|app|] Started GET "/api/hosts?search=name+%3D+%22HOSTNAME.DOMAIN%22" for IP_FOREMAN at 2018-09-04 11:11:57 +0900
2018-09-04T11:11:57 [I|app|2b5d6] Processing by Api::V2::HostsController#index as JSON
2018-09-04T11:11:57 [I|app|2b5d6]   Parameters: {"search"=>"name = \"HOSTNAME.DOMAIN\"", "apiv"=>"v2", "host"=>{}}
2018-09-04T11:11:57 [I|app|2b5d6] Current user: foreman_admin (administrator)
2018-09-04T11:11:57 [I|app|2b5d6] Authorized user admin(Admin User)
2018-09-04T11:11:57 [I|app|2b5d6] Current user: admin (administrator)
2018-09-04T11:11:58 [I|app|2b5d6]   Rendering api/v2/hosts/index.json.rabl within api/v2/layouts/index_layout
2018-09-04T11:11:59 [I|app|2b5d6]   Rendered api/v2/hosts/index.json.rabl within api/v2/layouts/index_layout (239.1ms)
2018-09-04T11:11:59 [I|app|2b5d6] Completed 200 OK in 1197ms (Views: 228.8ms | ActiveRecord: 185.3ms)
2018-09-04T11:12:01 [I|app|] Started DELETE "/api/hosts/103" for IP_FOREMAN at 2018-09-04 11:12:01 +0900
2018-09-04T11:12:01 [I|app|89759] Processing by Api::V2::HostsController#destroy as JSON
2018-09-04T11:12:01 [I|app|89759]   Parameters: {"apiv"=>"v2", "id"=>"103", "host"=>{}}
2018-09-04T11:12:01 [I|app|89759] Current user: foreman_admin (administrator)
2018-09-04T11:12:01 [I|app|89759] Authorized user admin(Admin User)
2018-09-04T11:12:01 [I|app|89759] Current user: admin (administrator)
2018-09-04T11:12:01 [I|aud|89759] destroy event for Nic::Managed with id 105
2018-09-04T11:12:01 [I|app|89759] Delete the DNS PTR record for IP_VM/HOSTNAME.DOMAIN
2018-09-04T11:12:09 [I|app|89759] Delete DHCP reservation HOSTNAME.DOMAIN for HOSTNAME.DOMAIN-52:54:00:13:44:a0/IP_VM
2018-09-04T11:12:09 [I|app|89759] Processed 2 tasks from queue 'Host::Managed Main', completed 2/2
2018-09-04T11:12:09 [I|aud|89759] destroy event for Host::Base with id 103
2018-09-04T11:12:10 [I|app|89759] Remove puppet certificate for HOSTNAME.DOMAIN
2018-09-04T11:12:12 [I|app|89759] Delete realm entry for HOSTNAME.DOMAIN
2018-09-04T11:12:12 [I|app|89759] Delete the autosign entry for HOSTNAME.DOMAIN
2018-09-04T11:12:12 [I|app|89759] Removing Compute instance for HOSTNAME.DOMAIN
2018-09-04T11:12:14 [I|app|89759] Processed 4 tasks from queue 'Host::Managed Main', completed 6/6
2018-09-04T11:12:14 [I|app|89759] Completed 200 OK in 13065ms (Views: 18.0ms | ActiveRecord: 131.2ms)

probably the relevant part is:

2018-09-04T11:03:22 [E|dyn|] PG::UndefinedColumn: ERROR:  column katello_subscriptions.product_id does not exist
LINE 1: ...katello_subscriptions"."organization_id" = $1 AND "katello_s...
                                                             ^
: SELECT  "katello_subscriptions".* FROM "katello_subscriptions" WHERE "katello_subscriptions"."organization_id" = $1 AND "katello_subscriptions"."product_id" = $2 LIMIT $3

About libvirt yes, we are using it.

About katello subscriptions I remember that I’ve uploaded the manifest and an error popped up:

Import Manifest organization

Validation failed: Environments expecting environments used by hosts or inherited (check mismatches report)., Domains expecting domains used by hosts or inherited (check mismatches report)., Smart proxies expecting smart proxies used by hosts or inherited (check mismatches report).

This error did not popped up with foreman 1.17 and ignored since I can download rhel repos anyway.

Thanks for the help,

Alex

Ale · September 4, 2018, 2:43am

more logs,

this time even with error it did delete the vm so katello pg error is not related:

2018-09-04T11:36:36 [I|app|] Started GET "/node/FOREMAN.DOMAIN?format=yml" for FOREMAN_IP at 2018-09-04 11:36:36 +0900
2018-09-04T11:36:36 [I|app|323cf] Processing by HostsController#externalNodes as YML
2018-09-04T11:36:36 [I|app|323cf]   Parameters: {"name"=>"FOREMAN.DOMAIN"}
2018-09-04T11:36:36 [I|app|323cf] Current user: foreman_api_admin (administrator)
2018-09-04T11:36:36 [I|app|323cf]   Rendering text template
2018-09-04T11:36:36 [I|app|323cf]   Rendered text template (0.1ms)
2018-09-04T11:36:36 [I|app|323cf] Completed 200 OK in 328ms (Views: 1.7ms | ActiveRecord: 38.2ms)
2018-09-04T11:36:37 [I|app|] Started POST "/api/hosts/facts" for FOREMAN_IP at 2018-09-04 11:36:37 +0900
2018-09-04T11:36:37 [I|app|ffa3a] Processing by Api::V2::HostsController#facts as JSON
2018-09-04T11:36:37 [I|app|ffa3a]   Parameters: {"facts"=>"[FILTERED]", "name"=>"FOREMAN.DOMAIN", "certname"=>"FOREMAN.DOMAIN", "apiv"=>"v2", "host"=>{"certname"=>"FOREMAN.DOMAIN", "name"=>"FOREMAN.DOMAIN"}}
2018-09-04T11:36:37 [I|app|ffa3a] Current user: foreman_api_admin (administrator)
2018-09-04T11:36:39 [I|app|ffa3a] Import facts for 'FOREMAN.DOMAIN' completed. Added: 0, Updated: 19, Deleted 0 facts
2018-09-04T11:36:39 [I|app|ffa3a] Completed 201 Created in 1467ms (Views: 9.8ms | ActiveRecord: 277.0ms)
2018-09-04T11:36:39 [I|app|] Started GET "/node/FOREMAN.DOMAIN?format=yml" for FOREMAN_IP at 2018-09-04 11:36:39 +0900
2018-09-04T11:36:39 [I|app|a15e0] Processing by HostsController#externalNodes as YML
2018-09-04T11:36:39 [I|app|a15e0]   Parameters: {"name"=>"FOREMAN.DOMAIN"}
2018-09-04T11:36:39 [I|app|a15e0] Current user: foreman_api_admin (administrator)
2018-09-04T11:36:39 [I|app|a15e0]   Rendering text template
2018-09-04T11:36:39 [I|app|a15e0]   Rendered text template (0.0ms)
2018-09-04T11:36:39 [I|app|a15e0] Completed 200 OK in 266ms (Views: 1.0ms | ActiveRecord: 33.2ms)
2018-09-04T11:36:40 [I|app|] Started POST "/api/config_reports" for FOREMAN_IP at 2018-09-04 11:36:40 +0900
2018-09-04T11:36:40 [I|app|60715] Processing by Api::V2::ConfigReportsController#create as JSON
2018-09-04T11:36:40 [I|app|60715]   Parameters: {"config_report"=>"[FILTERED]", "apiv"=>"v2"}
2018-09-04T11:36:40 [I|app|60715] Current user: foreman_api_admin (administrator)
2018-09-04T11:36:40 [I|app|60715] Scanning report with: Foreman::PuppetReportScanner
2018-09-04T11:36:40 [I|app|60715] Imported report for FOREMAN.DOMAIN in 0.15 seconds, status refreshed in 0.03 seconds
2018-09-04T11:36:40 [I|app|60715]   Rendering api/v2/config_reports/create.json.rabl
2018-09-04T11:36:40 [I|app|60715]   Rendered api/v2/config_reports/create.json.rabl (15.4ms)
2018-09-04T11:36:40 [I|app|60715] Completed 201 Created in 224ms (Views: 20.6ms | ActiveRecord: 56.2ms)
2018-09-04T11:37:32 [I|app|] Started GET "/api/hosts?search=name+%3D+%22VM_HOSTNAME.DOMAIN%22" for HAMMER_IP at 2018-09-04 11:37:32 +0900
2018-09-04T11:37:32 [I|app|9b1e4] Processing by Api::V2::HostsController#index as JSON
2018-09-04T11:37:32 [I|app|9b1e4]   Parameters: {"search"=>"name = \"VM_HOSTNAME.DOMAIN\"", "apiv"=>"v2", "host"=>{}}
2018-09-04T11:37:32 [I|app|9b1e4] Current user: foreman_admin (administrator)
2018-09-04T11:37:32 [I|app|9b1e4] Authorized user admin(Admin User)
2018-09-04T11:37:32 [I|app|9b1e4] Current user: admin (administrator)
2018-09-04T11:37:32 [I|app|9b1e4]   Rendering api/v2/hosts/index.json.rabl within api/v2/layouts/index_layout
2018-09-04T11:37:32 [I|app|9b1e4]   Rendered api/v2/hosts/index.json.rabl within api/v2/layouts/index_layout (54.1ms)
2018-09-04T11:37:32 [I|app|9b1e4] Completed 200 OK in 185ms (Views: 56.4ms | ActiveRecord: 36.2ms)
2018-09-04T11:37:32 [I|app|] Started DELETE "/api/hosts/106" for HAMMER_IP at 2018-09-04 11:37:32 +0900
2018-09-04T11:37:32 [I|app|c7671] Processing by Api::V2::HostsController#destroy as JSON
2018-09-04T11:37:32 [I|app|c7671]   Parameters: {"apiv"=>"v2", "id"=>"106", "host"=>{}}
2018-09-04T11:37:32 [I|app|c7671] Current user: foreman_admin (administrator)
2018-09-04T11:37:32 [I|app|c7671] Authorized user admin(Admin User)
2018-09-04T11:37:32 [I|app|c7671] Current user: admin (administrator)
2018-09-04T11:37:33 [I|kat|c7671] DELETE: https://FOREMAN.DOMAIN/pulp/api/v2/consumers/a8b46479-8b13-4ad5-bf2d-db3d5218dde2/: {"content_type"=>"application/json", "accept"=>"application/json"}
Response: 200: null
2018-09-04T11:37:33 [I|aud|c7671] destroy event for Host::Base with id 85
2018-09-04T11:37:33 [I|aud|c7671] destroy event for Host::Base with id 104
2018-09-04T11:37:33 [I|aud|c7671] destroy event for Nic::Managed with id 108
2018-09-04T11:37:33 [I|app|c7671] Delete the DNS PTR record for 172.20.210.54/VM_HOSTNAME.DOMAIN
2018-09-04T11:37:34 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T11:37:34 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T11:37:34 [E|dyn|] PG::UndefinedColumn: ERROR:  column katello_subscriptions.product_id does not exist
LINE 1: ...katello_subscriptions"."organization_id" = $1 AND "katello_s...
                                                             ^
: SELECT  "katello_subscriptions".* FROM "katello_subscriptions" WHERE "katello_subscriptions"."organization_id" = $1 AND "katello_subscriptions"."product_id" = $2 LIMIT $3
2018-09-04T11:37:34 [E|dyn|] /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/postgresql_adapter.rb:616:in `async_exec'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/postgresql_adapter.rb:616:in `block (2 levels) in exec_no_cache'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/dependencies/interlock.rb:46:in `block in permit_concurrent_loads'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/concurrency/share_lock.rb:185:in `yield_shares'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/dependencies/interlock.rb:45:in `permit_concurrent_loads'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/postgresql_adapter.rb:615:in `block in exec_no_cache'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract_adapter.rb:613:in `block (2 levels) in log'
/opt/rh/rh-ruby24/root/usr/share/ruby/monitor.rb:214:in `mon_synchronize'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract_adapter.rb:612:in `block in log'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/notifications/instrumenter.rb:21:in `instrument'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract_adapter.rb:604:in `log'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/postgresql_adapter.rb:614:in `exec_no_cache'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/postgresql_adapter.rb:603:in `execute_and_clear'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/postgresql/database_statements.rb:79:in `exec_query'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/database_statements.rb:371:in `select'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/database_statements.rb:42:in `select_all'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/query_cache.rb:95:in `block in select_all'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/query_cache.rb:118:in `block in cache_sql'
/opt/rh/rh-ruby24/root/usr/share/ruby/monitor.rb:214:in `mon_synchronize'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/query_cache.rb:104:in `cache_sql'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/query_cache.rb:95:in `select_all'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/querying.rb:39:in `find_by_sql'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/relation.rb:678:in `exec_queries'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/relation.rb:546:in `load'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/relation.rb:255:in `records'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/relation/finder_methods.rb:508:in `find_take'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/relation/finder_methods.rb:100:in `take'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/relation/finder_methods.rb:78:in `find_by'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/querying.rb:7:in `find_by'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/core.rb:208:in `find_by'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/models/katello/glue/candlepin/pool.rb:85:in `stacking_subscription'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/models/katello/glue/candlepin/pool.rb:104:in `import_data'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/core_ext/object/try.rb:17:in `public_send'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/core_ext/object/try.rb:17:in `try!'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/core_ext/object/try.rb:6:in `try'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/models/katello/events/import_pool.rb:11:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/katello/event_queue/monitor.rb:111:in `block in act_on_event'
/usr/share/foreman/app/models/concerns/foreman/thread_session.rb:94:in `as'
/usr/share/foreman/app/models/concerns/foreman/thread_session.rb:100:in `as_anonymous_admin'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/katello/event_queue/monitor.rb:109:in `act_on_event'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/katello/event_queue/monitor.rb:44:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:74:in `block in assigns'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:73:in `tap'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:73:in `assigns'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:56:in `match_value'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:36:in `block in match?'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:35:in `each'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:35:in `match?'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:23:in `match'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/katello/event_queue/monitor.rb:36:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:538:in `block (3 levels) in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/common/singleton.rb:15:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.13.4/app/lib/actions/middleware/rails_executor_wrap.rb:14:in `block in run'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/execution_wrapper.rb:85:in `wrap'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.13.4/app/lib/actions/middleware/rails_executor_wrap.rb:13:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action/progress.rb:30:in `with_progress_calculation'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action/progress.rb:16:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/middleware/keep_locale.rb:11:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/middleware/keep_locale.rb:22:in `with_locale'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/middleware/keep_locale.rb:11:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.13.4/app/lib/actions/middleware/keep_current_user.rb:15:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.13.4/app/lib/actions/middleware/keep_current_user.rb:43:in `restore_curent_user'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.13.4/app/lib/actions/middleware/keep_current_user.rb:15:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware.rb:31:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/world.rb:30:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:537:in `block (2 levels) in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:536:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:536:in `block in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:451:in `block in with_error_handling'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:451:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:451:in `with_error_handling'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:531:in `execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:278:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:17:in `block (2 levels) in execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/execution_plan/steps/abstract.rb:162:in `with_meta_calculation'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:16:in `block in execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:30:in `open_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:15:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/director.rb:56:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/executors/parallel/worker.rb:12:in `block in on_message'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/executors.rb:12:in `run_user_code'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/executors/parallel/worker.rb:11:in `on_message'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/context.rb:46:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/executes_context.rb:7:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/actor.rb:26:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/awaits.rb:15:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/buffer.rb:38:in `process_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/buffer.rb:31:in `process_envelopes?'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/buffer.rb:20:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/termination.rb:55:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/removes_child.rb:10:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/core.rb:161:in `process_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/core.rb:95:in `block in on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/core.rb:118:in `block (2 levels) in schedule_execution'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `block in synchronize'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `synchronize'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/core.rb:115:in `block in schedule_execution'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/serialized_execution.rb:18:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/serialized_execution.rb:96:in `work'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/serialized_execution.rb:77:in `block in call_job'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:348:in `run_task'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:337:in `block (3 levels) in create_worker'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in `loop'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in `block (2 levels) in create_worker'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in `catch'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in `block in create_worker'
/opt/theforeman/tfm/root/usr/share/gems/gems/logging-2.2.2/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
2018-09-04T11:37:49 [I|app|c7671] Delete DHCP reservation VM_HOSTNAME.DOMAIN for VM_HOSTNAME.DOMAIN-52:54:00:cc:e3:22/172.20.210.54
2018-09-04T11:37:49 [I|app|c7671] Processed 2 tasks from queue 'Host::Managed Main', completed 2/2
2018-09-04T11:37:49 [I|aud|c7671] destroy event for Host::Base with id 106
2018-09-04T11:37:49 [I|app|c7671] Remove puppet certificate for VM_HOSTNAME.DOMAIN
2018-09-04T11:37:52 [I|app|c7671] Delete realm entry for VM_HOSTNAME.DOMAIN
2018-09-04T11:37:52 [I|app|c7671] Delete the autosign entry for VM_HOSTNAME.DOMAIN
2018-09-04T11:37:52 [I|app|c7671] Removing Compute instance for VM_HOSTNAME.DOMAIN
2018-09-04T11:37:53 [I|app|c7671] Processed 4 tasks from queue 'Host::Managed Main', completed 6/6
2018-09-04T11:37:53 [I|app|c7671] Completed 200 OK in 20543ms (Views: 8.7ms | ActiveRecord: 95.8ms)
2018-09-04T11:39:06 [I|app|] Started GET "/rhsm/status/" for 172.20.26.51 at 2018-09-04 11:39:06 +0900
2018-09-04T11:39:06 [I|app|2f10d] Processing by Katello::Api::Rhsm::CandlepinProxiesController#server_status as JSON
2018-09-04T11:39:06 [I|app|2f10d] Completed 200 OK in 47ms (Views: 0.7ms | ActiveRecord: 5.2ms)
2018-09-04T11:39:06 [I|app|] Started GET "/rhsm/status" for 172.20.26.51 at 2018-09-04 11:39:06 +0900
2018-09-04T11:39:06 [I|app|5ec9f] Processing by Katello::Api::Rhsm::CandlepinProxiesController#server_status as JSON
2018-09-04T11:39:06 [I|app|5ec9f] Completed 200 OK in 34ms (Views: 0.5ms | ActiveRecord: 3.4ms)
2018-09-04T11:39:06 [I|app|] Started POST "/rhsm/hypervisors/rnd?reporter_id=[FILTERED]&cloaked=False&env=Library" for 172.20.26.51 at 2018-09-04 11:39:06 +0900
2018-09-04T11:39:06 [I|app|559e1] Processing by Katello::Api::Rhsm::CandlepinProxiesController#async_hypervisors_update as JSON
2018-09-04T11:39:06 [I|app|559e1]   Parameters: {"reporter_id"=>"[FILTERED]", "cloaked"=>"False", "env"=>"Library", "owner"=>"rnd"}
2018-09-04T11:39:06 [I|app|559e1] Current user: foreman_admin (administrator)
2018-09-04T11:39:06 [I|kat|559e1] Authorized user virt_who_reporter_2(virt_who_reporter_2)
2018-09-04T11:39:06 [I|app|559e1] Current user: virt_who_reporter_2 (regular user)
2018-09-04T11:39:06 [I|app|559e1] Current user: foreman_admin (administrator)
2018-09-04T11:39:07 [I|app|559e1] Current user: virt_who_reporter_2 (regular user)
2018-09-04T11:39:07 [I|app|559e1] Completed 200 OK in 334ms (Views: 0.6ms | ActiveRecord: 38.5ms)
2018-09-04T11:39:22 [I|app|] Started GET "/rhsm/status/" for 172.20.26.51 at 2018-09-04 11:39:22 +0900
2018-09-04T11:39:22 [I|app|5d0e3] Processing by Katello::Api::Rhsm::CandlepinProxiesController#server_status as JSON
2018-09-04T11:39:22 [I|app|5d0e3] Completed 200 OK in 48ms (Views: 0.6ms | ActiveRecord: 5.6ms)
2018-09-04T11:39:22 [I|app|] Started GET "/rhsm/jobs/hypervisor_update_51f811ea-2eee-40e9-aa6e-b7ffa49e0a9e?result_data=True" for 172.20.26.51 at 2018-09-04 11:39:22 +0900
2018-09-04T11:39:22 [I|app|19d3d] Processing by Katello::Api::Rhsm::CandlepinProxiesController#get as JSON
2018-09-04T11:39:22 [I|app|19d3d]   Parameters: {"result_data"=>"True", "jobId"=>"hypervisor_update_51f811ea-2eee-40e9-aa6e-b7ffa49e0a9e"}
2018-09-04T11:39:22 [I|app|19d3d] Current user: foreman_admin (administrator)
2018-09-04T11:39:22 [I|kat|19d3d] Authorized user virt_who_reporter_2(virt_who_reporter_2)
2018-09-04T11:39:22 [I|app|19d3d] Current user: virt_who_reporter_2 (regular user)
2018-09-04T11:39:22 [I|app|19d3d] Completed 200 OK in 109ms (Views: 0.3ms | ActiveRecord: 19.1ms)

Ale · September 4, 2018, 4:58am

sorry for the spam-log

it seems that the problem is with libvirt:

2018-09-04T13:19:21 [I|app|] Started GET "/api/hosts?search=name+%3D+%22VM_HOSTNAME.DOMAIN%22" for HAMMER_IP at 2018-09-04 13:19:21 +0900
2018-09-04T13:19:22 [I|app|8551b] Processing by Api::V2::HostsController#index as JSON
2018-09-04T13:19:22 [I|app|8551b]   Parameters: {"search"=>"name = \"VM_HOSTNAME.DOMAIN\"", "apiv"=>"v2", "host"=>{}}
2018-09-04T13:19:22 [I|app|8551b] Current user: foreman_admin (administrator)
2018-09-04T13:19:22 [I|app|8551b] Authorized user admin(Admin User)
2018-09-04T13:19:22 [I|app|8551b] Current user: admin (administrator)
2018-09-04T13:19:22 [I|app|8551b]   Rendering api/v2/hosts/index.json.rabl within api/v2/layouts/index_layout
2018-09-04T13:19:22 [I|app|8551b]   Rendered api/v2/hosts/index.json.rabl within api/v2/layouts/index_layout (79.3ms)
2018-09-04T13:19:22 [I|app|8551b] Completed 200 OK in 274ms (Views: 82.9ms | ActiveRecord: 44.1ms)
2018-09-04T13:19:22 [I|app|] Started DELETE "/api/hosts/111" for HAMMER_IP at 2018-09-04 13:19:22 +0900
2018-09-04T13:19:22 [I|app|6269a] Processing by Api::V2::HostsController#destroy as JSON
2018-09-04T13:19:22 [I|app|6269a]   Parameters: {"apiv"=>"v2", "id"=>"111", "host"=>{}}
2018-09-04T13:19:22 [I|app|6269a] Current user: foreman_admin (administrator)
2018-09-04T13:19:22 [I|app|6269a] Authorized user admin(Admin User)
2018-09-04T13:19:22 [I|app|6269a] Current user: admin (administrator)
2018-09-04T13:19:22 [I|kat|6269a] DELETE: https://FOREMAN.DOMAIN/pulp/api/v2/consumers/73c1e1b2-0040-4c9b-a8de-cff1d612bbc2/: {"content_type"=>"application/json", "accept"=>"application/json"}
Response: 200: null
2018-09-04T13:19:22 [I|aud|6269a] destroy event for Host::Base with id 90
2018-09-04T13:19:22 [I|aud|6269a] destroy event for Host::Base with id 109
2018-09-04T13:19:22 [I|aud|6269a] destroy event for Nic::Managed with id 113
2018-09-04T13:19:23 [I|app|6269a] Delete the DNS PTR record for VM_IP/VM_HOSTNAME.DOMAIN
2018-09-04T13:19:24 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T13:19:24 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T13:19:25 [E|dyn|] PG::UndefinedColumn: ERROR:  column katello_subscriptions.product_id does not exist
LINE 1: ...katello_subscriptions"."organization_id" = $1 AND "katello_s...
                                                             ^
: SELECT  "katello_subscriptions".* FROM "katello_subscriptions" WHERE "katello_subscriptions"."organization_id" = $1 AND "katello_subscriptions"."product_id" = $2 LIMIT $3
2018-09-04T13:19:25 [E|dyn|] /opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/postgresql_adapter.rb:616:in `async_exec'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/postgresql_adapter.rb:616:in `block (2 levels) in exec_no_cache'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/dependencies/interlock.rb:46:in `block in permit_concurrent_loads'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/concurrency/share_lock.rb:185:in `yield_shares'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/dependencies/interlock.rb:45:in `permit_concurrent_loads'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/postgresql_adapter.rb:615:in `block in exec_no_cache'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract_adapter.rb:613:in `block (2 levels) in log'
/opt/rh/rh-ruby24/root/usr/share/ruby/monitor.rb:214:in `mon_synchronize'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract_adapter.rb:612:in `block in log'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/notifications/instrumenter.rb:21:in `instrument'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract_adapter.rb:604:in `log'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/postgresql_adapter.rb:614:in `exec_no_cache'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/postgresql_adapter.rb:603:in `execute_and_clear'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/postgresql/database_statements.rb:79:in `exec_query'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/database_statements.rb:371:in `select'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/database_statements.rb:42:in `select_all'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/query_cache.rb:95:in `block in select_all'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/query_cache.rb:118:in `block in cache_sql'
/opt/rh/rh-ruby24/root/usr/share/ruby/monitor.rb:214:in `mon_synchronize'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/query_cache.rb:104:in `cache_sql'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/query_cache.rb:95:in `select_all'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/querying.rb:39:in `find_by_sql'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/relation.rb:678:in `exec_queries'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/relation.rb:546:in `load'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/relation.rb:255:in `records'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/relation/finder_methods.rb:508:in `find_take'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/relation/finder_methods.rb:100:in `take'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/relation/finder_methods.rb:78:in `find_by'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/querying.rb:7:in `find_by'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/core.rb:208:in `find_by'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/models/katello/glue/candlepin/pool.rb:85:in `stacking_subscription'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/models/katello/glue/candlepin/pool.rb:104:in `import_data'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/core_ext/object/try.rb:17:in `public_send'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/core_ext/object/try.rb:17:in `try!'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/core_ext/object/try.rb:6:in `try'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/models/katello/events/import_pool.rb:11:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/katello/event_queue/monitor.rb:111:in `block in act_on_event'
/usr/share/foreman/app/models/concerns/foreman/thread_session.rb:94:in `as'
/usr/share/foreman/app/models/concerns/foreman/thread_session.rb:100:in `as_anonymous_admin'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/katello/event_queue/monitor.rb:109:in `act_on_event'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/katello/event_queue/monitor.rb:44:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:74:in `block in assigns'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:73:in `tap'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matchers/abstract.rb:73:in `assigns'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:56:in `match_value'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:36:in `block in match?'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:35:in `each'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:35:in `match?'
/opt/theforeman/tfm/root/usr/share/gems/gems/algebrick-0.7.3/lib/algebrick/matching.rb:23:in `match'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/katello/event_queue/monitor.rb:36:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:538:in `block (3 levels) in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/common/singleton.rb:15:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.13.4/app/lib/actions/middleware/rails_executor_wrap.rb:14:in `block in run'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/execution_wrapper.rb:85:in `wrap'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.13.4/app/lib/actions/middleware/rails_executor_wrap.rb:13:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action/progress.rb:30:in `with_progress_calculation'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action/progress.rb:16:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/middleware/keep_locale.rb:11:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/middleware/keep_locale.rb:22:in `with_locale'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/middleware/keep_locale.rb:11:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.13.4/app/lib/actions/middleware/keep_current_user.rb:15:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.13.4/app/lib/actions/middleware/keep_current_user.rb:43:in `restore_curent_user'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.13.4/app/lib/actions/middleware/keep_current_user.rb:15:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware.rb:31:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/middleware/world.rb:30:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:537:in `block (2 levels) in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:536:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:536:in `block in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:451:in `block in with_error_handling'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:451:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:451:in `with_error_handling'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:531:in `execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/action.rb:278:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:17:in `block (2 levels) in execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/execution_plan/steps/abstract.rb:162:in `with_meta_calculation'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:16:in `block in execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:30:in `open_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:15:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/director.rb:56:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/executors/parallel/worker.rb:12:in `block in on_message'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/executors.rb:12:in `run_user_code'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/executors/parallel/worker.rb:11:in `on_message'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/context.rb:46:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/executes_context.rb:7:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.1.0/lib/dynflow/actor.rb:26:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/awaits.rb:15:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/buffer.rb:38:in `process_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/buffer.rb:31:in `process_envelopes?'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/buffer.rb:20:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/termination.rb:55:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/removes_child.rb:10:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/core.rb:161:in `process_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/core.rb:95:in `block in on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/core.rb:118:in `block (2 levels) in schedule_execution'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `block in synchronize'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `synchronize'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/core.rb:115:in `block in schedule_execution'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/serialized_execution.rb:18:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/serialized_execution.rb:96:in `work'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/serialized_execution.rb:77:in `block in call_job'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:348:in `run_task'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:337:in `block (3 levels) in create_worker'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in `loop'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in `block (2 levels) in create_worker'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in `catch'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in `block in create_worker'
/opt/theforeman/tfm/root/usr/share/gems/gems/logging-2.2.2/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
2018-09-04T13:19:36 [I|app|6269a] Delete DHCP reservation VM_HOSTNAME.DOMAIN for VM_HOSTNAME.DOMAIN-52:54:00:71:6e:dc/VM_IP
2018-09-04T13:19:36 [I|app|6269a] Processed 2 tasks from queue 'Host::Managed Main', completed 2/2
2018-09-04T13:19:36 [I|aud|6269a] destroy event for Host::Base with id 111
2018-09-04T13:19:36 [I|app|6269a] Remove puppet certificate for VM_HOSTNAME.DOMAIN
2018-09-04T13:19:39 [I|app|6269a] Delete realm entry for VM_HOSTNAME.DOMAIN
2018-09-04T13:19:39 [I|app|6269a] Delete the autosign entry for VM_HOSTNAME.DOMAIN
2018-09-04T13:19:39 [I|app|6269a] Removing Compute instance for VM_HOSTNAME.DOMAIN
2018-09-04T13:21:23 [I|app|] Started DELETE "/api/hosts/111" for HAMMER_IP at 2018-09-04 13:21:23 +0900
2018-09-04T13:21:23 [I|app|2c726] Processing by Api::V2::HostsController#destroy as JSON
2018-09-04T13:21:23 [I|app|2c726]   Parameters: {"apiv"=>"v2", "id"=>"111", "host"=>{}}
2018-09-04T13:21:24 [I|app|2c726] Current user: foreman_admin (administrator)
2018-09-04T13:21:24 [I|app|2c726] Authorized user admin(Admin User)
2018-09-04T13:21:24 [I|app|2c726] Current user: admin (administrator)
2018-09-04T13:21:24 [I|aud|2c726] destroy event for Nic::Managed with id 113
2018-09-04T13:22:59 [I|app|] Started GET "/rhsm/" for VM_IP at 2018-09-04 13:22:59 +0900
2018-09-04T13:23:00 [I|app|653f4] Processing by Katello::Api::V2::RootController#rhsm_resource_list as JSON
2018-09-04T13:23:00 [I|app|653f4]   Parameters: {"root"=>{}}
2018-09-04T13:23:00 [I|app|653f4]   Rendering /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/views/katello/api/v2/root/resource_list.json.rabl within katello/api/v2/layouts/collection
2018-09-04T13:23:00 [I|app|653f4]   Rendered /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/views/katello/api/v2/root/resource_list.json.rabl within katello/api/v2/layouts/collection (7.1ms)
2018-09-04T13:23:00 [I|app|653f4] Completed 200 OK in 158ms (Views: 24.9ms | ActiveRecord: 36.7ms)
2018-09-04T13:23:00 [I|app|] Started GET "/rhsm/consumers/73c1e1b2-0040-4c9b-a8de-cff1d612bbc2/certificates/serials" for VM_IP at 2018-09-04 13:23:00 +0900
2018-09-04T13:23:00 [I|app|a3f89] Processing by Katello::Api::Rhsm::CandlepinProxiesController#serials as JSON
2018-09-04T13:23:00 [I|app|a3f89]   Parameters: {"id"=>"73c1e1b2-0040-4c9b-a8de-cff1d612bbc2"}
2018-09-04T13:23:00 [I|app|a3f89] Current user: foreman_admin (administrator)
2018-09-04T13:23:00 [E|app|a3f89] RestClient::Gone: Katello::Resources::Candlepin::Consumer: 410 Gone {"displayMessage":"Unit 73c1e1b2-0040-4c9b-a8de-cff1d612bbc2 has been deleted","requestUuid":"c875a472-c289-486e-857e-8647dd080c1f","deletedId":"73c1e1b2-0040-4c9b-a8de-cff1d612bbc2"} (GET /candlepin/consumers/73c1e1b2-0040-4c9b-a8de-cff1d612bbc2)
Body: {"displayMessage":"Unit 73c1e1b2-0040-4c9b-a8de-cff1d612bbc2 has been deleted","requestUuid":"c875a472-c289-486e-857e-8647dd080c1f","deletedId":"73c1e1b2-0040-4c9b-a8de-cff1d612bbc2"}
/opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-2.0.1/lib/restclient/abstract_response.rb:223:in `exception_with_response'
/opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-2.0.1/lib/restclient/abstract_response.rb:103:in `return!'
/opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-2.0.1/lib/restclient/request.rb:809:in `process_result'
/opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-2.0.1/lib/restclient/request.rb:725:in `block in transmit'
/opt/rh/rh-ruby24/root/usr/share/ruby/net/http.rb:877:in `start'
/opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-2.0.1/lib/restclient/request.rb:715:in `transmit'
/opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-2.0.1/lib/restclient/request.rb:145:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-2.0.1/lib/restclient/request.rb:52:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-2.0.1/lib/restclient/resource.rb:51:in `get'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/katello/http_resource.rb:84:in `get'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/katello/resources/candlepin/consumer.rb:18:in `get'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/controllers/katello/api/rhsm/candlepin_proxies_controller.rb:312:in `block in find_host'
/usr/share/foreman/app/models/concerns/foreman/thread_session.rb:94:in `as'
/usr/share/foreman/app/models/concerns/foreman/thread_session.rb:100:in `as_anonymous_admin'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/controllers/katello/api/rhsm/candlepin_proxies_controller.rb:312:in `find_host'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:413:in `block in make_lambda'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:178:in `block (2 levels) in halting_and_conditional'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/abstract_controller/callbacks.rb:12:in `block (2 levels) in <module:Callbacks>'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:179:in `block in halting_and_conditional'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:507:in `block in invoke_before'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:507:in `each'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:507:in `invoke_before'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:106:in `block in run_callbacks'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/controllers/katello/api/rhsm/candlepin_proxies_controller.rb:35:in `repackage_message'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
/usr/share/foreman/app/controllers/api/v2/base_controller.rb:162:in `disable_json_root'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
/usr/share/foreman/app/controllers/concerns/application_shared.rb:15:in `set_timezone'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
/usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117: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-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
/opt/theforeman/tfm/root/usr/share/gems/gems/audited-4.7.0/lib/audited/sweeper.rb:14:in `around'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
/opt/theforeman/tfm/root/usr/share/gems/gems/audited-4.7.0/lib/audited/sweeper.rb:14:in `around'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:135:in `run_callbacks'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/abstract_controller/callbacks.rb:19:in `process_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal/rescue.rb:20:in `process_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/notifications.rb:166:in `block in instrument'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/notifications/instrumenter.rb:21:in `instrument'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/notifications.rb:166:in `instrument'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal/instrumentation.rb:30:in `process_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal/params_wrapper.rb:252:in `process_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/railties/controller_runtime.rb:22:in `process_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/controllers/katello/concerns/api/api_controller.rb:39:in `process_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/abstract_controller/base.rb:124:in `process'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionview-5.1.6/lib/action_view/rendering.rb:30:in `process'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal.rb:189:in `dispatch'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal.rb:253:in `dispatch'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/routing/route_set.rb:49:in `dispatch'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/routing/route_set.rb:31:in `serve'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/journey/router.rb:50:in `block in serve'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/journey/router.rb:33:in `each'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/journey/router.rb:33:in `serve'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/routing/route_set.rb:844:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/railties-5.1.6/lib/rails/engine.rb:522:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/railties-5.1.6/lib/rails/railtie.rb:185:in `public_send'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/railties-5.1.6/lib/rails/railtie.rb:185:in `method_missing'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/routing/mapper.rb:17:in `block in <class:Constraints>'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/routing/mapper.rb:46:in `serve'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/journey/router.rb:50:in `block in serve'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/journey/router.rb:33:in `each'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/journey/router.rb:33:in `serve'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/routing/route_set.rb:844:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.9/lib/apipie/static_dispatcher.rb:65:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.9/lib/apipie/extractor/recorder.rb:136:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in `call'
/usr/share/foreman/lib/middleware/telemetry.rb:9:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.9/lib/apipie/middleware/checksum_in_headers.rb:27:in `call'
/usr/share/foreman/lib/middleware/catch_json_parse_errors.rb:8:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/etag.rb:25:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/conditional_get.rb:25:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/head.rb:12:in `call'
/usr/share/foreman/lib/middleware/logging_context.rb:23:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/session/abstract/id.rb:232:in `context'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/session/abstract/id.rb:226:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/cookies.rb:613:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/callbacks.rb:26:in `block in call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:97:in `run_callbacks'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/callbacks.rb:24:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/debug_exceptions.rb:59:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/show_exceptions.rb:31:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/railties-5.1.6/lib/rails/rack/logger.rb:36:in `call_app'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/railties-5.1.6/lib/rails/rack/logger.rb:26:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/sprockets-rails-3.2.1/lib/sprockets/rails/quiet_assets.rb:13:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/remote_ip.rb:79:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/request_id.rb:25:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/lib/katello/prevent_json_parsing.rb:12:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/method_override.rb:22:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/runtime.rb:22:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/cache/strategy/local_cache_middleware.rb:27:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/executor.rb:12:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/sendfile.rb:111:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/secure_headers-5.0.5/lib/secure_headers/middleware.rb:13:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/railties-5.1.6/lib/rails/engine.rb:522:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/railties-5.1.6/lib/rails/railtie.rb:185:in `public_send'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/railties-5.1.6/lib/rails/railtie.rb:185:in `method_missing'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/urlmap.rb:68:in `block in call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/urlmap.rb:53:in `each'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/urlmap.rb:53:in `call'
/usr/share/passenger/phusion_passenger/rack/thread_handler_extension.rb:74:in `process_request'
/usr/share/passenger/phusion_passenger/request_handler/thread_handler.rb:141:in `accept_and_process_next_request'
/usr/share/passenger/phusion_passenger/request_handler/thread_handler.rb:109:in `main_loop'
/usr/share/passenger/phusion_passenger/request_handler.rb:455:in `block (3 levels) in start_threads'
/opt/theforeman/tfm/root/usr/share/gems/gems/logging-2.2.2/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
2018-09-04T13:23:00 [I|app|a3f89]   Rendering text template
2018-09-04T13:23:00 [I|app|a3f89]   Rendered text template (0.1ms)
2018-09-04T13:23:00 [I|app|a3f89] Completed 410 Gone in 125ms (Views: 1.8ms | ActiveRecord: 15.4ms)
2018-09-04T13:28:44 [I|app|] Started GET "/rhsm/consumers/5da9450c-e238-4873-bede-d49e4891bd19/compliance" for VM_IP5 at 2018-09-04 13:28:44 +0900
2018-09-04T13:28:44 [I|app|857d2] Processing by Katello::Api::Rhsm::CandlepinProxiesController#get as JSON
2018-09-04T13:28:44 [I|app|857d2]   Parameters: {"id"=>"5da9450c-e238-4873-bede-d49e4891bd19"}
2018-09-04T13:28:45 [I|app|857d2] Current user: 5da9450c-e238-4873-bede-d49e4891bd19 (regular user)
2018-09-04T13:28:45 [I|app|857d2] Completed 200 OK in 333ms (Views: 0.6ms | ActiveRecord: 10.8ms)
2018-09-04T13:30:12 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T13:30:12 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T13:30:12 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T13:30:12 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T13:30:15 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T13:30:15 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T13:30:16 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T13:30:16 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T13:30:16 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T13:30:16 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T13:30:16 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T13:30:16 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T13:30:16 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T13:30:16 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T13:30:16 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T13:30:16 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T13:30:16 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T13:30:16 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T13:30:16 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T13:30:16 [I|app|] Current user: foreman_admin (administrator)
2018-09-04T13:30:22 [I|dyn|] start terminating throttle_limiter...
2018-09-04T13:30:22 [I|dyn|] start terminating client dispatcher...
2018-09-04T13:30:22 [I|dyn|] stop listening for new events...
2018-09-04T13:30:22 [I|dyn|] start terminating clock...
2018-09-04T13:30:23 [I|dyn|] start terminating throttle_limiter...
2018-09-04T13:30:23 [I|dyn|] start terminating client dispatcher...
2018-09-04T13:30:23 [I|dyn|] stop listening for new events...
2018-09-04T13:30:23 [I|dyn|] start terminating clock...
2018-09-04T13:34:22 [I|dyn|] start terminating throttle_limiter...
2018-09-04T13:34:22 [I|dyn|] start terminating client dispatcher...
2018-09-04T13:34:22 [I|dyn|] stop listening for new events...
2018-09-04T13:34:22 [I|dyn|] start terminating clock...
2018-09-04T13:35:09 [W|app|6269a] Failed retrieving libvirt vm by uuid 025a24c6-a8d2-424f-8943-95afdd31296e
Libvirt::RetrieveError: Call to virDomainLookupByUUID failed: End of file while reading data: packet_write_wait: Connection to UNKNOWN port 65535: Broken pipe: Input/output error
/opt/theforeman/tfm/root/usr/share/gems/gems/fog-libvirt-0.4.1/lib/fog/libvirt/requests/compute/list_domains.rb:9:in `lookup_domain_by_uuid'
/opt/theforeman/tfm/root/usr/share/gems/gems/fog-libvirt-0.4.1/lib/fog/libvirt/requests/compute/list_domains.rb:9:in `list_domains'
/opt/theforeman/tfm/root/usr/share/gems/gems/fog-libvirt-0.4.1/lib/fog/libvirt/models/compute/servers.rb:15:in `get'
/usr/share/foreman/app/models/compute_resource.rb:181:in `find_vm_by_uuid'
/usr/share/foreman/app/models/compute_resources/foreman/model/libvirt.rb:40:in `find_vm_by_uuid'
/usr/share/foreman/app/models/compute_resources/foreman/model/libvirt.rb:48:in `destroy_vm'
/usr/share/foreman/app/models/concerns/orchestration/compute.rb:183:in `delCompute'
/usr/share/foreman/app/models/concerns/orchestration.rb:222:in `execute'
/usr/share/foreman/app/models/concerns/orchestration.rb:145:in `block in process'
/usr/share/foreman/app/models/concerns/orchestration.rb:137:in `each'
/usr/share/foreman/app/models/concerns/orchestration.rb:137:in `process'
/usr/share/foreman/app/models/concerns/orchestration.rb:60:in `on_destroy'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:413:in `block in make_lambda'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:235:in `block in halting_and_conditional'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:511:in `block in invoke_after'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:511:in `each'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:511:in `invoke_after'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:132:in `run_callbacks'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:827:in `_run_destroy_callbacks'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/callbacks.rb:321:in `destroy'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/transactions.rb:303:in `block in destroy'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/transactions.rb:384:in `block in with_transaction_returning_status'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/database_statements.rb:235:in `block in transaction'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/transaction.rb:194:in `block in within_new_transaction'
/opt/rh/rh-ruby24/root/usr/share/ruby/monitor.rb:214:in `mon_synchronize'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/transaction.rb:191:in `within_new_transaction'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/database_statements.rb:235:in `transaction'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/transactions.rb:210:in `transaction'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/transactions.rb:381:in `with_transaction_returning_status'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/transactions.rb:303:in `destroy'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.13.4/app/models/foreman_tasks/concerns/action_triggering.rb:35:in `block in destroy'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.13.4/app/models/foreman_tasks/concerns/action_triggering.rb:127:in `dynflow_task_wrap'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.13.4/app/models/foreman_tasks/concerns/action_triggering.rb:35:in `destroy'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/services/katello/registration_manager.rb:84:in `destroy_host_record'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/services/katello/registration_manager.rb:30:in `unregister_host'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/controllers/katello/concerns/api/v2/hosts_controller_extensions.rb:21:in `destroy'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal/basic_implicit_render.rb:4:in `send_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/abstract_controller/base.rb:186:in `process_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal/rendering.rb:30:in `process_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/abstract_controller/callbacks.rb:20:in `block in process_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:108:in `block in run_callbacks'
/usr/share/foreman/app/controllers/api/v2/base_controller.rb:162:in `disable_json_root'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
/usr/share/foreman/app/controllers/concerns/application_shared.rb:15:in `set_timezone'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
/usr/share/foreman/app/models/concerns/foreman/thread_session.rb:32:in `clear_thread'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117: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-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
/opt/theforeman/tfm/root/usr/share/gems/gems/audited-4.7.0/lib/audited/sweeper.rb:14:in `around'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
/opt/theforeman/tfm/root/usr/share/gems/gems/audited-4.7.0/lib/audited/sweeper.rb:14:in `around'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:135:in `run_callbacks'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/abstract_controller/callbacks.rb:19:in `process_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal/rescue.rb:20:in `process_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal/instrumentation.rb:32:in `block in process_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/notifications.rb:166:in `block in instrument'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/notifications/instrumenter.rb:21:in `instrument'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/notifications.rb:166:in `instrument'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal/instrumentation.rb:30:in `process_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal/params_wrapper.rb:252:in `process_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.6/lib/active_record/railties/controller_runtime.rb:22:in `process_action'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/abstract_controller/base.rb:124:in `process'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionview-5.1.6/lib/action_view/rendering.rb:30:in `process'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal.rb:189:in `dispatch'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_controller/metal.rb:253:in `dispatch'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/routing/route_set.rb:49:in `dispatch'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/routing/route_set.rb:31:in `serve'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/routing/mapper.rb:16:in `block in <class:Constraints>'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/routing/mapper.rb:46:in `serve'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/journey/router.rb:50:in `block in serve'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/journey/router.rb:33:in `each'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/journey/router.rb:33:in `serve'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/routing/route_set.rb:844:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.9/lib/apipie/static_dispatcher.rb:65:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.9/lib/apipie/extractor/recorder.rb:136:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in `call'
/usr/share/foreman/lib/middleware/telemetry.rb:9:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/apipie-rails-0.5.9/lib/apipie/middleware/checksum_in_headers.rb:27:in `call'
/usr/share/foreman/lib/middleware/catch_json_parse_errors.rb:8:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/etag.rb:25:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/conditional_get.rb:38:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/head.rb:12:in `call'
/usr/share/foreman/lib/middleware/logging_context.rb:23:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/session/abstract/id.rb:232:in `context'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/session/abstract/id.rb:226:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/cookies.rb:613:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/callbacks.rb:26:in `block in call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:97:in `run_callbacks'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/callbacks.rb:24:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/debug_exceptions.rb:59:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/show_exceptions.rb:31:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/railties-5.1.6/lib/rails/rack/logger.rb:36:in `call_app'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/railties-5.1.6/lib/rails/rack/logger.rb:26:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/sprockets-rails-3.2.1/lib/sprockets/rails/quiet_assets.rb:13:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/remote_ip.rb:79:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/request_id.rb:25:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/lib/katello/prevent_json_parsing.rb:12:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/method_override.rb:22:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/runtime.rb:22:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/cache/strategy/local_cache_middleware.rb:27:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/executor.rb:12:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/sendfile.rb:111:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/secure_headers-5.0.5/lib/secure_headers/middleware.rb:13:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/railties-5.1.6/lib/rails/engine.rb:522:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/railties-5.1.6/lib/rails/railtie.rb:185:in `public_send'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/railties-5.1.6/lib/rails/railtie.rb:185:in `method_missing'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/urlmap.rb:68:in `block in call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/urlmap.rb:53:in `each'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/rack-2.0.3/lib/rack/urlmap.rb:53:in `call'
/usr/share/passenger/phusion_passenger/rack/thread_handler_extension.rb:74:in `process_request'
/usr/share/passenger/phusion_passenger/request_handler/thread_handler.rb:141:in `accept_and_process_next_request'
/usr/share/passenger/phusion_passenger/request_handler/thread_handler.rb:109:in `main_loop'
/usr/share/passenger/phusion_passenger/request_handler.rb:455:in `block (3 levels) in start_threads'
/opt/theforeman/tfm/root/usr/share/gems/gems/logging-2.2.2/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
2018-09-04T13:35:09 [I|app|6269a] Processed 4 tasks from queue 'Host::Managed Main', completed 6/6
2018-09-04T13:35:09 [I|app|6269a] Completed 200 OK in 946942ms (Views: 25.5ms | ActiveRecord: 117.6ms)
2018-09-04T13:35:09 [I|app|2c726] Delete the DNS PTR record for VM_IP/VM_HOSTNAME.DOMAIN
2018-09-04T13:35:21 [I|app|2c726] Delete DHCP reservation VM_HOSTNAME.DOMAIN for VM_HOSTNAME.DOMAIN-52:54:00:71:6e:dc/VM_IP
2018-09-04T13:35:21 [I|app|2c726] Processed 2 tasks from queue 'Host::Managed Main', completed 2/2
2018-09-04T13:35:21 [I|aud|2c726] destroy event for Host::Base with id 111
2018-09-04T13:35:22 [I|app|2c726] Remove puppet certificate for VM_HOSTNAME.DOMAIN
2018-09-04T13:35:24 [I|app|2c726] Delete realm entry for VM_HOSTNAME.DOMAIN
2018-09-04T13:35:24 [I|app|2c726] Delete the autosign entry for VM_HOSTNAME.DOMAIN
2018-09-04T13:35:25 [I|app|2c726] Removing Compute instance for VM_HOSTNAME.DOMAIN
2018-09-04T13:35:26 [I|app|2c726] Processed 4 tasks from queue 'Host::Managed Main', completed 6/6
2018-09-04T13:35:26 [I|app|2c726] Completed 200 OK in 842342ms (Views: 17.5ms | ActiveRecord: 824218.1ms)

relevant logs:

2018-09-04T13:35:09 [W|app|6269a] Failed retrieving libvirt vm by uuid 025a24c6-a8d2-424f-8943-95afdd31296e
Libvirt::RetrieveError: Call to virDomainLookupByUUID failed: End of file while reading data: packet_write_wait: Connection to UNKNOWN port 65535: Broken pipe: Input/output error
/opt/theforeman/tfm/root/usr/share/gems/gems/fog-libvirt-0.4.1/lib/fog/libvirt/requests/compute/list_domains.rb:9:in `lookup_domain_by_uuid'
/opt/theforeman/tfm/root/usr/share/gems/gems/fog-libvirt-0.4.1/lib/fog/libvirt/requests/compute/list_domains.rb:9:in `list_domains'
/opt/theforeman/tfm/root/usr/share/gems/gems/fog-libvirt-0.4.1/lib/fog/libvirt/models/compute/servers.rb:15:in `get'
/usr/share/foreman/app/models/compute_resource.rb:181:in `find_vm_by_uuid'
/usr/share/foreman/app/models/compute_resources/foreman/model/libvirt.rb:40:in `find_vm_by_uuid'
/usr/share/foreman/app/models/compute_resources/foreman/model/libvirt.rb:48:in `destroy_vm'

This happens 5 minutes later of the time-out and it deletes the vm…but 5 minutes later.

Thanks again @lzap for help

lzap · September 4, 2018, 4:44pm

The katello/dynflow error is irrelevant to the timeout error, have you migrated your database? Maybe @iNecas remembers some known issue.

lzap · September 4, 2018, 4:46pm

Ok libvirt closes the connection, that’s the issue. How far is the hypervisor? How’s the route? Any VPNs and firewalls and stuff?

This works fine but we assume that libvirt is “close enough” over stable connection.

Ale · September 6, 2018, 7:33am

it seems that the problem was related to realm/dns. I deployed a 2nd freeipa instance and problem went away since this morning with around 100 vm deployments/deletions

lzap · September 6, 2018, 2:09pm

Write a blog post about it! Send us links, we would love to hear about how people use Forman! Thanks.

Bryan_Anderson · October 24, 2018, 9:18pm

Hey so I am running into a very similar issue. When you say Realm/DNS are you talking for the host/hypervisor or for authentication?

Ale · October 26, 2018, 6:02am

Ey @Bryan_Anderson, we were using foreman with FreeIPA dns and realm.

We made more and more tests and we saw that 1 of the baremetal hosts was taking too long to authenticate through ssh, like ~20seconds at first try. As soon as we removed that host, this error almost stopped happening, although it still happens from time to time… ¯\_(ツ)_/¯

edit: just saw this Call to virDomainLookupByUUID failed: internal error: client socket is closed