ahmetb
"dlog: unexpected stream byte" when header bytes are absent
$ docker run -t --entrypoint bash --name example nginx:1.13.1 -c 'ls'
bin dev home lib32 libx32 mnt proc run srv tmp var
boot etc lib lib64 media opt root sbin sys usr
$ curl -sN --unix-socket /var/run/docker.sock "http://./containers/example/logs?stdout=1&stderr=1" | hexdump -C
00000000 62 69 6e 20 20 20 64 65 76 20 20 68 6f 6d 65 20 |bin dev home |
00000010 20 6c 69 62 33 32 09 6c 69 62 78 33 32 09 6d 6e | lib32.libx32.mn|
00000020 74 20 20 70 72 6f 63 20 20 72 75 6e 09 20 73 72 |t proc run. sr|
00000030 76 20 20 74 6d 70 20 20 76 61 72 0d 0a 62 6f 6f |v tmp var..boo|
00000040 74 20 20 65 74 63 20 20 6c 69 62 09 20 6c 69 62 |t etc lib. lib|
00000050 36 34 09 6d 65 64 69 61 09 6f 70 74 20 20 72 6f |64.media.opt ro|
00000060 6f 74 20 20 73 62 69 6e 20 20 73 79 73 20 20 75 |ot sbin sys u|
00000070 73 72 0d 0a |sr..|
00000074
Here I've created a container with -t and run a command. The Docker socket does not have the expected prefix, leading to dlog reporting the error "dlog: unexpected stream byte".
The docker logs command does the right thing:
$ docker logs example
bin dev home lib32 libx32 mnt proc run srv tmp var
boot etc lib lib64 media opt root sbin sys usr
so it seems dlog doesn't handle this case?
@Wilfred if my memory serves correctly, dlog only handles docker logs "stream".
It looks like you’re getting is just plain text. This might be a recent change in the docker-engine API (maybe they stopped sending streams).
Thankfully I blogged about this when I released this project: https://ahmet.im/blog/docker-logs-api-binary-format-explained/ it looks like the same request (without follow=1) actually returned the proper binary format for me.
Try making the request with &follow=1 (and maybe add -N to curl) and you’ll get the stream output?
dlog won’t handle plain text. It totally expects the "stream" format that used to be there before.
Same behaviour with follow=1:
$ curl -sN --unix-socket /var/run/docker.sock "http://./containers/example/logs?stdout=1&stderr=1&follow=1" | hexdump -C
00000000 62 69 6e 20 20 20 64 65 76 20 20 68 6f 6d 65 20 |bin dev home |
00000010 20 6c 69 62 33 32 09 6c 69 62 78 33 32 09 6d 6e | lib32.libx32.mn|
00000020 74 20 20 70 72 6f 63 20 20 72 75 6e 09 20 73 72 |t proc run. sr|
00000030 76 20 20 74 6d 70 20 20 76 61 72 0d 0a 62 6f 6f |v tmp var..boo|
00000040 74 20 20 65 74 63 20 20 6c 69 62 09 20 6c 69 62 |t etc lib. lib|
00000050 36 34 09 6d 65 64 69 61 09 6f 70 74 20 20 72 6f |64.media.opt ro|
00000060 6f 74 20 20 73 62 69 6e 20 20 73 79 73 20 20 75 |ot sbin sys u|
00000070 73 72 0d 0a |sr..|
00000074
There must be a way of reliably getting the stream, but it's not obvious to me.
The relevant docs do now document the format, and mention TTY specifically as being different: https://docs.docker.com/engine/api/v1.33/#operation/ContainerAttach
Relevant moby code: https://github.com/moby/moby/blob/master/client/container_attach.go#L15-L33
Similar issue in docker-py: https://github.com/docker/docker-py/issues/630
Looks like the correct solution is to inspect the container before deciding whether to use dlog.Newreader or just the underlying stream directly. Perhaps example_test.go could demonstrate this?
$ curl -sN --unix-socket /var/run/docker.sock "http://./containers/example/json" | jq '.Config.Tty'
true
Yes, I remember asking for it to be documented specifically because the only documentation at the time was on my blog. :)
I am happy to merge any documentation changes saying "this library doesn't work if containers are started with TTY (-t)". I am not sure if this applies to a broad set of containers, though. People don’t run their production containers that are logging stuff using TTY. TTY is for interactive human use.