updater_thread now works and we listen on unix_socket

This commit is contained in:
Sebastian Moser
2024-06-19 21:50:52 +02:00
parent 7340aaa37a
commit 053742f849
19 changed files with 797 additions and 413 deletions

View File

@@ -3,7 +3,7 @@ use std::path::PathBuf;
use clap::ArgMatches;
use home::home_dir;
use std::fs::File;
use log::{trace, debug, info, warn, error};
use tracing::{trace, debug, info, warn, error};
use nix::sys::signal::{self, Signal};
use mize::error::{MizeResultTrait, IntoMizeResult, MizeError, MizeResult};

View File

@@ -12,9 +12,10 @@ use crate::{core::instance::store::Store, mize_err};
use crate::error::{IntoMizeResult, MizeResult, MizeError};
use crate::core::item::{ItemData, Item};
use crate::core::id::MizeId;
use crate::core::memstore::get_raw_from_cbor;
use crate::item::get_raw_from_cbor;
use crate::instance::Instance;
#[derive(Clone)]
pub struct FileStore {
path: PathBuf,
}

257
src/platform/os/logging.rs Normal file
View File

@@ -0,0 +1,257 @@
use std::path::PathBuf;
use clap::{ArgAction, ArgMatches};
use clap::{Arg, crate_version, Command};
use mize::error::{MizeError, MizeResult};
use mize::item::ItemData;
use tokio::sync::{Mutex, mpsc};
use std::sync::Arc;
use std::io::Write;
use colored::Colorize;
use std::env;
use tracing_subscriber::fmt::Subscriber;
use tracing::Level;
use tracing::level_filters::LevelFilter;
use tracing_subscriber::filter::EnvFilter;
use tracing_subscriber::fmt::FormatEvent;
use tracing_subscriber::registry::LookupSpan;
use tracing_subscriber::fmt::FormatFields;
use tracing_subscriber::fmt::FmtContext;
use tracing_subscriber::fmt::format;
use tracing::Event;
use core::fmt;
use tracing_subscriber::fmt::FormattedFields;
use tracing::{trace, debug, info, warn, error};
use crate::DEFAULT_LOG_LEVEL;
pub fn init_logger(cli_matches: &ArgMatches) {
// to save log messages, before the logger is setup
let mut log_messages: Vec<(Level, String)> = Vec::new();
log_messages.push((Level::INFO, "Starting Mize".to_owned()));
// builder with DEFAULT_LOG_LEVEL
let mut builder = tracing_subscriber::fmt::Subscriber::builder();
// set loglevel
let mut log_level = DEFAULT_LOG_LEVEL;
log_messages.push((Level::TRACE, format!("set log level from DEFAULT_LOG_LEVEL to {}", DEFAULT_LOG_LEVEL)));
// check env RUST_LOG
let mut val_rust_log = level_from_env("RUST_LOG", log_level);
if let Some(level_rust_log) = val_rust_log.0 {
log_level = level_rust_log;
log_messages.push((Level::TRACE, format!("set log level from the Variable RUST_LOG to {}", level_rust_log)));
}
log_messages.append(&mut val_rust_log.1);
// check env MIZE_LOG
let mut val_mize_log = level_from_env("MIZE_LOG", log_level);
if let Some(level_mize_log) = val_mize_log.0 {
log_level = level_mize_log;
log_messages.push((Level::TRACE, format!("set log level from the Variable MIZE_LOG to {}", level_mize_log)));
}
log_messages.append(&mut val_mize_log.1);
// check -vvvvv flags
let v_flag_count = cli_matches.get_count("verbose");
let default_log_level_as_num = match DEFAULT_LOG_LEVEL {
LevelFilter::OFF => 0,
LevelFilter::ERROR => 1,
LevelFilter::WARN => 2,
LevelFilter::INFO => 3,
LevelFilter::DEBUG => 4,
LevelFilter::TRACE => 5,
};
let new_log_level_num = default_log_level_as_num + v_flag_count;
log_level = match new_log_level_num {
0 => LevelFilter::OFF,
1 => LevelFilter::ERROR,
2 => LevelFilter::WARN,
3 => LevelFilter::INFO,
4 => LevelFilter::DEBUG,
5 => LevelFilter::TRACE,
_ => {
log_messages.push((Level::TRACE, format!("the number of verbose (-v) flags passed ({}) exeeds the maximumg log_level", v_flag_count)));
LevelFilter::TRACE
},
};
log_messages.push((Level::TRACE, format!("set log level from the verbose flags to {}", log_level)));
// check --log-level arg
if let Some(log_level_arg_string) = cli_matches.get_one::<&str>("log-level") {
let log_level_from_arg = match log_level_arg_string.to_lowercase().as_str() {
"none" => LevelFilter::OFF,
"trace" => LevelFilter::TRACE,
"debug" => LevelFilter::DEBUG,
"info" => LevelFilter::INFO,
"warn" => LevelFilter::WARN,
"error" => LevelFilter::ERROR,
_ => {
log_messages.push((Level::WARN, format!(
"The argument to --log-level \"{}\" is not a valid log-level. loglevel stays at: {}"
, log_level_arg_string
, log_level
)));
log_level
}
};
log_level = log_level_from_arg;
log_messages.push((Level::TRACE, format!("set log level from the --log-level arg to {}", log_level_from_arg)));
}
// check --silent flag
if cli_matches.get_flag("silent") {
if log_level != DEFAULT_LOG_LEVEL {
log_messages.push((Level::WARN, format!(
"The loglevel was set by some method (it's not the DEFAULT_LOG_LEVEL) and is now overwritten by the --siltne to be OFF"
)))
}
log_level = LevelFilter::OFF;
}
// actually set the log_level on the builder
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"))
//.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"))
;
builder
.with_env_filter(my_env_filter)
.without_time()
.event_format(MyFormatter)
//.with_max_level(log_level)
.init();
// write out all log messages from log_messages
for (level, msg) in log_messages {
match level {
Level::ERROR => error!("{}", msg),
Level::WARN => warn!("{}", msg),
Level::INFO => info!("{}", msg),
Level::DEBUG => debug!("{}", msg),
Level::TRACE => trace!("{}", msg),
}
}
}
fn level_from_env(var_name: &str, log_level: LevelFilter) -> (Option<LevelFilter>, Vec<(Level, String)>) {
let mut log_messages: Vec<(Level, String)> = Vec::new();
let var_value = env::var(var_name);
match var_value {
Ok(val) => {
// set loglevel acording to RUST_LOG
let level = match val.to_lowercase().as_str() {
"none" => LevelFilter::OFF,
"trace" => LevelFilter::TRACE,
"debug" => LevelFilter::DEBUG,
"info" => LevelFilter::INFO,
"warn" => LevelFilter::WARN,
"error" => LevelFilter::ERROR,
_ => {
log_messages.push((Level::WARN, format!(
"The value of Environment Variable {}: \"{}\" is not a valid log-level. loglevel stays at: {}"
, var_name
, val
, log_level
)));
log_level
}
};
return (Some(level), log_messages)
},
Err(env::VarError::NotPresent) => {},
Err(env::VarError::NotUnicode(os_string)) => {
let os_string_as_hex : String = os_string.clone().into_encoded_bytes().iter()
.map(|b| format!("{:02x}", b).to_string())
.collect::<Vec<String>>()
.join("");
log_messages.push((Level::DEBUG, format!(
"value of Environment Variable {} was not a unicode valid string. Therefore ignoring it.
\n value with replacement char U+FFFD: {}
\n the WTF-8 raw bytes as hex: {}"
, var_name
, os_string.to_string_lossy(), os_string_as_hex
)));
},
};
return (None, log_messages);
}
struct MyFormatter;
impl<S, N> FormatEvent<S, N> for MyFormatter
where
S: tracing::Subscriber + for<'a> LookupSpan<'a>,
N: for<'a> FormatFields<'a> + 'static,
{
fn format_event(
&self,
ctx: &FmtContext<'_, S, N>,
mut writer: format::Writer<'_>,
event: &Event<'_>,
) -> fmt::Result {
// Format values from the event's's metadata:
let metadata = event.metadata();
// set format
/*
builder.format(|buf, record| {
match record.level() {
}
});
*/
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()),
};
// with target
// write!(&mut writer, "{} {}: ", level_str, metadata.target())?;
write!(&mut writer, "{} ", level_str)?;
// Format all the spans in the event's span context.
if let Some(scope) = ctx.event_scope() {
for span in scope.from_root() {
write!(writer, "{}", span.name())?;
// `FormattedFields` is a formatted representation of the span's
// fields, which is stored in its extensions by the `fmt` layer's
// `new_span` method. The fields will have been formatted
// by the same field formatter that's provided to the event
// formatter in the `FmtContext`.
let ext = span.extensions();
let fields = &ext
.get::<FormattedFields<N>>()
.expect("will never be `None`");
// Skip formatting the fields if the span had no fields.
if !fields.is_empty() {
//write!(writer, "{{{}}}", fields)?;
}
write!(writer, ": ")?;
}
}
// Write fields on the event
ctx.field_format().format_fields(writer.by_ref(), event)?;
writeln!(writer)
}
}

