Synchronize repository task hanging

Problem:

It’s now the third time that last couple of days that at some point two or more repository sync tasks are hanging and never finish. It’s different repositories and at different times. Currently it’s EPEL 8 and CentOS 7 Plus. It’s working fine before that for multiple times. A reboot or restart of katello and a manual sync work fine.

Tasks are pending, delayed.

Running action is Actions::Pulp::Repository::Sync in state suspended.

Dynflow console says “waiting for Pulp to finish the task”.

It will stay like this until a restart of katello/foreman.

How do I fix this? Thx

Expected outcome:

Sync finishing within seconds or minutes as usual.

Foreman and Proxy versions:

Foreman 2.0.0

Foreman and Proxy plugin versions:

Katello 3.15

Distribution and version:

CentOS 7.8.2003

It’s really bad: it takes 1-2 days after a restart of katello until the next repo sync hangs. That means the sync plan hangs. That means it doesn’t sync any of those repositories. That task just sits there “running”…

Has anyone any insight how to troubleshoot this issue?

Can you share us the foreman-debug output when you get this error ?. Do you see any traces in /var/log/messages or /var/log/foreman/production.log ?

I see one error in production.log at about the time when I would expect the sync task to finish:

2020-05-30T06:54:34 [E|dyn|] PersistenceError in executor
2020-05-30T06:54:34 [E|dyn|] caused by Sequel::PoolTimeout: timeout: 5.0, elapsed: 5.000103840007796 (Dynflow::Errors::PersistenceError)
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/connection_pool/threaded.rb:247:in raise_pool_timeout' /opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/connection_pool/threaded.rb:149:in acquire’
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/connection_pool/threaded.rb:90:in hold' /opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/database/connecting.rb:269:in synchronize’
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/adapters/postgres.rb:731:in literal_string_append' /opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/dataset/sql.rb:82:in literal_append’
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/dataset/sql.rb:406:in complex_expression_sql_append' /opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/adapters/shared/postgres.rb:1320:in complex_expression_sql_append’
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/sql.rb:96:in to_s_append' /opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/dataset/sql.rb:1161:in literal_expression_append’
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/dataset/sql.rb:89:in literal_append' /opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/dataset/sql.rb:414:in block in complex_expression_sql_append’
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/dataset/sql.rb:412:in each' /opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/dataset/sql.rb:412:in complex_expression_sql_append’
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/adapters/shared/postgres.rb:1320:in complex_expression_sql_append' /opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/sql.rb:96:in to_s_append’
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/dataset/sql.rb:1161:in literal_expression_append' /opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/dataset/sql.rb:89:in literal_append’
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/dataset/placeholder_literalizer.rb:181:in block in sql' /opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/dataset/placeholder_literalizer.rb:173:in each’
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/dataset/placeholder_literalizer.rb:173:in sql' /opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/dataset/placeholder_literalizer.rb:159:in first’
/opt/theforeman/tfm/root/usr/share/gems/gems/sequel-5.7.1/lib/sequel/dataset/actions.rb:241:in first' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.3/lib/dynflow/persistence_adapters/sequel.rb:312:in block in load_record’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.3/lib/dynflow/persistence_adapters/sequel.rb:440:in with_retry' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.3/lib/dynflow/persistence_adapters/sequel.rb:312:in load_record’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.3/lib/dynflow/persistence_adapters/sequel.rb:159:in load_action' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.3/lib/dynflow/persistence.rb:22:in load_action’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.3/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:31:in open_action' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.3/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:16:in execute’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.3/lib/dynflow/director.rb:93:in execute' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.3/lib/dynflow/executors/sidekiq/worker_jobs.rb:11:in block (2 levels) in perform’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.3/lib/dynflow/executors.rb:12:in run_user_code' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.3/lib/dynflow/executors/sidekiq/worker_jobs.rb:9:in block in perform’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.3/lib/dynflow/executors/sidekiq/worker_jobs.rb:25:in with_telemetry' /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.3/lib/dynflow/executors/sidekiq/worker_jobs.rb:8:in perform’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.3/lib/dynflow/executors/sidekiq/serialization.rb:27:in perform' [ sidekiq ] [ concurrent-ruby ] /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.3/lib/dynflow/executors/sidekiq/orchestrator_jobs.rb:40:in perform’
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.4.3/lib/dynflow/executors/sidekiq/serialization.rb:27:in `perform’
[ sidekiq ]
[ concurrent-ruby ]

Hmm. Not enough context to troubleshoot one way or the other. Could you email me the foreman debug output (paji@redhat.com) ?

It happened again yesterday. I have looked through the logs and journal and tracked the progress of the yum importer (which seems to be the hanging step in dynflow) and compared it to a successful task: it actually succeeds and also seem to start the repo.publish.publish directly after that which also succeeds. The task hanging has actually finished successfully but dynflow/foreman doesn’t seem to pick that up…

Try increasing the db-pool size. We ve been noticing some issues with the
default
foreman-installer --foreman-db-pool=15

So far no hanging tasks. Of course, I can’t be sure as I don’t have a way to force the issue.

And even if the increase of the db-pool helps the issue at the moment, I think it should handle the whole problem, whenever it occurs, better than just keep a task hanging which blocks your sync plan and which you cannot cancel in the web gui but only by a foreman/katello restart…

There were some fixes around the connection pool handling which went into dynflow 1.4.4 (2.0 repos currently have 1.4.3). We could probably get the newer version into 2.0 repos as well.

1 Like

It happened again yesterday. I have increased the db pool to 15. Yet, the sync of one repository is hanging again.

Can you send me the

journalctl -u dynflow-sidekiq@*

output the next time you hit this issue?