Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

logging enhancements #57

Merged
merged 3 commits into from
Jun 20, 2024
Merged

logging enhancements #57

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
f2138c8
logging enhancements
eguzki Jun 14, 2024
f0bd703
logging: context in the beginning of the log line
eguzki Jun 20, 2024
add6f73
fix tests for the new log format
eguzki Jun 20, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion src/filter.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -31,7 +31,7 @@ extern "C" fn start() {
proxy_wasm::hostcalls::log(LogLevel::Critical, &panic_info.to_string()).unwrap();
}));
proxy_wasm::set_root_context(|context_id| -> Box<dyn RootContext> {
info!("set_root_context #{}", context_id);
info!("#{} set_root_context", context_id);
Box::new(FilterRoot {
context_id,
config: Rc::new(FilterConfig::new()),
Expand Down
79 changes: 47 additions & 32 deletions src/filter/http_context.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -8,7 +8,7 @@ use crate::envoy::{
};
use crate::filter::http_context::TracingHeader::{Baggage, Traceparent, Tracestate};
use crate::utils::tokenize_with_escaping;
use log::{debug, info, warn};
use log::{debug, warn};
use protobuf::Message;
use proxy_wasm::traits::{Context, HttpContext};
use proxy_wasm::types::{Action, Bytes};
Expand Down Expand Up @@ -63,7 +63,10 @@ impl Filter {
fn process_rate_limit_policy(&self, rlp: &RateLimitPolicy) -> Action {
let descriptors = self.build_descriptors(rlp);
if descriptors.is_empty() {
debug!("[context_id: {}] empty descriptors", self.context_id);
debug!(
"#{} process_rate_limit_policy: empty descriptors",
self.context_id
);
return Action::Continue;
}

Expand All @@ -89,7 +92,10 @@ impl Filter {
Duration::from_secs(5),
) {
Ok(call_id) => {
info!("Initiated gRPC call (id# {}) to Limitador", call_id);
debug!(
"#{} initiated gRPC call (id# {}) to Limitador",
self.context_id, call_id
);
Action::Pause
}
Err(e) => {
Expand Down Expand Up @@ -137,28 +143,29 @@ impl Filter {
let attribute_path = tokenize_with_escaping(&p_e.selector, '.', '\\');
// convert a Vec<String> to Vec<&str>
// attribute_path.iter().map(AsRef::as_ref).collect()
let attribute_value =
match self.get_property(attribute_path.iter().map(AsRef::as_ref).collect()) {
None => {
let attribute_value = match self
.get_property(attribute_path.iter().map(AsRef::as_ref).collect())
{
None => {
debug!(
"#{} pattern_expression_applies: selector not found: {}, defaulting to ``",
self.context_id, p_e.selector
);
"".to_string()
}
// TODO(eastizle): not all fields are strings
// https://www.envoyproxy.io/docs/envoy/latest/intro/arch_overview/advanced/attributes
Some(attribute_bytes) => match String::from_utf8(attribute_bytes) {
Err(e) => {
debug!(
"[context_id: {}]: selector not found: {}, defaulting to ``",
self.context_id, p_e.selector
);
"".to_string()
}
// TODO(eastizle): not all fields are strings
// https://www.envoyproxy.io/docs/envoy/latest/intro/arch_overview/advanced/attributes
Some(attribute_bytes) => match String::from_utf8(attribute_bytes) {
Err(e) => {
debug!(
"[context_id: {}]: failed to parse selector value: {}, error: {}",
"#{} pattern_expression_applies: failed to parse selector value: {}, error: {}",
self.context_id, p_e.selector, e
);
return false;
}
Ok(attribute_value) => attribute_value,
},
};
return false;
}
Ok(attribute_value) => attribute_value,
},
};
p_e.operator
.eval(p_e.value.as_str(), attribute_value.as_str())
}
Expand Down Expand Up @@ -189,7 +196,7 @@ impl Filter {
{
None => {
debug!(
"[context_id: {}]: selector not found: {}",
"#{} build_single_descriptor: selector not found: {}",
self.context_id, selector_item.selector
);
match &selector_item.default {
Expand All @@ -202,8 +209,9 @@ impl Filter {
Some(attribute_bytes) => match String::from_utf8(attribute_bytes) {
Err(e) => {
debug!(
"[context_id: {}]: failed to parse selector value: {}, error: {}",
self.context_id, selector_item.selector, e);
"#{} build_single_descriptor: failed to parse selector value: {}, error: {}",
self.context_id, selector_item.selector, e
);
return None;
}
Ok(attribute_value) => attribute_value,
Expand Down Expand Up @@ -234,7 +242,7 @@ impl Filter {

impl HttpContext for Filter {
fn on_http_request_headers(&mut self, _: usize, _: bool) -> Action {
info!("on_http_request_headers #{}", self.context_id);
debug!("#{} on_http_request_headers", self.context_id);

for header in TracingHeader::all() {
if let Some(value) = self.get_http_request_header_bytes(header.as_str()) {
Expand All @@ -248,29 +256,36 @@ impl HttpContext for Filter {
.get_longest_match_policy(self.request_authority().as_str())
{
None => {
info!(
"context #{}: Allowing request to pass because zero descriptors generated",
debug!(
"#{} allowing request to pass because zero descriptors generated",
self.context_id
);
Action::Continue
}
Some(rlp) => self.process_rate_limit_policy(rlp),
Some(rlp) => {
debug!("#{} ratelimitpolicy selected {}", self.context_id, rlp.name);
self.process_rate_limit_policy(rlp)
}
}
}

fn on_http_response_headers(&mut self, _num_headers: usize, _end_of_stream: bool) -> Action {
debug!("on_http_response_headers #{}", self.context_id);
debug!("#{} on_http_response_headers", self.context_id);
for (name, value) in &self.response_headers_to_add {
self.add_http_response_header(name, value);
}
Action::Continue
}

fn on_log(&mut self) {
debug!("#{} completed.", self.context_id);
}
}

impl Context for Filter {
fn on_grpc_call_response(&mut self, token_id: u32, status_code: u32, resp_size: usize) {
info!(
"on_grpc_call_response #{}: received gRPC call response: token: {token_id}, status: {status_code}",
debug!(
"#{} on_grpc_call_response: received gRPC call response: token: {token_id}, status: {status_code}",
self.context_id
);

Expand Down
10 changes: 5 additions & 5 deletions src/filter/root_context.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,7 +1,7 @@
use crate::configuration::{FilterConfig, PluginConfiguration};
use crate::filter::http_context::Filter;
use const_format::formatcp;
use log::{info, warn};
use log::{debug, info, warn};
use proxy_wasm::traits::{Context, HttpContext, RootContext};
use proxy_wasm::types::ContextType;
use std::rc::Rc;
Expand All @@ -28,14 +28,14 @@ impl RootContext for FilterRoot {
);

info!(
"{} {} root-context #{}: VM started",
WASM_SHIM_HEADER, full_version, self.context_id
"#{} {} {}: VM started",
self.context_id, WASM_SHIM_HEADER, full_version
);
true
}

fn create_http_context(&self, context_id: u32) -> Option<Box<dyn HttpContext>> {
info!("create_http_context #{}", context_id);
debug!("#{} create_http_context", context_id);
Some(Box::new(Filter {
context_id,
config: Rc::clone(&self.config),
Expand All @@ -45,7 +45,7 @@ impl RootContext for FilterRoot {
}

fn on_configure(&mut self, _config_size: usize) -> bool {
info!("on_configure #{}", self.context_id);
info!("#{} on_configure", self.context_id);
let configuration: Vec<u8> = match self.get_plugin_configuration() {
Some(c) => c,
None => return false,
Expand Down
Loading
Loading