From ffe3e1a461cff662c600c105c8cf14a7f078fb52 Mon Sep 17 00:00:00 2001 From: Islam Shehata Date: Tue, 16 Jan 2024 11:03:32 +0200 Subject: [PATCH 1/6] update the regex to capture new lines in messages The `.*` doesn't catch new lines. Its now updated to `(?s:(.*))` to be able to capture the rest of the message as on line. --- server/server.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/server/server.go b/server/server.go index 4d80a13..017f546 100644 --- a/server/server.go +++ b/server/server.go @@ -38,7 +38,7 @@ var ( axiomMetaInfo = map[string]string{} ) -var logLineRgx, _ = regexp.Compile(`^([0-9.:TZ-]{20,})\s+([0-9a-f-]{36})\s+(ERROR|INFO|WARN|DEBUG|TRACE)\s+(.*)`) +var logLineRgx, _ = regexp.Compile(`^([0-9.:TZ-]{20,})\s+([0-9a-f-]{36})\s+(ERROR|INFO|WARN|DEBUG|TRACE)\s+(?s:(.*))`) func init() { logger, _ = zap.NewProduction() From 083e653c03135ed02bf19a89a251c14bce0f2eb8 Mon Sep 17 00:00:00 2001 From: Islam Shehata Date: Tue, 16 Jan 2024 11:13:54 +0200 Subject: [PATCH 2/6] prepare v11 --- version/version.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/version/version.go b/version/version.go index 6acc1ff..45e2ef1 100644 --- a/version/version.go +++ b/version/version.go @@ -1,7 +1,7 @@ package version // manually set constant version -const version string = "v10" +const version string = "v11" // Get returns the Go module version of the axiom-go module. func Get() string { From 2912e0c3b94577ac064c2b79cba32594f40f7d33 Mon Sep 17 00:00:00 2001 From: Islam Shehata Date: Tue, 16 Jan 2024 12:38:19 +0200 Subject: [PATCH 3/6] add unit tests for event message extraction --- server/server.go | 54 ++++++++++++++---------- server/server_test.go | 98 +++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 130 insertions(+), 22 deletions(-) create mode 100644 server/server_test.go diff --git a/server/server.go b/server/server.go index 017f546..f3a9ddf 100644 --- a/server/server.go +++ b/server/server.go @@ -91,28 +91,7 @@ func httpHandler(ax *flusher.Axiom, runtimeDone chan struct{}) http.HandlerFunc e["_time"], e["time"] = e["time"], nil if e["type"] == "function" { - e["message"] = e["record"] - if recordStr, ok := e["record"].(string); ok && len(recordStr) > 0 { - recordStr = strings.Trim(recordStr, "\n") - // parse the record - // first check if the record is a json object, if not parse it as a text log line - if recordStr[0] == '{' && recordStr[len(recordStr)-1] == '}' { - var record map[string]any - err = json.Unmarshal([]byte(recordStr), &record) - if err != nil { - logger.Error("Error unmarshalling record:", zap.Error(err)) - // do not return, we want to continue processing the event - } else { - e["record"] = record - } - } else { - matches := logLineRgx.FindStringSubmatch(recordStr) - if len(matches) == 5 { - e["record"] = map[string]any{"requestId": matches[2], "message": matches[4], "timestamp": matches[1], "level": e["level"]} - e["level"] = strings.ToLower(matches[3]) - } - } - } + extractEventMessage(e) } // decide if the handler should notify the extension that the runtime is done @@ -136,3 +115,34 @@ func httpHandler(ax *flusher.Axiom, runtimeDone chan struct{}) http.HandlerFunc } } } + +// extractEventMessage extracts the message from the record field and puts it in the message field +// it detects if the record is a json string or a text log line that confirms to AWS log line formatting. +func extractEventMessage(e map[string]any) { + e["message"] = e["record"] + if recordStr, ok := e["record"].(string); ok && len(recordStr) > 0 { + recordStr = strings.Trim(recordStr, "\n") + // parse the record + // first check if the record is a json object, if not parse it as a text log line + if recordStr[0] == '{' && recordStr[len(recordStr)-1] == '}' { + var record map[string]any + err := json.Unmarshal([]byte(recordStr), &record) + if err != nil { + logger.Error("Error unmarshalling record:", zap.Error(err)) + // do not return, we want to continue processing the event + } else { + if level, ok := record["level"].(string); ok { + record["level"] = strings.ToLower(level) + } + e["level"] = record["level"] + e["record"] = record + } + } else { + matches := logLineRgx.FindStringSubmatch(recordStr) + if len(matches) == 5 { + e["level"] = strings.ToLower(matches[3]) + e["record"] = map[string]any{"requestId": matches[2], "message": matches[4], "timestamp": matches[1], "level": e["level"]} + } + } + } +} diff --git a/server/server_test.go b/server/server_test.go new file mode 100644 index 0000000..4211e5d --- /dev/null +++ b/server/server_test.go @@ -0,0 +1,98 @@ +package server + +import ( + "testing" +) + +func TestMessageExtraction(t *testing.T) { + testCases := []struct { + name string + input string + expected map[string]any + }{ + { + name: "error messages on multiple lines", + input: "2024-01-16T08:53:51.919Z 4b995efa-75f8-4fdc-92af-0882c79f47a1 ERROR testing sending an error\nand this is a new line inside the error \n and a new line \n bye", + expected: map[string]any{ + "level": "error", + "message": "SAME_AS_INPUT_NO_NEED_TO_DUPLICATE_INPUT_HERE", + "record": map[string]any{"requestId": "4b995efa-75f8-4fdc-92af-0882c79f47a1", "message": "testing sending an error\nand this is a new line inside the error \n and a new line \n bye", "timestamp": "2024-01-16T08:53:51.919Z", "level": "error"}, + }, + }, + { + name: "info messages", + input: "2024-01-16T08:53:51.919Z 4b995efa-75f8-4fdc-92af-0882c79f47a2 INFO Hello, world!", + expected: map[string]any{ + "level": "info", + "message": "SAME_AS_INPUT_NO_NEED_TO_DUPLICATE_INPUT_HERE", + "record": map[string]any{"requestId": "4b995efa-75f8-4fdc-92af-0882c79f47a2", "message": "Hello, world!", "timestamp": "2024-01-16T08:53:51.919Z", "level": "info"}, + }, + }, + { + name: "warn messages", + input: "2024-01-16T08:53:51.919Z 4b995efa-75f8-4fdc-92af-0882c79f47a3 WARN head my warning", + expected: map[string]any{ + "level": "warn", + "message": "SAME_AS_INPUT_NO_NEED_TO_DUPLICATE_INPUT_HERE", + "record": map[string]any{"requestId": "4b995efa-75f8-4fdc-92af-0882c79f47a3", "message": "head my warning", "timestamp": "2024-01-16T08:53:51.919Z", "level": "warn"}, + }, + }, + { + name: "trace messages", + input: "2024-01-16T08:53:51.919Z 4b995efa-75f8-4fdc-92af-0882c79f47a4 TRACE this is a trace \n with information on a new line.", + expected: map[string]any{ + "level": "trace", + "message": "SAME_AS_INPUT_NO_NEED_TO_DUPLICATE_INPUT_HERE", + "record": map[string]any{"requestId": "4b995efa-75f8-4fdc-92af-0882c79f47a4", "message": "this is a trace \n with information on a new line.", "timestamp": "2024-01-16T08:53:51.919Z", "level": "trace"}, + }, + }, + { + name: "debug messages", + input: "2024-01-16T08:53:51.919Z 4b995efa-75f8-4fdc-92af-0882c79f47a5 DEBUG Debugging is fun!", + expected: map[string]any{ + "level": "debug", + "message": "SAME_AS_INPUT_NO_NEED_TO_DUPLICATE_INPUT_HERE", + "record": map[string]any{"requestId": "4b995efa-75f8-4fdc-92af-0882c79f47a5", "message": "Debugging is fun!", "timestamp": "2024-01-16T08:53:51.919Z", "level": "debug"}, + }, + }, + { + name: "testing json messages", + input: `{"timestamp":"2024-01-08T16:48:45.316Z","level":"INFO","requestId":"de126cf0-6124-426c-818a-174983fbfc4b","message":"foo != bar"}`, + expected: map[string]any{ + "level": "info", + "message": "SAME_AS_INPUT_NO_NEED_TO_DUPLICATE_INPUT_HERE", + "record": map[string]any{"requestId": "de126cf0-6124-426c-818a-174983fbfc4b", "message": "foo != bar", "timestamp": "2024-01-08T16:48:45.316Z", "level": "info"}, + }, + }, + } + + for _, testCase := range testCases { + t.Run(testCase.name, func(t *testing.T) { + e := make(map[string]any) + e["record"] = testCase.input + extractEventMessage(e) + if e["level"] != testCase.expected["level"] { + t.Errorf("Expected level to be %s, got %s", testCase.expected["level"], e["level"]) + } + if e["message"] != testCase.input { // the message field should contain the original input + t.Errorf("Expected message to be %s, got %s", testCase.input, e["message"]) + } + + expectedRecord := testCase.expected["record"].(map[string]any) + outputRecord := e["record"].(map[string]any) + + if outputRecord["timestamp"] != expectedRecord["timestamp"] { + t.Errorf("Expected timestamp to be %s, got %s", testCase.expected["timestamp"], e["timestamp"]) + } + if outputRecord["level"] != expectedRecord["level"] { + t.Errorf("Expected record.level to be %s, got %s", expectedRecord["level"], outputRecord["level"]) + } + if outputRecord["requestId"] != expectedRecord["requestId"] { + t.Errorf("Expected record.requestId to be %s, got %s", expectedRecord["requestId"], outputRecord["requestId"]) + } + if outputRecord["message"] != expectedRecord["message"] { + t.Errorf("Expected record.message to be %s, got %s", expectedRecord["message"], outputRecord["message"]) + } + }) + } +} From db4d09aa4412ac91f6137113ca85696df3b53abf Mon Sep 17 00:00:00 2001 From: Islam Shehata Date: Tue, 16 Jan 2024 12:43:31 +0200 Subject: [PATCH 4/6] add tests job to CI --- .github/workflows/ci.yaml | 18 ++++++++++++++++++ Makefile | 3 +++ 2 files changed, 21 insertions(+) diff --git a/.github/workflows/ci.yaml b/.github/workflows/ci.yaml index 84bb524..4a97b2d 100644 --- a/.github/workflows/ci.yaml +++ b/.github/workflows/ci.yaml @@ -28,6 +28,24 @@ jobs: go-version: ${{ env.GOVERSION }} - uses: golangci/golangci-lint-action@v3 + test: + name: Test + runs-on: ubuntu-latest + needs: + - lint + strategy: + matrix: + architecture: + - amd64 + - arm64 + steps: + - uses: actions/checkout@v3 + - uses: actions/setup-go@v3 + with: + go-version: ${{ env.GOVERSION }} + - name: unit tests (${{ matrix.architecture }}) + run: GOARCH=${{ matrix.architecture }} make test + build: name: Build runs-on: ubuntu-latest diff --git a/Makefile b/Makefile index 2268a4b..d4b82f8 100644 --- a/Makefile +++ b/Makefile @@ -1,5 +1,8 @@ GOOS=linux +test: + go test ./... + build: mkdir -p bin/extensions GOOS=${GOOS} GOARCH=${GOARCH} go build -o bin/extensions/axiom-lambda-extension . From 2e858787d1820a5a8e6ec2b1412162583cec2826 Mon Sep 17 00:00:00 2001 From: Islam Shehata Date: Tue, 16 Jan 2024 12:50:25 +0200 Subject: [PATCH 5/6] merge test and build into one job --- .github/workflows/ci.yaml | 20 ++------------------ Makefile | 2 +- 2 files changed, 3 insertions(+), 19 deletions(-) diff --git a/.github/workflows/ci.yaml b/.github/workflows/ci.yaml index 4a97b2d..3fecfb2 100644 --- a/.github/workflows/ci.yaml +++ b/.github/workflows/ci.yaml @@ -28,24 +28,6 @@ jobs: go-version: ${{ env.GOVERSION }} - uses: golangci/golangci-lint-action@v3 - test: - name: Test - runs-on: ubuntu-latest - needs: - - lint - strategy: - matrix: - architecture: - - amd64 - - arm64 - steps: - - uses: actions/checkout@v3 - - uses: actions/setup-go@v3 - with: - go-version: ${{ env.GOVERSION }} - - name: unit tests (${{ matrix.architecture }}) - run: GOARCH=${{ matrix.architecture }} make test - build: name: Build runs-on: ubuntu-latest @@ -61,6 +43,8 @@ jobs: - uses: actions/setup-go@v3 with: go-version: ${{ env.GOVERSION }} + - name: unit tests ${{ matrix.architecture }} + run: GOARCH=${{ matrix.architecture }} make test - name: build the binary ${{ matrix.architecture }} run: GOARCH=${{ matrix.architecture }} make build diff --git a/Makefile b/Makefile index d4b82f8..e9de60b 100644 --- a/Makefile +++ b/Makefile @@ -1,7 +1,7 @@ GOOS=linux test: - go test ./... + GOOS=${GOOS} GOARCH=${GOARCH} go test ./... build: mkdir -p bin/extensions From 913e5ebc009505a49686db26bacbd58ff1ba2ae9 Mon Sep 17 00:00:00 2001 From: Islam Shehata Date: Tue, 16 Jan 2024 13:13:27 +0200 Subject: [PATCH 6/6] split test job to run on 1 arch only --- .github/workflows/ci.yaml | 15 +++++++++++++-- 1 file changed, 13 insertions(+), 2 deletions(-) diff --git a/.github/workflows/ci.yaml b/.github/workflows/ci.yaml index 3fecfb2..175d9b1 100644 --- a/.github/workflows/ci.yaml +++ b/.github/workflows/ci.yaml @@ -28,6 +28,19 @@ jobs: go-version: ${{ env.GOVERSION }} - uses: golangci/golangci-lint-action@v3 + test: + name: Test + runs-on: ubuntu-latest + needs: + - lint + steps: + - uses: actions/checkout@v3 + - uses: actions/setup-go@v3 + with: + go-version: ${{ env.GOVERSION }} + - name: unit tests + run: make test + build: name: Build runs-on: ubuntu-latest @@ -43,8 +56,6 @@ jobs: - uses: actions/setup-go@v3 with: go-version: ${{ env.GOVERSION }} - - name: unit tests ${{ matrix.architecture }} - run: GOARCH=${{ matrix.architecture }} make test - name: build the binary ${{ matrix.architecture }} run: GOARCH=${{ matrix.architecture }} make build