janis/executor
1
0
Fork 0
Code Issues Pull requests Actions Packages Projects Releases Wiki Activity

feature-gating tracing

Browse source
This commit is contained in:
Janis 2025-07-01 11:54:39 +02:00
parent 19ef21e2ef
commit f384f61f81
9 changed files with 118 additions and 57 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

7
distaff/Cargo.toml
View file

@ -5,13 +5,14 @@ edition = "2024"
[features] [features]
default = ["metrics"] default = ["metrics"]
tracing = ["dep:tracing"]
std = [] std = []
metrics = [] metrics = []
[dependencies] [dependencies]
parking_lot = {version = "0.12.3"} parking_lot = {version = "0.12.3"}
atomic-wait = "1.1.0" atomic-wait = "1.1.0"
tracing = "0.1.40" tracing = {version = "0.1", optional = true}
parking_lot_core = "0.9.10" parking_lot_core = "0.9.10"
crossbeam-utils = "0.8.21" crossbeam-utils = "0.8.21"
either = "1.15.0" either = "1.15.0"
@ -19,6 +20,6 @@ either = "1.15.0"
async-task = "4.7.1" async-task = "4.7.1"
[dev-dependencies] [dev-dependencies]
tracing-test = "0.2.5" tracing-test = {version = "0.2"}
tracing-tracy = "0.11.4" tracing-tracy = {version = "0.11"}
futures = "0.3" futures = "0.3"

6
distaff/src/channel.rs
View file

