github.com/hustcat/docker@v1.3.3-0.20160314103604-901c67a8eeab/daemon/logger/journald/read.go (about)

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