Skip to content

Commit

Permalink
[TT-1187] export log verifying function (#962)
Browse files Browse the repository at this point in the history
  • Loading branch information
Tofel authored May 20, 2024
1 parent b994043 commit 4e66f66
Show file tree
Hide file tree
Showing 2 changed files with 91 additions and 66 deletions.
84 changes: 84 additions & 0 deletions testreporters/log_scanner.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,84 @@
package testreporters

import (
"encoding/json"
"fmt"
"strings"

"github.com/rs/zerolog"
"go.uber.org/zap/zapcore"
)

var (
OneLogAtLogLevelErr = "found log at level"
MultipleLogsAtLogLevelErr = "found too many logs at level"
)

// ScanLogLine scans a log line for a failing log level, returning the number of failing logs found so far. It returns an error if the failure threshold is reached or if any panic is found
// or if there's no log level found. It also takes a list of allowed messages that are ignored if found.
func ScanLogLine(log zerolog.Logger, jsonLogLine string, failingLogLevel zapcore.Level, foundSoFar, failureThreshold uint, allowedMessages []AllowedLogMessage) (uint, error) {
var zapLevel zapcore.Level
var err error

if !strings.HasPrefix(jsonLogLine, "{") { // don't bother with non-json lines
if strings.HasPrefix(jsonLogLine, "panic") { // unless it's a panic
return 0, fmt.Errorf("found panic: %s", jsonLogLine)
}
return foundSoFar, nil
}
jsonMapping := map[string]any{}

if err = json.Unmarshal([]byte(jsonLogLine), &jsonMapping); err != nil {
// This error can occur anytime someone uses %+v in a log message, ignoring
return foundSoFar, nil
}
logLevel, ok := jsonMapping["level"].(string)
if !ok {
return 0, fmt.Errorf("found no log level in chainlink log line: %s", jsonLogLine)
}

if logLevel == "crit" { // "crit" is a custom core type they map to DPanic
zapLevel = zapcore.DPanicLevel
} else {
zapLevel, err = zapcore.ParseLevel(logLevel)
if err != nil {
return 0, fmt.Errorf("'%s' not a valid zapcore level", logLevel)
}
}

if zapLevel >= failingLogLevel {
logErr := fmt.Errorf("%s '%s', failing any log level higher than %s: %s", OneLogAtLogLevelErr, logLevel, zapLevel.String(), jsonLogLine)
if failureThreshold > 1 {
logErr = fmt.Errorf("%s '%s' or above; failure threshold of %d reached; last error found: %s", MultipleLogsAtLogLevelErr, logLevel, failureThreshold, jsonLogLine)
}
logMessage, hasMessage := jsonMapping["msg"]
if !hasMessage {
foundSoFar++
if foundSoFar >= failureThreshold {
return foundSoFar, logErr
}
return foundSoFar, nil
}

for _, allowedLog := range allowedMessages {
if strings.Contains(logMessage.(string), allowedLog.message) {
if allowedLog.logWhenFound {
log.Warn().
Str("Reason", allowedLog.reason).
Str("Level", allowedLog.level.CapitalString()).
Str("Msg", logMessage.(string)).
Msg("Found allowed log message, ignoring")
}

return foundSoFar, nil
}
}

foundSoFar++
if foundSoFar >= failureThreshold {
return foundSoFar, logErr
}
}

return foundSoFar, nil
}
73 changes: 7 additions & 66 deletions testreporters/reporter_model.go
Original file line number Diff line number Diff line change
Expand Up @@ -2,7 +2,6 @@ package testreporters

import (
"bufio"
"encoding/json"
"fmt"
"io/fs"
"os"
Expand Down Expand Up @@ -155,81 +154,23 @@ var defaultAllowedLogMessages = []AllowedLogMessage{
// in the log file. The failureThreshold is the number of logs at the failingLogLevel or higher that can be found before
// the function returns an error.
func VerifyLogFile(file *os.File, failingLogLevel zapcore.Level, failureThreshold uint, allowedMessages ...AllowedLogMessage) error {
// nolint
defer file.Close()
defer func(file *os.File) {
_ = file.Close()
}(file)

var (
zapLevel zapcore.Level
err error
)
var err error
scanner := bufio.NewScanner(file)
scanner.Split(bufio.ScanLines)

allAllowedMessages := append(defaultAllowedLogMessages, allowedMessages...)

var logsFound uint

SCANNER_LOOP:
for scanner.Scan() {
jsonLogLine := scanner.Text()
if !strings.HasPrefix(jsonLogLine, "{") { // don't bother with non-json lines
if strings.HasPrefix(jsonLogLine, "panic") { // unless it's a panic
return fmt.Errorf("found panic: %s", jsonLogLine)
}
continue
}
jsonMapping := map[string]any{}

if err = json.Unmarshal([]byte(jsonLogLine), &jsonMapping); err != nil {
// This error can occur anytime someone uses %+v in a log message, ignoring
continue
}
logLevel, ok := jsonMapping["level"].(string)
if !ok {
return fmt.Errorf("found no log level in chainlink log line: %s", jsonLogLine)
}

if logLevel == "crit" { // "crit" is a custom core type they map to DPanic
zapLevel = zapcore.DPanicLevel
} else {
zapLevel, err = zapcore.ParseLevel(logLevel)
if err != nil {
return fmt.Errorf("'%s' not a valid zapcore level", logLevel)
}
}

if zapLevel >= failingLogLevel {
logErr := fmt.Errorf("found log at level '%s', failing any log level higher than %s: %s", logLevel, zapLevel.String(), jsonLogLine)
if failureThreshold > 1 {
logErr = fmt.Errorf("found too many logs at level '%s' or above; failure threshold of %d reached; last error found: %s", logLevel, failureThreshold, jsonLogLine)
}
logMessage, hasMessage := jsonMapping["msg"]
if !hasMessage {
logsFound++
if logsFound >= failureThreshold {
return logErr
}
continue
}

for _, allowedLog := range allAllowedMessages {
if strings.Contains(logMessage.(string), allowedLog.message) {
if allowedLog.logWhenFound {
log.Warn().
Str("Reason", allowedLog.reason).
Str("Level", allowedLog.level.CapitalString()).
Str("Msg", logMessage.(string)).
Msg("Found allowed log message, ignoring")
}

continue SCANNER_LOOP
}
}

logsFound++
if logsFound >= failureThreshold {
return logErr
}
logsFound, err = ScanLogLine(log.Logger, jsonLogLine, failingLogLevel, logsFound, failureThreshold, allAllowedMessages)
if err != nil {
return err
}
}
return nil
Expand Down

0 comments on commit 4e66f66

Please sign in to comment.