Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Logs are preserved (possibly erroneously) across launches. #1946

Closed
lxe opened this issue Aug 28, 2015 · 8 comments
Closed

Logs are preserved (possibly erroneously) across launches. #1946

lxe opened this issue Aug 28, 2015 · 8 comments

Comments

@lxe
Copy link

lxe commented Aug 28, 2015

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
Copy link

dnephin commented Aug 28, 2015

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
Copy link
Author

lxe commented Aug 28, 2015

@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
Copy link

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
Copy link

pwaller commented Sep 3, 2015

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
Copy link

aanand commented Sep 3, 2015

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
Copy link

triptec commented Sep 5, 2015

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
Copy link

Isn't this a duplicate of #1756?

@dnephin
Copy link

dnephin commented Oct 22, 2015

It is. Closing as duplicate, Thanks!

@dnephin dnephin closed this as completed Oct 22, 2015
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

7 participants