up

src/Policy/StellaOps.Policy.Engine/Services/PolicyRuntimeEvaluationService.cs

@@ -1,4 +1,5 @@
 using System.Collections.Immutable;
+using System.Diagnostics;
 using System.Security.Cryptography;
 using System.Text;
 using System.Text.Json;
@@ -6,6 +7,7 @@ using Microsoft.Extensions.Logging;
 using StellaOps.Policy.Engine.Caching;
 using StellaOps.Policy.Engine.Domain;
 using StellaOps.Policy.Engine.Evaluation;
+using StellaOps.Policy.Engine.Telemetry;
 using StellaOps.PolicyDsl;
 
 namespace StellaOps.Policy.Engine.Services;
@@ -88,6 +90,12 @@ internal sealed class PolicyRuntimeEvaluationService
     {
         ArgumentNullException.ThrowIfNull(request);
 
+        using var activity = PolicyEngineTelemetry.StartEvaluateActivity(
+            request.TenantId, request.PackId, runId: null);
+        activity?.SetTag("policy.version", request.Version);
+        activity?.SetTag("subject.purl", request.SubjectPurl);
+        activity?.SetTag("advisory.id", request.AdvisoryId);
+
         var startTimestamp = _timeProvider.GetTimestamp();
         var evaluationTimestamp = request.EvaluationTimestamp ?? _timeProvider.GetUtcNow();
 
@@ -97,6 +105,9 @@ internal sealed class PolicyRuntimeEvaluationService
 
         if (bundle is null)
         {
+            PolicyEngineTelemetry.RecordError("evaluation", request.TenantId);
+            PolicyEngineTelemetry.RecordEvaluationFailure(request.TenantId, request.PackId, "bundle_not_found");
+            activity?.SetStatus(ActivityStatusCode.Error, "Bundle not found");
             throw new InvalidOperationException(
                 $"Policy bundle not found for pack '{request.PackId}' version {request.Version}.");
         }
@@ -113,6 +124,12 @@ internal sealed class PolicyRuntimeEvaluationService
             if (cacheResult.CacheHit && cacheResult.Entry is not null)
             {
                 var duration = GetElapsedMilliseconds(startTimestamp);
+                var durationSeconds = duration / 1000.0;
+                PolicyEngineTelemetry.RecordEvaluationLatency(durationSeconds, request.TenantId, request.PackId);
+                PolicyEngineTelemetry.RecordEvaluation(request.TenantId, request.PackId, "cached");
+                activity?.SetTag("cache.hit", true);
+                activity?.SetTag("cache.source", cacheResult.Source.ToString());
+                activity?.SetStatus(ActivityStatusCode.Ok);
                 _logger.LogDebug(
                     "Cache hit for evaluation {PackId}@{Version} subject {Subject} from {Source}",
                     request.PackId, request.Version, request.SubjectPurl, cacheResult.Source);
@@ -122,12 +139,17 @@ internal sealed class PolicyRuntimeEvaluationService
             }
         }
 
+        activity?.SetTag("cache.hit", false);
+
         // Cache miss - perform evaluation
-        var document = DeserializeCompiledPolicy(bundle.Payload);
+        var document = bundle.CompiledDocument;
         if (document is null)
         {
+            PolicyEngineTelemetry.RecordError("evaluation", request.TenantId);
+            PolicyEngineTelemetry.RecordEvaluationFailure(request.TenantId, request.PackId, "document_not_found");
+            activity?.SetStatus(ActivityStatusCode.Error, "Document not found");
             throw new InvalidOperationException(
-                $"Failed to deserialize compiled policy for pack '{request.PackId}' version {request.Version}.");
+                $"Compiled policy document not found for pack '{request.PackId}' version {request.Version}.");
         }
 
         var context = new PolicyEvaluationContext(
@@ -162,6 +184,21 @@ internal sealed class PolicyRuntimeEvaluationService
         await _cache.SetAsync(cacheKey, cacheEntry, cancellationToken).ConfigureAwait(false);
 
         var evalDuration = GetElapsedMilliseconds(startTimestamp);
+        var evalDurationSeconds = evalDuration / 1000.0;
+
+        // Record metrics
+        PolicyEngineTelemetry.RecordEvaluationLatency(evalDurationSeconds, request.TenantId, request.PackId);
+        PolicyEngineTelemetry.RecordEvaluation(request.TenantId, request.PackId, "full");
+        if (!string.IsNullOrEmpty(result.RuleName))
+        {
+            PolicyEngineTelemetry.RecordRuleFired(request.PackId, result.RuleName);
+        }
+
+        activity?.SetTag("evaluation.status", result.Status);
+        activity?.SetTag("evaluation.rule", result.RuleName ?? "none");
+        activity?.SetTag("evaluation.duration_ms", evalDuration);
+        activity?.SetStatus(ActivityStatusCode.Ok);
+
         _logger.LogDebug(
             "Evaluated {PackId}@{Version} subject {Subject} in {Duration}ms - {Status}",
             request.PackId, request.Version, request.SubjectPurl, evalDuration, result.Status);
@@ -195,7 +232,13 @@ internal sealed class PolicyRuntimeEvaluationService
             return Array.Empty<RuntimeEvaluationResponse>();
         }
 
