Project

Profile

Help

Issue #1645

The DownloadStep does not guard against cancel() being called before initialize()

Added by rbarlow almost 5 years ago. Updated over 1 year ago.

Status:
CLOSED - CURRENTRELEASE
Priority:
Normal
Assignee:
Category:
-
Sprint/Milestone:
-
Start date:
Due date:
Estimated time:
Severity:
2. Medium
Version:
Platform Release:
2.8.0
OS:
Triaged:
Yes
Groomed:
No
Sprint Candidate:
No
Tags:
Pulp 2
Sprint:
Quarter:

Description

I started a v2 sync and canceled it as fast as I could. By looking at the tasks collection, I can see that it canceled during the metadata fetching step. The following traceback appeared in the logs:

Feb 08 22:15:48 dev pulp[5686]: pulp.server.async.tasks:INFO: Task canceled: 8a0c6230-4314-4943-ba44-abd6ee2362ed.
Feb 08 22:15:48 dev pulp[5680]: celery.worker.control:INFO: Terminating 8a0c6230-4314-4943-ba44-abd6ee2362ed (15)
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080) 'TokenAuthDownloadStep' object has no attribute 'downloader'
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080) Traceback (most recent call last):
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)   File "/usr/lib/python2.7/site-packages/nectar/downloaders/threaded.py", line 229, in _fetch
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)     self.config.read_timeout))
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)   File "/usr/lib/python2.7/site-packages/requests/sessions.py", line 480, in get
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)     return self.request('GET', url, **kwargs)
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)   File "/usr/lib/python2.7/site-packages/requests/sessions.py", line 468, in request
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)     resp = self.send(prep, **send_kwargs)
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)   File "/usr/lib/python2.7/site-packages/requests/sessions.py", line 576, in send
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)     r = adapter.send(request, **kwargs)
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)   File "/usr/lib/python2.7/site-packages/requests/adapters.py", line 376, in send
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)     timeout=timeout
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)   File "/usr/lib/python2.7/site-packages/requests/packages/urllib3/connectionpool.py", line 559, in urlopen
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)     body=body, headers=headers)
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)   File "/usr/lib/python2.7/site-packages/requests/packages/urllib3/connectionpool.py", line 376, in _make_request
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)     httplib_response = conn.getresponse(buffering=True)
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)   File "/usr/lib64/python2.7/httplib.py", line 1132, in getresponse
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)     response.begin()
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)   File "/usr/lib64/python2.7/httplib.py", line 453, in begin
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)     version, status, reason = self._read_status()
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)   File "/usr/lib64/python2.7/httplib.py", line 409, in _read_status
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)     line = self.fp.readline(_MAXLINE + 1)
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)   File "/usr/lib64/python2.7/socket.py", line 480, in readline
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)     data = self._sock.recv(self._rbufsize)
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)   File "/usr/lib64/python2.7/ssl.py", line 734, in recv
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)     return self.read(buflen)
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)   File "/usr/lib64/python2.7/ssl.py", line 621, in read
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)     v = self._sslobj.read(len or 1024)
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)   File "/home/vagrant/devel/pulp/server/pulp/server/async/tasks.py", line 641, in sigterm_handler
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)     handler()
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)   File "/home/vagrant/devel/pulp_docker/plugins/pulp_docker/plugins/importers/importer.py", line 95, in cancel_sync_repo
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)     self.sync_step.cancel()
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)   File "/home/vagrant/devel/pulp/server/pulp/plugins/util/publish_step.py", line 408, in cancel
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)     step.cancel()
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)   File "/home/vagrant/devel/pulp/server/pulp/plugins/util/publish_step.py", line 1156, in cancel
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080)     self.downloader.cancel()
Feb 08 22:15:48 dev pulp[6093]: nectar.downloaders.threaded:ERROR: (6093-10080) AttributeError: 'TokenAuthDownloadStep' object has no attribute 'downloader'
Feb 08 22:15:48 dev pulp[6093]: pulp.server.async.tasks:INFO: Task failed : [8a0c6230-4314-4943-ba44-abd6ee2362ed]
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080) Task pulp.server.managers.repo.sync.sync[8a0c6230-4314-4943-ba44-abd6ee2362ed] raised unexpected: IOError("'TokenAuthDownloadStep' object has no attribute 'downloader'
",)
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080) Traceback (most recent call last):
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)   File "/usr/lib/python2.7/site-packages/celery/app/trace.py", line 240, in trace_task
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)     R = retval = fun(*args, **kwargs)
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)   File "/home/vagrant/devel/pulp/server/pulp/server/async/tasks.py", line 473, in __call__
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)     return super(Task, self).__call__(*args, **kwargs)
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)   File "/home/vagrant/devel/pulp/server/pulp/server/async/tasks.py", line 103, in __call__
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)     return super(PulpTask, self).__call__(*args, **kwargs)
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)   File "/usr/lib/python2.7/site-packages/celery/app/trace.py", line 437, in __protected_call__
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)     return self.run(*args, **kwargs)
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)   File "/home/vagrant/devel/pulp/server/pulp/server/controllers/repository.py", line 757, in sync
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)     sync_report = sync_repo(transfer_repo, conduit, call_config)
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)   File "/home/vagrant/devel/pulp/server/pulp/server/async/tasks.py", line 658, in wrap_f
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)     return f(*args, **kwargs)
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)   File "/home/vagrant/devel/pulp_docker/plugins/pulp_docker/plugins/importers/importer.py", line 85, in sync_repo
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)     return self.sync_step.process_lifecycle()
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)   File "/home/vagrant/devel/pulp/server/pulp/plugins/util/publish_step.py", line 562, in process_lifecycle
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)     super(PluginStep, self).process_lifecycle()
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)   File "/home/vagrant/devel/pulp/server/pulp/plugins/util/publish_step.py", line 159, in process_lifecycle
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)     step.process()
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)   File "/home/vagrant/devel/pulp/server/pulp/plugins/util/publish_step.py", line 249, in process
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)     self._process_block()
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)   File "/home/vagrant/devel/pulp/server/pulp/plugins/util/publish_step.py", line 293, in _process_block
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)     self.process_main()
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)   File "/home/vagrant/devel/pulp_docker/plugins/pulp_docker/plugins/importers/sync.py", line 229, in process_main
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)     digest, manifest = self.parent.index_repository.get_manifest(tag)
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)   File "/home/vagrant/devel/pulp_docker/plugins/pulp_docker/plugins/registry.py", line 365, in get_manifest
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)     headers, manifest = self._get_path(path)
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)   File "/home/vagrant/devel/pulp_docker/plugins/pulp_docker/plugins/registry.py", line 423, in _get_path
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080)     raise IOError(report.error_msg)
Feb 08 22:15:48 dev pulp[5680]: celery.worker.job:ERROR: (5680-10080) IOError: 'TokenAuthDownloadStep' object has no attribute 'downloader'

