log span that doesn't exit to openobserve

[brianmay]

I had code that looked something like (not exact, just to show concept):

fn process_messages(id: Id, rx: Pipe) [
  debug!(?id, "enter")

  loop {
    let rx = rx.recv();
    debug!(?id, "doing something");
    debug!(?id, "doing something else");
  }
}

This function continues for the life of the program. It never exits.

The problem is that I have to remember to pass ?id to every log message. The solution which a lot of people mention is to use spans, Ok, so lets change that to:

#[instrument(fields(id), skip_all)]
fn process_messages(id: Id, rx: Pipe) [
  debug!("enter")

  loop {
    let rx = rx.recv();
    debug!("doing something");
    debug!("doing something else");
  }
}

But now I have the problem, that since the span never exits, it never gets sent to openobserve via otlp, meaning the id values never get logged.

At least that is my running theory. It seems like a good theory.

I could split this up so that there is one span per each loop iteration, that would mean one span for every message. Which kind of seems excessive here, but is one solution. Maybe the preferred solution though, track each iteration as a seperate span. But I still have the same problem if I want to associate these with a parent span.

Is it possible to get spans sent on entry to the span?

Alternatively, what should I be going here?

[lalitb]

If you just want to avoid binding id to every debug! call, how about wrapping it within a struct. Creating a span just for binding the id seems to be bad idea to me. Or perhaps I am missing something, as this seems too simplified :)

use tracing::{event, Level};

struct MessageLogger {
    id: Id,
}

impl MessageLogger {
    fn new(id: Id) -> Self {
        MessageLogger { id }
    }

    fn log(&self, message: &str) {
        event!(Level::DEBUG, ?self.id, message);
    }
}

fn process_messages(id: Id, rx: Pipe) {
    let logger = MessageLogger::new(id);

    loop {
        let rx = rx.recv();
        logger.log("doing something");
        logger.log("doing something else");
    }
}

[brianmay]

Yes, I have considered that.

But downside is that I have lost the ability to pass through extra fields from the log commands.

Maybe I could create a macro to do that. Not quite sure how that would look. Probably need to be more awake then I am right now :-)

[brianmay]

Hmmm. Seems disappointing, but apparently there isn't a batter solution. I think simplest solution is just to try to make sure I log the id values.

Lets take this from a nother angle. Say I have a struct:

struct Chair {
   id: String;
   name: String;
  external_id: u64;
  number_of_legs: u8;
  type_of_back: TypeOfBack;
}

Is it possible to do this:

let chair = Chair{...};
debug!(chair, "New chair");

And have that automatically into:

let chair = Chair{...};
debug!(id=chair.id, name=chair.name, external_id=chair.external_id, object_type="chair", "New chair);

I know that there is the experimental valuable support in the tracing library. Not sure I understand it enough to say if it can do the above.

My early experimentation with that seems to indicate it ends up as a formatted debug string in openobserve, same as before. Possibly an indication that the tracer subscriber doesn't yet support it very well.