Skip to content

Implement the "logs" endpoint for the journald log driver#13707

Merged
LK4D4 merged 1 commit intomoby:masterfrom
nalind:journald-logs
Sep 11, 2015
Merged

Implement the "logs" endpoint for the journald log driver#13707
LK4D4 merged 1 commit intomoby:masterfrom
nalind:journald-logs

Conversation

@nalind
Copy link
Contributor

@nalind nalind commented Jun 3, 2015

This change set uses the journald libraries to read log entries from the journal, and hooks that up to the "logs" endpoint. It moves handling of the --last option out of the endpoint logic and into the log drivers themselves, because doing so has the potential cut down on how much data the journald driver will have to dump to its pipe.

It's multiple patches to hopefully be easier to review, but I have no qualms about squashing things together if that's preferred.

@rhatdan
Copy link
Contributor

rhatdan commented Jun 8, 2015

Any comment from upstream? This would be a really nice feature. I already have logging people asking me about it.

@thaJeztah
Copy link
Member

Think they've been busy bug-hunting for the release.

@LK4D4
Copy link
Contributor

LK4D4 commented Jun 8, 2015

I get Unrecognized input header with this driver. Also I have double output for json-file log-driver on first run of docker logs -f.

@nalind
Copy link
Contributor Author

nalind commented Jun 8, 2015

I can't reproduce the first symptom; can you give me more details about how you're getting it to happen? The duplicate log data doesn't appear to be driver-specific (now that I know what to look for, I'm seeing it with the journald driver, too), but it goes away if I revert 153f98b.

@LK4D4
Copy link
Contributor

LK4D4 commented Jun 8, 2015

@nalind I run

docker run -d --log-driver=journald busybox ping google.com

and then just do docker logs -f on that container. Nothing in daemon logs also.

@nalind
Copy link
Contributor Author

nalind commented Jun 8, 2015

Ah, thanks! It's still not giving me the Unrecognized input header error, though it does show me the first few lines of the output twice if I run docker logs -f quickly enough.

It looks as though, if the client and daemon disagreed about whether or not the container had a tty allocated to it, that the data stream coming back from the server wouldn't be muxed using an stdcopy.StdWriter, so it wouldn't be in the format that stdcopy.StdCopy expects to demux, and that should cause the Unrecognized input header message to appear, but I'm at a loss as to how to actually trigger it.

@LK4D4
Copy link
Contributor

LK4D4 commented Jun 8, 2015

@nalind I'm using systemd-220. Maybe it returns crap instead of logs sometimes.

@nalind
Copy link
Contributor Author

nalind commented Jun 8, 2015

I'm also running with version 220 (Fedora 23's systemd-220-3.fc23), but the like messages we retrieve from json-logs, data we read back from the journal should be wrapped up and chunked before it gets to the client, so if the driver was getting garbage back, I'd expect to get garbage in the output of the docker logs command rather than an error parsing the HTTP stream that's carrying it. Is there anything else that might be making a difference?

@LK4D4
Copy link
Contributor

LK4D4 commented Jun 8, 2015

@nalind I can't imagine. I'll try to put some logging to your code later.

@nalind
Copy link
Contributor Author

nalind commented Jun 9, 2015

Ah, found it. When built without the journald tag, which the build scripts try to enable automatically when the libraries are detected, this is triggered when the daemon sends back an error message indicating that it couldn't read the logs, because it sends that message back without the framing that the client is expecting.

The Dockerfile installs libsystemd-journal-dev, and hack/make.sh tries to check for it, but that check fails because pkg-config isn't also available, so the journald build tag wasn't being enabled. Adding it as a requirement to the top-level Dockerfile should handle most of the cases that the changes to contrib/builder/deb/generate.sh and hack/make/.build-rpm/docker-engine.spec didn't already cover.

As for the formatting of the error when it's sent back to the client, if ContainerLogs replaces the OutStream member of the ContainerLogsConfig that it gets with its wrapper, and getContainersLogs sends the error message through that, the client displays the error that the server sent.

I'm tweaking the patch set to fix both of these problems and rebasing against the current master.

@nalind
Copy link
Contributor Author

nalind commented Jun 11, 2015

Rebasing to resolve reported merge conflicts.

@nalind nalind force-pushed the journald-logs branch 5 times, most recently from 5fa6cbf to 9a0d79e Compare June 18, 2015 13:23
@nalind
Copy link
Contributor Author

nalind commented Jun 26, 2015

Catching up with the new fluentd driver.

