Compose: Logs are preserved (possibly erroneously) across launches.

[lxe]

I'm not sure if this is a feature of a bug. I've installed docker-compose version: 1.4.0 from homebrew and I'm seeing logs getting preserved across runs:

docker-compose.yml

helloworld:
  image: busybox
  command: echo "Hello World!"

Here's the log of multiple docker-compose up:

~/dockercompose-test ❯❯❯ docker-compose up
Starting dockercomposetest_helloworld_1...
Attaching to dockercomposetest_helloworld_1
helloworld_1 | Hello World!
dockercomposetest_helloworld_1 exited with code 0
Gracefully stopping... (press Ctrl+C again to force)
~/dockercompose-test ❯❯❯ docker-compose up
Starting dockercomposetest_helloworld_1...
Attaching to dockercomposetest_helloworld_1
helloworld_1 | Hello World!
helloworld_1 | Hello World!
dockercomposetest_helloworld_1 exited with code 0
Gracefully stopping... (press Ctrl+C again to force)
~/dockercompose-test ❯❯❯ docker-compose up
Starting dockercomposetest_helloworld_1...
Attaching to dockercomposetest_helloworld_1
helloworld_1 | Hello World!
helloworld_1 | Hello World!
helloworld_1 | Hello World!
dockercomposetest_helloworld_1 exited with code 0
Gracefully stopping... (press Ctrl+C again to force)
~/dockercompose-test ❯❯❯ docker-compose --version

As you can see the logs are getting preserved across the runs.

[dnephin]

This is because after 1.4.0 we don't destroy the container on up if the config hasn't changed. So it's actually starting the same container, not recreating it, which means the logs are still there from previous runs.

You can disable this feature with docker-compose up --force-recreate or by removing the containers yourself with docker-compsoe rm

[lxe]

@dnephin makes sense. --force-recreate does fix this. However there still is something strange happening:

I changed the 'echo' to 'date -T' to demonstrate:

Run 1:

~/dockercompose-test ❯❯❯ docker-compose up
Recreating dockercomposetest_helloworld_1...
Attaching to dockercomposetest_helloworld_1
helloworld_1 | Fri, 28 Aug 2015 18:42:10 +0000
dockercomposetest_helloworld_1 exited with code 0
Gracefully stopping... (press Ctrl+C again to force)

^ Shows the log as expected

---

Run 2:

~/dockercompose-test ❯❯❯ docker-compose up
Starting dockercomposetest_helloworld_1...
Attaching to dockercomposetest_helloworld_1
helloworld_1 | Fri, 28 Aug 2015 18:42:10 +0000
helloworld_1 | Fri, 28 Aug 2015 18:42:12 +0000
dockercomposetest_helloworld_1 exited with code 0
Gracefully stopping... (press Ctrl+C again to force)

^ Shows the new log and the old log

---

Run 3:

~/dockercompose-test ❯❯❯ docker-compose up
Starting dockercomposetest_helloworld_1...
Attaching to dockercomposetest_helloworld_1
helloworld_1 | Fri, 28 Aug 2015 18:42:10 +0000
helloworld_1 | Fri, 28 Aug 2015 18:42:12 +0000
dockercomposetest_helloworld_1 exited with code 0
Gracefully stopping... (press Ctrl+C again to force)

^ Shows only the old logs, and does not show the new logs :(

---

Run 4:

~/dockercompose-test ❯❯❯ docker-compose up
Starting dockercomposetest_helloworld_1...
Attaching to dockercomposetest_helloworld_1
helloworld_1 | Fri, 28 Aug 2015 18:42:10 +0000
helloworld_1 | Fri, 28 Aug 2015 18:42:12 +0000
helloworld_1 | Fri, 28 Aug 2015 18:42:15 +0000
helloworld_1 | Fri, 28 Aug 2015 18:42:18 +0000
dockercomposetest_helloworld_1 exited with code 0
Gracefully stopping... (press Ctrl+C again to force)

^ Now it's showing the new log, Logs from 1, 2, and the missed log from Run 3

[terbooter]

I have been updated docker-compose from 1.2.0 to 1.4.0 and spend twenty crazy minutes trying to find out what is going on with my logs after docker-compose up
docker-compose up --force-recreate solve this problem.
But why you are breaking utility contract in major version without any warning?

[pwaller]

Ouch! I like that it doesn't recreate the container (it's noticeably faster to boot up), but showing the logs from last time is highly confusing and spammy in my terminal. I have two services, one of which I want to see the logs of, and the other I don't. Now when I say docker-compose up (which I've diligently trained everyone in my org to do), the important logs are buried in unimportant logs from the other service from a previous start.

[aanand]

This is really a bug caused by a workaround for another bug.

On docker-compose up, we start the containers before attaching to them. This can cause a race condition where a container produces some output before we attach to it, meaning it'll be missing from the aggregated output of docker-compose up. To ensure we get that output, we attach with logs=True, which gives us the container's full output from when it started.

Back when we always recreated containers, this was fine, but now that they're longer-lived it makes for lots of log output. The correct solution is to change the order of API calls:

• recreate if necessary
• attach
• start if necessary

However, this will involve a significant refactoring, because right now the recreate + start steps are tightly coupled. See #1510 for a sketch of one possible solution, but we're still figuring it out.

[triptec]

I've been using this:
alias docker-logs-truncate="docker-machine ssh default -- 'sudo find /var/lib/docker/containers/ -iname \"*json.log\"|xargs -I{} sudo dd if=/dev/null of={}'"

[mikehaertl]

Isn't this a duplicate of #1756?

[dnephin]

It is. Closing as duplicate, Thanks!