Bug 1033660 - Manifest upload task finishes with timeout
Summary: Manifest upload task finishes with timeout
Keywords:
Status: CLOSED WORKSFORME
Alias: None
Product: Red Hat Satellite
Classification: Red Hat
Component: Content Management
Version: Nightly
Hardware: Unspecified
OS: Unspecified
unspecified
high vote
Target Milestone: Unspecified
Assignee: Tom McKay
QA Contact: Katello QA List
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2013-11-22 14:42 UTC by Vitaly Kuznetsov
Modified: 2014-06-16 19:54 UTC (History)
3 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2014-06-16 19:54:30 UTC
Target Upstream Version:


Attachments (Terms of Use)

Description Vitaly Kuznetsov 2013-11-22 14:42:21 UTC
Description of problem:
I'm performing refreshed manifest upload via api (prov_api.import_manifest). Manifest renews existent one and contains thousands of subscriptions. API call succeeds and results in task id. This task finishes with 'timeout' in 5 minutes:
{u'task_owner_id': None, u'task_owner_type': None, u'task_type': u'import manifest', u'start_time': u'2013-11-29T05:31:21Z', u'uuid': u'6fe0ed94-41ce-49e8-b22b-187ab64cdf55', u'parameters': {}, u'user_id': 1, u'finish_time': u'2013-11-29T05:35:23Z', u'created_at': u'2013-11-29T05:31:17Z', u'updated_at': u'2013-11-29T05:35:23Z', u'organization_id': 2, u'state': u'error', u'result': {u'errors': [u'Resources::Candlepin::Owner: Request Timeout  (POST /candlepin/owners/testorg49731D/imports)', u"/opt/rh/ruby193/root/usr/share/gems/gems/rest-client-1.6.1/lib/restclient/request.rb:174:in `rescue in transmit'\n/opt/rh/ruby193/root/usr/share/gems/gems/rest-client-1.6.1/lib/restclient/request.rb:138:in `transmit'\n/opt/rh/ruby193/root/usr/share/gems/gems/rest-client-1.6.1/lib/restclient/request.rb:60:in `execute'\n/opt/rh/ruby193/root/usr/share/gems/gems/rest-client-1.6.1/lib/restclient/request.rb:31:in `execute'\n/opt/rh/ruby193/root/usr/share/gems/gems/rest-client-1.6.1/lib/restclient/resource.rb:59:in `post'\n/usr/share/katello/app/lib/http_resource.rb:110:in `post'\n/usr/share/katello/app/lib/resources/candlepin.rb:352:in `import'\n/usr/share/katello/app/models/glue/provider.rb:188:in `owner_import'\n/usr/share/katello/app/models/glue.rb:174:in `execute'\n/usr/share/katello/app/models/glue.rb:124:in `block in process'\n/usr/share/katello/app/models/glue.rb:111:in `each'\n/usr/share/katello/app/models/glue.rb:111:in `process'\n/usr/share/katello/app/models/glue.rb:35:in `on_save'\n/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:214:in `_conditional_callback_around_3543'\n/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:403:in `_run__3693831915968787353__save__2279260168017067528__callbacks'\n/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:405:in `__run_callback'\n/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:385:in `_run_save_callbacks'\n/opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/callbacks.rb:81:in `run_callbacks'\n/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/callbacks.rb:264:in `create_or_update'\n/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/persistence.rb:104:in `save!'\n/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/validations.rb:56:in `save!'\n/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/attribute_methods/dirty.rb:33:in `save!'\n/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:246:in `block in save!'\n/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:295:in `block in with_transaction_returning_status'\n/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/connection_adapters/abstract/database_statements.rb:192:in `transaction'\n/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:208:in `transaction'\n/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:293:in `with_transaction_returning_status'\n/opt/rh/ruby193/root/usr/share/gems/gems/activerecord-3.2.8/lib/active_record/transactions.rb:246:in `save!'\n/usr/share/katello/app/models/glue/provider.rb:308:in `queue_import_manifest'\n/usr/share/katello/app/models/async_operation.rb:58:in `perform'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/backend/base.rb:94:in `block in invoke_job'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/lifecycle.rb:60:in `call'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/lifecycle.rb:60:in `block in initialize'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/lifecycle.rb:65:in `call'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/lifecycle.rb:65:in `execute'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/lifecycle.rb:38:in `run_callbacks'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/backend/base.rb:91:in `invoke_job'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/worker.rb:178:in `block (2 levels) in run'\n/opt/rh/ruby193/root/usr/share/ruby/timeout.rb:69:in `timeout'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/worker.rb:178:in `block in run'\n/opt/rh/ruby193/root/usr/share/ruby/benchmark.rb:295:in `realtime'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/worker.rb:177:in `run'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/worker.rb:234:in `block in reserve_and_run_one_job'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/lifecycle.rb:60:in `call'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/lifecycle.rb:60:in `block in initialize'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/lifecycle.rb:65:in `call'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/lifecycle.rb:65:in `execute'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/lifecycle.rb:38:in `run_callbacks'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/worker.rb:234:in `reserve_and_run_one_job'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/worker.rb:162:in `block in work_off'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/worker.rb:161:in `times'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/worker.rb:161:in `work_off'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/worker.rb:133:in `block (4 levels) in start'\n/opt/rh/ruby193/root/usr/share/ruby/benchmark.rb:295:in `realtime'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/worker.rb:132:in `block (3 levels) in start'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/lifecycle.rb:60:in `call'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/lifecycle.rb:60:in `block in initialize'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/lifecycle.rb:65:in `call'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/lifecycle.rb:65:in `execute'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/lifecycle.rb:38:in `run_callbacks'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/worker.rb:129:in `block (2 levels) in start'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/worker.rb:128:in `loop'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/worker.rb:128:in `block in start'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/plugins/clear_locks.rb:7:in `call'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/plugins/clear_locks.rb:7:in `block (2 levels) in <class:ClearLocks>'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/lifecycle.rb:78:in `call'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/lifecycle.rb:78:in `block (2 levels) in add'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/lifecycle.rb:60:in `call'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/lifecycle.rb:60:in `block in initialize'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/lifecycle.rb:78:in `call'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/lifecycle.rb:78:in `block in add'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/lifecycle.rb:65:in `call'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/lifecycle.rb:65:in `execute'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/lifecycle.rb:38:in `run_callbacks'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/worker.rb:127:in `start'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/command.rb:101:in `run'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/command.rb:89:in `block in run_process'\n/opt/rh/ruby193/root/usr/share/gems/gems/daemons-1.1.4/lib/daemons/application.rb:249:in `call'\n/opt/rh/ruby193/root/usr/share/gems/gems/daemons-1.1.4/lib/daemons/application.rb:249:in `block in start_proc'\n/opt/rh/ruby193/root/usr/share/gems/gems/daemons-1.1.4/lib/daemons/daemonize.rb:197:in `call'\n/opt/rh/ruby193/root/usr/share/gems/gems/daemons-1.1.4/lib/daemons/daemonize.rb:197:in `call_as_daemon'\n/opt/rh/ruby193/root/usr/share/gems/gems/daemons-1.1.4/lib/daemons/application.rb:253:in `start_proc'\n/opt/rh/ruby193/root/usr/share/gems/gems/daemons-1.1.4/lib/daemons/application.rb:293:in `start'\n/opt/rh/ruby193/root/usr/share/gems/gems/daemons-1.1.4/lib/daemons/controller.rb:70:in `run'\n/opt/rh/ruby193/root/usr/share/gems/gems/daemons-1.1.4/lib/daemons.rb:195:in `block in run_proc'\n/opt/rh/ruby193/root/usr/share/gems/gems/daemons-1.1.4/lib/daemons/cmdline.rb:109:in `call'\n/opt/rh/ruby193/root/usr/share/gems/gems/daemons-1.1.4/lib/daemons/cmdline.rb:109:in `catch_exceptions'\n/opt/rh/ruby193/root/usr/share/gems/gems/daemons-1.1.4/lib/daemons.rb:194:in `run_proc'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/command.rb:87:in `run_process'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/command.rb:80:in `block in daemonize'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/command.rb:78:in `times'\n/opt/rh/ruby193/root/usr/share/gems/gems/delayed_job-3.0.2/lib/delayed/command.rb:78:in `daemonize'\nscript/delayed_job:5:in `<main>'"]}, u'progress': None, u'pending?': False, u'id': 2}

It takes candlepin another hour or two to finish importing this manifest.

Version-Release number of selected component (if applicable):
The bug was discovered with SAM-1.3 but should be present in current SAT6 as well.

How reproducible:
Always.

Steps to Reproduce:
1. Upload manifest with lots of subscriptions, subscribe systems
2. Upload renewed manifest with API call
3. Try following job status

Actual results:
Job ends with timeout after 5 minutes

Expected results:
Job persists in 'running' state while candlepin performs manifest import and finishes with normal result.

Additional info:

Comment 1 RHEL Program Management 2013-11-22 14:54:11 UTC
Since this issue was entered in Red Hat Bugzilla, the release flag has been
set to ? to ensure that it is properly evaluated for this release.

Comment 3 Bryan Kearney 2014-04-24 15:26:54 UTC
Can you share hte manifest or the account?

Comment 4 Mike McCune 2014-06-16 19:54:30 UTC
this no longer occurs.  please re-open if you are still seeing this.


Note You need to log in before you can comment on or make changes to this bug.