@nalind nalind force-pushed the journald-logs branch 2 times, most recently from 61a5dca to b27de40 Compare June 26, 2015 16:35
@thaJeztah
Copy link
Member

ping @LK4D4 have you been able to successfully test this?

@cpuguy83
Copy link
Member

Hi, the log reader interface was refactored and should (I hope!) be much simpler to implement now, as all you need to do is implement a ReadLogs function on journald.

@LK4D4
Copy link
Contributor

LK4D4 commented Jul 22, 2015

Yes, I waited for this refactoring. Now implementation of journald logs should be simpler and more robust.

@nalind
Copy link
Contributor Author

nalind commented Jul 22, 2015

The current refactor keeps knowledge of the number of lines to read when it's in "last" mode, and the cutoff time in "since" mode, in ContainerLogs. The journald driver could definitely use that information to skip sending data that is only going to be ignored by ContainerLogs, and I suspect other log readers would, too. (The current ContainerLogs also spends some time dealing with file numbers, which really seems to me like a jsonfilelog-specific notion, but a reader can ignore that.)

@cpuguy83
Copy link
Member

@nalind Not anymore. ContainerLogs does nothing except call the ReadLogs on the configured logger and Listens for logger.Messages on a channel.

@nalind
Copy link
Contributor Author

nalind commented Jul 22, 2015

@cpuguy83 Oh, you're right, that's new today, and it's much better.

@LK4D4
Copy link
Contributor

LK4D4 commented Dec 7, 2015

@dmp1ce Are you getting error or not? I'm not sure how your docker is built, but with --log-driver=journalctl all should work fine.

@dmp1ce
Copy link

dmp1ce commented Dec 7, 2015

@LK4D4 Sorry, I AM getting the error. I updated my comment with the removed "not".

I'm installing using the instructions here: https://docs.docker.com/engine/installation/ubuntulinux/

I'm using the journald driver using Docker Compose and docker run --log-driver=journald. I'm not using --log-driver=journalctl.

@LK4D4
Copy link
Contributor

LK4D4 commented Dec 7, 2015

@dmp1ce it should be fine if binary built as dynamic with journald build-tag. I think @jfrazelle or @tianon know more than me about which binary we ship for ubuntu.

@bobrik
Copy link
Contributor

bobrik commented Jan 21, 2016

I am using official docker-engine package for jessie and getting this message too:

Error running logs job: configured logging reader does not support reading
ivan@36com10:~$ ldd `which docker`
    linux-vdso.so.1 (0x00007ffdec1b1000)
    libapparmor.so.1 => /usr/lib/x86_64-linux-gnu/libapparmor.so.1 (0x00007fe08b90a000)
    libpthread.so.0 => /lib/x86_64-linux-gnu/libpthread.so.0 (0x00007fe08b6ed000)
    libdl.so.2 => /lib/x86_64-linux-gnu/libdl.so.2 (0x00007fe08b4e8000)
    libdevmapper.so.1.02.1 => /lib/x86_64-linux-gnu/libdevmapper.so.1.02.1 (0x00007fe08b29f000)
    libc.so.6 => /lib/x86_64-linux-gnu/libc.so.6 (0x00007fe08aef6000)
    /lib64/ld-linux-x86-64.so.2 (0x0000562f5b55f000)
    libselinux.so.1 => /lib/x86_64-linux-gnu/libselinux.so.1 (0x00007fe08acd0000)
    libudev.so.1 => /lib/x86_64-linux-gnu/libudev.so.1 (0x00007fe08aac1000)
    libpcre.so.3 => /lib/x86_64-linux-gnu/libpcre.so.3 (0x00007fe08a853000)
    librt.so.1 => /lib/x86_64-linux-gnu/librt.so.1 (0x00007fe08a64a000)

Getting logs through journalctl works except for #15722.

@LK4D4
Copy link
Contributor

LK4D4 commented Jan 21, 2016

@bobrik How do you start your container and what version do you use? Seems like works fine for me on master with

docker run -it --rm --log-driver=journald busybox ping google.com

@tianon
Copy link
Member

tianon commented Jan 21, 2016 via email

@bobrik
Copy link
Contributor

bobrik commented Jan 21, 2016

$ docker run -it --rm --log-driver=journald --name nope busybox ping google.com
$ docker logs nope
Error running logs job: configured logging reader does not support reading
$ docker version
Client:
 Version:      1.9.1
 API version:  1.21
 Go version:   go1.4.2
 Git commit:   a34a1d5
 Built:        Fri Nov 20 12:59:02 UTC 2015
 OS/Arch:      linux/amd64

