github.com/clintkitson/docker@v1.9.1/daemon/logger/journald/read.go (about)

     1  // +build linux,cgo,!static_build,journald
     2  
     3  package journald
     4  
     5  // #cgo pkg-config: libsystemd-journal
     6  // #include <sys/types.h>
     7  // #include <sys/poll.h>
     8  // #include <systemd/sd-journal.h>
     9  // #include <errno.h>
    10  // #include <stdio.h>
    11  // #include <stdlib.h>
    12  // #include <string.h>
    13  // #include <time.h>
    14  // #include <unistd.h>
    15  //
    16  //static int get_message(sd_journal *j, const char **msg, size_t *length)
    17  //{
    18  //	int rc;
    19  //	*msg = NULL;
    20  //	*length = 0;
    21  //	rc = sd_journal_get_data(j, "MESSAGE", (const void **) msg, length);
    22  //	if (rc == 0) {
    23  //		if (*length > 8) {
    24  //			(*msg) += 8;
    25  //			*length -= 8;
    26  //		} else {
    27  //			*msg = NULL;
    28  //			*length = 0;
    29  //			rc = -ENOENT;
    30  //		}
    31  //	}
    32  //	return rc;
    33  //}
    34  //static int get_priority(sd_journal *j, int *priority)
    35  //{
    36  //	const void *data;
    37  //	size_t i, length;
    38  //	int rc;
    39  //	*priority = -1;
    40  //	rc = sd_journal_get_data(j, "PRIORITY", &data, &length);
    41  //	if (rc == 0) {
    42  //		if ((length > 9) && (strncmp(data, "PRIORITY=", 9) == 0)) {
    43  //			*priority = 0;
    44  //			for (i = 9; i < length; i++) {
    45  //				*priority = *priority * 10 + ((const char *)data)[i] - '0';
    46  //			}
    47  //			if (length > 9) {
    48  //				rc = 0;
    49  //			}
    50  //		}
    51  //	}
    52  //	return rc;
    53  //}
    54  //static int wait_for_data_or_close(sd_journal *j, int pipefd)
    55  //{
    56  //	struct pollfd fds[2];
    57  //	uint64_t when = 0;
    58  //	int timeout, jevents, i;
    59  //	struct timespec ts;
    60  //	uint64_t now;
    61  //	do {
    62  //		memset(&fds, 0, sizeof(fds));
    63  //		fds[0].fd = pipefd;
    64  //		fds[0].events = POLLHUP;
    65  //		fds[1].fd = sd_journal_get_fd(j);
    66  //		if (fds[1].fd < 0) {
    67  //			return -1;
    68  //		}
    69  //		jevents = sd_journal_get_events(j);
    70  //		if (jevents < 0) {
    71  //			return -1;
    72  //		}
    73  //		fds[1].events = jevents;
    74  //		sd_journal_get_timeout(j, &when);
    75  //		if (when == -1) {
    76  //			timeout = -1;
    77  //		} else {
    78  //			clock_gettime(CLOCK_MONOTONIC, &ts);
    79  //			now = (uint64_t) ts.tv_sec * 1000000 + ts.tv_nsec / 1000;
    80  //			timeout = when > now ? (int) ((when - now + 999) / 1000) : 0;
    81  //		}
    82  //		i = poll(fds, 2, timeout);
    83  //		if ((i == -1) && (errno != EINTR)) {
    84  //			/* An unexpected error. */
    85  //			return -1;
    86  //		}
    87  //		if (fds[0].revents & POLLHUP) {
    88  //			/* The close notification pipe was closed. */
    89  //			return 0;
    90  //		}
    91  //		if (sd_journal_process(j) == SD_JOURNAL_APPEND) {
    92  //			/* Data, which we might care about, was appended. */
    93  //			return 1;
    94  //		}
    95  //	} while ((fds[0].revents & POLLHUP) == 0);
    96  //	return 0;
    97  //}
    98  import "C"
    99  
   100  import (
   101  	"fmt"
   102  	"time"
   103  	"unsafe"
   104  
   105  	"github.com/coreos/go-systemd/journal"
   106  	"github.com/docker/docker/daemon/logger"
   107  )
   108  
   109  func (s *journald) Close() error {
   110  	s.readers.mu.Lock()
   111  	for reader := range s.readers.readers {
   112  		reader.Close()
   113  	}
   114  	s.readers.mu.Unlock()
   115  	return nil
   116  }
   117  
   118  func (s *journald) drainJournal(logWatcher *logger.LogWatcher, config logger.ReadConfig, j *C.sd_journal, oldCursor string) string {
   119  	var msg, cursor *C.char
   120  	var length C.size_t
   121  	var stamp C.uint64_t
   122  	var priority C.int
   123  
   124  	// Walk the journal from here forward until we run out of new entries.
   125  drain:
   126  	for {
   127  		// Try not to send a given entry twice.
   128  		if oldCursor != "" {
   129  			ccursor := C.CString(oldCursor)
   130  			defer C.free(unsafe.Pointer(ccursor))
   131  			for C.sd_journal_test_cursor(j, ccursor) > 0 {
   132  				if C.sd_journal_next(j) <= 0 {
   133  					break drain
   134  				}
   135  			}
   136  		}
   137  		// Read and send the logged message, if there is one to read.
   138  		i := C.get_message(j, &msg, &length)
   139  		if i != -C.ENOENT && i != -C.EADDRNOTAVAIL {
   140  			// Read the entry's timestamp.
   141  			if C.sd_journal_get_realtime_usec(j, &stamp) != 0 {
   142  				break
   143  			}
   144  			// Set up the time and text of the entry.
   145  			timestamp := time.Unix(int64(stamp)/1000000, (int64(stamp)%1000000)*1000)
   146  			line := append(C.GoBytes(unsafe.Pointer(msg), C.int(length)), "\n"...)
   147  			// Recover the stream name by mapping
   148  			// from the journal priority back to
   149  			// the stream that we would have
   150  			// assigned that value.
   151  			source := ""
   152  			if C.get_priority(j, &priority) != 0 {
   153  				source = ""
   154  			} else if priority == C.int(journal.PriErr) {
   155  				source = "stderr"
   156  			} else if priority == C.int(journal.PriInfo) {
   157  				source = "stdout"
   158  			}
   159  			// Send the log message.
   160  			cid := s.vars["CONTAINER_ID_FULL"]
   161  			logWatcher.Msg <- &logger.Message{ContainerID: cid, Line: line, Source: source, Timestamp: timestamp}
   162  		}
   163  		// If we're at the end of the journal, we're done (for now).
   164  		if C.sd_journal_next(j) <= 0 {
   165  			break
   166  		}
   167  	}
   168  	retCursor := ""
   169  	if C.sd_journal_get_cursor(j, &cursor) == 0 {
   170  		retCursor = C.GoString(cursor)
   171  		C.free(unsafe.Pointer(cursor))
   172  	}
   173  	return retCursor
   174  }
   175  
   176  func (s *journald) followJournal(logWatcher *logger.LogWatcher, config logger.ReadConfig, j *C.sd_journal, pfd [2]C.int, cursor string) {
   177  	go func() {
   178  		// Keep copying journal data out until we're notified to stop.
   179  		for C.wait_for_data_or_close(j, pfd[0]) == 1 {
   180  			cursor = s.drainJournal(logWatcher, config, j, cursor)
   181  		}
   182  		// Clean up.
   183  		C.close(pfd[0])
   184  		s.readers.mu.Lock()
   185  		delete(s.readers.readers, logWatcher)
   186  		s.readers.mu.Unlock()
   187  	}()
   188  	s.readers.mu.Lock()
   189  	s.readers.readers[logWatcher] = logWatcher
   190  	s.readers.mu.Unlock()
   191  	// Wait until we're told to stop.
   192  	select {
   193  	case <-logWatcher.WatchClose():
   194  		// Notify the other goroutine that its work is done.
   195  		C.close(pfd[1])
   196  	}
   197  }
   198  
   199  func (s *journald) readLogs(logWatcher *logger.LogWatcher, config logger.ReadConfig) {
   200  	var j *C.sd_journal
   201  	var cmatch *C.char
   202  	var stamp C.uint64_t
   203  	var sinceUnixMicro uint64
   204  	var pipes [2]C.int
   205  	cursor := ""
   206  
   207  	defer close(logWatcher.Msg)
   208  	// Get a handle to the journal.
   209  	rc := C.sd_journal_open(&j, C.int(0))
   210  	if rc != 0 {
   211  		logWatcher.Err <- fmt.Errorf("error opening journal")
   212  		return
   213  	}
   214  	defer C.sd_journal_close(j)
   215  	// Remove limits on the size of data items that we'll retrieve.
   216  	rc = C.sd_journal_set_data_threshold(j, C.size_t(0))
   217  	if rc != 0 {
   218  		logWatcher.Err <- fmt.Errorf("error setting journal data threshold")
   219  		return
   220  	}
   221  	// Add a match to have the library do the searching for us.
   222  	cmatch = C.CString("CONTAINER_ID_FULL=" + s.vars["CONTAINER_ID_FULL"])
   223  	defer C.free(unsafe.Pointer(cmatch))
   224  	rc = C.sd_journal_add_match(j, unsafe.Pointer(cmatch), C.strlen(cmatch))
   225  	if rc != 0 {
   226  		logWatcher.Err <- fmt.Errorf("error setting journal match")
   227  		return
   228  	}
   229  	// If we have a cutoff time, convert it to Unix time once.
   230  	if !config.Since.IsZero() {
   231  		nano := config.Since.UnixNano()
   232  		sinceUnixMicro = uint64(nano / 1000)
   233  	}
   234  	if config.Tail > 0 {
   235  		lines := config.Tail
   236  		// Start at the end of the journal.
   237  		if C.sd_journal_seek_tail(j) < 0 {
   238  			logWatcher.Err <- fmt.Errorf("error seeking to end of journal")
   239  			return
   240  		}
   241  		if C.sd_journal_previous(j) < 0 {
   242  			logWatcher.Err <- fmt.Errorf("error backtracking to previous journal entry")
   243  			return
   244  		}
   245  		// Walk backward.
   246  		for lines > 0 {
   247  			// Stop if the entry time is before our cutoff.
   248  			// We'll need the entry time if it isn't, so go
   249  			// ahead and parse it now.
   250  			if C.sd_journal_get_realtime_usec(j, &stamp) != 0 {
   251  				break
   252  			} else {
   253  				// Compare the timestamp on the entry
   254  				// to our threshold value.
   255  				if sinceUnixMicro != 0 && sinceUnixMicro > uint64(stamp) {
   256  					break
   257  				}
   258  			}
   259  			lines--
   260  			// If we're at the start of the journal, or
   261  			// don't need to back up past any more entries,
   262  			// stop.
   263  			if lines == 0 || C.sd_journal_previous(j) <= 0 {
   264  				break
   265  			}
   266  		}
   267  	} else {
   268  		// Start at the beginning of the journal.
   269  		if C.sd_journal_seek_head(j) < 0 {
   270  			logWatcher.Err <- fmt.Errorf("error seeking to start of journal")
   271  			return
   272  		}
   273  		// If we have a cutoff date, fast-forward to it.
   274  		if sinceUnixMicro != 0 && C.sd_journal_seek_realtime_usec(j, C.uint64_t(sinceUnixMicro)) != 0 {
   275  			logWatcher.Err <- fmt.Errorf("error seeking to start time in journal")
   276  			return
   277  		}
   278  		if C.sd_journal_next(j) < 0 {
   279  			logWatcher.Err <- fmt.Errorf("error skipping to next journal entry")
   280  			return
   281  		}
   282  	}
   283  	cursor = s.drainJournal(logWatcher, config, j, "")
   284  	if config.Follow {
   285  		// Create a pipe that we can poll at the same time as the journald descriptor.
   286  		if C.pipe(&pipes[0]) == C.int(-1) {
   287  			logWatcher.Err <- fmt.Errorf("error opening journald close notification pipe")
   288  		} else {
   289  			s.followJournal(logWatcher, config, j, pipes, cursor)
   290  		}
   291  	}
   292  	return
   293  }
   294  
   295  func (s *journald) ReadLogs(config logger.ReadConfig) *logger.LogWatcher {
   296  	logWatcher := logger.NewLogWatcher()
   297  	go s.readLogs(logWatcher, config)
   298  	return logWatcher
   299  }