Skip to content

Commit

Permalink
Optional tracing
Browse files Browse the repository at this point in the history
  • Loading branch information
@ecton
ecton committed Aug 7, 2024
1 parent 6b276a6 commit 5e13ee3
Show file tree
Hide file tree
Showing 13 changed files with 341 additions and 3 deletions.
5 changes: 5 additions & 0 deletions Cargo.lock
View file

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

4 changes: 4 additions & 0 deletions Cargo.toml
View file
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,8 @@ parking_lot = "0.12.1"
refuse = "0.0.4"
refuse-pool = "0.0.4"
serde = { version = "1.0.195", features = ["derive", "rc"] }
tracing = "0.1.40"
tracing-subscriber = "0.3.18"

[package]
name = "muse"
Expand All @@ -28,6 +30,7 @@ reactor = ["dep:muse-reactor"]
ui = ["dep:muse-ui"]
dispatched = ["muse-lang/dispatched"]
repl = ["dep:rustyline", "dep:ariadne", "dep:dirs"]
tracing = ["muse-reactor/tracing", "muse-lang/tracing"]

[[bin]]
name = "muse"
Expand All @@ -49,6 +52,7 @@ rsn = "0.1"
pollster = "0.3.0"
flume = "0.11.0"
serde = { workspace = true }
tracing-subscriber = { workspace = true }

[lints.clippy]
pedantic = { level = "warn", priority = -1 }
Expand Down
5 changes: 5 additions & 0 deletions muse-lang/Cargo.toml
View file
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ license = "MIT OR Apache-2.0"

[features]
dispatched = []
tracing = ["dep:tracing"]

[dependencies]
serde = { workspace = true }
Expand All @@ -19,3 +20,7 @@ parking_lot = { workspace = true }
ahash = "0.8.7"
regex = "1.10.3"
unicode-ident = "1.0.12"
tracing = { workspace = true, optional = true }

[dev-dependencies]
tracing-subscriber = { workspace = true }
7 changes: 7 additions & 0 deletions muse-lang/src/lib.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,13 @@ macro_rules! impl_from {
};
}

#[cfg(feature = "tracing")]
#[macro_use]
extern crate tracing;
#[cfg(not(feature = "tracing"))]
#[macro_use]
mod mock_tracing;

pub mod compiler;
pub mod vm;

