"Could not parse Docker build output for image ID" in docker version 1.12.1 using build_options `-q`

[wtanaka]

Using Docker version 1.12.1, build 23cf638 I get errors such as these:

-----> Cleaning up any prior instances of <ansible144-ubuntu-1404>
-----> Destroying <ansible144-ubuntu-1404>...
Finished destroying <ansible144-ubuntu-1404> (0m0.00s).
-----> Testing <ansible144-ubuntu-1404>
-----> Creating <ansible144-ubuntu-1404>...
sha256:33764a95b67665df6742906718f6aa6be85e9b2d5b3b98dc21a592b9b7a59cff
Create failed on instance <ansible144-ubuntu-1404>.
------Exception-------
Class: Kitchen::ActionFailed
Message: Could not parse Docker build output for image ID
----------------------
------Backtrace-------
.../ruby/2.3.0/gems/kitchen-docker-2.5.0/lib/kitchen/driver/docker.rb:276:in `parse_image_id'
.../ruby/2.3.0/gems/kitchen-docker-2.5.0/lib/kitchen/driver/docker.rb:296:in `build_image'
.../ruby/2.3.0/gems/kitchen-docker-2.5.0/lib/kitchen/driver/docker.rb:110:in `create'
.../ruby/2.3.0/gems/test-kitchen-1.11.1/lib/kitchen/instance.rb:449:in `public_send'
.../ruby/2.3.0/gems/test-kitchen-1.11.1/lib/kitchen/instance.rb:449:in `block in perform_action'
.../ruby/2.3.0/gems/test-kitchen-1.11.1/lib/kitchen/instance.rb:513:in `synchronize_or_call'
.../ruby/2.3.0/gems/test-kitchen-1.11.1/lib/kitchen/instance.rb:478:in `block in action'
/usr/lib/ruby/2.3.0/benchmark.rb:293:in `measure'
.../ruby/2.3.0/gems/test-kitchen-1.11.1/lib/kitchen/instance.rb:477:in `action'
.../ruby/2.3.0/gems/test-kitchen-1.11.1/lib/kitchen/instance.rb:449:in `perform_action'
.../ruby/2.3.0/gems/test-kitchen-1.11.1/lib/kitchen/instance.rb:359:in `create_action'
.../ruby/2.3.0/gems/test-kitchen-1.11.1/lib/kitchen/instance.rb:348:in `block in transition_to'
.../ruby/2.3.0/gems/test-kitchen-1.11.1/lib/kitchen/instance.rb:347:in `each'
.../ruby/2.3.0/gems/test-kitchen-1.11.1/lib/kitchen/instance.rb:347:in `transition_to'
.../ruby/2.3.0/gems/test-kitchen-1.11.1/lib/kitchen/instance.rb:160:in `verify'

[coderanger]

Please include your .kitchen.yml config. The tests run using the latest Docker so that is not likely the issue.

[wtanaka]

https://github.com/wtanaka/role-tester-ansible/blob/master/.kitchen.yml

[wtanaka]

I'll update the title

/tmp/wtanaka % docker --version
Docker version 1.12.1, build 23cf638
/tmp/wtanaka % docker build -q -f Dockerfile .
sha256:ff60113363279ed0eb02aadd3149368b414dcf9baa4d3ce3c1fc8b6f4a03875e
/tmp/wtanaka % docker build -f Dockerfile .
Sending build context to Docker daemon 2.048 kB
Step 1 : FROM ubuntu:14.04
 ---> ff6011336327
Successfully built ff6011336327

[coderanger]

Does it work if you remove the build_options -q? I'm guessing that suppresses the output we need to parse.

[coderanger]

Ahh yeah, as you noted. I probably won't fix that any time soon, the _options things are a trapdoor for new Docker features and I don't think there is a need to support every one of them that changes output.

[wtanaka]

-q is particularly useful in online CI services which tend to limit the amount of output that you can produce from CI test jobs.

[coderanger]

The limit is usually a few megabytes, the docker build is generally no more than 1k of output. I don't think something less than ~<0.1% is worth optimizing. If there's a specific CI platform that has weirdly stricter limits, I would reconsider :)

[coderanger]

(also having the build record is super important for replicating failed CI builds sometimes)

[wtanaka]

It can add up as the cross product of platforms and suites starts to add up.

platforms:
- driver_config: {image: 'centos:5'}
  name: centos-5
- driver_config: {image: 'centos:7'}
  name: centos-7
- driver_config: {image: 'debian:7'}
  name: debian-7
- driver_config: {image: 'debian:8'}
  name: debian-8
- driver_config: {image: 'fedora:20'}
  name: fedora-20
- driver_config: {image: 'fedora:24'}
  name: fedora-24
- driver_config: {image: 'ubuntu:12.04'}
  name: ubuntu-12.04
- driver_config: {image: 'ubuntu:16.04'}
  name: ubuntu-16.04
suites:
- {name: ansiblesystem}
- name: ansible1.4.4
  provisioner: {ansible_playbook_bin: ansible1.4.4/bin/ansible-playbook, raw_arguments: --module-path=ansible1.4.4/share/ansible}
- name: ansible1.5.4
  provisioner: {ansible_playbook_bin: ansible1.5.4/bin/ansible-playbook, raw_arguments: --module-path=ansible1.5.4/share/ansible}
- name: ansible1.7.2
  provisioner: {ansible_playbook_bin: ansible1.7.2/bin/ansible-playbook, raw_arguments: --module-path=ansible1.7.2/share/ansible}
- name: ansible1.9.2
  provisioner: {ansible_playbook_bin: ansible1.9.2/bin/ansible-playbook}
- name: ansible2.0.0.2
  provisioner: {ansible_playbook_bin: ansible2.0.0.2/bin/ansible-playbook}
- name: ansible2.1.0.0
  provisioner: {ansible_playbook_bin: ansible2.1.0.0/bin/ansible-playbook}

[coderanger]

That's still only 56 instances. In theory the build output should be cached for every suite after the first on a given platform but even assuming ~50kb of output, Travis' log limit if 4MB, that ~1.2% of the allowable log size. I agree it's not nothing, but the benefits of having the log data for failed builds feels more valuable to me.

[wtanaka]

I think the docker output might be spammier than you imagine. I spent a few minutes trying to find an example without -q -- I didn't succeed yet, but this gives a flavor (unfortunately, I think this doesn't get suppressed when you add -q, but there's similar progressbar output from "yum install" in fedora etc that ends up generating a lot of output when -q is turned off)

To be clear, I wouldn't imagine turning on -q by default, but it seems like it shouldn't be too hard to support the new "sha256:IMAGEID" style output that results with -q? I just don't personally know enough Ruby to submit a patch quickly.

[coderanger]

Ahh right, I forget not everyone is using the remote mode which disables the build context. That's fair.

[coderanger]

There is also a separate flag to disable the build context, but that might not always help.

[maksteel]

Similar error seen with export DOCKER_BUILDKIT=1 https://docs.docker.com/develop/develop-images/build_enhancements/ #337