Actions
Issue #6589
closed
Issues synching large Redhat repos
Status:
CLOSED - DUPLICATE
Priority:
Normal
Assignee:
-
Sprint/Milestone:
-
Start date:
Due date:
Estimated time:
Severity:
2. Medium
Version:
Platform Release:
OS:
Triaged:
No
Groomed:
No
Sprint Candidate:
No
Tags:
Sprint:
Quarter:
Description
Hi
I have found issues when synching large repos with RedHat when using Pulp 3.2 and 3.3 on RHEL7. Some examples of the repos are:
- https://cdn.redhat.com/content/dist/rhel/server/7/7Server/x86_64/debug
- https://cdn.redhat.com/content/dist/rhel/server/7/7Server/x86_64/os
If I re kick off the download Pulp in some cases manage to finish the repo download. In the cases below the download failed again shortly afterwards. These logs are where there is where the server has direct access to the Internet. It also seems like it is random files pulp gets stuck on, becase sometimes the sync can run for a long time before it fails. Othertimes quite quickly.
In either case I seem to see:
- A socket read timeout
- A server disconnected error
One thing I'm not sure on is does Pulp 3 retry a connection when it is dropped? Or is it able to move onto the next file if a problem is found, and then log the files it failed to download?
Below is what happened when I tried to download from the debug repo:
{
"pulp_href": "/pulp/api/v3/tasks/11b53226-941a-4708-800a-58c1af19aa63/",
"pulp_created": "2020-04-24T09:30:21.775169Z",
"state": "failed",
"name": "pulp_rpm.app.tasks.synchronizing.synchronize",
"started_at": "2020-04-24T09:30:21.902780Z",
"finished_at": "2020-04-24T10:19:09.519158Z",
"error": {
"traceback": " File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/worker.py\", line 886, in perform_job\n rv = job.perform()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py\", line 664, in perform\n self._result = self._execute()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py\", line 670, in _execute\n return self.func(*self.args, **self.kwargs)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulp_rpm/app/tasks/synchronizing.py\", line 167, in synchronize\n dv.create()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/declarative_version.py\", line 149, in create\n loop.run_until_complete(pipeline)\n File \"/usr/lib64/python3.6/asyncio/base_events.py\", line 484, in run_until_complete\n return future.result()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/api.py\", line 228, in create_pipeline\n await asyncio.gather(*futures)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/api.py\", line 43, in __call__\n await self.run()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py\", line 132, in run\n pb.done += task.result() # download_count\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py\", line 157, in _handle_content_unit\n await asyncio.gather(*downloaders_for_content)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/models.py\", line 81, in download\n download_result = await downloader.run(extra_data=self.extra_data)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/download/base.py\", line 221, in run\n return await self._run(extra_data=extra_data)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/backoff/_async.py\", line 133, in retry\n ret = await target(*args, **kwargs)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/download/http.py\", line 186, in _run\n to_return = await self._handle_response(response)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/download/http.py\", line 160, in _handle_response\n chunk = await response.content.read(1048576) # 1 megabyte\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/streams.py\", line 368, in read\n await self._wait('read')\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/streams.py\", line 296, in _wait\n await waiter\n",
"description": "Timeout on reading data from socket"
},
"worker": "/pulp/api/v3/workers/69f2d00a-a47a-492c-8f9e-55167b1a8c7c/",
"parent_task": null,
"child_tasks": [],
"task_group": null,
"progress_reports": [
{
"message": "Parsed Comps",
"code": "parsing.comps",
"state": "completed",
"total": 0,
"done": 0,
"suffix": null
},
{
"message": "Parsed Advisories",
"code": "parsing.advisories",
"state": "completed",
"total": 3611,
"done": 3611,
"suffix": null
},
{
"message": "Downloading Artifacts",
"code": "downloading.artifacts",
"state": "failed",
"total": null,
"done": 2622,
"suffix": null
},
{
"message": "Parsed Packages",
"code": "parsing.packages",
"state": "canceled",
"total": 9541,
"done": 5006,
"suffix": null
},
{
"message": "Downloading Metadata Files",
"code": "downloading.metadata",
"state": "canceled",
"total": null,
"done": 5,
"suffix": null
},
{
"message": "Associating Content",
"code": "associating.content",
"state": "canceled",
"total": null,
"done": 6000,
"suffix": null
}
],
"created_resources": [],
"reserved_resources_record": [
"/pulp/api/v3/remotes/rpm/rpm/a65d9b42-1289-4355-bc3a-5de4ae4c45c7/",
"/pulp/api/v3/repositories/rpm/rpm/9fff639e-55f2-42da-8539-d1e1b2dd1d52/"
]
},
Errors seen in /var/log/messages
Apr 24 11:19:09 pulpserver rq: pulp: rq.worker:ERROR: aiohttp.client_exceptions.ServerTimeoutError: Timeout on reading data from socket
Apr 24 11:19:09 pulpserver rq: Traceback (most recent call last):
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/worker.py", line 886, in perform_job
Apr 24 11:19:09 pulpserver rq: rv = job.perform()
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py", line 664, in perform
Apr 24 11:19:09 pulpserver rq: self._result = self._execute()
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py", line 670, in _execute
Apr 24 11:19:09 pulpserver rq: return self.func(*self.args, **self.kwargs)
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulp_rpm/app/tasks/synchronizing.py", line 167, in synchronize
Apr 24 11:19:09 pulpserver rq: dv.create()
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/declarative_version.py", line 149, in create
Apr 24 11:19:09 pulpserver rq: loop.run_until_complete(pipeline)
Apr 24 11:19:09 pulpserver rq: File "/usr/lib64/python3.6/asyncio/base_events.py", line 484, in run_until_complete
Apr 24 11:19:09 pulpserver rq: return future.result()
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/api.py", line 228, in create_pipeline
Apr 24 11:19:09 pulpserver rq: await asyncio.gather(*futures)
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/api.py", line 43, in __call__
Apr 24 11:19:09 pulpserver rq: await self.run()
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py", line 132, in run
Apr 24 11:19:09 pulpserver rq: pb.done += task.result() # download_count
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py", line 157, in _handle_content_unit
Apr 24 11:19:09 pulpserver rq: await asyncio.gather(*downloaders_for_content)
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/models.py", line 81, in download
Apr 24 11:19:09 pulpserver rq: download_result = await downloader.run(extra_data=self.extra_data)
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/download/base.py", line 221, in run
Apr 24 11:19:09 pulpserver rq: return await self._run(extra_data=extra_data)
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/backoff/_async.py", line 133, in retry
Apr 24 11:19:09 pulpserver rq: ret = await target(*args, **kwargs)
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/download/http.py", line 186, in _run
Apr 24 11:19:09 pulpserver rq: to_return = await self._handle_response(response)
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/download/http.py", line 160, in _handle_response
Apr 24 11:19:09 pulpserver rq: chunk = await response.content.read(1048576) # 1 megabyte
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/streams.py", line 368, in read
Apr 24 11:19:09 pulpserver rq: await self._wait('read')
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/streams.py", line 296, in _wait
Apr 24 11:19:09 pulpserver rq: await waiter
Apr 24 11:19:09 pulpserver rq: aiohttp.client_exceptions.ServerTimeoutError: Timeout on reading data from socket
Apr 24 11:19:09 pulpserver rq: Traceback (most recent call last):
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/worker.py", line 886, in perform_job
Apr 24 11:19:09 pulpserver rq: rv = job.perform()
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py", line 664, in perform
Apr 24 11:19:09 pulpserver rq: self._result = self._execute()
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py", line 670, in _execute
Apr 24 11:19:09 pulpserver rq: return self.func(*self.args, **self.kwargs)
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulp_rpm/app/tasks/synchronizing.py", line 167, in synchronize
Apr 24 11:19:09 pulpserver rq: dv.create()
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/declarative_version.py", line 149, in create
Apr 24 11:19:09 pulpserver rq: loop.run_until_complete(pipeline)
Apr 24 11:19:09 pulpserver rq: File "/usr/lib64/python3.6/asyncio/base_events.py", line 484, in run_until_complete
Apr 24 11:19:09 pulpserver rq: return future.result()
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/api.py", line 228, in create_pipeline
Apr 24 11:19:09 pulpserver rq: await asyncio.gather(*futures)
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/api.py", line 43, in __call__
Apr 24 11:19:09 pulpserver rq: await self.run()
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py", line 132, in run
Apr 24 11:19:09 pulpserver rq: pb.done += task.result() # download_count
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py", line 157, in _handle_content_unit
Apr 24 11:19:09 pulpserver rq: await asyncio.gather(*downloaders_for_content)
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/models.py", line 81, in download
Apr 24 11:19:09 pulpserver rq: download_result = await downloader.run(extra_data=self.extra_data)
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/download/base.py", line 221, in run
Apr 24 11:19:09 pulpserver rq: return await self._run(extra_data=extra_data)
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/backoff/_async.py", line 133, in retry
Apr 24 11:19:09 pulpserver rq: ret = await target(*args, **kwargs)
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/download/http.py", line 186, in _run
Apr 24 11:19:09 pulpserver rq: to_return = await self._handle_response(response)
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/download/http.py", line 160, in _handle_response
Apr 24 11:19:09 pulpserver rq: chunk = await response.content.read(1048576) # 1 megabyte
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/streams.py", line 368, in read
Apr 24 11:19:09 pulpserver rq: await self._wait('read')
Apr 24 11:19:09 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/streams.py", line 296, in _wait
Apr 24 11:19:09 pulpserver rq: await waiter
Apr 24 11:19:09 pulpserver rq: aiohttp.client_exceptions.ServerTimeoutError: Timeout on reading data from socket
Apr 24 11:19:10 pulpserver rq: pulp: rq.worker:INFO: Cleaning registries for queue: 14665@unallocated.barefruit.co.uk
Apr 24 11:19:10 pulpserver rq: pulp: rq.worker:INFO: 14665@unallocated.barefruit.co.uk: fbd49388-425a-4816-9fe6-d8e5451f254b
Apr 24 11:19:10 pulpserver rq: pulp: rq.worker:INFO: 14665@unallocated.barefruit.co.uk: Job OK (fbd49388-425a-4816-9fe6-d8e5451f254b)
When I tried to resync I got the following:
{
"pulp_href": "/pulp/api/v3/tasks/75013a27-43aa-4cf1-8ba8-43554168c9e3/",
"pulp_created": "2020-04-24T10:25:48.963795Z",
"state": "failed",
"name": "pulp_rpm.app.tasks.synchronizing.synchronize",
"started_at": "2020-04-24T10:25:49.160507Z",
"finished_at": "2020-04-24T12:22:39.109603Z",
"error": {
"traceback": " File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/worker.py\", line 886, in perform_job\n rv = job.perform()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py\", line 664, in perform\n self._result = self._execute()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py\", line 670, in _execute\n return self.func(*self.args, **self.kwargs)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulp_rpm/app/tasks/synchronizing.py\", line 167, in synchronize\n dv.create()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/declarative_version.py\", line 149, in create\n loop.run_until_complete(pipeline)\n File \"/usr/lib64/python3.6/asyncio/base_events.py\", line 484, in run_until_complete\n return future.result()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/api.py\", line 228, in create_pipeline\n await asyncio.gather(*futures)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/api.py\", line 43, in __call__\n await self.run()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py\", line 132, in run\n pb.done += task.result() # download_count\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py\", line 157, in _handle_content_unit\n await asyncio.gather(*downloaders_for_content)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/models.py\", line 81, in download\n download_result = await downloader.run(extra_data=self.extra_data)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/download/base.py\", line 221, in run\n return await self._run(extra_data=extra_data)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/backoff/_async.py\", line 133, in retry\n ret = await target(*args, **kwargs)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/download/http.py\", line 184, in _run\n async with self.session.get(self.url, proxy=self.proxy, auth=self.auth) as response:\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/client.py\", line 1012, in __aenter__\n self._resp = await self._coro\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/client.py\", line 504, in _request\n await resp.start(conn)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/client_reqrep.py\", line 847, in start\n message, payload = await self._protocol.read() # type: ignore # noqa\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/streams.py\", line 591, in read\n await self._waiter\n",
"description": ""
},
"worker": "/pulp/api/v3/workers/69f2d00a-a47a-492c-8f9e-55167b1a8c7c/",
"parent_task": null,
"child_tasks": [],
"task_group": null,
"progress_reports": [
{
"message": "Parsed Comps",
"code": "parsing.comps",
"state": "completed",
"total": 0,
"done": 0,
"suffix": null
},
{
"message": "Parsed Advisories",
"code": "parsing.advisories",
"state": "completed",
"total": 3611,
"done": 3611,
"suffix": null
},
{
"message": "Parsed Packages",
"code": "parsing.packages",
"state": "completed",
"total": 9541,
"done": 9541,
"suffix": null
},
{
"message": "Downloading Metadata Files",
"code": "downloading.metadata",
"state": "completed",
"total": null,
"done": 5,
"suffix": null
},
{
"message": "Downloading Artifacts",
"code": "downloading.artifacts",
"state": "failed",
"total": null,
"done": 6500,
"suffix": null
},
{
"message": "Associating Content",
"code": "associating.content",
"state": "canceled",
"total": null,
"done": 12500,
"suffix": null
}
],
"created_resources": [],
"reserved_resources_record": [
"/pulp/api/v3/remotes/rpm/rpm/a65d9b42-1289-4355-bc3a-5de4ae4c45c7/",
"/pulp/api/v3/repositories/rpm/rpm/9fff639e-55f2-42da-8539-d1e1b2dd1d52/"
]
},
The output from /var/log/messages
Apr 24 13:11:17 pulpserver rq: pulp: rq.worker:INFO: Cleaning registries for queue: resource-manager
Apr 24 13:13:18 pulpserver rq: pulp: rq.worker:INFO: Cleaning registries for queue: 14711@unallocated.barefruit.co.uk
Apr 24 13:22:39 pulpserver rq: pulp: rq.worker:ERROR: aiohttp.client_exceptions.ServerDisconnectedError
Apr 24 13:22:39 pulpserver rq: Traceback (most recent call last):
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/worker.py", line 886, in perform_job
Apr 24 13:22:39 pulpserver rq: rv = job.perform()
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py", line 664, in perform
Apr 24 13:22:39 pulpserver rq: self._result = self._execute()
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py", line 670, in _execute
Apr 24 13:22:39 pulpserver rq: return self.func(*self.args, **self.kwargs)
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulp_rpm/app/tasks/synchronizing.py", line 167, in synchronize
Apr 24 13:22:39 pulpserver rq: dv.create()
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/declarative_version.py", line 149, in create
Apr 24 13:22:39 pulpserver rq: loop.run_until_complete(pipeline)
Apr 24 13:22:39 pulpserver rq: File "/usr/lib64/python3.6/asyncio/base_events.py", line 484, in run_until_complete
Apr 24 13:22:39 pulpserver rq: return future.result()
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/api.py", line 228, in create_pipeline
Apr 24 13:22:39 pulpserver rq: await asyncio.gather(*futures)
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/api.py", line 43, in __call__
Apr 24 13:22:39 pulpserver rq: await self.run()
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py", line 132, in run
Apr 24 13:22:39 pulpserver rq: pb.done += task.result() # download_count
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py", line 157, in _handle_content_unit
Apr 24 13:22:39 pulpserver rq: await asyncio.gather(*downloaders_for_content)
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/models.py", line 81, in download
Apr 24 13:22:39 pulpserver rq: download_result = await downloader.run(extra_data=self.extra_data)
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/download/base.py", line 221, in run
Apr 24 13:22:39 pulpserver rq: return await self._run(extra_data=extra_data)
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/backoff/_async.py", line 133, in retry
Apr 24 13:22:39 pulpserver rq: ret = await target(*args, **kwargs)
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/download/http.py", line 184, in _run
Apr 24 13:22:39 pulpserver rq: async with self.session.get(self.url, proxy=self.proxy, auth=self.auth) as response:
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/client.py", line 1012, in __aenter__
Apr 24 13:22:39 pulpserver rq: self._resp = await self._coro
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/client.py", line 504, in _request
Apr 24 13:22:39 pulpserver rq: await resp.start(conn)
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/client_reqrep.py", line 847, in start
Apr 24 13:22:39 pulpserver rq: message, payload = await self._protocol.read() # type: ignore # noqa
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/streams.py", line 591, in read
Apr 24 13:22:39 pulpserver rq: await self._waiter
Apr 24 13:22:39 pulpserver rq: aiohttp.client_exceptions.ServerDisconnectedError
Apr 24 13:22:39 pulpserver rq: Traceback (most recent call last):
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/worker.py", line 886, in perform_job
Apr 24 13:22:39 pulpserver rq: rv = job.perform()
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py", line 664, in perform
Apr 24 13:22:39 pulpserver rq: self._result = self._execute()
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py", line 670, in _execute
Apr 24 13:22:39 pulpserver rq: return self.func(*self.args, **self.kwargs)
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulp_rpm/app/tasks/synchronizing.py", line 167, in synchronize
Apr 24 13:22:39 pulpserver rq: dv.create()
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/declarative_version.py", line 149, in create
Apr 24 13:22:39 pulpserver rq: loop.run_until_complete(pipeline)
Apr 24 13:22:39 pulpserver rq: File "/usr/lib64/python3.6/asyncio/base_events.py", line 484, in run_until_complete
Apr 24 13:22:39 pulpserver rq: return future.result()
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/api.py", line 228, in create_pipeline
Apr 24 13:22:39 pulpserver rq: await asyncio.gather(*futures)
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/api.py", line 43, in __call__
Apr 24 13:22:39 pulpserver rq: await self.run()
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py", line 132, in run
Apr 24 13:22:39 pulpserver rq: pb.done += task.result() # download_count
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py", line 157, in _handle_content_unit
Apr 24 13:22:39 pulpserver rq: await asyncio.gather(*downloaders_for_content)
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/models.py", line 81, in download
Apr 24 13:22:39 pulpserver rq: download_result = await downloader.run(extra_data=self.extra_data)
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/download/base.py", line 221, in run
Apr 24 13:22:39 pulpserver rq: return await self._run(extra_data=extra_data)
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/backoff/_async.py", line 133, in retry
Apr 24 13:22:39 pulpserver rq: ret = await target(*args, **kwargs)
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/download/http.py", line 184, in _run
Apr 24 13:22:39 pulpserver rq: async with self.session.get(self.url, proxy=self.proxy, auth=self.auth) as response:
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/client.py", line 1012, in __aenter__
Apr 24 13:22:39 pulpserver rq: self._resp = await self._coro
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/client.py", line 504, in _request
Apr 24 13:22:39 pulpserver rq: await resp.start(conn)
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/client_reqrep.py", line 847, in start
Apr 24 13:22:39 pulpserver rq: message, payload = await self._protocol.read() # type: ignore # noqa
Apr 24 13:22:39 pulpserver rq: File "/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/streams.py", line 591, in read
Apr 24 13:22:39 pulpserver rq: await self._waiter
Apr 24 13:22:39 pulpserver rq: aiohttp.client_exceptions.ServerDisconnectedError
For the OS repos I saw the following:
{
"pulp_href": "/pulp/api/v3/tasks/6639b9ee-3f64-4c8e-848c-4c9cff779b1c/",
"pulp_created": "2020-04-24T09:30:08.033791Z",
"state": "failed",
"name": "pulp_rpm.app.tasks.synchronizing.synchronize",
"started_at": "2020-04-24T09:30:08.150657Z",
"finished_at": "2020-04-24T10:40:19.555715Z",
"error": {
"traceback": " File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/worker.py\", line 886, in perform_job\n rv = job.perform()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py\", line 664, in perform\n self._result = self._execute()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py\", line 670, in _execute\n return self.func(*self.args, **self.kwargs)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulp_rpm/app/tasks/synchronizing.py\", line 167, in synchronize\n dv.create()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/declarative_version.py\", line 149, in create\n loop.run_until_complete(pipeline)\n File \"/usr/lib64/python3.6/asyncio/base_events.py\", line 484, in run_until_complete\n return future.result()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/api.py\", line 228, in create_pipeline\n await asyncio.gather(*futures)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/api.py\", line 43, in __call__\n await self.run()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py\", line 132, in run\n pb.done += task.result() # download_count\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py\", line 157, in _handle_content_unit\n await asyncio.gather(*downloaders_for_content)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/models.py\", line 81, in download\n download_result = await downloader.run(extra_data=self.extra_data)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/download/base.py\", line 221, in run\n return await self._run(extra_data=extra_data)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/backoff/_async.py\", line 133, in retry\n ret = await target(*args, **kwargs)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/download/http.py\", line 184, in _run\n async with self.session.get(self.url, proxy=self.proxy, auth=self.auth) as response:\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/client.py\", line 1012, in __aenter__\n self._resp = await self._coro\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/client.py\", line 504, in _request\n await resp.start(conn)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/client_reqrep.py\", line 847, in start\n message, payload = await self._protocol.read() # type: ignore # noqa\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/streams.py\", line 591, in read\n await self._waiter\n",
"description": ""
},
"worker": "/pulp/api/v3/workers/e1b73364-ddd2-43d7-8874-b30ad4adff88/",
"parent_task": null,
"child_tasks": [],
"task_group": null,
"progress_reports": [
{
"message": "Parsed Comps",
"code": "parsing.comps",
"state": "completed",
"total": 91,
"done": 91,
"suffix": null
},
{
"message": "Parsed Advisories",
"code": "parsing.advisories",
"state": "completed",
"total": 4325,
"done": 4325,
"suffix": null
},
{
"message": "Downloading Artifacts",
"code": "downloading.artifacts",
"state": "failed",
"total": null,
"done": 24696,
"suffix": null
},
{
"message": "Parsed Packages",
"code": "parsing.packages",
"state": "canceled",
"total": 28773,
"done": 27028,
"suffix": null
},
{
"message": "Downloading Metadata Files",
"code": "downloading.metadata",
"state": "canceled",
"total": null,
"done": 5,
"suffix": null
},
{
"message": "Associating Content",
"code": "associating.content",
"state": "canceled",
"total": null,
"done": 29032,
"suffix": null
}
],
"created_resources": [],
"reserved_resources_record": [
"/pulp/api/v3/repositories/rpm/rpm/169ae56e-08a5-4fdd-ac71-e8624ca442bb/",
"/pulp/api/v3/remotes/rpm/rpm/bf23c689-5e23-4286-91f0-48e6704083d4/"
]
}
and
{
"pulp_href": "/pulp/api/v3/tasks/5d420b1d-dcf0-40a3-b564-1fa2b78b1cc6/",
"pulp_created": "2020-04-24T10:45:59.167139Z",
"state": "failed",
"name": "pulp_rpm.app.tasks.synchronizing.synchronize",
"started_at": "2020-04-24T10:45:59.416371Z",
"finished_at": "2020-04-24T10:57:29.180060Z",
"error": {
"traceback": " File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/worker.py\", line 886, in perform_job\n rv = job.perform()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py\", line 664, in perform\n self._result = self._execute()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py\", line 670, in _execute\n return self.func(*self.args, **self.kwargs)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulp_rpm/app/tasks/synchronizing.py\", line 167, in synchronize\n dv.create()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/declarative_version.py\", line 149, in create\n loop.run_until_complete(pipeline)\n File \"/usr/lib64/python3.6/asyncio/base_events.py\", line 484, in run_until_complete\n return future.result()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/api.py\", line 228, in create_pipeline\n await asyncio.gather(*futures)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/api.py\", line 43, in __call__\n await self.run()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py\", line 132, in run\n pb.done += task.result() # download_count\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py\", line 157, in _handle_content_unit\n await asyncio.gather(*downloaders_for_content)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/models.py\", line 81, in download\n download_result = await downloader.run(extra_data=self.extra_data)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/download/base.py\", line 221, in run\n return await self._run(extra_data=extra_data)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/backoff/_async.py\", line 133, in retry\n ret = await target(*args, **kwargs)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/download/http.py\", line 184, in _run\n async with self.session.get(self.url, proxy=self.proxy, auth=self.auth) as response:\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/client.py\", line 1012, in __aenter__\n self._resp = await self._coro\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/client.py\", line 504, in _request\n await resp.start(conn)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/client_reqrep.py\", line 847, in start\n message, payload = await self._protocol.read() # type: ignore # noqa\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/streams.py\", line 591, in read\n await self._waiter\n",
"description": ""
},
"worker": "/pulp/api/v3/workers/e1b73364-ddd2-43d7-8874-b30ad4adff88/",
"parent_task": null,
"child_tasks": [],
"task_group": null,
"progress_reports": [
{
"message": "Parsed Comps",
"code": "parsing.comps",
"state": "completed",
"total": 91,
"done": 91,
"suffix": null
},
{
"message": "Parsed Advisories",
"code": "parsing.advisories",
"state": "completed",
"total": 4325,
"done": 4325,
"suffix": null
},
{
"message": "Downloading Artifacts",
"code": "downloading.artifacts",
"state": "failed",
"total": null,
"done": 475,
"suffix": null
},
{
"message": "Parsed Packages",
"code": "parsing.packages",
"state": "canceled",
"total": 28773,
"done": 28029,
"suffix": null
},
{
"message": "Downloading Metadata Files",
"code": "downloading.metadata",
"state": "canceled",
"total": null,
"done": 5,
"suffix": null
},
{
"message": "Associating Content",
"code": "associating.content",
"state": "canceled",
"total": null,
"done": 29500,
"suffix": null
}
],
"created_resources": [],
"reserved_resources_record": [
"/pulp/api/v3/repositories/rpm/rpm/169ae56e-08a5-4fdd-ac71-e8624ca442bb/",
"/pulp/api/v3/remotes/rpm/rpm/bf23c689-5e23-4286-91f0-48e6704083d4/"
]
},
If you need me to gather more logs or if there is a way to get file names being failed upon, then please let me know
Thanks
Matt
Related issues
Updated by ttereshc over 4 years ago
- Related to Task #6624: Document how Pulp handles the ServerDisconnectedError and why added
Updated by ttereshc over 4 years ago
Pulp 3 doesn't retry if the connection is dropped. I filed an issue #6624 to document that and why Pulp chooses not to.
How often do you see the problem? Do you think it was a temporary problem on the server side or do you get such bad experience frequently/consistently?
Thanks for the report!
Updated by mped over 4 years ago
Hi
I get the problem quite consistently and frequently, I tried on a different Internet connection too, and on different days. When I sync with pulp2 although some packages may get missed I am able to quickly grab these agian on another sync. On pulp 3 the problem was much worse.
Thanks
Matt
Updated by mped over 4 years ago
Hi
I just tried to carry on with a failed sync agian now, and it bombed out again quite quickly
{
"count": 7,
"next": null,
"previous": null,
"results": [
{
"pulp_href": "/pulp/api/v3/tasks/096a4235-e394-461b-929f-e22bf7a4a787/",
"pulp_created": "2020-04-30T17:15:59.356352Z",
"state": "failed",
"name": "pulp_rpm.app.tasks.synchronizing.synchronize",
"started_at": "2020-04-30T17:16:00.433322Z",
"finished_at": "2020-04-30T17:47:47.127061Z",
"error": {
"traceback": " File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/worker.py\", line 886, in perform_job\n rv = job.perform()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py\", line 664, in perform\n self._result = self._execute()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/rq/job.py\", line 670, in _execute\n return self.func(*self.args, **self.kwargs)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulp_rpm/app/tasks/synchronizing.py\", line 167, in synchronize\n dv.create()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/declarative_version.py\", line 149, in create\n loop.run_until_complete(pipeline)\n File \"/usr/lib64/python3.6/asyncio/base_events.py\", line 484, in run_until_complete\n return future.result()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/api.py\", line 228, in create_pipeline\n await asyncio.gather(*futures)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/api.py\", line 43, in __call__\n await self.run()\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py\", line 132, in run\n pb.done += task.result() # download_count\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py\", line 157, in _handle_content_unit\n await asyncio.gather(*downloaders_for_content)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/plugin/stages/models.py\", line 81, in download\n download_result = await downloader.run(extra_data=self.extra_data)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/download/base.py\", line 221, in run\n return await self._run(extra_data=extra_data)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/backoff/_async.py\", line 133, in retry\n ret = await target(*args, **kwargs)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/pulpcore/download/http.py\", line 184, in _run\n async with self.session.get(self.url, proxy=self.proxy, auth=self.auth) as response:\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/client.py\", line 1012, in __aenter__\n self._resp = await self._coro\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/client.py\", line 504, in _request\n await resp.start(conn)\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/client_reqrep.py\", line 847, in start\n message, payload = await self._protocol.read() # type: ignore # noqa\n File \"/usr/local/lib/pulp/lib64/python3.6/site-packages/aiohttp/streams.py\", line 591, in read\n await self._waiter\n",
"description": ""
},
"worker": "/pulp/api/v3/workers/e1b73364-ddd2-43d7-8874-b30ad4adff88/",
"parent_task": null,
"child_tasks": [],
"task_group": null,
"progress_reports": [
{
"message": "Parsed Comps",
"code": "parsing.comps",
"state": "completed",
"total": 91,
"done": 91,
"suffix": null
},
{
"message": "Downloading Metadata Files",
"code": "downloading.metadata",
"state": "completed",
"total": null,
"done": 5,
"suffix": null
},
{
"message": "Parsed Advisories",
"code": "parsing.advisories",
"state": "completed",
"total": 4330,
"done": 4330,
"suffix": null
},
{
"message": "Parsed Packages",
"code": "parsing.packages",
"state": "completed",
"total": 28804,
"done": 28804,
"suffix": null
},
{
"message": "Downloading Artifacts",
"code": "downloading.artifacts",
"state": "failed",
"total": null,
"done": 1498,
"suffix": null
},
{
"message": "Associating Content",
"code": "associating.content",
"state": "canceled",
"total": null,
"done": 31001,
"suffix": null
}
],
"created_resources": [],
"reserved_resources_record": [
"/pulp/api/v3/repositories/rpm/rpm/169ae56e-08a5-4fdd-ac71-e8624ca442bb/",
"/pulp/api/v3/remotes/rpm/rpm/bf23c689-5e23-4286-91f0-48e6704083d4/"
]
},
So I can repeat this quite often
Thanks
Updated by mped over 4 years ago
Hi
One more update, I just synched EPEL 7 now, from fresh and no issues, and again that is large. I'm don't think that Pulp 2 seems to get disconnected in the same way from RedHat as Pulp 3 does. I'll try and get some time to setup a new box with Pulp 2 and track the messages
Matt
Updated by bmbouter over 4 years ago
mped wrote:
Hi
One more update, I just synched EPEL 7 now, from fresh and no issues, and again that is large. I'm don't think that Pulp 2 seems to get disconnected in the same way from RedHat as Pulp 3 does. I'll try and get some time to setup a new box with Pulp 2 and track the messages
Matt
Thank you for reporting this and for the correspondence.
Here's a tl;dr of what we should put on the docs issue #6624. Pulp2 has network-unsafe retry logic so comparing the two side-by-side will give very different results. It's not expected for Pulp3 to behave the same; Pulp3 doesn't have automatic retry for network safety reasons. Pulp 3 will pick up its downloading where it left off for subsequent syncs if the same operation is started again. I recommend users add retry logic if they are comfortable doing so by having a script monitor a sync and retry. This would provide a roughly equivalent outcome for that user and let Pulp itself remain a good network citizen.
Feedback, suggestions, recommendations, and concerns are welcome.
Updated by mped over 4 years ago
Hi
Thanks for the update, I will implement some retry logic.
I looked at some stats for how many packages get synched during the failed attempts and it can vary from 41 to 2450 artifacts downloaded before the connection is dropped, so I guess even for a smaller repo a few retries maybe needed. I'm not expecting anything to be done with this, it is just an observation.
Thanks again
Matt
Updated by dkliban@redhat.com over 4 years ago
- Status changed from NEW to CLOSED - NOTABUG
As discussed in previous comments, Pulp is behaving as designed. Users that experiencing problems due to server or network issues should simply sync again. Pulp will not re-download anything it successfully downloaded in the previous sync attempt.
Updated by mped over 4 years ago
Hi
After doing some more testing found a few issues in our environment with Pulp2 synching a few rpms and being able to set http connection timeout and read time out solved the issue. It doesn't look like this is possible in Pulp3 so I have raised https://pulp.plan.io/issues/6699, which I think would solve this for me. Especially in environment where I saw multiple varying failures
Thanks
Matt
Updated by dalley over 3 years ago
- Status changed from CLOSED - NOTABUG to CLOSED - DUPLICATE
Just came back across this issue. We recently added automatic retries of file downloads for a large variety of errors encountered during the sync, which should resolve this issue as described, without any manual steps required.
Updated by dalley over 3 years ago
- Related to Story #8881: As a user, Pulp will retry downloads by default 3 times and I can configure this value on my Remote added
Actions
.