Bug #23538: Intermittent smart proxy synchronization malfunction - Katello - Foreman

Actions

Copy link

Bug #23538

open

Intermittent smart proxy synchronization malfunction

Added by Tony Coffman over 6 years ago. Updated over 6 years ago.

Status:

Assigned

Priority:

Normal

Assignee:

Justin Sherrill

Category:

Foreman Proxy Content

Target version:

Katello 3.6.1

Difficulty:

Triaged:

Yes

Bugzilla link:

Pull request:

Fixed in Releases:

Found in Releases:

Katello 3.6.0

Red Hat JIRA:

Description

Katello 3.6.0

During a content view promotion, the promotion succeeds, and then schedules the sync tasks for the smart proxies. I have two smart proxies.

One of the smart proxies fails immediately with this error
undefined method `join' for #<ProxyAPI::RestClientLogger:0x007f9dac74e158>

For the other smart proxy, I get two synchronize jobs - they both run longer than normal (full synch?) but complete successfully.

This happens intermittently (so far about 50% of the time) during a CV promotion. When it doesn't fail, I see only two sync tasks - one for each proxy and everything completes normally.

Actions

Copy link

Updated by John Mitsch over 6 years ago

Do you have a traceback from this error?

Also, are both smart proxies 3.6?

Actions

Copy link

Updated by Tony Coffman over 6 years ago

John Mitsch wrote:

Do you have a traceback from this error?

Also, are both smart proxies 3.6?

Yes both proxies are 3.6

Backtrace

/opt/theforeman/tfm/root/usr/share/gems/gems/runcible-2.6.0/lib/runcible/base.rb:212:in `generate_log_message'
/opt/theforeman/tfm/root/usr/share/gems/gems/runcible-2.6.0/lib/runcible/base.rb:199:in `log_exception'
/opt/theforeman/tfm/root/usr/share/gems/gems/runcible-2.6.0/lib/runcible/base.rb:75:in `rescue in call'
/opt/theforeman/tfm/root/usr/share/gems/gems/runcible-2.6.0/lib/runcible/base.rb:31:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/runcible-2.6.0/lib/runcible/resources/repository.rb:31:in `retrieve'
/opt/theforeman/tfm/root/usr/share/gems/gems/runcible-2.6.0/lib/runcible/extensions/repository.rb:415:in `retrieve_with_details'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.6.0/app/lib/katello/capsule_content.rb:139:in `pulp_repo_facts'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.6.0/app/models/katello/glue/pulp/repo.rb:64:in `block in needs_importer_updates'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.6.0/app/models/katello/glue/pulp/repo.rb:63:in `select'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.6.0/app/models/katello/glue/pulp/repo.rb:63:in `needs_importer_updates'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.6.0/app/lib/actions/katello/capsule_content/sync.rb:115:in `repos_needing_updates'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.6.0/app/lib/actions/katello/capsule_content/sync.rb:39:in `plan'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action.rb:486:in `block (3 levels) in execute_plan'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware.rb:35:in `plan'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware.rb:35:in `plan'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.6.0/app/lib/actions/middleware/keep_locale.rb:7:in `plan'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.11.2/app/lib/actions/middleware/keep_current_user.rb:23:in `block in plan'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.11.2/app/lib/actions/middleware/keep_current_user.rb:39:in `with_current_user'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.11.2/app/lib/actions/middleware/keep_current_user.rb:22:in `plan'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware.rb:35:in `plan'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/world.rb:30:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action.rb:485:in `block (2 levels) in execute_plan'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/execution_plan.rb:368:in `switch_flow'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action.rb:389:in `concurrence'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action.rb:484:in `block in execute_plan'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action.rb:444:in `block in with_error_handling'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action.rb:444:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action.rb:444:in `with_error_handling'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action.rb:483:in `execute_plan'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action.rb:277:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/execution_plan/steps/plan_step.rb:54:in `block in execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/execution_plan/steps/abstract.rb:155:in `with_meta_calculation'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/execution_plan/steps/plan_step.rb:53:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/execution_plan.rb:270:in `block (2 levels) in plan'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/execution_plan.rb:368:in `switch_flow'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/execution_plan.rb:358:in `with_planning_scope'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/execution_plan.rb:269:in `block in plan'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware.rb:43:in `plan_phase'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware.rb:43:in `plan_phase'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware.rb:43:in `plan_phase'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware.rb:43:in `plan_phase'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/common/transaction.rb:16:in `block in rollback_on_error'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.4/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.4/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.4/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.4/lib/active_record/connection_adapters/abstract/database_statements.rb:235:in `transaction'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.4/lib/active_record/transactions.rb:210:in `transaction'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/transaction_adapters/active_record.rb:5:in `transaction'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/common/transaction.rb:15:in `rollback_on_error'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/common/transaction.rb:5:in `plan_phase'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/world.rb:30:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/execution_plan.rb:268:in `plan'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/world.rb:181:in `block in plan_with_caller'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/world.rb:179:in `tap'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/world.rb:179:in `plan_with_caller'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action/with_sub_plans.rb:83:in `block in trigger'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/world.rb:146:in `trigger'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action/with_sub_plans.rb:83:in `trigger'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.11.2/app/lib/actions/bulk_action.rb:52:in `block in create_sub_plans'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.4/lib/active_record/relation/delegation.rb:39:in `each'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activerecord-5.1.4/lib/active_record/relation/delegation.rb:39:in `each'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.11.2/app/lib/actions/bulk_action.rb:51:in `map'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.11.2/app/lib/actions/bulk_action.rb:51:in `create_sub_plans'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action/with_sub_plans.rb:40:in `spawn_plans'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action/with_bulk_sub_plans.rb:70:in `spawn_plans'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action/with_sub_plans.rb:36:in `initiate'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action/with_bulk_sub_plans.rb:35:in `initiate'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action/with_sub_plans.rb:16: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/dynflow-0.8.37/lib/dynflow/action/with_sub_plans.rb:11:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action/with_bulk_sub_plans.rb:23:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.11.2/app/lib/actions/bulk_action.rb:21:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action.rb:531:in `block (3 levels) in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.11.2/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.4/lib/active_support/execution_wrapper.rb:85:in `wrap'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.11.2/app/lib/actions/middleware/rails_executor_wrap.rb:13:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action/progress.rb:30:in `with_progress_calculation'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action/progress.rb:16:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.6.0/app/lib/actions/middleware/keep_locale.rb:11:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.6.0/app/lib/actions/middleware/keep_locale.rb:22:in `with_locale'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.6.0/app/lib/actions/middleware/keep_locale.rb:11:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.11.2/app/lib/actions/middleware/keep_current_user.rb:28:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.11.2/app/lib/actions/middleware/keep_current_user.rb:51:in `restore_curent_user'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.11.2/app/lib/actions/middleware/keep_current_user.rb:28:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware.rb:31:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/middleware/world.rb:30:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action.rb:530:in `block (2 levels) in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action.rb:529:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action.rb:529:in `block in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action.rb:444:in `block in with_error_handling'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action.rb:444:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action.rb:444:in `with_error_handling'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action.rb:524:in `execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/action.rb:277:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:9:in `block (2 levels) in execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/execution_plan/steps/abstract.rb:155:in `with_meta_calculation'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:8:in `block in execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:22:in `open_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:7:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/director.rb:42:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/executors/parallel/worker.rb:12:in `block in on_message'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/lib/dynflow/executors.rb:11:in `run_user_code'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.37/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-0.8.37/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-1.8.2/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context'

Actions

Copy link

Updated by Justin Sherrill over 6 years ago

Can you check /var/log/messages on the capsule that failed around the time of the failure and see if there is anything interesting there? I think pulp may be throwing an error.

Actions

Copy link

Updated by Tony Coffman over 6 years ago

Here is the log for that time period. The sync task ran 2018-05-08 12:49:52 - 12:49:58 UTC

The log snippet is from the failed proxy /var/log/messages and the time for this snippet is US EDT. Time is in sync between the two systems.

May 8 08:47:43 detr-form-01-pv pulp: celery.beat:INFO: Scheduler: Sending due task download_deferred_content (pulp.server.controllers.repository.queue_download_deferred)
May 8 08:47:43 detr-form-01-pv pulp: celery.worker.strategy:INFO: Received task: pulp.server.controllers.repository.queue_download_deferred[2e8c2596-b2c4-44c9-a549-985cbafba511]
May 8 08:47:43 detr-form-01-pv pulp: celery.worker.strategy:INFO: Received task: pulp.server.controllers.repository.download_deferred[e19935fe-2dba-457b-9a2e-3a86e005c923]
May 8 08:47:43 detr-form-01-pv pulp: celery.worker.job:INFO: Task pulp.server.controllers.repository.queue_download_deferred[2e8c2596-b2c4-44c9-a549-985cbafba511] succeeded in 0.0420817770064s: None
May 8 08:47:44 detr-form-01-pv pulp: celery.worker.job:INFO: Task pulp.server.controllers.repository.download_deferred[e19935fe-2dba-457b-9a2e-3a86e005c923] succeeded in 1.02099037508s: None
May 8 08:47:48 detr-form-01-pv puppet-agent¹¹⁹⁴⁴: Applied catalog in 0.34 seconds
May 8 08:49:54 detr-form-01-pv pulp: kombu.transport.qpid:INFO: Connected to qpid with SASL mechanism ANONYMOUS
May 8 08:57:43 detr-form-01-pv pulp: celery.beat:INFO: Scheduler: Sending due task download_deferred_content (pulp.server.controllers.repository.queue_download_deferred)
May 8 08:57:43 detr-form-01-pv pulp: celery.worker.strategy:INFO: Received task: pulp.server.controllers.repository.queue_download_deferred[05bd1ca2-8a76-496a-8f5a-cbc7a198aed0]
May 8 08:57:43 detr-form-01-pv pulp: celery.worker.strategy:INFO: Received task: pulp.server.controllers.repository.download_deferred[dbc4a481-45a1-4333-95f5-3357e82232bc]
May 8 08:57:43 detr-form-01-pv pulp: celery.worker.job:INFO: Task pulp.server.controllers.repository.queue_download_deferred[05bd1ca2-8a76-496a-8f5a-cbc7a198aed0] succeeded in 0.0385821970413s: None
May 8 08:57:44 detr-form-01-pv pulp: celery.worker.job:INFO: Task pulp.server.controllers.repository.download_deferred[dbc4a481-45a1-4333-95f5-3357e82232bc] succeeded in 1.02069851896s: None

Actions

Copy link

Updated by Josh Pavel over 6 years ago

FYI, we noticed this as well, but only AFTER our upgrade from Katello 3.4 -> 3.5.1. So unless it's a different issue, I don't think this is specific to 3.6

Actions

Copy link

Updated by Justin Sherrill over 6 years ago

Could you provide a foreman-debug after one of the failures from both the foreman server and the smart proxy, as well as a task export ( foreman-rake foreman_tasks:export_tasks )

Actions

Copy link

Updated by Tony Coffman over 6 years ago

Time of the event was 2018-05-18 19:20:07 UTC

foreman-debug
https://s3.amazonaws.com/tonycoffman/foreman-debug-q5Mui.tar.xz

Task Export
https://s3.amazonaws.com/tonycoffman/task-export-1526676052.tar.gz

Actions

Copy link

Updated by Tony Coffman over 6 years ago

Warning: small sample size, but I think I see a pattern in these failures. They seem to be strictly on content views that contain Oracle Linux 6 and Oracle Linux 7 repositories.

I also have content views for C5, C6, C7 and those don't seem to experience this type of failure.

Actions

Copy link

Updated by Justin Sherrill over 6 years ago

Hi all,

To help diagnose this issue we have updated the runcible library to handle the logging error that you were seeing. Since we haven't traced the issue down to an actual pulp error, i suspect this is related. This may solve the error, or it may just print the actual error that was being masked before. Either way if you can install this update, restart foreman-tasks and httpd and reproduce again, hopefully we will get a different (and better) error:

For 3.5: