From 86ed415e8ab5e36390ad4d6077eb547e647a2e80 Mon Sep 17 00:00:00 2001
From: Adil Hafeez <adil.hafeez@gmail.com>
Date: Thu, 30 Jan 2025 15:11:04 -0800
Subject: [PATCH] more logging improvements

---
 crates/llm_gateway/src/stream_context.rs    |  3 +--
 crates/prompt_gateway/src/http_context.rs   |  7 ++++---
 crates/prompt_gateway/src/stream_context.rs | 22 +++++++++++----------
 3 files changed, 17 insertions(+), 15 deletions(-)

diff --git a/crates/llm_gateway/src/stream_context.rs b/crates/llm_gateway/src/stream_context.rs
index 68a5a67c..12595409 100644
--- a/crates/llm_gateway/src/stream_context.rs
+++ b/crates/llm_gateway/src/stream_context.rs
@@ -87,7 +87,7 @@ impl StreamContext {
         ));
 
         debug!(
-            "llm provider hint: {:?}, selected llm: {}",
+            "request received: llm provider hint: {:?}, selected llm: {}",
             self.get_http_request_header(ARCH_PROVIDER_HINT_HEADER),
             self.llm_provider.as_ref().unwrap().name
         );
@@ -177,7 +177,6 @@ impl HttpContext for StreamContext {
     // the lifecycle of the http request and response.
     fn on_http_request_headers(&mut self, _num_headers: usize, _end_of_stream: bool) -> Action {
         let request_path = self.get_http_request_header(":path").unwrap_or_default();
-        debug!("request_path: {}", request_path);
         self.select_llm_provider();
 
         // if endpoint is not set then use provider name as routing header so envoy can resolve the cluster name
diff --git a/crates/prompt_gateway/src/http_context.rs b/crates/prompt_gateway/src/http_context.rs
index 58a725b4..9b8fc0ce 100644
--- a/crates/prompt_gateway/src/http_context.rs
+++ b/crates/prompt_gateway/src/http_context.rs
@@ -78,8 +78,8 @@ impl HttpContext for StreamContext {
             }
         };
 
-        debug!(
-            "developer => archgw request body: {}",
+        trace!(
+            "request body: {}",
             String::from_utf8_lossy(&body_bytes)
         );
 
@@ -152,7 +152,8 @@ impl HttpContext for StreamContext {
             }
         };
 
-        debug!("archgw => modelserver request body: {}", json_data);
+        debug!("sending request to model server");
+        trace!("request body: {}", json_data);
 
         let mut headers = vec![
             (ARCH_UPSTREAM_HOST_HEADER, MODEL_SERVER_NAME),
diff --git a/crates/prompt_gateway/src/stream_context.rs b/crates/prompt_gateway/src/stream_context.rs
index a0cc7a88..178e6fcc 100644
--- a/crates/prompt_gateway/src/stream_context.rs
+++ b/crates/prompt_gateway/src/stream_context.rs
@@ -14,7 +14,7 @@ use common::http::{CallArgs, Client};
 use common::stats::Gauge;
 use derivative::Derivative;
 use http::StatusCode;
-use log::{debug, warn};
+use log::{debug, trace, warn};
 use proxy_wasm::traits::*;
 use serde_yaml::Value;
 use std::cell::RefCell;
@@ -125,7 +125,8 @@ impl StreamContext {
         mut callout_context: StreamCallContext,
     ) {
         let body_str = String::from_utf8(body).unwrap();
-        debug!("archgw <= modelserver response body: {}", body_str);
+        debug!("model server response received");
+        trace!("response body: {}", body_str);
 
         let model_server_response: ModelServerResponse = match serde_json::from_str(&body_str) {
             Ok(arch_fc_response) => arch_fc_response,
@@ -343,10 +344,9 @@ impl StreamContext {
             Duration::from_secs(5),
         );
 
-        debug!(
-            "archgw => developer api call endpoint: {}, path: {}, body: {}",
-            endpoint.name.as_str(),
-            path,
+        debug!("dispatching api call to developer endpoint: {}, path: {}", endpoint.name, path);
+        trace!(
+            "request body: {}",
             tool_params_json_str
         );
 
@@ -363,7 +363,8 @@ impl StreamContext {
         let http_status = self
             .get_http_call_response_header(":status")
             .unwrap_or(StatusCode::OK.as_str().to_string());
-        if http_status != StatusCode::OK.as_str() {
+          debug!("api call response received: status code: {}", http_status);
+          if http_status != StatusCode::OK.as_str() {
             warn!(
                 "api server responded with non 2xx status code: {}",
                 http_status
@@ -379,8 +380,8 @@ impl StreamContext {
             );
         }
         self.tool_call_response = Some(String::from_utf8(body).unwrap());
-        debug!(
-            "archgw <= api call response: {}",
+        trace!(
+            "response body: {}",
             self.tool_call_response.as_ref().unwrap()
         );
 
@@ -430,7 +431,8 @@ impl StreamContext {
                 return self.send_server_error(ServerError::Serialization(e), None);
             }
         };
-        debug!("archgw => llm request: {}", llm_request_str);
+        debug!("sending request to upstream llm");
+        trace!("request body: {}", llm_request_str);
 
         self.start_upstream_llm_request_time = SystemTime::now()
             .duration_since(UNIX_EPOCH)