Convox CLI build output doesn't appear in Bitbucket Pipelines logs

CLI
1

Hey there,

Does anyone else experience build logs sent from Convox to CIs getting suddenly stopping, while the build operation continues and ends successfully?

–

We use Bitbucket Pipelines as our CI/CD solution. Our CI script looks something like this:

convox deploy --app blahblah --rack blahblah/mehmeh --manifest ./convox.lalala.yml --id

If a build only includes using existing Docker cache layers, then the Pipelines log works each and every time and it looks something like:

...
...
Starting build... OK
Authenticating 212345667898.dkr.ecr.us-east-2.amazonaws.com: Login Succeeded
Building: ./service1
Sending build context to Docker daemon  865.3kB
Step 1/20 : FROM python:3.6-alpine3.6
 ---> 316214a5f0e2
Step 2/20 : RUN apk update && apk add --no-cache --virtual=build-dependencies curl gcc python-dev build-base libc6-compat linux-headers libffi-dev git py-pip && apk add --no-cache tzdata py-cffi libev && pip install --upgrade pip && pip install --upgrade setuptools
 ---> Using cache
 ---> a4c31b6a5d9f
Step 3/20 : RUN apk add --no-cache --virtual=build-dependencies openssl-dev && apk add --no-cache ca-certificates py-cryptography openssl wget
 ---> Using cache
 ---> 836d506f0660
Step 4/30 : RUN mkdir -p /opt/blahblah/service1
 ---> Using cache
 ---> adb0fb7feadf
Step 5/30 : WORKDIR /opt/blahblah/service1
 ---> Using cache
 ---> 8e44cfdd286b
Step 6/30 : COPY package.json .
 ---> Using cache
 ---> 94aa68139000
Step 7/30 : COPY yarn.lock .
 ---> Using cache
 ---> 7146067dce9c
Step 8/30 : RUN yarn install
 ---> Using cache
 ---> 506d9c94c460
...
...
...
...
Step 29/30 : ADD src .
 ---> Using cache
 ---> d0f5d3c41020
Step 30/30 : ENTRYPOINT yarn run production-run-server 2>&1
 ---> Using cache
 ---> 25f85b6efce5
Successfully built 25f85b6efce5
Successfully tagged 43684bdbd872e3e8c5895dcd8c59563fe5bc0e74:latest
Running: docker tag 05ef123099ad4a0f7c70b7197c9798a0fab80fdf convox/blahblah:service2.BABCDEFGHHX
Injecting: convox-env
Running: docker tag 13466b4f3c34dd3a97cacff2f94f4f8dbba239f3 convox/blahblah:service3.BABCDEFGHHX
Injecting: convox-env
Running: docker tag convox/blahblah:service2.BABCDEFGHHX 212345667898.dkr.ecr.us-east-2.amazonaws.com/blahblah-regis-198k60j3z1gep:service2.BABCDEFGHHX
Running: docker push 212345667898.dkr.ecr.us-east-2.amazonaws.com/blahblah-regis-198k60j3z1gep:service2.BABCDEFGHHX
Running: docker tag convox/blahblah:service1.BABCDEFGHHX 212345667898.dkr.ecr.us-east-2.amazonaws.com/blahblah-regis-198k60j3z1gep:service1.BABCDEFGHHX
Running: docker push 212345667898.dkr.ecr.us-east-2.amazonaws.com/blahblah-regis-198k60j3z1gep:service1.BABCDEFGHHX
Running: docker tag convox/blahblah:service3.BABCDEFGHHX 212345667898.dkr.ecr.us-east-2.amazonaws.com/blahblah-regis-198k60j3z1gep:service3.BABCDEFGHHX
Running: docker push 212345667898.dkr.ecr.us-east-2.amazonaws.com/blahblah-regis-198k60j3z1gep:service3.BABCDEFGHHX
Promoting RABCDEFFAFF... OK
RABCDEFFAFFDone. Getting info...
Name        blahblah
Status      running
Generation  2
Locked      false
Release     RABCABCABCD

But if there’s any actual building, any actual usage of CLI tools and build logs generated, then there’s a high chance that we’ll get something like this:

...
...
...
...
 ---> Running in 98c2b52a3871
Removing intermediate container 98c2b52a3871
 ---> 16d8165d80be
Step 23/30 : COPY ./common ./src/common
 ---> 5f433667f74e
Step 24/30 : RUN yarn run production-build-client
 ---> Running in 7cc979cd837e
yarn run v5.5.5
$ NODE_ENV=production webpack --progress --colors --display-error-details --config ./webpack/webpack.config.client.production.js
Building for environment blahblah.
Forcing BABEL_ENV to client-production
crackle: webpack.config.client.production.babel.js
<-----------------------------------------------------------------------------
<-----------------------------------------------------------------------------
<---- no logs here for 12 minutes, no additional log line <--------- NOTE THIS
<-----------------------------------------------------------------------------
<-----------------------------------------------------------------------------
ERROR: build failed

