Enhance tokio-tracing with Optional Event ID Metadata for Improved Logging Efficiency

[lalitb]

I'd like to share an idea with you all about potentially improving the usability and efficiency of tokio-tracing, particularly for logging and diagnostics. This idea draws inspiration from the way .Net and Otel C++ handle event IDs for log entries. Here's a bit more about what influences this suggestion:

• The way .NET uses event IDs in its logging system.
• The user-facing logging API in OpenTelemetry C++ (see here for more details).

I don't know much about the internals of tokio-tracing, which is exactly why I'm bringing this idea to the table. I'm looking for guidance, suggestions, and to understand if this is even feasible for those who are more acquainted with the crate's nuances.

The proposal is the idea to introduce an optional id field to the Metadata struct within tokio-tracing. This ID would act as a unique identifier, similar to how EventId.Id works in .Net and C++. The main aim here is to enable quicker and more efficient filtering, identification, and categorization of log entries. Numeric IDs, after all, can often be processed faster than string comparisons, especially when it comes to filtering and searching. This is a critical consideration in system languages like Rust and C++. By making this new field optional and designing it to be non-disruptive to current implementations, we can preserve backward compatibility while also offering an enhanced functionality for those who could benefit from it.

One of the use-case for this support would be Otel logging subscriber, where the LogData/LogRecord structures could be updated for supporting EventId along with the EventName

cc @cijothomas

[hawkw]

tracing metadata already has a notion of a "callsite identifier" which uniquely identifies an invocation of each event! or span! macro, which, as far as I can tell, sounds similar to what you're looking for. These Identifiers are based on the address of the static generated by the macro invocation and should be unique within the binary. Currently, we do not expose a way to turn them into an integer, but they do implement Hash, PartialEq, and Eq, so they can be compared to each other and used as hash map keys etc.

[lalitb]

Thanks, correct me, the callsite seems to be providing unique identifier for each event!/span! macro invocation, but the proposal here is for an identifier tied to an event-type :

Eg, for demonstration purpose:

  // pre-computed set of error-codes, to be used for logging.

lazy_static! {
    static ref ERROR_MESSAGES: HashMap<u16, &'static str> = {
        let mut m = HashMap::new();
        m.insert(404, "UserNotFound");
        m.insert(500, "DatabaseConnectionFailed");
        m.insert(413, "PayloadTooLarge");
        m
    };
}
async fn handle_request(payload_size: usize) -> Result<(), u16> {
    if payload_size > 1024 {
        // Simulate a Payload Too Large error
        let status_code = 413;
        if let Some(error_message) = ERROR_MESSAGES.get(&status_code) {
            event!(Level::ERROR, id: %status_code, name: %error_message, "Payload size exceeds limit: {}", payload_size);
        }
        return Err(status_code);
    }

    // Other error scenarios...
    // Simulate an Internal Server Error
    let simulate_internal_error = false;
    if simulate_internal_error {
        let status_code = 500;
        if let Some(error_message) = ERROR_MESSAGES.get(&status_code) {
            event!(Level::ERROR, id: %status_code, name: %error_message, "An internal server error occurred");
        }
        return Err(status_code);
    }

    // Simulate successful request handling
    Ok(())
}

Imagine a situation where a subscriber aims to filter log events by using the subscriber::event_enabled() method, focusing on a specific pattern. In this case, filtering by performing a numerical comparison of the id metadata proves to be more straightforward and efficient than applying regex on the name. The applications using the instrumented library would in general want minimal overhead (near ~0) for the logging macro call for the events which are disabled.

EDIT: Updated to demonstrate the event_enabled() example below for filtering events based on severity, name and id.

   fn event_enabled(
        &self,
        event: &tracing_core::Event<'_>,
        _ctx: tracing_subscriber::layer::Context<'_, S>,
    ) -> bool {
           let metadata = event.metadata();

        // Example of filtering based on severity
        if metadata.level() <= &Level::WARN {
            return false; // Skip events below warning level
        }
        ....
  
        // costly event filtering based on event-name pattern
        let name = metadata.name();
        if name.contains("PayloadTooLarge") || name.starts_with("Database") {
            return true;
        } 

      // much efficient filtering using event-id.
       if let Some(id_field) = event.field("id") {
           if let Ok(id) = id_field.to_string().parse::<u16>() {
              return id >= 400 && id <= 499;
           }
       }
       true
}