Implement pretty component logging

[janhohenheim]

Objective

log_components looks like this:

eek! what is going on??? I could pretty-print this by fiddling with the logging filters, but that

• is weird boilerplate, just arcane enough that I would not be able to do it without looking it up or copy-pasting it from somewhere and
• would change ALL debug prints to use newlines, which would flood my terminal.

Can I just pretty print the component log plz?

Solution

Add log_components_pretty:

much better!

• The name and the entity ID of the logged entity
• All component names without the DebugName wrapper
• Alphanumerically sorted components

And we can go one step further when downstream (thanks Chris!)

DefaultPlugins.set(bevy::log::LogPlugin {
            fmt_layer: |_| {
                Some(Box::new(
                    bevy::log::tracing_subscriber::fmt::Layer::default()
                        .map_fmt_fields(|f| f.debug_alt())
                        .with_writer(std::io::stderr),
                ))
            },
            ..default()
        })

which gives us newlines:

Additional info

Added a debug feature because the experience of getting blasted with 30 strings telling me to enable a feature is suboptimal.

[ChristopherBiscardi]

The alternative is to use the logging infrastructure to do this.

fn fmt_layer(
    _app: &mut App,
) -> Option<bevy::log::BoxedFmtLayer> {
    Some(Box::new(
        bevy::log::tracing_subscriber::fmt::Layer::default()
        .map_fmt_fields(|f| f.debug_alt())
        .with_writer(std::io::stderr),
    ))
}

.add_plugins(DefaultPlugins.set(bevy::log::LogPlugin {
    fmt_layer,
    ..default()
}))

and log_components upstream should really be:

pub fn log_components() -> impl EntityCommand {
    move |entity: EntityWorldMut| {
        let debug_infos: Vec<_> = entity
            .world()
            .inspect_entity(entity.id())
            .expect("Entity existence is verified before an EntityCommand is executed")
            .map(bevy::ecs::component::ComponentInfo::name)
            .collect();
        info!(
            entity=?entity.id(),
            names=?debug_infos,
            "log_components"
        );
    }
}

which results in:

---

DebugName's Debug format probably also shouldn't print DebugName{ name: x }

[ChristopherBiscardi]

also 0.17 regressed the output here by introducing DebugName. The 0.16 output used to be just the strings:

[alice-i-cecile]

I like this, but I'd prefer to only have one method for this. I'm fine to either make this the only method, or to require users to provide an argument to log_components.

[janhohenheim]

I did not know that the alt debugger was different from pretty printing! Tried it out and it's lovely. Changed it to Chris' suggestion :)

Not updating the screenshots since it looks basically the same as my original PR.
Updated screenshots!

[ChristopherBiscardi]

just leaving a note here that this isn't as_string because as_string only exists on debug whereas to_string handles the debug/no-debug difference

[Lyndon-Mackay]

I don’t want to block this, but something to consider is being able to put these in a span as my default logging settings tend to block info level logs from sources other then my game.

If I could put an optional span name it would be easier to just allow a specific span name.

Even if you don’t use span for filtering it could be another way of pinning down the specific log?

[Lyndon-Mackay]

I don’t want to block this, but something to consider is being able to put these in a span as my default logging settings tend to block info level logs from sources other then my game.

If I could put an optional span name it would be easier to just allow a specific span name.

Even if you don’t use span for filtering it could be another way of pinning down the specific log?

I think it is best to defer to another request, as discussed in discord