logtree: capture multiple lines in leveled log entries
This implements a solution to a disputed answer to the following
question:
“What happens when someone calls Infof("foo\nbar")?”
Multiple answers immediately present themselves:
a) Don't do anything, whatever consumers logs needs to expect that
they might contain newlines.
b) Yell/error/panic so that the programmer doesn't do this.
c) Split the one Info call into multiple Info calls, one per line,
somewhere in the logging path.
Following the argumentation for these we establish the follwoing
requirments for any solution:
1) We want the programmer to be able to log multiple lines from a
single Info call and have that not fail. This is especially
important for reliability - we don't want an accidental codepath
that suddenly starts printing %s-formatted user-controlled
messages to start erroring out in production. This rules out b).
2) We want to allow emitting multiple lines that will not be
interleaved when viewing the log data. This rules out c).
3) We want to prohibit log injection by malicious \n-containing
payloads (in case of %s-formatted user-controlled content). This
rules out a).
4) If multiple lines are allowed in a leveled payload, the type
system should support that, so that log consumers/tools will not
forget to account for the possible newlines. This too rules out
a).
With these in mind, we instead opt for a different solutions: changing
the API of logtree and logging protos to contain multiple possible lines
per single log entry. This is a breaking change, but since all access to
logs is currently self-contained within the Monogon OS codebase, we can
afford this.
To support this change, we change the access API (at LogEntry and
LeveledPayload level) to contain two different methods for retrieving
the canonical representation of an entry:
fn String() string
which returns a string with possible intra-string newlines (but no
trailing newlines), but with each newline-delimited chunk having the
canonical text representation prefix for this message. This prevents
newline injection into logs creating fake prefixes.
fn Strings() (prefix string, lines []string)
which returns a common prefix for this entry (in its text
representation) and a set of lines that were contained in the original
log entry. This allows slightly smarter consuming code to make more
active decisions regarding the rendering of a multi-line entry, while
still providing a canonical text formatted representation of that log
entry.
These permit simple log access code that prints log data into a terminal
(or terminal-like view), like dbg, to continue using the String() call.
In fact, no changes had to be made to dbg for it to continue working,
even though the API underneath changed.
Naturally, raw logging entries continue to contain only a single line,
so no change is implemented in the LineBuffer API. The containing
LogEntry for raw log entries emits single-lined Strings() results and no
newline-containing strings in String() results.
Test Plan: Updated unit tests to cover this.
X-Origin-Diff: phab/D650
GitOrigin-RevId: 4e339a930c4cbefff91b289b07bc31f774745eca
diff --git a/core/pkg/logtree/logtree_access.go b/core/pkg/logtree/logtree_access.go
index bb8a524..7709526 100644
--- a/core/pkg/logtree/logtree_access.go
+++ b/core/pkg/logtree/logtree_access.go
@@ -19,6 +19,7 @@
import (
"errors"
"fmt"
+ "strings"
"sync/atomic"
"git.monogon.dev/source/nexantic.git/core/pkg/logbuffer"
@@ -102,6 +103,59 @@
DN DN
}
+// String returns a canonical representation of this payload as a single string prefixed with metadata. If the entry is
+// a leveled log entry that originally was logged with newlines this representation will also contain newlines, with
+// each original message part prefixed by the metadata.
+// For an alternative call that will instead return a canonical prefix and a list of lines in the message, see Strings().
+func (l *LogEntry) String() string {
+ if l.Leveled != nil {
+ prefix, messages := l.Leveled.Strings()
+ res := make([]string, len(messages))
+ for i, m := range messages {
+ res[i] = fmt.Sprintf("%-32s %s%s", l.DN, prefix, m)
+ }
+ return strings.Join(res, "\n")
+ }
+ if l.Raw != nil {
+ return fmt.Sprintf("%-32s R %s", l.DN, l.Raw)
+ }
+ return "INVALID"
+}
+
+// Strings returns the canonical representation of this payload split into a prefix and all lines that were contained in
+// the original message. This is meant to be displayed to the user by showing the prefix before each line, concatenated
+// together - possibly in a table form with the prefixes all unified with a rowspan-like mechanism.
+//
+// For example, this function can return:
+// prefix = "root.foo.bar I1102 17:20:06.921395 0 foo.go:42] "
+// lines = []string{"current tags:", " - one", " - two"}
+//
+// With this data, the result should be presented to users this way in text form:
+// root.foo.bar I1102 17:20:06.921395 foo.go:42] current tags:
+// root.foo.bar I1102 17:20:06.921395 foo.go:42] - one
+// root.foo.bar I1102 17:20:06.921395 foo.go:42] - two
+//
+// Or, in a table layout:
+// .-------------------------------------------------------------------------------------.
+// | root.foo.bar I1102 17:20:06.921395 foo.go:42] : current tags: |
+// | :------------------|
+// | : - one |
+// | :------------------|
+// | : - two |
+// '-------------------------------------------------------------------------------------'
+//
+func (l *LogEntry) Strings() (prefix string, lines []string) {
+ if l.Leveled != nil {
+ prefix, messages := l.Leveled.Strings()
+ prefix = fmt.Sprintf("%-32s %s", l.DN, prefix)
+ return prefix, messages
+ }
+ if l.Raw != nil {
+ return fmt.Sprintf("%-32s R ", l.DN), []string{l.Raw.Data}
+ }
+ return "INVALID ", []string{"INVALID"}
+}
+
// Convert this LogEntry to proto. Returned value may be nil if given LogEntry is invalid, eg. contains neither a Raw
// nor Leveled entry.
func (l *LogEntry) Proto() *apb.LogEntry {
@@ -125,23 +179,6 @@
return p
}
-// String returns a standardized human-readable representation of either underlying raw or leveled entry. The returned
-// data is pre-formatted to be displayed in a fixed-width font.
-func (l *LogEntry) String() string {
- if l.Leveled != nil {
- // Use glog-like layout, but with supervisor DN instead of filename.
- timestamp := l.Leveled.Timestamp()
- _, month, day := timestamp.Date()
- hour, minute, second := timestamp.Clock()
- nsec := timestamp.Nanosecond() / 1000
- return fmt.Sprintf("%s%02d%02d %02d:%02d:%02d.%06d %s] %s", l.Leveled.Severity(), month, day, hour, minute, second, nsec, l.DN, l.Leveled.Message())
- }
- if l.Raw != nil {
- return fmt.Sprintf("%-32s R %s", l.DN, l.Raw)
- }
- return "INVALID"
-}
-
// Parse a proto LogEntry back into internal structure. This can be used in log proto API consumers to easily print
// received log entries.
func LogEntryFromProto(l *apb.LogEntry) (*LogEntry, error) {