Makes changes to log streamer to guess the event level (#2013)

* Makes changes to log streamer to guess the event level

* Updates diff

* Adds log class for level

* Groups messages by level

* Fixes bugs for grouping

* Fixes tests

* Fixes json bug

* Updates logic to support other kind of levels

* Fixes mobile view

assets/components.d.ts

@@ -22,6 +22,7 @@ declare module '@vue/runtime-core' {
     LogContainer: typeof import('./components/LogViewer/LogContainer.vue')['default']
     LogDate: typeof import('./components/LogViewer/LogDate.vue')['default']
     LogEventSource: typeof import('./components/LogViewer/LogEventSource.vue')['default']
+    LogLevel: typeof import('./components/LogViewer/LogLevel.vue')['default']
     LogViewer: typeof import('./components/LogViewer/LogViewer.vue')['default']
     LogViewerWithSource: typeof import('./components/LogViewer/LogViewerWithSource.vue')['default']
     MdiDotsVertical: typeof import('~icons/mdi/dots-vertical')['default']

assets/components/LogViewer/ComplexLogItem.vue

@@ -1,8 +1,11 @@
 <template>
-  <div class="columns is-1 is-variable">
+  <div class="columns is-1 is-variable is-mobile">
     <div class="column is-narrow" v-if="showTimestamp">
       <log-date :date="logEntry.date"></log-date>
     </div>
+    <div class="column is-narrow">
+      <log-level :level="logEntry.level"></log-level>
+    </div>
     <div class="column">
       <ul class="fields" :class="{ expanded }" @click="expanded = !expanded">
         <li v-for="(value, name) in validValues(logEntry.message)">

assets/components/LogViewer/LogLevel.vue

@@ -0,0 +1,56 @@
+<template>
+  <div :class="level" :data-position="position"></div>
+</template>
+<script lang="ts" setup>
+import { Position } from "@/models/LogEntry";
+
+defineProps<{
+  level?: string;
+  position?: Position;
+}>();
+</script>
+
+<style lang="scss" scoped>
+div {
+  display: inline-block;
+  width: 0.7em;
+  height: 0.7em;
+  border-radius: 0.5em;
+
+  &[data-position="middle"] {
+    border-radius: 0;
+    height: 2em;
+    margin: -0.5em 0;
+  }
+
+  &[data-position="start"] {
+    border-radius: 0.5em 0.5em 0 0;
+    height: 1.2em;
+    margin-bottom: -0.4em;
+  }
+
+  &[data-position="end"] {
+    border-radius: 0 0 0.5em 0.5em;
+    height: 1.4em;
+    margin-top: -0.4em;
+  }
+
+  &.debug,
+  &.trace {
+    background-color: #9c27b0;
+  }
+
+  &.info {
+    background-color: #00b5ad;
+  }
+
+  &.error,
+  &.fatal {
+    background-color: #f44336;
+  }
+
+  &.warn {
+    background-color: #ff9800;
+  }
+}
+</style>

assets/components/LogViewer/SimpleLogItem.vue

@@ -1,8 +1,11 @@
 <template>
-  <div class="columns is-1 is-variable">
+  <div class="columns is-1 is-variable is-mobile">
     <div class="column is-narrow" v-if="showTimestamp">
       <log-date :date="logEntry.date"></log-date>
     </div>
+    <div class="column is-narrow">
+      <log-level :level="logEntry.level" :position="logEntry.position"></log-level>
+    </div>
     <div class="text column" v-html="colorize(logEntry.message)"></div>
   </div>
 </template>

assets/components/LogViewer/__snapshots__/LogEventSource.spec.ts.snap

@@ -23,8 +23,11 @@ exports[`<LogEventSource /> > render html correctly > should render dates with 1
         </div>
       </div>
     </div>
-    <div class=\\"columns is-1 is-variable\\" visible-keys=\\"\\" data-v-a49e52d4=\\"\\" data-v-2e92daca=\\"\\">
+    <div class=\\"columns is-1 is-variable is-mobile\\" visible-keys=\\"\\" data-v-a49e52d4=\\"\\" data-v-2e92daca=\\"\\">
       <div class=\\"column is-narrow\\" data-v-a49e52d4=\\"\\"><time datetime=\\"2019-06-12T10:55:42.459Z\\" class=\\"date\\" data-v-de513450=\\"\\" data-v-a49e52d4=\\"\\">06/12/2019 10:55:42 AM</time></div>
+      <div class=\\"column is-narrow\\" data-v-a49e52d4=\\"\\">
+        <div class=\\"\\" data-v-e625cddd=\\"\\" data-v-a49e52d4=\\"\\"></div>
+      </div>
       <div class=\\"text column\\" data-v-a49e52d4=\\"\\">&lt;test&gt;foo bar&lt;/test&gt;</div>
     </div>
   </li>
@@ -54,8 +57,11 @@ exports[`<LogEventSource /> > render html correctly > should render dates with 2
         </div>
       </div>
     </div>
-    <div class=\\"columns is-1 is-variable\\" visible-keys=\\"\\" data-v-a49e52d4=\\"\\" data-v-2e92daca=\\"\\">
+    <div class=\\"columns is-1 is-variable is-mobile\\" visible-keys=\\"\\" data-v-a49e52d4=\\"\\" data-v-2e92daca=\\"\\">
       <div class=\\"column is-narrow\\" data-v-a49e52d4=\\"\\"><time datetime=\\"2019-06-12T10:55:42.459Z\\" class=\\"date\\" data-v-de513450=\\"\\" data-v-a49e52d4=\\"\\">06/12/2019 10:55:42</time></div>
+      <div class=\\"column is-narrow\\" data-v-a49e52d4=\\"\\">
+        <div class=\\"\\" data-v-e625cddd=\\"\\" data-v-a49e52d4=\\"\\"></div>
+      </div>
       <div class=\\"text column\\" data-v-a49e52d4=\\"\\">&lt;test&gt;foo bar&lt;/test&gt;</div>
     </div>
   </li>
@@ -85,8 +91,11 @@ exports[`<LogEventSource /> > render html correctly > should render messages 1`]
         </div>
       </div>
     </div>
-    <div class=\\"columns is-1 is-variable\\" visible-keys=\\"\\" data-v-a49e52d4=\\"\\" data-v-2e92daca=\\"\\">
+    <div class=\\"columns is-1 is-variable is-mobile\\" visible-keys=\\"\\" data-v-a49e52d4=\\"\\" data-v-2e92daca=\\"\\">
       <div class=\\"column is-narrow\\" data-v-a49e52d4=\\"\\"><time datetime=\\"2019-06-12T10:55:42.459Z\\" class=\\"date\\" data-v-de513450=\\"\\" data-v-a49e52d4=\\"\\">06/12/2019 10:55:42 AM</time></div>
+      <div class=\\"column is-narrow\\" data-v-a49e52d4=\\"\\">
+        <div class=\\"\\" data-v-e625cddd=\\"\\" data-v-a49e52d4=\\"\\"></div>
+      </div>
       <div class=\\"text column\\" data-v-a49e52d4=\\"\\">This is a message.</div>
     </div>
   </li>
@@ -116,8 +125,11 @@ exports[`<LogEventSource /> > render html correctly > should render messages wit
         </div>
       </div>
     </div>
-    <div class=\\"columns is-1 is-variable\\" visible-keys=\\"\\" data-v-a49e52d4=\\"\\" data-v-2e92daca=\\"\\">
+    <div class=\\"columns is-1 is-variable is-mobile\\" visible-keys=\\"\\" data-v-a49e52d4=\\"\\" data-v-2e92daca=\\"\\">
       <div class=\\"column is-narrow\\" data-v-a49e52d4=\\"\\"><time datetime=\\"2019-06-12T10:55:42.459Z\\" class=\\"date\\" data-v-de513450=\\"\\" data-v-a49e52d4=\\"\\">06/12/2019 10:55:42 AM</time></div>
+      <div class=\\"column is-narrow\\" data-v-a49e52d4=\\"\\">
+        <div class=\\"\\" data-v-e625cddd=\\"\\" data-v-a49e52d4=\\"\\"></div>
+      </div>
       <div class=\\"text column\\" data-v-a49e52d4=\\"\\"><span style=\\"color:#000\\">black<span style=\\"color:#AAA\\">white</span></span></div>
     </div>
   </li>
@@ -147,8 +159,11 @@ exports[`<LogEventSource /> > render html correctly > should render messages wit
         </div>
       </div>
     </div>
-    <div class=\\"columns is-1 is-variable\\" visible-keys=\\"\\" data-v-a49e52d4=\\"\\" data-v-2e92daca=\\"\\">
+    <div class=\\"columns is-1 is-variable is-mobile\\" visible-keys=\\"\\" data-v-a49e52d4=\\"\\" data-v-2e92daca=\\"\\">
       <div class=\\"column is-narrow\\" data-v-a49e52d4=\\"\\"><time datetime=\\"2019-06-12T10:55:42.459Z\\" class=\\"date\\" data-v-de513450=\\"\\" data-v-a49e52d4=\\"\\">06/12/2019 10:55:42 AM</time></div>
+      <div class=\\"column is-narrow\\" data-v-a49e52d4=\\"\\">
+        <div class=\\"\\" data-v-e625cddd=\\"\\" data-v-a49e52d4=\\"\\"></div>
+      </div>
       <div class=\\"text column\\" data-v-a49e52d4=\\"\\"><mark>test</mark> bar</div>
     </div>
   </li>
@@ -178,8 +193,11 @@ exports[`<LogEventSource /> > render html correctly > should render messages wit
         </div>
       </div>
     </div>
-    <div class=\\"columns is-1 is-variable\\" visible-keys=\\"\\" data-v-a49e52d4=\\"\\" data-v-2e92daca=\\"\\">
+    <div class=\\"columns is-1 is-variable is-mobile\\" visible-keys=\\"\\" data-v-a49e52d4=\\"\\" data-v-2e92daca=\\"\\">
       <div class=\\"column is-narrow\\" data-v-a49e52d4=\\"\\"><time datetime=\\"2019-06-12T10:55:42.459Z\\" class=\\"date\\" data-v-de513450=\\"\\" data-v-a49e52d4=\\"\\">06/12/2019 10:55:42 AM</time></div>
+      <div class=\\"column is-narrow\\" data-v-a49e52d4=\\"\\">
+        <div class=\\"\\" data-v-e625cddd=\\"\\" data-v-a49e52d4=\\"\\"></div>
+      </div>
       <div class=\\"text column\\" data-v-a49e52d4=\\"\\">&lt;test&gt;foo bar&lt;/test&gt;</div>
     </div>
   </li>
@@ -202,5 +220,7 @@ SimpleLogEntry {
   "_message": "This is a message.",
   "date": 2019-06-12T10:55:42.459Z,
   "id": 1,
+  "level": undefined,
+  "position": undefined,
 }
 `;

assets/models/LogEntry.ts

@@ -11,16 +11,18 @@ export interface HasComponent {
 
 export type JSONValue = string | number | boolean | JSONObject | Array<JSONValue>;
 export type JSONObject = { [x: string]: JSONValue };
-
+export type Position = "start" | "end" | "middle" | undefined;
 export interface LogEvent {
   readonly m: string | JSONObject;
   readonly ts: number;
   readonly id: number;
+  readonly l: string;
+  readonly p: Position;
 }
 
 export abstract class LogEntry<T extends string | JSONObject> implements HasComponent {
   protected readonly _message: T;
-  constructor(message: T, public readonly id: number, public readonly date: Date) {
+  constructor(message: T, public readonly id: number, public readonly date: Date, public readonly level?: string) {
     this._message = message;
   }
 
@@ -32,6 +34,15 @@ export abstract class LogEntry<T extends string | JSONObject> implements HasComp
 }
 
 export class SimpleLogEntry extends LogEntry<string> {
+  constructor(
+    message: string,
+    id: number,
+    date: Date,
+    public readonly level: string,
+    public readonly position: Position
+  ) {
+    super(message, id, date, level);
+  }
   getComponent(): Component {
     return SimpleLogItem;
   }
@@ -40,8 +51,14 @@ export class SimpleLogEntry extends LogEntry<string> {
 export class ComplexLogEntry extends LogEntry<JSONObject> {
   private readonly filteredMessage: ComputedRef<JSONObject>;
 
-  constructor(message: JSONObject, id: number, date: Date, visibleKeys?: Ref<string[][]>) {
+  constructor(
-    super(message, id, date);
+    message: JSONObject,
+    id: number,
+    date: Date,
+    public readonly level: string,
+    visibleKeys?: Ref<string[][]>
+  ) {
+    super(message, id, date, level);
     if (visibleKeys) {
       this.filteredMessage = computed(() => {
         if (!visibleKeys.value.length) {
@@ -67,13 +84,13 @@ export class ComplexLogEntry extends LogEntry<JSONObject> {
   }
 
   static fromLogEvent(event: ComplexLogEntry, visibleKeys: Ref<string[][]>): ComplexLogEntry {
-    return new ComplexLogEntry(event._message, event.id, event.date, visibleKeys);
+    return new ComplexLogEntry(event._message, event.id, event.date, event.level, visibleKeys);
   }
 }
 
 export class DockerEventLogEntry extends LogEntry<string> {
   constructor(message: string, date: Date, public readonly event: string) {
-    super(message, date.getTime(), date);
+    super(message, date.getTime(), date, "info");
   }
   getComponent(): Component {
     return DockerEventLogItem;
@@ -90,7 +107,7 @@ export class SkippedLogsEntry extends LogEntry<string> {
     public readonly firstSkipped: LogEntry<string | JSONObject>,
     lastSkipped: LogEntry<string | JSONObject>
   ) {
-    super("", date.getTime(), date);
+    super("", date.getTime(), date, "info");
     this._totalSkipped = totalSkipped;
     this.lastSkipped = lastSkipped;
   }
@@ -114,8 +131,8 @@ export class SkippedLogsEntry extends LogEntry<string> {
 
 export function asLogEntry(event: LogEvent): LogEntry<string | JSONObject> {
   if (typeof event.m === "string") {
-    return new SimpleLogEntry(event.m, event.id, new Date(event.ts));
+    return new SimpleLogEntry(event.m, event.id, new Date(event.ts), event.l, event.p);
   } else {
-    return new ComplexLogEntry(event.m, event.id, new Date(event.ts));
+    return new ComplexLogEntry(event.m, event.id, new Date(event.ts), event.l);
   }
 }

docker/log_iterator.go

@@ -0,0 +1,164 @@
+package docker
+
+import (
+	"bufio"
+	"encoding/json"
+	"hash/fnv"
+	"regexp"
+	"strings"
+	"time"
+
+	log "github.com/sirupsen/logrus"
+)
+
+type eventGenerator struct {
+	reader  *bufio.Reader
+	channel chan *LogEvent
+	next    *LogEvent
+	error   error
+}
+
+func NewEventIterator(reader *bufio.Reader) *eventGenerator {
+	generator := &eventGenerator{reader: reader, channel: make(chan *LogEvent, 100)}
+	go generator.consume()
+	return generator
+}
+
+func (g *eventGenerator) Next() (*LogEvent, error) {
+	var currentEvent *LogEvent
+	var nextEvent *LogEvent
+	if g.next != nil {
+		currentEvent = g.next
+		g.next = nil
+		nextEvent = g.Peek()
+	} else {
+		event, ok := <-g.channel
+		if !ok {
+			return nil, g.error
+		}
+		currentEvent = event
+		nextEvent = g.Peek()
+	}
+
+	currentLevel := guessLogLevel(currentEvent)
+
+	if nextEvent != nil {
+		if currentEvent.IsCloseToTime(nextEvent) && currentLevel != "" && !nextEvent.HasLevel() {
+			currentEvent.Position = START
+			nextEvent.Position = MIDDLE
+		}
+
+		// If next item is not close to current item or has level, set current item position to end
+		if currentEvent.Position == MIDDLE && (nextEvent.HasLevel() || !currentEvent.IsCloseToTime(nextEvent)) {
+			currentEvent.Position = END
+		}
+
+		// If next item is close to current item and has no level, set next item position to middle
+		if currentEvent.Position == MIDDLE && !nextEvent.HasLevel() && currentEvent.IsCloseToTime(nextEvent) {
+			nextEvent.Position = MIDDLE
+		}
+		// Set next item level to current item level
+		if currentEvent.Position == START || currentEvent.Position == MIDDLE {
+			nextEvent.Level = currentEvent.Level
+		}
+	} else if currentEvent.Position == MIDDLE {
+		currentEvent.Position = END
+	}
+
+	return currentEvent, nil
+}
+
+func (g *eventGenerator) LastError() error {
+	return g.error
+}
+
+func (g *eventGenerator) Peek() *LogEvent {
+	if g.next != nil {
+		return g.next
+	}
+	select {
+	case event := <-g.channel:
+		g.next = event
+		return g.next
+	case <-time.After(50 * time.Millisecond):
+		return nil
+	}
+}
+
+func (g *eventGenerator) consume() {
+	for {
+		message, readerError := g.reader.ReadString('\n')
+
+		h := fnv.New32a()
+		h.Write([]byte(message))
+
+		logEvent := &LogEvent{Id: h.Sum32(), Message: message}
+
+		if index := strings.IndexAny(message, " "); index != -1 {
+			logId := message[:index]
+			if timestamp, err := time.Parse(time.RFC3339Nano, logId); err == nil {
+				logEvent.Timestamp = timestamp.UnixMilli()
+				message = strings.TrimSuffix(message[index+1:], "\n")
+				logEvent.Message = message
+				if strings.HasPrefix(message, "{") && strings.HasSuffix(message, "}") {
+					var data map[string]interface{}
+					if err := json.Unmarshal([]byte(message), &data); err != nil {
+						log.Errorf("json unmarshal error while streaming %v", err.Error())
+					} else {
+						logEvent.Message = data
+					}
+				}
+			}
+		}
+
+		logEvent.Level = guessLogLevel(logEvent)
+
+		g.channel <- logEvent
+
+		if readerError != nil {
+			close(g.channel)
+			g.error = readerError
+			break
+		}
+	}
+}
+
+var NON_ASCII_REGEX = regexp.MustCompile("^[^a-z]+[^ewidtf]?")
+var KEY_VALUE_REGEX = regexp.MustCompile("level=([^ ]+)")
+
+func guessLogLevel(logEvent *LogEvent) string {
+	switch value := logEvent.Message.(type) {
+	case string:
+		value = NON_ASCII_REGEX.ReplaceAllString(strings.ToLower(value), "")
+
+		if strings.HasPrefix(value, "error") {
+			return "error"
+		}
+		if strings.HasPrefix(value, "warn") {
+			return "warn"
+		}
+		if strings.HasPrefix(value, "info") {
+			return "info"
+		}
+		if strings.HasPrefix(value, "debug") {
+			return "debug"
+		}
+		if strings.HasPrefix(value, "trace ") {
+			return "trace"
+		}
+		if strings.HasPrefix(value, "fatal") {
+			return "fatal"
+		}
+
+		if matches := KEY_VALUE_REGEX.FindStringSubmatch(value); matches != nil {
+			return matches[1]
+		}
+
+	case map[string]interface{}:
+		if value["level"] != nil {
+			return strings.ToLower(value["level"].(string))
+		}
+	}
+
+	return ""
+}

docker/types.go

@@ -1,5 +1,7 @@
 package docker
 
+import "math"
+
 // Container represents an internal representation of docker containers
 type Container struct {
 	ID      string   `json:"id"`
@@ -27,8 +29,26 @@ type ContainerEvent struct {
 	Name    string `json:"name"`
 }
 
+type LogPosition string
+
+const (
+	START  LogPosition = "start"
+	MIDDLE LogPosition = "middle"
+	END    LogPosition = "end"
+)
+
 type LogEvent struct {
-	Message   any    `json:"m,omitempty"`
+	Message   any         `json:"m,omitempty"`
-	Timestamp int64  `json:"ts"`
+	Timestamp int64       `json:"ts"`
-	Id        uint32 `json:"id,omitempty"`
+	Id        uint32      `json:"id,omitempty"`
+	Level     string      `json:"l,omitempty"`
+	Position  LogPosition `json:"p,omitempty"`
+}
+
+func (l *LogEvent) HasLevel() bool {
+	return l.Level != ""
+}
+
+func (l *LogEvent) IsCloseToTime(other *LogEvent) bool {
+	return math.Abs(float64(l.Timestamp-other.Timestamp)) < 5
 }

web/__snapshots__/web.snapshot

@@ -144,7 +144,7 @@ Connection: keep-alive
 Content-Type: text/event-stream
 X-Accel-Buffering: no
 
-data: {"m":"INFO Testing logs...","ts":0,"id":4256192898}
+data: {"m":"INFO Testing logs...","ts":0,"id":4256192898,"l":"info"}
 
 event: container-stopped
 data: end of stream
@@ -170,7 +170,7 @@ Connection: keep-alive
 Content-Type: text/event-stream
 X-Accel-Buffering: no
 
-data: {"m":"INFO Testing logs...","ts":1589396137772,"id":1469707724}
+data: {"m":"INFO Testing logs...","ts":1589396137772,"id":1469707724,"l":"info"}
 id: 1589396137772
 
 event: container-stopped

web/logs.go

@@ -5,13 +5,11 @@ import (
 	"compress/gzip"
 	"context"
 	"encoding/json"
-	"hash/fnv"
 
 	"fmt"
 	"io"
 	"net/http"
 	"runtime"
-	"strings"
 
 	"time"
 
@@ -48,36 +46,6 @@ func (h *handler) downloadLogs(w http.ResponseWriter, r *http.Request) {
 	io.Copy(zw, reader)
 }
 
-func logEventIterator(reader *bufio.Reader) func() (docker.LogEvent, error) {
-	return func() (docker.LogEvent, error) {
-		message, readerError := reader.ReadString('\n')
-
-		h := fnv.New32a()
-		h.Write([]byte(message))
-
-		logEvent := docker.LogEvent{Id: h.Sum32(), Message: message}
-
-		if index := strings.IndexAny(message, " "); index != -1 {
-			logId := message[:index]
-			if timestamp, err := time.Parse(time.RFC3339Nano, logId); err == nil {
-				logEvent.Timestamp = timestamp.UnixMilli()
-				message = strings.TrimSuffix(message[index+1:], "\n")
-				logEvent.Message = message
-				if strings.HasPrefix(message, "{") && strings.HasSuffix(message, "}") {
-					var data map[string]interface{}
-					if err := json.Unmarshal([]byte(message), &data); err != nil {
-						log.Errorf("json unmarshal error while streaming %v", err.Error())
-					} else {
-						logEvent.Message = data
-					}
-				}
-			}
-		}
-
-		return logEvent, readerError
-	}
-}
-
 func (h *handler) fetchLogsBetweenDates(w http.ResponseWriter, r *http.Request) {
 	w.Header().Set("Content-Type", "application/ld+json; charset=UTF-8")
 
@@ -94,10 +62,10 @@ func (h *handler) fetchLogsBetweenDates(w http.ResponseWriter, r *http.Request)
 	}
 
 	buffered := bufio.NewReader(reader)
-	eventIterator := logEventIterator(buffered)
+	iterator := docker.NewEventIterator(buffered)
 
 	for {
-		logEvent, readerError := eventIterator()
+		logEvent, readerError := iterator.Next()
 		if readerError != nil {
 			break
 		}
@@ -165,13 +133,14 @@ func (h *handler) streamLogs(w http.ResponseWriter, r *http.Request) {
 	}()
 
 	buffered := bufio.NewReader(reader)
-	var readerError error
+	iterator := docker.NewEventIterator(buffered)
-	eventIterator := logEventIterator(buffered)
 
 	for {
 
-		var logEvent docker.LogEvent
+		logEvent, err := iterator.Next()
-		logEvent, readerError = eventIterator()
+		if err != nil {
+			break
+		}
 		if buf, err := json.Marshal(logEvent); err != nil {
 			log.Errorf("json encoding error while streaming %v", err.Error())
 		} else {
@@ -182,19 +151,17 @@ func (h *handler) streamLogs(w http.ResponseWriter, r *http.Request) {
 		}
 		fmt.Fprintf(w, "\n")
 		f.Flush()
-		if readerError != nil {
+
-			break
-		}
 	}
 
 	log.Debugf("streaming stopped: %v", container.ID)
 
-	if readerError == io.EOF {
+	if iterator.LastError() == io.EOF {
 		log.Debugf("container stopped: %v", container.ID)
 		fmt.Fprintf(w, "event: container-stopped\ndata: end of stream\n\n")
 		f.Flush()
-	} else if readerError != context.Canceled {
+	} else if iterator.LastError() != context.Canceled {
-		log.Errorf("unknown error while streaming %v", readerError.Error())
+		log.Errorf("unknown error while streaming %v", iterator.LastError().Error())
 	}
 
 	log.WithField("routines", runtime.NumGoroutine()).Debug("runtime goroutine stats")