Skip to content

Commit

Permalink
Better monolog json
Browse files Browse the repository at this point in the history
* Improved handling of default Monolog format

* Improved JSON handling in default Monolog format

* Removal of JSON from line to form message
  • Loading branch information
marcin-jozwikowski authored Feb 9, 2024
1 parent f061753 commit 4944427
Show file tree
Hide file tree
Showing 6 changed files with 166 additions and 90 deletions.
2 changes: 1 addition & 1 deletion .github/workflows/test.yml
Original file line number Diff line number Diff line change
Expand Up @@ -23,4 +23,4 @@ jobs:

- name: Run tests
run: |
go test mcv_test.go
make test
3 changes: 3 additions & 0 deletions Makefile
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,9 @@ build_and_run:
run_against_data:
go run mcv.go -test

test:
go test mcv_test.go

log:
echo '{"message":"Example log of DEBUG level.","context":{"firewall_name":"main"},"level":100,"level_name":"DEBUG","channel":"security","datetime":"2023-11-14T00:37:26.623539+02:00","extra":{}}' > var/log.log
echo '{"message":"Example log of INFO level.","context":{"firewall_name":"main"},"level":200,"level_name":"INFO","channel":"security","datetime":"2023-11-14T00:37:26.623539+02:00","extra":{}}' >> var/log.log
Expand Down
76 changes: 50 additions & 26 deletions mcv_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,15 @@ func init() {
templ, _ = templates.GetTemplatateByName(templates.DefaultTemplateName)
}

const result_line_1__some_test = "NOTICE:default\t2023-11-09 14:29:06\tSome test message\r\n{\"session\":{\"id\":\"bq2fk4i3nhkgbj4eua964g5r63\"},\"user\":{\"id\":1}}"
const result_line_2__checking_support = "DEBUG:security\t2023-11-14 00:37:26\tChecking support on authenticator.\r\n{\"authenticator\":\"App\\\\Security\\\\AppAuthenticator\",\"firewall_name\":\"main\"}"
const result_line_3__unparsed = "2023-10-23 11:03:16: [9a4e77e9afa8] [ERROR] [Whatever] Login Error"
const result_line_4__file_change = "==> some/path/to\\file.log <=="
const result_line_5__user_logged = "INFO:default\t2023-10-23 11:07:47\tUser logged in\r\n{\"user\":{\"id\":\"54767261-98c6-4a57-9064-0d35fd06d1fc\"}}"
const result_line_6__route_matched = "INFO:request\t2023-12-29 10:26:40\tMatched route \"api_login\".\r\n{\"method\":\"POST\",\"request_uri\":\"http://localhost/api/v1/login\",\"route\":\"api_login\",\"route_parameters\":{\"_controller\":\"App\\\\User\\\\Infrastructure\\\\Controller\\\\ApiLoginController::index\",\"_route\":\"api_login\"}}"
const result_line_7__doctrine = "ERROR:request\t2023-12-31 11:18:53\tUncaught PHP Exception Symfony\\Component\\HttpKernel\\Exception\\HttpException: \"This value should be of type unknown. This value should not be blank. This value should not be blank.\" at RequestPayloadValueResolver.php line 127\r\n{\"exception\":\"[object] (Symfony\\\\Component\\\\HttpKernel\\\\Exception\\\\HttpException(code: 0): This value should be of type unknown.\\nThis value should not be blank.\\nThis value should not be blank. at /var/www/vendor/symfony/http-kernel/Controller/ArgumentResolver/RequestPayloadValueResolver.php:127)\\n[previous exception] [object] (Symfony\\\\Component\\\\Validator\\\\Exception\\\\ValidationFailedException(code: 0): :\\n This value should be of type unknown.\\nObject(App\\\\Scooter\\\\Infrastructure\\\\Request\\\\UpdateLocation\\\\UpdateLocationRequest).latitude:\\n This value should not be blank. (code c1051bb4-d103-4f74-8988-acbcafc7fdc3)\\nObject(App\\\\Scooter\\\\Infrastructure\\\\Request\\\\UpdateLocation\\\\UpdateLocationRequest).longitude:\\n This value should not be blank. (code c1051bb4-d103-4f74-8988-acbcafc7fdc3)\\n at /var/www/vendor/symfony/http-kernel/Controller/ArgumentResolver/RequestPayloadValueResolver.php:127)\"}"
const result_line__empty = ""

func TestDefault(t *testing.T) {
viewer.SetSettings(viewer.Settings{
NoNewLine: false,
Expand All @@ -23,11 +32,13 @@ func TestDefault(t *testing.T) {
})

runTests(t, "TestDefault", []string{
"NOTICE:default\t2023-11-09 14:29:06\tSome test message\r\n{\"session\":{\"id\":\"bq2fk4i3nhkgbj4eua964g5r63\"},\"user\":{\"id\":1}}\r\n\n",
"DEBUG:security\t2023-11-14 00:37:26\tChecking support on authenticator.\r\n{\"authenticator\":\"App\\\\Security\\\\AppAuthenticator\",\"firewall_name\":\"main\"}\r\n\n",
"2023-10-23 11:03:16: [9a4e77e9afa8] [ERROR] [Whatever] Login Error\n\n",
"",
"INFO:default\t2023-10-23 11:07:47\tUser logged in \r\n{\"user\":{\"id\":\"54767261-98c6-4a57-9064-0d35fd06d1fc\"}}\r\n\n",
result_line_1__some_test + "\r\n\n",
result_line_2__checking_support + "\r\n\n",
result_line_3__unparsed + "\n\n",
result_line__empty,
result_line_5__user_logged + "\r\n\n",
result_line_6__route_matched + "\r\n\n",
result_line_7__doctrine + "\r\n\n",
})
}

Expand All @@ -40,11 +51,13 @@ func TestNoNewLine(t *testing.T) {
})

runTests(t, "TestNoNewLine", []string{
"NOTICE:default\t2023-11-09 14:29:06\tSome test message\r\n{\"session\":{\"id\":\"bq2fk4i3nhkgbj4eua964g5r63\"},\"user\":{\"id\":1}}\r\n",
"DEBUG:security\t2023-11-14 00:37:26\tChecking support on authenticator.\r\n{\"authenticator\":\"App\\\\Security\\\\AppAuthenticator\",\"firewall_name\":\"main\"}\r\n",
"2023-10-23 11:03:16: [9a4e77e9afa8] [ERROR] [Whatever] Login Error\n",
"",
"INFO:default\t2023-10-23 11:07:47\tUser logged in \r\n{\"user\":{\"id\":\"54767261-98c6-4a57-9064-0d35fd06d1fc\"}}\r\n",
result_line_1__some_test + "\r\n",
result_line_2__checking_support + "\r\n",
result_line_3__unparsed + "\n",
result_line__empty,
result_line_5__user_logged + "\r\n",
result_line_6__route_matched + "\r\n",
result_line_7__doctrine + "\r\n",
})
}

Expand All @@ -57,11 +70,13 @@ func TestShowFileChange(t *testing.T) {
})

runTests(t, "TestShowFileChange", []string{
"NOTICE:default\t2023-11-09 14:29:06\tSome test message\r\n{\"session\":{\"id\":\"bq2fk4i3nhkgbj4eua964g5r63\"},\"user\":{\"id\":1}}\r\n\n",
"DEBUG:security\t2023-11-14 00:37:26\tChecking support on authenticator.\r\n{\"authenticator\":\"App\\\\Security\\\\AppAuthenticator\",\"firewall_name\":\"main\"}\r\n\n",
"2023-10-23 11:03:16: [9a4e77e9afa8] [ERROR] [Whatever] Login Error\n\n",
"==> some/path/to\\file.log <==\n\n",
"INFO:default\t2023-10-23 11:07:47\tUser logged in \r\n{\"user\":{\"id\":\"54767261-98c6-4a57-9064-0d35fd06d1fc\"}}\r\n\n",
result_line_1__some_test + "\r\n\n",
result_line_2__checking_support + "\r\n\n",
result_line_3__unparsed + "\n\n",
result_line_4__file_change + "\n\n",
result_line_5__user_logged + "\r\n\n",
result_line_6__route_matched + "\r\n\n",
result_line_7__doctrine + "\r\n\n",
})
}

Expand All @@ -74,11 +89,13 @@ func TestParsedLinesOnly(t *testing.T) {
})

runTests(t, "TestParsedLinesOnly", []string{
"NOTICE:default\t2023-11-09 14:29:06\tSome test message\r\n{\"session\":{\"id\":\"bq2fk4i3nhkgbj4eua964g5r63\"},\"user\":{\"id\":1}}\r\n\n",
"DEBUG:security\t2023-11-14 00:37:26\tChecking support on authenticator.\r\n{\"authenticator\":\"App\\\\Security\\\\AppAuthenticator\",\"firewall_name\":\"main\"}\r\n\n",
"",
"",
"INFO:default\t2023-10-23 11:07:47\tUser logged in \r\n{\"user\":{\"id\":\"54767261-98c6-4a57-9064-0d35fd06d1fc\"}}\r\n\n",
result_line_1__some_test + "\r\n\n",
result_line_2__checking_support + "\r\n\n",
result_line__empty,
result_line__empty,
result_line_5__user_logged + "\r\n\n",
result_line_6__route_matched + "\r\n\n",
result_line_7__doctrine + "\r\n\n",
})
}

Expand All @@ -91,21 +108,28 @@ func TestNoNewLineFileChangeParsedOnly(t *testing.T) {
})

runTests(t, "TestNoNewLineFileChangeParsedOnly", []string{
"NOTICE:default\t2023-11-09 14:29:06\tSome test message\r\n{\"session\":{\"id\":\"bq2fk4i3nhkgbj4eua964g5r63\"},\"user\":{\"id\":1}}\r\n",
"DEBUG:security\t2023-11-14 00:37:26\tChecking support on authenticator.\r\n{\"authenticator\":\"App\\\\Security\\\\AppAuthenticator\",\"firewall_name\":\"main\"}\r\n",
"",
"==> some/path/to\\file.log <==\n",
"INFO:default\t2023-10-23 11:07:47\tUser logged in \r\n{\"user\":{\"id\":\"54767261-98c6-4a57-9064-0d35fd06d1fc\"}}\r\n",
result_line_1__some_test + "\r\n",
result_line_2__checking_support + "\r\n",
result_line__empty,
result_line_4__file_change + "\n",
result_line_5__user_logged + "\r\n",
result_line_6__route_matched + "\r\n",
result_line_7__doctrine + "\r\n",
})
}

func runTests(t *testing.T, name string, expected []string) {
count := len(expected)
for id, line := range data.GetTestData() {
logLineItem := viewer.InitLogLine(line)
result := logLineItem.GetFormattedString()

if id == count {
t.Errorf("Response %d out of bounds on %s. Did not expect: '%q'", id, name, result)
}

if result != expected[id] {
t.Errorf("Invalid string value on '%s' item '%d'. Expected '%q', got '%q'", "testDefault", id, expected[id], result)
t.Errorf("Invalid string value on test '%s' item '%d'. Expected\r\n'%q', got\r\n'%q'", name, id, expected[id], result)
}
}
}
2 changes: 2 additions & 0 deletions src/data/test_data.go
Original file line number Diff line number Diff line change
Expand Up @@ -7,5 +7,7 @@ func GetTestData() []string {
`2023-10-23 11:03:16: [9a4e77e9afa8] [ERROR] [Whatever] Login Error`,
`==> some/path/to\file.log <==`,
`[2023-10-23T11:07:47.038324+00:00] default.INFO: User logged in {"user":{"id":"54767261-98c6-4a57-9064-0d35fd06d1fc"}} []`,
`[2023-12-29T10:26:40.537772+00:00] request.INFO: Matched route "api_login". {"route":"api_login","route_parameters":{"_route":"api_login","_controller":"App\\User\\Infrastructure\\Controller\\ApiLoginController::index"},"request_uri":"http://localhost/api/v1/login","method":"POST"} []`,
`[2023-12-31T11:18:53.286291+00:00] request.ERROR: Uncaught PHP Exception Symfony\Component\HttpKernel\Exception\HttpException: "This value should be of type unknown. This value should not be blank. This value should not be blank." at RequestPayloadValueResolver.php line 127 {"exception":"[object] (Symfony\\Component\\HttpKernel\\Exception\\HttpException(code: 0): This value should be of type unknown.\nThis value should not be blank.\nThis value should not be blank. at /var/www/vendor/symfony/http-kernel/Controller/ArgumentResolver/RequestPayloadValueResolver.php:127)\n[previous exception] [object] (Symfony\\Component\\Validator\\Exception\\ValidationFailedException(code: 0): :\n This value should be of type unknown.\nObject(App\\Scooter\\Infrastructure\\Request\\UpdateLocation\\UpdateLocationRequest).latitude:\n This value should not be blank. (code c1051bb4-d103-4f74-8988-acbcafc7fdc3)\nObject(App\\Scooter\\Infrastructure\\Request\\UpdateLocation\\UpdateLocationRequest).longitude:\n This value should not be blank. (code c1051bb4-d103-4f74-8988-acbcafc7fdc3)\n at /var/www/vendor/symfony/http-kernel/Controller/ArgumentResolver/RequestPayloadValueResolver.php:127)"} []`,
}
}
65 changes: 2 additions & 63 deletions src/viewer/reader.go
Original file line number Diff line number Diff line change
@@ -1,25 +1,23 @@
package viewer

import (
"errors"
"monolog-cli-viewer/src/viewer/reader"
"regexp"
"strings"

"github.com/stretchr/objx"
)

var monologRegex *regexp.Regexp
var fileChangeRegex *regexp.Regexp

func init() {
monologRegex = regexp.MustCompile(`\[(?P<time>[\S]+)\] (?P<channel>[\S]+)\.(?P<level>[\S]+): (?P<message>[\w\d\s]+)`)
fileChangeRegex = regexp.MustCompile(`^==>.*<==$`)
}

func InitLogLine(rawLine string) *LogLine {
j, err := objx.FromJSON(rawLine)
if err != nil {
j, err = readMonologFormat(rawLine)
j, err = reader.MonologFormat(rawLine)
if err != nil {
// cannot have it as JSON so lets at least return the raw line back
return &LogLine{
Expand All @@ -31,65 +29,6 @@ func InitLogLine(rawLine string) *LogLine {
return LogLineFromObjx(j, rawLine)
}

func readMonologFormat(rawLine string) (objx.Map, error) {
results, matched := regexMatchToMap(rawLine, monologRegex)

if len(results) == 0 {
return objx.MSI(), errors.New("could not read")
}

contextExtra, removed := strings.CutPrefix(rawLine, matched)
if !removed {
return objx.MSI(), errors.New("no context nor extra")
}

contextExtra = strings.ReplaceAll(contextExtra, "\r\n", " ") // remove Windows-style newline
contextExtra = strings.ReplaceAll(contextExtra, "}\n", "} ") // remove Unix newline
contextExtra = strings.ReplaceAll(contextExtra, "} []", "}\n{}") // empty extra
contextExtra = strings.ReplaceAll(contextExtra, "} {", "}\n{") // filled extra

splitContextExtra := strings.Split(contextExtra, "\n")
objxFields := map[string]objx.Map{}

if len(splitContextExtra) > 0 { // at least one field - context
objxFields["context"] = objx.MustFromJSON(splitContextExtra[0])
} else { // no additional fields
objxFields["context"] = objx.MSI()
}

if len(splitContextExtra) > 1 { // more than one field - this mean extra
objxFields["extra"] = objx.MustFromJSON(splitContextExtra[1])
} else { // no extras
objxFields["extra"] = objx.MSI()
}

return objx.MSI(
"level_name", results["level"],
"level", results["level"],
"datetime", results["time"],
"message", results["message"],
"channel", results["channel"],
"context", objxFields["context"],
"extra", objxFields["extra"],
), nil
}

func regexMatchToMap(value string, regex *regexp.Regexp) (map[string]string, string) {
match := regex.FindString(value)
matches := regex.FindStringSubmatch(value)
results := make(map[string]string)

if len(match) > 0 {
for i, name := range regex.SubexpNames() {
if i != 0 && name != "" {
results[name] = matches[i]
}
}
}

return results, match
}

func isFileChangeLine(rawLine string) bool {
found := fileChangeRegex.FindString(rawLine)

Expand Down
108 changes: 108 additions & 0 deletions src/viewer/reader/monolog.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,108 @@
package reader

import (
"errors"
"regexp"
"strings"

"github.com/stretchr/objx"
)

var monologRegex *regexp.Regexp
var jsonSegmentsRegex []*regexp.Regexp

func init() {
monologRegex = regexp.MustCompile(`\[(?P<time>[\S]+)\] (?P<channel>[\S]+)\.(?P<level>[\S]+):`)
jsonSegmentsRegex = []*regexp.Regexp{
regexp.MustCompile(`\{(?:[^{}]*\{[^{}]*\}[^{}]*)*\}|\[.*?\]`),
regexp.MustCompile(`\{.*?\}|\[.*?\]`),
regexp.MustCompile(`(\{[^}]*\}|\[[^]]*\])`),
}
}

func MonologFormat(rawLine string) (objx.Map, error) {
mappedValues, matched := regexMatchToMap(rawLine, monologRegex) // extract time, channel, and level from raw string

if len(mappedValues) == 0 {
// nothing was found - not a Monolog format
return objx.MSI(), errors.New("could not read")
}

messageContextExtra, removed := strings.CutPrefix(rawLine, matched)
if !removed {
// does not have
return objx.MSI(), errors.New("no context nor extra")
}

contextExtra, message := extractJSONSegments(messageContextExtra)
objxFields := map[string]objx.Map{}

if len(contextExtra) > 0 && len(contextExtra[0]) > 2 { // at least one field - context
objxFields["context"] = getJsonOrEmpty(contextExtra[0])
}

if len(contextExtra) > 1 && len(contextExtra[1]) > 2 { // more than one field - this mean extra
objxFields["extra"] = getJsonOrEmpty(contextExtra[1])
}

return objx.MSI(
"level_name", mappedValues["level"],
"level", mappedValues["level"],
"datetime", mappedValues["time"],
"message", message,
"channel", mappedValues["channel"],
"context", objxFields["context"],
"extra", objxFields["extra"],
), nil
}

func getJsonOrEmpty(input string) objx.Map {
if obj, err := objx.FromJSON(input); err == nil {
return obj
}
return objx.MSI()
}

func extractJSONSegments(input string) ([]string, string) {
// @todo further improve on the algorithm to consider only one type array/object at once
result := []string{}
inputLength := len(input)
openenedCount := 0
closingIndex := inputLength
for index := inputLength - 1; index > 0; index-- {
currentChar := input[index]
if currentChar == '}' || currentChar == ']' { // we're at the closing char
if openenedCount == 0 { // we're not inside JSON
closingIndex = index // means we've found the outermost closing tag
}
openenedCount++
}

if currentChar == '{' || currentChar == '[' { // we're at the opening char
openenedCount--
if openenedCount == 0 {
// prepend the JSON to the result. We're reading backwards.
result = append([]string{input[index : closingIndex+1]}, result...)
input = input[0:index]
}
}
}

return result, strings.Trim(input, "\r\t\n ")
}

func regexMatchToMap(value string, regex *regexp.Regexp) (map[string]string, string) {
match := regex.FindString(value)
matches := regex.FindStringSubmatch(value)
results := make(map[string]string)

if len(match) > 0 {
for i, name := range regex.SubexpNames() {
if i != 0 && name != "" {
results[name] = matches[i]
}
}
}

return results, match
}

0 comments on commit 4944427

Please sign in to comment.