Expand Down
135 changes: 135 additions & 0 deletions muse-lang/src/mock_tracing.rs
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,135 @@
#[allow(unused_macros)]
macro_rules! info {
// Name / target / parent.
(name: $name:expr, target: $target:expr, parent: $parent:expr, { $($field:tt)* }, $($arg:tt)* ) => {};
(name: $name:expr, target: $target:expr, parent: $parent:expr, $($k:ident).+ $($field:tt)+ ) => {};
(name: $name:expr, target: $target:expr, parent: $parent:expr, ?$($k:ident).+ $($field:tt)+ ) => {};
(name: $name:expr, target: $target:expr, parent: $parent:expr, %$($k:ident).+ $($field:tt)+ ) => {};
(name: $name:expr, target: $target:expr, parent: $parent:expr, $($arg:tt)+ ) => {};

// Name / target.
(name: $name:expr, target: $target:expr, { $($field:tt)* }, $($arg:tt)* ) => {};
(name: $name:expr, target: $target:expr, $($k:ident).+ $($field:tt)+ ) => {};
(name: $name:expr, target: $target:expr, ?$($k:ident).+ $($field:tt)+ ) => {};
(name: $name:expr, target: $target:expr, %$($k:ident).+ $($field:tt)+ ) => {};
(name: $name:expr, target: $target:expr, $($arg:tt)+ ) => {};

// Target / parent.
(target: $target:expr, parent: $parent:expr, { $($field:tt)* }, $($arg:tt)* ) => {};
(target: $target:expr, parent: $parent:expr, $($k:ident).+ $($field:tt)+ ) => {};
(target: $target:expr, parent: $parent:expr, ?$($k:ident).+ $($field:tt)+ ) => {};
(target: $target:expr, parent: $parent:expr, %$($k:ident).+ $($field:tt)+ ) => {};
(target: $target:expr, parent: $parent:expr, $($arg:tt)+ ) => {};

// Name / parent.
(name: $name:expr, parent: $parent:expr, { $($field:tt)* }, $($arg:tt)* ) => {};
(name: $name:expr, parent: $parent:expr, $($k:ident).+ $($field:tt)+ ) => {};
(name: $name:expr, parent: $parent:expr, ?$($k:ident).+ $($field:tt)+ ) => {};
(name: $name:expr, parent: $parent:expr, %$($k:ident).+ $($field:tt)+ ) => {};
(name: $name:expr, parent: $parent:expr, $($arg:tt)+ ) => {};

// Name.
(name: $name:expr, { $($field:tt)* }, $($arg:tt)* ) => {};
(name: $name:expr, $($k:ident).+ $($field:tt)* ) => {};
(name: $name:expr, ?$($k:ident).+ $($field:tt)* ) => {};
(name: $name:expr, %$($k:ident).+ $($field:tt)* ) => {};
(name: $name:expr, $($arg:tt)+ ) => {};

// Target.
(target: $target:expr, { $($field:tt)* }, $($arg:tt)* ) => {};
(target: $target:expr, $($k:ident).+ $($field:tt)* ) => {};
(target: $target:expr, ?$($k:ident).+ $($field:tt)* ) => {};
(target: $target:expr, %$($k:ident).+ $($field:tt)* ) => {};
(target: $target:expr, $($arg:tt)+ ) => {};

// Parent.
(parent: $parent:expr, { $($field:tt)+ }, $($arg:tt)+ ) => {};
(parent: $parent:expr, $($k:ident).+ = $($field:tt)*) => {};
(parent: $parent:expr, ?$($k:ident).+ = $($field:tt)*) => {};
(parent: $parent:expr, %$($k:ident).+ = $($field:tt)*) => {};
(parent: $parent:expr, $($k:ident).+, $($field:tt)*) => {};
(parent: $parent:expr, ?$($k:ident).+, $($field:tt)*) => {};
(parent: $parent:expr, %$($k:ident).+, $($field:tt)*) => {};
(parent: $parent:expr, $($arg:tt)+) => {};

// ...
({ $($field:tt)+ }, $($arg:tt)+ ) => {};
($($k:ident).+ = $($field:tt)*) => {};
(?$($k:ident).+ = $($field:tt)*) => {};
(%$($k:ident).+ = $($field:tt)*) => {};
($($k:ident).+, $($field:tt)*) => {};
(?$($k:ident).+, $($field:tt)*) => {};
(%$($k:ident).+, $($field:tt)*) => {};
(?$($k:ident).+) => {};
(%$($k:ident).+) => {};
($($k:ident).+) => {};
($($arg:tt)+) => {};
}

