Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 1131062

Summary: Cancellation of the puppet repo sync task during metadata retrieval leads to the failure
Product: [Retired] Pulp Reporter: Ina Panova <ipanova>
Component: async/tasksAssignee: Chris Duryee <cduryee>
Status: CLOSED CURRENTRELEASE QA Contact: Ina Panova <ipanova>
Severity: medium Docs Contact:
Priority: medium    
Version: unspecifiedCC: cduryee, rbarlow
Target Milestone: ---Keywords: Triaged
Target Release: 2.5.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2014-11-24 21:33:36 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Ina Panova 2014-08-18 12:49:39 UTC
Description of problem:
During verification of this https://bugzilla.redhat.com/show_bug.cgi?id=1094470 noticed that cancellation of puppet repo sync task during metadata retrieval leads to 'failed' task.
Moreover cancelling this running task first shows 'canceled' but after several seconds it transits to 'failed'.

[root@ec2-54-216-195-222 ~]# pulp-admin -u admin -p admin tasks list
+----------------------------------------------------------------------+
                                 Tasks
+----------------------------------------------------------------------+
Operations:  sync
Resources:   puppet-repo (repository)
State:       Running
Start Time:  2014-08-18T12:43:36Z
Finish Time: Incomplete
Task Id:     d0e780af-786a-4876-85e3-5b0b65f8eb60

[root@ec2-54-216-195-222 ~]# pulp-admin -u admin -p admin tasks cancel --task-id d0e780af-786a-4876-85e3-5b0b65f8eb60
Task cancel is successfully initiated.

[root@ec2-54-216-195-222 ~]# pulp-admin -u admin -p admin tasks list
+----------------------------------------------------------------------+
                                 Tasks
+----------------------------------------------------------------------+
Operations:  sync
Resources:   puppet-repo (repository)
State:       Cancelled
Start Time:  2014-08-18T12:43:36Z
Finish Time: Incomplete
Task Id:     d0e780af-786a-4876-85e3-5b0b65f8eb60

[root@ec2-54-216-195-222 ~]# pulp-admin -u admin -p admin tasks list
+----------------------------------------------------------------------+
                                 Tasks
+----------------------------------------------------------------------+

Operations:  sync
Resources:   puppet-repo (repository)
State:       Failed
Start Time:  2014-08-18T12:43:36Z
Finish Time: 2014-08-18T12:44:02Z
Task Id:     d0e780af-786a-4876-85e3-5b0b65f8eb60

