Fix logging

This commit is contained in:
William Brown 2018-12-29 19:56:03 +10:00
parent e26081dad5
commit b888d9036f
8 changed files with 138 additions and 34 deletions

View file

@ -1,9 +1,11 @@
use actix::prelude::*; use actix::prelude::*;
use std::time::Duration; use std::time::Duration;
use std::time::SystemTime; use std::time::SystemTime;
use std::fmt;
use chrono::offset::Utc; use chrono::offset::Utc;
use chrono::DateTime; use chrono::DateTime;
use serde_json;
#[macro_export] #[macro_export]
macro_rules! audit_log { macro_rules! audit_log {
@ -43,14 +45,12 @@ macro_rules! audit_segment {
let end = Instant::now(); let end = Instant::now();
let diff = end.duration_since(start); let diff = end.duration_since(start);
println!("diff: {:?}", diff);
// Return the result. Hope this works! // Return the result. Hope this works!
return r; r
}}; }};
} }
#[derive(Debug, Serialize, Deserialize)] #[derive(Serialize, Deserialize)]
enum AuditEvent { enum AuditEvent {
log(AuditLog), log(AuditLog),
scope(AuditScope), scope(AuditScope),
@ -65,7 +65,7 @@ struct AuditLog {
// This structure tracks and event lifecycle, and is eventually // This structure tracks and event lifecycle, and is eventually
// sent to the logging system where it's structured and written // sent to the logging system where it's structured and written
// out to the current logging BE. // out to the current logging BE.
#[derive(Debug, Serialize, Deserialize)] #[derive(Serialize, Deserialize)]
pub struct AuditScope { pub struct AuditScope {
// vec of start/end points of various parts of the event? // vec of start/end points of various parts of the event?
// We probably need some functions for this. Is there a way in rust // We probably need some functions for this. Is there a way in rust
@ -81,6 +81,13 @@ impl Message for AuditScope {
type Result = (); type Result = ();
} }
impl fmt::Display for AuditScope {
fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
let d = serde_json::to_string_pretty(self).unwrap();
write!(f, "{}", d)
}
}
impl AuditScope { impl AuditScope {
pub fn new(name: &str) -> Self { pub fn new(name: &str) -> Self {
let t_now = SystemTime::now(); let t_now = SystemTime::now();

View file

@ -204,6 +204,29 @@ impl Backend {
}) })
} }
/// Given a filter, assert some condition exists.
/// Basically, this is a specialised case of search, where we don't need to
/// load any candidates if they match. This is heavily used in uuid
/// refint and attr uniqueness.
pub fn exists(&self, au: &mut AuditScope, filt: &Filter) -> Result<bool, BackendError> {
let r = self.search(au, filt);
match r {
Ok(v) => {
if v.len() > 0 {
audit_log!(au, "candidate exists {:?}", filt);
Ok(true)
} else {
audit_log!(au, "candidate does not exist {:?}", filt);
Ok(false)
}
}
Err(e) => {
audit_log!(au, "error processing filt {:?}, {:?}", filt, e);
Err(e)
}
}
}
pub fn modify() {} pub fn modify() {}
pub fn delete() {} pub fn delete() {}

View file

@ -146,13 +146,10 @@ impl Entry {
} }
pub fn attribute_equality(&self, attr: &str, value: &str) -> bool { pub fn attribute_equality(&self, attr: &str, value: &str) -> bool {
// Do a schema aware equality? // we assume based on schema normalisation on the way in
// Either we get schema passed in.
// OR we assume based on schema normalisation on the way in
// that the equality here of the raw values MUST be correct. // that the equality here of the raw values MUST be correct.
// If we do this, we likely need a DB normalise function ... // We also normalise filters, to ensure that their values are
// The other issue is we have to normalise what's in the filter // syntax valid and will correctly match here with our indexes.
// but that could be done *before* we get here?
// FIXME: Make this binary_search // FIXME: Make this binary_search
@ -162,6 +159,10 @@ impl Entry {
}) })
} }
pub fn attribute_substring(&self, attr: &str, subvalue: &str) -> bool {
unimplemented!();
}
pub fn classes(&self) -> EntryClasses { pub fn classes(&self) -> EntryClasses {
// Get the class vec, if any? // Get the class vec, if any?
// How do we indicate "empty?" // How do we indicate "empty?"

View file

@ -55,15 +55,25 @@ impl Filter {
// Go through the filter components and check them in the entry. // Go through the filter components and check them in the entry.
// This is recursive!!!! // This is recursive!!!!
match self { match self {
Filter::Eq(_, _) => false, Filter::Eq(attr, value) => {
Filter::Sub(_, _) => false, e.attribute_equality(attr.as_str(), value.as_str())
}
Filter::Sub(attr, subvalue) => {
e.attribute_substring(attr.as_str(), subvalue.as_str())
}
Filter::Pres(attr) => { Filter::Pres(attr) => {
// Given attr, is is present in the entry? // Given attr, is is present in the entry?
e.attribute_pres(attr.as_str()) e.attribute_pres(attr.as_str())
} }
Filter::Or(_) => false, Filter::Or(_) => {
Filter::And(_) => false, unimplemented!();
Filter::Not(_) => false, }
Filter::And(_) => {
unimplemented!();
}
Filter::Not(_) => {
unimplemented!();
}
} }
} }
} }
@ -98,13 +108,12 @@ impl PartialEq for Filter {
// remember, this isn't ordering by alphanumeric, this is ordering of // remember, this isn't ordering by alphanumeric, this is ordering of
// optimisation preference! // optimisation preference!
//
impl PartialOrd for Filter { impl PartialOrd for Filter {
fn partial_cmp(&self, rhs: &Filter) -> Option<Ordering> { fn partial_cmp(&self, rhs: &Filter) -> Option<Ordering> {
match (self, rhs) { match (self, rhs) {
(Filter::Eq(a1, _), Filter::Eq(a2, _)) => { (Filter::Eq(a1, _), Filter::Eq(a2, _)) => {
// Order attr name, then value // Order attr name, then value
// Later me may add rules to put certain attrs ahead due // Later we may add rules to put certain attrs ahead due
// to optimisation rules // to optimisation rules
a1.partial_cmp(a2) a1.partial_cmp(a2)
} }

View file

@ -4,6 +4,7 @@ use serde_json;
use super::audit::AuditScope; use super::audit::AuditScope;
// Helper for internal logging. // Helper for internal logging.
// Should only be used at startup/shutdown
#[macro_export] #[macro_export]
macro_rules! log_event { macro_rules! log_event {
($log_addr:expr, $($arg:tt)*) => ({ ($log_addr:expr, $($arg:tt)*) => ({
@ -66,8 +67,7 @@ impl Handler<AuditScope> for EventLog {
type Result = (); type Result = ();
fn handle(&mut self, event: AuditScope, _: &mut SyncContext<Self>) -> Self::Result { fn handle(&mut self, event: AuditScope, _: &mut SyncContext<Self>) -> Self::Result {
let d = serde_json::to_string_pretty(&event).unwrap(); println!("AUDIT: {}", event);
println!("AUDIT: {}", d);
} }
} }

View file

@ -1,9 +1,9 @@
use audit::AuditScope; use audit::AuditScope;
use be::Backend; use be::Backend;
use entry::Entry; use entry::Entry;
use error::OperationError;
use event::CreateEvent; use event::CreateEvent;
use schema::Schema; use schema::Schema;
use error::OperationError;
trait Plugin { trait Plugin {
fn pre_create( fn pre_create(

View file

@ -4,9 +4,10 @@ use uuid::Uuid;
use audit::AuditScope; use audit::AuditScope;
use be::Backend; use be::Backend;
use entry::Entry; use entry::Entry;
use event::CreateEvent;
use schema::Schema;
use error::OperationError; use error::OperationError;
use event::CreateEvent;
use filter::Filter;
use schema::Schema;
struct UUID {} struct UUID {}
@ -39,19 +40,34 @@ impl Plugin for UUID {
// this better .... // this better ....
match Uuid::parse_str(v.as_str()) { match Uuid::parse_str(v.as_str()) {
Ok(up) => up, Ok(up) => up,
Err(_) => { Err(_) => return Err(OperationError::Plugin),
return Err(
OperationError::Plugin
)
}
} }
} }
None => Uuid::new_v4() None => Uuid::new_v4(),
}; };
// Make it a string, so we can filter. // Make it a string, so we can filter.
println!("uuid: {}", c_uuid); let str_uuid = format!("{}", c_uuid);
println!("{}", str_uuid);
let mut au_be = AuditScope::new("be_exist");
// We need to clone to the filter because it owns the content
let filt = Filter::Eq(name_uuid.clone(), str_uuid.clone());
let r = be.exists(&mut au_be, &filt);
au.append_scope(au_be);
// end the scope?
match r {
Ok(b) => {
if b == true {
return Err(OperationError::Plugin);
}
}
Err(e) => return Err(OperationError::Plugin),
}
// check that the uuid is unique in the be (even if one is provided // check that the uuid is unique in the be (even if one is provided
// we especially need to check that) // we especially need to check that)
@ -96,6 +112,12 @@ mod tests {
let mut be = Backend::new(&mut au, ""); let mut be = Backend::new(&mut au, "");
// TODO: Preload entries here! // TODO: Preload entries here!
if ! $preload_entries.is_empty() {
assert!(be.create(
&mut au,
&$preload_entries
).is_ok());
};
let ce = CreateEvent::from_vec($create_entries.clone()); let ce = CreateEvent::from_vec($create_entries.clone());
let mut schema = Schema::new(); let mut schema = Schema::new();
@ -112,8 +134,8 @@ mod tests {
au.append_scope(au_test); au.append_scope(au_test);
}); });
// Dump the raw audit. Perhaps we should serialise this pretty? // Dump the raw audit log.
println!("{:?}", au); println!("{}", au);
}}; }};
} }
@ -136,6 +158,7 @@ mod tests {
ce: &CreateEvent, ce: &CreateEvent,
schema: &Schema| { schema: &Schema| {
let r = UUID::pre_create(be, au, cand, ce, schema); let r = UUID::pre_create(be, au, cand, ce, schema);
assert!(r.is_ok()); assert!(r.is_ok());
// Nothing should have changed. // Nothing should have changed.
assert!(cand.len() == 0); assert!(cand.len() == 0);
@ -190,6 +213,44 @@ mod tests {
// check create where provided uuid is valid. It should be unchanged. // check create where provided uuid is valid. It should be unchanged.
// check create where uuid already exists. // check create where uuid already exists.
#[test]
fn test_pre_create_uuid_exist() {
// Need a macro to create all the bits here ...
// Macro needs preload entries, the create entries
// schema, identity for create event (later)
let preload: Vec<Entry> = Vec::new();
let e: Entry = serde_json::from_str(
r#"{
"attrs": {
"class": ["person"],
"name": ["testperson"],
"description": ["testperson"],
"displayname": ["testperson"],
"uuid": ["79724141-3603-4060-b6bb-35c72772611d"]
}
}"#,
)
.unwrap();
let mut create = vec![e.clone()];
let mut preload = vec![e];
run_pre_create_test!(
preload,
create,
false,
false,
|be: &mut Backend,
au: &mut AuditScope,
cand: &mut Vec<Entry>,
ce: &CreateEvent,
schema: &Schema| {
let r = UUID::pre_create(be, au, cand, ce, schema);
assert!(r.is_err());
}
);
}
// check create where uuid is a well-known // check create where uuid is a well-known
// WARNING: This actually requires me to implement backend migrations and // WARNING: This actually requires me to implement backend migrations and

View file

@ -12,7 +12,9 @@ use schema::Schema;
pub fn start(log: actix::Addr<EventLog>, path: &str, threads: usize) -> actix::Addr<QueryServer> { pub fn start(log: actix::Addr<EventLog>, path: &str, threads: usize) -> actix::Addr<QueryServer> {
let mut audit = AuditScope::new("server_start"); let mut audit = AuditScope::new("server_start");
audit_segment!(audit, || { let log_inner = log.clone();
let qs_addr = audit_segment!(audit, || {
// Create the BE connection // Create the BE connection
// probably need a config type soon .... // probably need a config type soon ....
@ -28,10 +30,11 @@ pub fn start(log: actix::Addr<EventLog>, path: &str, threads: usize) -> actix::A
// it probably needs it ... // it probably needs it ...
// audit.end_event("server_new"); // audit.end_event("server_new");
SyncArbiter::start(threads, move || { SyncArbiter::start(threads, move || {
QueryServer::new(log.clone(), be.clone(), schema.clone()) QueryServer::new(log_inner.clone(), be.clone(), schema.clone())
}) })
}); });
log.do_send(audit); log.do_send(audit);
qs_addr
} }
// This is the core of the server. It implements all // This is the core of the server. It implements all