'Preparing the "docker-autoscaler" executor' step of a CI job takes too long to execute

Summary

The first step of a CI job executed by a GitLab runner using docker-autoscaler executor sometimes takes 2 minutes 40 seconds to complete. Other times the same 'Preparing the "docker-autoscaler" executor' step of a similar job takes only 30 seconds to execute. Why is this 2 minutes difference in execution time?

Steps to reproduce

Create AWS autoscaling group with maximum capacity = 2
Configure 1 GitLab runner with docker-autoscaler executor
Trigger CI jobs

  [runners.autoscaler]
    plugin                 = "aws:latest"
    capacity_per_instance  = 1
    max_instances          = 2
    instance_ready_command = "sudo su -c 'cloud-init status --wait'"
    
    [runners.autoscaler.plugin_config]
      name = "${autoscaling_group_name}"

    [runners.autoscaler.connector_config]
      username          = "ec2-user"
      use_external_addr = false

    [[runners.autoscaler.policy]]
      idle_count = 1
      idle_time  = "30m0s"

.gitlab-ci.yml

stages:
  - build-artifacts

default:
  image:
    name: registry.gitlab.com/<redacted>
    pull_policy: if-not-present

fast-job:
  stage: build-artifacts
  script:
    - cd $PATH
    - npm ci --prefer-offline
    - npm run tsc
  rules:
    - if: $CI_PIPELINE_SOURCE == 'merge_request_event'
      changes:
        - ".gitlab-ci.yml"

slow-job:
  stage: build-artifacts
  script:
    - cd $PATH
    - npm ci --prefer-offline
    - npm run lint
  rules:
    - if: $CI_PIPELINE_SOURCE == 'merge_request_event'
      changes:
        - ".gitlab-ci.yml"

Actual behavior

The first step of one job took 02:41 to complete, the same step of a similar job took 33 seconds to complete.

Expected behavior

The first step of both jobs should complete in around 30 seconds.

Relevant logs and/or screenshots

Preparing the "docker-autoscaler" executor took 02:41 to complete:

Slow job log

Running with gitlab-runner 17.3.1 (66269445)
  on Build Runner (i-02730e44953xxxxxx) x7uDGsUj, system ID: s_fec38545bb53
  feature flags: FF_DISABLE_UMASK_FOR_DOCKER_EXECUTOR:true
Resolving secrets
Preparing the "docker-autoscaler" executor 02:41
Dialing instance i-04ea0568124ae6a12...
Instance i-04ea0568124ae6a12 connected
Using Docker executor with image registry.gitlab.com/<redacted> ...
Authenticating with credentials from job payload (GitLab Registry)
Pulling docker image registry.gitlab.com/<redacted> ...
Using docker image <redacted> for registry.gitlab.com/<redacted> with digest registry.gitlab.com/<redacted> ...
Not using umask - FF_DISABLE_UMASK_FOR_DOCKER_EXECUTOR is set!
Preparing environment 00:06
Running on runner-x7udgsuj-project-14989075-concurrent-1 via build-runner...
Getting source from Git repository 00:05
Fetching changes with git depth set to 25...

<removed the rest of the job log>

Preparing the "docker-autoscaler" executor took 00:33 to complete:

Fast job log

Running with gitlab-runner 17.3.1 (66269445)
  on Build Runner (i-02730e44953xxxxxx) x7uDGsUj, system ID: s_fec38545bb53
  feature flags: FF_DISABLE_UMASK_FOR_DOCKER_EXECUTOR:true
Resolving secrets
Preparing the "docker-autoscaler" executor 00:33
Dialing instance i-02ebe7947cff259e7...
Instance i-02ebe7947cff259e7 connected
Using Docker executor with image registry.gitlab.com/<redacted> ...
Authenticating with credentials from job payload (GitLab Registry)
Pulling docker image registry.gitlab.com/<redacted> ...
Using docker image sha256:<redacted> for registry.gitlab.com/<redacted> with digest registry.gitlab.com/<redacted> ...
Not using umask - FF_DISABLE_UMASK_FOR_DOCKER_EXECUTOR is set!
Preparing environment 00:06
Running on runner-x7udgsuj-project-14989075-concurrent-1 via build-runner...
Getting source from Git repository 00:05
Fetching changes with git depth set to 25...

<removed the rest of the job log>

Environment description

gitlab-runner is installed in AWS AMI from script: https://packages.gitlab.com/runner/gitlab-runner/install#bash-rpm
gitlab-runner uses the docker-autoscaler executor

