From 8d597d25a86c608e2e1e4ef150d7e9eb68306bc0 Mon Sep 17 00:00:00 2001 From: Nalin Dahyabhai Date: Thu, 17 Mar 2016 18:25:14 -0400 Subject: [PATCH 1/2] Improve error reporting when following journals When we set up to start following a journal, if we get error results from sd_journal_get_fd() or sd_journal_get_events() that prevent us from following the journal, report the error instead of just mysteriously failing. Signed-off-by: Nalin Dahyabhai (github: nalind) --- daemon/logger/journald/read.go | 20 +++++++++++++++----- 1 file changed, 15 insertions(+), 5 deletions(-) diff --git a/daemon/logger/journald/read.go b/daemon/logger/journald/read.go index 3364160b9e..c0bec1f623 100644 --- a/daemon/logger/journald/read.go +++ b/daemon/logger/journald/read.go @@ -63,11 +63,11 @@ package journald // fds[0].events = POLLHUP; // fds[1].fd = sd_journal_get_fd(j); // if (fds[1].fd < 0) { -// return -1; +// return fds[1].fd; // } // jevents = sd_journal_get_events(j); // if (jevents < 0) { -// return -1; +// return jevents; // } // fds[1].events = jevents; // sd_journal_get_timeout(j, &when); @@ -81,7 +81,7 @@ package journald // i = poll(fds, 2, timeout); // if ((i == -1) && (errno != EINTR)) { // /* An unexpected error. */ -// return -1; +// return (errno != 0) ? -errno : -EINTR; // } // if (fds[0].revents & POLLHUP) { // /* The close notification pipe was closed. */ @@ -101,6 +101,7 @@ import ( "time" "unsafe" + "github.com/Sirupsen/logrus" "github.com/coreos/go-systemd/journal" "github.com/docker/docker/daemon/logger" ) @@ -177,9 +178,18 @@ func (s *journald) followJournal(logWatcher *logger.LogWatcher, config logger.Re s.readers.readers[logWatcher] = logWatcher s.readers.mu.Unlock() go func() { - // Keep copying journal data out until we're notified to stop. - for C.wait_for_data_or_close(j, pfd[0]) == 1 { + // Keep copying journal data out until we're notified to stop + // or we hit an error. + status := C.wait_for_data_or_close(j, pfd[0]) + for status == 1 { cursor = s.drainJournal(logWatcher, config, j, cursor) + status = C.wait_for_data_or_close(j, pfd[0]) + } + if status < 0 { + cerrstr := C.strerror(C.int(-status)) + errstr := C.GoString(cerrstr) + fmtstr := "error %q while attempting to follow journal for container %q" + logrus.Errorf(fmtstr, errstr, s.vars["CONTAINER_ID_FULL"]) } // Clean up. C.close(pfd[0]) From ab62ecf393b92d1e644f82c4711b6618b7c572a5 Mon Sep 17 00:00:00 2001 From: Nalin Dahyabhai Date: Fri, 18 Mar 2016 09:06:30 -0400 Subject: [PATCH 2/2] Open the journald following descriptor earlier Following a journal log almost always requires a descriptor to be allocated. In cases where we're running out of descriptors, this means we might get stuck while attempting to start following the journal, at a point where it's too late to report it to the client and clean up easily. The journal reading context will cache the value once it's allocated, so here we move the check earlier, so that we can detect a problem when we can still report it cleanly. Signed-off-by: Nalin Dahyabhai --- daemon/logger/journald/read.go | 21 ++++++++++++++------- 1 file changed, 14 insertions(+), 7 deletions(-) diff --git a/daemon/logger/journald/read.go b/daemon/logger/journald/read.go index c0bec1f623..1b8b8cce10 100644 --- a/daemon/logger/journald/read.go +++ b/daemon/logger/journald/read.go @@ -303,14 +303,21 @@ func (s *journald) readLogs(logWatcher *logger.LogWatcher, config logger.ReadCon } cursor = s.drainJournal(logWatcher, config, j, "") if config.Follow { - // Create a pipe that we can poll at the same time as the journald descriptor. - if C.pipe(&pipes[0]) == C.int(-1) { - logWatcher.Err <- fmt.Errorf("error opening journald close notification pipe") + // Allocate a descriptor for following the journal, if we'll + // need one. Do it here so that we can report if it fails. + if fd := C.sd_journal_get_fd(j); fd < C.int(0) { + logWatcher.Err <- fmt.Errorf("error opening journald follow descriptor: %q", C.GoString(C.strerror(-fd))) } else { - s.followJournal(logWatcher, config, j, pipes, cursor) - // Let followJournal handle freeing the journal context - // object and closing the channel. - following = true + // Create a pipe that we can poll at the same time as + // the journald descriptor. + if C.pipe(&pipes[0]) == C.int(-1) { + logWatcher.Err <- fmt.Errorf("error opening journald close notification pipe") + } else { + s.followJournal(logWatcher, config, j, pipes, cursor) + // Let followJournal handle freeing the journal context + // object and closing the channel. + following = true + } } } return