connect flecs to tracing ecosystem

Cargo.toml

@@ -1,5 +1,5 @@
 [workspace]
-members = ["flecs_ecs", "flecs_ecs_derive", "flecs_ecs_sys", "test_crash_handler"]
+members = ["flecs_ecs", "flecs_ecs_derive", "flecs_ecs_sys", "flecs_ecs_tracing", "test_crash_handler"]
 resolver = "2"
 
 exclude = [

flecs_ecs_tracing/Cargo.toml

@@ -0,0 +1,23 @@
+[package]
+name = "flecs_ecs_tracing"
+version = "0.1.0"
+edition.workspace = true
+license.workspace = true
+repository.workspace = true
+rust-version.workspace = true
+
+[lints]
+workspace = true
+
+[dependencies]
+flecs_ecs = { version = "0.1.3", path = "../flecs_ecs" }
+fxhash = "0.2.1"
+tracing-core = "0.1.32"
+
+[dev-dependencies]
+# for doctest/example
+tracing = "0.1.40"
+tracing-subscriber = { version = "0.3.18", features = ["env-filter"] }
+
+[features]
+perf_trace = ["flecs_ecs/flecs_perf_trace"]

flecs_ecs_tracing/src/lib.rs

@@ -0,0 +1,95 @@
+//! Integrates Flecs ECS logging and performance tracing into the `tracing` ecosystem.
+
+use flecs_ecs::prelude::*;
+
+mod log;
+mod metadata;
+#[cfg(feature = "perf_trace")]
+mod perf_trace;
+mod util;
+
+/// Send Flecs internal logging to `tracing` subscribers instead.
+///
+/// Note that the application will need to set up those subscribers; by default, logs will go nowhere.
+///
+/// This must be called before the first [`World`] is created anywhere in the process;
+/// see [`ecs_os_api::add_init_hook`] for details on those limitations.
+///
+/// # Example
+/// ```no_run
+/// use flecs_ecs::prelude::*;
+/// use flecs_ecs_tracing::log_to_tracing;
+/// use tracing_subscriber::prelude::*;
+///
+/// tracing_subscriber::registry()
+///     // Send logs to stdout
+///     .with(
+///         tracing_subscriber::fmt::layer()
+///             // By default, hide anything below WARN log level from stdout
+///             .with_filter(
+///                 tracing_subscriber::EnvFilter::builder()
+///                     .with_default_directive(tracing::level_filters::LevelFilter::WARN.into())
+///                     .from_env_lossy(),
+///             ),
+///     )
+///     .init();
+///
+/// log_to_tracing();
+/// let world = World::new();
+/// ```
+pub fn log_to_tracing() {
+    // Ensure that the registry is initialized now
+    metadata::init();
+
+    ecs_os_api::add_init_hook(Box::new(|api| {
+        api.log_ = Some(log::log_to_tracing);
+    }));
+}
+
+#[cfg(feature = "perf_trace")]
+/// Send Flecs performance traces to `tracing` subscribers.
+///
+/// This must be called before the first [`World`] is created anywhere in the process;
+/// see [`ecs_os_api::add_init_hook`] for details on those limitations.
+///
+/// # Example
+/// ```ignore
+/// use flecs_ecs::prelude::*;
+/// use flecs_ecs_tracing::{log_to_tracing, perf_trace_to_tracing};
+/// use tracing_subscriber::prelude::*;
+///
+/// tracing_subscriber::registry()
+///     // Send logs to stdout
+///     .with(
+///         tracing_subscriber::fmt::layer()
+///             // By default, hide anything below WARN log level from stdout
+///             .with_filter(
+///                 tracing_subscriber::EnvFilter::builder()
+///                     .with_default_directive(tracing::level_filters::LevelFilter::WARN.into())
+///                     .from_env_lossy(),
+///             ),
+///     )
+///     // Send logs and performance tracing data to the Tracy profiler
+///     .with(
+///         tracing_tracy::TracyLayer::default()
+///             .with_filter(tracing::level_filters::LevelFilter::INFO),
+///     )
+///     .init();
+///
+/// log_to_tracing();
+/// perf_trace_to_tracing(tracing::Level::INFO);
+///
+/// let world = World::new();
+/// ```
+pub fn perf_trace_to_tracing(span_level: tracing_core::Level) {
+    // Ensure that the registry is initialized now
+    perf_trace::init();
+
+    // Set the log level of performance tracing spans
+    perf_trace::SPAN_LEVEL.get_or_init(|| span_level);
+
+    ecs_os_api::add_init_hook(Box::new(|api| {
+        api.perf_trace_push_ = Some(perf_trace::perf_trace_push);
+        api.perf_trace_pop_ = Some(perf_trace::perf_trace_pop);
+    }));
+}

flecs_ecs_tracing/src/log.rs

@@ -0,0 +1,82 @@
+use std::borrow::Cow;
+
+use crate::{metadata, util::*};
+use tracing_core::{Dispatch, Metadata};
+
+fn ensure_event_meta(
+    dispatch: &Dispatch,
+    request: metadata::MetadataRequest<'_>,
+) -> &'static Metadata<'static> {
+    // Double-checked locking
+    {
+        let registry = metadata::REGISTRY.read().unwrap();
+        if let Some(existing) = registry.metadata.get(&request) {
+            return existing;
+        }
+    }
+
+    let mut registry = metadata::REGISTRY.write().unwrap();
+
+    if let Some(existing) = registry.metadata.get(&request) {
+        return existing;
+    }
+
+    let (metadata, request) = request.register(dispatch);
+    registry.metadata.insert(request, metadata);
+
+    metadata
+}
+
+fn get_event_meta(
+    dispatch: &Dispatch,
+    filename: Option<Cow<'_, str>>,
+    line: i32,
+    level: tracing_core::metadata::Level,
+) -> &'static Metadata<'static> {
+    let request = metadata::MetadataRequest {
+        kind: metadata::MetadataKind::Event,
+        name: Cow::Borrowed("log"),
+        filename,
+        line: line.try_into().ok(),
+        level,
+    };
+
+    if let Some(existing) = metadata::REGISTRY.read().unwrap().metadata.get(&request) {
+        // existing metadata - fast path
+        return existing;
+    }
+
+    // new metadata - slow path
+    ensure_event_meta(dispatch, request)
+}
+
+pub(crate) unsafe extern "C-unwind" fn log_to_tracing(
+    level: i32,
+    file: *const i8,
+    line: i32,
+    msg: *const i8,
+) {
+    tracing_core::dispatcher::get_default(|dispatch| {
+        let file = flecs_str(file);
+        let msg = flecs_str(msg).unwrap_or(Cow::Borrowed(""));
+        let level = match level {
+            -4 | -3 => tracing_core::metadata::Level::ERROR,
+            -2 => tracing_core::metadata::Level::WARN,
+            0 => tracing_core::metadata::Level::INFO,
+            1..=3 => tracing_core::metadata::Level::DEBUG,
+            _ => tracing_core::metadata::Level::TRACE,
+        };
+
+        let meta = get_event_meta(dispatch, file, line, level);
+        if dispatch.enabled(meta) {
+            let message_field = meta.fields().iter().next().expect("FieldSet corrupted");
+            tracing_core::Event::dispatch(
+                meta,
+                &meta.fields().value_set(&[(
+                    &message_field,
+                    Some(&(format_args!("{msg}")) as &dyn tracing_core::field::Value),
+                )]),
+            );
+        }
+    });
+}

flecs_ecs_tracing/src/metadata.rs

@@ -0,0 +1,157 @@
+//! Construct [`tracing_core::Metadata`] objects in the way required by that ecosystem.
+//!
+//! Dynamic call site stuff based on <https://github.com/slowli/tracing-toolbox/>
+
+use crate::util::*;
+use std::{
+    borrow::Cow,
+    collections::HashMap,
+    sync::{LazyLock, OnceLock, RwLock},
+};
+use tracing_core::{field::FieldSet, metadata::Level, Dispatch, Kind, Metadata};
+
+/// Registry of dynamic tracing metadata generated from Flecs
+pub(crate) static REGISTRY: LazyLock<RwLock<Registry>> = LazyLock::new(Default::default);
+
+/// Registry of dynamic tracing metadata generated from Flecs
+pub(crate) struct Registry {
+    pub(crate) metadata:
+        HashMap<MetadataRequest<'static>, &'static Metadata<'static>, fxhash::FxBuildHasher>,
+}
+
+impl Default for Registry {
+    fn default() -> Self {
+        Self {
+            // Capacity was chosen arbitrarily
+            metadata: HashMap::with_capacity_and_hasher(256, Default::default()),
+        }
+    }
+}
+
+pub(crate) fn init() {
+    LazyLock::force(&REGISTRY);
+}
+
+#[derive(Default)]
+pub(crate) struct DynamicCallsite {
+    /// Due to the opaque [`tracing_core::callsite::Identifier`],
+    /// which borrows [`tracing_core::Callsite`] for `'static`, have to use interior mutability.
+    ///
+    /// See [`MetadataRequest::register`] for details
+    pub(crate) metadata: OnceLock<Metadata<'static>>,
+}
+
+impl tracing_core::Callsite for DynamicCallsite {
+    fn set_interest(&self, _interest: tracing_core::Interest) {
+        // No-op
+    }
+
+    fn metadata(&self) -> &Metadata<'_> {
+        self.metadata.get().unwrap()
+    }
+}
+
+#[derive(Debug, Clone, Copy, PartialEq, Eq, Hash)]
+pub(crate) enum MetadataKind {
+    // hash/eq skip filename/line since they may differ between start & stop
+    // only used when perf_trace is enabled
+    #[cfg_attr(not(feature = "perf_trace"), allow(unused))]
+    Span,
+    Event,
+}
+
+#[derive(Clone, Debug)]
+pub(crate) struct MetadataRequest<'a> {
+    pub(crate) kind: MetadataKind,
+    pub(crate) level: Level,
+    pub(crate) name: Cow<'a, str>,
+    pub(crate) filename: Option<Cow<'a, str>>,
+    pub(crate) line: Option<u32>,
+}
+
+impl<'a> PartialEq for MetadataRequest<'a> {
+    fn eq(&self, other: &Self) -> bool {
+        self.kind == other.kind
+            && self.name == other.name
+            && self.level == other.level
+            && match self.kind {
+                MetadataKind::Span => true,
+                MetadataKind::Event => self.filename == other.filename && self.line == other.line,
+            }
+    }
+}
+
+impl<'a> Eq for MetadataRequest<'a> {}
+
+impl<'a> std::hash::Hash for MetadataRequest<'a> {
+    fn hash<H: std::hash::Hasher>(&self, state: &mut H) {
+        self.kind.hash(state);
+        self.name.hash(state);
+        self.level.hash(state);
+        match self.kind {
+            MetadataKind::Span => {}
+            MetadataKind::Event => {
+                self.filename.hash(state);
+                self.line.hash(state);
+            }
+        }
+    }
+}
+
+impl<'a> MetadataRequest<'a> {
+    /// Construct a new [`Metadata`].
+    ///
+    /// Does not interact with [`crate::REGISTRY`] by design to avoid having to deal with locking;
+    /// the caller should handle memoization if necessary.
+    pub(crate) fn register(
+        self,
+        dispatch: &Dispatch,
+    ) -> (&'static Metadata<'static>, MetadataRequest<'static>) {
+        // `Dispatch::register_callsite` demands `&'static Metadata`, this is the simplest way to get that
+        let callsite = Box::leak(Box::new(DynamicCallsite::default()));
+
+        // This macro is the only 'public' way of constructing [`Identifier`]
+        let id = tracing_core::identify_callsite!(callsite);
+
+        let name = leak_cowstr(self.name);
+        let filename: Option<&'static str> = self.filename.map(leak_cowstr);
+
+        let metadata = Metadata::new(
+            name,
+            "flecs",
+            self.level,
+            filename,
+            self.line,
+            Some("flecs_ecs_tracing"),
+            match self.kind {
+                MetadataKind::Span { .. } => FieldSet::new(&[], id),
+                MetadataKind::Event { .. } => FieldSet::new(&["message"], id),
+            },
+            match self.kind {
+                MetadataKind::Span { .. } => Kind::SPAN,
+                MetadataKind::Event { .. } => Kind::EVENT,
+            },
+        );
+
+        // Store the new Metadata
+        callsite.metadata.set(metadata).unwrap();
+
+        // Since the `DynamicCallsite` is alive forever we can also use it to get
+        // a `&'static` to the metadata, without extra allocations
+        let metadata: &'static Metadata = callsite.metadata.get().unwrap();
+
+        // Tell `tracing` subscribers about the new callsite
+        dispatch.register_callsite(metadata);
+
+        (
+            metadata,
+            MetadataRequest {
+                name: Cow::Borrowed(name),
+                kind: self.kind,
+                filename: filename.map(Cow::Borrowed),
+                line: self.line,
+                level: self.level,
+            },
+        )
+    }
+}