use std::{
cell::RefCell, collections::BTreeMap, fmt::Debug, marker::PhantomData, rc::Rc, sync::Arc,
time::Duration,
};
use std::time::Instant;
use trustfall::{
FieldValue,
provider::{
Adapter, AsVertex, ContextIterator, ContextOutcomeIterator, EdgeParameters, Eid,
ResolveEdgeInfo, ResolveInfo, VertexInfo, VertexIterator, Vid,
},
};
#[derive(Clone)]
pub struct ExpHistogram {
buckets: [u32; 16],
}
pub const HIST_BOUNDARIES: [u64; 16] = [
100,
300,
1000,
3000,
10000,
30000,
100000,
300000,
1000000,
3000000,
10000000,
30000000,
100000000,
300000000,
1000000000,
u64::MAX,
];
impl ExpHistogram {
pub fn new() -> ExpHistogram {
ExpHistogram { buckets: [0; 16] }
}
pub fn add(&mut self, num: u64) {
for (i, lim) in HIST_BOUNDARIES.iter().enumerate() {
if num <= *lim {
self.buckets[i] = self.buckets[i].saturating_add(1);
break;
}
}
}
pub fn boundaries(&self) -> &'static [u64; 16] {
&HIST_BOUNDARIES
}
pub fn count(&self) -> u32 {
self.buckets()
.iter()
.copied()
.fold(0, |acc, num| acc.saturating_add(num))
}
pub fn buckets(&self) -> &[u32; 16] {
&self.buckets
}
}
impl Debug for ExpHistogram {
fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
write!(
f,
"ExpHistogram {{ buckets: {:?}, count: {:?} }}",
self.buckets,
self.count()
)
}
}
impl Default for ExpHistogram {
fn default() -> Self {
Self::new()
}
}
#[derive(Debug, Clone)]
pub struct Summary {
hist: ExpHistogram,
min: Duration,
max: Duration,
sum: Duration,
}
impl Summary {
pub fn new(duration: Duration) -> Summary {
let mut hist = ExpHistogram::new();
hist.add(duration.as_nanos() as u64);
Summary {
hist,
min: duration,
max: duration,
sum: duration,
}
}
pub fn update(&mut self, duration: Duration) {
self.hist.add(duration.as_nanos() as u64);
self.min = self.min.min(duration);
self.max = self.max.max(duration);
self.sum = self.sum.saturating_add(duration);
}
pub fn count(&self) -> u32 {
self.hist.count()
}
pub fn total(&self) -> Duration {
self.sum
}
pub fn min(&self) -> Duration {
self.min
}
pub fn max(&self) -> Duration {
self.max
}
pub fn histogram(&self) -> &ExpHistogram {
&self.hist
}
pub fn mean(&self) -> Duration {
self.sum / self.count()
}
}
#[derive(Debug, Clone)]
pub struct Tracer {
pub calls: BTreeMap<FunctionCall, Summary>,
last_input_duration: Option<Duration>,
}
impl Tracer {
pub fn new() -> Self {
Self {
calls: BTreeMap::new(),
last_input_duration: None,
}
}
pub fn record_time(&mut self, call_id: &FunctionCall, duration: Duration) {
if let Some(summary) = self.calls.get_mut(call_id) {
summary.update(duration);
} else {
self.calls.insert(call_id.clone(), Summary::new(duration));
}
}
pub fn record_last_input_duration(&mut self, duration: Duration) {
self.last_input_duration = Some(duration);
}
pub fn get_last_input_duration(&self) -> Duration {
self.last_input_duration.unwrap()
}
}
impl Default for Tracer {
fn default() -> Self {
Self::new()
}
}
#[derive(Debug, Clone, PartialEq, Eq, PartialOrd, Ord)]
pub enum FunctionCall {
ResolveProperty(Vid, Arc<str>, Arc<str>), ResolveNeighbors(Vid, Arc<str>, Eid), ResolveNeighborsInner(Vid, Arc<str>, Eid), ResolveCoercion(Vid, Arc<str>, Arc<str>), }
struct PerfSpanIter<I, T, F>
where
I: Iterator<Item = T>,
F: Fn(T, Duration) -> T,
{
inner: I,
post_action: F,
}
impl<I, T, F> Iterator for PerfSpanIter<I, T, F>
where
I: Iterator<Item = T>,
F: Fn(T, Duration) -> T,
{
type Item = T;
fn next(&mut self) -> Option<Self::Item> {
let start = Instant::now();
let item = self.inner.next();
let time = start.elapsed();
match item {
Some(item) => Some((self.post_action)(item, time)),
None => None,
}
}
fn size_hint(&self) -> (usize, Option<usize>) {
self.inner.size_hint()
}
}
fn make_iter_with_perf_span<I, T, F>(inner: I, post_action: F) -> PerfSpanIter<I, T, F>
where
I: Iterator<Item = T>,
F: Fn(T, Duration) -> T,
{
PerfSpanIter { inner, post_action }
}
#[derive(Debug, Clone)]
pub struct TracingAdapter<'vertex, AdapterT>
where
AdapterT: Adapter<'vertex>,
AdapterT::Vertex: Debug + Clone + 'vertex,
{
pub tracer: Rc<RefCell<Tracer>>,
inner: AdapterT,
_phantom: PhantomData<&'vertex ()>,
}
impl<'vertex, AdapterT> TracingAdapter<'vertex, AdapterT>
where
AdapterT: Adapter<'vertex>,
AdapterT::Vertex: Debug + Clone + 'vertex,
{
pub fn new(adapter: AdapterT) -> Self {
Self {
tracer: Rc::new(RefCell::new(Tracer::new())),
inner: adapter,
_phantom: PhantomData,
}
}
pub fn finish(&self) -> Tracer {
let trace_ref = self.tracer.borrow_mut();
let new_trace = Tracer::new();
drop(trace_ref);
self.tracer.replace(new_trace)
}
}
impl<'vertex, AdapterT> Adapter<'vertex> for TracingAdapter<'vertex, AdapterT>
where
AdapterT: Adapter<'vertex> + 'vertex,
AdapterT::Vertex: Debug + Clone + 'vertex,
{
type Vertex = AdapterT::Vertex;
fn resolve_starting_vertices(
&self,
edge_name: &Arc<str>,
parameters: &EdgeParameters,
resolve_info: &ResolveInfo,
) -> VertexIterator<'vertex, Self::Vertex> {
self.inner
.resolve_starting_vertices(edge_name, parameters, resolve_info)
}
fn resolve_property<V: AsVertex<Self::Vertex> + 'vertex>(
&self,
contexts: ContextIterator<'vertex, V>,
type_name: &Arc<str>,
property_name: &Arc<str>,
resolve_info: &ResolveInfo,
) -> ContextOutcomeIterator<'vertex, V, FieldValue> {
let call_id = FunctionCall::ResolveProperty(
resolve_info.vid(),
type_name.clone(),
property_name.clone(),
);
let tracer_ref = self.tracer.clone();
let wrapped_contexts = Box::new(make_iter_with_perf_span(
contexts,
move |context, duration| {
tracer_ref.borrow_mut().record_last_input_duration(duration);
context
},
));
let inner_iter =
self.inner
.resolve_property(wrapped_contexts, type_name, property_name, resolve_info);
let tracer_ref_2 = self.tracer.clone();
Box::new(make_iter_with_perf_span(
inner_iter,
move |(context, value), duration| {
let input_duration = tracer_ref_2.borrow().get_last_input_duration();
tracer_ref_2
.borrow_mut()
.record_time(&call_id, duration - input_duration);
(context, value)
},
))
}
fn resolve_neighbors<V: AsVertex<Self::Vertex> + 'vertex>(
&self,
contexts: ContextIterator<'vertex, V>,
type_name: &Arc<str>,
edge_name: &Arc<str>,
parameters: &EdgeParameters,
resolve_info: &ResolveEdgeInfo,
) -> ContextOutcomeIterator<'vertex, V, VertexIterator<'vertex, Self::Vertex>> {
let call_id = FunctionCall::ResolveNeighbors(
resolve_info.origin_vid(),
type_name.clone(),
resolve_info.eid(),
);
let call_id_inner = FunctionCall::ResolveNeighborsInner(
resolve_info.origin_vid(),
type_name.clone(),
resolve_info.eid(),
);
let tracer_ref = self.tracer.clone();
let wrapped_contexts = Box::new(make_iter_with_perf_span(
contexts,
move |context, duration| {
tracer_ref.borrow_mut().record_last_input_duration(duration);
context
},
));
let inner_iter = self.inner.resolve_neighbors(
wrapped_contexts,
type_name,
edge_name,
parameters,
resolve_info,
);
let tracer_ref_2 = self.tracer.clone();
Box::new(make_iter_with_perf_span(
inner_iter,
move |(context, neighbor_iter), duration| {
let input_duration = tracer_ref_2.borrow().get_last_input_duration();
tracer_ref_2
.borrow_mut()
.record_time(&call_id, duration - input_duration);
let tracer_ref_3 = tracer_ref_2.clone();
let value = call_id_inner.clone();
let tapped_neighbor_iter = Box::new(make_iter_with_perf_span(
neighbor_iter,
move |vertex, duration| {
tracer_ref_3.borrow_mut().record_time(&value, duration);
vertex
},
));
(context, tapped_neighbor_iter)
},
))
}
fn resolve_coercion<V: AsVertex<Self::Vertex> + 'vertex>(
&self,
contexts: ContextIterator<'vertex, V>,
type_name: &Arc<str>,
coerce_to_type: &Arc<str>,
resolve_info: &ResolveInfo,
) -> ContextOutcomeIterator<'vertex, V, bool> {
let call_id = FunctionCall::ResolveCoercion(
resolve_info.vid(),
type_name.clone(),
coerce_to_type.clone(),
);
let tracer_ref = self.tracer.clone();
let wrapped_contexts = Box::new(make_iter_with_perf_span(
contexts,
move |context, duration| {
tracer_ref.borrow_mut().record_last_input_duration(duration);
context
},
));
let inner_iter =
self.inner
.resolve_coercion(wrapped_contexts, type_name, coerce_to_type, resolve_info);
let tracer_ref_2 = self.tracer.clone();
Box::new(make_iter_with_perf_span(
inner_iter,
move |(context, can_coerce), duration| {
let input_duration = tracer_ref_2.borrow().get_last_input_duration();
tracer_ref_2
.borrow_mut()
.record_time(&call_id, duration - input_duration);
(context, can_coerce)
},
))
}
}