IMO this should be fixed before releasing 2.0.0.

Associated revisions

Revision d1273b45 View on GitHub
Added by rbarlow almost 5 years ago

Return gracefully when DownloadStep.cancel() is called before init.

DownloadStep.cancel() had unconditionally called self.downloader.cancel(), which caused an AttributeError if cancel() was called before intialize(). This would happen, for example, if a pulp-docker sync were canceled during metadata fetching.

https://pulp.plan.io/issues/1645

fixes #1645

Revision d1273b45 View on GitHub
Added by rbarlow almost 5 years ago

Return gracefully when DownloadStep.cancel() is called before init.

DownloadStep.cancel() had unconditionally called self.downloader.cancel(), which caused an AttributeError if cancel() was called before intialize(). This would happen, for example, if a pulp-docker sync were canceled during metadata fetching.

https://pulp.plan.io/issues/1645

fixes #1645

History

#1 Updated by rbarlow almost 5 years ago

  • Subject changed from Canceling a v2 sync results in IOError: 'TokenAuthDownloadStep' object has no attribute 'downloader' to Canceling a v2 sync during manifest fetching results in IOError

#2 Updated by ipanova@redhat.com almost 5 years ago

there was a similar issue with puppet plugin maybe that will help https://bugzilla.redhat.com/show_bug.cgi?id=1131062

#3 Updated by rbarlow almost 5 years ago

  • Project changed from Docker Support to Pulp
  • Subject changed from Canceling a v2 sync during manifest fetching results in IOError to The DownloadStep does not guard against cancel() being called before initialize()
  • Status changed from NEW to ASSIGNED
  • Assignee set to rbarlow
  • Platform Release set to 2.8.0

This can be fixed by a simple if statement in steps.

#4 Updated by rbarlow almost 5 years ago

  • Status changed from ASSIGNED to POST
  • Triaged changed from No to Yes

#5 Updated by rbarlow almost 5 years ago

  • Status changed from POST to MODIFIED
  • % Done changed from 0 to 100

#6 Updated by dkliban@redhat.com almost 5 years ago

  • Status changed from MODIFIED to 5

#7 Updated by dkliban@redhat.com over 4 years ago

  • Status changed from 5 to CLOSED - CURRENTRELEASE

#8 Updated by bmbouter over 1 year ago

  • Tags Pulp 2 added

Please register to edit this issue

Also available in: Atom PDF