Skip to content

Commit

Permalink
chore: Log level detection improvements (#12440)
Browse files Browse the repository at this point in the history
  • Loading branch information
@sandeepsukhani
sandeepsukhani authored Apr 3, 2024
1 parent 6820b93 commit 1ae5b3e
Show file tree
Hide file tree
Showing 2 changed files with 114 additions and 26 deletions.
78 changes: 66 additions & 12 deletions pkg/distributor/distributor.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@ import (
"strconv"
"strings"
"time"
"unicode"

"github.com/go-kit/log"
"github.com/go-kit/log/level"
Expand Down Expand Up @@ -882,26 +883,79 @@ func detectLogLevelFromLogEntry(entry logproto.Entry, structuredMetadata labels.
}

func extractLogLevelFromLogLine(log string) string {
if strings.Contains(log, `:"err"`) || strings.Contains(log, `:"ERR"`) ||
strings.Contains(log, "=err") || strings.Contains(log, "=ERR") ||
strings.Contains(log, "err:") || strings.Contains(log, "ERR:") ||
// check for log levels in known log formats to avoid any false detection

// json logs:
var firstNonSpaceChar rune
for _, char := range log {
if !unicode.IsSpace(char) {
firstNonSpaceChar = char
break
}
}

var lastNonSpaceChar rune
for i := len(log) - 1; i >= 0; i-- {
char := rune(log[i])
if !unicode.IsSpace(char) {
lastNonSpaceChar = char
break
}
}

if firstNonSpaceChar == '{' && lastNonSpaceChar == '}' {
if strings.Contains(log, `:"err"`) || strings.Contains(log, `:"ERR"`) ||
strings.Contains(log, `:"error"`) || strings.Contains(log, `:"ERROR"`) {
return logLevelError
}
if strings.Contains(log, `:"warn"`) || strings.Contains(log, `:"WARN"`) ||
strings.Contains(log, `:"warning"`) || strings.Contains(log, `:"WARNING"`) {
return logLevelWarn
}
if strings.Contains(log, `:"critical"`) || strings.Contains(log, `:"CRITICAL"`) {
return logLevelCritical
}
if strings.Contains(log, `:"debug"`) || strings.Contains(log, `:"DEBUG"`) {
return logLevelDebug
}
if strings.Contains(log, `:"info"`) || strings.Contains(log, `:"INFO"`) {
return logLevelDebug
}
}

// logfmt logs:
if strings.Contains(log, "=") {
if strings.Contains(log, "=err") || strings.Contains(log, "=ERR") ||
strings.Contains(log, "=error") || strings.Contains(log, "=ERROR") {
return logLevelError
}
if strings.Contains(log, "=warn") || strings.Contains(log, "=WARN") ||
strings.Contains(log, "=warning") || strings.Contains(log, "=WARNING") {
return logLevelWarn
}
if strings.Contains(log, "=critical") || strings.Contains(log, "=CRITICAL") {
return logLevelCritical
}
if strings.Contains(log, "=debug") || strings.Contains(log, "=DEBUG") {
return logLevelDebug
}
if strings.Contains(log, "=info") || strings.Contains(log, "=INFO") {
return logLevelDebug
}
}

if strings.Contains(log, "err:") || strings.Contains(log, "ERR:") ||
strings.Contains(log, "error") || strings.Contains(log, "ERROR") {
return logLevelError
}
if strings.Contains(log, `:"warn"`) || strings.Contains(log, `:"WARN"`) ||
strings.Contains(log, "=warn") || strings.Contains(log, "=WARN") ||
strings.Contains(log, "warn:") || strings.Contains(log, "WARN:") ||
if strings.Contains(log, "warn:") || strings.Contains(log, "WARN:") ||
strings.Contains(log, "warning") || strings.Contains(log, "WARNING") {
return logLevelWarn
}
if strings.Contains(log, `:"critical"`) || strings.Contains(log, `:"CRITICAL"`) ||
strings.Contains(log, "=critical") || strings.Contains(log, "=CRITICAL") ||
strings.Contains(log, "CRITICAL:") || strings.Contains(log, "critical:") {
if strings.Contains(log, "CRITICAL:") || strings.Contains(log, "critical:") {
return logLevelCritical
}
if strings.Contains(log, `:"debug"`) || strings.Contains(log, `:"DEBUG"`) ||
strings.Contains(log, "=debug") || strings.Contains(log, "=DEBUG") ||
strings.Contains(log, "debug:") || strings.Contains(log, "DEBUG:") {
if strings.Contains(log, "debug:") || strings.Contains(log, "DEBUG:") {
return logLevelDebug
}

Expand Down
62 changes: 48 additions & 14 deletions pkg/distributor/distributor_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -536,18 +536,33 @@ func TestDistributorPushErrors(t *testing.T) {
}

func Test_SortLabelsOnPush(t *testing.T) {
limits := &validation.Limits{}
flagext.DefaultValues(limits)
limits.DiscoverServiceName = nil
ingester := &mockIngester{}
distributors, _ := prepare(t, 1, 5, limits, func(addr string) (ring_client.PoolClient, error) { return ingester, nil })
t.Run("with service_name already present in labels", func(t *testing.T) {
limits := &validation.Limits{}
flagext.DefaultValues(limits)
ingester := &mockIngester{}
distributors, _ := prepare(t, 1, 5, limits, func(addr string) (ring_client.PoolClient, error) { return ingester, nil })

request := makeWriteRequest(10, 10)
request.Streams[0].Labels = `{buzz="f", a="b"}`
_, err := distributors[0].Push(ctx, request)
require.NoError(t, err)
topVal := ingester.Peek()
require.Equal(t, `{a="b", buzz="f"}`, topVal.Streams[0].Labels)
request := makeWriteRequest(10, 10)
request.Streams[0].Labels = `{buzz="f", service_name="foo", a="b"}`
_, err := distributors[0].Push(ctx, request)
require.NoError(t, err)
topVal := ingester.Peek()
require.Equal(t, `{a="b", buzz="f", service_name="foo"}`, topVal.Streams[0].Labels)
})

t.Run("with service_name added during ingestion", func(t *testing.T) {
limits := &validation.Limits{}
flagext.DefaultValues(limits)
ingester := &mockIngester{}
distributors, _ := prepare(t, 1, 5, limits, func(addr string) (ring_client.PoolClient, error) { return ingester, nil })

request := makeWriteRequest(10, 10)
request.Streams[0].Labels = `{buzz="f", x="y", a="b"}`
_, err := distributors[0].Push(ctx, request)
require.NoError(t, err)
topVal := ingester.Peek()
require.Equal(t, `{a="b", buzz="f", service_name="unknown_service", x="y"}`, topVal.Streams[0].Labels)
})
}

func Test_TruncateLogLines(t *testing.T) {
Expand Down Expand Up @@ -1620,14 +1635,14 @@ func Test_detectLogLevelFromLogEntry(t *testing.T) {
{
name: "json log line with an error",
entry: logproto.Entry{
Line: `{"foo":"bar","level":"error"}`,
Line: `{"foo":"bar",msg:"message with keyword error but it should not get picked up",level":"critical"}`,
},
expectedLogLevel: logLevelError,
expectedLogLevel: logLevelCritical,
},
{
name: "logfmt log line with a warn",
entry: logproto.Entry{
Line: `foo=bar level=warn`,
Line: `foo=bar msg="message with keyword error but it should not get picked up" level=warn`,
},
expectedLogLevel: logLevelWarn,
},
Expand All @@ -1638,3 +1653,22 @@ func Test_detectLogLevelFromLogEntry(t *testing.T) {
})
}
}

func Benchmark_extractLogLevelFromLogLine(b *testing.B) {
// looks scary, but it is some random text of about 1000 chars from charset a-zA-Z0-9
logLine := "dGzJ6rKk Zj U04SWEqEK4Uwho8 DpNyLz0 Nfs61HJ fz5iKVigg 44 kabOz7ghviGmVONriAdz4lA 7Kis1OTvZGT3 " +
"ZB6ioK4fgJLbzm AuIcbnDZKx3rZ aeZJQzRb3zhrn vok8Efav6cbyzbRUQ PYsEdQxCpdCDcGNsKG FVwe61 nhF06t9hXSNySEWa " +
"gBAXP1J8oEL grep1LfeKjA23ntszKA A772vNyxjQF SjWfJypwI7scxk oLlqRzrDl ostO4CCwx01wDB7Utk0 64A7p5eQDITE6zc3 " +
"rGL DrPnD K2oj Vro2JEvI2YScstnMx SVu H o GUl8fxZJJ1HY0 C QOA HNJr5XtsCNRrLi 0w C0Pd8XWbVZyQkSlsRm zFw1lW " +
"c8j6JFQuQnnB EyL20z0 2Duo0dvynnAGD 45ut2Z Jrz8Nd7Pmg 5oQ09r9vnmy U2 mKHO5uBfndPnbjbr mzOvQs9bM1 9e " +
"yvNSfcbPyhuWvB VKJt2kp8IoTVc XCe Uva5mp9NrGh3TEbjQu1 C Zvdk uPr7St2m kwwMRcS9eC aS6ZuL48eoQUiKo VBPd4m49ymr " +
"eQZ0fbjWpj6qA A6rYs4E 58dqh9ntu8baziDJ4c 1q6aVEig YrMXTF hahrlt 6hKVHfZLFZ V 9hEVN0WKgcpu6L zLxo6YC57 XQyfAGpFM " +
"Wm3 S7if5qCXPzvuMZ2 gNHdst Z39s9uNc58QBDeYRW umyIF BDqEdqhE tAs2gidkqee3aux8b NLDb7 ZZLekc0cQZ GUKQuBg2pL2y1S " +
"RJtBuW ABOqQHLSlNuUw ZlM2nGS2 jwA7cXEOJhY 3oPv4gGAz Uqdre16MF92C06jOH dayqTCK8XmIilT uvgywFSfNadYvRDQa " +
"iUbswJNcwqcr6huw LAGrZS8NGlqqzcD2wFU rm Uqcrh3TKLUCkfkwLm 5CIQbxMCUz boBrEHxvCBrUo YJoF2iyif4xq3q yk "

for i := 0; i < b.N; i++ {
level := extractLogLevelFromLogLine(logLine)
require.Equal(b, logLevelInfo, level)
}
}

0 comments on commit 1ae5b3e

Please sign in to comment.