Server:
 Version:      1.9.1
 API version:  1.21
 Go version:   go1.4.2
 Git commit:   a34a1d5
 Built:        Fri Nov 20 12:59:02 UTC 2015
 OS/Arch:      linux/amd64
$ docker info
Containers: 263
Images: 1716
Server Version: 1.9.1
Storage Driver: overlay
 Backing Filesystem: xfs
Execution Driver: native-0.2
Logging Driver: json-file
Kernel Version: 4.1.3-wtf
Operating System: Debian GNU/Linux 8 (jessie)
CPUs: 32
Total Memory: 125.8 GiB
Name: 36com10
ID: CEGP:5ZLU:4ZGY:IQD7:RBMI:FB7A:JOB7:QP7Z:AXVM:N7Q5:Z5YH:YNLO
WARNING: No swap limit support

@LK4D4
Copy link
Contributor

LK4D4 commented Jan 21, 2016

I think it's packaging problem. The binary must be linked with libsystemd.
Am I right, @tianon ?

@tianon
Copy link
Member

tianon commented Jan 22, 2016

Interesting, I can reproduce on both 1.9.1 and 1.10.0-rc1 using the official docker-engine Debian packages (for debian-jessie specifically); both give something like:

Error running logs job: configured logging reader does not support reading

@LK4D4
Copy link
Contributor

LK4D4 commented Jan 22, 2016

@tianon check ldd. Also, maybe we don't set journald tag.

@nalind
Copy link
Contributor Author

nalind commented Jan 22, 2016

Hmm, I think the build containers (per contrib/builder/deb/generate.sh) might not have pkg-config in them. I had erroneously assumed that they were pulled in by build-essential on Debian, and the various development tools groups.

If nm -CDu /usr/bin/docker | grep sd_journal_add_match turns up empty, then the logic's not getting compiled in.

@tianon
Copy link
Member

tianon commented Jan 22, 2016

Yeah, I don't see systemd or journal anywhere in ldd, so I'll be digging into the build containers next.

@tianon
Copy link
Member

tianon commented Jan 22, 2016

$ nm -CDu /usr/bin/docker | grep sd_journal_add_match
$ 

Into the build system I go! 😄

@tianon
Copy link
Member

tianon commented Jan 22, 2016

Man, I could've sworn pkg-config was part of build-essential also, but it's not there!

@dmp1ce
Copy link

dmp1ce commented Feb 11, 2016

I have Ubuntu 15.10 running with Docker version 1.10.0. I'm still getting Error running logs job: configured logging reader does not support reading. Should this have been fixed?

@thaJeztah thaJeztah added this to the 1.9.0 milestone Feb 11, 2016
@nalind
Copy link
Contributor Author

nalind commented Feb 17, 2016

Yes, it should have. When I poke at the packages in the apt repository, I'm finding the expected references to the right unresolved symbols in the 1.10.1 packages for jessie, precise, trusty, and wheezy, but not in the packages for stretch or wily.

On stretch and wily, the expected headers are included in libsystemd-dev, which the build scripts install, but there is no libsystemd-journal.pc for pkg-config to find when hack/make.sh calls it, so the logic doesn't get built at build-time. Given that those are newer versions, we might be better off changing pkg-config references to just look for libsystemd, and have make.sh look for a version of it that's at least 209, when systemd's news file says those were all merged together.

@nalind
Copy link
Contributor Author

nalind commented Feb 17, 2016

Whoops, packages for precise and wheezy don't link with the right libraries - I was taking their packages apart wrong. So only jessie and trusty are being built with the feature.

@dmp1ce
Copy link

dmp1ce commented Feb 18, 2016

@nalind OK. Thanks. Is this already merged then for Wily? What about the future Xenial?

@nalind
Copy link
Contributor Author

nalind commented Feb 18, 2016

@dmp1ce I was mistaken in thinking that we could fix it by changing the pkg-config dependency (we'd stop pulling things in on older releases, and there's no single option that's present across all of the desired build targets), so that was closed without merging. So for the moment at least, it's not working in stretch or wily.

@dmp1ce
Copy link

dmp1ce commented Feb 18, 2016

@nalind Should I create an issue for Wily?

@nalind
Copy link
Contributor Author

nalind commented Feb 18, 2016

@dmp1ce Yeah, I think that's how we make sure it stays on the radar.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.