[Pulp-list] Running sync task with a finish time?

ben.stanley at exemail.com.au ben.stanley at exemail.com.au
Wed Jan 7 00:42:38 UTC 2015


Pulp version: 2.5.0-1.el7
It looks like there is a newer one, and it appears in my pulp system, but
yum only knows about the old one. It seems that the repodata/repomd.xml
doesn't know about it, and yum won't upgrade it. I will look into that.

Firstly, here is the information from
pulp-admin tasks list

Operations:  sync
Resources:   rhel-6-workstation-x86_64-debug (repository)
State:       Running
Start Time:  2015-01-05T22:58:04Z
Finish Time: 2015-01-05T22:49:54Z
Task ID:     fc0aba8d-a34f-4c24-9f1e-6120ee5dcf62

Looking at the logs reveals a few interesting things.
Jan  6 09:40:16 bumblebee pulp: celery.worker.strategy:INFO: Received
task:
pulp.server.tasks.repository.sync_with_auto_publish[fc0aba8d-a34f-4c24-9f1e-6120ee5dcf62]
Jan  6 09:49:54 bumblebee pulp: celery.worker.job:ERROR: Task
pulp.server.tasks.repository.sync_with_auto_publish[fc0aba8d-a34f-4c24-9f1e-6120ee5dcf62]
raised unexpected: CancelException()
Jan  6 09:49:54 bumblebee pulp: celery.worker.job:ERROR: Traceback (most
recent call last):
Jan  6 09:49:54 bumblebee pulp: celery.worker.job:ERROR:   File
"/usr/lib/python2.7/site-packages/celery/app/trace.py", line 240, in
trace_task
Jan  6 09:49:54 bumblebee pulp: celery.worker.job:ERROR:     R = retval =
fun(*args, **kwargs)
Jan  6 09:49:54 bumblebee pulp: celery.worker.job:ERROR:   File
"/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py", line 315,
in __call__
Jan  6 09:49:54 bumblebee pulp: celery.worker.job:ERROR:     return
super(Task, self).__call__(*args, **kwargs)
Jan  6 09:49:54 bumblebee pulp: celery.worker.job:ERROR:   File
"/usr/lib/python2.7/site-packages/celery/app/trace.py", line 437, in
__protected_call__
Jan  6 09:49:54 bumblebee pulp: celery.worker.job:ERROR:     return
self.run(*args, **kwargs)
Jan  6 09:49:54 bumblebee pulp: celery.worker.job:ERROR:   File
"/usr/lib/python2.7/site-packages/pulp/server/tasks/repository.py", line
210, in sync_with_auto_publish
Jan  6 09:49:54 bumblebee pulp: celery.worker.job:ERROR:     sync_result =
managers.repo_sync_manager().sync(repo_id, sync_config_override=overrides)
Jan  6 09:49:54 bumblebee pulp: celery.worker.job:ERROR:   File
"/usr/lib/python2.7/site-packages/pulp/server/managers/repo/sync.py", line
109, in sync
Jan  6 09:49:54 bumblebee pulp: celery.worker.job:ERROR:     call_config)
Jan  6 09:49:54 bumblebee pulp: celery.worker.job:ERROR:   File
"/usr/lib/python2.7/site-packages/pulp/server/managers/repo/sync.py", line
157, in _do_sync
Jan  6 09:49:54 bumblebee pulp: celery.worker.job:ERROR:     sync_report =
sync_repo(transfer_repo, conduit, call_config)
Jan  6 09:49:54 bumblebee pulp: celery.worker.job:ERROR:   File
"/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py", line 470,
in wrap_f
Jan  6 09:49:54 bumblebee pulp: celery.worker.job:ERROR:     return
f(*args, **kwargs)
Jan  6 09:49:54 bumblebee pulp: celery.worker.job:ERROR:   File
"/usr/lib/python2.7/site-packages/pulp_rpm/plugins/importers/yum/importer.py",
line 67, in sync_repo
Jan  6 09:49:54 bumblebee pulp: celery.worker.job:ERROR:     report =
self._current_sync.run()
Jan  6 09:49:54 bumblebee pulp: celery.worker.job:ERROR:   File
"/usr/lib/python2.7/site-packages/pulp_rpm/plugins/importers/yum/sync.py",
line 159, in run
Jan  6 09:49:54 bumblebee pulp: celery.worker.job:ERROR:    
self.set_progress()
Jan  6 09:49:54 bumblebee pulp: celery.worker.job:ERROR:   File
"/usr/lib/python2.7/site-packages/pulp_rpm/plugins/importers/yum/sync.py",
line 73, in set_progress
Jan  6 09:49:54 bumblebee pulp: celery.worker.job:ERROR:     raise
CancelException
Jan  6 09:49:54 bumblebee pulp: celery.worker.job:ERROR: CancelException
Jan  6 09:49:55 bumblebee celery: reserved_resource_worker-0 at bumblebee ready.
Jan  6 09:49:55 bumblebee systemd: Stopped Pulp Worker #0.
Jan  6 09:51:19 bumblebee pulp: celery.worker.strategy:INFO: Received
task:
pulp.server.tasks.repository.sync_with_auto_publish[fc0aba8d-a34f-4c24-9f1e-6120ee5dcf62]
Jan  6 09:57:30 bumblebee pulp: pulp_rpm.plugins.importers.yum.sync:INFO:
Determining which units need to be downloaded.
Jan  6 09:57:45 bumblebee pulp: pulp.server.content.sources.model:ERROR:
source [rhel-7-workstation-rpms] not valid
Jan  6 09:57:45 bumblebee pulp: pulp.server.content.sources.model:ERROR:
Traceback (most recent call last):
Jan  6 09:57:45 bumblebee pulp: pulp.server.content.sources.model:ERROR:  
File
"/usr/lib/python2.7/site-packages/pulp/server/content/sources/model.py",
line 173, in is_valid
Jan  6 09:57:45 bumblebee pulp: pulp.server.content.sources.model:ERROR:  
  self.get_downloader()
