nav[aria-label="Primary Navigation"] { padding: 0; & ul { list-style: none; width: 100%; display: flex; flex-direction: row; justify-content: start; align-items: start; gap: 30px; padding: 0; & li { margin: 0; } & ul li { list-style: none; } } }

Why do I get a lot of throttling on bitbucket docker images all of a sudden

Stefan Van Dyck_6yvqpv

Lately I have been getting a lot of these:

Screenshot from 2023-11-03 15-37-29-1.png

Especially on one repo where the pipeline spins up 4 parallel steps.

We are running self-hosted bitbucket pipeline runners on a kubernetes cluster.
I already set up docker proxy cache and perform docker logins whenever I can.

But the images in question seem to be the bitbucket images hosted on ECR:
public.ecr.aws/o4g5y6x4/sox/atlassian/public/pipelines-auth-proxy:prod-stable, etc.

Is there any way to avoid/mitigate this issue?
It does not seem possible to use a registry mirror for images not hosted on docker-hub.
Am I somehow not caching these images properly with my k8s setup?

Any help would be greatly appreciated.

Accepted answers

All comments

Stefan Van Dyck_6yvqpv

An excerpt of the runner logs around the time of the failure.

2023-11-03 15:31:55.018
runner-213399c0-f71a-5934-aefa-ce6832b619cb-q87xs: [2023-11-03 14:31:54,941] Appending log line to main log.
2023-11-03 15:31:56.021
runner-213399c0-f71a-5934-aefa-ce6832b619cb-q87xs: [2023-11-03 14:31:55,943] Appending log line to main log.
2023-11-03 15:31:57.023
runner-213399c0-f71a-5934-aefa-ce6832b619cb-q87xs: [2023-11-03 14:31:56,943] Appending log line to main log.
2023-11-03 15:31:58.026
runner-213399c0-f71a-5934-aefa-ce6832b619cb-q87xs: [2023-11-03 14:31:57,942] Appending log line to main log.
2023-11-03 15:31:58.464
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:31:58,321] Pulling image deltaraybv/infrastructure.dind:1.0.9.
2023-11-03 15:31:59.029
runner-213399c0-f71a-5934-aefa-ce6832b619cb-q87xs: [2023-11-03 14:31:58,940] Appending log line to main log.
2023-11-03 15:32:00.031
runner-213399c0-f71a-5934-aefa-ce6832b619cb-q87xs: [2023-11-03 14:31:59,939] Appending log line to main log.
2023-11-03 15:32:01.033
runner-213399c0-f71a-5934-aefa-ce6832b619cb-q87xs: [2023-11-03 14:32:00,939] Appending log line to main log.
2023-11-03 15:32:02.036
runner-213399c0-f71a-5934-aefa-ce6832b619cb-q87xs: [2023-11-03 14:32:01,942] Appending log line to main log.
2023-11-03 15:32:03.038
runner-213399c0-f71a-5934-aefa-ce6832b619cb-q87xs: [2023-11-03 14:32:02,942] Appending log line to main log.
2023-11-03 15:32:04.040
runner-213399c0-f71a-5934-aefa-ce6832b619cb-q87xs: [2023-11-03 14:32:03,940] Appending log line to main log.
2023-11-03 15:32:04.731
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:32:04,711] Pulling image public.ecr.aws/o4g5y6x4/sox/atlassian/public/pipelines-auth-proxy:prod-stable.
2023-11-03 15:32:04.731
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:32:04,715] Looking for auth in config for image Image{name=public.ecr.aws/o4g5y6x4/sox/atlassian/public/pipelines-auth-proxy:prod-stable, runAsUser=None, auth=None} and found auth null
2023-11-03 15:32:05.042
runner-213399c0-f71a-5934-aefa-ce6832b619cb-q87xs: [2023-11-03 14:32:04,939] Appending log line to main log.
2023-11-03 15:32:06.045
runner-213399c0-f71a-5934-aefa-ce6832b619cb-q87xs: [2023-11-03 14:32:05,941] Appending log line to main log.
2023-11-03 15:32:06.988
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:32:06,755] An error occurred whilst pulling image.
2023-11-03 15:32:06.988
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: com.github.dockerjava.api.exception.DockerClientException: Could not pull image: toomanyrequests: Rate exceeded
2023-11-03 15:32:06.988
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at com.github.dockerjava.api.command.PullImageResultCallback.checkDockerClientPullSuccessful(PullImageResultCallback.java:97)
2023-11-03 15:32:06.988
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at com.github.dockerjava.api.command.PullImageResultCallback.throwFirstError(PullImageResultCallback.java:112)
2023-11-03 15:32:06.988
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at com.github.dockerjava.api.async.ResultCallbackTemplate.awaitCompletion(ResultCallbackTemplate.java:93)
2023-11-03 15:32:06.988
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at com.atlassian.pipelines.runner.core.service.docker.ImageServiceImpl.lambda$pull$0(ImageServiceImpl.java:57)
2023-11-03 15:32:06.988
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at io.reactivex.internal.operators.completable.CompletableFromAction.subscribeActual(CompletableFromAction.java:35)
2023-11-03 15:32:06.988
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at io.reactivex.Completable.subscribe(Completable.java:2309)
2023-11-03 15:32:06.988
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at brave.context.rxjava2.internal.TraceContextCompletable.subscribeActual(TraceContextCompletable.java:39)
2023-11-03 15:32:06.988
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at io.reactivex.Completable.subscribe(Completable.java:2309)
2023-11-03 15:32:06.989
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at io.reactivex.internal.operators.completable.CompletableObserveOn.subscribeActual(CompletableObserveOn.java:34)
2023-11-03 15:32:06.989
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at io.reactivex.Completable.subscribe(Completable.java:2309)
2023-11-03 15:32:06.989
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at brave.context.rxjava2.internal.TraceContextCompletable.subscribeActual(TraceContextCompletable.java:39)
2023-11-03 15:32:06.989
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at io.reactivex.Completable.subscribe(Completable.java:2309)
2023-11-03 15:32:06.989
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at io.reactivex.internal.operators.completable.CompletableSubscribeOn$SubscribeOnObserver.run(CompletableSubscribeOn.java:64)
2023-11-03 15:32:06.989
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at brave.propagation.CurrentTraceContext$1CurrentTraceContextRunnable.run(CurrentTraceContext.java:264)
2023-11-03 15:32:06.989
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at com.atlassian.pipelines.common.trace.rxjava.CopyMdcSchedulerHandler$CopyMdcRunnableAdapter.run(CopyMdcSchedulerHandler.java:74)
2023-11-03 15:32:06.989
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at io.reactivex.Scheduler$DisposeTask.run(Scheduler.java:608)
2023-11-03 15:32:06.989
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at brave.propagation.CurrentTraceContext$1CurrentTraceContextRunnable.run(CurrentTraceContext.java:264)
2023-11-03 15:32:06.989
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at com.atlassian.pipelines.common.trace.rxjava.CopyMdcSchedulerHandler$CopyMdcRunnableAdapter.run(CopyMdcSchedulerHandler.java:74)
2023-11-03 15:32:06.989
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at io.reactivex.internal.schedulers.ScheduledRunnable.run(ScheduledRunnable.java:66)
2023-11-03 15:32:06.989
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at io.reactivex.internal.schedulers.ScheduledRunnable.call(ScheduledRunnable.java:57)
2023-11-03 15:32:06.989
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at java.base/java.util.concurrent.FutureTask.run(Unknown Source)
2023-11-03 15:32:06.989
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
2023-11-03 15:32:06.989
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
2023-11-03 15:32:06.989
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
2023-11-03 15:32:06.989
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: at java.base/java.lang.Thread.run(Unknown Source)
2023-11-03 15:32:06.989
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:32:06,765] Removing container (name: 7a75bf4b-be9d-5469-9273-59447a5c5357_7d8cd45b-3a43-475d-9496-1f9509a8c195_build)
2023-11-03 15:32:06.989
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:32:06,778] Not uploading caches. (numberOfCaches: 0, resultOrError: FAILED)
2023-11-03 15:32:06.990
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:32:06,785] Updating step progress to UPLOADING_ARTIFACTS.
2023-11-03 15:32:07.048
runner-213399c0-f71a-5934-aefa-ce6832b619cb-q87xs: [2023-11-03 14:32:06,941] Appending log line to main log.
2023-11-03 15:32:07.239
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:32:07,107] Updating step progress to PARSING_TEST_RESULTS.
2023-11-03 15:32:07.489
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:32:07,303] Appending log line to main log.
2023-11-03 15:32:07.489
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:32:07,417] Test report processing complete.
2023-11-03 15:32:07.489
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:32:07,418] Removing container (name: 7a75bf4b-be9d-5469-9273-59447a5c5357_7d8cd45b-3a43-475d-9496-1f9509a8c195_clone)
2023-11-03 15:32:07.489
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:32:07,423] Removing container (name: 7a75bf4b-be9d-5469-9273-59447a5c5357_7d8cd45b-3a43-475d-9496-1f9509a8c195_clone)
2023-11-03 15:32:07.489
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:32:07,429] Removing container (name: 7a75bf4b-be9d-5469-9273-59447a5c5357_7d8cd45b-3a43-475d-9496-1f9509a8c195_build)
2023-11-03 15:32:07.489
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:32:07,433] Removing container (name: 7a75bf4b-be9d-5469-9273-59447a5c5357_7d8cd45b-3a43-475d-9496-1f9509a8c195_yml_docker)
2023-11-03 15:32:07.489
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:32:07,438] Removing container (name: 7a75bf4b-be9d-5469-9273-59447a5c5357_7d8cd45b-3a43-475d-9496-1f9509a8c195_system_auth-proxy)
2023-11-03 15:32:07.490
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:32:07,443] Removing container (name: 7a75bf4b-be9d-5469-9273-59447a5c5357_7d8cd45b-3a43-475d-9496-1f9509a8c195_pause)
2023-11-03 15:32:07.490
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:32:07,453] Updating step progress to COMPLETING_LOGS.
2023-11-03 15:32:07.740
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:32:07,726] Shutting down log uploader.
2023-11-03 15:32:07.740
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:32:07,731] Appending log line to main log.
2023-11-03 15:32:08.051
runner-213399c0-f71a-5934-aefa-ce6832b619cb-q87xs: [2023-11-03 14:32:07,942] Appending log line to main log.
2023-11-03 15:32:08.241
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:32:08,120] Tearing down directories.
2023-11-03 15:32:08.241
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:32:08,125] Cancelling timeout
2023-11-03 15:32:08.241
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:32:08,132] Completing step with result Result{status=FAILED, error=Some(Error{key='runner.bitbucket-pipelines.image-pull-failure', message='Could not pull image: toomanyrequests: Rate exceeded', arguments={}})}.
2023-11-03 15:32:08.743
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:32:08,490] Setting runner state to not executing step.
2023-11-03 15:32:08.743
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:32:08,492] Waiting for next step.
2023-11-03 15:32:08.743
runner-7a75bf4b-be9d-5469-9273-59447a5c5357-mt256: [2023-11-03 14:32:08,492] Finished executing step. StepId{accountUuid={acd3f09f-51f0-494e-b80e-2d2d4719bfa3}, repositoryUuid={352f3fed-a757-483f-bf18-fee86e476534}, pipelineUuid={70c7e412-3b74-43ec-a87c-fa8b7f8c5d3f}, stepUuid={7d8cd45b-3a43-475d-9496-1f9509a8c195}}
2023-11-03 15:32:09.054
runner-213399c0-f71a-5934-aefa-ce6832b619cb-q87xs: [2023-11-03 14:32:08,941] Appending log line to main log.

