Project

Profile

Help

Issue #4075

closed

ArtifactDownloader stage does not reduce traffic when Downloaders receive 429 status code

Added by gmbnomis about 6 years ago. Updated almost 5 years ago.

Status:
CLOSED - CURRENTRELEASE
Priority:
Normal
Assignee:
Category:
-
Sprint/Milestone:
Start date:
Due date:
Estimated time:
Severity:
2. Medium
Version:
Platform Release:
OS:
Triaged:
Yes
Groomed:
No
Sprint Candidate:
No
Tags:
Sprint:
Quarter:

Description

Problem

The downloader backs off exponentially when it receives specific HTTP status codes (like 429 TOO MANY REQUESTS), see https://github.com/pulp/pulp/blob/60700bc51a2f5d49030950129edc9c723333e82d/plugin/pulpcore/plugin/download/http.py#L161. This is done to reduce the load on the upstream server.

When a downloader goes into backoff, the downloader will free up a connection and sleep. As the ArtifactDownloader stage may have > 200 downloaders waiting for a connection in the default configuration, a new downloader will hit the server immediately without a backoff. Since the upstream server is already limiting the traffic, it is very likely that it will continue to send 429 return codes for requests until the load reduces.

Even if there is only one artifact to download per content unit, Pulp will hammer the server with 200 requests until all of them are retrying in the worst case. And 200 downloaders in retry will probably still cause lots of load.

Example (pulp_cookbook plugin)

Parameters:
- connection limit: 2
- number of artifact to download: 17 (i.e. much less than possible in the worst case)
- HttpDownloader modified to log request and responses

With 200 OK answers only, the log looks like:

Oct 09 19:52:28.650534 pulp3.dev rq[3076]: pulp: rq.worker:INFO: resource_manager: Job OK (358681c9-8194-431c-b921-d3ed080f5b8b)
Oct 09 19:52:28.729031 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/universe
Oct 09 19:52:29.242186 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/universe
Oct 09 19:52:29.284098 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_1/apache2-5.0.1.tar.gz
Oct 09 19:52:29.286094 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_0/apache2-5.0.0.tar.gz
Oct 09 19:52:29.287768 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/3_0_1/apache2-3.0.1.tar.gz
Oct 09 19:52:29.289186 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/1_10_2/apache2-1.10.2.tar.gz
Oct 09 19:52:29.290442 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/1_9_6/apache2-1.9.6.tar.gz
Oct 09 19:52:29.291904 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/1_9_1/apache2-1.9.1.tar.gz
Oct 09 19:52:29.293134 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apt/7_0_0/apt-7.0.0.tar.gz
Oct 09 19:52:29.294139 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apt/6_0_1/apt-6.0.1.tar.gz
Oct 09 19:52:29.295234 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apt/5_0_1/apt-5.0.1.tar.gz
Oct 09 19:52:29.296218 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/ubuntu/2_0_1/ubuntu-2.0.1.tar.gz
Oct 09 19:52:29.297256 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/ubuntu/1_0_0/ubuntu-1.0.0.tar.gz
Oct 09 19:52:29.298237 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/8_0_0/nginx-8.0.0.tar.gz
Oct 09 19:52:29.299866 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_7_4/nginx-2.7.4.tar.gz
Oct 09 19:52:29.300547 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_7_2/nginx-2.7.2.tar.gz
Oct 09 19:52:29.301471 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_7_0/nginx-2.7.0.tar.gz
Oct 09 19:52:29.302332 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_6_0/nginx-2.6.0.tar.gz
Oct 09 19:52:29.303226 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_5_0/nginx-2.5.0.tar.gz
Oct 09 19:52:29.412633 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_1/apache2-5.0.1.tar.gz
Oct 09 19:52:29.749311 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/3_0_1/apache2-3.0.1.tar.gz
Oct 09 19:52:29.774998 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_0/apache2-5.0.0.tar.gz
Oct 09 19:52:30.081178 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/1_10_2/apache2-1.10.2.tar.gz
Oct 09 19:52:30.128988 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/1_9_6/apache2-1.9.6.tar.gz
Oct 09 19:52:30.236108 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/1_9_1/apache2-1.9.1.tar.gz
Oct 09 19:52:30.262124 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apt/7_0_0/apt-7.0.0.tar.gz
Oct 09 19:52:30.370061 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apt/5_0_1/apt-5.0.1.tar.gz
Oct 09 19:52:30.423165 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apt/6_0_1/apt-6.0.1.tar.gz
Oct 09 19:52:30.496480 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/ubuntu/2_0_1/ubuntu-2.0.1.tar.gz
Oct 09 19:52:30.559540 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/ubuntu/1_0_0/ubuntu-1.0.0.tar.gz
Oct 09 19:52:30.640429 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/8_0_0/nginx-8.0.0.tar.gz
Oct 09 19:52:30.697512 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_7_4/nginx-2.7.4.tar.gz
Oct 09 19:52:30.755412 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_7_2/nginx-2.7.2.tar.gz
Oct 09 19:52:30.871853 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_6_0/nginx-2.6.0.tar.gz
Oct 09 19:52:31.009434 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_5_0/nginx-2.5.0.tar.gz
Oct 09 19:52:31.053522 pulp3.dev rq[3075]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_7_0/nginx-2.7.0.tar.gz

