Optimize performance

[dpc]

https://github.com/dpc/slog-rs/wiki/Bench-log

Ideas:

• &'a str in RecordInfo`
• static dispatch - 39e6b5e
• measure perf of closure-values
• stdlog not to allocate String
• Arc chaining instead of copying in Logger hierarchies?
• closure-values not to allocate anything - implement SerializeKey for Fn(&RecordInfo, mut io::Writer) ? so the value can output itself without returning?
• use the same feature that standard log uses to remove logging statesments at compile time. Now that macros are being used, this should work smoothly.

[3Hren]

Where are benchmarks?

[3Hren]

&'a str in RecordInfo

Maybe Cow<'a, str> is better?

[dpc]

Hmm... msg is kind of expected to be just string literal, and Cow causes a if every time it's used, no?

[dpc]

I forgot to commit some files. :D Should be there now.

[3Hren]

Hmm... msg is kind of expected to be just string literal, and Cow causes a if every time it's used, no?

Of course.

I'm not sure about how you obtain those string. In blacklog there was a choice what to save: a raw string literal, which does not require formatting (use &'static str) or a result of format!("{}", Arguments<'a>), which is String. There Cow perfectly fit.

Did you think about integration with Rust formatting ecosystem?

[3Hren]

Because there - https://github.com/dpc/slog-rs/blob/master/crates/stdlog/src/lib.rs#L61 - arguments are evaluated every time, even if an event will be filtered out.

[dpc]

Oh, good catch. I haven't looked into log crate adapters yet. It would be nice to forward this Arguments as is.

[dpc]

Now you have make me thing about it. Simplest solution that I come up with, ATM is Drain to have two functions: one for &str, one for Arguments. Each drain that had to convert Arguments into string would actually pass it forward via fn log(&'str msg...) so everything above it, doesn't have to format it again. A bit more code for each drain, but avoids any unnecessary operations at runtime.

This would also allow taking msg that would have formatting in it, if necessary. Though it seems to me, that structured logging avoids need for format! and users should rather put really simple msg-s (&'static str), as anything "variable" should be a key-value.

What do you think?

[3Hren]

I think formatting is important.

Actually creating Arguments<'a> from string literal without other arguments is cheap. Even with arguments it is cheap, because it contains only references. You can always pass Arguments<'a> and, since, you format in the caller thread into Vec<u8> do it with write!(vec, "{}", args) as you do here for example: https://github.com/dpc/slog-rs/blob/master/crates/json/src/lib.rs#L184.

Then you don't need to store msg: &'str in the record, just store args: Arguments<'a> (it's Copy, but tricky, because of borrowing).

The Dark side: because log now accepts Arguments<'a> it's necessary to prepare them with format_args!(), even if there is a single string literal, but it's can be done in some kind of log! macro... just as I did in blacklog.
The second Dark side: in the case of multiple drains, you have to format the same arguments multiple times. I think it is the place where Cow/Borrow/ToOwned magic can help.

[dpc]

The biggest problem is that Argument<'a> introduces another lifetime that break closures as values.

[3Hren]

Just as replacing String with &'a str in the RecordInfo, isn't it?

[dpc]

There was so much problem with it... In short version... RecordInfo became RecordInfo<'a> and then lifetimes did not work with closures implementing Serialize and noone could help me. After I got it to work (the problem was |_:&_| syntax), it does not look so scary, but took me a long while to figure it out. :(

I actually got it work, but with &'a str, not &'a Arguments<'a>. It appears to me that Arguments<'a> support for msg is unnecessary. In stdlog I'll just pass Arguments as a closure value under different key so it get evaluated only if it was used. Since anyone can write any custom formatter etc. with a bit of work it's possible to get any actual output with this scheme, so why complicate and slow down the common case (just using the string literal)?

The way I think about: if anyone really, really needs format_args! it's possible with combination of:

• building own macro
• using closure-values
• using format! manually

I need to benchmark closure values, and see if there's no fundamental problems with their performance.

[3Hren]

Disagree, but as your wish.

[dpc]

I'm still open to being convinced, if you feel strongly about it, and if more people will voice an opinion in favour of changing it, I probably will.

After I got &'a str to work it shouldn't be too hard to get &'a Arguments<'a> to work, so I might try just to see the performance of format_args!("literal").

[dpc]

Also, it seems to me that current version of closure values is sub-optimal. Eg. sometimes it needs to allocate String etc. since it has to return the value (so it can't return newly created &str (or even &str from RecordInfo).

Maybe passing it some handle that would allow it to call a method to serialize a value would help?

[dpc]

While thinking about #16 I've noticed that switching drains at run-time is not something everyone needs, while it prevents optimizations. Removing it to be a separate drain, was a big benchmark win.

[dpc]

OK, so fmt::Argument<'a> is supported after all.

[dpc]

It's done.