docker logs and buffered output

Question

I want to continously print dots without newline (waiting behavior).

This bash one-liner works fine on my machine:

$ while true; do sleep 1; printf '.'; done
.......^C

However, when I run it in a Docker container, and when I try to read its output with docker logs, no output is printed:

$ docker run -d --name test_logs ubuntu:14.04 bash -c "while true; do sleep 1; printf '.'; done"
60627015ed0a0d331a26e0c48ccad31c641f2142da55d24e10f7ad5737211a18
$ docker logs test_logs
$ docker logs -f test_logs
^C

I can confirm that the bash loop is executing in the container by using strace on process 1 (bash command):

$ docker exec -t test bash -c 'apt-get install -y strace; strace -p1 -s9999 -e write'
Reading package lists... Done
Building dependency tree
Reading state information... Done
The following NEW packages will be installed:
  strace
0 upgraded, 1 newly installed, 0 to remove and 0 not upgraded.
Need to get 113 kB of archives.
After this operation, 504 kB of additional disk space will be used.
Get:1 http://archive.ubuntu.com/ubuntu/ trusty/main strace amd64 4.8-1ubuntu5 [113 kB]
Fetched 113 kB in 0s (154 kB/s)
debconf: unable to initialize frontend: Dialog
debconf: (TERM is not set, so the dialog frontend is not usable.)
debconf: falling back to frontend: Readline
Selecting previously unselected package strace.
(Reading database ... 11542 files and directories currently installed.)
Preparing to unpack .../strace_4.8-1ubuntu5_amd64.deb ...
Unpacking strace (4.8-1ubuntu5) ...
Setting up strace (4.8-1ubuntu5) ...
Process 1 attached
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=136, si_status=0, si_utime=0, si_stime=0} ---
write(1, ".", 1)                        = 1
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=153, si_status=0, si_utime=0, si_stime=0} ---
write(1, ".", 1)                        = 1
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=154, si_status=0, si_utime=0, si_stime=0} ---
write(1, ".", 1)                        = 1
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=155, si_status=0, si_utime=0, si_stime=0} ---
write(1, ".", 1)                        = 1

...and so on.

Also, it works fine when directly watching output with option -t (without using docker logs):

$ docker run -t --name test_logs ubuntu:14.04 bash -c "while true; do sleep 1; printf '.'; done"
...........^C

Even weirder, background + pseudo-tty (option -d + option -t) worked once, but then didn't work anymore.

printf is a line-buffered command, and if I add flushing by printing a newline character, it works:

$ docker run -d --name test_logs ubuntu:14.04 bash -c "while true; do sleep 1; printf '.\n'; done"
720e274fcf85f52587b8a2a402465407c5e925c41d80af05ad3a73cebaf7110f
$ docker logs -f test_logs
.
.
.
.
.
.
^C

So I tried to "unbuffer" printf with stdbuf, without any success:

$ docker run -d --name test_logs ubuntu:14.04 bash -c "while true; do sleep 1; stdbuf -o0 printf '.'; done"
2ba2116190c1b510288144dc5a220669f52f701c17f6f102e6bd6af88de4674e
$  docker logs test_logs
$ docker logs -f test_logs
^C

Next I tried to redirect printf to the standard error, still without success:

$ docker run -d --name test_logs ubuntu:14.04 bash -c "while true; do sleep 1; printf '.' >&2; done"
b1645b48bd9afd5b72318fba5296157ce1c0346f6a82fa166e802a979c1b0b0f
$ docker logs test_logs
$ docker logs -f test_logs
^C

...and with both at the same time, still without success:

$  docker run -d --name test_logs ubuntu:14.04 bash -c "while true; do sleep 1; stdbuf -o0 printf '.' >&2; done"

I encountered the same behaviour when using echo -n instead of printf.

My questions: Do I unbuffer correctly? If yes, what makes it not working?

Looking for insight on this :)

Answer 1

The default docker logging driver (json-file) does not supported unbuffered output. You will eventually see your dots, but only after the buffer has been filled.

If you need unbuffered output, you can use the syslog logging driver. However, because it's syslog, I doubt that will give you what you want since it will be delivering unbuffered output to syslog. Documented here on docs.docker.com

Since running dots are usually useful only in interactive situations where seeing more dots means that work is continuing, you may just want to put out a periodic status with a newline so docker logs gives you better information.

The solution here is usually to check to see if you are in interactive mode, and if so, show the dots:

#!/bin/bash
while true; do
     if [ -t ]; then
         echo -n .
     elif ((++COUNT % 60 == 0)); then
         echo "$(date) still in progress"
     fi
     sleep 1   # or whatever work is going on
done