Jan  6 09:57:45 bumblebee pulp: pulp.server.content.sources.model:ERROR:  
File
"/usr/lib/python2.7/site-packages/pulp/server/content/sources/model.py",
line 281, in get_downloader
Jan  6 09:57:45 bumblebee pulp: pulp.server.content.sources.model:ERROR:  
  return plugin.get_downloader(conduit, self.descriptor, self.base_url)
Jan  6 09:57:45 bumblebee pulp: pulp.server.content.sources.model:ERROR:  
File
"/usr/lib/python2.7/site-packages/pulp_rpm/plugins/catalogers/yum.py",
line 71, in get_downloader
Jan  6 09:57:45 bumblebee pulp: pulp.server.content.sources.model:ERROR:  
  return nectar_factory.create_downloader(url, self.nectar_config(config))
Jan  6 09:57:45 bumblebee pulp: pulp.server.content.sources.model:ERROR:  
File
"/usr/lib/python2.7/site-packages/pulp_rpm/plugins/catalogers/yum.py",
line 101, in nectar_config
Jan  6 09:57:45 bumblebee pulp: pulp.server.content.sources.model:ERROR:  
  return descriptor.nectar_config(config)
Jan  6 09:57:45 bumblebee pulp: pulp.server.content.sources.model:ERROR:  
File
"/usr/lib/python2.7/site-packages/pulp/server/content/sources/descriptor.py",
line 166, in nectar_config
Jan  6 09:57:45 bumblebee pulp: pulp.server.content.sources.model:ERROR:  
  return DownloaderConfig(**options)
Jan  6 09:57:45 bumblebee pulp: pulp.server.content.sources.model:ERROR:  
File "/usr/lib/python2.7/site-packages/nectar/config.py", line 131, in
__init__
Jan  6 09:57:45 bumblebee pulp: pulp.server.content.sources.model:ERROR:  
  self._process_ssl_settings()
Jan  6 09:57:45 bumblebee pulp: pulp.server.content.sources.model:ERROR:  
File "/usr/lib/python2.7/site-packages/nectar/config.py", line 160, in
_process_ssl_settings
Jan  6 09:57:45 bumblebee pulp: pulp.server.content.sources.model:ERROR:  
  raise AttributeError('Cannot read file: %s' % file_arg_value)