+        using var activity = PolicyEngineTelemetry.ActivitySource.StartActivity("policy.evaluate_batch", ActivityKind.Internal);
+        activity?.SetTag("batch.size", requests.Count);
+
+        var batchStartTimestamp = _timeProvider.GetTimestamp();
         var results = new List<RuntimeEvaluationResponse>(requests.Count);
+        var cacheHits = 0;
+        var cacheMisses = 0;
 
         // Group by pack/version for bundle loading efficiency
         var groups = requests.GroupBy(r => (r.PackId, r.Version));
@@ -210,6 +253,7 @@ internal sealed class PolicyRuntimeEvaluationService
             {
                 foreach (var request in group)
                 {
+                    PolicyEngineTelemetry.RecordEvaluationFailure(request.TenantId, packId, "bundle_not_found");
                     _logger.LogWarning(
                         "Policy bundle not found for pack '{PackId}' version {Version}, skipping evaluation",
                         packId, version);
@@ -217,11 +261,12 @@ internal sealed class PolicyRuntimeEvaluationService
                 continue;
             }
 
-            var document = DeserializeCompiledPolicy(bundle.Payload);
+            var document = bundle.CompiledDocument;
             if (document is null)
             {
+                PolicyEngineTelemetry.RecordEvaluationFailure("default", packId, "document_not_found");
                 _logger.LogWarning(
-                    "Failed to deserialize policy bundle for pack '{PackId}' version {Version}",
+                    "Compiled policy document not found for pack '{PackId}' version {Version}",
                     packId, version);
                 continue;
             }
@@ -249,6 +294,8 @@ internal sealed class PolicyRuntimeEvaluationService
                 {
                     var response = CreateResponseFromCache(request, bundle.Digest, entry, CacheSource.InMemory, 0);
                     results.Add(response);
+                    cacheHits++;
+                    PolicyEngineTelemetry.RecordEvaluation(request.TenantId, packId, "cached");
                 }
                 else
                 {
@@ -294,6 +341,15 @@ internal sealed class PolicyRuntimeEvaluationService
                     expiresAt);
 
                 entriesToCache[key] = cacheEntry;
+                cacheMisses++;
+
+                // Record metrics for each evaluation
+                PolicyEngineTelemetry.RecordEvaluationLatency(duration / 1000.0, request.TenantId, packId);
+                PolicyEngineTelemetry.RecordEvaluation(request.TenantId, packId, "full");
+                if (!string.IsNullOrEmpty(result.RuleName))
+                {
+                    PolicyEngineTelemetry.RecordRuleFired(packId, result.RuleName);
+                }
 
                 results.Add(new RuntimeEvaluationResponse(
                     request.PackId,
@@ -319,6 +375,17 @@ internal sealed class PolicyRuntimeEvaluationService
             }
         }
 
+        // Record batch-level metrics
+        var batchDuration = GetElapsedMilliseconds(batchStartTimestamp);
+        activity?.SetTag("batch.cache_hits", cacheHits);
+        activity?.SetTag("batch.cache_misses", cacheMisses);
+        activity?.SetTag("batch.duration_ms", batchDuration);
+        activity?.SetStatus(ActivityStatusCode.Ok);
+
+        _logger.LogDebug(
+            "Batch evaluation completed: {Total} subjects, {CacheHits} cache hits, {CacheMisses} evaluated in {Duration}ms",
+            requests.Count, cacheHits, cacheMisses, batchDuration);
+
         return results;
     }
 
@@ -398,24 +465,6 @@ internal sealed class PolicyRuntimeEvaluationService
         return Convert.ToHexString(hash);
     }
 
-    private static PolicyIrDocument? DeserializeCompiledPolicy(ImmutableArray<byte> payload)
-    {
-        if (payload.IsDefaultOrEmpty)
-        {
-            return null;
-        }
-
-        try
-        {
-            var json = Encoding.UTF8.GetString(payload.AsSpan());
-            return JsonSerializer.Deserialize<PolicyIrDocument>(json);
-        }
-        catch
-        {
-            return null;
-        }
-    }
-
     private long GetElapsedMilliseconds(long startTimestamp)
     {
         var elapsed = _timeProvider.GetElapsedTime(startTimestamp);