appender: Add appender to write same log line to multiple outputs in a loop.

[SriRamanujam]

Motivation

tracing currently doesn't have a way to send the same log line to multiple appenders at the same time.

Solution

This is a very quick implementation of an appender that wraps an arbitrary number of other appenders and writes the same log line to all of them in a loop.

I didn't write any tests for this module because it legitimately doesn't do anything except call the implementations of its inner writers, so there's really nothing testable here.

[hawkw]

Thanks for the PR, and I'm sorry to have kept you waiting for a review --- I've been quite busy.

I think this is definitely functionality we want in tracing-appender. However, I had some thoughts about the way it's currently implemented. I think it's possible to provide similar functionality in a way that's much more flexible, and allows writing to a broader variety of Writers and MakeWriters.

Let me know what you think about my alternative proposal! Thanks again!

[hawkw]

Elsewhere in tracing, we just refer to this as io::Result --- can we do that here as well, for consistency?

[hawkw]

Take it or leave it: I might consider just naming this "Tee" --- it's concise and has name recognition.

[hawkw]

nit: we could avoid a pointer indirection by using Arc<[S]> rather than Arc<Vec<S>>, since a Vec is a pointer to an array on the heap. we'd have to use the From<Vec<T>> impl rather than Arc::new:

Suggested change

	writers: Arc<Vec<S>>,
	}
	impl<S> MultiAppender<S>
	where
	S: MakeWriter + std::io::Write + Send + Sync,
	{
	/// Returns a new `MultiAppender` wrapping a provided `Vec` of [`MakeWriter`][make_writer].
	///
	/// [make_writer]: https://docs.rs/tracing-subscriber/latest/tracing_subscriber/fmt/trait.MakeWriter.html
	pub fn from(writers: Vec<S>) -> Self {
	MultiAppender {
	writers: Arc::new(writers),
	writers: Arc<[S]>,
	}
	impl<S> MultiAppender<S>
	where
	S: MakeWriter + std::io::Write + Send + Sync,
	{
	/// Returns a new `MultiAppender` wrapping a provided `Vec` of [`MakeWriter`][make_writer].
	///
	/// [make_writer]: https://docs.rs/tracing-subscriber/latest/tracing_subscriber/fmt/trait.MakeWriter.html
	pub fn from(writers: Vec<S>) -> Self {
	MultiAppender {
	writers: Arc::from(writers),

[hawkw]

If this constructor is going to be called from, it ought to be an implementation of the From trait --- otherwise, it could be confusing. If it's an inherent impl, we should probably just call it new.

[hawkw]

This means that we can only use MultiAppender as it's written today to join together types that are writers. It would be nice if it could also be used for joining MakeWriter types that do not themselves implement Write, and Write implementors that don't also implement MakeWriter.

[hawkw]

Only being able to join together multiple writers of the same type seems like a major limitation here...I can imagine some people wanting to use this to (for example) log to both stdout and to a file.

I thought of an alternative approach that would still allow joining multiple writers of the same type, but would also allow us to join multiple writers of heterogenous types. What do you think about doing something like this, instead:

#[derive(Clone, Debug)]
pub struct Tee<A, B>(A, B);

pub fn tee<A, B>(a: A, b: B) -> Tee<A, B> {
    Tee(a, b)
}

impl<A, B> MakeWriter for Tee<A, B>
where 
    A: MakeWriter,
    B: MakeWriter,
{
    type Writer = Tee<A::Writer, B::Writer>;

    fn make_writer(&self) -> Self::Writer {
        Tee(self.0.make_writer(), self.1.make_writer())
    }
}

impl<A, B> Write for Tee<A, B>
where 
    A: Write,
    B: Write,
{
    fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
        // write the same amount to both writers, so that the return value is consistent
        let n = self.0.write(buf)?;
        self.1.write(&buf[0..n])
    }

    fn flush(&mut self) -> io::Result<()> {
        match (self.0.flush(), self.1.flush()) {
            (Ok(_), Ok(_)) => Ok(()),
            (Err(e), _) => Err(e),
            (_, Err(e)) => Err(e),
        }
    }

    // ... other `Write` trait methods ...
}

This has some advantages over the current approach proposed in this PR:

• It doesn't require multiple allocations and heap pointer dereferences (for the Arc and Vec).
• It allows joining multiple MakeWriter implementations of different types, like this:

  let file = tracing_appender::rolling::hourly("/var/log", "myapp.log");
  let non_blocking = tracing_appender::non_blocking(file)
  let make_writer = tracing_appender::tee(file, std::io::stdout);
  let subscriber = tracing_subscriber::fmt().with_writer(make_writer);

• It allows teeing together two Write implementations, like this:

  let file = tracing_appender::rolling::daily("/tmp/whatever", "foo.log");
  let writers = tracing_appender::tee(file, std::io::stdout().lock());
  let (_guard, make_writer) = tracing_appender::non_blocking(writers);
  let subscriber = tracing_subscriber::fmt().with_writer(make_writer);

  or two MakeWriter implementations, as in the above example.
• It doesn't require the joined types to implement both Write and MakeWriter.
• And, more than two writers can still be teed together by nesting Tees:

  let file = tracing_appender::rolling::hourly("/var/log", "myapp.log");
  let (_guard, file) = tracing_appender::non_blocking(file);
  let console = tracing_appender::tee(std::io::stdout, std::io::stderr);
  let make_writer = tracing_appender::tee(console, file);

If we went with this approach, we could also easily add an extension trait to add a .tee method to Write and MakeWriter implementations, so that they can be joined together in a method-chaining style, like this:

use tracing_appender::prelude::*;

let file = tracing_appender::rolling::hourly("/var/log", "myapp.log");
let (_guard, file) = tracing_appender::non_blocking(file);
let make_writer = std::io::stdout
    .tee(std::io::stderr)
    .tee(file);

What do you think of this approach?

[SriRamanujam]

I already do use this to log to both stdout and a file, actually 😁 . I just wrap std::io::stdout() and the file appender in NonBlocking. I believe that I have to wrap both sinks in NonBlocking to ensure the IO actually occurs in a dedicated background thread anyway, so for my use case this happens to work out nicely.

I agree that this limits flexibility in the sense that you cannot freely mix and match non-wrapped appenders within the same MultiWriter, but the static solution outlined here I think makes it much harder to use this API in a common scenario: receiving configuration during program startup and using that configuration to build up a writer.

For example, my specific use case is that I need to configure whether log lines go to stdout, stderr, or a file. Any combination of these is valid, including none of them, any one of them, any two of them, or all three of them. Configuration is passed in during startup. With MultiWriter, It is straightforward to determine during runtime which appenders are required, create them, wrap them in NonBlocking, and store them in a vector which is then used to create the MultiWriter.

fn create_writer(use_stderr: bool, use_stdout: bool, file: Option<&PathBuf>) -> Option<MultiWriter<NonBlocking>> {
    let mut writers = Vec::new();

    if use_stdout {
        writers.push(NonBlocking::new(std::io::stdout()));
    }

    if use_stderr {
        writers.push(NonBlocking::new(std::io::stderr()));
    }

    match file {
        Some(f) => writers.push(NonBlocking::new(RollingFileAppender::new(f.parent().unwrap(), f.file_name()))),
        None => {}
    }

    if writers.is_empty() {
        None
    } else {
        Some(MultiWriter::from(writers))
    }
}

With the static approach, it becomes much, much harder (if not impossible) to write a function that does the same thing as the one above due to type checking snarls. I tried several approaches over the last few hours to try to get something readable that also compiled. The closest I got was a single large match statement that contains every permutation of the options written out to avoid many nested if/else statements. Even that became unwieldy to read past two or three match arms. The code also needs to repeat itself a lot, since I have to write out the appenders' initializations within the match statement arms every time. Even worse, I can't easily return the writer out at the end of the function because the types are different in every branch! So this is now a giant match statement that's hard to read and may not even be able to get past the type checker in the first place.

fn create_writer(use_stderr: bool, use_stdout: bool, file: Option<&PathBuf>) -> Option<???> {
    match (use_stderr, use_stdout, file) {
        (true, true, Some(f)) => {
            let make_writer: Tee<Tee<RollingFileAppender, std::io::stdout>, std::io::stderr> = RollingFileAppender::new(f.parent().unwrap(), f.file_name())
                .tee(NonBlocking::new(std::io::stdout()))
                .tee(NonBlocking::new(std::io::stderr()));

            Some(make_writer)
        }
        (true, false, Some(f)) => {
            // the case where it was requested to log to stderr and a file but _not_ stdout

            // the type is different from the branch above! This won't compile.
            let make_writer: Tee<RollingFileAppender, std::io::stderr> = RollingFileAppender::new(f.parent().unwrap(), f.file_name())
                .tee(NonBlocking::new(std::io::stderr()))

            Some(make_writer)
        }
        [...]
        (true, false, None) => {
            // the case where only stdout logging was requested.

            // Cannot "tee" a single appender, so the return type from this branch is going to be different yet again
            Some(NonBlocking::new(std::io::stdout))
        }
        [...]
        (false, false, None) => None
    }
}

I also tried boxing everything so that the return type could be Box<dyn MakeWriter>, but unfortunately nothing else accepts boxed writers so that was a no-go. I fully admit that I am not a Rust expert by any means, so perhaps there is something I have missed or overlooked in my approach here. If there is, I'd be glad to learn about it! Nevertheless, I believe that it's valuable to note that somebody trying to use this API for the first time could not get it working after 4 hours of effort.

I understand why we'd want to to use generics to reduce runtime overhead, but it just makes this particular use case, which I think would be very common, very difficult to figure out to the point where I'm not sure if it's possible at all with my current understanding of Rust the language.

[hawkw]

Your point about dynamically configuring the set of writers is a good point, I hadn't thought of that — using a Vec definitely makes that much easier. Perhaps we want to have a static Tee based API and a Vec-based one, eventually, with the static approach being recommended when a small number of writers are known at compile-time, and the Vec-based approach recommended when there is a large set of writers that are only known at runtime.

I hadn't thought of just using multiple NonBlockings to erase the underlying writer types, so I had assumed that this API could only be used with a single writer type. However, I think it would be be better in the long run if NonBlocking were not necessary here, since each NonBlocking instance spawns its own background worker thread to write to the wrapped writer. Ideally, I think it would probably be more efficient if we could have a single background worker thread that owns all the writers, and performs all the I/O work. So, it seems worth having another way to erase the type of a writer without also moving it to a background thread.

You mentioned that

I also tried boxing everything so that the return type could be Box<dyn MakeWriter>, but unfortunately nothing else accepts boxed writers so that was a no-go

I think we could probably fix this by adding a boxed MakeWriter type in tracing-subscriber. Since MakeWriter has an associated type for the Writer it produces, I think we would need to wrap the MakeWriter in a newtype struct so that we can also box the writer type it outputs. The implementation would be something like this:

pub struct BoxMakeWriter {
    inner: Box<dyn MakeWriter<Writer = Box<dyn std::io::Write>> + Send + Sync>,
}

struct Boxed<M>(M);

impl<M> MakeWriter for Boxed<M>
where
    M: MakeWriter,
    M::Writer: 'static,
 {
    type Writer = Box<dyn std::io::Write>;
    fn make_writer(&self) -> Self::Writer {
        Box::new(self.0.make_writer())
    }
}

impl BoxMakeWriter {
    pub fn new<M>(make_writer: M) -> Self 
    where
        M: MakeWriter + Send + Sync
        M::Writer: 'static,
    {
        Self {
            inner: Box::new(Boxed(make_writer)),
        }
    }
}

impl MakeWriter for Boxed<M> {
    type Writer = Box<dyn std::io::Write>;
    fn make_writer(&self) -> Self::Writer {
        self.inner.make_writer()
    }
}

This would then allow erasing the type of a MakeWriter without needing to wrap it in a NonBlocking. This would allow constructing a Vec-based MultiAppender type out of multiple appenders and then wrapping it in a NonBlocking, so that a single worker thread can own multiple writers. Additionally, it would allow erasing the type of a complex nested static tee writer.

I think it would be good to open a separate PR against tracing-subscriber to add something like this. If that's something you're interested in working on, I'd be happy to review that PR, otherwise, I'll open a new issue to see if someone else wants to do it. Let me know what you think!

[SriRamanujam]

I'd be happy to implement this, it seems straightfoward and it'd be nice to get this functionality upstream. Just to confirm, then: I'll close this PR and open a new one with a boxed MakeWriter that erases the type of the output it's wrapping, and a MultiAppender struct that works similarly to MultiWriter here around it. The Tee implementation along with its associated trait (Teeable?) you laid out here could also be brought along for the ride, though perhaps that should be its own PR.

[hawkw]

I think we can leave this PR open and just add a boxed writer type to tracing-subscriber separately. We would probably need to make some additional changes to this branch to make it work nicely with a boxed writer, though (since this PR currently requires the wrapped types to implement both MakeWriter and Write, which a type-erased boxed writer would never do).

[joshka]

With the static approach, it becomes much, much harder (if not impossible) to write a function that does the same thing as the one above due to type checking snarls. I

In #3196 I implemented MakeWriter for Option<M: MakeWriter>. This makes it possible to write this logic fairly simply as:

fn create_writer(use_stderr: bool, use_stdout: bool, file: Option<&PathBuf>) -> impl MakeWriter<'_> {
    let stderr_writer = use_stderr.then_some(std::io::stderr);
    let stdout_writer = use_stdout.then_some(std::io::stdout);
    let file_writer = file.map(|f| File::create(f).unwrap());
    stderr_writer.and(stdout_writer).and(file_writer)
}

I suspect that's simple enough for most cases (a known quantity of writers), but obviously doesn't solve the unknown quantity of writers problem.

[frol]

Could you also consider the use-case where you need to have different filters for different writers? I want to report only WARN+ logs in human-readable format to stderr while writing DEBUG+ messages in JSON format to some local file and INFO+ logs to centralized logs storage (e.g. graylog, or other solution which requires its own serialization format).

This solution does not seem to be able to fulfill the requirements, right?

I find Python logging being quite flexible: https://docs.python.org/3/howto/logging.html#advanced-logging-tutorial

[davidbarsky]

Could you also consider the use-case where you need to have different filters for different writers? I want to report only WARN+ logs in human-readable format to stderr while writing DEBUG+ messages in JSON format to some local file and INFO+ logs to centralized logs storage (e.g. graylog, or other solution which requires its own serialization format).

You're right, this PR doesn't allow you to selectively filter on a per-layer basis. That use case will be addressed in #508.

[bryangarza]

@SriRamanujam - Should we close this PR?
cc @hawkw