Skip to content

Commit

Permalink
Efficient logging without extra allocations
Browse files Browse the repository at this point in the history 
All logging functions now take a new `Loggable` object
that contains a `Cow<CStr>` - making it possible to log
without an extra re-allocation.
  • Loading branch information
@nyurik
nyurik committed Sep 13, 2024
1 parent b5df3da commit f7ce686
Show file tree
Hide file tree
Showing 3 changed files with 67 additions and 22 deletions.
18 changes: 9 additions & 9 deletions src/vcl/backend.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -80,7 +80,7 @@ use std::time::{SystemTime, UNIX_EPOCH};

use crate::ffi;
use crate::vcl::convert::IntoVCL;
use crate::vcl::ctx::{Ctx, Event, LogTag};
use crate::vcl::ctx::{Ctx, Event, LogTag, Loggable};
use crate::vcl::utils::{
validate_director, validate_vdir, validate_vfp_ctx, validate_vfp_entry, validate_vrt_ctx,
};
Expand Down Expand Up @@ -305,13 +305,13 @@ unsafe extern "C" fn vfp_pull<T: Transfer>(
let reader = vfe.priv1.cast::<T>().as_mut().unwrap();
match reader.read(buf) {
Err(e) => {
let msg = e.to_string();
let msg = Loggable::from(e.to_string());
// TODO: we should grow a VSL object
ffi::VSLbt(
ctx.req.as_ref().unwrap().vsl,
ffi::VSL_tag_e_SLT_Error,
// SAFETY: we assume ffi::VSLbt() will not store the pointer to the string's content
ffi::txt::from_str(msg.as_str()),
ffi::txt::from_cstr(msg.as_cstr()),
);
ffi::vfp_status_VFP_ERROR
}
Expand Down Expand Up @@ -385,7 +385,7 @@ unsafe extern "C" fn wrap_gethdrs<S: Serve<T>, T: Transfer>(
}
if beresp.proto().is_none() {
if let Err(e) = beresp.set_proto("HTTP/1.1") {
ctx.fail(&format!("{}: {e}", backend.get_type()));
ctx.fail(format!("{}: {e}", backend.get_type()));
return 1;
}
}
Expand All @@ -396,7 +396,7 @@ unsafe extern "C" fn wrap_gethdrs<S: Serve<T>, T: Transfer>(
)
.cast::<ffi::http_conn>();
if htc.is_null() {
ctx.fail(&format!("{}: insufficient workspace", backend.get_type()));
ctx.fail(format!("{}: insufficient workspace", backend.get_type()));
return -1;
}
(*htc).magic = ffi::HTTP_CONN_MAGIC;
Expand Down Expand Up @@ -429,13 +429,13 @@ unsafe extern "C" fn wrap_gethdrs<S: Serve<T>, T: Transfer>(
)
.cast::<ffi::vfp>();
if vfp.is_null() {
ctx.fail(&format!("{}: insufficient workspace", backend.get_type()));
ctx.fail(format!("{}: insufficient workspace", backend.get_type()));
return -1;
}
let Ok(t) = WS::new((*ctx.raw.bo).ws.as_mut_ptr())
.copy_bytes_with_null(&backend.get_type())
else {
ctx.fail(&format!("{}: insufficient workspace", backend.get_type()));
ctx.fail(format!("{}: insufficient workspace", backend.get_type()));
return -1;
};
(*vfp).name = t.as_ptr();
Expand All @@ -445,7 +445,7 @@ unsafe extern "C" fn wrap_gethdrs<S: Serve<T>, T: Transfer>(
(*vfp).priv1 = null();
let vfe = ffi::VFP_Push((*ctx.raw.bo).vfc, vfp);
if vfe.is_null() {
ctx.fail(&format!("{}: couldn't insert vfp", backend.get_type()));
ctx.fail(format!("{}: couldn't insert vfp", backend.get_type()));
return -1;
}
// we don't need to clean (*vfe).priv1 at the vfp level, the backend will
Expand Down Expand Up @@ -501,7 +501,7 @@ unsafe extern "C" fn wrap_getip<T: Transfer>(
.get_ip()
.and_then(|ip| ip.into_vcl(&mut ctx.ws).map_err(|e| e.into()))
.unwrap_or_else(|e| {
ctx.fail(&format!("{e}"));
ctx.fail(format!("{e}"));
null()
})
}
Expand Down
67 changes: 56 additions & 11 deletions src/vcl/ctx.rs
View file
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
//! Expose the Varnish context [`vrt_ctx`] as a Rust object
//!
use std::ffi::{c_int, c_uint, c_void, CString};
use std::borrow::Cow;
use std::ffi::{c_int, c_uint, c_void, CStr, CString};

use crate::ffi;
use crate::ffi::{
Expand Down Expand Up @@ -73,6 +74,50 @@ pub struct Ctx<'a> {
pub ws: WS<'a>,
}

/// An instance of a message that can be logged efficiently, possibly avoiding allocations.
pub struct Loggable<'a>(Cow<'a, CStr>);

impl Loggable<'_> {
pub fn as_cstr(&self) -> &CStr {
self.0.as_ref()
}
}

/// TODO: Try to show all parts of the message that are not null bytes, i.e. lossy for CString
const NULL_BYTE_ERR_MSG: &CStr = c"Internal Error: message contains null bytes and cannot be shown";

impl<'a> From<&'a str> for Loggable<'a> {
fn from(s: &'a str) -> Self {
Self(CString::new(s).map_or(Cow::Borrowed(NULL_BYTE_ERR_MSG), |s| Cow::Owned(s)))
}
}

