diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml new file mode 100644 index 0000000..f620bdf --- /dev/null +++ b/.github/workflows/ci.yml @@ -0,0 +1,93 @@ +name: CI + +on: + push: + branches: + - master + pull_request: + branches: + - master + +jobs: + test: + name: Test + runs-on: ubuntu-latest + permissions: + contents: read + strategy: + matrix: + go-version: ['1.23.0'] + + steps: + - name: Checkout code + uses: actions/checkout@v4 + + - name: Set up Go + uses: actions/setup-go@v5 + with: + go-version: ${{ matrix.go-version }} + + - name: Get dependencies + run: go mod download + + - name: Run tests + run: go test -v -race -coverprofile=coverage.out -covermode=atomic ./... + + - name: Upload coverage to Codecov + uses: codecov/codecov-action@v4 + with: + file: ./coverage.out + flags: unittests + name: codecov-umbrella + + build: + name: Build + runs-on: ubuntu-latest + permissions: + contents: read + strategy: + matrix: + go-version: ['1.23.0'] + + steps: + - name: Checkout code + uses: actions/checkout@v4 + + - name: Set up Go + uses: actions/setup-go@v5 + with: + go-version: ${{ matrix.go-version }} + + - name: Build + run: go build -v ./... + + release: + name: Release + runs-on: ubuntu-latest + permissions: + contents: write + issues: write + pull-requests: write + needs: [test, build] + if: github.event_name == 'push' && github.ref == 'refs/heads/master' + + steps: + - name: Checkout code + uses: actions/checkout@v4 + with: + fetch-depth: 0 + + - name: Set up Node.js + uses: actions/setup-node@v4 + with: + node-version: 'lts/*' + + - name: Install semantic-release + run: | + npm install -g semantic-release@24 \ + conventional-changelog-conventionalcommits@8 + + - name: Release + env: + GITHUB_TOKEN: ${{ secrets.GITHUB_TOKEN }} + run: npx semantic-release diff --git a/.releaserc.json b/.releaserc.json new file mode 100644 index 0000000..037377e --- /dev/null +++ b/.releaserc.json @@ -0,0 +1,37 @@ +{ + "branches": ["master"], + "plugins": [ + ["@semantic-release/commit-analyzer", { + "preset": "conventionalcommits", + "releaseRules": [ + {"type": "feat", "release": "minor"}, + {"type": "fix", "release": "patch"}, + {"type": "perf", "release": "patch"}, + {"type": "revert", "release": "patch"}, + {"type": "docs", "release": "patch"}, + {"type": "chore", "release": false}, + {"type": "refactor", "release": "patch"}, + {"type": "test", "release": false}, + {"type": "build", "release": false}, + {"type": "ci", "release": false} + ] + }], + ["@semantic-release/release-notes-generator", { + "preset": "conventionalcommits", + "presetConfig": { + "types": [ + {"type": "feat", "section": "Features"}, + {"type": "fix", "section": "Bug Fixes"}, + {"type": "perf", "section": "Performance Improvements"}, + {"type": "revert", "section": "Reverts"}, + {"type": "docs", "section": "Documentation"}, + {"type": "refactor", "section": "Code Refactoring"}, + {"type": "test", "section": "Tests", "hidden": true}, + {"type": "build", "section": "Build System", "hidden": true}, + {"type": "ci", "section": "CI", "hidden": true} + ] + } + }], + ["@semantic-release/github"] + ] +} diff --git a/README.md b/README.md index d56fd6a..0724bca 100644 --- a/README.md +++ b/README.md @@ -1 +1,216 @@ -# casbin-opentelemetry-logger \ No newline at end of file +# casbin-opentelemetry-logger + +[![Go Report Card](https://goreportcard.com/badge/github.com/casbin/casbin-opentelemetry-logger)](https://goreportcard.com/report/github.com/casbin/casbin-opentelemetry-logger) +[![Go](https://github.com/casbin/casbin-opentelemetry-logger/actions/workflows/ci.yml/badge.svg)](https://github.com/casbin/casbin-opentelemetry-logger/actions/workflows/ci.yml) +[![Coverage Status](https://codecov.io/gh/casbin/casbin-opentelemetry-logger/branch/master/graph/badge.svg)](https://codecov.io/gh/casbin/casbin-opentelemetry-logger) +[![GoDoc](https://godoc.org/github.com/casbin/casbin-opentelemetry-logger?status.svg)](https://godoc.org/github.com/casbin/casbin-opentelemetry-logger) +[![Release](https://img.shields.io/github/release/casbin/casbin-opentelemetry-logger.svg)](https://github.com/casbin/casbin-opentelemetry-logger/releases/latest) +[![Discord](https://img.shields.io/discord/1022748306096537660?logo=discord&label=discord&color=5865F2)](https://discord.gg/S5UjpzGZjN) + +An OpenTelemetry logger implementation for [Casbin](https://github.com/casbin/casbin), providing event-driven metrics collection for authorization events. + +## Features + +- **Event-Driven Logging**: Implements the Casbin Logger interface with support for event-driven logging +- **OpenTelemetry Metrics**: Exports comprehensive metrics using the OpenTelemetry standard +- **Customizable Event Types**: Filter which event types to log +- **Custom Callbacks**: Add custom processing for log entries +- **Context Support**: Support for custom contexts for propagation and cancellation + +## Metrics Exported + +### Enforce Metrics +- `casbin.enforce.total` - Total number of enforce requests (labeled by `allowed`, `domain`) +- `casbin.enforce.duration` - Duration of enforce requests in seconds (labeled by `allowed`, `domain`) + +### Policy Operation Metrics +- `casbin.policy.operations.total` - Total number of policy operations (labeled by `operation`, `success`) +- `casbin.policy.operations.duration` - Duration of policy operations in seconds (labeled by `operation`) +- `casbin.policy.rules.count` - Number of policy rules affected by operations (labeled by `operation`) + +## Installation + +```bash +go get github.com/casbin/casbin-opentelemetry-logger +``` + +## Usage + +### Basic Usage + +```go +package main + +import ( + "context" + + opentelemetrylogger "github.com/casbin/casbin-opentelemetry-logger" + "go.opentelemetry.io/otel" +) + +func main() { + // Get a meter from your OpenTelemetry provider + meter := otel.Meter("casbin") + + // Create logger + logger, err := opentelemetrylogger.NewOpenTelemetryLogger(meter) + if err != nil { + panic(err) + } + + // Use with Casbin + // enforcer.SetLogger(logger) +} +``` + +### With Custom Context + +```go +ctx := context.Background() +logger, err := opentelemetrylogger.NewOpenTelemetryLoggerWithContext(ctx, meter) +if err != nil { + panic(err) +} +``` + +### Configure Event Types + +```go +// Only log specific event types +logger.SetEventTypes([]opentelemetrylogger.EventType{ + opentelemetrylogger.EventEnforce, + opentelemetrylogger.EventAddPolicy, +}) +``` + +### Add Custom Callback + +```go +// Add custom processing for log entries +logger.SetLogCallback(func(entry *opentelemetrylogger.LogEntry) error { + fmt.Printf("Event: %s, Duration: %v\n", entry.EventType, entry.Duration) + return nil +}) +``` + +## Event Types + +The logger supports the following event types: + +- `EventEnforce` - Authorization enforcement requests +- `EventAddPolicy` - Policy addition operations +- `EventRemovePolicy` - Policy removal operations +- `EventLoadPolicy` - Policy loading operations +- `EventSavePolicy` - Policy saving operations + +## Complete Example with OTLP Exporter + +```go +package main + +import ( + "context" + "log" + "time" + + opentelemetrylogger "github.com/casbin/casbin-opentelemetry-logger" + "go.opentelemetry.io/otel" + "go.opentelemetry.io/otel/exporters/otlp/otlpmetric/otlpmetricgrpc" + "go.opentelemetry.io/otel/sdk/metric" + "go.opentelemetry.io/otel/sdk/resource" + semconv "go.opentelemetry.io/otel/semconv/v1.26.0" +) + +func main() { + ctx := context.Background() + + // Create OTLP exporter + exporter, err := otlpmetricgrpc.New(ctx, + otlpmetricgrpc.WithEndpoint("localhost:4317"), + otlpmetricgrpc.WithInsecure(), + ) + if err != nil { + log.Fatal(err) + } + + // Create resource + res, err := resource.New(ctx, + resource.WithAttributes( + semconv.ServiceName("casbin-app"), + ), + ) + if err != nil { + log.Fatal(err) + } + + // Create meter provider + provider := metric.NewMeterProvider( + metric.WithReader(metric.NewPeriodicReader(exporter)), + metric.WithResource(res), + ) + otel.SetMeterProvider(provider) + + // Create logger + meter := otel.Meter("casbin") + logger, err := opentelemetrylogger.NewOpenTelemetryLogger(meter) + if err != nil { + log.Fatal(err) + } + + // Use with Casbin enforcer + // enforcer.SetLogger(logger) + + // Shutdown + defer func() { + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + if err := provider.Shutdown(ctx); err != nil { + log.Printf("Error shutting down meter provider: %v", err) + } + }() +} +``` + +## OpenTelemetry Collector Configuration + +To collect metrics from your application, configure the OpenTelemetry Collector: + +```yaml +receivers: + otlp: + protocols: + grpc: + endpoint: 0.0.0.0:4317 + +exporters: + prometheus: + endpoint: "0.0.0.0:8889" + logging: + loglevel: debug + +service: + pipelines: + metrics: + receivers: [otlp] + exporters: [prometheus, logging] +``` + +## Visualization with Prometheus and Grafana + +1. **Configure OpenTelemetry Collector** to export metrics to Prometheus (see above) +2. **Configure Prometheus** to scrape the OpenTelemetry Collector endpoint +3. **Import Grafana Dashboard** using similar panels as the Prometheus logger project + +## License + +This project is licensed under the Apache 2.0 License - see the [LICENSE](LICENSE) file for details. + +## Contributing + +Contributions are welcome! Please feel free to submit a Pull Request. + +## Related Projects + +- [Casbin](https://github.com/casbin/casbin) - An authorization library that supports access control models +- [OpenTelemetry](https://opentelemetry.io/) - Observability framework for cloud-native software +- [casbin-prometheus-logger](https://github.com/casbin/casbin-prometheus-logger) - Prometheus logger for Casbin \ No newline at end of file diff --git a/go.mod b/go.mod new file mode 100644 index 0000000..83f10d5 --- /dev/null +++ b/go.mod @@ -0,0 +1,19 @@ +module github.com/casbin/casbin-opentelemetry-logger + +go 1.23.0 + +require ( + go.opentelemetry.io/otel v1.33.0 + go.opentelemetry.io/otel/metric v1.33.0 + go.opentelemetry.io/otel/sdk/metric v1.33.0 +) + +require ( + github.com/go-logr/logr v1.4.2 // indirect + github.com/go-logr/stdr v1.2.2 // indirect + github.com/google/uuid v1.6.0 // indirect + go.opentelemetry.io/auto/sdk v1.1.0 // indirect + go.opentelemetry.io/otel/sdk v1.33.0 // indirect + go.opentelemetry.io/otel/trace v1.33.0 // indirect + golang.org/x/sys v0.29.0 // indirect +) diff --git a/go.sum b/go.sum new file mode 100644 index 0000000..99d39cd --- /dev/null +++ b/go.sum @@ -0,0 +1,31 @@ +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/go-logr/logr v1.2.2/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A= +github.com/go-logr/logr v1.4.2 h1:6pFjapn8bFcIbiKo3XT4j/BhANplGihG6tvd+8rYgrY= +github.com/go-logr/logr v1.4.2/go.mod h1:9T104GzyrTigFIr8wt5mBrctHMim0Nb2HLGrmQ40KvY= +github.com/go-logr/stdr v1.2.2 h1:hSWxHoqTgW2S2qGc0LTAI563KZ5YKYRhT3MFKZMbjag= +github.com/go-logr/stdr v1.2.2/go.mod h1:mMo/vtBO5dYbehREoey6XUKy/eSumjCCveDpRre4VKE= +github.com/google/go-cmp v0.6.0 h1:ofyhxvXcZhMsU5ulbFiLKl/XBFqE1GSq7atu8tAmTRI= +github.com/google/go-cmp v0.6.0/go.mod h1:17dUlkBOakJ0+DkrSSNjCkIjxS6bF9zb3elmeNGIjoY= +github.com/google/uuid v1.6.0 h1:NIvaJDMOsjHA8n1jAhLSgzrAzy1Hgr+hNrb57e+94F0= +github.com/google/uuid v1.6.0/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo= +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/testify v1.10.0 h1:Xv5erBjTwe/5IxqUQTdXv5kgmIvbHo3QQyRwhJsOfJA= +github.com/stretchr/testify v1.10.0/go.mod h1:r2ic/lqez/lEtzL7wO/rwa5dbSLXVDPFyf8C91i36aY= +go.opentelemetry.io/auto/sdk v1.1.0 h1:cH53jehLUN6UFLY71z+NDOiNJqDdPRaXzTel0sJySYA= +go.opentelemetry.io/auto/sdk v1.1.0/go.mod h1:3wSPjt5PWp2RhlCcmmOial7AvC4DQqZb7a7wCow3W8A= +go.opentelemetry.io/otel v1.33.0 h1:/FerN9bax5LoK51X/sI0SVYrjSE0/yUL7DpxW4K3FWw= +go.opentelemetry.io/otel v1.33.0/go.mod h1:SUUkR6csvUQl+yjReHu5uM3EtVV7MBm5FHKRlNx4I8I= +go.opentelemetry.io/otel/metric v1.33.0 h1:r+JOocAyeRVXD8lZpjdQjzMadVZp2M4WmQ+5WtEnklQ= +go.opentelemetry.io/otel/metric v1.33.0/go.mod h1:L9+Fyctbp6HFTddIxClbQkjtubW6O9QS3Ann/M82u6M= +go.opentelemetry.io/otel/sdk v1.33.0 h1:iax7M131HuAm9QkZotNHEfstof92xM+N8sr3uHXc2IM= +go.opentelemetry.io/otel/sdk v1.33.0/go.mod h1:A1Q5oi7/9XaMlIWzPSxLRWOI8nG3FnzHJNbiENQuihM= +go.opentelemetry.io/otel/sdk/metric v1.33.0 h1:Gs5VK9/WUJhNXZgn8MR6ITatvAmKeIuCtNbsP3JkNqU= +go.opentelemetry.io/otel/sdk/metric v1.33.0/go.mod h1:dL5ykHZmm1B1nVRk9dDjChwDmt81MjVp3gLkQRwKf/Q= +go.opentelemetry.io/otel/trace v1.33.0 h1:cCJuF7LRjUFso9LPnEAHJDB2pqzp+hbO8eu1qqW2d/s= +go.opentelemetry.io/otel/trace v1.33.0/go.mod h1:uIcdVUZMpTAmz0tI1z04GoVSezK37CbGV4fr1f2nBck= +golang.org/x/sys v0.29.0 h1:TPYlXGxvx1MGTn2GiZDhnjPA9wZzZeGKHHmKhHYvgaU= +golang.org/x/sys v0.29.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA= +gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA= +gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= diff --git a/opentelemetry_logger.go b/opentelemetry_logger.go new file mode 100644 index 0000000..af9a9cc --- /dev/null +++ b/opentelemetry_logger.go @@ -0,0 +1,228 @@ +// Copyright 2026 The casbin Authors. All Rights Reserved. +// +// 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 opentelemetrylogger + +import ( + "context" + "time" + + "go.opentelemetry.io/otel/attribute" + "go.opentelemetry.io/otel/metric" +) + +// OpenTelemetryLogger is a logger that exports metrics to OpenTelemetry. +type OpenTelemetryLogger struct { + enabledEventTypes map[EventType]bool + callback func(entry *LogEntry) error + + // OpenTelemetry metrics + enforceDuration metric.Float64Histogram + enforceTotal metric.Int64Counter + policyOpsTotal metric.Int64Counter + policyOpsDuration metric.Float64Histogram + policyRulesCount metric.Int64Gauge + + ctx context.Context +} + +// NewOpenTelemetryLogger creates a new OpenTelemetryLogger with the provided meter. +func NewOpenTelemetryLogger(meter metric.Meter) (*OpenTelemetryLogger, error) { + return NewOpenTelemetryLoggerWithContext(context.Background(), meter) +} + +// NewOpenTelemetryLoggerWithContext creates a new OpenTelemetryLogger with a custom context and meter. +func NewOpenTelemetryLoggerWithContext(ctx context.Context, meter metric.Meter) (*OpenTelemetryLogger, error) { + logger := &OpenTelemetryLogger{ + enabledEventTypes: make(map[EventType]bool), + ctx: ctx, + } + + var err error + + // Create enforce duration histogram + logger.enforceDuration, err = meter.Float64Histogram( + "casbin.enforce.duration", + metric.WithDescription("Duration of enforce requests in seconds"), + metric.WithUnit("s"), + ) + if err != nil { + return nil, err + } + + // Create enforce total counter + logger.enforceTotal, err = meter.Int64Counter( + "casbin.enforce.total", + metric.WithDescription("Total number of enforce requests"), + ) + if err != nil { + return nil, err + } + + // Create policy operations total counter + logger.policyOpsTotal, err = meter.Int64Counter( + "casbin.policy.operations.total", + metric.WithDescription("Total number of policy operations"), + ) + if err != nil { + return nil, err + } + + // Create policy operations duration histogram + logger.policyOpsDuration, err = meter.Float64Histogram( + "casbin.policy.operations.duration", + metric.WithDescription("Duration of policy operations in seconds"), + metric.WithUnit("s"), + ) + if err != nil { + return nil, err + } + + // Create policy rules count gauge + logger.policyRulesCount, err = meter.Int64Gauge( + "casbin.policy.rules.count", + metric.WithDescription("Number of policy rules affected by operations"), + ) + if err != nil { + return nil, err + } + + return logger, nil +} + +// SetEventTypes configures which event types should be logged. +func (l *OpenTelemetryLogger) SetEventTypes(eventTypes []EventType) error { + l.enabledEventTypes = make(map[EventType]bool) + for _, eventType := range eventTypes { + l.enabledEventTypes[eventType] = true + } + return nil +} + +// OnBeforeEvent is called before an event occurs. +func (l *OpenTelemetryLogger) OnBeforeEvent(entry *LogEntry) error { + if len(l.enabledEventTypes) > 0 && !l.enabledEventTypes[entry.EventType] { + entry.IsActive = false + return nil + } + + entry.IsActive = true + entry.StartTime = time.Now() + return nil +} + +// OnAfterEvent is called after an event completes and records metrics. +func (l *OpenTelemetryLogger) OnAfterEvent(entry *LogEntry) error { + if !entry.IsActive { + return nil + } + + entry.EndTime = time.Now() + entry.Duration = entry.EndTime.Sub(entry.StartTime) + + // Record metrics based on event type + switch entry.EventType { + case EventEnforce: + l.recordEnforceMetrics(entry) + case EventAddPolicy, EventRemovePolicy, EventLoadPolicy, EventSavePolicy: + l.recordPolicyMetrics(entry) + } + + // Call custom callback if set + if l.callback != nil { + return l.callback(entry) + } + + return nil +} + +// SetLogCallback sets a custom callback function for log entries. +func (l *OpenTelemetryLogger) SetLogCallback(callback func(entry *LogEntry) error) error { + l.callback = callback + return nil +} + +// recordEnforceMetrics records metrics for enforce events. +func (l *OpenTelemetryLogger) recordEnforceMetrics(entry *LogEntry) { + domain := entry.Domain + if domain == "" { + domain = "default" + } + + allowed := "false" + if entry.Allowed { + allowed = "true" + } + + attrs := []attribute.KeyValue{ + attribute.String("allowed", allowed), + attribute.String("domain", domain), + } + + l.enforceDuration.Record(l.ctx, entry.Duration.Seconds(), metric.WithAttributes(attrs...)) + l.enforceTotal.Add(l.ctx, 1, metric.WithAttributes(attrs...)) +} + +// recordPolicyMetrics records metrics for policy operation events. +func (l *OpenTelemetryLogger) recordPolicyMetrics(entry *LogEntry) { + operation := string(entry.EventType) + success := "true" + if entry.Error != nil { + success = "false" + } + + opsAttrs := []attribute.KeyValue{ + attribute.String("operation", operation), + attribute.String("success", success), + } + + durationAttrs := []attribute.KeyValue{ + attribute.String("operation", operation), + } + + l.policyOpsTotal.Add(l.ctx, 1, metric.WithAttributes(opsAttrs...)) + l.policyOpsDuration.Record(l.ctx, entry.Duration.Seconds(), metric.WithAttributes(durationAttrs...)) + + if entry.RuleCount > 0 { + countAttrs := []attribute.KeyValue{ + attribute.String("operation", operation), + } + l.policyRulesCount.Record(l.ctx, int64(entry.RuleCount), metric.WithAttributes(countAttrs...)) + } +} + +// GetEnforceDuration returns the enforce duration histogram metric. +func (l *OpenTelemetryLogger) GetEnforceDuration() metric.Float64Histogram { + return l.enforceDuration +} + +// GetEnforceTotal returns the enforce total counter metric. +func (l *OpenTelemetryLogger) GetEnforceTotal() metric.Int64Counter { + return l.enforceTotal +} + +// GetPolicyOpsTotal returns the policy operations total counter metric. +func (l *OpenTelemetryLogger) GetPolicyOpsTotal() metric.Int64Counter { + return l.policyOpsTotal +} + +// GetPolicyOpsDuration returns the policy operations duration histogram metric. +func (l *OpenTelemetryLogger) GetPolicyOpsDuration() metric.Float64Histogram { + return l.policyOpsDuration +} + +// GetPolicyRulesCount returns the policy rules count gauge metric. +func (l *OpenTelemetryLogger) GetPolicyRulesCount() metric.Int64Gauge { + return l.policyRulesCount +} diff --git a/opentelemetry_logger_test.go b/opentelemetry_logger_test.go new file mode 100644 index 0000000..f019d42 --- /dev/null +++ b/opentelemetry_logger_test.go @@ -0,0 +1,581 @@ +// Copyright 2026 The casbin Authors. All Rights Reserved. +// +// 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 opentelemetrylogger + +import ( + "context" + "errors" + "testing" + "time" + + "go.opentelemetry.io/otel/sdk/metric" + "go.opentelemetry.io/otel/sdk/metric/metricdata" +) + +func TestNewOpenTelemetryLogger(t *testing.T) { + reader := metric.NewManualReader() + provider := metric.NewMeterProvider(metric.WithReader(reader)) + meter := provider.Meter("test") + + logger, err := NewOpenTelemetryLogger(meter) + if err != nil { + t.Fatalf("NewOpenTelemetryLogger returned error: %v", err) + } + + if logger == nil { + t.Fatal("NewOpenTelemetryLogger returned nil") + } + + if logger.enabledEventTypes == nil { + t.Error("enabledEventTypes map not initialized") + } + + if logger.enforceDuration == nil { + t.Error("enforceDuration metric not initialized") + } + + if logger.enforceTotal == nil { + t.Error("enforceTotal metric not initialized") + } + + if logger.policyOpsTotal == nil { + t.Error("policyOpsTotal metric not initialized") + } + + if logger.policyOpsDuration == nil { + t.Error("policyOpsDuration metric not initialized") + } + + if logger.policyRulesCount == nil { + t.Error("policyRulesCount metric not initialized") + } +} + +func TestNewOpenTelemetryLoggerWithContext(t *testing.T) { + reader := metric.NewManualReader() + provider := metric.NewMeterProvider(metric.WithReader(reader)) + meter := provider.Meter("test") + + ctx := context.Background() + logger, err := NewOpenTelemetryLoggerWithContext(ctx, meter) + if err != nil { + t.Fatalf("NewOpenTelemetryLoggerWithContext returned error: %v", err) + } + + if logger == nil { + t.Fatal("NewOpenTelemetryLoggerWithContext returned nil") + } + + if logger.ctx != ctx { + t.Error("Context not set correctly") + } +} + +func TestSetEventTypes(t *testing.T) { + reader := metric.NewManualReader() + provider := metric.NewMeterProvider(metric.WithReader(reader)) + meter := provider.Meter("test") + + logger, err := NewOpenTelemetryLogger(meter) + if err != nil { + t.Fatalf("Setup failed: %v", err) + } + + eventTypes := []EventType{EventEnforce, EventAddPolicy} + err = logger.SetEventTypes(eventTypes) + if err != nil { + t.Errorf("SetEventTypes returned error: %v", err) + } + + if len(logger.enabledEventTypes) != 2 { + t.Errorf("Expected 2 enabled event types, got %d", len(logger.enabledEventTypes)) + } + + if !logger.enabledEventTypes[EventEnforce] { + t.Error("EventEnforce should be enabled") + } + + if !logger.enabledEventTypes[EventAddPolicy] { + t.Error("EventAddPolicy should be enabled") + } + + if logger.enabledEventTypes[EventRemovePolicy] { + t.Error("EventRemovePolicy should not be enabled") + } +} + +func TestOnBeforeEvent(t *testing.T) { + reader := metric.NewManualReader() + provider := metric.NewMeterProvider(metric.WithReader(reader)) + meter := provider.Meter("test") + + logger, err := NewOpenTelemetryLogger(meter) + if err != nil { + t.Fatalf("Setup failed: %v", err) + } + + // Test with no event type filtering + entry := &LogEntry{ + EventType: EventEnforce, + } + + err = logger.OnBeforeEvent(entry) + if err != nil { + t.Errorf("OnBeforeEvent returned error: %v", err) + } + + if !entry.IsActive { + t.Error("Entry should be active when no event types are configured") + } + + if entry.StartTime.IsZero() { + t.Error("StartTime should be set") + } + + // Test with event type filtering - enabled event + logger.SetEventTypes([]EventType{EventEnforce}) + entry2 := &LogEntry{ + EventType: EventEnforce, + } + + err = logger.OnBeforeEvent(entry2) + if err != nil { + t.Errorf("OnBeforeEvent returned error: %v", err) + } + + if !entry2.IsActive { + t.Error("Entry should be active for enabled event type") + } + + // Test with event type filtering - disabled event + entry3 := &LogEntry{ + EventType: EventAddPolicy, + } + + err = logger.OnBeforeEvent(entry3) + if err != nil { + t.Errorf("OnBeforeEvent returned error: %v", err) + } + + if entry3.IsActive { + t.Error("Entry should not be active for disabled event type") + } +} + +func TestOnAfterEvent_Enforce(t *testing.T) { + reader := metric.NewManualReader() + provider := metric.NewMeterProvider(metric.WithReader(reader)) + meter := provider.Meter("test") + + logger, err := NewOpenTelemetryLogger(meter) + if err != nil { + t.Fatalf("Setup failed: %v", err) + } + + entry := &LogEntry{ + IsActive: true, + EventType: EventEnforce, + StartTime: time.Now().Add(-100 * time.Millisecond), + Subject: "alice", + Object: "data1", + Action: "read", + Domain: "domain1", + Allowed: true, + } + + err = logger.OnAfterEvent(entry) + if err != nil { + t.Errorf("OnAfterEvent returned error: %v", err) + } + + if entry.EndTime.IsZero() { + t.Error("EndTime should be set") + } + + if entry.Duration == 0 { + t.Error("Duration should be calculated") + } + + // Verify metrics were recorded + var rm metricdata.ResourceMetrics + err = reader.Collect(context.Background(), &rm) + if err != nil { + t.Fatalf("Failed to collect metrics: %v", err) + } + + if len(rm.ScopeMetrics) == 0 { + t.Error("Expected metrics to be recorded") + } + + // Check that we have at least one metric + hasMetrics := false + for _, sm := range rm.ScopeMetrics { + if len(sm.Metrics) > 0 { + hasMetrics = true + break + } + } + + if !hasMetrics { + t.Error("Expected at least one metric to be recorded") + } +} + +func TestOnAfterEvent_InactiveEntry(t *testing.T) { + reader := metric.NewManualReader() + provider := metric.NewMeterProvider(metric.WithReader(reader)) + meter := provider.Meter("test") + + logger, err := NewOpenTelemetryLogger(meter) + if err != nil { + t.Fatalf("Setup failed: %v", err) + } + + entry := &LogEntry{ + IsActive: false, + EventType: EventEnforce, + } + + err = logger.OnAfterEvent(entry) + if err != nil { + t.Errorf("OnAfterEvent returned error: %v", err) + } + + // Verify no metrics were recorded + var rm metricdata.ResourceMetrics + err = reader.Collect(context.Background(), &rm) + if err != nil { + t.Fatalf("Failed to collect metrics: %v", err) + } + + // For an inactive entry, we should have no metrics + totalMetrics := 0 + for _, sm := range rm.ScopeMetrics { + totalMetrics += len(sm.Metrics) + } + + if totalMetrics != 0 { + t.Errorf("Expected 0 metrics for inactive entry, got %d", totalMetrics) + } +} + +func TestOnAfterEvent_PolicyOperation(t *testing.T) { + testCases := []struct { + name string + eventType EventType + }{ + {"AddPolicy", EventAddPolicy}, + {"RemovePolicy", EventRemovePolicy}, + {"LoadPolicy", EventLoadPolicy}, + {"SavePolicy", EventSavePolicy}, + } + + for _, tc := range testCases { + t.Run(tc.name, func(t *testing.T) { + reader := metric.NewManualReader() + provider := metric.NewMeterProvider(metric.WithReader(reader)) + meter := provider.Meter("test") + + logger, err := NewOpenTelemetryLogger(meter) + if err != nil { + t.Fatalf("Setup failed: %v", err) + } + + entry := &LogEntry{ + IsActive: true, + EventType: tc.eventType, + StartTime: time.Now().Add(-50 * time.Millisecond), + RuleCount: 5, + } + + err = logger.OnAfterEvent(entry) + if err != nil { + t.Errorf("OnAfterEvent returned error: %v", err) + } + + if entry.EndTime.IsZero() { + t.Error("EndTime should be set") + } + + if entry.Duration == 0 { + t.Error("Duration should be calculated") + } + + // Verify metrics were recorded + var rm metricdata.ResourceMetrics + err = reader.Collect(context.Background(), &rm) + if err != nil { + t.Fatalf("Failed to collect metrics: %v", err) + } + + if len(rm.ScopeMetrics) == 0 { + t.Error("Expected metrics to be recorded") + } + }) + } +} + +func TestOnAfterEvent_WithError(t *testing.T) { + reader := metric.NewManualReader() + provider := metric.NewMeterProvider(metric.WithReader(reader)) + meter := provider.Meter("test") + + logger, err := NewOpenTelemetryLogger(meter) + if err != nil { + t.Fatalf("Setup failed: %v", err) + } + + entry := &LogEntry{ + IsActive: true, + EventType: EventAddPolicy, + StartTime: time.Now().Add(-50 * time.Millisecond), + RuleCount: 3, + Error: errors.New("test error"), + } + + err = logger.OnAfterEvent(entry) + if err != nil { + t.Errorf("OnAfterEvent returned error: %v", err) + } + + // Verify metrics were recorded with success="false" + var rm metricdata.ResourceMetrics + err = reader.Collect(context.Background(), &rm) + if err != nil { + t.Fatalf("Failed to collect metrics: %v", err) + } + + if len(rm.ScopeMetrics) == 0 { + t.Error("Expected metrics to be recorded") + } +} + +func TestSetLogCallback(t *testing.T) { + reader := metric.NewManualReader() + provider := metric.NewMeterProvider(metric.WithReader(reader)) + meter := provider.Meter("test") + + logger, err := NewOpenTelemetryLogger(meter) + if err != nil { + t.Fatalf("Setup failed: %v", err) + } + + callbackCalled := false + callback := func(entry *LogEntry) error { + callbackCalled = true + return nil + } + + err = logger.SetLogCallback(callback) + if err != nil { + t.Errorf("SetLogCallback returned error: %v", err) + } + + // Trigger an event to verify callback is called + entry := &LogEntry{ + IsActive: true, + EventType: EventEnforce, + StartTime: time.Now(), + Allowed: true, + } + + err = logger.OnAfterEvent(entry) + if err != nil { + t.Errorf("OnAfterEvent returned error: %v", err) + } + + if !callbackCalled { + t.Error("Callback should have been called") + } +} + +func TestSetLogCallback_WithError(t *testing.T) { + reader := metric.NewManualReader() + provider := metric.NewMeterProvider(metric.WithReader(reader)) + meter := provider.Meter("test") + + logger, err := NewOpenTelemetryLogger(meter) + if err != nil { + t.Fatalf("Setup failed: %v", err) + } + + expectedError := errors.New("callback error") + callback := func(entry *LogEntry) error { + return expectedError + } + + logger.SetLogCallback(callback) + + entry := &LogEntry{ + IsActive: true, + EventType: EventEnforce, + StartTime: time.Now(), + Allowed: true, + } + + err = logger.OnAfterEvent(entry) + if err != expectedError { + t.Errorf("Expected error %v, got %v", expectedError, err) + } +} + +func TestEnforceMetrics_DifferentDomains(t *testing.T) { + reader := metric.NewManualReader() + provider := metric.NewMeterProvider(metric.WithReader(reader)) + meter := provider.Meter("test") + + logger, err := NewOpenTelemetryLogger(meter) + if err != nil { + t.Fatalf("Setup failed: %v", err) + } + + // Test with specific domain + entry1 := &LogEntry{ + IsActive: true, + EventType: EventEnforce, + StartTime: time.Now(), + Domain: "domain1", + Allowed: true, + } + + logger.OnAfterEvent(entry1) + + // Test with default domain (empty) + entry2 := &LogEntry{ + IsActive: true, + EventType: EventEnforce, + StartTime: time.Now(), + Domain: "", + Allowed: false, + } + + logger.OnAfterEvent(entry2) + + // Verify metrics were recorded with different labels + var rm metricdata.ResourceMetrics + err = reader.Collect(context.Background(), &rm) + if err != nil { + t.Fatalf("Failed to collect metrics: %v", err) + } + + if len(rm.ScopeMetrics) == 0 { + t.Error("Expected metrics to be recorded") + } +} + +func TestMetricGetters(t *testing.T) { + reader := metric.NewManualReader() + provider := metric.NewMeterProvider(metric.WithReader(reader)) + meter := provider.Meter("test") + + logger, err := NewOpenTelemetryLogger(meter) + if err != nil { + t.Fatalf("Setup failed: %v", err) + } + + if logger.GetEnforceDuration() == nil { + t.Error("GetEnforceDuration returned nil") + } + + if logger.GetEnforceTotal() == nil { + t.Error("GetEnforceTotal returned nil") + } + + if logger.GetPolicyOpsTotal() == nil { + t.Error("GetPolicyOpsTotal returned nil") + } + + if logger.GetPolicyOpsDuration() == nil { + t.Error("GetPolicyOpsDuration returned nil") + } + + if logger.GetPolicyRulesCount() == nil { + t.Error("GetPolicyRulesCount returned nil") + } +} + +func TestLogger_InterfaceImplementation(t *testing.T) { + reader := metric.NewManualReader() + provider := metric.NewMeterProvider(metric.WithReader(reader)) + meter := provider.Meter("test") + + logger, err := NewOpenTelemetryLogger(meter) + if err != nil { + t.Fatalf("Setup failed: %v", err) + } + + var _ Logger = logger +} + +func TestFullWorkflow(t *testing.T) { + reader := metric.NewManualReader() + provider := metric.NewMeterProvider(metric.WithReader(reader)) + meter := provider.Meter("test") + + logger, err := NewOpenTelemetryLogger(meter) + if err != nil { + t.Fatalf("Setup failed: %v", err) + } + + // Configure to only log enforce events + logger.SetEventTypes([]EventType{EventEnforce}) + + // Simulate enforce event + enforceEntry := &LogEntry{ + EventType: EventEnforce, + Subject: "alice", + Object: "data1", + Action: "read", + Domain: "org1", + } + + // Before event + logger.OnBeforeEvent(enforceEntry) + if !enforceEntry.IsActive { + t.Error("Enforce entry should be active") + } + + // Simulate some processing time + time.Sleep(10 * time.Millisecond) + + // After event + enforceEntry.Allowed = true + logger.OnAfterEvent(enforceEntry) + + // Simulate policy event (should be filtered out) + policyEntry := &LogEntry{ + EventType: EventAddPolicy, + RuleCount: 5, + } + + logger.OnBeforeEvent(policyEntry) + if policyEntry.IsActive { + t.Error("Policy entry should not be active (filtered)") + } + + logger.OnAfterEvent(policyEntry) + + // Verify metrics were recorded + var rm metricdata.ResourceMetrics + err = reader.Collect(context.Background(), &rm) + if err != nil { + t.Fatalf("Failed to collect metrics: %v", err) + } + + // We should have enforce metrics but not policy metrics (filtered) + if len(rm.ScopeMetrics) == 0 { + t.Error("Expected enforce metrics to be recorded") + } +} diff --git a/types.go b/types.go new file mode 100644 index 0000000..5c404ca --- /dev/null +++ b/types.go @@ -0,0 +1,74 @@ +// Copyright 2026 The casbin Authors. All Rights Reserved. +// +// 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 opentelemetrylogger + +import "time" + +// EventType represents the type of logging event. +// These types are defined to match the casbin/v2/log package interface. +type EventType string + +// Event type constants. +const ( + EventEnforce EventType = "enforce" + EventAddPolicy EventType = "addPolicy" + EventRemovePolicy EventType = "removePolicy" + EventLoadPolicy EventType = "loadPolicy" + EventSavePolicy EventType = "savePolicy" +) + +// LogEntry represents a complete log entry for a Casbin event. +// This type is defined to match the casbin/v2/log package interface. +type LogEntry struct { + IsActive bool + // EventType is the type of the event being logged. + EventType EventType + + StartTime time.Time + EndTime time.Time + Duration time.Duration + + // Enforce parameters. + // Subject is the user or entity requesting access. + Subject string + // Object is the resource being accessed. + Object string + // Action is the operation being performed. + Action string + // Domain is the domain/tenant for multi-tenant scenarios. + Domain string + // Allowed indicates whether the enforcement request was allowed. + Allowed bool + + // Rules contains the policy rules involved in the operation. + Rules [][]string + // RuleCount is the number of rules affected by the operation. + RuleCount int + + // Error contains any error that occurred during the event. + Error error +} + +// Logger defines the interface for event-driven logging in Casbin. +// This interface is defined to match the casbin/v2/log package interface. +type Logger interface { + SetEventTypes([]EventType) error + // OnBeforeEvent is called before an event occurs and returns a handle for context. + OnBeforeEvent(entry *LogEntry) error + // OnAfterEvent is called after an event completes with the handle and final entry. + OnAfterEvent(entry *LogEntry) error + + SetLogCallback(func(entry *LogEntry) error) error +}