go-agent icon indicating copy to clipboard operation
go-agent copied to clipboard

zerolog-writer.go panics when message has "," (and/or a combination of escaped `"`) as the last character(s)

Open MarioCarrion opened this issue 5 months ago • 1 comments

Description

go-agent panics when message has , (or a escaped ") as the last character(s)

Steps to Reproduce

The easiest way to reproduce is to use a message like the following:

zerolog.Ctx(ctx).Info().Msg("\"value\",")

Also notice the diff for the tests (listed below) has a test cases using only , and still panics.

Expected Behavior

Does not panic

NR Diag results

This is the normal output we get when serving the app, but below there's a shorter log that uses the diff:

| 2024/08/27 16:06:22 goroutine 2178 [running]:
| runtime/debug.Stack()
| 	/usr/local/go/src/runtime/debug/stack.go:24 +0x5e
| github.com/newrelic/go-agent/v3/newrelic.(*thread).End(0xc000117470, {0x13cc040, 0xc000166db0})
| 	/go/pkg/mod/github.com/newrelic/go-agent/[email protected]/newrelic/internal_txn.go:452 +0x22b
| github.com/newrelic/go-agent/v3/newrelic.(*Transaction).End(0xc00081c498)
| 	/go/pkg/mod/github.com/newrelic/go-agent/[email protected]/newrelic/transaction.go:48 +0x1a9
| panic({0x13cc040?, 0xc000166db0?})
| 	/usr/local/go/src/runtime/panic.go:770 +0x132
| github.com/newrelic/go-agent/v3/integrations/logcontext-v2/zerologWriter.isStringValue(...)
| 	/go/pkg/mod/github.com/newrelic/go-agent/v3/integrations/logcontext-v2/[email protected]/zerolog-writer.go:93
| github.com/newrelic/go-agent/v3/integrations/logcontext-v2/zerologWriter.parseJSONLogData({0xc00078c000, 0x1bc, 0x580})
| 	/go/pkg/mod/github.com/newrelic/go-agent/v3/integrations/logcontext-v2/[email protected]/zerolog-writer.go:74 +0x354
| github.com/newrelic/go-agent/v3/integrations/logcontext-v2/zerologWriter.ZerologWriter.Write({{0x0, {0x16bae00, 0xc000118020}, 0xc000432030, 0xc00081c498}}, {0xc00078c000, 0x1bc, 0x580})
| 	/go/pkg/mod/github.com/newrelic/go-agent/v3/integrations/logcontext-v2/[email protected]/zerolog-writer.go:47 +0x67
| github.com/rs/zerolog.LevelWriterAdapter.WriteLevel(...)
| 	/go/pkg/mod/github.com/rs/[email protected]/writer.go:27
| github.com/rs/zerolog.(*Event).write(0xc00021e620)
| 	/go/pkg/mod/github.com/rs/[email protected]/event.go:80 +0x103
| github.com/rs/zerolog.(*Event).msg(0xc00021e620, {0xc00035c1c0, 0xda})
| 	/go/pkg/mod/github.com/rs/[email protected]/event.go:151 +0x21a
| github.com/rs/zerolog.(*Event).Msgf(0xc00021e620, {0x14a7cee?, 0x0?}, {0xc000eeb280?, 0x7e?, 0xc1ab9c3fb3fbec7d?})
| 	/go/pkg/mod/github.com/rs/[email protected]/event.go:131 +0x46
| <proprietary code starts here>

Your Environment

N/A

Reproduction case

Here's a diff demonstrating the issue using the existing test cases:

diff --git a/v3/integrations/logcontext-v2/zerologWriter/zerolog-writer_test.go b/v3/integrations/logcontext-v2/zerologWriter/zerolog-writer_test.go
index ab0a2f97..2a92c570 100644
--- a/v3/integrations/logcontext-v2/zerologWriter/zerolog-writer_test.go
+++ b/v3/integrations/logcontext-v2/zerologWriter/zerolog-writer_test.go
@@ -123,6 +123,22 @@ func TestParseLogData(t *testing.T) {
 				Severity: "debug",
 			},
 		},
+		{
+			`{"level":"info",message":"\"value\","}` + "\n",
+			"level",
+			newrelic.LogData{
+				Message:  `{"level":"info",message":"\"value\","}` + "\n",
+				Severity: "info",
+			},
+		},
+		{
+			`{"level":"info",message":","}` + "\n",
+			"level",
+			newrelic.LogData{
+				Message:  `{"level":"info",message":","}` + "\n",
+				Severity: "info",
+			},
+		},
 	}
 	for _, test := range tests {
 		if test.levelKey != "" {

Log output:

go test -v ./...
?   	github.com/newrelic/go-agent/v3/integrations/logcontext-v2/zerologWriter/example	[no test files]
=== RUN   TestParseLogData
--- FAIL: TestParseLogData (0.00s)
panic: runtime error: index out of range [-1] [recovered]
	panic: runtime error: index out of range [-1]

goroutine 21 [running]:
testing.tRunner.func1.2({0x10119e020, 0x140000de8a0})
	/opt/homebrew/Cellar/go/1.22.5/libexec/src/testing/testing.go:1631 +0x1c4
testing.tRunner.func1()
	/opt/homebrew/Cellar/go/1.22.5/libexec/src/testing/testing.go:1634 +0x33c
panic({0x10119e020?, 0x140000de8a0?})
	/opt/homebrew/Cellar/go/1.22.5/libexec/src/runtime/panic.go:770 +0x124
github.com/newrelic/go-agent/v3/integrations/logcontext-v2/zerologWriter.isStringValue(...)
	/Users/mario/Repositories/github.com/newrelic/go-agent/v3/integrations/logcontext-v2/zerologWriter/zerolog-writer.go:93
github.com/newrelic/go-agent/v3/integrations/logcontext-v2/zerologWriter.parseJSONLogData({0x100fc1788, 0x27, 0x27})
	/Users/mario/Repositories/github.com/newrelic/go-agent/v3/integrations/logcontext-v2/zerologWriter/zerolog-writer.go:74 +0x2a8
github.com/newrelic/go-agent/v3/integrations/logcontext-v2/zerologWriter.TestParseLogData(0x140000e4d00)
	/Users/mario/Repositories/github.com/newrelic/go-agent/v3/integrations/logcontext-v2/zerologWriter/zerolog-writer_test.go:147 +0x104
testing.tRunner(0x140000e4d00, 0x1011e3620)
	/opt/homebrew/Cellar/go/1.22.5/libexec/src/testing/testing.go:1689 +0xec
created by testing.(*T).Run in goroutine 1
	/opt/homebrew/Cellar/go/1.22.5/libexec/src/testing/testing.go:1742 +0x318
FAIL	github.com/newrelic/go-agent/v3/integrations/logcontext-v2/zerologWriter	0.466s
FAIL

Additional context

Maybe be related to: https://github.com/newrelic/go-agent/issues/583 ?

MarioCarrion avatar Aug 27 '24 20:08 MarioCarrion