dan/per-12689-pdp-clean-health-check-logs (permitio#280)

danyi1212 · web-flow · commit 8eb57bf3b057 · 2025-07-31T17:03:22.000+03:00
* Add enforcement API logs

* Removed spamming watchdog logs

* Changed debug log serialization error
diff --git a/pdp-server/src/opa_client/allowed.rs b/pdp-server/src/opa_client/allowed.rs
@@ -1,15 +1,35 @@
 use crate::opa_client::{send_request_to_opa, ForwardingError};
 use crate::state::AppState;
+use log::{debug, info};
 use serde::{Deserialize, Serialize};
 use std::collections::HashMap;
+use std::fmt::Display;
 use utoipa::ToSchema;
 
 /// Send an allowed query to OPA and get the result
 pub async fn query_allowed(
     state: &AppState,
     query: &AllowedQuery,
 ) -> Result<AllowedResult, ForwardingError> {
-    send_request_to_opa::<AllowedResult, _>(state, "/v1/data/permit/root", query).await
+    let result =
+        send_request_to_opa::<AllowedResult, _>(state, "/v1/data/permit/root", query).await;
+    if let Ok(response) = &result {
+        if state.config.debug.unwrap_or(false) {
+            info!(
+                "permit.check(\"{user}\", \"{action}\", \"{resource}\") -> {result}",
+                user = query.user,
+                action = query.action,
+                resource = query.resource,
+                result = response.allow,
+            );
+            debug!(
+                "Query: {}\nResult: {}",
+                serde_json::to_string_pretty(query).unwrap_or("Serialization error".to_string()),
+                serde_json::to_string_pretty(response).unwrap_or("Serialization error".to_string()),
+            );
+        }
+    }
+    result
 }
 
 #[derive(Debug, Serialize, Deserialize, ToSchema, Clone, PartialEq)]
@@ -30,6 +50,12 @@ pub struct User {
     pub attributes: HashMap<String, serde_json::Value>,
 }
 
+impl Display for User {
+    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
+        write!(f, "{}", self.key)
+    }
+}
+
 #[derive(Debug, Serialize, Deserialize, ToSchema, Clone, PartialEq)]
 pub struct Resource {
     /// Type of the resource
@@ -48,6 +74,18 @@ pub struct Resource {
     pub context: HashMap<String, serde_json::Value>,
 }
 
+impl Display for Resource {
+    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
+        if let Some(key) = &self.key {
+            write!(f, "{}:{}", self.r#type, key)
+        } else if let Some(tenant) = &self.tenant {
+            write!(f, "{}@{}", self.r#type, tenant)
+        } else {
+            write!(f, "{}", self.r#type)
+        }
+    }
+}
+
 /// Authorization query parameters for the allowed endpoint
 #[derive(Debug, Serialize, Deserialize, ToSchema, Clone, PartialEq)]
 pub struct AllowedQuery {
diff --git a/pdp-server/src/opa_client/allowed_bulk.rs b/pdp-server/src/opa_client/allowed_bulk.rs
@@ -27,6 +27,31 @@ pub async fn query_allowed_bulk(
     let bulk_query = BulkAuthorizationQuery {
         checks: queries.to_vec(),
     };
-    send_request_to_opa::<BulkAuthorizationResult, _>(state, "/v1/data/permit/bulk", &bulk_query)
-        .await
+    let result = send_request_to_opa::<BulkAuthorizationResult, _>(
+        state,
+        "/v1/data/permit/bulk",
+        &bulk_query,
+    )
+    .await;
+
+    // Add debug logging if enabled
+    if let Ok(response) = &result {
+        if state.config.debug.unwrap_or(false) {
+            let allowed_count = response.allow.iter().filter(|r| r.allow).count();
+            log::info!(
+                "permit.bulk_check({} queries) -> {} allowed, {} denied",
+                queries.len(),
+                allowed_count,
+                response.allow.len() - allowed_count
+            );
+            log::debug!(
+                "Query: {}\nResult: {}",
+                serde_json::to_string_pretty(&bulk_query)
+                    .unwrap_or("Serialization error".to_string()),
+                serde_json::to_string_pretty(response).unwrap_or("Serialization error".to_string()),
+            );
+        }
+    }
+
+    result
 }
diff --git a/pdp-server/src/opa_client/authorized_users.rs b/pdp-server/src/opa_client/authorized_users.rs
@@ -24,7 +24,27 @@ pub async fn query_authorized_users(
     // Process the result to extract the nested 'result' field if it exists
     if let serde_json::Value::Object(map) = &result {
         if let Some(inner_result) = map.get("result") {
-            return Ok(serde_json::from_value(inner_result.clone())?);
+            let authorized_result: AuthorizedUsersResult =
+                serde_json::from_value(inner_result.clone())?;
+
+            // Add debug logging if enabled
+            if state.config.debug.unwrap_or(false) {
+                log::info!(
+                    "permit.authorized_users(\"{}\", \"{}\") -> {} users",
+                    query.action,
+                    query.resource,
+                    authorized_result.users.len()
+                );
+                log::debug!(
+                    "Query: {}\nResult: {}",
+                    serde_json::to_string_pretty(query)
+                        .unwrap_or("Serialization error".to_string()),
+                    serde_json::to_string_pretty(&authorized_result)
+                        .unwrap_or("Serialization error".to_string()),
+                );
+            }
+
+            return Ok(authorized_result);
         }
     }
 
@@ -40,11 +60,26 @@ pub async fn query_authorized_users(
         .clone()
         .unwrap_or_else(|| "default".to_string());
 
-    Ok(AuthorizedUsersResult {
+    let empty_result = AuthorizedUsersResult {
         resource: format!("{}:{}", query.resource.r#type, resource_key),
         tenant,
         users: HashMap::new(),
-    })
+    };
+
+    // Add debug logging if enabled
+    if state.config.debug.unwrap_or(false) {
+        log::info!(
+            "permit.authorized_users(\"{}\", \"{}\") -> 0 users",
+            query.action,
+            query.resource
+        );
+        log::debug!(
+            "Query: {}\nResult: empty",
+            serde_json::to_string_pretty(query)?
+        );
+    }
+
+    Ok(empty_result)
 }
 
 /// Query parameters for the authorized users endpoint
diff --git a/pdp-server/src/opa_client/user_permissions.rs b/pdp-server/src/opa_client/user_permissions.rs
@@ -22,7 +22,29 @@ pub async fn query_user_permissions(
 
     if let serde_json::Value::Object(result_map) = response {
         if let Some(permissions) = result_map.get("permissions") {
-            return Ok(serde_json::from_value(permissions.clone())?);
+            let result: HashMap<String, UserPermissionsResult> =
+                serde_json::from_value(permissions.clone())?;
+
+            // Add debug logging if enabled
+            if state.config.debug.unwrap_or(false) {
+                log::info!(
+                    "permit.user_permissions(\"{}\", tenants={:?}, resources={:?}, resource_types={:?}) -> {} permissions",
+                    query.user,
+                    query.tenants,
+                    query.resources,
+                    query.resource_types,
+                    result.len()
+                );
+                log::debug!(
+                    "Query: {}\nResult: {}",
+                    serde_json::to_string_pretty(query)
+                        .unwrap_or("Serialization error".to_string()),
+                    serde_json::to_string_pretty(&result)
+                        .unwrap_or("Serialization error".to_string()),
+                );
+            }
+
+            return Ok(result);
         } else {
             debug!("No 'permissions' field found in result");
         }
@@ -31,7 +53,24 @@ pub async fn query_user_permissions(
     }
 
     // If we couldn't find the permissions, return an empty map
-    Ok(HashMap::new())
+    let empty_result = HashMap::new();
+
+    // Add debug logging if enabled
+    if state.config.debug.unwrap_or(false) {
+        log::info!(
+            "permit.user_permissions(\"{}\", tenants={:?}, resources={:?}, resource_types={:?}) -> 0 permissions",
+            query.user,
+            query.tenants,
+            query.resources,
+            query.resource_types
+        );
+        log::debug!(
+            "Query: {}\nResult: empty",
+            serde_json::to_string_pretty(query)?
+        );
+    }
+
+    Ok(empty_result)
 }
 
 #[derive(Debug, Serialize, Deserialize, ToSchema, Clone, PartialEq)]
diff --git a/watchdog/src/service.rs b/watchdog/src/service.rs
@@ -1,7 +1,7 @@
 use crate::health::HealthCheck;
 use crate::stats::ServiceWatchdogStats;
 use crate::{CommandWatchdog, CommandWatchdogOptions};
-use log::{debug, error, info, warn};
+use log::{debug, error, info, log, warn};
 use std::sync::Arc;
 use std::time::Duration;
 use tokio::process::Command;
@@ -130,7 +130,12 @@ impl ServiceWatchdog {
                                 }
 
                                 if consecutive_failures > 0 {
-                                    info!(
+                                    log!(
+                                        if consecutive_failures < opt.health_check_failure_threshold / 2 {
+                                            log::Level::Debug
+                                        } else {
+                                            log::Level::Info
+                                        },
                                         "Service '{}' health restored after {} failures",
                                         command_watchdog.program_name, consecutive_failures
                                     );
@@ -146,7 +151,12 @@ impl ServiceWatchdog {
                                 stats.increment_failed_health_checks();
                                 consecutive_failures += 1;
 
-                                warn!(
+                                log!(
+                                    if consecutive_failures < opt.health_check_failure_threshold / 2 {
+                                        log::Level::Debug
+                                    } else {
+                                        log::Level::Warn
+                                    },
                                     "Service '{}' health check failed: {} (consecutive failures: {}/{})",
                                     command_watchdog.program_name,
                                     e,