Jan  6 09:57:45 bumblebee pulp: pulp.server.content.sources.model:ERROR:
AttributeError: Cannot read file: /etc/rhsm/ca/redhat-uep.pem
Jan  6 09:57:45 bumblebee pulp: pulp_rpm.plugins.importers.yum.sync:INFO:
Downloading 0 RPMs.
Jan  6 09:57:54 bumblebee pulp:
pulp_rpm.plugins.importers.yum.repomd.alternate:INFO: The content
container reported: {'downloads': {}, 'total_sources': 0} for base URL:
https://cdn.redhat.com/content/dist/rhel/workstation/6/6Workstation/x86_64/debug/
Jan  6 09:57:54 bumblebee pulp: pulp_rpm.plugins.importers.yum.sync:INFO:
Downloading additional units.
Jan  6 09:57:54 bumblebee pulp:
requests.packages.urllib3.connectionpool:INFO: Starting new HTTPS
connection (1): cdn.redhat.com
Jan  6 09:57:56 bumblebee pulp:
requests.packages.urllib3.connectionpool:INFO: Starting new HTTPS
connection (1): cdn.redhat.com
Jan  6 09:58:04 bumblebee pulp: pulp_rpm.plugins.importers.yum.sync:INFO:
Sync complete.
Jan  6 10:54:13 bumblebee systemd: Stopped Pulp's Celerybeat.
Jan  6 10:54:13 bumblebee systemd: Stopping Pulp Celery Workers...
Jan  6 10:54:13 bumblebee systemd: Stopped Pulp Worker #11.
Jan  6 10:54:13 bumblebee systemd: Stopped Pulp Worker #10.
Jan  6 10:54:13 bumblebee systemd: Stopped Pulp Worker #9.
Jan  6 10:54:13 bumblebee systemd: Stopped Pulp Worker #8.
Jan  6 10:54:13 bumblebee systemd: Stopped Pulp Worker #6.
Jan  6 10:54:13 bumblebee systemd: Stopping Pulp Worker #0...
Jan  6 10:54:13 bumblebee celery: worker: Warm shutdown (MainProcess)
Jan  6 10:54:13 bumblebee systemd: Stopping Pulp Worker #2...
Jan  6 10:54:13 bumblebee systemd: Stopped Pulp Worker #4.
Jan  6 10:54:13 bumblebee systemd: Stopped Pulp Worker #5.
Jan  6 10:54:13 bumblebee systemd: Stopped Pulp Worker #7.
Jan  6 10:54:13 bumblebee systemd: Stopping Pulp Worker #1...
Jan  6 10:54:13 bumblebee systemd: Stopping Pulp Worker #3...
Jan  6 10:54:13 bumblebee celery: worker: Warm shutdown (MainProcess)
Jan  6 10:54:13 bumblebee celery: worker: Warm shutdown (MainProcess)
Jan  6 10:54:13 bumblebee celery: worker: Warm shutdown (MainProcess)
Jan  6 10:54:14 bumblebee pulp: celery.worker.job:ERROR: Task
pulp.server.tasks.repository.sync_with_auto_publish[fc0aba8d-a34f-4c24-9f1e-6120ee5dcf62]
raised unexpected: WorkerLostError('Worker exited prematurely: signal 15
(SIGTERM).',)
Jan  6 10:54:14 bumblebee pulp: celery.worker.job:ERROR: Traceback (most
recent call last):
Jan  6 10:54:14 bumblebee pulp: celery.worker.job:ERROR:   File
"/usr/lib64/python2.7/site-packages/billiard/pool.py", line 1169, in
mark_as_worker_lost
Jan  6 10:54:14 bumblebee pulp: celery.worker.job:ERROR:    
human_status(exitcode)),
Jan  6 10:54:14 bumblebee pulp: celery.worker.job:ERROR: WorkerLostError:
Worker exited prematurely: signal 15 (SIGTERM).
Jan  6 10:54:14 bumblebee pulp: celery.worker.job:ERROR: Task
pulp.server.tasks.repository.sync_with_auto_publish[e017724e-19c6-46ab-86fa-b75be5678292]
raised unexpected: WorkerLostError('Worker exited prematurely: signal 15
(SIGTERM).',)
Jan  6 10:54:14 bumblebee pulp: celery.worker.job:ERROR: Traceback (most
recent call last):
Jan  6 10:54:14 bumblebee pulp: celery.worker.job:ERROR:   File
"/usr/lib64/python2.7/site-packages/billiard/pool.py", line 1169, in
mark_as_worker_lost
Jan  6 10:54:14 bumblebee pulp: celery.worker.job:ERROR:    
human_status(exitcode)),
Jan  6 10:54:14 bumblebee pulp: celery.worker.job:ERROR: WorkerLostError:
Worker exited prematurely: signal 15 (SIGTERM).
Jan  6 10:54:14 bumblebee pulp: celery.worker.job:ERROR: Task
pulp.server.async.tasks._queue_release_resource[38662456-9269-466c-adaf-92325cc358c5]
raised unexpected: WorkerLostError('Worker exited prematurely: signal 15
(SIGTERM).',)
Jan  6 10:54:14 bumblebee pulp: celery.worker.job:ERROR: Traceback (most
recent call last):
Jan  6 10:54:14 bumblebee pulp: celery.worker.job:ERROR:   File
"/usr/lib64/python2.7/site-packages/billiard/pool.py", line 1169, in
mark_as_worker_lost
Jan  6 10:54:14 bumblebee pulp: celery.worker.job:ERROR: Task
pulp.server.async.tasks._queue_release_resource[9c075009-87ea-4f3a-a629-044d48d0b241]
raised unexpected: WorkerLostError('Worker exited prematurely: signal 15
(SIGTERM).',)
Jan  6 10:54:14 bumblebee pulp: celery.worker.job:ERROR:    
human_status(exitcode)),
Jan  6 10:54:14 bumblebee pulp: celery.worker.job:ERROR: WorkerLostError:
Worker exited prematurely: signal 15 (SIGTERM).
Jan  6 10:54:14 bumblebee pulp: celery.worker.job:ERROR: Traceback (most
recent call last):
Jan  6 10:54:14 bumblebee pulp: celery.worker.job:ERROR:   File
"/usr/lib64/python2.7/site-packages/billiard/pool.py", line 1169, in
mark_as_worker_lost
Jan  6 10:54:14 bumblebee pulp: celery.worker.job:ERROR:    
human_status(exitcode)),
Jan  6 10:54:14 bumblebee pulp: celery.worker.job:ERROR: WorkerLostError:
Worker exited prematurely: signal 15 (SIGTERM).
Jan  6 10:54:14 bumblebee celery:
reserved_resource_worker-0 at bumblebee.rydalmere.corpnet ready.
Jan  6 10:54:14 bumblebee celery:
reserved_resource_worker-2 at bumblebee.rydalmere.corpnet ready.
Jan  6 10:54:14 bumblebee celery:
reserved_resource_worker-1 at bumblebee.rydalmere.corpnet ready.
Jan  6 10:54:14 bumblebee celery:
reserved_resource_worker-3 at bumblebee.rydalmere.corpnet ready.
Jan  6 10:54:14 bumblebee systemd: Stopped Pulp Worker #1.
Jan  6 10:54:14 bumblebee systemd: Stopped Pulp Worker #2.
Jan  6 10:54:14 bumblebee systemd: Stopped Pulp Worker #3.
Jan  6 10:54:14 bumblebee systemd: Stopped Pulp Worker #0.
Jan  6 10:54:14 bumblebee systemd: Stopped Pulp Celery Workers.