#[allow(unused_macros)]
macro_rules! trace {
// Name / target / parent.
(name: $name:expr, target: $target:expr, parent: $parent:expr, { $($field:tt)* }, $($arg:tt)* ) => {};
(name: $name:expr, target: $target:expr, parent: $parent:expr, $($k:ident).+ $($field:tt)+ ) => {};
(name: $name:expr, target: $target:expr, parent: $parent:expr, ?$($k:ident).+ $($field:tt)+ ) => {};
(name: $name:expr, target: $target:expr, parent: $parent:expr, %$($k:ident).+ $($field:tt)+ ) => {};
(name: $name:expr, target: $target:expr, parent: $parent:expr, $($arg:tt)+ ) => {};

// Name / target.
(name: $name:expr, target: $target:expr, { $($field:tt)* }, $($arg:tt)* ) => {};
(name: $name:expr, target: $target:expr, $($k:ident).+ $($field:tt)+ ) => {};
(name: $name:expr, target: $target:expr, ?$($k:ident).+ $($field:tt)+ ) => {};
(name: $name:expr, target: $target:expr, %$($k:ident).+ $($field:tt)+ ) => {};
(name: $name:expr, target: $target:expr, $($arg:tt)+ ) => {};

// Target / parent.
(target: $target:expr, parent: $parent:expr, { $($field:tt)* }, $($arg:tt)* ) => {};
(target: $target:expr, parent: $parent:expr, $($k:ident).+ $($field:tt)+ ) => {};
(target: $target:expr, parent: $parent:expr, ?$($k:ident).+ $($field:tt)+ ) => {};
(target: $target:expr, parent: $parent:expr, %$($k:ident).+ $($field:tt)+ ) => {};
(target: $target:expr, parent: $parent:expr, $($arg:tt)+ ) => {};

// Name / parent.
(name: $name:expr, parent: $parent:expr, { $($field:tt)* }, $($arg:tt)* ) => {};
(name: $name:expr, parent: $parent:expr, $($k:ident).+ $($field:tt)+ ) => {};
(name: $name:expr, parent: $parent:expr, ?$($k:ident).+ $($field:tt)+ ) => {};
(name: $name:expr, parent: $parent:expr, %$($k:ident).+ $($field:tt)+ ) => {};
(name: $name:expr, parent: $parent:expr, $($arg:tt)+ ) => {};

// Name.
(name: $name:expr, { $($field:tt)* }, $($arg:tt)* ) => {};
(name: $name:expr, $($k:ident).+ $($field:tt)* ) => {};
(name: $name:expr, ?$($k:ident).+ $($field:tt)* ) => {};
(name: $name:expr, %$($k:ident).+ $($field:tt)* ) => {};
(name: $name:expr, $($arg:tt)+ ) => {};

// Target.
(target: $target:expr, { $($field:tt)* }, $($arg:tt)* ) => {};
(target: $target:expr, $($k:ident).+ $($field:tt)* ) => {};
(target: $target:expr, ?$($k:ident).+ $($field:tt)* ) => {};
(target: $target:expr, %$($k:ident).+ $($field:tt)* ) => {};
(target: $target:expr, $($arg:tt)+ ) => {};

// Parent.
(parent: $parent:expr, { $($field:tt)+ }, $($arg:tt)+ ) => {};
(parent: $parent:expr, $($k:ident).+ = $($field:tt)*) => {};
(parent: $parent:expr, ?$($k:ident).+ = $($field:tt)*) => {};
(parent: $parent:expr, %$($k:ident).+ = $($field:tt)*) => {};
(parent: $parent:expr, $($k:ident).+, $($field:tt)*) => {};
(parent: $parent:expr, ?$($k:ident).+, $($field:tt)*) => {};
(parent: $parent:expr, %$($k:ident).+, $($field:tt)*) => {};
(parent: $parent:expr, $($arg:tt)+) => {};

// ...
({ $($field:tt)+ }, $($arg:tt)+ ) => {};
($($k:ident).+ = $($field:tt)*) => {};
(?$($k:ident).+ = $($field:tt)*) => {};
(%$($k:ident).+ = $($field:tt)*) => {};
($($k:ident).+, $($field:tt)*) => {};
(?$($k:ident).+, $($field:tt)*) => {};
(%$($k:ident).+, $($field:tt)*) => {};
(?$($k:ident).+) => {};
(%$($k:ident).+) => {};
($($k:ident).+) => {};
($($arg:tt)+) => {};
}
13 changes: 13 additions & 0 deletions muse-lang/src/tests.rs
View file
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
use std::collections::VecDeque;

use refuse::CollectionGuard;
use tracing_subscriber::filter::LevelFilter;

use crate::compiler::syntax::token::{Paired, Token};
use crate::compiler::syntax::{Expression, Ranged, SourceRange, TokenizeInto};
Expand All @@ -11,9 +12,16 @@ use crate::runtime::value::{Primitive, Value};
use crate::vm::bitcode::BitcodeBlock;
use crate::vm::{ExecutionError, Register, Vm};

fn initialize_tracing() {
let _ = tracing_subscriber::fmt()
.with_max_level(LevelFilter::TRACE)
.try_init();
}