Or this:

Successfully tagged df96f844d8d63aa05d48c6ab46a571f1a6fbd193:latest
Building: ./service4
Sending build context to Docker daemon  453.6kB
Step 1/20 : FROM python:3.6-alpine3.6
 ---> 316214a5f0e2
Step 2/20 : RUN apk update && apk add --no-cache --virtual=build-dependencies curl gcc python-dev build-base libc6-compat linux-headers libffi-dev git py-pip && apk add --no-cache tzdata py-cffi libev && pip install --upgrade setuptools
 ---> Running in 79325303db0d
fetch http://dl-cdn.alpinelinux.org/alpine/v3.6/main/x86_64/APKINDEX.tar.gz
fetch http://dl-cdn.alpinelinux.org/alpine/v3.6/community/x86_64/APKINDEX.tar.gz
v3.6.5-44-gda55e27396 [http://dl-cdn.alpinelinux.org/alpine/v3.6/main]
v3.6.5-34-gf0ba0b43d5 [http://dl-cdn.alpinelinux.org/alpine/v3.6/community]
OK: 8446 distinct packages available
fetch http://dl-cdn.alpinelinux.org/alpine/v3.6/main/x86_64/APKINDEX.tar.gz
fetch http://dl-cdn.alpinelinux.org/alpine/v3.6/community/x86_64/APKINDEX.tar.gz
(1/33) Upgrading musl (1.1.16-r14 -> 1.1.16-r15)
(2/33) Installing libssh2 (1.8.2-r0)
(3/33) Installing libcurl (7.61.1-r2)
(4/33) Installing curl (7.61.1-r2)
(5/33) Installing binutils-libs (2.30-r1)
(6/33) Installing binutils (2.30-r1)
(7/33) Installing gmp (6.1.2-r0)
(8/33) Installing isl (0.17.1-r0)
(9/33) Installing libgomp (6.3.0-r4)
(10/33) Installing libatomic (6.3.0-r4)
(11/33) Installing pkgconf (1.3.7-r0)
(12/33) Installing libgcc (6.3.0-r4)
(13/33) Installing mpfr3 (3.1.5-r0)
(14/33) Installing mpc1 (1.0.3-r0)
(15/33) Installing libstdc++ (6.3.0-r4)
(16/33) Installing gcc (6.3.0-r4)
(17/33) Installing python2 (2.7.15-r0)
(18/33) Installing python2-dev (2.7.15-r0)
(19/33) Installing musl-dev (1.1.16-r15)
(20/33) Installing libc-dev (0.7.1-r0)
(21/33) Installing g++ (6.3.0-r4)
(22/33) Installing make (4.2.1-r0)
(23/33) Installing fortify-headers (0.8-r0)
(24/33) Installing build-base (0.5-r0)
...
...
...
...
...
OK: 258 MiB in 61 packages
Collecting setuptools
Mon Feb 10 06:17:12 UTC 2020
  Downloading https://files.pythonhosted.org/packages/3d/72/1c1498c1e908e0562b1e1cd30012580baa7d33b5b0ffdbeb5fde2462cc71/setuptools-45.2.0-py3-none-any.whl (584kB)
Installing collected packages: setuptools
  Found existing installation: setuptools 40.7.1
    Uninstalling setuptools-40.7.1:
      Successfully uninstalled setuptools-40.7.1
Successfully installed setuptools-45.2.0
You are using pip version 19.0.1, however version 20.0.2 is available.
<-----------------------------------------------------------------------------
<-----------------------------------------------------------------------------
<---- no logs here for 35 minutes, no additional log line <--------- NOTE THIS
<-----------------------------------------------------------------------------
<-----------------------------------------------------------------------------
Promoting RABCDEFGHIZ... OK
RABCDEFGHIZDone. Getting info...
Name        blahblah
Status      updating
Generation  2
Locked      false
Release     RASDQQWEQWV

Or this:

(6/16) Installing py-parsing (2.2.0-r0)
(7/16) Installing py2-parsing (2.2.0-r0)
(8/16) Installing py-six (1.10.0-r6)
(9/16) Installing py2-six (1.10.0-r6)
(10/16) Installing py-packaging (16.8-r2)
(11/16) Installing py2-packaging (16.8-r2)
(12/16) Installing py-cryptography (1.8.1-r2)
(13/16) Installing py2-ipaddress (1.0.18-r1)
(14/16) Installing py-enum34 (1.1.6-r2)
(15/16) Installing py2-cryptography (1.8.1-r2)
(16/16) Installing wget (1.20.3-r0)
Executing busybox-1.26.2-r11.trigger
Executing ca-certificates-20161130-r2.trigger
OK: 286 MiB in 81 packages
Removing intermediate container 78a8a7345991
 ---> 6b0c3744622c
Step 4/21 : RUN wget http://github.com/some/package/releases/download/v1.01/somepackage_amd64.tar.gz && tar -zxvf somepackage_amd64.tar.gz && cp ./somepackage/somepackage /usr/local/bin
 ---> Running in 037249785ec6
--2020-02-12 13:49:31--  http://github.com/some/package/releases/download/v1.01/somepackage_amd64.tar.gz
<-----------------------------------------------------------------------------
<-----------------------------------------------------------------------------
<---- no logs here for 55 minutes, no additional log line <--------- NOTE THIS
<-----------------------------------------------------------------------------
<-----------------------------------------------------------------------------
Promoting RQWEERTEEAD... OK
RQWEERTEEADDone. Getting info...
Name        blahblah
Status      updating
Generation  2
Locked      false
Release     RQWERHFGFGO

It seems to happen when the console/terminal moves to a certain mode, typically for downloading or installing - I think yarn, npm, pip and wget are typically the services we see running last before the log stream disappears.

Did anyone else encounter this issue? We’ve had it for at least 2 years now, consistently.

Thanks!

2

Yes that happens on every build from CircleCI. It doesn’t happen when pushing locally for me, but I also haven’t updated the CLI in about a year so I think they broke it on the CLI side at some point.

3

@ddollar
Is this a known issue?

4

@scott
Did you see this fixed when updating the CLI?

So you say it also happens in CircleCI, in addition to Bitbucket Pipelines - so is this clearly a Convox issue, would you say?

5

After discussing this with the Bitbucket team, specifically with Senior Support Engineer Sandeep Khandelwal, I can confirm this is indeed a bug with Convox.

This is what Sandeep wrote to me:

I had discussed the issue with Dev team and did some tests. Sharing below the test results.

For the testing purpose we created a rack on Convox. The rack was created in AWS ECR.

We were able to narrow down the issue with RUN pip install --upgrade setuptools command in the Docker file. The same issue could with other command as well but we fill focus on pip install --upgrade setuptools command for testing purpose.

  • Image was build locally using Convox - No issue was found with log

    • Command used:
      time convox deploy --app test10 --rack test/test --manifest ./convox.yml

  • Image built on Pipeline (directly without Convox) - No issue was found with log

    • Command used:
      docker build -t test .

  • Image built using Convox on Pipeline - Issue was found with log
    Please note that There is no log after “Successfully installed setuptools-44.1.0” . There is no Docker image build log after the layer where RUN pip install --upgrade setuptools executed.**
    Tried with adding -q --no-color option in the command but now luck, nor with -q --no-color option set and without -q --no-color option set.

    • Command used:
      time convox deploy --app test10 --rack test/test --manifest ./convox.yml

The above explanation clearly verify that issue is with Convox deployment and something related to log message redirection from Convox to Pipeline and possibly with the color of the log message.

So, the issue is easily reproducible by using this Dockerfile:

FROM node:8.15-alpine
RUN mkdir -p /opt/software
RUN apk update && \
    apk add --no-progress --no-cache --virtual=build-dependencies openssh curl wget gcc python-dev build-base libc6-compat linux-headers libffi-dev git py-pip libpng-dev lcms2-dev bash && \
    apk add --no-progress --no-cache tzdata py-cffi libev 
RUN pip install -q --no-color --upgrade setuptools
... any other commands

Any output after RUN pip install -q --no-color --upgrade setuptools will not be shown.

This happens in Circle CI, Bitbucket Pipelines and potentially many other CI tools.

6

Convox team, this has been an issue for at least 2 years now.
Would it be possible to get some feedback about the issue? Are you are aware of this? Planning to fix it? Not planning to fix it? Are there any workarounds?
Is this not an issue in Gen 3?

Any sort of feedback would be welcome.

@ddollar @cameron @ed_convox

7

Weirdly enough we just found a fix while trying to address something different. We are using the CircleCI convox orb, and it looks like it was still using a super old version from years ago. We just added sudo convox update as a step before the deployment, and we are back to getting all of the build and release promotion logs.

8

Interesting @scott , really hope this works!
So your script is similar to:

sudo convox update
convox deploy --app blahblah --rack blahblah/mehmeh --manifest ./convox.lalala.yml

right?

9

Yes very similar. CircleCI deploy config in case anyone else wants a simple example where we do a build, run migrations, then promote:

- checkout
- run: sudo convox update
- run:
    command: convox_release_id=$(convox build --app $CONVOX_APP_NAME --id) && echo "export CONVOX_RELEASE_ID=\"$convox_release_id\"" >> $BASH_ENV
    no_output_timeout: 40m
- run: echo "Promoting release $CONVOX_RELEASE_ID"
- run: convox run web app/bin/release_migrations --app $CONVOX_APP_NAME --release "$CONVOX_RELEASE_ID"
- run:
    command: convox releases promote --app $CONVOX_APP_NAME "$CONVOX_RELEASE_ID" --wait
    no_output_timeout: 30m