diff --git a/README.md b/README.md index cf86582..0bd91e2 100644 --- a/README.md +++ b/README.md @@ -20,14 +20,17 @@ A Prometheus logger implementation for [Casbin](https://github.com/casbin/casbin ## Metrics Exported ### Enforce Metrics -- `casbin_enforce_total` - Total number of enforce requests (labeled by `allowed`, `domain`) -- `casbin_enforce_duration_seconds` - Duration of enforce requests (labeled by `allowed`, `domain`) +- `casbin_enforce_total` - Total number of enforce requests (labeled by `allowed`, `domain`, and optionally `subject`, `object`, `action`) +- `casbin_enforce_duration_seconds` - Duration of enforce requests (labeled by `allowed`, `domain`, and optionally `subject`, `object`, `action`) ### Policy Operation Metrics - `casbin_policy_operations_total` - Total number of policy operations (labeled by `operation`, `success`) - `casbin_policy_operations_duration_seconds` - Duration of policy operations (labeled by `operation`) - `casbin_policy_rules_count` - Number of policy rules affected by operations (labeled by `operation`) +### Policy State Metrics +- `casbin_policy_state_count` - Current number of policy rules by type (labeled by `ptype`) + ## Installation ```bash @@ -68,6 +71,38 @@ func main() { } ``` +### Configure Optional Enforce Metric Labels + +```go +// Create logger with additional labels for enforce metrics +options := &prometheuslogger.PrometheusLoggerOptions{ + EnforceLabels: []string{ + prometheuslogger.EnforceLabelSubject, + prometheuslogger.EnforceLabelObject, + prometheuslogger.EnforceLabelAction, + }, +} + +registry := prometheus.NewRegistry() +logger := prometheuslogger.NewPrometheusLoggerWithOptions(registry, options) +defer logger.UnregisterFrom(registry) + +// Enforce metrics will now include subject, object, and action labels +// in addition to the default allowed and domain labels +``` + +### Update Policy State Metrics + +```go +// Update the current policy state count +// This helps monitor permission growth over time +logger.UpdatePolicyState("p", 100) // 100 p-type policies +logger.UpdatePolicyState("g", 50) // 50 g-type role assignments +logger.UpdatePolicyState("g1", 25) // 25 g1-type role assignments +logger.UpdatePolicyState("g2", 10) // 10 g2-type role assignments +logger.UpdatePolicyState("g3", 5) // 5 g3-type role assignments +``` + ### Configure Event Types ```go diff --git a/go.sum b/go.sum index bea060b..d6b8ca9 100644 --- a/go.sum +++ b/go.sum @@ -7,6 +7,8 @@ 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/google/go-cmp v0.7.0 h1:wk8382ETsv4JYUZwIsn6YpYiWiBsYLSJiTsyBybVuN8= github.com/google/go-cmp v0.7.0/go.mod h1:pXiqmnSA92OHEEa9HXL2W4E7lf9JzCmGVUdgjX3N/iU= +github.com/klauspost/compress v1.18.0 h1:c/Cqfb0r+Yi+JtIEq73FWXVkRonBlf0CRNYc8Zttxdo= +github.com/klauspost/compress v1.18.0/go.mod h1:2Pp+KzxcywXVXMr50+X0Q/Lsb43OQHYWRCY2AiWywWQ= github.com/kr/pretty v0.3.1 h1:flRD4NNwYAUpkphVc1HcthR4KEIFJ65n8Mw5qdRn3LE= github.com/kr/pretty v0.3.1/go.mod h1:hoEshYVHaxMs3cyo3Yncou5ZscifuDolrwPKZanG3xk= github.com/kr/text v0.2.0 h1:5Nx0Ya0ZqY2ygV366QzturHI13Jq95ApcVaJBhpS+AY= diff --git a/prometheus_logger.go b/prometheus_logger.go index 8408955..787611d 100644 --- a/prometheus_logger.go +++ b/prometheus_logger.go @@ -20,92 +20,87 @@ import ( "github.com/prometheus/client_golang/prometheus" ) +// Valid optional enforce label names +const ( + EnforceLabelSubject = "subject" + EnforceLabelObject = "object" + EnforceLabelAction = "action" +) + // PrometheusLogger is a logger that exports metrics to Prometheus. type PrometheusLogger struct { enabledEventTypes map[EventType]bool callback func(entry *LogEntry) error + // Configuration + enforceLabels []string // Optional labels for enforce metrics (e.g., "subject", "object", "action") + // Prometheus metrics enforceDuration *prometheus.HistogramVec enforceTotal *prometheus.CounterVec policyOpsTotal *prometheus.CounterVec policyOpsDuration *prometheus.HistogramVec policyRulesCount *prometheus.GaugeVec + policyStateCount *prometheus.GaugeVec // Current count of policies by type } // NewPrometheusLogger creates a new PrometheusLogger with default metrics. func NewPrometheusLogger() *PrometheusLogger { - logger := &PrometheusLogger{ - enabledEventTypes: make(map[EventType]bool), - enforceDuration: prometheus.NewHistogramVec( - prometheus.HistogramOpts{ - Name: "casbin_enforce_duration_seconds", - Help: "Duration of enforce requests in seconds", - Buckets: prometheus.DefBuckets, - }, - []string{"allowed", "domain"}, - ), - enforceTotal: prometheus.NewCounterVec( - prometheus.CounterOpts{ - Name: "casbin_enforce_total", - Help: "Total number of enforce requests", - }, - []string{"allowed", "domain"}, - ), - policyOpsTotal: prometheus.NewCounterVec( - prometheus.CounterOpts{ - Name: "casbin_policy_operations_total", - Help: "Total number of policy operations", - }, - []string{"operation", "success"}, - ), - policyOpsDuration: prometheus.NewHistogramVec( - prometheus.HistogramOpts{ - Name: "casbin_policy_operations_duration_seconds", - Help: "Duration of policy operations in seconds", - Buckets: prometheus.DefBuckets, - }, - []string{"operation"}, - ), - policyRulesCount: prometheus.NewGaugeVec( - prometheus.GaugeOpts{ - Name: "casbin_policy_rules_count", - Help: "Number of policy rules affected by operations", - }, - []string{"operation"}, - ), - } - - // Register all metrics - prometheus.MustRegister( - logger.enforceDuration, - logger.enforceTotal, - logger.policyOpsTotal, - logger.policyOpsDuration, - logger.policyRulesCount, - ) - - return logger + return NewPrometheusLoggerWithOptions(nil, nil) } // NewPrometheusLoggerWithRegistry creates a new PrometheusLogger with a custom registry. func NewPrometheusLoggerWithRegistry(registry *prometheus.Registry) *PrometheusLogger { + return NewPrometheusLoggerWithOptions(registry, nil) +} + +// PrometheusLoggerOptions provides configuration options for the logger. +type PrometheusLoggerOptions struct { + // EnforceLabels specifies optional labels for enforce metrics. + // Valid values: EnforceLabelSubject, EnforceLabelObject, EnforceLabelAction + // By default, only "allowed" and "domain" labels are used. + EnforceLabels []string +} + +// NewPrometheusLoggerWithOptions creates a new PrometheusLogger with custom options. +// If registry is nil, the default Prometheus registry is used. +// If options is nil, default options are used. +func NewPrometheusLoggerWithOptions(registry *prometheus.Registry, options *PrometheusLoggerOptions) *PrometheusLogger { + if options == nil { + options = &PrometheusLoggerOptions{} + } + + // Build enforce label list: always include "allowed" and "domain" + enforceLabels := []string{"allowed", "domain"} + validLabels := map[string]bool{ + EnforceLabelSubject: true, + EnforceLabelObject: true, + EnforceLabelAction: true, + } + + for _, label := range options.EnforceLabels { + if validLabels[label] { + enforceLabels = append(enforceLabels, label) + } + } + logger := &PrometheusLogger{ enabledEventTypes: make(map[EventType]bool), + enforceLabels: enforceLabels, enforceDuration: prometheus.NewHistogramVec( prometheus.HistogramOpts{ Name: "casbin_enforce_duration_seconds", Help: "Duration of enforce requests in seconds", Buckets: prometheus.DefBuckets, }, - []string{"allowed", "domain"}, + enforceLabels, ), enforceTotal: prometheus.NewCounterVec( prometheus.CounterOpts{ Name: "casbin_enforce_total", Help: "Total number of enforce requests", }, - []string{"allowed", "domain"}, + enforceLabels, ), policyOpsTotal: prometheus.NewCounterVec( prometheus.CounterOpts{ @@ -129,16 +124,35 @@ func NewPrometheusLoggerWithRegistry(registry *prometheus.Registry) *PrometheusL }, []string{"operation"}, ), + policyStateCount: prometheus.NewGaugeVec( + prometheus.GaugeOpts{ + Name: "casbin_policy_state_count", + Help: "Current number of policy rules by type", + }, + []string{"ptype"}, + ), } - // Register all metrics with the provided registry - registry.MustRegister( - logger.enforceDuration, - logger.enforceTotal, - logger.policyOpsTotal, - logger.policyOpsDuration, - logger.policyRulesCount, - ) + // Register all metrics with the provided registry or default + if registry != nil { + registry.MustRegister( + logger.enforceDuration, + logger.enforceTotal, + logger.policyOpsTotal, + logger.policyOpsDuration, + logger.policyRulesCount, + logger.policyStateCount, + ) + } else { + prometheus.MustRegister( + logger.enforceDuration, + logger.enforceTotal, + logger.policyOpsTotal, + logger.policyOpsDuration, + logger.policyRulesCount, + logger.policyStateCount, + ) + } return logger } @@ -207,8 +221,29 @@ func (p *PrometheusLogger) recordEnforceMetrics(entry *LogEntry) { allowed = "true" } - p.enforceDuration.WithLabelValues(allowed, domain).Observe(entry.Duration.Seconds()) - p.enforceTotal.WithLabelValues(allowed, domain).Inc() + // Build label values based on configured labels + labelValues := make([]string, len(p.enforceLabels)) + for i, label := range p.enforceLabels { + switch label { + case "allowed": + labelValues[i] = allowed + case "domain": + labelValues[i] = domain + case EnforceLabelSubject: + labelValues[i] = entry.Subject + case EnforceLabelObject: + labelValues[i] = entry.Object + case EnforceLabelAction: + labelValues[i] = entry.Action + default: + // This should not happen due to validation in NewPrometheusLoggerWithOptions, + // but provide a safe default value if it does + labelValues[i] = "" + } + } + + p.enforceDuration.WithLabelValues(labelValues...).Observe(entry.Duration.Seconds()) + p.enforceTotal.WithLabelValues(labelValues...).Inc() } // recordPolicyMetrics records metrics for policy operation events. @@ -227,6 +262,13 @@ func (p *PrometheusLogger) recordPolicyMetrics(entry *LogEntry) { } } +// UpdatePolicyState updates the current policy state count for a given policy type. +// ptype should be one of: "p", "g", "g1", "g2", "g3", etc. +// count is the current number of policies of that type. +func (p *PrometheusLogger) UpdatePolicyState(ptype string, count int) { + p.policyStateCount.WithLabelValues(ptype).Set(float64(count)) +} + // Unregister unregisters all metrics from the default Prometheus registry. // This is useful for testing or when you need to recreate the logger. func (p *PrometheusLogger) Unregister() { @@ -235,6 +277,7 @@ func (p *PrometheusLogger) Unregister() { prometheus.Unregister(p.policyOpsTotal) prometheus.Unregister(p.policyOpsDuration) prometheus.Unregister(p.policyRulesCount) + prometheus.Unregister(p.policyStateCount) } // UnregisterFrom unregisters all metrics from a specific Prometheus registry. @@ -245,6 +288,7 @@ func (p *PrometheusLogger) UnregisterFrom(registry *prometheus.Registry) bool { result = registry.Unregister(p.policyOpsTotal) && result result = registry.Unregister(p.policyOpsDuration) && result result = registry.Unregister(p.policyRulesCount) && result + result = registry.Unregister(p.policyStateCount) && result return result } @@ -272,3 +316,8 @@ func (p *PrometheusLogger) GetPolicyOpsDuration() *prometheus.HistogramVec { func (p *PrometheusLogger) GetPolicyRulesCount() *prometheus.GaugeVec { return p.policyRulesCount } + +// GetPolicyStateCount returns the policy state count gauge metric. +func (p *PrometheusLogger) GetPolicyStateCount() *prometheus.GaugeVec { + return p.policyStateCount +} diff --git a/prometheus_logger_test.go b/prometheus_logger_test.go index c5654ca..0630a8b 100644 --- a/prometheus_logger_test.go +++ b/prometheus_logger_test.go @@ -429,6 +429,10 @@ func TestMetricGetters(t *testing.T) { if logger.GetPolicyRulesCount() == nil { t.Error("GetPolicyRulesCount returned nil") } + + if logger.GetPolicyStateCount() == nil { + t.Error("GetPolicyStateCount returned nil") + } } func TestLogger_InterfaceImplementation(t *testing.T) { @@ -490,3 +494,186 @@ func TestFullWorkflow(t *testing.T) { t.Errorf("Expected 0 policy metrics (filtered), got %d", policyCount) } } + +func TestNewPrometheusLoggerWithOptions_DefaultLabels(t *testing.T) { + registry := prometheus.NewRegistry() + logger := NewPrometheusLoggerWithOptions(registry, nil) + defer logger.UnregisterFrom(registry) + + if logger == nil { + t.Fatal("NewPrometheusLoggerWithOptions returned nil") + } + + // Default labels should be "allowed" and "domain" + if len(logger.enforceLabels) != 2 { + t.Errorf("Expected 2 default enforce labels, got %d", len(logger.enforceLabels)) + } + + if logger.enforceLabels[0] != "allowed" || logger.enforceLabels[1] != "domain" { + t.Error("Default enforce labels should be 'allowed' and 'domain'") + } +} + +func TestNewPrometheusLoggerWithOptions_CustomLabels(t *testing.T) { + registry := prometheus.NewRegistry() + options := &PrometheusLoggerOptions{ + EnforceLabels: []string{EnforceLabelSubject, EnforceLabelObject, EnforceLabelAction}, + } + logger := NewPrometheusLoggerWithOptions(registry, options) + defer logger.UnregisterFrom(registry) + + if logger == nil { + t.Fatal("NewPrometheusLoggerWithOptions returned nil") + } + + // Should have "allowed", "domain", "subject", "object", "action" + expectedLabels := 5 + if len(logger.enforceLabels) != expectedLabels { + t.Errorf("Expected %d enforce labels, got %d", expectedLabels, len(logger.enforceLabels)) + } + + // Verify all expected labels are present + labelSet := make(map[string]bool) + for _, label := range logger.enforceLabels { + labelSet[label] = true + } + + requiredLabels := []string{"allowed", "domain", "subject", "object", "action"} + for _, label := range requiredLabels { + if !labelSet[label] { + t.Errorf("Expected label '%s' not found in enforce labels", label) + } + } +} + +func TestNewPrometheusLoggerWithOptions_InvalidLabels(t *testing.T) { + registry := prometheus.NewRegistry() + options := &PrometheusLoggerOptions{ + EnforceLabels: []string{EnforceLabelSubject, "invalid_label", EnforceLabelObject}, + } + logger := NewPrometheusLoggerWithOptions(registry, options) + defer logger.UnregisterFrom(registry) + + // Should have "allowed", "domain", "subject", "object" (invalid_label excluded) + expectedLabels := 4 + if len(logger.enforceLabels) != expectedLabels { + t.Errorf("Expected %d enforce labels (invalid label should be excluded), got %d", expectedLabels, len(logger.enforceLabels)) + } +} + +func TestEnforceMetrics_WithCustomLabels(t *testing.T) { + registry := prometheus.NewRegistry() + options := &PrometheusLoggerOptions{ + EnforceLabels: []string{EnforceLabelSubject, EnforceLabelObject, EnforceLabelAction}, + } + logger := NewPrometheusLoggerWithOptions(registry, options) + defer logger.UnregisterFrom(registry) + + entry := &LogEntry{ + IsActive: true, + EventType: EventEnforce, + StartTime: time.Now(), + Subject: "alice", + Object: "data1", + Action: "read", + Domain: "domain1", + Allowed: true, + } + + logger.OnAfterEvent(entry) + + // Verify metrics were recorded + count := testutil.CollectAndCount(logger.enforceTotal) + if count != 1 { + t.Errorf("Expected 1 metric sample, got %d", count) + } + + count = testutil.CollectAndCount(logger.enforceDuration) + if count != 1 { + t.Errorf("Expected 1 metric sample for duration, got %d", count) + } +} + +func TestUpdatePolicyState(t *testing.T) { + registry := prometheus.NewRegistry() + logger := NewPrometheusLoggerWithRegistry(registry) + defer logger.UnregisterFrom(registry) + + // Update policy state for different types + logger.UpdatePolicyState("p", 10) + logger.UpdatePolicyState("g", 5) + logger.UpdatePolicyState("g1", 3) + logger.UpdatePolicyState("g2", 2) + logger.UpdatePolicyState("g3", 1) + + // Verify metrics were set + count := testutil.CollectAndCount(logger.policyStateCount) + if count != 5 { + t.Errorf("Expected 5 metric samples, got %d", count) + } + + // Update the same policy type again + logger.UpdatePolicyState("p", 15) + + // Should still have 5 metric samples (same label, different value) + count = testutil.CollectAndCount(logger.policyStateCount) + if count != 5 { + t.Errorf("Expected 5 metric samples after update, got %d", count) + } +} + +func TestPolicyStateCount_MultipleTypes(t *testing.T) { + registry := prometheus.NewRegistry() + logger := NewPrometheusLoggerWithRegistry(registry) + defer logger.UnregisterFrom(registry) + + policyTypes := []struct { + ptype string + count int + }{ + {"p", 100}, + {"p2", 50}, + {"g", 25}, + {"g1", 10}, + {"g2", 5}, + {"g3", 2}, + } + + for _, pt := range policyTypes { + logger.UpdatePolicyState(pt.ptype, pt.count) + } + + count := testutil.CollectAndCount(logger.policyStateCount) + if count != len(policyTypes) { + t.Errorf("Expected %d metric samples, got %d", len(policyTypes), count) + } +} + +func TestEnforceMetrics_EmptyOptionalFields(t *testing.T) { + registry := prometheus.NewRegistry() + options := &PrometheusLoggerOptions{ + EnforceLabels: []string{EnforceLabelSubject, EnforceLabelObject, EnforceLabelAction}, + } + logger := NewPrometheusLoggerWithOptions(registry, options) + defer logger.UnregisterFrom(registry) + + // Test with empty subject, object, action fields + entry := &LogEntry{ + IsActive: true, + EventType: EventEnforce, + StartTime: time.Now(), + Subject: "", + Object: "", + Action: "", + Domain: "domain1", + Allowed: true, + } + + logger.OnAfterEvent(entry) + + // Should not panic and should record metrics with empty strings + count := testutil.CollectAndCount(logger.enforceTotal) + if count != 1 { + t.Errorf("Expected 1 metric sample, got %d", count) + } +}