From 324933fff9636eec55e15a857984f3eba28d36ae Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Vin=C3=ADcius=20Garcia?= Date: Tue, 11 Jul 2023 09:47:27 -0300 Subject: [PATCH 01/13] Add a first version of the InjectLogger function --- ksql.go | 20 ++++++++++++----- ksql_test.go | 41 ++++++++++++++++++++++++++++++++++ logger.go | 63 ++++++++++++++++++++++++++++++++++++++++++++++++++++ 3 files changed, 118 insertions(+), 6 deletions(-) create mode 100644 logger.go diff --git a/ksql.go b/ksql.go index 6181157..74494ce 100644 --- a/ksql.go +++ b/ksql.go @@ -148,7 +148,7 @@ func (c DB) Query( records interface{}, query string, params ...interface{}, -) error { +) (err error) { slicePtr := reflect.ValueOf(records) slicePtrType := slicePtr.Type() if slicePtrType.Kind() != reflect.Ptr { @@ -187,6 +187,8 @@ func (c DB) Query( query = selectPrefix + query } + defer ctxLog(ctx, query, params, &err) + rows, err := c.db.QueryContext(ctx, query, params...) if err != nil { return fmt.Errorf("error running query: %w", err) @@ -242,7 +244,7 @@ func (c DB) QueryOne( record interface{}, query string, params ...interface{}, -) error { +) (err error) { v := reflect.ValueOf(record) t := v.Type() if t.Kind() != reflect.Ptr { @@ -277,6 +279,8 @@ func (c DB) QueryOne( query = selectPrefix + query } + defer ctxLog(ctx, query, params, &err) + rows, err := c.db.QueryContext(ctx, query, params...) if err != nil { return fmt.Errorf("error running query: %w", err) @@ -423,10 +427,10 @@ func (c DB) Insert( ctx context.Context, table Table, record interface{}, -) error { +) (err error) { v := reflect.ValueOf(record) t := v.Type() - if err := assertStructPtr(t); err != nil { + if err = assertStructPtr(t); err != nil { return fmt.Errorf( "KSQL: expected record to be a pointer to struct, but got: %T", record, @@ -447,6 +451,7 @@ func (c DB) Insert( } query, params, scanValues, err := buildInsertQuery(ctx, c.dialect, table, t, v, info, record) + defer ctxLog(ctx, query, params, &err) if err != nil { return err } @@ -581,7 +586,7 @@ func (c DB) Delete( ctx context.Context, table Table, idOrRecord interface{}, -) error { +) (err error) { if err := table.validate(); err != nil { return fmt.Errorf("can't delete from ksql.Table: %w", err) } @@ -595,6 +600,8 @@ func (c DB) Delete( var params []interface{} query, params = buildDeleteQuery(c.dialect, table, idMap) + defer ctxLog(ctx, query, params, &err) + result, err := c.db.ExecContext(ctx, query, params...) if err != nil { return err @@ -655,7 +662,7 @@ func (c DB) Patch( ctx context.Context, table Table, record interface{}, -) error { +) (err error) { v := reflect.ValueOf(record) t := v.Type() tStruct := t @@ -676,6 +683,7 @@ func (c DB) Patch( } query, params, err := buildUpdateQuery(ctx, c.dialect, table.name, info, recordMap, table.idColumns...) + defer ctxLog(ctx, query, params, &err) if err != nil { return err } diff --git a/ksql_test.go b/ksql_test.go index ba997ef..ae1a61f 100644 --- a/ksql_test.go +++ b/ksql_test.go @@ -1,6 +1,7 @@ package ksql import ( + "context" "fmt" "io" "testing" @@ -98,3 +99,43 @@ func TestClose(t *testing.T) { tt.AssertErrContains(t, err, "fakeCloseErrMsg") }) } + +func TestInjectLogger(t *testing.T) { + ctx := context.Background() + + t.Run("should work for the Query function", func(t *testing.T) { + var inputQuery string + var inputParams []interface{} + c := DB{ + db: mockDBAdapter{ + QueryContextFn: func(ctx context.Context, query string, params ...interface{}) (Rows, error) { + inputQuery = query + inputParams = params + + return mockRows{ + NextFn: func() bool { return false }, + }, nil + }, + }, + } + + var loggedQuery string + var loggedParams []interface{} + var loggedErr error + ctx := InjectLogger(ctx, "info", func(ctx context.Context, values LogValues) { + loggedQuery = values.Query + loggedParams = values.Params + loggedErr = values.Err + }) + + var row []struct { + Count int `ksql:"count"` + } + err := c.Query(ctx, &row, `SELECT count(*) AS count FROM users WHERE type = $1 AND age < $2`, "fakeType", 42) + tt.AssertNoErr(t, err) + tt.AssertEqual(t, len(row), 0) + tt.AssertEqual(t, loggedQuery, inputQuery) + tt.AssertEqual(t, loggedParams, inputParams) + tt.AssertEqual(t, loggedErr, nil) + }) +} diff --git a/logger.go b/logger.go new file mode 100644 index 0000000..de3ef85 --- /dev/null +++ b/logger.go @@ -0,0 +1,63 @@ +package ksql + +import "context" + +type loggerKey struct{} + +type LogValues struct { + Query string + Params []interface{} + Err error +} + +func InjectLogger( + ctx context.Context, + level string, + logFn func(ctx context.Context, values LogValues), +) context.Context { + if level != "info" { + level = "error" + } + + return context.WithValue(ctx, loggerKey{}, logger{ + level: level, + logFn: func(ctx context.Context, query string, params []interface{}, err error) { + logFn(ctx, LogValues{ + Query: query, + Params: params, + Err: err, + }) + }, + }) +} + +func ctxLog(ctx context.Context, query string, params []interface{}, err *error) { + l := ctx.Value(loggerKey{}) + if l == nil { + return + } + + if *err != nil { + l.(logger)._error(ctx, query, params, *err) + return + } + + l.(logger)._info(ctx, query, params, nil) +} + +type logger struct { + level string + logFn func(ctx context.Context, query string, params []interface{}, err error) +} + +func (l logger) _info(ctx context.Context, query string, params []interface{}, err error) { + if l.level == "error" { + return + } + + l.logFn(ctx, query, params, err) +} + +func (l logger) _error(ctx context.Context, query string, params []interface{}, err error) { + l.logFn(ctx, query, params, err) +} From c55ba119a3cfad02a383959015af722c1a189c46 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Vin=C3=ADcius=20Garcia?= Date: Tue, 11 Jul 2023 10:26:13 -0300 Subject: [PATCH 02/13] Add a few more tests --- internal/testtools/assert.go | 13 ++++ internal_mocks.go | 20 ++++++ ksql_test.go | 131 ++++++++++++++++++++++++++--------- 3 files changed, 133 insertions(+), 31 deletions(-) diff --git a/internal/testtools/assert.go b/internal/testtools/assert.go index 8763f1a..e10c793 100644 --- a/internal/testtools/assert.go +++ b/internal/testtools/assert.go @@ -47,6 +47,19 @@ func AssertErrContains(t *testing.T, err error, substrs ...string) { } } +// AssertContains will check if the input text contains +// all the substrs specified on the substrs argument or +// fail with an appropriate error message. +func AssertContains(t *testing.T, str string, substrs ...string) { + for _, substr := range substrs { + require.True(t, + strings.Contains(str, substr), + "missing substring '%s' in error message: '%s'", + substr, str, + ) + } +} + // AssertApproxDuration checks if the durations v1 and v2 are close up to the tolerance specified. // The format and args slice can be used for generating an appropriate error message if they are not. func AssertApproxDuration(t *testing.T, tolerance time.Duration, v1, v2 time.Duration, format string, args ...interface{}) { diff --git a/internal_mocks.go b/internal_mocks.go index 013e3ac..7ef9b9e 100644 --- a/internal_mocks.go +++ b/internal_mocks.go @@ -62,6 +62,26 @@ func (m mockRows) Columns() ([]string, error) { return m.ColumnsFn() } +// mockResult mocks the ksql.Result interface +type mockResult struct { + LastInsertIdFn func() (int64, error) + RowsAffectedFn func() (int64, error) +} + +func (m mockResult) LastInsertId() (int64, error) { + if m.LastInsertIdFn != nil { + return m.LastInsertIdFn() + } + return 0, nil +} + +func (m mockResult) RowsAffected() (int64, error) { + if m.RowsAffectedFn != nil { + return m.RowsAffectedFn() + } + return 0, nil +} + // mockTx mocks the ksql.Tx interface type mockTx struct { DBAdapter diff --git a/ksql_test.go b/ksql_test.go index ae1a61f..13105ca 100644 --- a/ksql_test.go +++ b/ksql_test.go @@ -2,6 +2,7 @@ package ksql import ( "context" + "errors" "fmt" "io" "testing" @@ -103,39 +104,107 @@ func TestClose(t *testing.T) { func TestInjectLogger(t *testing.T) { ctx := context.Background() - t.Run("should work for the Query function", func(t *testing.T) { - var inputQuery string - var inputParams []interface{} - c := DB{ - db: mockDBAdapter{ - QueryContextFn: func(ctx context.Context, query string, params ...interface{}) (Rows, error) { - inputQuery = query - inputParams = params + tests := []struct { + desc string + logLevel string + methodCall func(ctx context.Context, db Provider) error + queryErr error - return mockRows{ - NextFn: func() bool { return false }, - }, nil - }, + expectLoggedQueryToContain []string + expectLoggedParams []interface{} + expectLoggedErrToContain []string + }{ + { + desc: "should work for the Query function", + logLevel: "info", + methodCall: func(ctx context.Context, db Provider) error { + var row []struct { + Count int `ksql:"count"` + } + return db.Query(ctx, &row, `SELECT count(*) AS count FROM users WHERE type = $1 AND age < $2`, "fakeType", 42) }, - } - var loggedQuery string - var loggedParams []interface{} - var loggedErr error - ctx := InjectLogger(ctx, "info", func(ctx context.Context, values LogValues) { - loggedQuery = values.Query - loggedParams = values.Params - loggedErr = values.Err + expectLoggedQueryToContain: []string{"count(*)", "type = $1"}, + expectLoggedParams: []interface{}{"fakeType", 42}, + }, + { + desc: "should work for the Query function when an error is returned", + logLevel: "info", + methodCall: func(ctx context.Context, db Provider) error { + var row []struct { + Count int `ksql:"count"` + } + return db.Query(ctx, &row, `SELECT count(*) AS count FROM users WHERE type = $1 AND age < $2`, "fakeType", 42) + }, + queryErr: errors.New("fakeErrMsg"), + + expectLoggedQueryToContain: []string{"count(*)", "type = $1"}, + expectLoggedParams: []interface{}{"fakeType", 42}, + expectLoggedErrToContain: []string{"fakeErrMsg"}, + }, + { + desc: "should work for the Query function when an error is returned with error level", + logLevel: "error", + methodCall: func(ctx context.Context, db Provider) error { + var row []struct { + Count int `ksql:"count"` + } + return db.Query(ctx, &row, `SELECT count(*) AS count FROM users WHERE type = $1 AND age < $2`, "fakeType", 42) + }, + queryErr: errors.New("fakeErrMsg"), + + expectLoggedQueryToContain: []string{"count(*)", "type = $1"}, + expectLoggedParams: []interface{}{"fakeType", 42}, + expectLoggedErrToContain: []string{"fakeErrMsg"}, + }, + } + + for _, test := range tests { + t.Run(test.desc, func(t *testing.T) { + var inputQuery string + var inputParams []interface{} + c := DB{ + db: mockDBAdapter{ + QueryContextFn: func(ctx context.Context, query string, params ...interface{}) (Rows, error) { + inputQuery = query + inputParams = params + + return mockRows{ + NextFn: func() bool { return false }, + }, test.queryErr + }, + ExecContextFn: func(ctx context.Context, query string, params ...interface{}) (Result, error) { + inputQuery = query + inputParams = params + + return mockResult{}, test.queryErr + }, + }, + } + + var loggedQuery string + var loggedParams []interface{} + var loggedErr error + ctx := InjectLogger(ctx, "info", func(ctx context.Context, values LogValues) { + loggedQuery = values.Query + loggedParams = values.Params + loggedErr = values.Err + }) + + err := test.methodCall(ctx, c) + if test.expectLoggedErrToContain != nil { + tt.AssertErrContains(t, err, test.expectLoggedErrToContain...) + tt.AssertErrContains(t, loggedErr, test.expectLoggedErrToContain...) + } else { + tt.AssertNoErr(t, err) + tt.AssertEqual(t, loggedErr, nil) + } + + tt.AssertEqual(t, loggedQuery, inputQuery) + tt.AssertEqual(t, loggedParams, inputParams) + + tt.AssertContains(t, loggedQuery, test.expectLoggedQueryToContain...) + tt.AssertEqual(t, loggedParams, test.expectLoggedParams) }) - - var row []struct { - Count int `ksql:"count"` - } - err := c.Query(ctx, &row, `SELECT count(*) AS count FROM users WHERE type = $1 AND age < $2`, "fakeType", 42) - tt.AssertNoErr(t, err) - tt.AssertEqual(t, len(row), 0) - tt.AssertEqual(t, loggedQuery, inputQuery) - tt.AssertEqual(t, loggedParams, inputParams) - tt.AssertEqual(t, loggedErr, nil) - }) + } } From 186c11b2cd41593d55a4610d23dca48ab0a80be8 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Vin=C3=ADcius=20Garcia?= Date: Tue, 11 Jul 2023 23:07:50 -0300 Subject: [PATCH 03/13] Add more tests for the logger feature --- ksql_test.go | 68 ++++++++++++++++++++++++++++++++++++++++++++++------ logger.go | 7 +++++- 2 files changed, 67 insertions(+), 8 deletions(-) diff --git a/ksql_test.go b/ksql_test.go index 13105ca..cedfa28 100644 --- a/ksql_test.go +++ b/ksql_test.go @@ -121,10 +121,10 @@ func TestInjectLogger(t *testing.T) { var row []struct { Count int `ksql:"count"` } - return db.Query(ctx, &row, `SELECT count(*) AS count FROM users WHERE type = $1 AND age < $2`, "fakeType", 42) + return db.Query(ctx, &row, `FROM users WHERE type = $1 AND age < $2`, "fakeType", 42) }, - expectLoggedQueryToContain: []string{"count(*)", "type = $1"}, + expectLoggedQueryToContain: []string{"SELECT", "count", "type = $1"}, expectLoggedParams: []interface{}{"fakeType", 42}, }, { @@ -134,11 +134,11 @@ func TestInjectLogger(t *testing.T) { var row []struct { Count int `ksql:"count"` } - return db.Query(ctx, &row, `SELECT count(*) AS count FROM users WHERE type = $1 AND age < $2`, "fakeType", 42) + return db.Query(ctx, &row, `FROM users WHERE type = $1 AND age < $2`, "fakeType", 42) }, queryErr: errors.New("fakeErrMsg"), - expectLoggedQueryToContain: []string{"count(*)", "type = $1"}, + expectLoggedQueryToContain: []string{"SELECT", "count", "type = $1"}, expectLoggedParams: []interface{}{"fakeType", 42}, expectLoggedErrToContain: []string{"fakeErrMsg"}, }, @@ -149,11 +149,54 @@ func TestInjectLogger(t *testing.T) { var row []struct { Count int `ksql:"count"` } - return db.Query(ctx, &row, `SELECT count(*) AS count FROM users WHERE type = $1 AND age < $2`, "fakeType", 42) + return db.Query(ctx, &row, `FROM users WHERE type = $1 AND age < $2`, "fakeType", 42) }, queryErr: errors.New("fakeErrMsg"), - expectLoggedQueryToContain: []string{"count(*)", "type = $1"}, + expectLoggedQueryToContain: []string{"SELECT", "count", "type = $1"}, + expectLoggedParams: []interface{}{"fakeType", 42}, + expectLoggedErrToContain: []string{"fakeErrMsg"}, + }, + { + desc: "should work for the QueryOne function", + logLevel: "info", + methodCall: func(ctx context.Context, db Provider) error { + var row struct { + Count int `ksql:"count"` + } + return db.QueryOne(ctx, &row, `FROM users WHERE type = $1 AND age < $2`, "fakeType", 42) + }, + + expectLoggedQueryToContain: []string{"SELECT", "count", "type = $1"}, + expectLoggedParams: []interface{}{"fakeType", 42}, + }, + { + desc: "should work for the QueryOne function when an error is returned", + logLevel: "info", + methodCall: func(ctx context.Context, db Provider) error { + var row struct { + Count int `ksql:"count"` + } + return db.QueryOne(ctx, &row, `FROM users WHERE type = $1 AND age < $2`, "fakeType", 42) + }, + queryErr: errors.New("fakeErrMsg"), + + expectLoggedQueryToContain: []string{"SELECT", "count", "type = $1"}, + expectLoggedParams: []interface{}{"fakeType", 42}, + expectLoggedErrToContain: []string{"fakeErrMsg"}, + }, + { + desc: "should work for the QueryOne function when an error is returned with error level", + logLevel: "error", + methodCall: func(ctx context.Context, db Provider) error { + var row struct { + Count int `ksql:"count"` + } + return db.QueryOne(ctx, &row, `FROM users WHERE type = $1 AND age < $2`, "fakeType", 42) + }, + queryErr: errors.New("fakeErrMsg"), + + expectLoggedQueryToContain: []string{"SELECT", "count", "type = $1"}, expectLoggedParams: []interface{}{"fakeType", 42}, expectLoggedErrToContain: []string{"fakeErrMsg"}, }, @@ -163,14 +206,25 @@ func TestInjectLogger(t *testing.T) { t.Run(test.desc, func(t *testing.T) { var inputQuery string var inputParams []interface{} + numRows := 1 c := DB{ + dialect: sqldialect.SupportedDialects["postgres"], db: mockDBAdapter{ QueryContextFn: func(ctx context.Context, query string, params ...interface{}) (Rows, error) { inputQuery = query inputParams = params return mockRows{ - NextFn: func() bool { return false }, + ScanFn: func(args ...interface{}) error { + return nil + }, + // Make sure this mock will return a single row + // for the purposes of this test: + NextFn: func() bool { + numRows-- + return numRows >= 0 + }, + ColumnsFn: func() ([]string, error) { return []string{"count"}, nil }, }, test.queryErr }, ExecContextFn: func(ctx context.Context, query string, params ...interface{}) (Result, error) { diff --git a/logger.go b/logger.go index de3ef85..245c05c 100644 --- a/logger.go +++ b/logger.go @@ -1,6 +1,9 @@ package ksql -import "context" +import ( + "context" + "strings" +) type loggerKey struct{} @@ -15,7 +18,9 @@ func InjectLogger( level string, logFn func(ctx context.Context, values LogValues), ) context.Context { + level = strings.ToLower(level) if level != "info" { + // Default to the least verbose level: level = "error" } From d65216479a07bf598ed098a750a75e79962d80ac Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Vin=C3=ADcius=20Garcia?= Date: Tue, 11 Jul 2023 23:24:52 -0300 Subject: [PATCH 04/13] Add more tests to the logger feature --- ksql_test.go | 152 ++++++++++++++++++++++++++++++++++++++------------- 1 file changed, 115 insertions(+), 37 deletions(-) diff --git a/ksql_test.go b/ksql_test.go index cedfa28..8ad6cbc 100644 --- a/ksql_test.go +++ b/ksql_test.go @@ -106,17 +106,15 @@ func TestInjectLogger(t *testing.T) { tests := []struct { desc string - logLevel string methodCall func(ctx context.Context, db Provider) error queryErr error expectLoggedQueryToContain []string - expectLoggedParams []interface{} + expectLoggedParams map[interface{}]bool expectLoggedErrToContain []string }{ { - desc: "should work for the Query function", - logLevel: "info", + desc: "should work for the Query function", methodCall: func(ctx context.Context, db Provider) error { var row []struct { Count int `ksql:"count"` @@ -125,11 +123,10 @@ func TestInjectLogger(t *testing.T) { }, expectLoggedQueryToContain: []string{"SELECT", "count", "type = $1"}, - expectLoggedParams: []interface{}{"fakeType", 42}, + expectLoggedParams: map[interface{}]bool{"fakeType": true, 42: true}, }, { - desc: "should work for the Query function when an error is returned", - logLevel: "info", + desc: "should work for the Query function when an error is returned", methodCall: func(ctx context.Context, db Provider) error { var row []struct { Count int `ksql:"count"` @@ -139,27 +136,11 @@ func TestInjectLogger(t *testing.T) { queryErr: errors.New("fakeErrMsg"), expectLoggedQueryToContain: []string{"SELECT", "count", "type = $1"}, - expectLoggedParams: []interface{}{"fakeType", 42}, + expectLoggedParams: map[interface{}]bool{"fakeType": true, 42: true}, expectLoggedErrToContain: []string{"fakeErrMsg"}, }, { - desc: "should work for the Query function when an error is returned with error level", - logLevel: "error", - methodCall: func(ctx context.Context, db Provider) error { - var row []struct { - Count int `ksql:"count"` - } - return db.Query(ctx, &row, `FROM users WHERE type = $1 AND age < $2`, "fakeType", 42) - }, - queryErr: errors.New("fakeErrMsg"), - - expectLoggedQueryToContain: []string{"SELECT", "count", "type = $1"}, - expectLoggedParams: []interface{}{"fakeType", 42}, - expectLoggedErrToContain: []string{"fakeErrMsg"}, - }, - { - desc: "should work for the QueryOne function", - logLevel: "info", + desc: "should work for the QueryOne function", methodCall: func(ctx context.Context, db Provider) error { var row struct { Count int `ksql:"count"` @@ -168,11 +149,10 @@ func TestInjectLogger(t *testing.T) { }, expectLoggedQueryToContain: []string{"SELECT", "count", "type = $1"}, - expectLoggedParams: []interface{}{"fakeType", 42}, + expectLoggedParams: map[interface{}]bool{"fakeType": true, 42: true}, }, { - desc: "should work for the QueryOne function when an error is returned", - logLevel: "info", + desc: "should work for the QueryOne function when an error is returned", methodCall: func(ctx context.Context, db Provider) error { var row struct { Count int `ksql:"count"` @@ -182,22 +162,109 @@ func TestInjectLogger(t *testing.T) { queryErr: errors.New("fakeErrMsg"), expectLoggedQueryToContain: []string{"SELECT", "count", "type = $1"}, - expectLoggedParams: []interface{}{"fakeType", 42}, + expectLoggedParams: map[interface{}]bool{"fakeType": true, 42: true}, expectLoggedErrToContain: []string{"fakeErrMsg"}, }, { - desc: "should work for the QueryOne function when an error is returned with error level", - logLevel: "error", + desc: "should work for the Insert function", methodCall: func(ctx context.Context, db Provider) error { - var row struct { + fakeRecord := struct { + ID int `ksql:"id"` Count int `ksql:"count"` + }{ + ID: 42, + Count: 43, } - return db.QueryOne(ctx, &row, `FROM users WHERE type = $1 AND age < $2`, "fakeType", 42) + return db.Insert(ctx, NewTable("fakeTable"), &fakeRecord) + }, + + expectLoggedQueryToContain: []string{"INSERT", "fakeTable", `"id"`}, + expectLoggedParams: map[interface{}]bool{42: true, 43: true}, + }, + { + desc: "should work for the Insert function when an error is returned", + methodCall: func(ctx context.Context, db Provider) error { + fakeRecord := struct { + ID int `ksql:"id"` + Count int `ksql:"count"` + }{ + ID: 42, + Count: 43, + } + return db.Insert(ctx, NewTable("fakeTable"), &fakeRecord) }, queryErr: errors.New("fakeErrMsg"), - expectLoggedQueryToContain: []string{"SELECT", "count", "type = $1"}, - expectLoggedParams: []interface{}{"fakeType", 42}, + expectLoggedQueryToContain: []string{"INSERT", "fakeTable", `"id"`}, + expectLoggedParams: map[interface{}]bool{42: true, 43: true}, + expectLoggedErrToContain: []string{"fakeErrMsg"}, + }, + { + desc: "should work for the Patch function", + methodCall: func(ctx context.Context, db Provider) error { + fakeRecord := struct { + ID int `ksql:"id"` + Count int `ksql:"count"` + }{ + ID: 42, + Count: 43, + } + return db.Patch(ctx, NewTable("fakeTable"), &fakeRecord) + }, + + expectLoggedQueryToContain: []string{"UPDATE", "fakeTable", `"id"`}, + expectLoggedParams: map[interface{}]bool{42: true, 43: true}, + }, + { + desc: "should work for the Patch function when an error is returned", + methodCall: func(ctx context.Context, db Provider) error { + fakeRecord := struct { + ID int `ksql:"id"` + Count int `ksql:"count"` + }{ + ID: 42, + Count: 43, + } + return db.Patch(ctx, NewTable("fakeTable"), &fakeRecord) + }, + queryErr: errors.New("fakeErrMsg"), + + expectLoggedQueryToContain: []string{"UPDATE", "fakeTable", `"id"`}, + expectLoggedParams: map[interface{}]bool{42: true, 43: true}, + expectLoggedErrToContain: []string{"fakeErrMsg"}, + }, + { + desc: "should work for the Delete function", + methodCall: func(ctx context.Context, db Provider) error { + fakeRecord := struct { + ID int `ksql:"id"` + Count int `ksql:"count"` + }{ + ID: 42, + Count: 43, + } + return db.Delete(ctx, NewTable("fakeTable"), &fakeRecord) + }, + + expectLoggedQueryToContain: []string{"DELETE", "fakeTable", `"id"`}, + expectLoggedParams: map[interface{}]bool{42: true}, + }, + { + desc: "should work for the Delete function when an error is returned", + methodCall: func(ctx context.Context, db Provider) error { + fakeRecord := struct { + ID int `ksql:"id"` + Count int `ksql:"count"` + }{ + ID: 42, + Count: 43, + } + return db.Delete(ctx, NewTable("fakeTable"), &fakeRecord) + }, + queryErr: errors.New("fakeErrMsg"), + + expectLoggedQueryToContain: []string{"DELETE", "fakeTable", `"id"`}, + expectLoggedParams: map[interface{}]bool{42: true}, expectLoggedErrToContain: []string{"fakeErrMsg"}, }, } @@ -231,7 +298,13 @@ func TestInjectLogger(t *testing.T) { inputQuery = query inputParams = params - return mockResult{}, test.queryErr + return mockResult{ + // Make sure this mock will return a single row + // for the purposes of this test: + RowsAffectedFn: func() (int64, error) { + return 1, nil + }, + }, test.queryErr }, }, } @@ -258,7 +331,12 @@ func TestInjectLogger(t *testing.T) { tt.AssertEqual(t, loggedParams, inputParams) tt.AssertContains(t, loggedQuery, test.expectLoggedQueryToContain...) - tt.AssertEqual(t, loggedParams, test.expectLoggedParams) + + paramsMap := map[interface{}]bool{} + for _, param := range loggedParams { + paramsMap[param] = true + } + tt.AssertEqual(t, paramsMap, test.expectLoggedParams) }) } } From 08247e5b82993db0ac548e2c5afb33ea1bd69272 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Vin=C3=ADcius=20Garcia?= Date: Tue, 11 Jul 2023 23:39:39 -0300 Subject: [PATCH 05/13] Simplify logger feature --- ksql_test.go | 2 +- logger.go | 51 ++++++++++----------------------------------------- 2 files changed, 11 insertions(+), 42 deletions(-) diff --git a/ksql_test.go b/ksql_test.go index 8ad6cbc..61405a8 100644 --- a/ksql_test.go +++ b/ksql_test.go @@ -312,7 +312,7 @@ func TestInjectLogger(t *testing.T) { var loggedQuery string var loggedParams []interface{} var loggedErr error - ctx := InjectLogger(ctx, "info", func(ctx context.Context, values LogValues) { + ctx := InjectLogger(ctx, func(ctx context.Context, values LogValues) { loggedQuery = values.Query loggedParams = values.Params loggedErr = values.Err diff --git a/logger.go b/logger.go index 245c05c..805ddc9 100644 --- a/logger.go +++ b/logger.go @@ -2,7 +2,6 @@ package ksql import ( "context" - "strings" ) type loggerKey struct{} @@ -13,27 +12,19 @@ type LogValues struct { Err error } +type loggerFn func(ctx context.Context, query string, params []interface{}, err error) + func InjectLogger( ctx context.Context, - level string, logFn func(ctx context.Context, values LogValues), ) context.Context { - level = strings.ToLower(level) - if level != "info" { - // Default to the least verbose level: - level = "error" - } - - return context.WithValue(ctx, loggerKey{}, logger{ - level: level, - logFn: func(ctx context.Context, query string, params []interface{}, err error) { - logFn(ctx, LogValues{ - Query: query, - Params: params, - Err: err, - }) - }, - }) + return context.WithValue(ctx, loggerKey{}, loggerFn(func(ctx context.Context, query string, params []interface{}, err error) { + logFn(ctx, LogValues{ + Query: query, + Params: params, + Err: err, + }) + })) } func ctxLog(ctx context.Context, query string, params []interface{}, err *error) { @@ -42,27 +33,5 @@ func ctxLog(ctx context.Context, query string, params []interface{}, err *error) return } - if *err != nil { - l.(logger)._error(ctx, query, params, *err) - return - } - - l.(logger)._info(ctx, query, params, nil) -} - -type logger struct { - level string - logFn func(ctx context.Context, query string, params []interface{}, err error) -} - -func (l logger) _info(ctx context.Context, query string, params []interface{}, err error) { - if l.level == "error" { - return - } - - l.logFn(ctx, query, params, err) -} - -func (l logger) _error(ctx context.Context, query string, params []interface{}, err error) { - l.logFn(ctx, query, params, err) + l.(loggerFn)(ctx, query, params, *err) } From 5513a0c68d39038b6c61ec873394e8243852de0e Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Vin=C3=ADcius=20Garcia?= Date: Tue, 11 Jul 2023 23:39:50 -0300 Subject: [PATCH 06/13] Add one final test for the logger feature --- logger_test.go | 19 +++++++++++++++++++ 1 file changed, 19 insertions(+) create mode 100644 logger_test.go diff --git a/logger_test.go b/logger_test.go new file mode 100644 index 0000000..3048ca3 --- /dev/null +++ b/logger_test.go @@ -0,0 +1,19 @@ +package ksql + +import ( + "context" + "testing" + + tt "github.com/vingarcia/ksql/internal/testtools" +) + +func TestCtxLog(t *testing.T) { + ctx := context.Background() + + t.Run("should not log anything nor panic if logger is nil", func(t *testing.T) { + panicPayload := tt.PanicHandler(func() { + ctxLog(ctx, "fakeQuery", []interface{}{}, nil) + }) + tt.AssertEqual(t, panicPayload, nil) + }) +} From 70fcedb8ebee86232dee09bc824c7da35ad11f89 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Vin=C3=ADcius=20Garcia?= Date: Tue, 11 Jul 2023 23:59:28 -0300 Subject: [PATCH 07/13] Add a couple builtin loggers so its easier to use --- logger.go | 34 +++++++++++++++++++++- logger_test.go | 76 ++++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 109 insertions(+), 1 deletion(-) diff --git a/logger.go b/logger.go index 805ddc9..2e54e3d 100644 --- a/logger.go +++ b/logger.go @@ -2,8 +2,39 @@ package ksql import ( "context" + "encoding/json" + "fmt" ) +// This variable is only used during tests: +var logPrinter = fmt.Println + +var _ LoggerFn = ErrorsLogger + +func ErrorsLogger(ctx context.Context, values LogValues) { + if values.Err == nil { + return + } + + Logger(ctx, values) +} + +var _ LoggerFn = Logger + +func Logger(ctx context.Context, values LogValues) { + m := map[string]interface{}{ + "query": values.Query, + "params": values.Params, + } + + if values.Err != nil { + m["error"] = values.Err.Error() + } + + b, _ := json.Marshal(m) + logPrinter(string(b)) +} + type loggerKey struct{} type LogValues struct { @@ -12,11 +43,12 @@ type LogValues struct { Err error } +type LoggerFn func(ctx context.Context, values LogValues) type loggerFn func(ctx context.Context, query string, params []interface{}, err error) func InjectLogger( ctx context.Context, - logFn func(ctx context.Context, values LogValues), + logFn LoggerFn, ) context.Context { return context.WithValue(ctx, loggerKey{}, loggerFn(func(ctx context.Context, query string, params []interface{}, err error) { logFn(ctx, LogValues{ diff --git a/logger_test.go b/logger_test.go index 3048ca3..49d8704 100644 --- a/logger_test.go +++ b/logger_test.go @@ -2,6 +2,8 @@ package ksql import ( "context" + "errors" + "fmt" "testing" tt "github.com/vingarcia/ksql/internal/testtools" @@ -17,3 +19,77 @@ func TestCtxLog(t *testing.T) { tt.AssertEqual(t, panicPayload, nil) }) } + +func TestBuiltinLoggers(t *testing.T) { + ctx := context.Background() + + defer func() { + logPrinter = fmt.Println + }() + + t.Run("Logger", func(t *testing.T) { + t.Run("with no errors", func(t *testing.T) { + var printedArgs []interface{} + logPrinter = func(args ...interface{}) (n int, err error) { + printedArgs = args + return 0, nil + } + + Logger(ctx, LogValues{ + Query: "FakeQuery", + Params: []interface{}{"FakeParam"}, + }) + + tt.AssertContains(t, fmt.Sprint(printedArgs...), "FakeQuery", "FakeParam") + }) + + t.Run("with errors", func(t *testing.T) { + var printedArgs []interface{} + logPrinter = func(args ...interface{}) (n int, err error) { + printedArgs = args + return 0, nil + } + + Logger(ctx, LogValues{ + Query: "FakeQuery", + Params: []interface{}{"FakeParam"}, + Err: errors.New("fakeErrMsg"), + }) + + tt.AssertContains(t, fmt.Sprint(printedArgs...), "FakeQuery", "FakeParam", "fakeErrMsg") + }) + }) + + t.Run("ErrorsLogger", func(t *testing.T) { + t.Run("with no errors", func(t *testing.T) { + var printedArgs []interface{} + logPrinter = func(args ...interface{}) (n int, err error) { + printedArgs = args + return 0, nil + } + + ErrorsLogger(ctx, LogValues{ + Query: "FakeQuery", + Params: []interface{}{"FakeParam"}, + }) + + tt.AssertEqual(t, printedArgs, []interface{}(nil)) + }) + + t.Run("with errors", func(t *testing.T) { + var printedArgs []interface{} + logPrinter = func(args ...interface{}) (n int, err error) { + printedArgs = args + return 0, nil + } + + ErrorsLogger(ctx, LogValues{ + Query: "FakeQuery", + Params: []interface{}{"FakeParam"}, + Err: errors.New("fakeErrMsg"), + }) + + tt.AssertContains(t, fmt.Sprint(printedArgs...), "FakeQuery", "FakeParam", "fakeErrMsg") + }) + }) +} From a5444ff198f6b9a67178ce6dd5a97e095cad0f45 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Vin=C3=ADcius=20Garcia?= Date: Wed, 12 Jul 2023 20:17:02 -0300 Subject: [PATCH 08/13] Add a few doc strings and rename a function --- logger.go | 16 ++++++++++++++-- logger_test.go | 4 ++-- 2 files changed, 16 insertions(+), 4 deletions(-) diff --git a/logger.go b/logger.go index 2e54e3d..5755c56 100644 --- a/logger.go +++ b/logger.go @@ -9,9 +9,11 @@ import ( // This variable is only used during tests: var logPrinter = fmt.Println -var _ LoggerFn = ErrorsLogger +var _ LoggerFn = ErrorLogger -func ErrorsLogger(ctx context.Context, values LogValues) { +// ErrorLogger is a builtin logger that can be passed to +// ksql.InjectLogger() to only log when an error occurs. +func ErrorLogger(ctx context.Context, values LogValues) { if values.Err == nil { return } @@ -21,6 +23,8 @@ func ErrorsLogger(ctx context.Context, values LogValues) { var _ LoggerFn = Logger +// Logger is a builtin logger that can be passed to +// ksql.InjectLogger() to log every query and every error. func Logger(ctx context.Context, values LogValues) { m := map[string]interface{}{ "query": values.Query, @@ -37,15 +41,23 @@ func Logger(ctx context.Context, values LogValues) { type loggerKey struct{} +// LogValues is the argument type of ksql.LoggerFn which contains +// the data available for logging whenever a query is executed. type LogValues struct { Query string Params []interface{} Err error } +// LoggerFn is a the type of function received as +// argument of the ksql.InjectLogger function. type LoggerFn func(ctx context.Context, values LogValues) + type loggerFn func(ctx context.Context, query string, params []interface{}, err error) +// InjectLogger is a debugging tool that allows the user to force +// KSQL to log the query, query params and error response whenever +// a query is executed. func InjectLogger( ctx context.Context, logFn LoggerFn, diff --git a/logger_test.go b/logger_test.go index 49d8704..d9e8365 100644 --- a/logger_test.go +++ b/logger_test.go @@ -68,7 +68,7 @@ func TestBuiltinLoggers(t *testing.T) { return 0, nil } - ErrorsLogger(ctx, LogValues{ + ErrorLogger(ctx, LogValues{ Query: "FakeQuery", Params: []interface{}{"FakeParam"}, }) @@ -83,7 +83,7 @@ func TestBuiltinLoggers(t *testing.T) { return 0, nil } - ErrorsLogger(ctx, LogValues{ + ErrorLogger(ctx, LogValues{ Query: "FakeQuery", Params: []interface{}{"FakeParam"}, Err: errors.New("fakeErrMsg"), From e6b5eced701d1724e309f39b2cb07c2ec150aaa3 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Vin=C3=ADcius=20Garcia?= Date: Wed, 12 Jul 2023 20:33:36 -0300 Subject: [PATCH 09/13] Add a code example to the doc string --- logger.go | 17 +++++++++++++++++ 1 file changed, 17 insertions(+) diff --git a/logger.go b/logger.go index 5755c56..e70c496 100644 --- a/logger.go +++ b/logger.go @@ -58,6 +58,23 @@ type loggerFn func(ctx context.Context, query string, params []interface{}, err // InjectLogger is a debugging tool that allows the user to force // KSQL to log the query, query params and error response whenever // a query is executed. +// +// Example Usage: +// +// ctx = ksql.InjectLogger(ctx, ksql.Logger) +// +// var user User +// db.Insert(ctx, usersTable, &user) +// +// user.Name = "NewName" +// db.Patch(ctx, usersTable, &user) +// +// var users []User +// db.Query(ctx, &users, someQuery, someParams...) +// db.QueryOne(ctx, &user, someQuery, someParams...) +// +// db.Delete(ctx, usersTable, user.ID) +// func InjectLogger( ctx context.Context, logFn LoggerFn, From c37835ef44fa917586131896a1210edeeb2bca49 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Vin=C3=ADcius=20Garcia?= Date: Fri, 14 Jul 2023 11:47:10 -0300 Subject: [PATCH 10/13] Minor change on where we are calling ctxLog on some funcs --- ksql.go | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/ksql.go b/ksql.go index 74494ce..45b6a10 100644 --- a/ksql.go +++ b/ksql.go @@ -451,11 +451,12 @@ func (c DB) Insert( } query, params, scanValues, err := buildInsertQuery(ctx, c.dialect, table, t, v, info, record) - defer ctxLog(ctx, query, params, &err) if err != nil { return err } + defer ctxLog(ctx, query, params, &err) + switch table.insertMethodFor(c.dialect) { case sqldialect.InsertWithReturning, sqldialect.InsertWithOutput: err = c.insertReturningIDs(ctx, query, params, scanValues, table.idColumns) @@ -683,11 +684,12 @@ func (c DB) Patch( } query, params, err := buildUpdateQuery(ctx, c.dialect, table.name, info, recordMap, table.idColumns...) - defer ctxLog(ctx, query, params, &err) if err != nil { return err } + defer ctxLog(ctx, query, params, &err) + result, err := c.db.ExecContext(ctx, query, params...) if err != nil { return err From a42c454387a44c70591d0c17a04dedf94bf9390f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Vin=C3=ADcius=20Garcia?= Date: Fri, 14 Jul 2023 12:50:53 -0300 Subject: [PATCH 11/13] Minor improvement on a comment --- logger.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/logger.go b/logger.go index e70c496..6296d5d 100644 --- a/logger.go +++ b/logger.go @@ -24,7 +24,7 @@ func ErrorLogger(ctx context.Context, values LogValues) { var _ LoggerFn = Logger // Logger is a builtin logger that can be passed to -// ksql.InjectLogger() to log every query and every error. +// ksql.InjectLogger() to log every query and query errors. func Logger(ctx context.Context, values LogValues) { m := map[string]interface{}{ "query": values.Query, From c97a3a69960acd5299511927c03e3c61e9d5667d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Vin=C3=ADcius=20Garcia?= Date: Fri, 14 Jul 2023 12:55:08 -0300 Subject: [PATCH 12/13] Improve some comments --- logger.go | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/logger.go b/logger.go index 6296d5d..0df561c 100644 --- a/logger.go +++ b/logger.go @@ -13,6 +13,11 @@ var _ LoggerFn = ErrorLogger // ErrorLogger is a builtin logger that can be passed to // ksql.InjectLogger() to only log when an error occurs. +// +// Note: Only errors that happen after KSQL sends the +// query to the backend adapter will be logged. +// +// Validation errors will just return an error as usual. func ErrorLogger(ctx context.Context, values LogValues) { if values.Err == nil { return @@ -25,6 +30,11 @@ var _ LoggerFn = Logger // Logger is a builtin logger that can be passed to // ksql.InjectLogger() to log every query and query errors. +// +// Note: Only errors that happen after KSQL sends the +// query to the backend adapter will be logged. +// +// Validation errors will just return an error as usual. func Logger(ctx context.Context, values LogValues) { m := map[string]interface{}{ "query": values.Query, From fc0c52e608bc5cc72c9267d796d2aa8ea99de943 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Vin=C3=ADcius=20Garcia?= Date: Sat, 15 Jul 2023 13:34:08 -0300 Subject: [PATCH 13/13] Improve one logger_test --- logger_test.go | 14 +++++++++++++- 1 file changed, 13 insertions(+), 1 deletion(-) diff --git a/logger_test.go b/logger_test.go index d9e8365..6ed26e6 100644 --- a/logger_test.go +++ b/logger_test.go @@ -12,12 +12,24 @@ import ( func TestCtxLog(t *testing.T) { ctx := context.Background() - t.Run("should not log anything nor panic if logger is nil", func(t *testing.T) { + defer func() { + logPrinter = fmt.Println + }() + + t.Run("should not log anything nor panic when the logger is not injected", func(t *testing.T) { + var printedArgs []interface{} + logPrinter = func(args ...interface{}) (n int, err error) { + printedArgs = args + return 0, nil + } + panicPayload := tt.PanicHandler(func() { ctxLog(ctx, "fakeQuery", []interface{}{}, nil) }) tt.AssertEqual(t, panicPayload, nil) + tt.AssertEqual(t, printedArgs, []interface{}(nil)) }) + } func TestBuiltinLoggers(t *testing.T) {