DevOps OptiTrust

Same here! I am using bitbucket self-hosted runners, which worked fine until a few days ago, when I started getting this error message from time to time.

EDITED

@Stefan Van Dyck @Alexandre Fillatre
I think that I found an issue. This is probably because you are using: services: - docker in your bitbucket-pipeline step. By default, it will pull an image from the aws.ecr repo with rate limitations. You can define your own docker image like this:

definitions: services: docker: Image: <your docker image> which will pull your image when you use docker services(or any other service you are using).

Theodora Boudale

Hi Stefan,

If that was rate limiting from Bitbucket Cloud for authenticated requests, we could check our logs and see the number of calls, what calls were made, from which IPs, etc. However, we don't have any visibility to ECR usage and I don't know how their rate limits are calculated.

I would suggest reaching out to ECR support team or forums to ask if there is a way to figure out your usage and why you're hitting the limit.

Kind regards,
Theodora

Alexandre Fillatre

I do have to same problem myself, with a fresh external runner from my GKE pool. I did not have this issue when I set up a similar runner several weeks ago.

When I SSH into the runner, I see that my docker images are actually downloaded. I tried a `docker pull` myself, and I'm still able to download images.

I currently have no idea where the problem comes from.

Alexandre Fillatre

Thanks for the hint @DevOps OptiTrust !

