Move logdog Logentry parsing to lib (#1703)

So that it can be used for other purposes as well.
For example we will need it for integration testing (#1693).

The functionality is now extended to also parse the log level.

Also logdog now calculates the width for format string

go/lib/log/logparse/logentry.go

@@ -0,0 +1,158 @@
+// Copyright 2018 Anapaya Systems
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//   http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+package logparse
+
+import (
+	"bufio"
+	"fmt"
+	"io"
+	"regexp"
+	"strings"
+	"time"
+
+	"github.com/inconshreveable/log15"
+
+	"github.com/scionproto/scion/go/lib/common"
+	"github.com/scionproto/scion/go/lib/log"
+)
+
+type Lvl log15.Lvl
+
+const (
+	LvlCrit  = Lvl(log15.LvlCrit)
+	LvlError = Lvl(log15.LvlError)
+	LvlWarn  = Lvl(log15.LvlWarn)
+	LvlInfo  = Lvl(log15.LvlInfo)
+	LvlDebug = Lvl(log15.LvlDebug)
+)
+
+var (
+	lineRegex = regexp.MustCompile(` \[(\w+)\] (.+)`)
+)
+
+func LvlFromString(lvl string) (Lvl, error) {
+	// Since we also parse python log entries we also have to handle the levels of python.
+	switch strings.ToUpper(lvl) {
+	case "DEBUG", "DBUG":
+		return LvlDebug, nil
+	case "INFO":
+		return LvlInfo, nil
+	case "WARN", "WARNING":
+		return LvlWarn, nil
+	case "ERROR", "EROR":
+		return LvlError, nil
+	case "CRIT", "CRITICAL":
+		return LvlCrit, nil
+	default:
+		return LvlDebug, fmt.Errorf("Unknown level: %v", lvl)
+	}
+}
+
+func (l Lvl) String() string {
+	return strings.ToUpper(log15.Lvl(l).String())
+}
+
+// LogEntry is one entry in a log.
+type LogEntry struct {
+	Timestamp time.Time
+	// Element describes the source of this LogEntry, e.g. the file name.
+	Element string
+	Level   Lvl
+	Lines   []string
+}
+
+func (l LogEntry) String() string {
+	return fmt.Sprintf("%s [%s] %s\n", l.Timestamp.Format(common.TimeFmt), l.Level, l.Lines)
+}
+
+// ParseFrom parses log lines from the reader.
+//
+// 2017-05-16T13:18:16.539536145+0000 [DBUG] Topology loaded topo=
+// >  Loc addrs:
+// >    127.0.0.65:30066
+// >  Interfaces:
+// >    IFID: 41 Link: CORE Local: 127.0.0.6:50000 Remote: 127.0.0.7:50000 IA: 1-ff00:0:312
+// 2017-05-16T13:18:16.539658666+0000 [INFO] Starting up id=br1-ff00:0:311-1
+//
+// Lines starting with "> " or a space are assumed to be continuations, i.e.
+// they belong with the line(s) above them.
+//
+// The fileName is used for logging.
+// The element is put in LogEntry.Element.
+// Parsed entries are passed to the entryConsumer.
+func ParseFrom(reader io.Reader, fileName, element string, entryConsumer func(LogEntry)) {
+	var prevEntry *LogEntry
+	scanner := bufio.NewScanner(reader)
+	for lineno := 1; scanner.Scan(); lineno++ {
+		line := scanner.Text()
+		if isContinuation(line) {
+			// If this is a continuation at the start of the reader, just drop it
+			if prevEntry == nil {
+				continue
+			}
+			prevEntry.Lines = append(prevEntry.Lines, line)
+			continue
+		}
+		if prevEntry != nil {
+			entryConsumer(*prevEntry)
+		}
+		prevEntry = parseInitialEntry(line, fileName, element, lineno)
+	}
+	if prevEntry != nil {
+		entryConsumer(*prevEntry)
+	}
+}
+
+// parseInitialEntry parses a line with the pattern <TS> [<Level>] <Entry>.
+func parseInitialEntry(line, fileName, element string, lineno int) *LogEntry {
+	tsLen := len(common.TimeFmt)
+
+	if len(line) < tsLen {
+		log.Error(fmt.Sprintf("Short line at %s:%d: '%+v'", fileName, lineno, line))
+	}
+	ts, err := time.Parse(common.TimeFmt, line[:tsLen])
+	if err != nil {
+		log.Error(fmt.Sprintf("%s:%d: Could not parse timestamp %+v: %+v",
+			fileName, lineno, line[:tsLen], err))
+		return nil
+	}
+	matches := lineRegex.FindStringSubmatch(line[tsLen:])
+	if matches == nil || len(matches) < 3 {
+		log.Error(fmt.Sprintf("Line %s:%d does not match regexep: %s",
+			fileName, lineno, lineRegex))
+		return nil
+	}
+	lvl, err := LvlFromString(matches[1])
+	if err != nil {
+		log.Error(fmt.Sprintf("%s:%d: Unknown log level: %v", fileName, lineno, err))
+	}
+	return &LogEntry{
+		Timestamp: ts,
+		Element:   element,
+		Level:     lvl,
+		Lines:     []string{matches[2]},
+	}
+}
+
+func isContinuation(line string) bool {
+	return strings.HasPrefix(line, "> ") || strings.HasPrefix(line, " ")
+}
+
+func min(a, b int) int {
+	if a < b {
+		return a
+	}
+	return b
+}

go/lib/log/logparse/logentry_test.go

@@ -0,0 +1,123 @@
+// Copyright 2018 Anapaya Systems
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//   http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+package logparse
+
+import (
+	"os"
+	"strings"
+	"testing"
+	"time"
+
+	. "github.com/smartystreets/goconvey/convey"
+
+	"github.com/scionproto/scion/go/lib/common"
+	"github.com/scionproto/scion/go/lib/log"
+	"github.com/scionproto/scion/go/lib/xtest"
+)
+
+func TestParseFrom(t *testing.T) {
+	defaultTs := mustParse("2018-07-19 14:39:29.489625+0000", t)
+	tests := []struct {
+		Name    string
+		Input   string
+		Entries []LogEntry
+	}{
+		{
+			Name:  "SingleLineTest",
+			Input: "2018-07-19 14:39:29.489625+0000 [ERROR] Txt",
+			Entries: []LogEntry{
+				{
+					Timestamp: defaultTs,
+					Level:     LvlError,
+					Lines:     []string{"Txt"},
+				},
+			},
+		},
+		{
+			Name: "MultilineTest>",
+			Input: "2018-07-19 14:39:29.489625+0000 [CRIT] (CliSrvExt 2-ff00:0: > ...\n" +
+				"> SCIONDPathReplyEntry:",
+			Entries: []LogEntry{
+				{
+					Timestamp: defaultTs,
+					Level:     LvlCrit,
+					Lines:     []string{"(CliSrvExt 2-ff00:0: > ...", "> SCIONDPathReplyEntry:"},
+				},
+			},
+		},
+		{
+			Name: "MultilineTestSpace",
+			Input: "2018-07-19 14:39:29.489625+0000 [CRIT] (CliSrvExt 2-ff00:0: > ...\n" +
+				" SCIONDPathReplyEntry:",
+			Entries: []LogEntry{
+				{
+					Timestamp: defaultTs,
+					Level:     LvlCrit,
+					Lines:     []string{"(CliSrvExt 2-ff00:0: > ...", " SCIONDPathReplyEntry:"},
+				},
+			},
+		},
+		{
+			Name:  "MissingLevel",
+			Input: "2018-07-19 14:39:29.489625+0000 Txt",
+		},
+		{
+			Name: "MultiEntry",
+			Input: "2018-07-19 14:39:29.489625+0000 [ERROR] Txt\n" +
+				"2018-07-19 14:39:30.489625+0000 [INFO] Txt2",
+			Entries: []LogEntry{
+				{
+					Timestamp: defaultTs,
+					Level:     LvlError,
+					Lines:     []string{"Txt"},
+				},
+				{
+					Timestamp: mustParse("2018-07-19 14:39:30.489625+0000", t),
+					Level:     LvlInfo,
+					Lines:     []string{"Txt2"},
+				},
+			},
+		},
+	}
+	Convey("ParseFrom", t, func() {
+		for _, tc := range tests {
+			Convey(tc.Name, func() {
+				r := strings.NewReader(tc.Input)
+				var entries []LogEntry
+				ParseFrom(r, tc.Name, tc.Name,
+					func(e LogEntry) { entries = append(entries, e) })
+				SoMsg("entries len", len(entries), ShouldEqual, len(tc.Entries))
+				for i, e := range entries {
+					SoMsg("entry ts", e.Timestamp, ShouldResemble, tc.Entries[i].Timestamp)
+					SoMsg("entry element", e.Element, ShouldEqual, tc.Name)
+					SoMsg("entry level", e.Level, ShouldEqual, tc.Entries[i].Level)
+					SoMsg("entry entry", e.Lines, ShouldResemble, tc.Entries[i].Lines)
+				}
+			})
+		}
+	})
+}
+
+func mustParse(ts string, t *testing.T) time.Time {
+	tts, err := time.Parse(common.TimeFmt, ts)
+	xtest.FailOnErr(t, err)
+	return tts
+}
+
+func TestMain(m *testing.M) {
+	l := log.Root()
+	l.SetHandler(log.DiscardHandler())
+	os.Exit(m.Run())
+}