Aug 18 12:43:36 ec2-54-216-195-222 pulp: celery.worker.strategy:INFO: Received task: pulp.server.tasks.repository.sync_with_auto_publish[d0e780af-786a-4876-85e3-5b0b65f8eb60]
Aug 18 12:43:36 ec2-54-216-195-222 pulp: celery.worker.strategy:INFO: Received task: pulp.server.async.tasks._queue_release_resource[b3e0df3d-372c-4ee9-a6cb-3964a57a56fc]
Aug 18 12:43:36 ec2-54-216-195-222 pulp: requests.packages.urllib3.connectionpool:INFO: Starting new HTTPS connection (1): forge.puppetlabs.com
Aug 18 12:43:37 ec2-54-216-195-222 pulp: nectar.downloaders.threaded:ERROR: Download of https://forge.puppetlabs.com/PULP_MANIFEST failed with code 404: Not Found
Aug 18 12:43:37 ec2-54-216-195-222 pulp: pulp_puppet.plugins.importers.directory:ERROR: Fetch URL: https://forge.puppetlabs.com/PULP_MANIFEST failed: Not Found
Aug 18 12:43:37 ec2-54-216-195-222 pulp: pulp_puppet.plugins.importers.forge:INFO: Beginning sync for repository <puppet-repo>
Aug 18 12:43:37 ec2-54-216-195-222 pulp: pulp_puppet.plugins.importers.forge:INFO: Beginning metadata retrieval for repository <puppet-repo>
Aug 18 12:43:37 ec2-54-216-195-222 pulp: requests.packages.urllib3.connectionpool:INFO: Starting new HTTPS connection (1): forge.puppetlabs.com
Aug 18 12:43:49 ec2-54-216-195-222 pulp: pulp.server.async.tasks:INFO: Task canceled: d0e780af-786a-4876-85e3-5b0b65f8eb60.
Aug 18 12:43:49 ec2-54-216-195-222 pulp: celery.worker.control:INFO: Terminating d0e780af-786a-4876-85e3-5b0b65f8eb60 (15)
Aug 18 12:44:02 ec2-54-216-195-222 pulp: pulp_puppet.plugins.importers.forge:ERROR: Exception while retrieving metadata for repository <puppet-repo>
Aug 18 12:44:02 ec2-54-216-195-222 pulp: pulp_puppet.plugins.importers.forge:ERROR: Traceback (most recent call last):
Aug 18 12:44:02 ec2-54-216-195-222 pulp: pulp_puppet.plugins.importers.forge:ERROR:   File "/usr/lib/python2.7/site-packages/pulp_puppet/plugins/importers/forge.py", line 123, in _parse_metadata
Aug 18 12:44:02 ec2-54-216-195-222 pulp: pulp_puppet.plugins.importers.forge:ERROR:     metadata_json_docs = downloader.retrieve_metadata(self.progress_report)
Aug 18 12:44:02 ec2-54-216-195-222 pulp: pulp_puppet.plugins.importers.forge:ERROR:   File "/usr/lib/python2.7/site-packages/pulp_puppet/plugins/importers/downloaders/web.py", line 71, in retrieve_metadata
Aug 18 12:44:02 ec2-54-216-195-222 pulp: pulp_puppet.plugins.importers.forge:ERROR:     raise exceptions.FileRetrievalException(report.error_msg)
Aug 18 12:44:02 ec2-54-216-195-222 pulp: pulp_puppet.plugins.importers.forge:ERROR: FileRetrievalException: FileRetrievalException: None
Aug 18 12:44:02 ec2-54-216-195-222 pulp: celery.worker.job:ERROR: Task pulp.server.tasks.repository.sync_with_auto_publish[d0e780af-786a-4876-85e3-5b0b65f8eb60] raised unexpected: PulpExecutionException('Importer indicated a failed response',)
Aug 18 12:44:02 ec2-54-216-195-222 pulp: celery.worker.job:ERROR: Traceback (most recent call last):
Aug 18 12:44:02 ec2-54-216-195-222 pulp: celery.worker.job:ERROR:   File "/usr/lib/python2.7/site-packages/celery/app/trace.py", line 240, in trace_task
Aug 18 12:44:02 ec2-54-216-195-222 pulp: celery.worker.job:ERROR:     R = retval = fun(*args, **kwargs)
Aug 18 12:44:02 ec2-54-216-195-222 pulp: celery.worker.job:ERROR:   File "/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py", line 305, in __call__
Aug 18 12:44:02 ec2-54-216-195-222 pulp: celery.worker.job:ERROR:     return super(Task, self).__call__(*args, **kwargs)
Aug 18 12:44:02 ec2-54-216-195-222 pulp: celery.worker.job:ERROR:   File "/usr/lib/python2.7/site-packages/celery/app/trace.py", line 437, in __protected_call__
Aug 18 12:44:02 ec2-54-216-195-222 pulp: celery.worker.job:ERROR:     return self.run(*args, **kwargs)
Aug 18 12:44:02 ec2-54-216-195-222 pulp: celery.worker.job:ERROR:   File "/usr/lib/python2.7/site-packages/pulp/server/tasks/repository.py", line 210, in sync_with_auto_publish
Aug 18 12:44:02 ec2-54-216-195-222 pulp: celery.worker.job:ERROR:     sync_result = managers.repo_sync_manager().sync(repo_id, sync_config_override=overrides)
Aug 18 12:44:02 ec2-54-216-195-222 pulp: celery.worker.job:ERROR:   File "/usr/lib/python2.7/site-packages/pulp/server/managers/repo/sync.py", line 113, in sync
Aug 18 12:44:02 ec2-54-216-195-222 pulp: celery.worker.job:ERROR:     raise PulpExecutionException(_('Importer indicated a failed response'))
Aug 18 12:44:02 ec2-54-216-195-222 pulp: celery.worker.job:ERROR: PulpExecutionException: Importer indicated a failed response
Aug 18 12:44:02 ec2-54-216-195-222 pulp: celery.worker.strategy:INFO: Received task: pulp.server.async.tasks._release_resource[2bac1b8f-43ca-4639-8bf4-143489d192aa]
Aug 18 12:44:02 ec2-54-216-195-222 pulp: celery.worker.job:INFO: Task pulp.server.async.tasks._queue_release_resource[b3e0df3d-372c-4ee9-a6cb-3964a57a56fc] succeeded in 0.0584585529868s: None
Aug 18 12:44:02 ec2-54-216-195-222 pulp: celery.worker.job:INFO: Task pulp.server.async.tasks._release_resource[2bac1b8f-43ca-4639-8bf4-143489d192aa] succeeded in 0.0297118010058s: None


Version-Release number of selected component (if applicable):


How reproducible:


Steps to Reproduce:
1. create puppet repo with feed
2. sync repo
3. cancel sync during matadata retrieval

Actual results:
final task state 'failed'

Expected results:
final task state 'cancelled'

Additional info:

Comment 1 Ina Panova 2014-08-18 12:50:20 UTC
Version-Release number of selected component (if applicable):

2.4.1-0.1.alpha

Comment 2 Ina Panova 2014-08-20 13:25:20 UTC
Same traceback when a worker is gracefully shut down during metadata retrieval:

# systemctl stop pulp_worker-0
# pulp-admin -u admin -p admin tasks list
+----------------------------------------------------------------------+
                                 Tasks
+----------------------------------------------------------------------+


Operations:  sync
Resources:   pup1 (repository)
State:       Failed
Start Time:  2014-08-20T12:55:44Z
Finish Time: 2014-08-20T12:56:09Z
Task Id:     945afdcb-3d69-4e1a-af5a-163766b474a4