17 content units are downloaded within 3 seconds.

Now, the HttpDownloader is modified to change all 200 OK codes into 429 (i.e. the download proceeds as usual, but after the download, an exception is raised). The only exception is the initial "universe" file containing the meta-data, which has to be downloaded successfully for the ArtifactDownloader stage to work.

Oct 09 19:56:23.424187 pulp3.dev rq[4778]: pulp: rq.worker:INFO: resource_manager: Job OK (d7f98c9f-c925-4021-a2ab-f53f77f4e3b6)
Oct 09 19:56:23.471552 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/universe
Oct 09 19:56:23.971217 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/universe
Oct 09 19:56:24.020130 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_1/apache2-5.0.1.tar.gz
Oct 09 19:56:24.030391 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_0/apache2-5.0.0.tar.gz
Oct 09 19:56:24.030391 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/3_0_1/apache2-3.0.1.tar.gz
Oct 09 19:56:24.030391 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/1_10_2/apache2-1.10.2.tar.gz
Oct 09 19:56:24.030391 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/1_9_6/apache2-1.9.6.tar.gz
Oct 09 19:56:24.030391 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/1_9_1/apache2-1.9.1.tar.gz
Oct 09 19:56:24.030645 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apt/7_0_0/apt-7.0.0.tar.gz
Oct 09 19:56:24.032460 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apt/6_0_1/apt-6.0.1.tar.gz
Oct 09 19:56:24.033529 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apt/5_0_1/apt-5.0.1.tar.gz
Oct 09 19:56:24.033673 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/ubuntu/2_0_1/ubuntu-2.0.1.tar.gz
Oct 09 19:56:24.034576 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/ubuntu/1_0_0/ubuntu-1.0.0.tar.gz
Oct 09 19:56:24.035923 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/8_0_0/nginx-8.0.0.tar.gz
Oct 09 19:56:24.045738 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_7_4/nginx-2.7.4.tar.gz
Oct 09 19:56:24.045738 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_7_2/nginx-2.7.2.tar.gz
Oct 09 19:56:24.045738 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_7_0/nginx-2.7.0.tar.gz
Oct 09 19:56:24.045738 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_6_0/nginx-2.6.0.tar.gz
Oct 09 19:56:24.045738 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_5_0/nginx-2.5.0.tar.gz
Oct 09 19:56:24.136134 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_1/apache2-5.0.1.tar.gz
Oct 09 19:56:24.137785 pulp3.dev rq[4773]: Backing off run(...) for 1.0s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:24.138049 pulp3.dev rq[4773]: pulp: backoff:INFO: Backing off run(...) for 1.0s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:24.464911 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_0/apache2-5.0.0.tar.gz
Oct 09 19:56:24.465618 pulp3.dev rq[4773]: Backing off run(...) for 0.8s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:24.465709 pulp3.dev rq[4773]: pulp: backoff:INFO: Backing off run(...) for 0.8s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:24.595672 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/3_0_1/apache2-3.0.1.tar.gz
Oct 09 19:56:24.597405 pulp3.dev rq[4773]: Backing off run(...) for 0.4s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:24.597640 pulp3.dev rq[4773]: pulp: backoff:INFO: Backing off run(...) for 0.4s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:24.912059 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/1_10_2/apache2-1.10.2.tar.gz
Oct 09 19:56:24.913353 pulp3.dev rq[4773]: Backing off run(...) for 0.8s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:24.913628 pulp3.dev rq[4773]: pulp: backoff:INFO: Backing off run(...) for 0.8s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:24.986496 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/3_0_1/apache2-3.0.1.tar.gz
Oct 09 19:56:25.062739 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/1_9_6/apache2-1.9.6.tar.gz
Oct 09 19:56:25.066983 pulp3.dev rq[4773]: Backing off run(...) for 0.6s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:25.067167 pulp3.dev rq[4773]: pulp: backoff:INFO: Backing off run(...) for 0.6s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:25.130512 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_1/apache2-5.0.1.tar.gz
Oct 09 19:56:25.234611 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_0/apache2-5.0.0.tar.gz
Oct 09 19:56:25.347841 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/1_9_1/apache2-1.9.1.tar.gz
Oct 09 19:56:25.357986 pulp3.dev rq[4773]: Backing off run(...) for 0.1s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:25.358208 pulp3.dev rq[4773]: pulp: backoff:INFO: Backing off run(...) for 0.1s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:25.455890 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/1_9_1/apache2-1.9.1.tar.gz
Oct 09 19:56:25.522209 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apt/7_0_0/apt-7.0.0.tar.gz
Oct 09 19:56:25.525158 pulp3.dev rq[4773]: Backing off run(...) for 0.6s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:25.525490 pulp3.dev rq[4773]: pulp: backoff:INFO: Backing off run(...) for 0.6s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:25.666927 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/1_9_6/apache2-1.9.6.tar.gz
Oct 09 19:56:25.744142 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/1_10_2/apache2-1.10.2.tar.gz
Oct 09 19:56:25.787438 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apt/6_0_1/apt-6.0.1.tar.gz
Oct 09 19:56:25.789065 pulp3.dev rq[4773]: Backing off run(...) for 0.6s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:25.789337 pulp3.dev rq[4773]: pulp: backoff:INFO: Backing off run(...) for 0.6s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:25.981753 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apt/5_0_1/apt-5.0.1.tar.gz
Oct 09 19:56:25.982895 pulp3.dev rq[4773]: Backing off run(...) for 0.2s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:25.983145 pulp3.dev rq[4773]: pulp: backoff:INFO: Backing off run(...) for 0.2s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:26.138216 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apt/5_0_1/apt-5.0.1.tar.gz
Oct 09 19:56:26.162831 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apt/7_0_0/apt-7.0.0.tar.gz
Oct 09 19:56:26.241499 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/ubuntu/2_0_1/ubuntu-2.0.1.tar.gz
Oct 09 19:56:26.241885 pulp3.dev rq[4773]: Backing off run(...) for 0.2s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:26.241964 pulp3.dev rq[4773]: pulp: backoff:INFO: Backing off run(...) for 0.2s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:26.347021 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/8_0_0/nginx-8.0.0.tar.gz
Oct 09 19:56:26.347759 pulp3.dev rq[4773]: Backing off run(...) for 0.4s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:26.347888 pulp3.dev rq[4773]: pulp: backoff:INFO: Backing off run(...) for 0.4s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:26.370378 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apt/6_0_1/apt-6.0.1.tar.gz
Oct 09 19:56:26.397746 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/ubuntu/2_0_1/ubuntu-2.0.1.tar.gz
Oct 09 19:56:26.433233 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/ubuntu/1_0_0/ubuntu-1.0.0.tar.gz
Oct 09 19:56:26.433707 pulp3.dev rq[4773]: Backing off run(...) for 0.6s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:26.433801 pulp3.dev rq[4773]: pulp: backoff:INFO: Backing off run(...) for 0.6s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:26.734600 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/8_0_0/nginx-8.0.0.tar.gz
Oct 09 19:56:26.780072 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_7_4/nginx-2.7.4.tar.gz
Oct 09 19:56:26.781178 pulp3.dev rq[4773]: Backing off run(...) for 0.3s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:26.781494 pulp3.dev rq[4773]: pulp: backoff:INFO: Backing off run(...) for 0.3s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:26.895144 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_7_2/nginx-2.7.2.tar.gz
Oct 09 19:56:26.895860 pulp3.dev rq[4773]: Backing off run(...) for 0.5s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:26.896035 pulp3.dev rq[4773]: pulp: backoff:INFO: Backing off run(...) for 0.5s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:27.028685 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/ubuntu/1_0_0/ubuntu-1.0.0.tar.gz
Oct 09 19:56:27.112423 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_7_4/nginx-2.7.4.tar.gz
Oct 09 19:56:27.256928 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_7_0/nginx-2.7.0.tar.gz
Oct 09 19:56:27.258052 pulp3.dev rq[4773]: Backing off run(...) for 0.3s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:27.258334 pulp3.dev rq[4773]: pulp: backoff:INFO: Backing off run(...) for 0.3s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:27.391125 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_6_0/nginx-2.6.0.tar.gz
Oct 09 19:56:27.392983 pulp3.dev rq[4773]: Backing off run(...) for 0.6s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:27.392983 pulp3.dev rq[4773]: pulp: backoff:INFO: Backing off run(...) for 0.6s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:27.446930 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_7_2/nginx-2.7.2.tar.gz
Oct 09 19:56:27.582823 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_7_0/nginx-2.7.0.tar.gz
Oct 09 19:56:27.704984 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_5_0/nginx-2.5.0.tar.gz
Oct 09 19:56:27.705306 pulp3.dev rq[4773]: Backing off run(...) for 0.8s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:27.705306 pulp3.dev rq[4773]: pulp: backoff:INFO: Backing off run(...) for 0.8s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:27.839590 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/3_0_1/apache2-3.0.1.tar.gz
Oct 09 19:56:27.840092 pulp3.dev rq[4773]: Backing off run(...) for 1.8s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:27.840092 pulp3.dev rq[4773]: pulp: backoff:INFO: Backing off run(...) for 1.8s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:28.013792 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_6_0/nginx-2.6.0.tar.gz
Oct 09 19:56:28.157288 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_1/apache2-5.0.1.tar.gz
Oct 09 19:56:28.158126 pulp3.dev rq[4773]: Backing off run(...) for 1.2s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:28.158126 pulp3.dev rq[4773]: pulp: backoff:INFO: Backing off run(...) for 1.2s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:28.287627 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_0/apache2-5.0.0.tar.gz
Oct 09 19:56:28.288043 pulp3.dev rq[4773]: Backing off run(...) for 1.2s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:28.288043 pulp3.dev rq[4773]: pulp: backoff:INFO: Backing off run(...) for 1.2s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:28.495393 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/nginx/2_5_0/nginx-2.5.0.tar.gz
Oct 09 19:56:28.596240 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/1_9_1/apache2-1.9.1.tar.gz
Oct 09 19:56:28.607734 pulp3.dev rq[4773]: Backing off run(...) for 0.5s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:28.607734 pulp3.dev rq[4773]: pulp: backoff:INFO: Backing off run(...) for 0.5s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:28.742607 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/1_9_6/apache2-1.9.6.tar.gz
Oct 09 19:56:28.743365 pulp3.dev rq[4773]: Backing off run(...) for 1.3s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:28.743572 pulp3.dev rq[4773]: pulp: backoff:INFO: Backing off run(...) for 1.3s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:29.040811 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/1_10_2/apache2-1.10.2.tar.gz
Oct 09 19:56:29.041396 pulp3.dev rq[4773]: Backing off run(...) for 1.1s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:29.041396 pulp3.dev rq[4773]: pulp: backoff:INFO: Backing off run(...) for 1.1s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 19:56:29.145395 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/1_9_1/apache2-1.9.1.tar.gz
Oct 09 19:56:29.185700 pulp3.dev rq[4773]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apt/5_0_1/apt-5.0.1.tar.gz

