ppc/mize
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

logging works a bit more the way i want, but it's such a pfusch

Browse Source
This commit is contained in:
Sebastian Moser
2024-08-22 11:17:01 +02:00
parent 89c490fadb
commit 5a25fd7161
11 changed files with 276 additions and 40 deletions
Download Patch File Download Diff File Expand all files Collapse all files

1
Cargo.lock generated
View File

@@ -1277,6 +1277,7 @@ dependencies = [
"tokio-io",
"toml",
"tracing",
"tracing-core",
"tracing-subscriber",
"uuid",
"wasm-bindgen",

1
Cargo.toml
View File

@@ -58,6 +58,7 @@ dyn-clone = "1.0.17"
tokio-core = "0.1.18"
tokio-io = "0.1.13"
ciborium-io = "0.2.2"
tracing-core = "0.1.32"
#tokio-stream = { version = "0.1.9", optional = true }
#derive_more = "0.99.17"

2
src/core/instance/mod.rs
View File

@@ -160,7 +160,7 @@ impl Instance {
}
pub fn migrate_to_store(&self, new_store: Box<dyn Store>) -> MizeResult<()> {
println!("MIGRATING");
info!("MIGRATING");
let mut old_store = self.store.lock()?;
let id = self.id_from_string("0".to_owned())?;

2
src/core/instance/updater.rs
View File

@@ -57,8 +57,6 @@ pub fn handle_operation(operation: &mut Operation, instance: &Instance) -> MizeR
//check subs and handle them
let mut subs_inner = instance.subs.lock()?;
println!("goooooooooooooooooot some subs: {:?}", subs_inner);
println!("some subs id: {:?}", id);
if let Some(vec) = subs_inner.get_mut(&id) {
let update = Update {
instance: Arc::new(instance.to_owned()),

13
src/core/item.rs
View File

@@ -1,6 +1,7 @@
use tracing::{debug, error, info, instrument, trace, warn, Instrument};
use serde::Serialize;
use core::fmt;
use std::fmt::Debug;
use std::{i128, string};
use std::{collections::HashMap, path::PathBuf, io::Cursor, fmt::Display};
use std::fs::File;
@@ -105,16 +106,17 @@ impl Item<'_> {
}
}
pub fn merge<V: Into<ItemData>>(&mut self, mut value: V) -> MizeResult<()> {
#[instrument(name = "fn.ItemData::merge")]
pub fn merge<V: Into<ItemData> + Debug >(&mut self, mut value: V) -> MizeResult<()> {
let mut data = self.as_data_full()?;
println!("item::merge data: {:?}", data);
println!("item::merge id: {:?}", self.id());
trace!("item::merge data: {:?}", data);
trace!("item::merge id: {:?}", self.id());
let new_data = value.into();
data.merge(new_data);
println!("item::merge new_data: {:?}", data);
trace!("item::merge new_data: {:?}", data);
if self.instance.we_are_namespace()? {
let store_inner = self.instance.store.lock()?;
@@ -212,7 +214,6 @@ pub fn item_data_get_path(data: &CborValue, path: Vec<String>) -> MizeResult<&Cb
//println!("path_el: {}", path_el);
if let CborValue::Text(key_str) = key {
if key_str == &path_el {
println!("setting sub_data to: {:?}", val);
sub_data = val;
}
}
@@ -332,7 +333,7 @@ pub fn item_data_merge(merge_into: &mut CborValue, other: &CborValue){
}
}
#[instrument]
#[instrument(name = "fn.get_raw_from_cbor")]
pub fn get_raw_from_cbor<'a>(value: &'a CborValue, path: Vec<&String>) -> MizeResult<&'a [u8]> {
trace!("[ {} ] value: {:?}", "ARG".yellow(), value);
trace!("[ {} ] path: {:?}", "ARG".yellow(), path);

5
src/core/memstore.rs
View File

@@ -44,14 +44,14 @@ impl Store for MemStore {
Ok(Vec::new())
}
fn new_id(&self) -> MizeResult<String> {
println!("are we hereeeeeee memstore new_get");
let mut inner = self.inner.lock()?;
let id_string = format!("{}", inner.next_id);
inner.next_id += 1;
return Ok(id_string);
}
#[instrument(name="MemStore::get_value_raw" skip(self))]
#[instrument(name="fn.MemStore::get_value_raw" skip(self))]
fn get_value_raw(&self, id: MizeId) -> MizeResult<Vec<u8>> {
trace!("[ {} ] id: {:?}", "ARG".yellow(), id);
let inner = self.inner.lock()?;
@@ -90,7 +90,6 @@ impl Store for MemStore {
}
fn next_id(&self, prev_id_str: &str) -> MizeResult<Option<String>> {
println!("next_id: prev_id_str: {}", prev_id_str);
let inner = self.inner.lock()?;
let mut id = str_to_u64(prev_id_str)?;

4
src/platform/os/cli/show.rs
View File

@@ -18,11 +18,11 @@ pub fn show(sub_matches: &ArgMatches) -> MizeResult<()> {
let sub = Subscription::from_sender(tx);
instance.sub(id, sub)?;
println!("ItemData: {}", item.as_data_full()?);
println!("item: {}", item.as_data_full()?);
for update in rx {
println!("####### GOT UPDATE #######");
println!("ItemData: {}", update.new_item()?.as_data_full()?);
println!("item: {}", update.new_item()?.as_data_full()?);
}
Ok(())

6
src/platform/os/fsstore.rs
View File

@@ -50,9 +50,7 @@ impl FileStore {
}
pub fn store_is_opened(store_path: String) -> MizeResult<bool> {
println!("valid_pid_file: {}", valid_pid_file(Path::new(&store_path))?.is_some());
let res = valid_pid_file(Path::new(&store_path))?.is_some();
println!("after fn");
Ok(res)
}
}
@@ -65,7 +63,6 @@ impl Store for FileStore {
.parse()
.mize_result_msg(format!("could not parse next_id at '{}' to u64", self.path.display()))?;
println!("nextid fsstore: {}", next_id);
let id_string = format!("{}", next_id);
next_id += 1;
@@ -76,9 +73,7 @@ impl Store for FileStore {
}
fn set(&self, id: MizeId, data: ItemData) -> MizeResult<()> {
println!("setting: {:?}", id);
let path = self.path.join("store").join(id.namespace_str()).join(id.store_part());
println!("path: {:?}", &path);
fs::create_dir_all(self.path.join("store").join(id.namespace_str()))?;
let file = OpenOptions::new().write(true).create(true).open(path)?;
@@ -113,7 +108,6 @@ impl Store for FileStore {
fn get_value_data_full(&self, id: MizeId) -> MizeResult<ItemData> {
let file_path = self.path.join("store").join(id.namespace_str()).join(id.store_part());
println!("file_path: {:?}", file_path.display());
if !file_path.exists() {
}

274
src/platform/os/logging.rs
View File

@@ -1,16 +1,17 @@
use std::collections::HashMap;
use std::path::PathBuf;
use clap::{ArgAction, ArgMatches};
use clap::{Arg, crate_version, Command};
use mize::error::{MizeError, MizeResult};
use mize::id::MizeId;
use mize::item::ItemData;
use tokio::sync::{Mutex, mpsc};
use tokio::sync::mpsc;
use std::sync::Mutex;
use std::sync::Arc;
use std::io::Write;
use colored::Colorize;
use std::env;
use tracing_subscriber::fmt::Subscriber;
use tracing::Level;
use tracing::{span_enabled, Instrument, Level};
use tracing::level_filters::LevelFilter;
use tracing_subscriber::filter::EnvFilter;
use tracing_subscriber::fmt::FormatEvent;
@@ -26,6 +27,12 @@ use tracing::{trace, debug, info, warn, error};
use crate::DEFAULT_LOG_LEVEL;
use std::sync::atomic::AtomicUsize;
use tracing::{field::Visit, Id, Subscriber};
use tracing_core::Field;
use std::fmt::Write;
pub fn init_logger(cli_matches: &ArgMatches) {
// to save log messages, before the logger is setup
@@ -34,7 +41,7 @@ pub fn init_logger(cli_matches: &ArgMatches) {
log_messages.push((Level::INFO, "Starting Mize".to_owned()));
// builder with DEFAULT_LOG_LEVEL
let mut builder = tracing_subscriber::fmt::Subscriber::builder();
//let mut builder = tracing_subscriber::fmt::Subscriber::builder();
// set loglevel
let mut log_level = DEFAULT_LOG_LEVEL;
@@ -117,19 +124,21 @@ pub fn init_logger(cli_matches: &ArgMatches) {
log_messages.push((Level::INFO, format!("loglevel is now {}", log_level)));
// filter loging
let mut my_env_filter = tracing_subscriber::filter::EnvFilter::new("")
.add_directive("[get_raw_from_cbor]=debug".parse().expect("error parsing log directive"))
//let mut my_env_filter = tracing_subscriber::filter::EnvFilter::new("")
//.add_directive("[get_raw_from_cbor]=debug".parse().expect("error parsing log directive"))
//.add_directive("[MemStore::get_value_raw]=trace".parse().expect("error parsing log directive"))
.add_directive("trace".parse().unwrap())
.add_directive("[get_raw_from_cbor]=debug".parse().expect("error parsing log directive"))
;
//.add_directive("trace".parse().unwrap())
//.add_directive("[get_raw_from_cbor]=debug".parse().expect("error parsing log directive"))
//;
builder
.with_env_filter(my_env_filter)
.without_time()
.event_format(MyFormatter)
MinimalTracer::register();
//builder
//.with_env_filter(my_env_filter)
//.without_time()
//.event_format(MyFormatter)
//.with_max_level(log_level)
.init();
//.init();
// write out all log messages from log_messages
@@ -255,3 +264,238 @@ where
writeln!(writer)
}
}
// thanks: https://stackoverflow.com/a/75546824
pub struct StringVisitor<'a> {
string: &'a mut String,
}
impl<'a> StringVisitor<'a> {
pub(crate) fn new(string: &'a mut String) -> Self {
StringVisitor { string }
}
}
impl<'a> Visit for StringVisitor<'a> {
fn record_debug(&mut self, field: &Field, value: &dyn fmt::Debug) {
if field.name() == "message" {
write!(self.string, "{value:?} ").unwrap();
} else {
write!(self.string, "{} = {:?}; ", field.name(), value).unwrap();
}
}
}
struct LogFilter {
target: Option<String>,
level: Option<Level>,
}
pub struct MinimalTracer {
enabled: bool,
filters: Vec<LogFilter>,
level: Arc<Mutex<Level>>,
spans: Arc<Mutex<Vec<Id>>>,
span_levels: Arc<Mutex<HashMap<Id, Level>>>,
span_names: Arc<Mutex<HashMap<Id, String>>>,
span_names_to_enable: Arc<Mutex<Vec<String>>>,
level_no_span: Level,
}
fn string_to_level(string: &str) -> Option<Level> {
match string.to_lowercase().as_str() {
"info" => Some(Level::INFO),
"debug" => Some(Level::DEBUG),
"warn" | "warning" => Some(Level::WARN),
"trace" => Some(Level::TRACE),
"error" => Some(Level::ERROR),
_ => None,
}
}
impl MinimalTracer {
pub fn register() -> Result<(), tracing::subscriber::SetGlobalDefaultError> {
let mut enabled = true;
let mut span_names_to_enable = Vec::new();
let mut my_level = Level::INFO;
let mut filters: Vec<LogFilter> = Vec::with_capacity(10);
if let Ok(env_value) = env::var("RUST_LOG") {
for filter in env_value.split(',') {
let mut target = Some(filter);
let mut level = None;
if let Some(equals_index) = target.unwrap().find('=') {
let (first, second) = filter.split_at(equals_index);
target = Some(first);
level = string_to_level(&second[1..])
} else {
my_level = string_to_level(target.unwrap()).unwrap();
}
let target_level = string_to_level(target.unwrap());
//if let Some(target_level) = target_level {
//level = Some(target_level);
//target = None;
//}
// in case target is a span name, add id to span_names_to_enable
// for now every target is also a span_name.....
// i would think everything, that contains a "." would be a span, and not a module
// targeet
if let Some(name) = target {
span_names_to_enable.push(name.to_owned());
}
filters.push(LogFilter {
target: target.map(|v| v.to_string()),
level,
});
}
} else {
enabled = false;
}
tracing::subscriber::set_global_default(MinimalTracer {
enabled, filters,
spans: Arc::new(Mutex::new(Vec::new())),
level: Arc::new(Mutex::new(my_level)),
span_names: Arc::new(Mutex::new(HashMap::new())),
span_names_to_enable: Arc::new(Mutex::new(span_names_to_enable)),
span_levels: Arc::new(Mutex::new(HashMap::new())),
level_no_span: my_level,
})
}
}
static AUTO_ID: AtomicUsize = AtomicUsize::new(1);
impl Subscriber for MinimalTracer {
fn enabled(&self, metadata: &tracing::Metadata<'_>) -> bool {
return true;
if metadata.is_span() {
return true;
let mut span_names_to_enable = self.span_names_to_enable.lock().unwrap();
if span_names_to_enable.contains(&metadata.name().to_owned()) {
return true;
}
}
if self.enabled {
if self.filters.is_empty() {
return true;
}
let mut matches: bool;
for filter in &self.filters {
matches = true;
if let Some(level) = filter.level {
if metadata.level() != &level {
matches = false;
}
}
if let Some(target) = &filter.target {
if !metadata.target().starts_with(target) {
matches = false;
}
}
if matches {
return true;
}
}
return false;
}
false
}
fn new_span(&self, _span: &tracing_core::span::Attributes<'_>) -> tracing_core::span::Id {
let mut span_names = self.span_names.lock().unwrap();
let mut span_levels = self.span_levels.lock().unwrap();
let mut span_names_to_enable = self.span_names_to_enable.lock().unwrap();
let id = Id::from_u64(AUTO_ID.fetch_add(1, std::sync::atomic::Ordering::Relaxed) as u64);
let span_name = _span.metadata().name().to_string();
span_names.insert(id.clone(), span_name.clone());
if span_names_to_enable.contains(&span_name) {
span_levels.insert(id.clone(), Level::TRACE);
} else {
span_levels.insert(id.clone(), Level::ERROR);
}
id
}
fn record(&self, _span: &tracing_core::span::Id, _values: &tracing_core::span::Record<'_>) {
}
fn record_follows_from(
&self,
_span: &tracing_core::span::Id,
_follows: &tracing_core::span::Id,
) {
}
fn event(&self, event: &tracing::Event<'_>) {
let metadata = event.metadata();
let level = metadata.level();
let my_level = self.level.lock().unwrap();
//println!("uuuuuuuuuuuu event name: {}", metadata.name());
//println!("uuuuuuuuuuuu my_level: {}", my_level);
//println!("uuuuuuuuuuuu event level: {}", level);
if *level > *my_level {
//println!("uuuuuuuuuuuu comparison");
//println!("BLOCKED EVENT")
return;
}
let target = metadata.target();
let mut text = String::new();
let mut visitor = StringVisitor::new(&mut text);
event.record(&mut visitor);
let level_str = match metadata.level() {
&Level::TRACE => format!("[ {} ]", "TRACE".yellow()),
&Level::DEBUG => format!("[ {} ]", "DEBUG".green()),
&Level::INFO => format!("[ {} ]", "INFO".blue()),
&Level::WARN => format!("[ {} ]", "WARN".truecolor(245, 164, 66)),
&Level::ERROR => format!("[ {} ]", "ERROR".red()),
};
//println!("{} {:?}", "META:".red(), metadata.in_current_span());
let mut spans = self.spans.lock().unwrap();
let mut span_names = self.span_names.lock().unwrap();
let span_text = spans.iter()
.map(|id| span_names.get(id).unwrap().to_owned())
.collect::<Vec<String>>()
.join("::");
println!("{level_str} {span_text} {text}");
}
fn enter(&self, _span: &tracing_core::span::Id) {
//println!("eeeeeeeeeeeeeeeee enter");
let mut spans = self.spans.lock().unwrap();
let mut level = self.level.lock().unwrap();
let mut span_levels = self.span_levels.lock().unwrap();
let mut span_names = self.span_names.lock().unwrap();
let name = span_names.get(_span).unwrap().to_owned();
*level = span_levels.get(_span).unwrap().to_owned();
spans.push(_span.clone());
//println!("my_level is now: {}", level);
}
fn exit(&self, _span: &tracing_core::span::Id) {
//println!("eeeeeeeeeeeeeeeee exit");
let mut level = self.level.lock().unwrap();
*level = self.level_no_span;
let mut spans = self.spans.lock().unwrap();
spans.pop();
}
}

1
src/platform/os/mod.rs
View File

@@ -63,7 +63,6 @@ pub fn os_instance_init(instance: &mut Instance) -> MizeResult<()> {
////// if a config.store_path is set, upgrade to the filestore there
let mut test = instance.get("0")?.as_data_full()?;
println!("os::Mod test: {}", test);
let mut store_path = instance.get("0/config/store_path")?.value_string()?;
if store_path == "" {

7
src/platform/os/unix_socket.rs
View File

@@ -5,7 +5,7 @@ use tokio::net::unix::{OwnedReadHalf, OwnedWriteHalf};
use tokio::io::{Interest, AsyncReadExt, AsyncWriteExt};
use crossbeam::channel::{Receiver, Sender, unbounded};
use ciborium::Value as CborValue;
use tracing::{info, warn};
use tracing::{info, warn, debug};
use crate::instance::connection::{ConnListener, Connection};
use crate::instance::{self, Instance};
@@ -122,7 +122,7 @@ async fn unix_listen(listener: UnixListener, mut instance: Instance) -> MizeResu
fn unix_outgoing(mut unix_write: OwnedWriteHalf, send_rx: Receiver<MizeMessage>, mut instance: Instance, conn_id: u64) -> MizeResult<()> {
for msg in send_rx {
println!("unix outgoing got msg: {}", msg);
debug!("unix outgoing got msg: {}", msg);
let adapter = MyCiboriumWriter { inner: &mut unix_write, instance: &mut instance };
let value = msg.value();
ciborium::into_writer(&value, adapter)?
@@ -139,8 +139,7 @@ fn unix_incomming(mut unix_read: OwnedReadHalf, mut instance: Instance, conn_id:
break;
}
let msg = MizeMessage::new(value, conn_id);
println!("unix incoming got msg: {}", msg);
println!("op channel len: {}", instance.op_tx.len());
debug!("unix incoming got msg: {}", msg);
instance.got_msg(msg);
}
Ok(())