Note that the timestamps in the log are in localtime, which is currently Z+11

I have not included the complete log, and not everything makes sense, but:
1) It appears that the task ID has been started twice.
2) The first run of the task completed with an error.
3) Somewhere in there pulp was stopped and re-started.
4) Task final state is Cancelled, I suspect by re-starting pulp (again).

I will now focus on cancelling all stuck tasks and running a sync on my
pulp repository so that I can upgrade pulp to 2.5.1.

> Ben,
>
> A running task should not have a finish time. What version of pulp are you
> using?
>
> It would be helpful to see all of the log output related to a specific
> task where you saw this behavior. You can probably grep the system log the
> task ID to find what we need.
>
> Here is info about where pulp logs things:
> https://pulp-user-guide.readthedocs.org/en/latest/troubleshooting.html#logging
>
> Does the task eventually move to a completed state?
>
> Thanks,
> Michael
>
> ----- Original Message -----
> From: "Ben Stanley" <Ben.Stanley at exemail.com.au>
> To: pulp-list at redhat.com
> Sent: Tuesday, January 6, 2015 5:37:35 AM
> Subject: [Pulp-list] Running sync task with a finish time?
>
> In the output from pulp-admin tasks list, I have observed tasks that are
> in
> the Running state, but have a Finish Time.
>
> Most Running tasks have a Finish Time of Incomplete, and this seems
> sensible. Under what circumstances should a Running task have a finite
> Finish Time? Is it an estimated time of completion?
>
> Ben.
>
>
> _______________________________________________
> Pulp-list mailing list
> Pulp-list at redhat.com
> https://www.redhat.com/mailman/listinfo/pulp-list
>





More information about the Pulp-list mailing list