docker info


Client:
 Version:    25.0.5
 Context:    default
 Debug Mode: false
 Plugins:
  buildx: Docker Buildx (Docker Inc.)
    Version:  v0.0.0+unknown
    Path:     /usr/libexec/docker/cli-plugins/docker-buildx

Server:
 Server Version: 25.0.6
 Storage Driver: overlay2
  Backing Filesystem: xfs
  Supports d_type: true
  Using metacopy: false
  Native Overlay Diff: true
  userxattr: false
 Logging Driver: json-file
 Cgroup Driver: cgroupfs
 Cgroup Version: 1
 Plugins:
  Volume: local
  Network: bridge host ipvlan macvlan null overlay
  Log: awslogs fluentd gcplogs gelf journald json-file local splunk syslog
 Swarm: inactive
 Runtimes: io.containerd.runc.v2 runc
 Default Runtime: runc
 Init Binary: docker-init
 containerd version: 8fc6bcff51318944179630522a095cc9dbf9f353
 runc version: 4bccb38cc9cf198d52bebf2b3a90cd14e7af8c06
 init version: de40ad0
 Security Options:
  seccomp
   Profile: builtin
 Kernel Version: 5.10.223-212.873.amzn2.x86_64
 Operating System: Amazon Linux 2
 OSType: linux
 Architecture: x86_64
 CPUs: 2
 Total Memory: 430.5MiB
 Name: build-runner
 ID: 5e75bb9a-fa8f-4bad-9839-389aa83da67b
 Docker Root Dir: /var/lib/docker
 Debug Mode: false
 Experimental: false
 Insecure Registries:
  127.0.0.0/8
 Registry Mirrors:
  https://mirror.gcr.io/
 Live Restore Enabled: false

WARNING: bridge-nf-call-iptables is disabled
WARNING: bridge-nf-call-ip6tables is disabled

config.toml contents

concurrent = 2
check_interval = 0
log_format = "text"
connection_max_age = "15m0s"
shutdown_timeout = 0

[session_server]
  session_timeout = 1800

[[runners]]
  name = "<redacted>"
  request_concurrency = 1
  url = "https://gitlab.com/"
  id = <redacted>
  token = "<redacted>"
  executor = "docker-autoscaler"
  environment = [<redacted>]
  [runners.custom_build_dir]
  [runners.cache]
    MaxUploadedArchiveSize = 0
    [runners.cache.s3]
    [runners.cache.gcs]
    [runners.cache.azure]
  [runners.docker]
    tls_verify = false
    image = "alpine:latest"
    privileged = true
    disable_entrypoint_overwrite = false
    oom_kill_disable = false
    disable_cache = false
    volumes = [<redacted>]
    allowed_pull_policies = ["always", "if-not-present"]
    shm_size = 0
    network_mtu = 0
  [runners.autoscaler]
    capacity_per_instance = 1
    max_use_count = 0
    max_instances = 2
    plugin = "aws:latest"
    instance_ready_command = "sudo su -c 'cloud-init status --wait'"
    update_interval = "0s"
    update_interval_when_expecting = "0s"
    delete_instances_on_shutdown = true
    [runners.autoscaler.plugin_config]
      name = "<redacted>"
    [runners.autoscaler.connector_config]
      username = "ec2-user"
      password = ""
      key_path = ""
      use_static_credentials = false
      keepalive = "0s"
      timeout = "0s"
      use_external_addr = false

    [[runners.autoscaler.policy]]
      periods = ["* * * * *"]
      idle_count = 0
      idle_time = "0s"
      scale_factor = 0.0
      scale_factor_limit = 0

    [[runners.autoscaler.policy]]
      periods = ["* 8-19 * * MON-FRI"]
      idle_count = 1
      idle_time = "30m0s"
      scale_factor = 0.0
      scale_factor_limit = 0

Used GitLab Runner version

# gitlab-runner --version
Version:      17.3.1
Git revision: 66269445
Git branch:   17-3-stable
GO version:   go1.22.5
Built:        2024-08-21T15:24:26+0000
OS/Arch:      linux/amd64

# gitlab-runner fleeting list
Runtime platform                                    arch=amd64 os=linux pid=13875 revision=66269445 version=17.3.1
runner: yRJpsoqV, plugin: aws:latest, path: /root/.config/fleeting/plugins/registry.gitlab.com/gitlab-org/fleeting/plugins/aws/1.0.0/plugin

Edited Aug 28, 2024 by Natalia Golovatskaia