Within 5 seconds, the HttpDownloader receives 23 responses! Instead of reducing the load, it even creates more request/responses than available content units.

Now, max_concurrent_content is set to 2 in the ArtifactDownloader to artificially reduce the number of active downloaders:

Oct 09 20:03:45.590720 pulp3.dev rq[5138]: pulp: rq.worker:INFO: resource_manager: Job OK (e9459576-4f7b-4ca9-abf0-eec6b373d6a6)
Oct 09 20:03:45.720390 pulp3.dev rq[5137]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/universe
Oct 09 20:03:46.274251 pulp3.dev rq[5137]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/universe
Oct 09 20:03:46.345266 pulp3.dev rq[5137]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_1/apache2-5.0.1.tar.gz
Oct 09 20:03:46.349167 pulp3.dev rq[5137]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_0/apache2-5.0.0.tar.gz
Oct 09 20:03:46.488741 pulp3.dev rq[5137]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_1/apache2-5.0.1.tar.gz
Oct 09 20:03:46.488741 pulp3.dev rq[5137]: Backing off run(...) for 1.0s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 20:03:46.488741 pulp3.dev rq[5137]: pulp: backoff:INFO: Backing off run(...) for 1.0s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 20:03:46.844498 pulp3.dev rq[5137]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_0/apache2-5.0.0.tar.gz
Oct 09 20:03:46.845581 pulp3.dev rq[5137]: Backing off run(...) for 0.1s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 20:03:46.845581 pulp3.dev rq[5137]: pulp: backoff:INFO: Backing off run(...) for 0.1s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 20:03:46.920661 pulp3.dev rq[5137]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_0/apache2-5.0.0.tar.gz
Oct 09 20:03:47.362607 pulp3.dev rq[5137]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_0/apache2-5.0.0.tar.gz
Oct 09 20:03:47.362985 pulp3.dev rq[5137]: Backing off run(...) for 0.4s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 20:03:47.362985 pulp3.dev rq[5137]: pulp: backoff:INFO: Backing off run(...) for 0.4s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 20:03:47.481806 pulp3.dev rq[5137]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_1/apache2-5.0.1.tar.gz
Oct 09 20:03:47.727202 pulp3.dev rq[5137]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_0/apache2-5.0.0.tar.gz
Oct 09 20:03:47.933601 pulp3.dev rq[5137]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_1/apache2-5.0.1.tar.gz
Oct 09 20:03:47.933601 pulp3.dev rq[5137]: Backing off run(...) for 0.6s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 20:03:47.933601 pulp3.dev rq[5137]: pulp: backoff:INFO: Backing off run(...) for 0.6s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 20:03:48.171601 pulp3.dev rq[5137]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_0/apache2-5.0.0.tar.gz
Oct 09 20:03:48.176230 pulp3.dev rq[5137]: Backing off run(...) for 1.3s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 20:03:48.176230 pulp3.dev rq[5137]: pulp: backoff:INFO: Backing off run(...) for 1.3s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 20:03:48.558744 pulp3.dev rq[5137]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_1/apache2-5.0.1.tar.gz
Oct 09 20:03:48.997054 pulp3.dev rq[5137]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_1/apache2-5.0.1.tar.gz
Oct 09 20:03:48.997535 pulp3.dev rq[5137]: Backing off run(...) for 2.0s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 20:03:48.997535 pulp3.dev rq[5137]: pulp: backoff:INFO: Backing off run(...) for 2.0s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 20:03:49.503978 pulp3.dev rq[5137]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_0/apache2-5.0.0.tar.gz
Oct 09 20:03:49.934749 pulp3.dev rq[5137]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_0/apache2-5.0.0.tar.gz
Oct 09 20:03:49.935007 pulp3.dev rq[5137]: Backing off run(...) for 5.4s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 20:03:49.935007 pulp3.dev rq[5137]: pulp: backoff:INFO: Backing off run(...) for 5.4s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 20:03:50.982286 pulp3.dev rq[5137]: pulp: pulpcore.plugin.download.http:INFO: 2 downloader get https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_1/apache2-5.0.1.tar.gz
Oct 09 20:03:51.429772 pulp3.dev rq[5137]: pulp: pulpcore.plugin.download.http:INFO: downloader response https://pulpcookbook.s3.wasabisys.com/u1/cookbook_files/apache2/5_0_1/apache2-5.0.1.tar.gz
Oct 09 20:03:51.429772 pulp3.dev rq[5137]: Backing off run(...) for 7.3s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')
Oct 09 20:03:51.429772 pulp3.dev rq[5137]: pulp: backoff:INFO: Backing off run(...) for 7.3s (aiohttp.client_exceptions.ClientResponseError: 429, message='OK')

The ArtifactDownloader only works on 2 content units now (with increasing backoff time), resulting in 8 responses within the first 5 seconds.

This particular problem was introduced by https://pulp.plan.io/issues/4040, in which the ArtifactDownloader was simplified to rely on the aiohttp connection limit instead of managing the number of active downloaders itself.

Solutions

We could reduce max_concurrent_content to e.g. 10 to ameliorate this effect, but then, the entire ArtifactDownloader stage blocks when there are 10 content units scheduled for download. The main point about max_concurrent_content is that the stage allows declarative content not needing downloads to pass it on a "fast lane" until we have such a large number of content units that we don't want to buffer them anymore. It is not intended to limit the number of concurrent active downloaders (this is what the Semaphore in the previous ArtifactDownloader implementation was for). Furthermore, even 10 content units may need 20 downloads each and we have the same effect as before.

To limit the number of active downloaders, the simplest solution is to revert to the previous implementation of the stage and use the new configuration in the remote to limit the number of downloaders (and possibly, the number of connections at the same time).

Other suggestions are welcome, of course.

Also available in: Atom PDF