From 928f54135ea2d108a16b38efcc008096bfdc8bd6 Mon Sep 17 00:00:00 2001 From: Liran BG Date: Sun, 16 Jan 2022 10:07:24 +0200 Subject: [PATCH] Introducing redactor (#6) --- .github/workflows/ci.yaml | 9 +- buffer.go | 23 +++-- buffer_test.go | 85 +++++++++++++++++ go.mod | 18 ++-- go.sum | 68 ++++++++++---- logger.go | 92 ++++++++++--------- logger_test.go | 18 ++++ mux.go | 66 +++++++------- redactor.go | 187 ++++++++++++++++++++++++++++++++++++++ 9 files changed, 460 insertions(+), 106 deletions(-) create mode 100644 redactor.go diff --git a/.github/workflows/ci.yaml b/.github/workflows/ci.yaml index 154a67b..ae43b02 100644 --- a/.github/workflows/ci.yaml +++ b/.github/workflows/ci.yaml @@ -15,7 +15,7 @@ jobs: - uses: actions/setup-go@v2 with: - go-version: "1.14" + go-version: "1.17" - uses: actions/cache@v2 with: @@ -31,12 +31,17 @@ jobs: test: name: Test runs-on: ubuntu-latest + strategy: + matrix: + + # 1.14 for BC + go: [ "1.14", "1.17" ] steps: - uses: actions/checkout@v2 - uses: actions/setup-go@v2 with: - go-version: "1.14" + go-version: ${{ matrix.go }} - uses: actions/cache@v2 with: diff --git a/buffer.go b/buffer.go index 953714b..868b297 100644 --- a/buffer.go +++ b/buffer.go @@ -20,9 +20,10 @@ import ( "bytes" "encoding/json" "fmt" + "io" "time" - "github.com/pkg/errors" + "github.com/nuclio/errors" ) var ErrBufferPoolAllocationTimeout = errors.New("Timed out waiting for buffer logger") @@ -34,26 +35,36 @@ type BufferLogger struct { Buffer *bytes.Buffer } +// NewBufferLogger creates a logger that is able to capture the output into a buffer. if a request arrives +// and the user wishes to capture the log, this will be used as the logger instead of the default +// logger func NewBufferLogger(name string, encoding string, level Level) (*BufferLogger, error) { writer := &bytes.Buffer{} + return newBufferLogger(name, encoding, level, writer, writer) +} + +func NewBufferLoggerWithRedactor(name string, encoding string, level Level, redactor *Redactor) (*BufferLogger, error) { + return newBufferLogger(name, encoding, level, redactor, redactor.GetOutput().(*bytes.Buffer)) +} - // create a logger that is able to capture the output into a buffer. if a request arrives - // and the user wishes to capture the log, this will be used as the logger instead of the default - // logger +func newBufferLogger(name string, + encoding string, + level Level, + writer io.Writer, + buffer *bytes.Buffer) (*BufferLogger, error) { newLogger, err := NewNuclioZap(name, encoding, nil, writer, writer, level) - if err != nil { return nil, errors.Wrap(err, "Failed to create buffer logger") } return &BufferLogger{ Logger: newLogger, - Buffer: writer, + Buffer: buffer, encoding: encoding, }, nil } diff --git a/buffer_test.go b/buffer_test.go index 722d43e..fd0ce48 100644 --- a/buffer_test.go +++ b/buffer_test.go @@ -17,6 +17,7 @@ limitations under the License. package nucliozap import ( + "bytes" "testing" "time" @@ -27,6 +28,34 @@ type BufferLoggerTestSuite struct { suite.Suite } +func (suite *BufferLoggerTestSuite) TestRedactor() { + redactor := NewRedactor(&bytes.Buffer{}) + redactor.AddValueRedactions([]string{"password"}) + redactor.AddRedactions([]string{"replaceme"}) + bufferLogger, err := NewBufferLoggerWithRedactor("test", "json", InfoLevel, redactor) + suite.Require().NoError(err, "Failed creating buffer logger") + + bufferLogger.Logger.customEncoderConfig = NewEncoderConfig() + bufferLogger.Logger.customEncoderConfig.JSON.VarGroupName = "testVars" + bufferLogger.Logger.customEncoderConfig.JSON.VarGroupMode = VarGroupModeStructured + bufferLogger.Logger.prepareVarsCallback = bufferLogger.Logger.prepareVarsStructured + + // log + bufferLogger.Logger.InfoWith("Check", "password", "123456", "replaceme", "55") + + // get log entries + logEntries, err := bufferLogger.GetLogEntries() + suite.Require().NoError(err, "Failed to get log entries") + + // verify (debug should be filtered) + suite.Require().Equal("Check", logEntries[0]["message"]) + suite.Require().Equal("info", logEntries[0]["level"]) + suite.Require().Equal(map[string]interface{}{ + "*****": "55", + "password": "[redacted]", + }, logEntries[0][bufferLogger.Logger.customEncoderConfig.JSON.VarGroupName]) +} + func (suite *BufferLoggerTestSuite) TestJSONEncoding() { bufferLogger, err := NewBufferLogger("test", "json", InfoLevel) suite.Require().NoError(err, "Failed creating buffer logger") @@ -171,6 +200,62 @@ func (suite *BufferLoggerPoolTestSuite) TestAllocation() { suite.Require().Equal(0, bufferLogger.Buffer.Len()) } +// ============ +// Benchmarking +// ============ + +func BenchmarkNewBufferLogger(b *testing.B) { + loggerInstance := createBufferLogger(b, nil) + executeBenchmark(b, loggerInstance) +} + +func BenchmarkNewBufferLoggerWithRedactor(b *testing.B) { + loggerInstance := createBufferLogger(b, NewRedactor(&bytes.Buffer{})) + executeBenchmark(b, loggerInstance) +} + +func BenchmarkNewBufferLoggerWithDisabledRedactor(b *testing.B) { + redactor := NewRedactor(&bytes.Buffer{}) + redactor.SetDisabled(true) + loggerInstance := createBufferLogger(b, redactor) + executeBenchmark(b, loggerInstance) +} + +func BenchmarkNewBufferLoggerWithRedactorWithRedactions(b *testing.B) { + redactor := NewRedactor(&bytes.Buffer{}) + redactor.AddRedactions([]string{"replaceme"}) + loggerInstance := createBufferLogger(b, redactor) + executeBenchmark(b, loggerInstance) +} + +func BenchmarkNewBufferLoggerWithRedactorWithValueRedactions(b *testing.B) { + redactor := NewRedactor(&bytes.Buffer{}) + redactor.AddValueRedactions([]string{"replaceme"}) + loggerInstance := createBufferLogger(b, redactor) + executeBenchmark(b, loggerInstance) +} + +func createBufferLogger(b *testing.B, redactor *Redactor) *BufferLogger { + var err error + var bufferLogger *BufferLogger + if redactor != nil { + bufferLogger, err = NewBufferLoggerWithRedactor("test", "json", InfoLevel, redactor) + } else { + bufferLogger, err = NewBufferLogger("test", "json", InfoLevel) + } + if err != nil { + b.FailNow() + return nil + } + return bufferLogger +} + +func executeBenchmark(b *testing.B, bufferLogger *BufferLogger) { + for i := 0; i < b.N; i++ { + bufferLogger.Logger.InfoWith("Check", "password", "123456", "replaceme", "55") + } +} + func TestBufferLoggerTestSuite(t *testing.T) { suite.Run(t, new(BufferLoggerPoolTestSuite)) suite.Run(t, new(BufferLoggerTestSuite)) diff --git a/go.mod b/go.mod index 8ba99cb..279269c 100644 --- a/go.mod +++ b/go.mod @@ -1,13 +1,19 @@ module github.com/nuclio/zap -go 1.14 +go 1.17 require ( - github.com/mattn/go-colorable v0.1.7 // indirect - github.com/mgutz/ansi v0.0.0-20200706080929-d51e80ef957d + github.com/liranbg/uberzap v1.20.0-nuclio.1 + github.com/logrusorgru/aurora/v3 v3.0.0 + github.com/nuclio/errors v0.0.3 github.com/nuclio/logger v0.0.1 - github.com/pavius/zap v1.4.2-0.20180228181622-8d52692529b8 - github.com/pkg/errors v0.9.1 - github.com/stretchr/testify v1.6.1 + github.com/stretchr/testify v1.7.0 +) + +require ( + github.com/davecgh/go-spew v1.1.1 // indirect + github.com/pmezard/go-difflib v1.0.0 // indirect + go.uber.org/atomic v1.7.0 // indirect go.uber.org/multierr v1.6.0 // indirect + gopkg.in/yaml.v3 v3.0.0-20210107192922-496545a6307b // indirect ) diff --git a/go.sum b/go.sum index c58dfdf..dc514bf 100644 --- a/go.sum +++ b/go.sum @@ -1,32 +1,66 @@ +github.com/benbjohnson/clock v1.1.0 h1:Q92kusRqC1XV2MjkWETPvjJVqKetz1OzxZB7mHJLju8= +github.com/benbjohnson/clock v1.1.0/go.mod h1:J11/hYXuz8f4ySSvYwY0FKfm+ezbsZBKZxNJlLklBHA= github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= -github.com/mattn/go-colorable v0.1.7 h1:bQGKb3vps/j0E9GfJQ03JyhRuxsvdAanXlT9BTw3mdw= -github.com/mattn/go-colorable v0.1.7/go.mod h1:u6P/XSegPjTcexA+o6vUJrdnUu04hMope9wVRipJSqc= -github.com/mattn/go-isatty v0.0.12 h1:wuysRhFDzyxgEmMf5xjvJ2M9dZoWAXNNr5LSBS7uHXY= -github.com/mattn/go-isatty v0.0.12/go.mod h1:cbi8OIDigv2wuxKPP5vlRcQ1OAZbq2CE4Kysco4FUpU= -github.com/mgutz/ansi v0.0.0-20200706080929-d51e80ef957d h1:5PJl274Y63IEHC+7izoQE9x6ikvDFZS2mDVS3drnohI= -github.com/mgutz/ansi v0.0.0-20200706080929-d51e80ef957d/go.mod h1:01TrycV0kFyexm33Z7vhZRXopbI8J3TDReVlkTgMUxE= +github.com/kr/pretty v0.1.0 h1:L/CwN0zerZDmRFUapSPitk6f+Q3+0za1rQkzVuMiMFI= +github.com/kr/pretty v0.1.0/go.mod h1:dAy3ld7l9f0ibDNOQOHHMYYIIbhfbHSm3C4ZsoJORNo= +github.com/kr/pty v1.1.1/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ= +github.com/kr/text v0.1.0 h1:45sCR5RtlFHMR4UwH9sdQ5TC8v0qDQCHnXt+kaKSTVE= +github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI= +github.com/liranbg/uberzap v1.20.0-nuclio.1 h1:KUh2DHnhhF8q9iuzqZGxbIMg2i/5izyF+a8Cy9C6WsE= +github.com/liranbg/uberzap v1.20.0-nuclio.1/go.mod h1:Tj8cuE+vk7B5p5zywDnPCRk1FZX5UjyVugTtsTTHjxQ= +github.com/logrusorgru/aurora/v3 v3.0.0 h1:R6zcoZZbvVcGMvDCKo45A9U/lzYyzl5NfYIvznmDfE4= +github.com/logrusorgru/aurora/v3 v3.0.0/go.mod h1:vsR12bk5grlLvLXAYrBsb5Oc/N+LxAlxggSjiwMnCUc= +github.com/nuclio/errors v0.0.3 h1:eXi8DjLj5kn5X7TrVlpmt3lPfS3rueUKf/cIUmxV6x8= +github.com/nuclio/errors v0.0.3/go.mod h1:it2rUqDarIL8PasLYZo0Q1Ebsx4NRPM+OyYYakgNyrQ= github.com/nuclio/logger v0.0.1 h1:e+vT/Ug65RC+u0QX2J+lq3P57ZBwJ1ZA6Q2LCEcViwE= github.com/nuclio/logger v0.0.1/go.mod h1:ttazNAqTxKjQ7XrGDZxecumGa9KCIuJh88gzFY1mRXo= -github.com/pavius/zap v1.4.2-0.20180228181622-8d52692529b8 h1:WqLgmr/wj9TO5Sc6oYPQRAJBxuHE0NTeuVeFnT+FZVo= -github.com/pavius/zap v1.4.2-0.20180228181622-8d52692529b8/go.mod h1:6FWOCx06uh50GClv8S2cfk3asqTJs3qq3ZNRtLZE77I= -github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4= -github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= +github.com/pkg/errors v0.8.1 h1:iURUrRGxPUNPdy5/HRSm+Yj6okJ6UtLINN0Q9M4+h3I= +github.com/pkg/errors v0.8.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI= -github.com/stretchr/testify v1.6.1 h1:hDPOHmpOpP40lSULcqw7IrRb/u7w6RpDC9399XyoNd0= -github.com/stretchr/testify v1.6.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= +github.com/stretchr/testify v1.7.0 h1:nwc3DEeHmmLAfoZucVR881uASk0Mfjw8xYJ99tb5CcY= +github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg= +github.com/yuin/goldmark v1.3.5/go.mod h1:mwnBkeHKe2W/ZEtQ+71ViKU8L12m81fl3OWwC1Zlc8k= go.uber.org/atomic v1.7.0 h1:ADUqmZGgLDDfbSL9ZmPxKTybcoEYHgpYfELNoN+7hsw= go.uber.org/atomic v1.7.0/go.mod h1:fEN4uk6kAWBTFdckzkM89CLk9XfWZrxpCo0nPH17wJc= +go.uber.org/goleak v1.1.11 h1:wy28qYRKZgnJTxGxvye5/wgWr1EKjmUDGYox5mGlRlI= +go.uber.org/goleak v1.1.11/go.mod h1:cwTWslyiVhfpKIDGSZEM2HlOvcqm+tG4zioyIeLoqMQ= go.uber.org/multierr v1.6.0 h1:y6IPFStTAIT5Ytl7/XYmHvzXQ7S3g/IeZW9hyZ5thw4= go.uber.org/multierr v1.6.0/go.mod h1:cdWPpRnG4AhwMwsgIHip0KRBQjJy5kYEpYjJxpXp9iU= -golang.org/x/sys v0.0.0-20200116001909-b77594299b42/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= -golang.org/x/sys v0.0.0-20200223170610-d5e6a3e2c0ae h1:/WDfKMnPU+m5M4xB+6x4kaepxRw6jWvR5iDRdvjHgy8= -golang.org/x/sys v0.0.0-20200223170610-d5e6a3e2c0ae/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= -gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405 h1:yhCVgyC4o1eVCa2tZl7eS0r+SDo693bJlVdllGtEeKM= +golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w= +golang.org/x/crypto v0.0.0-20191011191535-87dc89f01550/go.mod h1:yigFU9vqHzYiE8UmvKecakEJjdnWj3jj499lnFckfCI= +golang.org/x/lint v0.0.0-20190930215403-16217165b5de/go.mod h1:6SW0HCj/g11FgYtHlgUYUwCkIfeOF89ocIRzGO/8vkc= +golang.org/x/mod v0.4.2/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA= +golang.org/x/net v0.0.0-20190311183353-d8887717615a/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg= +golang.org/x/net v0.0.0-20190404232315-eb5bcb51f2a3/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg= +golang.org/x/net v0.0.0-20190620200207-3b0461eec859/go.mod h1:z5CRVTTTmAJ677TzLLGU+0bjPO0LkuOLi4/5GtJWs/s= +golang.org/x/net v0.0.0-20210405180319-a5a99cb37ef4/go.mod h1:p54w0d4576C0XHj96bSt6lcn1PtDYWL6XObtHCRCNQM= +golang.org/x/sync v0.0.0-20190423024810-112230192c58/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= +golang.org/x/sync v0.0.0-20210220032951-036812b2e83c/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= +golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY= +golang.org/x/sys v0.0.0-20190412213103-97732733099d/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20201119102817-f84b799fce68/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20210330210617-4fbd30eecc44/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20210510120138-977fb7262007/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo= +golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ= +golang.org/x/text v0.3.3/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ= +golang.org/x/tools v0.0.0-20180917221912-90fa682c2a6e/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ= +golang.org/x/tools v0.0.0-20190311212946-11955173bddd/go.mod h1:LCzVGOaR6xXOjkQ3onu1FJEFr0SW1gC7cKk1uF8kGRs= +golang.org/x/tools v0.0.0-20191119224855-298f0cb1881e/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo= +golang.org/x/tools v0.1.5/go.mod h1:o0xws9oXOQQZyjljx8fwUC0k7L1pTE6eaCbjGeHmOkk= +golang.org/x/xerrors v0.0.0-20190717185122-a985d3407aa7/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= +golang.org/x/xerrors v0.0.0-20191011141410-1b5146add898/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= +golang.org/x/xerrors v0.0.0-20200804184101-5ec99f83aff1/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= -gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c h1:dUUwHk2QECo/6vqA44rthZ8ie2QXMNeKRTHCNY2nXvo= +gopkg.in/check.v1 v1.0.0-20180628173108-788fd7840127 h1:qIbj1fsPNlZgppZ+VLlY7N33q108Sa+fhmuc+sWQYwY= +gopkg.in/check.v1 v1.0.0-20180628173108-788fd7840127/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= +gopkg.in/yaml.v2 v2.2.8 h1:obN1ZagJSUGI0Ek/LBmuj4SNLPfIny3KsKFopxRdj10= +gopkg.in/yaml.v2 v2.2.8/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI= gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= +gopkg.in/yaml.v3 v3.0.0-20210107192922-496545a6307b h1:h8qDotaEPuJATrMmW04NCwg7v22aHH28wwpauUhK9Oo= +gopkg.in/yaml.v3 v3.0.0-20210107192922-496545a6307b/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= diff --git a/logger.go b/logger.go index 0d8c8dd..9b656ed 100644 --- a/logger.go +++ b/logger.go @@ -24,10 +24,10 @@ import ( "strings" "time" - "github.com/mgutz/ansi" + "github.com/liranbg/uberzap" + "github.com/liranbg/uberzap/zapcore" + "github.com/logrusorgru/aurora/v3" "github.com/nuclio/logger" - "github.com/pavius/zap" - "github.com/pavius/zap/zapcore" ) type VarGroupMode string @@ -80,23 +80,17 @@ const ( FatalLevel Level = Level(zapcore.FatalLevel) ) -type writerWrapper struct { - io.Writer -} - -func (w writerWrapper) Sync() error { - return nil -} - // NuclioZap is a concrete implementation of the nuclio logger interface, using zap type NuclioZap struct { *zap.SugaredLogger atomicLevel zap.AtomicLevel + outputWriter io.Writer + errorOutputWriter io.Writer coloredLevelDebug string coloredLevelInfo string coloredLevelWarn string coloredLevelError string - colorLoggerName func(string) string + colorLoggerName aurora.Color customEncoderConfig *EncoderConfig encoding string @@ -110,14 +104,17 @@ func NewNuclioZap(name string, sink io.Writer, errSink io.Writer, level Level) (*NuclioZap, error) { + + if customEncoderConfig == nil { + customEncoderConfig = NewEncoderConfig() + } + newNuclioZap := &NuclioZap{ atomicLevel: zap.NewAtomicLevelAt(zapcore.Level(level)), customEncoderConfig: customEncoderConfig, encoding: encoding, - } - - if customEncoderConfig == nil { - customEncoderConfig = NewEncoderConfig() + outputWriter: sink, + errorOutputWriter: errSink, } // create an encoder configuration @@ -129,8 +126,8 @@ func NewNuclioZap(name string, Development: true, Encoding: encoding, EncoderConfig: *encoderConfig, - OutputWriters: []zapcore.WriteSyncer{writerWrapper{sink}}, - ErrorOutputWriters: []zapcore.WriteSyncer{writerWrapper{errSink}}, + OutputWriters: []zapcore.WriteSyncer{zapcore.AddSync(newNuclioZap.outputWriter)}, + ErrorOutputWriters: []zapcore.WriteSyncer{zapcore.AddSync(newNuclioZap.errorOutputWriter)}, DisableStacktrace: true, } @@ -154,7 +151,7 @@ func NewNuclioZap(name string, return newNuclioZap, nil } -// We use this istead of testing.Verbose since we don't want to get testing flags in our code +// We use this instead of testing.Verbose since we don't want to get testing flags in our code func isVerboseTesting() bool { for _, arg := range os.Args { if arg == "-test.v=true" || arg == "-test.v" { @@ -174,12 +171,15 @@ func NewNuclioZapTest(name string) (*NuclioZap, error) { loggerLevel = InfoLevel } - return NewNuclioZapCmd(name, loggerLevel) + loggerRedactor := NewRedactor(os.Stdout) + loggerRedactor.Disable() + + return NewNuclioZapCmd(name, loggerLevel, loggerRedactor) } // NewNuclioZapCmd creates a logger pre-configured for commands -func NewNuclioZapCmd(name string, level Level) (*NuclioZap, error) { - return NewNuclioZap(name, "console", nil, os.Stdout, os.Stdout, level) +func NewNuclioZapCmd(name string, level Level, writer io.Writer) (*NuclioZap, error) { + return NewNuclioZap(name, "console", nil, writer, writer, level) } // GetLevelByName return logging level by name @@ -202,6 +202,14 @@ func GetLevelByName(levelName string) Level { } } +func (nz *NuclioZap) GetRedactor() *Redactor { + redactor, ok := nz.outputWriter.(*Redactor) + if ok { + return redactor + } + return nil +} + // SetLevel sets the logging level func (nz *NuclioZap) SetLevel(level Level) { nz.atomicLevel.SetLevel(zapcore.Level(level)) @@ -340,7 +348,7 @@ func (nz *NuclioZap) encodeLoggerName(loggerName string, enc zapcore.PrimitiveAr } // just truncate - enc.AppendString(nz.colorLoggerName(encodedLoggerName)) + enc.AppendString(aurora.Colorize(encodedLoggerName, nz.colorLoggerName).String()) } func (nz *NuclioZap) encodeStdoutLevel(level zapcore.Level, enc zapcore.PrimitiveArrayEncoder) { @@ -364,12 +372,11 @@ func (nz *NuclioZap) encodeStdoutTime(t time.Time, enc zapcore.PrimitiveArrayEnc } func (nz *NuclioZap) initializeColors() { - nz.coloredLevelDebug = ansi.Color("(D)", "green") - nz.coloredLevelInfo = ansi.Color("(I)", "blue") - nz.coloredLevelWarn = ansi.Color("(W)", "yellow") - nz.coloredLevelError = ansi.Color("(E)", "red") - - nz.colorLoggerName = ansi.ColorFunc("white") + nz.coloredLevelDebug = aurora.Green("(D)").String() + nz.coloredLevelInfo = aurora.Blue("(I)").String() + nz.coloredLevelWarn = aurora.Yellow("(W)").String() + nz.coloredLevelError = aurora.Red("(E)").String() + nz.colorLoggerName = aurora.WhiteFg } func (nz *NuclioZap) getEncoderConfig(encoding string, encoderConfig *EncoderConfig) *zapcore.EncoderConfig { @@ -386,7 +393,8 @@ func (nz *NuclioZap) getEncoderConfig(encoding string, encoderConfig *EncoderCon EncodeTime: nz.encodeStdoutTime, EncodeDuration: zapcore.StringDurationEncoder, EncodeCaller: func(zapcore.EntryCaller, zapcore.PrimitiveArrayEncoder) {}, - EncodeLoggerName: nz.encodeLoggerName, + EncodeName: nz.encodeLoggerName, + ConsoleSeparator: " ", } } @@ -399,18 +407,18 @@ func (nz *NuclioZap) getEncoderConfig(encoding string, encoderConfig *EncoderCon } return &zapcore.EncoderConfig{ - TimeKey: encoderConfig.JSON.TimeFieldName, - LevelKey: "level", - NameKey: "name", - CallerKey: "", - MessageKey: "message", - StacktraceKey: "stack", - LineEnding: encoderConfig.JSON.LineEnding, - EncodeLevel: zapcore.LowercaseLevelEncoder, - EncodeTime: timeEncoder, - EncodeDuration: zapcore.SecondsDurationEncoder, - EncodeCaller: func(zapcore.EntryCaller, zapcore.PrimitiveArrayEncoder) {}, - EncodeLoggerName: zapcore.FullLoggerNameEncoder, + TimeKey: encoderConfig.JSON.TimeFieldName, + NameKey: "name", + LevelKey: "level", + CallerKey: "", + MessageKey: "message", + StacktraceKey: "stack", + LineEnding: encoderConfig.JSON.LineEnding, + EncodeLevel: zapcore.LowercaseLevelEncoder, + EncodeTime: timeEncoder, + EncodeDuration: zapcore.SecondsDurationEncoder, + EncodeCaller: func(zapcore.EntryCaller, zapcore.PrimitiveArrayEncoder) {}, + EncodeName: zapcore.FullNameEncoder, } } diff --git a/logger_test.go b/logger_test.go index df72d9d..fc810a0 100644 --- a/logger_test.go +++ b/logger_test.go @@ -11,6 +11,24 @@ type LoggerTestSuite struct { suite.Suite } +func (suite *LoggerTestSuite) TestRedactor() { + output := &bytes.Buffer{} + loggerInstance, err := NewNuclioZapCmd("redacted-test", + InfoLevel, + NewRedactor(output)) + loggerInstance.GetRedactor().AddValueRedactions([]string{"password"}) + loggerInstance.GetRedactor().AddRedactions([]string{"replaceme"}) + suite.Require().NoError(err, "Failed creating buffer logger") + + // log + loggerInstance.InfoWith("Check", "password", "123456", "replaceme", "55") + + // verify (debug should be filtered) + suite.Require().Contains(output.String(), "Check") + suite.Require().NotContains(output.String(), "123456") + suite.Require().NotContains(output.String(), "replaceme") +} + func (suite *LoggerTestSuite) TestPrepareVars() { zap := NuclioZap{} vars := []interface{}{ diff --git a/mux.go b/mux.go index 6388f1f..e24bd31 100644 --- a/mux.go +++ b/mux.go @@ -22,7 +22,7 @@ import ( "github.com/nuclio/logger" ) -// a logger that multiplexes logs towards multiple loggers +// MuxLogger multiplexes logs towards multiple loggers type MuxLogger struct { loggers []logger.Logger } @@ -40,98 +40,98 @@ func (ml *MuxLogger) GetLoggers() []logger.Logger { } func (ml *MuxLogger) Error(format interface{}, vars ...interface{}) { - for _, logger := range ml.loggers { - logger.Error(format, vars...) + for _, loggerInstance := range ml.loggers { + loggerInstance.Error(format, vars...) } } func (ml *MuxLogger) ErrorCtx(ctx context.Context, format interface{}, vars ...interface{}) { - for _, logger := range ml.loggers { - logger.ErrorCtx(ctx, format, vars...) + for _, loggerInstance := range ml.loggers { + loggerInstance.ErrorCtx(ctx, format, vars...) } } func (ml *MuxLogger) Warn(format interface{}, vars ...interface{}) { - for _, logger := range ml.loggers { - logger.Warn(format, vars...) + for _, loggerInstance := range ml.loggers { + loggerInstance.Warn(format, vars...) } } func (ml *MuxLogger) WarnCtx(ctx context.Context, format interface{}, vars ...interface{}) { - for _, logger := range ml.loggers { - logger.WarnCtx(ctx, format, vars...) + for _, loggerInstance := range ml.loggers { + loggerInstance.WarnCtx(ctx, format, vars...) } } func (ml *MuxLogger) Info(format interface{}, vars ...interface{}) { - for _, logger := range ml.loggers { - logger.Info(format, vars...) + for _, loggerInstance := range ml.loggers { + loggerInstance.Info(format, vars...) } } func (ml *MuxLogger) InfoCtx(ctx context.Context, format interface{}, vars ...interface{}) { - for _, logger := range ml.loggers { - logger.InfoCtx(ctx, format, vars...) + for _, loggerInstance := range ml.loggers { + loggerInstance.InfoCtx(ctx, format, vars...) } } func (ml *MuxLogger) Debug(format interface{}, vars ...interface{}) { - for _, logger := range ml.loggers { - logger.Debug(format, vars...) + for _, loggerInstance := range ml.loggers { + loggerInstance.Debug(format, vars...) } } func (ml *MuxLogger) DebugCtx(ctx context.Context, format interface{}, vars ...interface{}) { - for _, logger := range ml.loggers { - logger.DebugCtx(ctx, format, vars...) + for _, loggerInstance := range ml.loggers { + loggerInstance.DebugCtx(ctx, format, vars...) } } func (ml *MuxLogger) ErrorWith(format interface{}, vars ...interface{}) { - for _, logger := range ml.loggers { - logger.ErrorWith(format, vars...) + for _, loggerInstance := range ml.loggers { + loggerInstance.ErrorWith(format, vars...) } } func (ml *MuxLogger) ErrorWithCtx(ctx context.Context, format interface{}, vars ...interface{}) { - for _, logger := range ml.loggers { - logger.ErrorWithCtx(ctx, format, vars...) + for _, loggerInstance := range ml.loggers { + loggerInstance.ErrorWithCtx(ctx, format, vars...) } } func (ml *MuxLogger) WarnWith(format interface{}, vars ...interface{}) { - for _, logger := range ml.loggers { - logger.WarnWith(format, vars...) + for _, loggerInstance := range ml.loggers { + loggerInstance.WarnWith(format, vars...) } } func (ml *MuxLogger) WarnWithCtx(ctx context.Context, format interface{}, vars ...interface{}) { - for _, logger := range ml.loggers { - logger.WarnWithCtx(ctx, format, vars...) + for _, loggerInstance := range ml.loggers { + loggerInstance.WarnWithCtx(ctx, format, vars...) } } func (ml *MuxLogger) InfoWith(format interface{}, vars ...interface{}) { - for _, logger := range ml.loggers { - logger.InfoWith(format, vars...) + for _, loggerInstance := range ml.loggers { + loggerInstance.InfoWith(format, vars...) } } func (ml *MuxLogger) InfoWithCtx(ctx context.Context, format interface{}, vars ...interface{}) { - for _, logger := range ml.loggers { - logger.InfoWithCtx(ctx, format, vars...) + for _, loggerInstance := range ml.loggers { + loggerInstance.InfoWithCtx(ctx, format, vars...) } } func (ml *MuxLogger) DebugWith(format interface{}, vars ...interface{}) { - for _, logger := range ml.loggers { - logger.DebugWith(format, vars...) + for _, loggerInstance := range ml.loggers { + loggerInstance.DebugWith(format, vars...) } } func (ml *MuxLogger) DebugWithCtx(ctx context.Context, format interface{}, vars ...interface{}) { - for _, logger := range ml.loggers { - logger.DebugWithCtx(ctx, format, vars...) + for _, loggerInstance := range ml.loggers { + loggerInstance.DebugWithCtx(ctx, format, vars...) } } diff --git a/redactor.go b/redactor.go new file mode 100644 index 0000000..1070600 --- /dev/null +++ b/redactor.go @@ -0,0 +1,187 @@ +/* +Copyright 2021 The Nuclio Authors. +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + http://www.apache.org/licenses/LICENSE-2.0 +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ + +package nucliozap + +import ( + "bytes" + "fmt" + "io" + "regexp" +) + +type RedactingLogger interface { + + // GetOutput returns redactor writer + GetOutput() io.Writer + + // GetRedactor returns redactor instance + GetRedactor() *Redactor +} + +type Redactor struct { + disabled bool + output io.Writer + redactions [][]byte + valueRedactions [][]byte + valueRedactionsRegexps []regexp.Regexp + replacement []byte + valueReplacement []byte + + // must have same signature as io.Writer Write + redactFunc func(p []byte) (n int, err error) +} + +func NewRedactor(output io.Writer) *Redactor { + redactor := &Redactor{ + output: output, + redactions: [][]byte{}, + valueRedactions: [][]byte{}, + valueRedactionsRegexps: []regexp.Regexp{}, + replacement: []byte("*****"), + valueReplacement: []byte(`$1"[redacted]"`), + disabled: false, + } + redactor.redactFunc = redactor.redactEnabled + return redactor +} + +// SetOutput sets redactor output +func (r *Redactor) SetOutput(output io.Writer) { + r.output = output +} + +// GetOutput returns redactor writer +func (r *Redactor) GetOutput() io.Writer { + return r.output +} + +// AddValueRedactions redacts key:[value] or key=[value] kind of strings +func (r *Redactor) AddValueRedactions(valueRedactions []string) { + for _, valueRedaction := range valueRedactions { + r.valueRedactions = append(r.valueRedactions, []byte(valueRedaction)) + } + r.valueRedactions = r.removeDuplicates(r.valueRedactions) + r.prepareReplacements() +} + +// AddRedactions redacts simple strings +func (r *Redactor) AddRedactions(redactions []string) { + var nonEmptyRedactions []string + + for _, redaction := range redactions { + if redaction != "" { + nonEmptyRedactions = append(nonEmptyRedactions, redaction) + } + } + + for _, nonEmptyRedaction := range nonEmptyRedactions { + r.redactions = append(r.redactions, []byte(nonEmptyRedaction)) + } + r.redactions = r.removeDuplicates(r.redactions) +} + +// SetDisabled turns logger redaction on/off +func (r *Redactor) SetDisabled(disable bool) { + r.disabled = disable + if disable { + r.redactFunc = r.redactDisabled + } else { + r.redactFunc = r.redactEnabled + } +} + +// Write writes to output +func (r *Redactor) Write(p []byte) (n int, err error) { + return r.redactFunc(p) +} + +func (r *Redactor) GetRedactions() [][]byte { + return r.redactions +} + +func (r *Redactor) Enable() { + r.disabled = false +} + +func (r *Redactor) Disable() { + r.disabled = true +} + +func (r *Redactor) prepareReplacements() { + + // redact values of either strings of type `valueRedaction=[value]` or `valueRedaction: [value]` + // w/wo single/double quotes + // golang regex doesn't support lookarounds, so we will check things manually + matchKeyWithSeparatorTemplate := `\\*[\'"]?(?i)%s\\*[\'"]?\s*[=:]\s*` + matchValue := `\'[^\']*?\'|\"[^\"]*\"|\S*` + + for _, redactionField := range r.valueRedactions { + matchKeyWithSeparator := fmt.Sprintf(matchKeyWithSeparatorTemplate, redactionField) + r.valueRedactionsRegexps = append(r.valueRedactionsRegexps, + *regexp.MustCompile(fmt.Sprintf(`(%s)(%s)`, matchKeyWithSeparator, matchValue)), + ) + } + +} + +func (r *Redactor) redactDisabled(p []byte) (n int, err error) { + return r.output.Write(p) +} + +func (r *Redactor) redactEnabled(p []byte) (n int, err error) { + redactedPrint := r.redact(p) + n, err = r.output.Write(redactedPrint) + if err != nil { + return + } + if n != len(redactedPrint) { + err = io.ErrShortWrite + return + } + + // HACK: let the caller know we wrote the original length of the text + // To prevent caller explode while validating the length of the written text (redaction might change the length) + return len(p), err +} + +func (r *Redactor) redact(inputToRedact []byte) []byte { + + // replace key=value or key: value + for _, valueRedactionsRegexp := range r.valueRedactionsRegexps { + inputToRedact = valueRedactionsRegexp.ReplaceAll(inputToRedact, r.valueReplacement) + } + + // replace the simple string redactions + for _, redactionField := range r.redactions { + inputToRedact = bytes.ReplaceAll(inputToRedact, redactionField, r.replacement) + } + + return inputToRedact +} + +func (r *Redactor) removeDuplicates(elements [][]byte) [][]byte { + encountered := map[string]bool{} + + // Create a map of all unique elements. + for v := range elements { + encountered[string(elements[v])] = true + } + + // Place all keys from the map into a slice. + var result [][]byte + for key := range encountered { + result = append(result, []byte(key)) + } + return result +}