View File

@@ -9,14 +9,16 @@ use mize::error::{MizeError, MizeResult};
use mize::item::ItemData;
use tokio::sync::{Mutex, mpsc};
use std::sync::Arc;
use log::Level;
use log::LevelFilter;
use env_logger::{Builder, Env};
use std::io::Write;
use colored::Colorize;
use std::env;
use tracing_subscriber::fmt::Subscriber;
use tracing::Level;
use tracing::level_filters::LevelFilter;
use tracing_subscriber::filter::EnvFilter;
use crate::logging::init_logger;
use log::{trace, debug, info, warn, error};
use tracing::{trace, debug, info, warn, error};
mod cli {
pub mod run;
@@ -36,8 +38,10 @@ mod cli {
pub use call::call;
}
mod logging;
static APPNAME: &str = "mize";
static DEFAULT_LOG_LEVEL: LevelFilter = LevelFilter::Warn;
static DEFAULT_LOG_LEVEL: LevelFilter = LevelFilter::WARN;
fn main() {
// welcome to the mize source code
@@ -48,10 +52,6 @@ fn main() {
init_logger(&cli_matches);
// log a message of every level, to test loging
// test_logger();
// match command
let result = match cli_matches.subcommand() {
// mi daemon
@@ -86,179 +86,6 @@ fn main() {
}
}
fn init_logger(cli_matches: &ArgMatches) {
// to save log messages, before the logger is setup
let mut log_messages: Vec<(Level, String)> = Vec::new();
log_messages.push((Level::Info, "Starting Mize".to_owned()));
// builder with DEFAULT_LOG_LEVEL
let mut builder = Builder::new();
builder.format_indent(Some(8));
// set loglevel
let mut log_level = DEFAULT_LOG_LEVEL;
log_messages.push((Level::Trace, format!("set log level from DEFAULT_LOG_LEVEL to {}", DEFAULT_LOG_LEVEL)));
// check env RUST_LOG
let mut val_rust_log = level_from_env("RUST_LOG", log_level);
if let Some(level_rust_log) = val_rust_log.0 {
log_level = level_rust_log;
log_messages.push((Level::Trace, format!("set log level from the Variable RUST_LOG to {}", level_rust_log)));
}
log_messages.append(&mut val_rust_log.1);
// check env MIZE_LOG
let mut val_mize_log = level_from_env("MIZE_LOG", log_level);
if let Some(level_mize_log) = val_mize_log.0 {
log_level = level_mize_log;
log_messages.push((Level::Trace, format!("set log level from the Variable MIZE_LOG to {}", level_mize_log)));
}
log_messages.append(&mut val_mize_log.1);
// check -vvvvv flags
let v_flag_count = cli_matches.get_count("verbose");
let default_log_level_as_num = match DEFAULT_LOG_LEVEL {
LevelFilter::Off => 0,
LevelFilter::Error => 1,
LevelFilter::Warn => 2,
LevelFilter::Info => 3,
LevelFilter::Debug => 4,
LevelFilter::Trace => 5,
};
let new_log_level_num = default_log_level_as_num + v_flag_count;
log_level = match new_log_level_num {
0 => LevelFilter::Off,
1 => LevelFilter::Error,
2 => LevelFilter::Warn,
3 => LevelFilter::Info,
4 => LevelFilter::Debug,
5 => LevelFilter::Trace,
_ => {
log_messages.push((Level::Trace, format!("the number of verbose (-v) flags passed ({}) exeeds the maximumg log_level", v_flag_count)));
LevelFilter::Trace
},
};
log_messages.push((Level::Trace, format!("set log level from the verbose flags to {}", log_level)));
// check --log-level arg
if let Some(log_level_arg_string) = cli_matches.get_one::<&str>("log-level") {
let log_level_from_arg = match log_level_arg_string.to_lowercase().as_str() {
"none" => LevelFilter::Off,
"trace" => LevelFilter::Trace,
"debug" => LevelFilter::Debug,
"info" => LevelFilter::Info,
"warn" => LevelFilter::Warn,
"error" => LevelFilter::Error,
_ => {
log_messages.push((Level::Warn, format!(
"The argument to --log-level \"{}\" is not a valid log-level. loglevel stays at: {}"
, log_level_arg_string
, log_level
)));
log_level
}
};
log_level = log_level_from_arg;
log_messages.push((Level::Trace, format!("set log level from the --log-level arg to {}", log_level_from_arg)));
}
// check --silent flag
if cli_matches.get_flag("silent") {
if log_level != DEFAULT_LOG_LEVEL {
log_messages.push((Level::Warn, format!(
"The loglevel was set by some method (it's not the DEFAULT_LOG_LEVEL) and is now overwritten by the --siltne to be OFF"
)))
}
log_level = LevelFilter::Off;
}
// actually set the log_level on the builder
builder.filter_level(log_level);
log_messages.push((Level::Info, format!("loglevel is now {}", log_level)));
// set format
builder.format(|buf, record| {
match record.level() {
Level::Trace => writeln!(buf, "[ {} ] {}", format!("{}", record.level()).yellow(), record.args()),
Level::Debug => writeln!(buf, "[ {} ] {}", format!("{}", record.level()).green(), record.args()),
Level::Info => writeln!(buf, "[ {} ] {}", format!("{}", record.level()).blue(), record.args()),
Level::Warn => writeln!(buf, "[ {} ] {}", format!("{}", record.level()).truecolor(245, 164, 66), record.args()),
Level::Error => writeln!(buf, "[ {} ] {}", format!("{}", record.level()).red(), record.args()),
}
});
builder.init();
// write out all log messages from log_messages
for (level, msg) in log_messages {
match level {
Level::Error => error!("{}", msg),
Level::Warn => warn!("{}", msg),
Level::Info => info!("{}", msg),
Level::Debug => debug!("{}", msg),
Level::Trace => trace!("{}", msg),
}
}
}
fn test_logger() {
error!("hi from error");
warn!("hi from warn");
info!("hi from info");
debug!("hi from debug");
trace!("hi from trace");
}
fn level_from_env(var_name: &str, log_level: LevelFilter) -> (Option<log::LevelFilter>, Vec<(Level, String)>) {
let mut log_messages: Vec<(Level, String)> = Vec::new();
let var_value = env::var(var_name);
match var_value {
Ok(val) => {
// set loglevel acording to RUST_LOG
let level = match val.to_lowercase().as_str() {
"none" => LevelFilter::Off,
"trace" => LevelFilter::Trace,
"debug" => LevelFilter::Debug,
"info" => LevelFilter::Info,
"warn" => LevelFilter::Warn,
"error" => LevelFilter::Error,
_ => {
log_messages.push((Level::Warn, format!(
"The value of Environment Variable {}: \"{}\" is not a valid log-level. loglevel stays at: {}"
, var_name
, val
, log_level
)));
log_level
}
};
return (Some(level), log_messages)
},
Err(env::VarError::NotPresent) => {},
Err(env::VarError::NotUnicode(os_string)) => {
let os_string_as_hex : String = os_string.clone().into_encoded_bytes().iter()
.map(|b| format!("{:02x}", b).to_string())
.collect::<Vec<String>>()
.join("");
log_messages.push((Level::Debug, format!(
"value of Environment Variable {} was not a unicode valid string. Therefore ignoring it.
\n value with replacement char U+FFFD: {}
\n the WTF-8 raw bytes as hex: {}"
, var_name
, os_string.to_string_lossy(), os_string_as_hex
)));
},
};
return (None, log_messages);
}
fn cli_matches() -> clap::ArgMatches {

View File

@@ -2,8 +2,9 @@ use ciborium::Value as CborValue;
use serde::Deserialize;
use std::env::VarError;
use std::fs;
use log::{debug, error, warn, trace};
use tracing::{debug, error, warn, trace};
use clap::ArgMatches;
use std::path::Path;
use crate::id::MizeId;
use crate::instance::store::Store;
@@ -11,12 +12,13 @@ use crate::instance::Instance;
use crate::error::{IntoMizeResult, MizeError, MizeResult};
use crate::item::{ItemData, IntoItemData};
use crate::memstore::MemStore;
use crate::platform::os::unix_socket::UnixListener;
use self::fsstore::FileStore;
mod fsstore;
mod unix_socket;
//mod web;
//mod unix-socket;
pub fn os_instance_init(instance: &mut Instance) -> MizeResult<()> {
@@ -64,6 +66,9 @@ pub fn os_instance_init(instance: &mut Instance) -> MizeResult<()> {
if store_path != "" {
let file_store = FileStore::new(store_path.as_str())?;
instance.migrate_to_store(Box::new(file_store))?;
let path = Path::new(&store_path).to_owned();
instance.add_listener(UnixListener::new(path)?)?;
}
Ok(())

View File

@@ -1,61 +0,0 @@
impl Connection {
pub fn from_unix(unix_sock: UnixStream) -> Connection {
let (recieve_tx, recieve_rx) = tokio::sync::mpsc::channel(crate::instance::UNIX_SOCKET_CHANNEL_SIZE);
let (send_tx, send_rx) = tokio::sync::mpsc::channel(crate::instance::UNIX_SOCKET_CHANNEL_SIZE);
let (unix_read, unix_write) = unix_sock.into_split();
// TODO: error handling and close con on error
tokio::spawn(unix_send(unix_write, send_rx));
tokio::spawn(unix_recieve(unix_read, recieve_tx));
return Connection { tx: send_tx, rx: recieve_rx }
}
}
async fn unix_send(unix_write: OwnedWriteHalf, send_rx: Receiver<MizeMessage>) -> MizeResult<()> {
loop {
let ready = unix_write.ready(Interest::WRITABLE).await.mize_result_msg("hi")?;
if ready.is_writable() {
// Try to write data, this may still fail with `WouldBlock`
// if the readiness event is a false positive.
match unix_write.try_write(b"hello world") {
Ok(n) => {
println!("wrote {} bytes to unix sock", n);
}
Err(ref e) if e.kind() == io::ErrorKind::WouldBlock => {
continue;
}
Err(e) => {
return Err(e.into());
}
}
}
}
}
async fn unix_recieve(unix_read: OwnedReadHalf, recieve_tx: Sender<MizeMessage>) -> MizeResult<()> {
loop {
let ready = unix_read.ready(Interest::READABLE).await.mize_result_msg("hi")?;
if ready.is_readable() {
let mut data = vec![0; 1024];
// Try to read data, this may still fail with `WouldBlock`
// if the readiness event is a false positive.
match unix_read.try_read(&mut data) {
Ok(n) => {
println!("read {} bytes from unix sock", n);
}
Err(ref e) if e.kind() == io::ErrorKind::WouldBlock => {
continue;
}
Err(e) => {
return Err(e.into());
}
}
}
}
}

View File

@@ -0,0 +1,94 @@
use std::path::{Path, PathBuf};
use tokio::net::UnixListener as TokioUnixListener;
use tokio::net::unix::{OwnedReadHalf, OwnedWriteHalf};
use tokio::io::Interest;
use crossbeam::channel::{Receiver, Sender, unbounded};
use crate::instance::peer::{PeerListener, Peer};
use crate::instance::{self, Instance};
use crate::error::{MizeError, MizeResult, IntoMizeResult};
use crate::proto::MizeMessage;
pub struct UnixListener {
sock_path: PathBuf,
}
impl UnixListener {
pub fn new(store_path: PathBuf) -> MizeResult<UnixListener> {
Ok(UnixListener { sock_path: store_path.join("sock").to_owned() })
}
}
impl PeerListener for UnixListener {
fn listen(self, mut instance: Instance) -> MizeResult<()> {
instance.spawn_async("unix listen async", unix_listen(self, instance.clone()));
Ok(())
}
}
async fn unix_listen(listener: UnixListener, mut instance: Instance) -> MizeResult<()> {
let listener = TokioUnixListener::bind(&listener.sock_path)
.mize_result_msg(format!("Could not bind to unix socket at '{}'", listener.sock_path.display()))?;
loop {
let (unix_sock, addr) = listener.accept().await
.mize_result_msg("Error while accepting Unix sock connection")?;
let (recieve_tx, recieve_rx) = unbounded::<MizeMessage>();
let (send_tx, send_rx) = unbounded::<MizeMessage>();
let (unix_read, unix_write) = unix_sock.into_split();
let peer = Peer::new(recieve_rx, send_tx);
instance.add_peer(peer);
instance.spawn_async("incomming", unix_incomming(unix_read, recieve_tx));
instance.spawn_async("outgoing", unix_outgoing(unix_write, send_rx));
}
}
async fn unix_outgoing(unix_write: OwnedWriteHalf, send_rx: Receiver<MizeMessage>) -> MizeResult<()> {
loop {
let ready = unix_write.ready(Interest::WRITABLE).await.mize_result_msg("hi")?;
if ready.is_writable() {
// Try to write data, this may still fail with `WouldBlock`
// if the readiness event is a false positive.
match unix_write.try_write(b"hello world") {
Ok(n) => {
println!("wrote {} bytes to unix sock", n);
}
Err(ref e) if e.kind() == tokio::io::ErrorKind::WouldBlock => {
continue;
}
Err(e) => {
return Err(e.into());
}
}
}
}
}
async fn unix_incomming(unix_read: OwnedReadHalf, recieve_tx: Sender<MizeMessage>) -> MizeResult<()> {
loop {
let ready = unix_read.ready(Interest::READABLE).await.mize_result_msg("unix_read_half.ready() failed")?;
if ready.is_readable() {
let mut data = vec![0; 1024];
// Try to read data, this may still fail with `WouldBlock`
// if the readiness event is a false positive.
match unix_read.try_read(&mut data) {
Ok(n) => {
println!("read {} bytes from unix sock", n);
}
Err(ref e) if e.kind() == tokio::io::ErrorKind::WouldBlock => {
continue;
}
Err(e) => {
return Err(e.into());
}
}
}
}
}