impl<'a> From<String> for Loggable<'a> {
fn from(s: String) -> Self {
Self(CString::new(s).map_or(Cow::Borrowed(NULL_BYTE_ERR_MSG), |s| Cow::Owned(s)))
}
}

/// FIXME: Do not use because it is likely you want to either pass the owned value,
/// or the &str / &CStr. TODO: delete this one?
impl<'a> From<&'a String> for Loggable<'a> {
fn from(s: &'a String) -> Self {
s.as_str().into()
}
}

impl<'a> From<&'a CStr> for Loggable<'a> {
fn from(s: &'a CStr) -> Self {
Self(Cow::Borrowed(s))
}
}

impl<'a> From<CString> for Loggable<'a> {
fn from(s: CString) -> Self {
Self(Cow::Owned(s))
}
}

impl<'a> Ctx<'a> {
/// Wrap a raw pointer into an object we can use.
///
Expand Down Expand Up @@ -105,23 +150,25 @@ impl<'a> Ctx<'a> {
///
/// Once the control goes back to Varnish, it will see that the transaction was marked as fail
/// and will return a synthetic error to the client.
pub fn fail(&mut self, msg: &str) -> u8 {
// not great, we have to copy the string to add a null character
let c_cstring = CString::new(msg).unwrap();
pub fn fail<'b, T: Into<Loggable<'b>>>(&mut self, msg: T) -> u8 {
unsafe {
VRT_fail(self.raw, c"%s".as_ptr(), c_cstring.as_ptr());
VRT_fail(self.raw, c"%s".as_ptr(), msg.into().0.as_ptr());
}
0
}

/// Log a message, attached to the current context
pub fn log(&mut self, logtag: LogTag, msg: &str) {
pub fn log<'b, T: Into<Loggable<'b>>>(&mut self, logtag: LogTag, msg: T) {
unsafe {
let vsl = self.raw.vsl;
if vsl.is_null() {
log(logtag, msg);
} else {
ffi::VSLbt(vsl, logtag.into_u32(), ffi::txt::from_str(msg));
ffi::VSLbt(
vsl,
logtag.into_u32(),
ffi::txt::from_cstr(msg.into().as_cstr()),
);
}
}
}
Expand Down Expand Up @@ -220,15 +267,13 @@ impl Event {
}
}

// TODO: avoid Stringification
pub fn log(logtag: LogTag, msg: &str) {
pub fn log<'b, T: Into<Loggable<'b>>>(logtag: LogTag, msg: T) {
unsafe {
let c_cstring = CString::new(msg).unwrap();
ffi::VSL(
logtag.into_u32(),
ffi::vxids { vxid: 0 },
c"%s".as_ptr(),
c_cstring.as_ptr().cast::<u8>(),
msg.into().0.as_ptr(),
);
}
}
4 changes: 2 additions & 2 deletions src/vmodtool-rs.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -86,7 +86,7 @@ def rustfuncBody(self, vcc, t):
rustFuncArgs(self, t)
print('''\t) {
\t\tOk(o) => { *objp = Box::into_raw(Box::new(o)); },
\t\tErr(e) => { _ctx.fail(&e.to_string()); },
\t\tErr(e) => { _ctx.fail(e.to_string()); },
\t}''')
elif t == "fini":
print("\tdrop(Box::from_raw(*objp));")
Expand All @@ -96,7 +96,7 @@ def rustfuncBody(self, vcc, t):
else:
print("\tcrate::{name}(".format(name=self.cname()))
rustFuncArgs(self, t)
print("\t).into_result().and_then(|v| v.into_vcl(&mut _ctx.ws)).unwrap_or_else(|e| {{ _ctx.fail(&e); <{0}>::vcl_default() }})".format(self.retval.ct if self.retval.vt != "VOID" else "()"))
print("\t).into_result().and_then(|v| v.into_vcl(&mut _ctx.ws)).unwrap_or_else(|e| {{ _ctx.fail(e); <{0}>::vcl_default() }})".format(self.retval.ct if self.retval.vt != "VOID" else "()"))
print("}")


Expand Down

0 comments on commit f7ce686

Please sign in to comment.