Issue #4958
Updated by amacdona@redhat.com almost 5 years ago
I wasn't able to replicate this personally, but a user reported this error while doing a docker sync from https://registry.hub.docker.com gitlab/gitlab-ee
<pre>
Jun 11 01:01:58 00000000000000 pulp: celery.worker.strategy:INFO: Received task: pulp.server.controllers.repository.queue_download_deferred[20e513fd-be55-4269-a64b-4cc020ed9869]
Jun 11 01:01:58 00000000000000 pulp: celery.worker.strategy:INFO: Received task: pulp.server.controllers.repository.download_deferred[e473501d-0d86-4171-8cd3-99fa1dae7f20]
Jun 11 01:01:58 00000000000000 pulp: celery.app.trace:INFO: [20e513fd] Task pulp.server.controllers.repository.queue_download_deferred[20e513fd-be55-4269-a64b-4cc020ed9869] succeeded in 0.0474473450013s: None
Jun 11 01:01:59 00000000000000 pulp: celery.app.trace:INFO: [e473501d] Task pulp.server.controllers.repository.download_deferred[e473501d-0d86-4171-8cd3-99fa1dae7f20] succeeded in 1.01020334501s: None
Jun 11 01:06:47 00000000000000 puppet-agent[45956]: Applied catalog in 0.39 seconds
Jun 11 01:11:58 00000000000000 pulp: celery.beat:INFO: Scheduler: Sending due task download_deferred_content (pulp.server.controllers.repository.queue_download_deferred)
Jun 11 01:11:58 00000000000000 pulp: celery.worker.strategy:INFO: Received task: pulp.server.controllers.repository.queue_download_deferred[d7752d41-29df-4f50-9aca-5552fba961e3]
Jun 11 01:11:58 00000000000000 pulp: celery.worker.strategy:INFO: Received task: pulp.server.controllers.repository.download_deferred[b5f5c1ec-6b62-4eef-b788-2787d8ea6878]
Jun 11 01:11:58 00000000000000 pulp: celery.app.trace:ERROR: [d7752d41] (13092-20320) Task pulp.server.controllers.repository.queue_download_deferred[d7752d41-29df-4f50-9aca-5552fba961e3] raised unexpected: DuplicateKeyError(u'E11000 duplicate key error collection: pulp_database.task_status index: task_id_-1 dup key: { : "b5f5c1ec-6b62-4eef-b788-2787d8ea6878" }',)
Jun 11 01:11:58 00000000000000 pulp: celery.app.trace:ERROR: [d7752d41] (13092-20320) Traceback (most recent call last):
Jun 11 01:11:58 00000000000000 pulp: celery.app.trace:ERROR: [d7752d41] (13092-20320) File "/usr/lib/python2.7/site-packages/celery/app/trace.py", line 367, in trace_task
Jun 11 01:11:58 00000000000000 pulp: celery.app.trace:ERROR: [d7752d41] (13092-20320) R = retval = fun(*args, **kwargs)
Jun 11 01:11:58 00000000000000 pulp: celery.app.trace:ERROR: [d7752d41] (13092-20320) File "/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py", line 107, in __call__
Jun 11 01:11:58 00000000000000 pulp: celery.app.trace:ERROR: [d7752d41] (13092-20320) return super(PulpTask, self).__call__(*args, **kwargs)
Jun 11 01:11:58 00000000000000 pulp: celery.app.trace:ERROR: [d7752d41] (13092-20320) File "/usr/lib/python2.7/site-packages/celery/app/trace.py", line 622, in __protected_call__
Jun 11 01:11:58 00000000000000 pulp: celery.app.trace:ERROR: [d7752d41] (13092-20320) return self.run(*args, **kwargs)
Jun 11 01:11:58 00000000000000 pulp: celery.app.trace:ERROR: [d7752d41] (13092-20320) File "/usr/lib/python2.7/site-packages/pulp/server/controllers/repository.py", line 1362, in queue_download_deferred
Jun 11 01:11:58 00000000000000 pulp: celery.app.trace:ERROR: [d7752d41] (13092-20320) download_deferred.apply_async(tags=task_tags)
Jun 11 01:11:58 00000000000000 pulp: celery.app.trace:ERROR: [d7752d41] (13092-20320) File "/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py", line 491, in apply_async
Jun 11 01:11:58 00000000000000 pulp: celery.app.trace:ERROR: [d7752d41] (13092-20320) 'spawned_tasks', 'traceback'])
Jun 11 01:11:58 00000000000000 pulp: celery.app.trace:ERROR: [d7752d41] (13092-20320) File "/usr/lib/python2.7/site-packages/pulp/server/db/model/__init__.py", line 566, in save_with_set_on_insert
Jun 11 01:11:58 00000000000000 pulp: celery.app.trace:ERROR: [d7752d41] (13092-20320) TaskStatus._get_collection().update({'task_id': task_id}, update, upsert=True)
Jun 11 01:11:58 00000000000000 pulp: celery.app.trace:ERROR: [d7752d41] (13092-20320) File "/usr/lib64/python2.7/site-packages/pymongo/collection.py", line 2232, in update
Jun 11 01:11:58 00000000000000 pulp: celery.app.trace:ERROR: [d7752d41] (13092-20320) check_keys, multi, manipulate, write_concern)
Jun 11 01:11:58 00000000000000 pulp: celery.app.trace:ERROR: [d7752d41] (13092-20320) File "/usr/lib64/python2.7/site-packages/pymongo/collection.py", line 710, in _update
Jun 11 01:11:58 00000000000000 pulp: celery.app.trace:ERROR: [d7752d41] (13092-20320) _check_write_command_response([(0, result)])
Jun 11 01:11:58 00000000000000 pulp: celery.app.trace:ERROR: [d7752d41] (13092-20320) File "/usr/lib64/python2.7/site-packages/pymongo/helpers.py", line 300, in _check_write_command_response
Jun 11 01:11:58 00000000000000 pulp: celery.app.trace:ERROR: [d7752d41] (13092-20320) raise DuplicateKeyError(error.get("errmsg"), 11000, error)
Jun 11 01:11:58 00000000000000 pulp: celery.app.trace:ERROR: [d7752d41] (13092-20320) DuplicateKeyError: E11000 duplicate key error collection: pulp_database.task_status index: task_id_-1 dup key: { : "b5f5c1ec-6b62-4eef-b788-2787d8ea6878" }
Jun 11 01:11:59 00000000000000 pulp: celery.app.trace:INFO: [b5f5c1ec] Task pulp.server.controllers.repository.download_deferred[b5f5c1ec-6b62-4eef-b788-2787d8ea6878] succeeded in 1.011006154s: None
Jun 11 01:21:58 00000000000000 pulp: celery.beat:INFO: Scheduler: Sending due task download_deferred_content (pulp.server.controllers.repository.queue_download_deferred)
Jun 11 01:21:58 00000000000000 pulp: celery.worker.strategy:INFO: Received task: pulp.server.controllers.repository.queue_download_deferred[021ed3ae-efe9-49ea-83e7-6761d96b6af0]
</pre>
I assume there isn't a problem other than the alarming logging, it looks like the same task was queued twice and one of them failed, one of them succeeded (both with same ID)
.