I checked my pipeline file, and I have :

definitions:
services:
mongo:
image: mongo:4.4.21
redis:
image: redis:7.0-alpine

When I execute docker images on the runner, I get:

node                                                                20            b5288ff94366   6 days ago      1.1GB

public.ecr.aws/o4g5y6x4/sox/atlassian/public/pipelines-dvcstools    prod-stable   f11cd980bfe8   7 days ago      29.2MB

redis                                                               7.0-alpine    7808c81c5cb0   2 weeks ago     35.9MB

public.ecr.aws/o4g5y6x4/sox/atlassian/public/pipelines-auth-proxy   prod-stable   a120d79b860d   3 months ago    15.1MB

mongo                                                               4.4.21        6dcde8b068de   6 months ago    432MB

public.ecr.aws/o4g5y6x4/sox/atlassian/public/k8s/pause              latest        4873874c08ef   16 months ago   711kB

which seems fine

Is that what you meant ?

DevOps OptiTrust

Yes, I meant that. In my case, the pipeline failed on the step where I used the docker service. Since I changed the image to my private image, I have no issues.
Steps to troubleshoot:

- check step which is falling
- check if you are using services or something else from bitbucket which pulls one of the images from aws.ecr.

Obviously, something changed on aws public ecr, probably they decreased rate limits.

@Theodora Boudale maybe you can consider moving your images to another public repo.

Welcome!

It looks like you're new here. Sign in or register to get started.

Quick Links

Find more posts tagged with

cloud

bitbucket

bitbucket-cloud