@ -38,6 +38,7 @@ impl Parker {
self.mutex.load(Ordering::Acquire) == Self::PARKED self.mutex.load(Ordering::Acquire) == Self::PARKED
} }
#[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip_all, fields(this = self as *const Self as usize)))]
pub fn park(&self) { pub fn park(&self) {
if self.mutex.fetch_sub(1, Ordering::Acquire) == Self::NOTIFIED { if self.mutex.fetch_sub(1, Ordering::Acquire) == Self::NOTIFIED {
// The thread was notified, so we can return immediately. // The thread was notified, so we can return immediately.
@ -60,6 +61,7 @@ impl Parker {
} }
} }
#[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip_all, fields(this = self as *const Self as usize)))]
pub fn unpark(&self) { pub fn unpark(&self) {
// write with Release ordering to ensure that any writes made by this // write with Release ordering to ensure that any writes made by this
// thread are made-available to the unparked thread. // thread are made-available to the unparked thread.
@ -102,6 +104,7 @@ impl<T: Send> Receiver<T> {
self.0.state.load(Ordering::Acquire) != State::Ready as u8 self.0.state.load(Ordering::Acquire) != State::Ready as u8
} }
#[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip_all))]
pub fn wait(&self) { pub fn wait(&self) {
loop { loop {
match self.0.state.compare_exchange( match self.0.state.compare_exchange(
@ -146,6 +149,7 @@ impl<T: Send> Receiver<T> {
} }
} }
#[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip_all))]
pub fn poll(&self) -> Option<thread::Result<T>> { pub fn poll(&self) -> Option<thread::Result<T>> {
if self if self
.0 .0
@ -164,6 +168,7 @@ impl<T: Send> Receiver<T> {
} }
} }
#[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip_all))]
pub fn recv(self) -> thread::Result<T> { pub fn recv(self) -> thread::Result<T> {
self.wait(); self.wait();
@ -194,6 +199,7 @@ impl<T: Send> Receiver<T> {
pub struct Sender<T = ()>(Arc<Channel<T>>); pub struct Sender<T = ()>(Arc<Channel<T>>);
impl<T: Send> Sender<T> { impl<T: Send> Sender<T> {
#[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip_all))]
pub fn send(self, val: thread::Result<T>) { pub fn send(self, val: thread::Result<T>) {
// SAFETY: // SAFETY:
// Only this thread can write to `val` and none can read it // Only this thread can write to `val` and none can read it

23
distaff/src/context.rs
View file

@ -59,6 +59,7 @@ impl Context {
} }
pub fn new_with_threads(num_threads: usize) -> Arc<Self> { pub fn new_with_threads(num_threads: usize) -> Arc<Self> {
#[cfg(feature = "tracing")]
tracing::trace!("Creating context with {} threads", num_threads); tracing::trace!("Creating context with {} threads", num_threads);
let this = Arc::new(Self { let this = Arc::new(Self {
@ -142,9 +143,11 @@ impl Context {
.iter() .iter()
.find(|(_, heartbeat)| heartbeat.is_waiting()) .find(|(_, heartbeat)| heartbeat.is_waiting())
{ {
#[cfg(feature = "tracing")]
tracing::trace!("Notifying worker thread {} about job sharing", i); tracing::trace!("Notifying worker thread {} about job sharing", i);
sender.wake(); sender.wake();
} else { } else {
#[cfg(feature = "tracing")]
tracing::warn!("No worker found to notify about job sharing"); tracing::warn!("No worker found to notify about job sharing");
} }
} }
@ -206,29 +209,33 @@ impl Context {
} }
/// Run closure in this context. /// Run closure in this context.
#[tracing::instrument(level = "trace", skip_all)] #[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip_all))]
pub fn run_in_worker<T, F>(self: &Arc<Self>, f: F) -> T pub fn run_in_worker<T, F>(self: &Arc<Self>, f: F) -> T
where where
T: Send, T: Send,
F: FnOnce(&WorkerThread) -> T + Send, F: FnOnce(&WorkerThread) -> T + Send,
{ {
let _guard = DropGuard::new(|| { let _guard = DropGuard::new(|| {
#[cfg(feature = "tracing")]
tracing::trace!("run_in_worker: finished"); tracing::trace!("run_in_worker: finished");
}); });
match WorkerThread::current_ref() { match WorkerThread::current_ref() {
Some(worker) => { Some(worker) => {
// check if worker is in the same context // check if worker is in the same context
if Arc::ptr_eq(&worker.context, self) { if Arc::ptr_eq(&worker.context, self) {
#[cfg(feature = "tracing")]
tracing::trace!("run_in_worker: current thread"); tracing::trace!("run_in_worker: current thread");
f(worker) f(worker)
} else { } else {
// current thread is a worker for a different context // current thread is a worker for a different context
#[cfg(feature = "tracing")]
tracing::trace!("run_in_worker: cross-context"); tracing::trace!("run_in_worker: cross-context");
self.run_in_worker_cross(worker, f) self.run_in_worker_cross(worker, f)
} }
} }
None => { None => {
// current thread is not a worker for any context // current thread is not a worker for any context
#[cfg(feature = "tracing")]
tracing::trace!("run_in_worker: inject into context"); tracing::trace!("run_in_worker: inject into context");
self.run_in_worker_cold(f) self.run_in_worker_cold(f)
} }
@ -242,6 +249,7 @@ impl Context {
F: FnOnce() + Send + 'static, F: FnOnce() + Send + 'static,
{ {
let job = Job::from_heapjob(Box::new(HeapJob::new(f))); let job = Job::from_heapjob(Box::new(HeapJob::new(f)));
#[cfg(feature = "tracing")]
tracing::trace!("Context::spawn: spawning job: {:?}", job); tracing::trace!("Context::spawn: spawning job: {:?}", job);
self.inject_job(job.share(None)); self.inject_job(job.share(None));
} }
@ -297,12 +305,10 @@ where
mod tests { mod tests {
use std::sync::atomic::AtomicU8; use std::sync::atomic::AtomicU8;
use tracing_test::traced_test;
use super::*; use super::*;
#[test] #[test]
#[cfg_attr(not(miri), traced_test)] #[cfg_attr(all(not(miri), feature = "tracing"), tracing_test::traced_test)]
fn run_in_worker() { fn run_in_worker() {
let ctx = Context::global_context().clone(); let ctx = Context::global_context().clone();
let result = ctx.run_in_worker(|_| 42); let result = ctx.run_in_worker(|_| 42);
@ -310,7 +316,7 @@ mod tests {
} }
#[test] #[test]
#[cfg_attr(not(miri), traced_test)] #[cfg_attr(all(not(miri), feature = "tracing"), tracing_test::traced_test)]
fn context_spawn_future() { fn context_spawn_future() {
let ctx = Context::global_context().clone(); let ctx = Context::global_context().clone();
let task = ctx.spawn_future(async { 42 }); let task = ctx.spawn_future(async { 42 });
@ -321,7 +327,7 @@ mod tests {
} }
#[test] #[test]
#[cfg_attr(not(miri), traced_test)] #[cfg_attr(all(not(miri), feature = "tracing"), tracing_test::traced_test)]
fn context_spawn_async() { fn context_spawn_async() {
let ctx = Context::global_context().clone(); let ctx = Context::global_context().clone();
let task = ctx.spawn_async(|| async { 42 }); let task = ctx.spawn_async(|| async { 42 });
@ -332,7 +338,7 @@ mod tests {
} }
#[test] #[test]
#[cfg_attr(not(miri), traced_test)] #[cfg_attr(all(not(miri), feature = "tracing"), tracing_test::traced_test)]
fn context_spawn() { fn context_spawn() {
let ctx = Context::global_context().clone(); let ctx = Context::global_context().clone();
let counter = Arc::new(AtomicU8::new(0)); let counter = Arc::new(AtomicU8::new(0));
@ -352,7 +358,7 @@ mod tests {
} }
#[test] #[test]
#[cfg_attr(not(miri), traced_test)] #[cfg_attr(all(not(miri), feature = "tracing"), tracing_test::traced_test)]
fn inject_job_and_wake_worker() { fn inject_job_and_wake_worker() {
let ctx = Context::new_with_threads(1); let ctx = Context::new_with_threads(1);
let counter = Arc::new(AtomicU8::new(0)); let counter = Arc::new(AtomicU8::new(0));
@ -363,6 +369,7 @@ mod tests {
{ {
let counter = counter.clone(); let counter = counter.clone();
move || { move || {
#[cfg(feature = "tracing")]
tracing::info!("Job running"); tracing::info!("Job running");
counter.fetch_add(1, Ordering::SeqCst); counter.fetch_add(1, Ordering::SeqCst);

18
distaff/src/job.rs
View file

@ -514,6 +514,7 @@ impl<T> Job<T> {
return JobResult::new(result); return JobResult::new(result);
} else { } else {
// spin until lock is released. // spin until lock is released.
#[cfg(feature = "tracing")]
tracing::trace!("spin-waiting for job: {:?}", self); tracing::trace!("spin-waiting for job: {:?}", self);
spin.spin(); spin.spin();
} }
@ -543,6 +544,7 @@ impl<T> Job<T> {
Err(_) => { Err(_) => {
// debug_assert_ne!(state, JobState::Empty as usize); // debug_assert_ne!(state, JobState::Empty as usize);
#[cfg(feature = "tracing")]
tracing::error!("######## what the sigma?"); tracing::error!("######## what the sigma?");
spin.spin(); spin.spin();
} }
@ -551,6 +553,7 @@ impl<T> Job<T> {
} }
pub fn execute(job: NonNull<Self>) { pub fn execute(job: NonNull<Self>) {
#[cfg(feature = "tracing")]
tracing::trace!("executing job: {:?}", job); tracing::trace!("executing job: {:?}", job);
// SAFETY: self is non-null // SAFETY: self is non-null
@ -655,6 +658,7 @@ mod stackjob {
let result = std::panic::catch_unwind(std::panic::AssertUnwindSafe(|| f())); let result = std::panic::catch_unwind(std::panic::AssertUnwindSafe(|| f()));
#[cfg(feature = "tracing")]
tracing::trace!("stack job completed: {:?}", job); tracing::trace!("stack job completed: {:?}", job);
let job = unsafe { &*job.cast::<Job<T>>() }; let job = unsafe { &*job.cast::<Job<T>>() };
job.complete(result); job.complete(result);
@ -720,6 +724,7 @@ mod heapjob {
ptr::drop_in_place(job); ptr::drop_in_place(job);
} }
#[cfg(feature = "tracing")]
tracing::trace!("heap job completed: {:?}", job); tracing::trace!("heap job completed: {:?}", job);
// free box that was allocated at (1) // free box that was allocated at (1)
@ -1018,12 +1023,14 @@ impl<T: Send> Job2<T> {
receiver: Cell::new(None), receiver: Cell::new(None),
}; };
#[cfg(feature = "tracing")]
tracing::trace!("new job: {:?}", this); tracing::trace!("new job: {:?}", this);
this this
} }
pub fn share(&self, parker: Option<&Parker>) -> SharedJob { pub fn share(&self, parker: Option<&Parker>) -> SharedJob {
#[cfg(feature = "tracing")]
tracing::trace!("sharing job: {:?}", self); tracing::trace!("sharing job: {:?}", self);
let (sender, receiver) = parker let (sender, receiver) = parker
@ -1048,7 +1055,10 @@ impl<T: Send> Job2<T> {
F: FnOnce() -> T + Send, F: FnOnce() -> T + Send,
{ {
#[align(8)] #[align(8)]
#[tracing::instrument(level = "trace", skip_all, name = "stack_job_harness")] #[cfg_attr(
feature = "tracing",
tracing::instrument(level = "trace", skip_all, name = "stack_job_harness")
)]
unsafe fn harness<F, T, L>( unsafe fn harness<F, T, L>(
_worker: &WorkerThread, _worker: &WorkerThread,
this: NonNull<()>, this: NonNull<()>,
@ -1082,7 +1092,10 @@ impl<T: Send> Job2<T> {
F: FnOnce() -> T + Send, F: FnOnce() -> T + Send,
{ {
#[align(8)] #[align(8)]
#[tracing::instrument(level = "trace", skip_all, name = "heap_job_harness")] #[cfg_attr(
feature = "tracing",
tracing::instrument(level = "trace", skip_all, name = "heap_job_harness")
)]
unsafe fn harness<F, T>(_worker: &WorkerThread, this: NonNull<()>, sender: Option<Sender>) unsafe fn harness<F, T>(_worker: &WorkerThread, this: NonNull<()>, sender: Option<Sender>)
where where
F: FnOnce() -> T + Send, F: FnOnce() -> T + Send,
@ -1121,6 +1134,7 @@ impl<T: Send> Job2<T> {
impl SharedJob { impl SharedJob {
pub unsafe fn execute(self, worker: &WorkerThread) { pub unsafe fn execute(self, worker: &WorkerThread) {
#[cfg(feature = "tracing")]
tracing::trace!("executing shared job: {:?}", self); tracing::trace!("executing shared job: {:?}", self);
let Self { let Self {

11
distaff/src/join.rs
View file

@ -1,5 +1,6 @@
#[cfg(feature = "metrics")] #[cfg(feature = "metrics")]
use std::sync::atomic::Ordering; use std::sync::atomic::Ordering;
use std::{hint::cold_path, sync::Arc}; use std::{hint::cold_path, sync::Arc};
use crate::{ use crate::{
@ -11,15 +12,12 @@ use crate::{
impl WorkerThread { impl WorkerThread {
#[inline] #[inline]
#[tracing::instrument(level = "trace", skip_all)] #[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip_all))]
fn join_seq<A, B, RA, RB>(&self, a: A, b: B) -> (RA, RB) fn join_seq<A, B, RA, RB>(&self, a: A, b: B) -> (RA, RB)
where where
A: FnOnce() -> RA, A: FnOnce() -> RA,
B: FnOnce() -> RB, B: FnOnce() -> RB,
{ {
let span = tracing::trace_span!("join_seq");
let _guard = span.enter();
let rb = b(); let rb = b();
let ra = a(); let ra = a();
@ -64,7 +62,7 @@ impl WorkerThread {
/// This function must be called from a worker thread. /// This function must be called from a worker thread.
#[inline] #[inline]
#[tracing::instrument(level = "trace", skip_all)] #[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip_all))]
fn join_heartbeat<A, B, RA, RB>(&self, a: A, b: B) -> (RA, RB) fn join_heartbeat<A, B, RA, RB>(&self, a: A, b: B) -> (RA, RB)
where where
RA: Send, RA: Send,
@ -86,6 +84,7 @@ impl WorkerThread {
let rb = match catch_unwind(AssertUnwindSafe(|| b())) { let rb = match catch_unwind(AssertUnwindSafe(|| b())) {
Ok(val) => val, Ok(val) => val,
Err(payload) => { Err(payload) => {
#[cfg(feature = "tracing")]
tracing::debug!("join_heartbeat: b panicked, waiting for a to finish"); tracing::debug!("join_heartbeat: b panicked, waiting for a to finish");
cold_path(); cold_path();
@ -107,6 +106,7 @@ impl WorkerThread {
match self.wait_until_recv(recv) { match self.wait_until_recv(recv) {
Some(t) => crate::util::unwrap_or_panic(t), Some(t) => crate::util::unwrap_or_panic(t),
None => { None => {
#[cfg(feature = "tracing")]
tracing::trace!( tracing::trace!(
"join_heartbeat: job was shared, but reclaimed, running a() inline" "join_heartbeat: job was shared, but reclaimed, running a() inline"
); );
@ -120,6 +120,7 @@ impl WorkerThread {
unsafe { unsafe {
// SAFETY: we just popped the job from the queue, so it is safe to unwrap. // SAFETY: we just popped the job from the queue, so it is safe to unwrap.
#[cfg(feature = "tracing")]
tracing::trace!("join_heartbeat: job was not shared, running a() inline"); tracing::trace!("join_heartbeat: job was not shared, running a() inline");
a.unwrap()() a.unwrap()()
} }

41
distaff/src/latch.rs
View file

@ -229,6 +229,7 @@ impl Latch for CountLatch {
unsafe fn set_raw(this: *const Self) { unsafe fn set_raw(this: *const Self) {
unsafe { unsafe {
if (&*this).count.fetch_sub(1, Ordering::Relaxed) == 1 { if (&*this).count.fetch_sub(1, Ordering::Relaxed) == 1 {
#[cfg(feature = "tracing")]
tracing::trace!("CountLatch set_raw: count was 1, setting inner latch"); tracing::trace!("CountLatch set_raw: count was 1, setting inner latch");
// If the count was 1, we need to set the inner latch. // If the count was 1, we need to set the inner latch.
let inner = (*this).inner.load(Ordering::Relaxed); let inner = (*this).inner.load(Ordering::Relaxed);
@ -343,12 +344,19 @@ impl WorkerLatch {
} }
} }
#[tracing::instrument(level = "trace", skip_all, fields( #[cfg_attr(
this = self as *const Self as usize, feature = "tracing",
))] tracing::instrument(
level = "trace",
skip_all,
fields(this = self as *const Self as usize)
)
)]
pub fn lock(&self) -> parking_lot::MutexGuard<'_, bool> { pub fn lock(&self) -> parking_lot::MutexGuard<'_, bool> {
#[cfg(feature = "tracing")]
tracing::trace!("aquiring mutex.."); tracing::trace!("aquiring mutex..");
let guard = self.mutex.lock(); let guard = self.mutex.lock();
#[cfg(feature = "tracing")]
tracing::trace!("mutex acquired."); tracing::trace!("mutex acquired.");
guard guard
@ -374,9 +382,11 @@ impl WorkerLatch {
**guard = false; **guard = false;
} }
#[tracing::instrument(level = "trace", skip_all, fields( #[cfg_attr(
feature = "tracing",
tracing::instrument(level = "trace", skip_all, fields(
this = self as *const Self as usize, this = self as *const Self as usize,
))] )))]
pub fn wait_unless<F>(&self, mut f: F) pub fn wait_unless<F>(&self, mut f: F)
where where
F: FnMut() -> bool, F: FnMut() -> bool,
@ -387,9 +397,11 @@ impl WorkerLatch {
} }
} }
#[tracing::instrument(level = "trace", skip_all, fields( #[cfg_attr(
feature = "tracing",
tracing::instrument(level = "trace", skip_all, fields(
this = self as *const Self as usize, this = self as *const Self as usize,
))] )))]
pub fn wait_until<F, T>(&self, mut f: F) -> T pub fn wait_until<F, T>(&self, mut f: F) -> T
where where
F: FnMut() -> Option<T>, F: FnMut() -> Option<T>,
@ -407,11 +419,14 @@ impl WorkerLatch {
*self.mutex.lock() *self.mutex.lock()
} }
#[tracing::instrument(level = "trace", skip_all, fields( #[cfg_attr(
feature = "tracing",
tracing::instrument(level = "trace", skip_all, fields(
this = self as *const Self as usize, this = self as *const Self as usize,
))] )))]
fn notify(&self) { fn notify(&self) {
let n = self.condvar.notify_all(); let n = self.condvar.notify_all();
#[cfg(feature = "tracing")]
tracing::trace!("WorkerLatch notify: notified {} threads", n); tracing::trace!("WorkerLatch notify: notified {} threads", n);
} }
@ -424,8 +439,6 @@ impl WorkerLatch {
mod tests { mod tests {
use std::{ptr, sync::Arc}; use std::{ptr, sync::Arc};
use tracing_test::traced_test;
use super::*; use super::*;
#[test] #[test]
@ -491,7 +504,7 @@ mod tests {
} }
#[test] #[test]
#[cfg_attr(not(miri), traced_test)] #[cfg_attr(all(not(miri), feature = "tracing"), tracing_test::traced_test)]
fn mutex_latch() { fn mutex_latch() {
let latch = Arc::new(MutexLatch::new()); let latch = Arc::new(MutexLatch::new());
assert!(!latch.probe()); assert!(!latch.probe());
@ -503,8 +516,10 @@ mod tests {
// Test wait functionality // Test wait functionality
let latch_clone = latch.clone(); let latch_clone = latch.clone();
let handle = std::thread::spawn(move || { let handle = std::thread::spawn(move || {
#[cfg(feature = "tracing")]
tracing::info!("Thread waiting on latch"); tracing::info!("Thread waiting on latch");
latch_clone.wait_and_reset(); latch_clone.wait_and_reset();
#[cfg(feature = "tracing")]
tracing::info!("Thread woke up from latch"); tracing::info!("Thread woke up from latch");
}); });
@ -512,8 +527,10 @@ mod tests {
std::thread::sleep(std::time::Duration::from_millis(100)); std::thread::sleep(std::time::Duration::from_millis(100));
assert!(!latch.probe()); assert!(!latch.probe());
#[cfg(feature = "tracing")]
tracing::info!("Setting latch from main thread"); tracing::info!("Setting latch from main thread");
latch.set(); latch.set();
#[cfg(feature = "tracing")]
tracing::info!("Latch set, joining waiting thread"); tracing::info!("Latch set, joining waiting thread");
handle.join().expect("Thread should join successfully"); handle.join().expect("Thread should join successfully");
} }

23
distaff/src/scope.rs
View file

@ -87,11 +87,13 @@ where
} }
impl<'scope, 'env> Scope<'scope, 'env> { impl<'scope, 'env> Scope<'scope, 'env> {
#[tracing::instrument(level = "trace", skip_all)] #[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip_all))]
fn wait_for_jobs(&self, worker: &WorkerThread) { fn wait_for_jobs(&self, worker: &WorkerThread) {
self.job_counter.set_inner(worker.heartbeat.parker()); self.job_counter.set_inner(worker.heartbeat.parker());
if self.job_counter.count() > 0 { if self.job_counter.count() > 0 {
#[cfg(feature = "tracing")]
tracing::trace!("waiting for {} jobs to finish.", self.job_counter.count()); tracing::trace!("waiting for {} jobs to finish.", self.job_counter.count());
#[cfg(feature = "tracing")]
tracing::trace!( tracing::trace!(
"thread id: {:?}, jobs: {:?}", "thread id: {:?}, jobs: {:?}",
worker.heartbeat.index(), worker.heartbeat.index(),
@ -104,7 +106,7 @@ impl<'scope, 'env> Scope<'scope, 'env> {
} }
/// should be called from within a worker thread. /// should be called from within a worker thread.
#[tracing::instrument(level = "trace", skip_all)] #[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip_all))]
fn complete<F, R>(&self, worker: &WorkerThread, f: F) -> R fn complete<F, R>(&self, worker: &WorkerThread, f: F) -> R
where where
F: FnOnce() -> R + Send, F: FnOnce() -> R + Send,
@ -128,7 +130,7 @@ impl<'scope, 'env> Scope<'scope, 'env> {
} }
/// resumes the panic if one happened in this scope. /// resumes the panic if one happened in this scope.
#[tracing::instrument(level = "trace", skip_all)] #[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip_all))]
fn maybe_propagate_panic(&self) { fn maybe_propagate_panic(&self) {
let err_ptr = self.panic.load(Ordering::Relaxed); let err_ptr = self.panic.load(Ordering::Relaxed);
if !err_ptr.is_null() { if !err_ptr.is_null() {
@ -140,8 +142,9 @@ impl<'scope, 'env> Scope<'scope, 'env> {
} }
/// stores the first panic that happened in this scope. /// stores the first panic that happened in this scope.
#[tracing::instrument(level = "trace", skip_all)] #[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip_all))]
fn panicked(&self, err: Box<dyn Any + Send + 'static>) { fn panicked(&self, err: Box<dyn Any + Send + 'static>) {
#[cfg(feature = "tracing")]
tracing::debug!("panicked in scope, storing error: {:?}", err); tracing::debug!("panicked in scope, storing error: {:?}", err);
self.panic.load(Ordering::Relaxed).is_null().then(|| { self.panic.load(Ordering::Relaxed).is_null().then(|| {
use core::mem::ManuallyDrop; use core::mem::ManuallyDrop;
@ -292,13 +295,11 @@ impl<'scope, 'env> Scope<'scope, 'env> {
mod tests { mod tests {
use std::sync::atomic::AtomicU8; use std::sync::atomic::AtomicU8;
use tracing_test::traced_test;
use super::*; use super::*;
use crate::ThreadPool; use crate::ThreadPool;
#[test] #[test]
#[cfg_attr(not(miri), traced_test)] #[cfg_attr(all(not(miri), feature = "tracing"), tracing_test::traced_test)]
fn scope_spawn_sync() { fn scope_spawn_sync() {
let pool = ThreadPool::new_with_threads(1); let pool = ThreadPool::new_with_threads(1);
let count = Arc::new(AtomicU8::new(0)); let count = Arc::new(AtomicU8::new(0));
@ -313,7 +314,7 @@ mod tests {
} }
#[test] #[test]
#[cfg_attr(not(miri), traced_test)] #[cfg_attr(all(not(miri), feature = "tracing"), tracing_test::traced_test)]
fn scope_join_one() { fn scope_join_one() {
let pool = ThreadPool::new_with_threads(1); let pool = ThreadPool::new_with_threads(1);
@ -326,7 +327,7 @@ mod tests {
} }
#[test] #[test]
#[cfg_attr(not(miri), traced_test)] #[cfg_attr(all(not(miri), feature = "tracing"), tracing_test::traced_test)]
fn scope_join_many() { fn scope_join_many() {
let pool = ThreadPool::new_with_threads(1); let pool = ThreadPool::new_with_threads(1);
@ -348,7 +349,7 @@ mod tests {
} }
#[test] #[test]
#[cfg_attr(not(miri), traced_test)] #[cfg_attr(all(not(miri), feature = "tracing"), tracing_test::traced_test)]
fn scope_spawn_future() { fn scope_spawn_future() {
let pool = ThreadPool::new_with_threads(1); let pool = ThreadPool::new_with_threads(1);
let mut x = 0; let mut x = 0;
@ -364,7 +365,7 @@ mod tests {
} }
#[test] #[test]
#[cfg_attr(not(miri), traced_test)] #[cfg_attr(all(not(miri), feature = "tracing"), tracing_test::traced_test)]
fn scope_spawn_many() { fn scope_spawn_many() {
let pool = ThreadPool::new_with_threads(1); let pool = ThreadPool::new_with_threads(1);
let count = Arc::new(AtomicU8::new(0)); let count = Arc::new(AtomicU8::new(0));

9
distaff/src/threadpool.rs
View file

@ -53,17 +53,16 @@ impl ThreadPool {
#[cfg(test)] #[cfg(test)]
mod tests { mod tests {
use tracing_test::traced_test;
use super::*; use super::*;
#[test] #[test]
#[cfg_attr(not(miri), traced_test)] #[cfg_attr(all(not(miri), feature = "tracing"), tracing_test::traced_test)]
fn pool_spawn_borrow() { fn pool_spawn_borrow() {
let pool = ThreadPool::new_with_threads(1); let pool = ThreadPool::new_with_threads(1);
let mut x = 0; let mut x = 0;
pool.scope(|scope| { pool.scope(|scope| {
scope.spawn(|_| { scope.spawn(|_| {
#[cfg(feature = "tracing")]
tracing::info!("Incrementing x"); tracing::info!("Incrementing x");
x += 1; x += 1;
}); });
@ -72,7 +71,7 @@ mod tests {
} }
#[test] #[test]
#[cfg_attr(not(miri), traced_test)] #[cfg_attr(all(not(miri), feature = "tracing"), tracing_test::traced_test)]
fn pool_spawn_future() { fn pool_spawn_future() {
let pool = ThreadPool::new_with_threads(1); let pool = ThreadPool::new_with_threads(1);
let mut x = 0; let mut x = 0;
@ -89,7 +88,7 @@ mod tests {
} }
#[test] #[test]
#[cfg_attr(not(miri), traced_test)] #[cfg_attr(all(not(miri), feature = "tracing"), tracing_test::traced_test)]
fn pool_join() { fn pool_join() {
let pool = ThreadPool::new_with_threads(1); let pool = ThreadPool::new_with_threads(1);
let (a, b) = pool.join(|| 3 + 4, || 5 * 6); let (a, b) = pool.join(|| 3 + 4, || 5 * 6);

35
distaff/src/workerthread.rs
View file

@ -1,5 +1,6 @@
#[cfg(feature = "metrics")] #[cfg(feature = "metrics")]
use std::sync::atomic::Ordering; use std::sync::atomic::Ordering;
use std::{ use std::{
cell::{Cell, UnsafeCell}, cell::{Cell, UnsafeCell},
ptr::NonNull, ptr::NonNull,
@ -22,6 +23,7 @@ pub struct WorkerThread {
pub(crate) queue: UnsafeCell<JobList>, pub(crate) queue: UnsafeCell<JobList>,
pub(crate) heartbeat: OwnedHeartbeatReceiver, pub(crate) heartbeat: OwnedHeartbeatReceiver,
pub(crate) join_count: Cell<u8>, pub(crate) join_count: Cell<u8>,
#[cfg(feature = "metrics")] #[cfg(feature = "metrics")]
pub(crate) metrics: CachePadded<crate::metrics::WorkerMetrics>, pub(crate) metrics: CachePadded<crate::metrics::WorkerMetrics>,
} }
@ -46,9 +48,9 @@ impl WorkerThread {
} }
impl WorkerThread { impl WorkerThread {
#[tracing::instrument(level = "trace", skip_all, fields( #[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip_all, fields(
worker = self.heartbeat.index(), worker = self.heartbeat.index(),
))] )))]
pub fn run(self: Box<Self>, barrier: Arc<Barrier>) { pub fn run(self: Box<Self>, barrier: Arc<Barrier>) {
let this = Box::into_raw(self); let this = Box::into_raw(self);
unsafe { unsafe {
@ -61,6 +63,7 @@ impl WorkerThread {
Self::drop_in_place(this); Self::drop_in_place(this);
}); });
#[cfg(feature = "tracing")]
tracing::trace!("WorkerThread::run: starting worker thread"); tracing::trace!("WorkerThread::run: starting worker thread");
barrier.wait(); barrier.wait();
@ -73,10 +76,11 @@ impl WorkerThread {
eprintln!("{:?}", (&*this).metrics); eprintln!("{:?}", (&*this).metrics);
} }
#[cfg(feature = "tracing")]
tracing::trace!("WorkerThread::run: worker thread finished"); tracing::trace!("WorkerThread::run: worker thread finished");
} }
#[tracing::instrument(level = "trace", skip_all)] #[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip_all))]
fn run_inner(&self) { fn run_inner(&self) {
let mut job = None; let mut job = None;
'outer: loop { 'outer: loop {
@ -104,19 +108,21 @@ impl WorkerThread {
/// which it returns `None`. /// which it returns `None`.
/// The caller should then check for `should_exit` to determine if the /// The caller should then check for `should_exit` to determine if the
/// thread should exit, or look for work again. /// thread should exit, or look for work again.
#[tracing::instrument(level = "trace", skip_all)] #[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip_all))]
pub(crate) fn find_work_or_wait(&self) -> Option<SharedJob> { pub(crate) fn find_work_or_wait(&self) -> Option<SharedJob> {
if let Some(job) = self.find_work() { if let Some(job) = self.find_work() {
return Some(job); return Some(job);
} }
#[cfg(feature = "tracing")]
tracing::trace!("waiting for new job"); tracing::trace!("waiting for new job");
self.heartbeat.parker().park(); self.heartbeat.parker().park();
#[cfg(feature = "tracing")]
tracing::trace!("woken up from wait"); tracing::trace!("woken up from wait");
None None
} }
#[tracing::instrument(level = "trace", skip_all)] #[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip_all))]
pub(crate) fn find_work_or_wait_unless<F>(&self, mut pred: F) -> Option<SharedJob> pub(crate) fn find_work_or_wait_unless<F>(&self, mut pred: F) -> Option<SharedJob>
where where
F: FnMut() -> bool, F: FnMut() -> bool,
@ -130,10 +136,12 @@ impl WorkerThread {
// job we scheduled. // job we scheduled.
// !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! // !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
// no jobs found, wait for a heartbeat or a new job // no jobs found, wait for a heartbeat or a new job
#[cfg(feature = "tracing")]
tracing::trace!(worker = self.heartbeat.index(), "waiting for new job"); tracing::trace!(worker = self.heartbeat.index(), "waiting for new job");
if !pred() { if !pred() {
self.heartbeat.parker().park(); self.heartbeat.parker().park();
} }
#[cfg(feature = "tracing")]
tracing::trace!(worker = self.heartbeat.index(), "woken up from wait"); tracing::trace!(worker = self.heartbeat.index(), "woken up from wait");
None None
@ -146,6 +154,7 @@ impl WorkerThread {
if let Some(job) = guard.pop_job() { if let Some(job) = guard.pop_job() {
#[cfg(feature = "metrics")] #[cfg(feature = "metrics")]
self.metrics.num_jobs_stolen.fetch_add(1, Ordering::Relaxed); self.metrics.num_jobs_stolen.fetch_add(1, Ordering::Relaxed);
#[cfg(feature = "tracing")]
tracing::trace!("WorkerThread::find_work_inner: found shared job: {:?}", job); tracing::trace!("WorkerThread::find_work_inner: found shared job: {:?}", job);
return Some(job); return Some(job);
} }
@ -158,6 +167,7 @@ impl WorkerThread {
if self.heartbeat.take() { if self.heartbeat.take() {
#[cfg(feature = "metrics")] #[cfg(feature = "metrics")]
self.metrics.num_heartbeats.fetch_add(1, Ordering::Relaxed); self.metrics.num_heartbeats.fetch_add(1, Ordering::Relaxed);
#[cfg(feature = "tracing")]
tracing::trace!( tracing::trace!(
"received heartbeat, thread id: {:?}", "received heartbeat, thread id: {:?}",
self.heartbeat.index() self.heartbeat.index()
@ -167,7 +177,7 @@ impl WorkerThread {
} }
#[inline] #[inline]
#[tracing::instrument(level = "trace", skip(self))] #[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip(self)))]
fn execute(&self, job: SharedJob) { fn execute(&self, job: SharedJob) {
unsafe { SharedJob::execute(job, self) }; unsafe { SharedJob::execute(job, self) };
self.tick(); self.tick();
@ -179,6 +189,7 @@ impl WorkerThread {
if !guard.jobs.contains_key(&self.heartbeat.id()) { if !guard.jobs.contains_key(&self.heartbeat.id()) {
if let Some(job) = self.pop_back() { if let Some(job) = self.pop_back() {
#[cfg(feature = "tracing")]
tracing::trace!("heartbeat: sharing job: {:?}", job); tracing::trace!("heartbeat: sharing job: {:?}", job);
#[cfg(feature = "metrics")] #[cfg(feature = "metrics")]
@ -270,8 +281,9 @@ impl HeartbeatThread {
Self { ctx } Self { ctx }
} }
#[tracing::instrument(level = "trace", skip(self))] #[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip(self)))]
pub fn run(self, barrier: Arc<Barrier>) { pub fn run(self, barrier: Arc<Barrier>) {
#[cfg(feature = "tracing")]
tracing::trace!("new heartbeat thread {:?}", std::thread::current()); tracing::trace!("new heartbeat thread {:?}", std::thread::current());
barrier.wait(); barrier.wait();
@ -302,7 +314,7 @@ impl HeartbeatThread {
} }
impl WorkerThread { impl WorkerThread {
#[tracing::instrument(level = "trace", skip(self))] #[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip(self)))]
pub fn wait_until_shared_job<T: Send>(&self, job: &Job<T>) -> Option<std::thread::Result<T>> { pub fn wait_until_shared_job<T: Send>(&self, job: &Job<T>) -> Option<std::thread::Result<T>> {
let recv = (*job).take_receiver().unwrap(); let recv = (*job).take_receiver().unwrap();
@ -321,7 +333,7 @@ impl WorkerThread {
out out
} }
#[tracing::instrument(level = "trace", skip_all)] #[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip_all))]
pub fn wait_until_recv<T: Send>(&self, recv: Receiver<T>) -> Option<std::thread::Result<T>> { pub fn wait_until_recv<T: Send>(&self, recv: Receiver<T>) -> Option<std::thread::Result<T>> {
if self if self
.context .context
@ -330,6 +342,7 @@ impl WorkerThread {
.remove(&self.heartbeat.id()) .remove(&self.heartbeat.id())
.is_some() .is_some()
{ {
#[cfg(feature = "tracing")]
tracing::trace!("reclaiming shared job"); tracing::trace!("reclaiming shared job");
return None; return None;
} }
@ -347,12 +360,13 @@ impl WorkerThread {
Some(recv.recv()) Some(recv.recv())
} }
#[tracing::instrument(level = "trace", skip_all)] #[cfg_attr(feature = "tracing", tracing::instrument(level = "trace", skip_all))]
pub fn wait_until_pred<F>(&self, mut pred: F) pub fn wait_until_pred<F>(&self, mut pred: F)
where where
F: FnMut() -> bool, F: FnMut() -> bool,
{ {
if !pred() { if !pred() {
#[cfg(feature = "tracing")]
tracing::trace!("thread {:?} waiting on predicate", self.heartbeat.index()); tracing::trace!("thread {:?} waiting on predicate", self.heartbeat.index());
self.wait_until_latch_cold(pred); self.wait_until_latch_cold(pred);
} }
@ -364,6 +378,7 @@ impl WorkerThread {
F: FnMut() -> bool, F: FnMut() -> bool,
{ {
if let Some(shared_job) = self.context.shared().jobs.remove(&self.heartbeat.id()) { if let Some(shared_job) = self.context.shared().jobs.remove(&self.heartbeat.id()) {
#[cfg(feature = "tracing")]
tracing::trace!( tracing::trace!(
"thread {:?} reclaiming shared job: {:?}", "thread {:?} reclaiming shared job: {:?}",
self.heartbeat.index(), self.heartbeat.index(),