#[test]
fn budgeting() {
const COUNT_TO: i64 = 42;
initialize_tracing();

let mut guard = CollectionGuard::acquire();
let mut code = BitcodeBlock::default();
Expand Down Expand Up @@ -42,6 +50,7 @@ fn budgeting() {
#[test]
fn module_budgeting() {
const MAX_OPS: usize = 24;
initialize_tracing();
let mut guard = CollectionGuard::acquire();
let code = Compiler::compile(
r"
Expand Down Expand Up @@ -86,6 +95,7 @@ fn module_budgeting() {

#[test]
fn invoke() {
initialize_tracing();
let mut guard = CollectionGuard::acquire();
let code = Compiler::compile(
r"
Expand Down Expand Up @@ -124,6 +134,7 @@ fn invoke() {

#[test]
fn macros() {
initialize_tracing();
let mut guard = CollectionGuard::acquire();
let code = Compiler::default()
.with_macro("$test", |mut tokens: VecDeque<Ranged<Token>>| {
Expand All @@ -148,6 +159,7 @@ fn macros() {

#[test]
fn recursive_macros() {
initialize_tracing();
let mut guard = CollectionGuard::acquire();
let code = Compiler::default()
.with_macro("$inner", |mut tokens: VecDeque<Ranged<Token>>| {
Expand Down Expand Up @@ -179,6 +191,7 @@ fn recursive_macros() {

#[test]
fn infix_macros() {
initialize_tracing();
let mut guard = CollectionGuard::acquire();
let code = Compiler::default()
.with_infix_macro(
Expand Down
2 changes: 1 addition & 1 deletion muse-lang/src/vm.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1416,7 +1416,7 @@ impl VmContext<'_, '_> {
Ordering::Equal => return Ok(StepResult::Complete),
Ordering::Greater => return Err(Fault::InvalidInstructionAddress),
};
println!("Executing {instruction:?}");
trace!("Executing {instruction:?}");
let next_instruction = StepResult::from(address.checked_add(1));
let result = match instruction {
LoadedOp::Return => return Ok(StepResult::Complete),
Expand Down
7 changes: 7 additions & 0 deletions muse-reactor/Cargo.toml
View file
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,9 @@ edition = "2021"
repository = "https://github.com/khonsulabs/muse"
license = "MIT OR Apache-2.0"

[features]
tracing = ["dep:tracing", "muse-lang/tracing"]

[dependencies]
muse-lang = { workspace = true }
alot = { workspace = true }
Expand All @@ -13,3 +16,7 @@ crossbeam-utils = { workspace = true }
kempt = { workspace = true }
parking_lot = { workspace = true }
refuse = { workspace = true }
tracing = { workspace = true, optional = true }

[dev-dependencies]
tracing-subscriber = { workspace = true }
17 changes: 15 additions & 2 deletions muse-reactor/src/lib.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -97,6 +97,13 @@ use muse_lang::vm::{
use parking_lot::{Condvar, Mutex, MutexGuard};
use refuse::{CollectionGuard, ContainsNoRefs, Trace};

#[cfg(feature = "tracing")]
#[macro_use]
extern crate tracing;
#[cfg(not(feature = "tracing"))]
#[macro_use]
mod mock_tracing;

pub struct Builder<Work> {
vm_source: Option<Arc<dyn NewVm<Work>>>,
threads: usize,
Expand Down Expand Up @@ -184,7 +191,7 @@ where
for id in 0..self.threads {
let (spawn_send, spawn_recv) = flume::unbounded();
let parker = Parker::new();
let data = Arc::new(PerThreadData::new(parker.unparker().clone()));
let data = Arc::new(PerThreadData::new(id, parker.unparker().clone()));
let reactor = Reactor {
id,
receiver: spawn_recv,
Expand Down Expand Up @@ -224,6 +231,8 @@ enum ThreadCommand<Work> {
}

struct DispatcherThread<Work> {
#[cfg_attr(not(feature = "tracing"), allow(dead_code))]
num: usize,
spawner: Sender<ThreadCommand<Work>>,
load: usize,
unparker: Unparker,
Expand Down Expand Up @@ -266,6 +275,7 @@ impl<Work> Dispatcher<Work> {
self.threads.clear();
for t in &*threads {
self.threads.push_back(DispatcherThread {
num: t.data.num,
spawner: t.spawner.clone(),
load: t.spawner.len() * 2
+ t.data.executing.load(Ordering::Relaxed)
Expand Down Expand Up @@ -344,6 +354,7 @@ impl<Work> Dispatcher<Work> {
return;
};

trace!(task = spawn.id, thread = thread.num, "spawn");
match thread.spawner.send(ThreadCommand::Spawn(spawn)) {
Ok(()) => {
thread.unparker.unpark();
Expand Down Expand Up @@ -1272,14 +1283,16 @@ struct PerThread<Work> {

#[derive(Debug)]
struct PerThreadData {
num: usize,
unparker: Unparker,
executing: AtomicUsize,
total: AtomicUsize,
}

impl PerThreadData {
fn new(unparker: Unparker) -> Self {
fn new(num: usize, unparker: Unparker) -> Self {
Self {
num,
unparker,
executing: AtomicUsize::new(0),
total: AtomicUsize::new(0),
Expand Down
Loading

0 comments on commit 5e13ee3

Please sign in to comment.