Slower docker pushes on CircleCI 2.0

docker

#1

In our main repository, we build about 15 docker images during deploys and push them to quay.io. In CircleCI 1.0, each push takes about a minute, but on 2.0 it’s closer to 1.5 - 2 minutes each. The duration appears to be the same whether we use layer caching or not.

Is this expected behavior, or is there some thing I can do to speed it up?


#2

I would try running some mtr --reports - it sounds like you’re just pushing them further than on 1.0. Are you running machine or docker as your executorType?


#3

I can’t seem to get mtr to work, it’s printing mtr: unable to get raw sockets. The executor type is docker, and it’s running the openjdk:8 image. mtr works when installed and run from that image locally.

Another thing I noticed is that repeatedly building pushing the same image to quay.io takes about the same amount of time. Locally, the first push takes about a minute, and subsequent ones take 10 seconds.


#4

Great question. I spent some time looking into this and the answer is unprivileged containers. The only way to run mtr from executorType: docker is to spin up a Docker container. Here is an example for your use case:

version: 2
executorType: docker
containerInfo:
  - image: openjdk:8
stages:
  build:
    workdir: /project
    steps:
    - type: shell
      pwd: /
      command: |
        echo "test"
        curl -L -o /tmp/docker.tgz https://get.docker.com/builds/Linux/x86_64/docker-1.12.6.tgz
        tar -xz -C /tmp -f /tmp/docker.tgz
        mv /tmp/docker/docker* /usr/bin/
    - type: setup-docker-engine
    - type: shell
      pwd: /
      command: |
        docker run -it ubuntu:latest /bin/bash -c "apt update && apt install -y mtr && mtr -r google.com"

#5

Cool, that worked, here’s the output from mtr -r quay.io

Start: Wed Feb 22 18:25:12 2017
HOST: 6414cb513aa9                Loss%   Snt   Last   Avg  Best  Wrst StDev
  1.|-- 172.17.0.1                 0.0%    10    0.1   0.1   0.1   0.1   0.0
  2.|-- 108.170.246.7              0.0%    10   12.8  12.9  12.6  13.5   0.0
  3.|-- ???                       100.0    10    0.0   0.0   0.0   0.0   0.0
  4.|-- ???                       100.0    10    0.0   0.0   0.0   0.0   0.0
  5.|-- ???                       100.0    10    0.0   0.0   0.0   0.0   0.0
  6.|-- 54.239.110.139             0.0%    10   79.8  42.7  20.5  79.8  19.5
  7.|-- 54.239.111.27              0.0%    10   13.6  13.8  13.3  14.5   0.0
  8.|-- 52.93.24.32                0.0%    10   22.6  31.2  15.5  58.8  16.0
  9.|-- 52.93.24.31                0.0%    10   13.3  13.4  13.1  15.3   0.6
 10.|-- ???                       100.0    10    0.0   0.0   0.0   0.0   0.0

#6

That looks perfectly reasonable. Are you able to parallelize your docker push to Quay?


#7

We could take advantage of container parallelization. When I tried running multiple pushes locally, it thrashed my laptop and ended up taking longer than running them serially.

Any insight into my observations in the second paragraph here? If I could get subsequent pushes to be as fast as they are locally, that would dramatically speed up our deployments. A lot of the images we build don’t change much from deployment to deployment, so should be able to take advantage of layer caching during pushes.


#8

No, but I’d like to take a closer look. Can you PM me a one of the builds where you’re seeing that?


#9

I can’t figure out how to DM, here’s the repo and branch https://circleci.com/gh/dwnld/dwnld_services/tree/circle2
This build https://circleci.com/gh/dwnld/dwnld_services/6061 shows pushes in the “pants” step:

00:32:56 09:40       [push]
00:34:33 11:17       [push]
00:36:07 12:51       [push]
00:37:38 14:22       [push]
00:39:30 16:14       [push]
00:41:06 17:50       [push]
00:42:29 19:13       [push]
00:43:58 20:42       [push]
00:45:31 22:15       [push]
00:46:55 23:39       [push]
00:48:20 25:04       [push]
00:49:48 26:32       [push]
00:51:12 27:56       [push]
00:52:40 29:24       [push]
00:54:13 30:57       [push]
00:55:43 32:27       [push]
00:57:09 33:53       [push]

#10

It turns out it had to do with how we were invoking docker from our build tool, switching to a plain shell running docker push made push times much faster.

Thanks for your help!


#11

@JoeEnnever Would you mind sharing how you invoked Docker that caused this, so we’ll know what to look for if it comes up with others?


#12

Sure. The docker push happens as part of a custom pants plugin. The code involves a method to run a docker command in a subprocess. The old version looks like:

def _run_docker_command(self, workunit, cmdline):
  stderr = workunit.output('stderr') if workunit else None
  try:
    process = subprocess.Popen(cmdline, stdout=subprocess.PIPE, stderr=stderr)
  except OSError as e:
    if workunit:
      workunit.set_outcome(WorkUnit.FAILURE)
    raise TaskError('Docker failed to execute {cmdline}: {error}'.format(
      cmdline=cmdline, error=e))
  stdout, _ = process.communicate()

  if workunit:
    workunit.output('stdout').write(stdout)

The fix was to instead pipe the output to /dev/null

  with open(os.devnull, 'w') as devnull:
    try:
      process = subprocess.Popen(cmdline, stdout=devnull, stderr=devnull)
    except OSError as e:
      if workunit:
        workunit.set_outcome(WorkUnit.FAILURE)
      raise TaskError('Docker failed to execute {cmdline}: {error}'.format(
        cmdline=cmdline, error=e))
    process.wait()

#13