# pulp-admin -u admin -p admin tasks details --task-id 945afdcb-3d69-4e1a-af5a-163766b474a4
+----------------------------------------------------------------------+
                              Task Details
+----------------------------------------------------------------------+

Operations:       sync
Resources:        pup1 (repository)
State:            Failed
Start Time:       2014-08-20T12:55:44Z
Finish Time:      2014-08-20T12:56:09Z
Result:           N/A
Task Id:          945afdcb-3d69-4e1a-af5a-163766b474a4
Progress Report:  
  Puppet Importer: 
    Metadata: 
      Current Query:        https://forge.puppetlabs.com/modules.json
      Error:                FileRetrievalException: None
      Error Message:        Error downloading metadata
      Execution Time:       24
      Query Finished Count: 0
      Query Total Count:    1
      State:                failed
      Traceback:            [[u'/usr/lib/python2.7/site-packages/pulp_puppet/plu
                            gins/importers/forge.py', 123, u'_parse_metadata',
                            u'metadata_json_docs =
                            downloader.retrieve_metadata(self.progress_report)']
                            ,
                            [u'/usr/lib/python2.7/site-packages/pulp_puppet/plug
                            ins/importers/downloaders/web.py', 71,
                            u'retrieve_metadata', u'raise
                            exceptions.FileRetrievalException(report.error_msg)'
                            ]]
    Modules:  
      Error:             None
      Error Count:       None
      Error Message:     None
      Execution Time:    None
      Finished Count:    None
      Individual Errors: 
      State:             not-started
      Total Count:       None
      Traceback:         None
Traceback:        Traceback (most recent call last):   File
                  "/usr/lib/python2.7/site-packages/celery/app/trace.py", line
                  240, in trace_task     R = retval = fun(*args, **kwargs)  
                  File
                  "/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py",
                  line 305, in __call__     return super(Task,
                  self).__call__(*args, **kwargs)   File
                  "/usr/lib/python2.7/site-packages/celery/app/trace.py", line
                  437, in __protected_call__     return self.run(*args,
                  **kwargs)   File
                  "/usr/lib/python2.7/site-packages/pulp/server/tasks/repository
                  .py", line 210, in sync_with_auto_publish     sync_result =
                  managers.repo_sync_manager().sync(repo_id,
                  sync_config_override=overrides)   File
                  "/usr/lib/python2.7/site-packages/pulp/server/managers/repo/sy
                  nc.py", line 113, in sync     raise
                  PulpExecutionException(_('Importer indicated a failed
                  response')) PulpExecutionException: Importer indicated a
                  failed response

Comment 3 Chris Duryee 2014-08-28 00:30:22 UTC
https://github.com/pulp/pulp_puppet/pull/134

Comment 4 Chris Duryee 2014-08-28 13:38:21 UTC
merged to 2.4-dev and master

also, good catch on this bz:)

Comment 5 Chris Duryee 2014-09-30 13:52:46 UTC
build: 2.5.0-0.6.beta

Comment 6 Ina Panova 2014-10-01 09:56:13 UTC
Tested in pulp-2.5.0-0.6.beta
1)created puppet repo with feed
2) initiated sync
3) cancelled sync during metadata retrieval:

# pulp-admin -u admin -p admin tasks list
+----------------------------------------------------------------------+
                                 Tasks
+----------------------------------------------------------------------+

Operations:  sync
Resources:   pup (repository)
State:       Running
Start Time:  2014-10-01T09:48:54Z
Finish Time: Incomplete
Task Id:     f6022510-7180-42d2-b3d7-03377229d5d6

# pulp-admin -u admin -p admin tasks cancel --task-id f6022510-7180-42d2-b3d7-03377229d5d6
Task cancel is successfully initiated.

[root@ec2-54-217-44-62 ~]# pulp-admin -u admin -p admin repo list
+----------------------------------------------------------------------+
                              Repositories
+----------------------------------------------------------------------+

Id:                  pup
Display Name:        pup
Description:         None
Content Unit Counts: 


[root@ec2-54-217-44-62 ~]# pulp-admin -u admin -p admin tasks details --task-id f6022510-7180-42d2-b3d7-03377229d5d6
+----------------------------------------------------------------------+
                              Task Details
+----------------------------------------------------------------------+

Operations:       sync
Resources:        pup (repository)
State:            Cancelled
Start Time:       2014-10-01T09:48:54Z
Finish Time:      Incomplete
Result:           N/A
Task Id:          f6022510-7180-42d2-b3d7-03377229d5d6
Progress Report:  
  Puppet Importer: 
    Metadata: 
      Current Query:        https://forge.puppetlabs.com/modules.json
      Error:                None
      Error Message:        None
      Execution Time:       None
      Query Finished Count: 0
      Query Total Count:    1
      State:                running
      Traceback:            None
    Modules:  
      Error:             None
      Error Count:       None
      Error Message:     None
      Execution Time:    None
      Finished Count:    None
      Individual Errors: 
      State:             not-started
      Total Count:       None
      Traceback:         None


Moving to Verified.