Skip to content

Commit 3630c51

Browse files
feat: Add structured logging with log/slog for observability (#47)
Implements comprehensive structured logging using Go's standard log/slog package (Go 1.21+). Logging is optional with zero overhead when disabled. ## Changes ### Core Infrastructure - Added WithLogger() functional option to Convert() - Default behavior uses slog.DiscardHandler (zero overhead) - Added logger field to converter struct - Performance metrics with conversion duration tracking ### Logging Points Added 1. **JSON Path Detection** (json.go) - shouldUseJSONPath: Logs table, field, and JSON detection results - buildJSONPath: Logs JSON path construction - buildJSONPathInternal: Logs operator selection (->>, ->) 2. **Comprehension Analysis** (comprehensions.go) - analyzeComprehensionPattern: Logs identified comprehension type - Logs for all, exists, exists_one, map, filter comprehensions - Includes iter_var, accu_var, and has_filter details 3. **Schema Lookups** (cel2sql.go) - isFieldJSON: Logs field type lookups with hits/misses - Logs when schemas not provided or table/field not found 4. **Operator Conversion** (cel2sql.go) - visitCallBinary: Logs CEL to SQL operator mapping 5. **Regex Conversion** (cel2sql.go) - callMatches: Logs RE2 to POSIX pattern transformation - Includes original pattern, converted pattern, case sensitivity 6. **Conversion Lifecycle** (cel2sql.go) - Start/completion events with duration metrics - Error logging with full context ### Testing - Added 11 comprehensive tests in logging_test.go - Tests cover JSON handler, text handler, all logging points - Verifies zero overhead default behavior - All existing tests pass ### Documentation - Updated CLAUDE.md with logging section - Added examples/logging/ with working example - Demonstrates both JSON and text handlers - README with integration guidance ### Example Usage ```go // Zero overhead (default) sql, err := cel2sql.Convert(ast) // With logging enabled logger := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{ Level: slog.LevelDebug, })) sql, err := cel2sql.Convert(ast, cel2sql.WithSchemas(schemas), cel2sql.WithLogger(logger)) ``` ## Benefits - **Zero Overhead**: DiscardHandler when logging disabled - **Standards-Based**: Uses Go 1.21+ standard library - **Structured**: All logs use key-value pairs - **Flexible**: Supports any slog.Handler - **Production-Ready**: JSON handler for log aggregation - **Developer-Friendly**: Text handler for debugging ## Log Events - JSON path detection decisions - Comprehension type identification - Schema lookups (hits/misses, field types) - Performance metrics - Regex pattern transformations - Operator mapping decisions - Error contexts with full details Closes #47 🤖 Generated with [Claude Code](https://claude.com/claude-code) Co-Authored-By: Claude <noreply@anthropic.com>
1 parent 198d97f commit 3630c51

File tree

7 files changed

+741
-7
lines changed

7 files changed

+741
-7
lines changed

CLAUDE.md

Lines changed: 58 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -175,6 +175,64 @@ sqlCondition, err := cel2sql.Convert(ast)
175175
// Returns: table.field = 'value' AND table.age > 30
176176
```
177177

178+
### Logging and Observability
179+
180+
cel2sql supports structured logging using Go's standard `log/slog` package (Go 1.21+).
181+
182+
Logging is optional and has **zero overhead** when not enabled (uses `slog.DiscardHandler` by default).
183+
184+
#### Enable Logging
185+
186+
```go
187+
import "log/slog"
188+
189+
// JSON handler for production/machine parsing
190+
logger := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
191+
Level: slog.LevelDebug,
192+
}))
193+
194+
// Text handler for development/debugging
195+
logger := slog.New(slog.NewTextHandler(os.Stderr, nil))
196+
197+
sql, err := cel2sql.Convert(ast,
198+
cel2sql.WithSchemas(schemas),
199+
cel2sql.WithLogger(logger))
200+
```
201+
202+
#### What Gets Logged
203+
204+
- **JSON path detection decisions** - Table, field, operator selection (->>, ?)
205+
- **Comprehension type identification** - all, exists, exists_one, filter, map
206+
- **Schema lookups** - Hits/misses, field type detection
207+
- **Performance metrics** - Conversion duration
208+
- **Regex pattern transformations** - RE2 to POSIX conversion
209+
- **Operator mapping decisions** - CEL to SQL operator conversion
210+
- **Error contexts** - Full details when conversions fail
211+
212+
#### Log Levels
213+
214+
- **Debug**: Detailed conversion steps, operator mappings, schema lookups
215+
- **Error**: Conversion failures with full context
216+
217+
#### Example Usage
218+
219+
```go
220+
// Without logger - zero overhead (default)
221+
sql, err := cel2sql.Convert(ast)
222+
223+
// With logging - detailed observability
224+
logger := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
225+
Level: slog.LevelDebug,
226+
}))
227+
228+
sql, err := cel2sql.Convert(ast,
229+
cel2sql.WithSchemas(schemas),
230+
cel2sql.WithContext(ctx),
231+
cel2sql.WithLogger(logger))
232+
```
233+
234+
See `examples/logging/` for a complete working example with both JSON and text handlers.
235+
178236
## Important Notes
179237

180238
### Migration Context

cel2sql.go

Lines changed: 82 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -5,9 +5,11 @@ import (
55
"context"
66
"errors"
77
"fmt"
8+
"log/slog"
89
"regexp"
910
"strconv"
1011
"strings"
12+
"time"
1113

1214
"github.com/google/cel-go/cel"
1315
"github.com/google/cel-go/common/operators"
@@ -42,6 +44,7 @@ type ConvertOption func(*convertOptions)
4244
type convertOptions struct {
4345
schemas map[string]pg.Schema
4446
ctx context.Context
47+
logger *slog.Logger
4548
}
4649

4750
// WithSchemas provides schema information for proper JSON/JSONB field handling.
@@ -78,6 +81,33 @@ func WithContext(ctx context.Context) ConvertOption {
7881
}
7982
}
8083

84+
// WithLogger provides a logger for observability and debugging.
85+
// If not provided, logging is disabled with zero overhead using slog.DiscardHandler.
86+
//
87+
// The logger enables visibility into:
88+
// - JSON path detection decisions (table, field, operator selection)
89+
// - Comprehension type identification (all, exists, filter, map)
90+
// - Schema lookups (hits/misses, field types)
91+
// - Performance metrics (conversion duration)
92+
// - Regex pattern transformations (RE2 to POSIX)
93+
// - Operator mapping decisions
94+
// - Error contexts with full details
95+
//
96+
// Example with JSON output:
97+
//
98+
// logger := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{Level: slog.LevelDebug}))
99+
// sql, err := cel2sql.Convert(ast, cel2sql.WithLogger(logger))
100+
//
101+
// Example with text output:
102+
//
103+
// logger := slog.New(slog.NewTextHandler(os.Stderr, nil))
104+
// sql, err := cel2sql.Convert(ast, cel2sql.WithSchemas(schemas), cel2sql.WithLogger(logger))
105+
func WithLogger(logger *slog.Logger) ConvertOption {
106+
return func(o *convertOptions) {
107+
o.logger = logger
108+
}
109+
}
110+
81111
// Convert converts a CEL AST to a PostgreSQL SQL WHERE clause condition.
82112
// Options can be provided to configure the conversion behavior.
83113
//
@@ -89,31 +119,53 @@ func WithContext(ctx context.Context) ConvertOption {
89119
//
90120
// sql, err := cel2sql.Convert(ast, cel2sql.WithSchemas(schemas))
91121
func Convert(ast *cel.Ast, opts ...ConvertOption) (string, error) {
92-
options := &convertOptions{}
122+
start := time.Now()
123+
124+
options := &convertOptions{
125+
logger: slog.New(slog.DiscardHandler), // Default: no-op logger with zero overhead
126+
}
93127
for _, opt := range opts {
94128
opt(options)
95129
}
96130

131+
options.logger.Debug("starting CEL to SQL conversion")
132+
97133
checkedExpr, err := cel.AstToCheckedExpr(ast)
98134
if err != nil {
135+
options.logger.Error("AST to CheckedExpr conversion failed", slog.Any("error", err))
99136
return "", err
100137
}
138+
101139
un := &converter{
102140
typeMap: checkedExpr.TypeMap,
103141
schemas: options.schemas,
104142
ctx: options.ctx,
143+
logger: options.logger,
105144
}
145+
106146
if err := un.visit(checkedExpr.Expr); err != nil {
147+
options.logger.Error("conversion failed", slog.Any("error", err))
107148
return "", err
108149
}
109-
return un.str.String(), nil
150+
151+
result := un.str.String()
152+
duration := time.Since(start)
153+
154+
options.logger.LogAttrs(context.Background(), slog.LevelDebug,
155+
"conversion completed",
156+
slog.String("sql", result),
157+
slog.Duration("duration", duration),
158+
)
159+
160+
return result, nil
110161
}
111162

112163
type converter struct {
113164
str strings.Builder
114165
typeMap map[int64]*exprpb.Type
115166
schemas map[string]pg.Schema
116167
ctx context.Context
168+
logger *slog.Logger
117169
}
118170

119171
// checkContext checks if the context has been cancelled or expired.
@@ -158,20 +210,31 @@ func (con *converter) visit(expr *exprpb.Expr) error {
158210
// isFieldJSON checks if a field in a table is a JSON/JSONB type using schema information
159211
func (con *converter) isFieldJSON(tableName, fieldName string) bool {
160212
if con.schemas == nil {
213+
con.logger.Debug("no schemas provided for JSON detection")
161214
return false
162215
}
163216

164217
schema, ok := con.schemas[tableName]
165218
if !ok {
219+
con.logger.Debug("schema not found for table", slog.String("table", tableName))
166220
return false
167221
}
168222

169223
for _, field := range schema {
170224
if field.Name == fieldName {
225+
con.logger.LogAttrs(context.Background(), slog.LevelDebug,
226+
"field type lookup",
227+
slog.String("table", tableName),
228+
slog.String("field", fieldName),
229+
slog.Bool("is_json", field.IsJSON),
230+
)
171231
return field.IsJSON
172232
}
173233
}
174234

235+
con.logger.Debug("field not found in schema",
236+
slog.String("table", tableName),
237+
slog.String("field", fieldName))
175238
return false
176239
}
177240

@@ -359,6 +422,13 @@ func (con *converter) visitCallBinary(expr *exprpb.Expr) error {
359422
} else {
360423
return fmt.Errorf("cannot unmangle operator: %s", fun)
361424
}
425+
426+
con.logger.LogAttrs(context.Background(), slog.LevelDebug,
427+
"binary operator conversion",
428+
slog.String("cel_op", fun),
429+
slog.String("sql_op", operator),
430+
)
431+
362432
con.str.WriteString(" ")
363433
con.str.WriteString(operator)
364434
con.str.WriteString(" ")
@@ -623,6 +693,16 @@ func (con *converter) callMatches(target *exprpb.Expr, args []*exprpb.Expr) erro
623693
return fmt.Errorf("invalid regex pattern: %w", err)
624694
}
625695

696+
// Determine case sensitivity
697+
caseInsensitive := strings.HasPrefix(re2Pattern, "(?i)")
698+
699+
con.logger.LogAttrs(context.Background(), slog.LevelDebug,
700+
"regex pattern conversion",
701+
slog.String("original_pattern", re2Pattern),
702+
slog.String("converted_pattern", posixPattern),
703+
slog.Bool("case_insensitive", caseInsensitive),
704+
)
705+
626706
// Write the converted pattern as a string literal
627707
escaped := strings.ReplaceAll(posixPattern, "'", "''")
628708
con.str.WriteString("'")

comprehensions.go

Lines changed: 37 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,8 +1,10 @@
11
package cel2sql
22

33
import (
4+
"context"
45
"errors"
56
"fmt"
7+
"log/slog"
68

79
"github.com/google/cel-go/common/operators"
810
exprpb "google.golang.org/genproto/googleapis/api/expr/v1alpha1"
@@ -95,6 +97,12 @@ func (con *converter) analyzeComprehensionPattern(comp *exprpb.Expr_Comprehensio
9597
if con.isLogicalAndStep(comp.GetLoopStep(), comp.GetAccuVar()) {
9698
info.Type = ComprehensionAll
9799
info.Predicate = con.extractPredicateFromAndStep(comp.GetLoopStep(), comp.GetAccuVar())
100+
con.logger.LogAttrs(context.Background(), slog.LevelDebug,
101+
"comprehension identified",
102+
slog.String("type", info.Type.String()),
103+
slog.String("iter_var", info.IterVar),
104+
slog.String("accu_var", info.AccuVar),
105+
)
98106
return info, nil
99107
}
100108
}
@@ -104,6 +112,12 @@ func (con *converter) analyzeComprehensionPattern(comp *exprpb.Expr_Comprehensio
104112
if con.isLogicalOrStep(comp.GetLoopStep(), comp.GetAccuVar()) {
105113
info.Type = ComprehensionExists
106114
info.Predicate = con.extractPredicateFromOrStep(comp.GetLoopStep(), comp.GetAccuVar())
115+
con.logger.LogAttrs(context.Background(), slog.LevelDebug,
116+
"comprehension identified",
117+
slog.String("type", info.Type.String()),
118+
slog.String("iter_var", info.IterVar),
119+
slog.String("accu_var", info.AccuVar),
120+
)
107121
return info, nil
108122
}
109123
}
@@ -113,6 +127,12 @@ func (con *converter) analyzeComprehensionPattern(comp *exprpb.Expr_Comprehensio
113127
if con.isConditionalCountStep(comp.GetLoopStep(), comp.GetAccuVar()) && con.isEqualsOneResult(comp.GetResult(), comp.GetAccuVar()) {
114128
info.Type = ComprehensionExistsOne
115129
info.Predicate = con.extractPredicateFromConditionalStep(comp.GetLoopStep())
130+
con.logger.LogAttrs(context.Background(), slog.LevelDebug,
131+
"comprehension identified",
132+
slog.String("type", info.Type.String()),
133+
slog.String("iter_var", info.IterVar),
134+
slog.String("accu_var", info.AccuVar),
135+
)
116136
return info, nil
117137
}
118138
}
@@ -122,6 +142,12 @@ func (con *converter) analyzeComprehensionPattern(comp *exprpb.Expr_Comprehensio
122142
if con.isListAppendStep(comp.GetLoopStep(), comp.GetAccuVar()) {
123143
info.Type = ComprehensionMap
124144
info.Transform = con.extractTransformFromAppendStep(comp.GetLoopStep(), comp.GetAccuVar())
145+
con.logger.LogAttrs(context.Background(), slog.LevelDebug,
146+
"comprehension identified",
147+
slog.String("type", info.Type.String()),
148+
slog.String("iter_var", info.IterVar),
149+
slog.Bool("has_filter", false),
150+
)
125151
return info, nil
126152
}
127153
// Map with filter: step = conditional(filter, accu + [transform], accu)
@@ -131,6 +157,12 @@ func (con *converter) analyzeComprehensionPattern(comp *exprpb.Expr_Comprehensio
131157
filter, transform := con.extractFilterAndTransformFromConditionalStep(comp.GetLoopStep(), comp.GetAccuVar())
132158
info.Filter = filter
133159
info.Transform = transform
160+
con.logger.LogAttrs(context.Background(), slog.LevelDebug,
161+
"comprehension identified",
162+
slog.String("type", info.Type.String()),
163+
slog.String("iter_var", info.IterVar),
164+
slog.Bool("has_filter", true),
165+
)
134166
return info, nil
135167
}
136168
}
@@ -140,6 +172,11 @@ func (con *converter) analyzeComprehensionPattern(comp *exprpb.Expr_Comprehensio
140172
if con.isConditionalFilterStep(comp.GetLoopStep(), comp.GetAccuVar(), comp.GetIterVar()) {
141173
info.Type = ComprehensionFilter
142174
info.Predicate = con.extractPredicateFromConditionalStep(comp.GetLoopStep())
175+
con.logger.LogAttrs(context.Background(), slog.LevelDebug,
176+
"comprehension identified",
177+
slog.String("type", info.Type.String()),
178+
slog.String("iter_var", info.IterVar),
179+
)
143180
return info, nil
144181
}
145182
}

0 commit comments

Comments
 (0)