Speed up fig up

[dnephin]

I did some profiling of one of our larger fig setups. I noticed a lot of time wasted on an unnecessary build(). This branch adds a flag to disable the build() that was called during fig up. The slowdown wasn't on the build() itself, but the conditional if not client.images(), because it requires hitting the docker remote again, and filtering through the images.

In almost every use of fig I perform a fig build before a fig up already, to ensure that fig up is actually running the latest code/containers, so this extra check is completely wasted (and is actually slower than the build itself).

This branch also includes a few cleanup and bug fixes. Some from an earlier fig tag branch that probably wont get merged, and some new ones I found while working on the tests. I'll comment on the specifics inline.

Background

On this host:

$ docker images | wc -l 
1335
$ docker ps -a  | wc -l
104

I suspect this issue is less noticeable when there are fewer images, but 1335 doesn't seem like a lot. We actually cleanup images that are greater than 30 days old, so there shouldn't be anything terribly old here.

Total time: 30s
Number of fig services: 8 (2 image, 6 build)
This setup basically does 3 things:

fig pull
fig build
fig up

fig 1.0 profile

This is heavily cleaned up, but shows the relevant lines.

    399922 function calls (394317 primitive calls) in 30.741 CPU seconds
    Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000   16.916   16.916 fig/project.py:170(up)
        6    0.000    0.000   12.334    2.056 docker/client.py:552(images)
        1    0.000    0.000   10.536   10.536 fig/project.py:163(build)
        4    0.000    0.000    2.692    0.673 docker/client.py:716(pull)

Tracing the project.up() call through the stack:

Function                         called...                                                         
                                 ncalls  tottime  cumtime
fig/project.py:170(up)  ->       1    0.000    0.000  fig/project.py:86(get_services)
                                 8    0.000   16.916  fig/service.py:187(recreate_containers)

Function                                          called...                                                         
                                                  ncalls  tottime  cumtime                                              
fig/service.py:187(recreate_containers)  ->       8    0.001    0.277  fig/service.py:77(containers)
                                                  8    0.000   14.839  fig/service.py:171(create_container)
                                                  8    0.000    1.798  fig/service.py:248(start_container)

Function                                       called...                                                         
                                               ncalls  tottime  cumtime                                              
fig/service.py:171(create_container)  ->       8    0.000    1.929  fig/container.py:35(create)
                                               8    0.000   12.910  fig/service.py:329(_get_container_create_options)


Function                                                    called...                                                         
                                                            ncalls  tottime  cumtime                                              
fig/service.py:329(_get_container_create_options)  ->       6    0.000   12.334  docker/client.py:552(images)

We see that 12 seconds out of 30 seconds are spent on an operation that we already know to be a no-op

this branch profile

    398171 function calls (392402 primitive calls) in 18.330 CPU seconds
    Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000   10.927   10.927 fig/project.py:163(build)
        1    0.000    0.000    4.843    4.843 fig/project.py:170(up)
        4    0.000    0.000    1.997    0.499 docker/client.py:728(pull)

Time is down to 18 seconds, and fig up is now 4 seconds instead of 16.

[dnephin]

This block was moved from _get_container_create_options(), which is mostly focused on building up an options dict. It feels a lot more appropriate here, since this function is doing other docker operations related to creating the container.

[bfirsh]

👍

[dnephin]

I guess I forgot to mention this is backwards compatible, the flag defaults to the old behaviour.

[bfirsh]

Would be nice to get this in. Needs a rebase now, though.

[dnephin]

Rebased (and fixed new tests that used the old start_container())

[dnephin]

Another rebase

[dnephin]

This branch seems to be pretty prone to conflicts.

Got any feedback on this branch @aanand, see anything concerning that might delay a merge?

[bfirsh]

LGTM

@aanand any opinions on the new option?

[aanand]

LGTM

The new option sounds sensible to me. In future (as you outline in #693) we might make fig up --no-build the default/only behaviour, but that still needs thinking about. For now, --no-build addresses a real problem, so I'm happy with it.

Once you've rebased, feel free to merge it straight away.

[dnephin]

We've noticed an interesting issue with wercker. If you set up wercker on your own fork, it won't run for pull requests on the upstream repo.

I just set that up the other day, and now it's running this PR here (https://app.wercker.com/#buildstep/54a445852ca6bc215572b0b0), but I don't think it ever gets linked up to this PR.

[dnephin]

The build passed. I also sent some feedback to wercker about the issue. I wasn't able to find a bug tracker, so I just used the feedback form on their site.

[bfirsh]

[bfirsh]

There is a shiny new jenkins instance for the docker project now, so we might be able to use that. https://jenkins.dockerproject.com/