Project

General

Profile

Bug #23538

Intermittent smart proxy synchronization malfunction

Added by Tony Coffman almost 3 years ago. Updated almost 3 years ago.

Status:
Assigned
Priority:
Normal
Category:
Foreman Proxy Content
Target version:
Difficulty:
Triaged:
Yes
Bugzilla link:
Pull request:
Fixed in Releases:
Found in Releases:

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.

History

#1 Updated by John Mitsch almost 3 years ago

Do you have a traceback from this error?

Also, are both smart proxies 3.6?

#2 Updated by Tony Coffman almost 3 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'

#3 Updated by Justin Sherrill almost 3 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.

#4 Updated by Tony Coffman almost 3 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-agent11944: 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

#5 Updated by Josh Pavel almost 3 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

#6 Updated by Justin Sherrill almost 3 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 )

#8 Updated by Tony Coffman almost 3 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.

#9 Updated by Justin Sherrill almost 3 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:
  1. yum update http://koji.katello.org/kojifiles/work/tasks/9184/99184/tfm-rubygem-runcible-2.8.1-1.el7.noarch.rpm
For 3.6:
  1. yum update http://koji.katello.org/kojifiles/work/tasks/9179/99179/tfm-rubygem-runcible-2.8.1-1.el7.noarch.rpm

Thanks!

#10 Updated by Tony Coffman almost 3 years ago

Some early feedback using the updated runcible.

So far zero failures on the first 10 promotions. Based on past experience I would have expected 2-4 failures.

I'll continue to try to break it over the next week or so and provide another update.

#11 Updated by Andrew Kofink almost 3 years ago

  • Assignee set to Justin Sherrill

#12 Updated by Tony Coffman almost 3 years ago

Update: Today, I ran a second set of 10 promotions with no failures.

#13 Updated by John Mitsch almost 3 years ago

  • Legacy Backlogs Release (now unused) set to 166
  • Status changed from New to Closed
  • Category set to Foreman Proxy Content

Tony,

Thanks for checking that, we are going to close the issue, feel free to reopen if you do hit this again.

#14 Updated by John Mitsch almost 3 years ago

  • Status changed from Closed to Assigned

Re-opening as we need to get the new runcible builds in the release.

#15 Updated by Justin Sherrill almost 3 years ago

  • Legacy Backlogs Release (now unused) changed from 166 to 352

#16 Updated by Greg Sutcliffe almost 3 years ago

  • Triaged set to No
  • Found in Releases Katello 3.6.0 added

Also available in: Atom PDF