Issue #7186
closedImmediate syncing of some CentOS 6 and 7 repos failing
Description
An upstream user reported failing repo syncs and I have noticed this as well. The issue seems to happen when downloading the artifacts. Related conversation: https://community.theforeman.org/t/syncing-of-large-repos-failing-on-initial-build/19647/3
Repos tested with:
http-mirror-centos-org/centos/6/updates/x86_64/
http-mirror-centos-org/centos/7/os/x86_64/
http-mirror-centos-org/centos/7/opstools/x86_64/
http-mirror-centos-org/centos/7/updates/x86_64/
Upstream user's errors in /var/log/messages:
Jul 16 13:43:05 foreman-01 pulpcore-worker-1: pulp: rq.worker:ERROR: aiohttp.client_exceptions.ClientConnectorError: Cannot connect to host mirror.centos.org:80 ssl:default
Jul 16 13:43:06 foreman-01 pulpcore-worker-1: aiohttp.client_exceptions.ClientConnectorError: Cannot connect to host mirror.centos.org:80 ssl:default [Connect call failed (‘204.15.127.248’, 80)]
…
Jul 16 13:43:06 foreman-01 pulpcore-worker-1: TimeoutError: [Errno 110] Connect call failed (‘204.15.127.248’, 80)
Stack trace:
…
Jul 17 13:41:08 foreman-01 dynflow-sidekiq@orchestrator: 2020-07-17T18:41:08.313Z 1030 TID-2ya2lq Dynflow::Executors::Sidekiq::OrchestratorJobs::WorkerDone JID-ca8bac8dd19753502afffa35 INFO: start
Jul 17 13:41:08 foreman-01 dynflow-sidekiq@orchestrator: 2020-07-17T18:41:08.315Z 1030 TID-2ya2lq Dynflow::Executors::Sidekiq::OrchestratorJobs::WorkerDone JID-ca8bac8dd19753502afffa35 INFO: done: 0.001 sec
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: pulp: rq.worker:ERROR: aiohttp.client_exceptions.ClientOSError: [Errno 32] Broken pipe
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: Traceback (most recent call last):
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/rq/worker.py”, line 883, in perform_job
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: rv = job.perform()
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/rq/job.py”, line 645, in perform
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: self._result = self._execute()
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/rq/job.py”, line 651, in _execute
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: return self.func(*self.args, **self.kwargs)
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/pulp_rpm/app/tasks/synchronizing.py”, line 167, in synchronize
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: dv.create()
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/declarative_version.py”, line 148, in create
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: loop.run_until_complete(pipeline)
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib64/python3.6/asyncio/base_events.py”, line 484, in run_until_complete
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: return future.result()
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/api.py”, line 225, in create_pipeline
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: await asyncio.gather(*futures)
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/api.py”, line 43, in call
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: await self.run()
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py”, line 133, in run
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: pb.done += task.result() # download_count
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py”, line 159, in _handle_content_unit
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: await asyncio.gather(*downloaders_for_content)
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/models.py”, line 88, in download
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: download_result = await downloader.run(extra_data=self.extra_data)
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/pulpcore/download/base.py”, line 227, in run
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: return await self._run(extra_data=extra_data)
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/backoff/_async.py”, line 133, in retry
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: ret = await target(*args, **kwargs)
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/pulpcore/download/http.py”, line 197, in _run
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: async with self.session.get(self.url, proxy=self.proxy, auth=self.auth) as response:
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib64/python3.6/site-packages/aiohttp/client.py”, line 1012, in aenter
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: self._resp = await self._coro
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib64/python3.6/site-packages/aiohttp/client.py”, line 504, in _request
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: await resp.start(conn)
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib64/python3.6/site-packages/aiohttp/client_reqrep.py”, line 847, in start
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: message, payload = await self._protocol.read() # type: ignore # noqa
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib64/python3.6/site-packages/aiohttp/streams.py”, line 591, in read
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: await self._waiter
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: aiohttp.client_exceptions.ClientOSError: [Errno 32] Broken pipe
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: Traceback (most recent call last):
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/rq/worker.py”, line 883, in perform_job
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: rv = job.perform()
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/rq/job.py”, line 645, in perform
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: self._result = self._execute()
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/rq/job.py”, line 651, in _execute
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: return self.func(*self.args, **self.kwargs)
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/pulp_rpm/app/tasks/synchronizing.py”, line 167, in synchronize
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: dv.create()
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/declarative_version.py”, line 148, in create
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: loop.run_until_complete(pipeline)
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib64/python3.6/asyncio/base_events.py”, line 484, in run_until_complete
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: return future.result()
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/api.py”, line 225, in create_pipeline
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: await asyncio.gather(*futures)
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/api.py”, line 43, in call
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: await self.run()
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py”, line 133, in run
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: pb.done += task.result() # download_count
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py”, line 159, in _handle_content_unit
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: await asyncio.gather(*downloaders_for_content)
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/models.py”, line 88, in download
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: download_result = await downloader.run(extra_data=self.extra_data)
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/pulpcore/download/base.py”, line 227, in run
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: return await self._run(extra_data=extra_data)
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/backoff/_async.py”, line 133, in retry
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: ret = await target(*args, **kwargs)
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib/python3.6/site-packages/pulpcore/download/http.py”, line 197, in _run
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: async with self.session.get(self.url, proxy=self.proxy, auth=self.auth) as response:
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib64/python3.6/site-packages/aiohttp/client.py”, line 1012, in aenter
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: self._resp = await self._coro
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib64/python3.6/site-packages/aiohttp/client.py”, line 504, in _request
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: await resp.start(conn)
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib64/python3.6/site-packages/aiohttp/client_reqrep.py”, line 847, in start
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: message, payload = await self._protocol.read() # type: ignore # noqa
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: File “/usr/lib64/python3.6/site-packages/aiohttp/streams.py”, line 591, in read
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: await self._waiter
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: aiohttp.client_exceptions.ClientOSError: [Errno 32] Broken pipe
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: pulp: rq.worker:INFO: Cleaning registries for queue: 1004@foreman-01.nedisys.local
Jul 17 13:41:20 foreman-01 pulpcore-worker-2: pulp: rq.worker:INFO: 1004@foreman-01.nedisys.local: a0b027f7-38ed-462a-b82c-41d64610619a
Jul 17 13:41:21 foreman-01 pulpcore-worker-2: pulp: rq.worker:INFO: 1004@foreman-01.nedisys.local: Job OK (a0b027f7-38ed-462a-b82c-41d64610619a)
Jul 17 13:41:24 foreman-01 dynflow-sidekiq@worker: 2020-07-17T18:41:24.304Z 1010 TID-2y16sa Dynflow::Executors::Sidekiq::WorkerJobs::PerformWork JID-be22f61c263897cb8e1fb7e6 INFO: start
Jul 17 13:41:24 foreman-01 pulpcore-api: 127.0.0.1 - - [17/Jul/2020:18:41:24 +0000] “GET /pulp/api/v3/tasks/4fc9f8a3-6043-4545-90df-15e2e9aa82de/ HTTP/1.1” 200 3747 “-” “OpenAPI-Generator/3.4.1/ruby”
Error that I saw:
Katello::Errors::Pulp3Error: Response payload is not completed
Jul 21 15:42:18 localhost pulpcore-worker-2: pulp: rq.worker:ERROR: aiohttp.client_exceptions.ClientPayloadError: Response payload is not completed
Jul 21 15:42:18 localhost pulpcore-worker-2: Traceback (most recent call last):
Jul 21 15:42:18 localhost pulpcore-worker-2: File "/usr/lib/python3.6/site-packages/rq/worker.py", line 883, in perform_job
Jul 21 15:42:18 localhost pulpcore-worker-2: rv = job.perform()
Jul 21 15:42:18 localhost pulpcore-worker-2: File "/usr/lib/python3.6/site-packages/rq/job.py", line 645, in perform
Jul 21 15:42:18 localhost pulpcore-worker-2: self._result = self._execute()
Jul 21 15:42:18 localhost pulpcore-worker-2: File "/usr/lib/python3.6/site-packages/rq/job.py", line 651, in _execute
Jul 21 15:42:18 localhost pulpcore-worker-2: return self.func(*self.args, **self.kwargs)
Jul 21 15:42:18 localhost pulpcore-worker-2: File "/usr/lib/python3.6/site-packages/pulp_rpm/app/tasks/synchronizing.py", line 167, in synchronize
Jul 21 15:42:18 localhost pulpcore-worker-2: dv.create()
Jul 21 15:42:18 localhost pulpcore-worker-2: File "/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/declarative_version.py", line 148, in create
Jul 21 15:42:19 localhost pulpcore-worker-2: loop.run_until_complete(pipeline)
Jul 21 15:42:19 localhost pulpcore-worker-2: File "/usr/lib64/python3.6/asyncio/base_events.py", line 484, in run_until_complete
Jul 21 15:42:19 localhost pulpcore-worker-2: return future.result()
Jul 21 15:42:19 localhost pulpcore-worker-2: File "/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/api.py", line 225, in create_pipeline
Jul 21 15:42:19 localhost pulpcore-worker-2: await asyncio.gather(*futures)
Jul 21 15:42:19 localhost pulpcore-worker-2: File "/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/api.py", line 43, in __call__
Jul 21 15:42:19 localhost pulpcore-worker-2: await self.run()
Jul 21 15:42:19 localhost pulpcore-worker-2: File "/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py", line 133, in run
Jul 21 15:42:19 localhost pulpcore-worker-2: pb.done += task.result() # download_count
Jul 21 15:42:19 localhost pulpcore-worker-2: File "/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/artifact_stages.py", line 159, in _handle_content_unit
Jul 21 15:42:19 localhost pulpcore-worker-2: await asyncio.gather(*downloaders_for_content)
Jul 21 15:42:19 localhost pulpcore-worker-2: File "/usr/lib/python3.6/site-packages/pulpcore/plugin/stages/models.py", line 88, in download
Jul 21 15:42:19 localhost pulpcore-worker-2: download_result = await downloader.run(extra_data=self.extra_data)
Jul 21 15:42:19 localhost pulpcore-worker-2: File "/usr/lib/python3.6/site-packages/pulpcore/download/base.py", line 227, in run
Jul 21 15:42:19 localhost pulpcore-worker-2: return await self._run(extra_data=extra_data)
Jul 21 15:42:19 localhost pulpcore-worker-2: File "/usr/lib/python3.6/site-packages/backoff/_async.py", line 133, in retry
Jul 21 15:42:19 localhost pulpcore-worker-2: ret = await target(*args, **kwargs)
Jul 21 15:42:19 localhost pulpcore-worker-2: File "/usr/lib/python3.6/site-packages/pulpcore/download/http.py", line 199, in _run
Jul 21 15:42:19 localhost pulpcore-worker-2: to_return = await self._handle_response(response)
Jul 21 15:42:19 localhost pulpcore-worker-2: File "/usr/lib/python3.6/site-packages/pulpcore/download/http.py", line 168, in _handle_response
Jul 21 15:42:19 localhost pulpcore-worker-2: chunk = await response.content.read(1048576) # 1 megabyte
Jul 21 15:42:19 localhost pulpcore-worker-2: File "/usr/lib64/python3.6/site-packages/aiohttp/streams.py", line 368, in read
Jul 21 15:42:19 localhost pulpcore-worker-2: await self._wait('read')
Jul 21 15:42:19 localhost pulpcore-worker-2: File "/usr/lib64/python3.6/site-packages/aiohttp/streams.py", line 296, in _wait
Related packages:
python3-pulpcore-3.4.1-1.el7.noarch
python3-pulp-rpm-3.4.1-2.el7.noarch
Related issues
Updated by bmbouter about 4 years ago
dalley shared a theory that it's possible Pulp is forming too many parallel connections to servers, they get angry, and close TCP connections non-gracefully causing errors like these. Pulp Remotes have a download_concurrency
options, which defaults to 20. Can someone who can reproduce this issue please adjust that value to 10, 5, or 3 to test if that makes these errors go away?
https://pulp-rpm.readthedocs.io/en/latest/restapi.html#operation/remotes_rpm_rpm_create
Updated by iballou about 4 years ago
I changed the concurrency to 10 for one of my remotes and the repo synced fine. I think we're on the right track.
I changed the concurrency for one of my other remotes (for http-mirror-centos-org/centos/7/opstools/x86_64/) but the repo sync failed with this error:
"Cannot create repository version. Path is duplicated: rubygem-elasticsearch-api-1.0.7-1.el7.noarch.rpm."}
Another bug perhaps?
Updated by ipanova@redhat.com about 4 years ago
I managed to reproduce this issue with this repo http://ftp.cs.stanford.edu/centos/7/opstools/x86_64/ I opened a separate issue to track https://pulp.plan.io/issues/7208
Updated by ipanova@redhat.com about 4 years ago
iballou wrote:
I changed the concurrency to 10 for one of my remotes and the repo synced fine. I think we're on the right track.
I changed the concurrency for one of my other remotes (for http-mirror-centos-org/centos/7/opstools/x86_64/) but the repo sync failed with this error:
"Cannot create repository version. Path is duplicated: rubygem-elasticsearch-api-1.0.7-1.el7.noarch.rpm."}
Another bug perhaps?
bmbouter, given the results, should we change our concurrency to something lower then 20?
Updated by bmbouter about 4 years ago
ipanova@redhat.com wrote:
iballou wrote:
I changed the concurrency to 10 for one of my remotes and the repo synced fine. I think we're on the right track.
I changed the concurrency for one of my other remotes (for http-mirror-centos-org/centos/7/opstools/x86_64/) but the repo sync failed with this error:
"Cannot create repository version. Path is duplicated: rubygem-elasticsearch-api-1.0.7-1.el7.noarch.rpm."}
Another bug perhaps?
bmbouter, given the results, should we change our concurrency to something lower then 20?
Yes we should, I opened this for us to work on to do just that: https://pulp.plan.io/issues/7212
Updated by bmbouter about 4 years ago
- Related to Issue #7212: Adjust download concurrency added
Updated by ttereshc about 4 years ago
- Status changed from NEW to CLOSED - DUPLICATE
Feel free to comment or email pulp-dev@redhat.com to reopen
Updated by jsherril@redhat.com about 3 years ago
- Related to Issue #8878: default Download Concurrency is too high for many centos mirrors added