diff --git a/CHANGELOG.md b/CHANGELOG.md index a2c3003f..6a9293d4 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,7 @@ All notable changes to this project will be documented in this file. ### Fixed ### Added +- @localghost added option to read original logs timestamps from containers ### Removed diff --git a/Makefile b/Makefile index 645b9ef7..43974373 100644 --- a/Makefile +++ b/Makefile @@ -38,7 +38,7 @@ build-custom: cd custom && docker build -t $(NAME):custom . lint: - test -x $(GOPATH)/bin/golint || go get github.com/golang/lint/golint + test -x $(GOPATH)/bin/golint || go get golang.org/x/lint/golint go get \ && go install $(GOPACKAGES) \ && go tool vet -v $(shell ls -d */ | egrep -v 'custom|vendor/' | xargs $(XARGS_ARG)) diff --git a/README.md b/README.md index 8fd82874..1792c654 100644 --- a/README.md +++ b/README.md @@ -189,6 +189,7 @@ If you use multiline logging with raw, it's recommended to json encode the Data * `MULTILINE_PATTERN` - pattern for multiline logging, see: [MULTILINE_MATCH](#multiline_match) (default: `^\s`) * `MULTILINE_FLUSH_AFTER` - maximum time between the first and last lines of a multiline log entry in milliseconds (default: 500) * `MULTILINE_SEPARATOR` - separator between lines for output (default: `\n`) +* `ORIGINAL_TIMESTAMPS` - read original log timestamps from containers (default: generate timestamps as the logs are processed by logspout) #### Raw Format diff --git a/circle.yml b/circle.yml index 9626e440..622a0da2 100644 --- a/circle.yml +++ b/circle.yml @@ -8,7 +8,7 @@ jobs: steps: - checkout - run: | - go get github.com/golang/lint/golint + go get golang.org/x/lint/golint - run: | make circleci - run: | diff --git a/router/pump.go b/router/pump.go index 94e34786..4216b057 100644 --- a/router/pump.go +++ b/router/pump.go @@ -33,6 +33,10 @@ func getopt(name, dfault string) string { return value } +func originalTimestamps() bool { + return getopt("ORIGINAL_TIMESTAMPS", "false") == "true" +} + func debug(v ...interface{}) { if os.Getenv("DEBUG") != "" { log.Println(v...) @@ -244,6 +248,7 @@ func (p *LogsPump) pumpLogs(event *docker.APIEvents, backlog bool, inactivityTim Since: sinceTime.Unix(), InactivityTimeout: inactivityTimeout, RawTerminal: rawTerminal, + Timestamps: originalTimestamps(), }) if err != nil { debug("pump.pumpLogs():", id, "stopped with error:", err) @@ -370,10 +375,11 @@ func newContainerPump(container *docker.Container, stdout, stderr io.Reader) *co } return } + logMessage, logTime := parseLogLine(line, originalTimestamps()) cp.send(&Message{ - Data: strings.TrimSuffix(line, "\n"), + Data: logMessage, Container: container, - Time: time.Now(), + Time: logTime, Source: source, }) } @@ -405,3 +411,22 @@ func (cp *containerPump) remove(logstream chan *Message) { defer cp.Unlock() delete(cp.logstreams, logstream) } + +func parseLogLine(line string, originalTimestamps bool) (string, time.Time) { + line = strings.TrimSuffix(line, "\n") + + if ! originalTimestamps { + return line, time.Now() + } + + logEntry := strings.SplitN(line, " ", 2) + logTime, err := time.Parse(time.RFC3339Nano, logEntry[0]) + if err != nil { + return line, time.Now() + } + + if len(logEntry) == 2 { + return logEntry[1], logTime + } + return "", logTime +} diff --git a/router/pump_test.go b/router/pump_test.go index e05f9f99..19f19cb2 100644 --- a/router/pump_test.go +++ b/router/pump_test.go @@ -3,12 +3,14 @@ package router import ( "bytes" "encoding/json" + "fmt" "io/ioutil" "log" "net" "net/http" "os" "testing" + "time" docker "github.com/fsouza/go-dockerclient" ) @@ -229,3 +231,45 @@ func TestPumpRoutingFrom(t *testing.T) { t.Errorf("expected RoutingFrom to return 'false'") } } + +func TestParseLogLine(t *testing.T) { + checkMessage := func(expectedMessage, actualMessage string) { + if actualMessage != expectedMessage { + t.Errorf("Expected message '%s' but got '%s'", expectedMessage, actualMessage) + } + } + + checkEqual := func(expectedMessage, actualMessage string, expectedTime, actualTime time.Time) { + if !actualTime.Equal(expectedTime) { + t.Errorf("Expected time %s but got %s", expectedTime, actualTime) + } + checkMessage(expectedMessage, actualMessage) + } + + checkAfter := func(expectedMessage, actualMessage string, expectedTime, actualTime time.Time) { + if !actualTime.After(expectedTime) { + t.Errorf("Expected actual time %s to be greater than %s", actualTime, expectedTime) + } + checkMessage(expectedMessage, actualMessage) + } + + originalTime := time.Now().Add(-time.Hour) + + actualMessage, actualTime := parseLogLine(fmt.Sprintf("%s Hello world!", originalTime.Format(time.RFC3339Nano)), true) + checkEqual("Hello world!", actualMessage, originalTime, actualTime) + + actualMessage, actualTime = parseLogLine(fmt.Sprintf("%s ", originalTime.Format(time.RFC3339Nano)), true) + checkEqual(" ", actualMessage, originalTime, actualTime) + + actualMessage, actualTime = parseLogLine(originalTime.Format(time.RFC3339Nano), true) + checkEqual("", actualMessage, originalTime, actualTime) + + actualMessage, _ = parseLogLine("Hello world!", true) + checkMessage("Hello world!", actualMessage) + + actualMessage, _ = parseLogLine("Hello world!", false) + checkMessage("Hello world!", actualMessage) + + actualMessage, actualTime = parseLogLine(fmt.Sprintf("%s Hello world!", originalTime.Format(time.RFC3339Nano)), false) + checkAfter(fmt.Sprintf("%s Hello world!", originalTime.Format(time.RFC3339Nano)), actualMessage, originalTime, actualTime) +}