Project

Profile

Help

Actions
Send by e-mail Copy link

Issue #7186

closed

Immediate syncing of some CentOS 6 and 7 repos failing

Added by iballou over 4 years ago. Updated over 4 years ago.

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

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

Related to Pulp - Issue #7212: Adjust download concurrencyCLOSED - CURRENTRELEASEdaviddavisActions
Related to Pulp - Issue #8878: default Download Concurrency is too high for many centos mirrorsCLOSED - DUPLICATEdalleyActions
Actions
Copy link
 #1

Updated by bmbouter over 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

Actions
Copy link
 #2

Updated by iballou over 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?

Actions
Copy link
 #3

Updated by ipanova@redhat.com over 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

Actions
Copy link
 #4

Updated by ipanova@redhat.com over 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?

Actions
Copy link
 #5

Updated by bmbouter over 4 years ago

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

Actions
Copy link
 #6

Updated by bmbouter over 4 years ago

  • Related to Issue #7212: Adjust download concurrency added
Actions
Copy link
 #7

Updated by ttereshc over 4 years ago

  • Status changed from NEW to CLOSED - DUPLICATE

Feel free to comment or email to reopen

Actions
Copy link
 #8

Updated by jsherril@redhat.com over 3 years ago

  • Related to Issue #8878: default Download Concurrency is too high for many centos mirrors added
Actions
Send by e-mail Copy link

Also available in: Atom PDF