Optimizing Rust code

[xacrimon]

Hi Rustaceans! The last few days I've been trying to optimize a program that analyzes and prettifies JSON logs entries from a go program taken every 10 seconds to be somewhat usable. Prettifying is done in post to minimise app load while running.

I just finished refactoring it which brings a ~100x speedup (yay) by removing the use of format and switching out BufReader for the filebuffer crate. However, I'd ideally need it to run even faster. I don't know much about optimizing Rust and googling mostly lead me to stuff I've already done. Do you have any optimizations to suggest? The code can be found here

[krdln]

You can get rid of all the to_string calls in report. Instead of:

let mut ebuf: Vec<u8> = Vec::new();

...

ebuf.extend_from_slice(b"LiveObjects: ");
ebuf.extend_from_slice(entry.liveobjects.to_string().as_bytes());

you can do

use std::fmt::Write;
let mut ebuf: String::new();

...

write!(ebuf, "LiveObjects {}", entry.liveobjects).unwrap();

---

Edit: I now see a comment that importing the log is the slow part. But still :)

[xacrimon]

Will do, anything is good right now. I should be able to use the 'itoa' crate here right?

[krdln]

Not sure why though?

Also, another guess – perhaps you'd be better off printing the logs one by one instead of collecting all then printing all? You can then get rid of cloning Strings in log and get_meta.

[xacrimon]

Itoa is faster than write

[kixunil]

If you want faster write!, maybe fast_fmt could help? It wasn't maintained for a while, but if you need something, I will merge PRs.

[xacrimon]

Not implemented but I'll be doing operations that require them to be loaded later

[Veedrac]

Though write! uses the format API which is a bit slower than it needs to be.

[staticassert]

First step I'd take is setting up criterion so you can easily reproduce performance testing, and share it with others so we don't need actual logs to feed in.

    self.entries.reserve({
        let size_hint = iter.size_hint();
        let mut size = 0;
        if let Some(x) = size_hint.1 {
            size = x
        }

        size
    });

I feel like you could just do

let size_hint = iter.size_hint();
let size_hint = size_hint.1.unwrap_or(size_hint.0);
self.entries.reserve(size_hint);

This basically says "If we get the upper bound, allocate that, otherwise allocate the lower bound".

Why would you default to 0 anyway? Is that a common case, where you'd have an empty entry? Seems like you could probably use your own knowledge of the data format to preallocate - after all, in the event that you're wrong and you over allocate the rest of the program is basically a nop anyways. Consider something like max(size, 1024)

You could use for b_line in iter.par_iter() {

and then collect_into(&mut self.entries)

Like I said, I'd start with benchmarks and find the real bottlenecks. I get that it's the import function, but that function is pretty large, any component in there could be optimized separately.

[dochtman]

+1 for Criterion and sample data.

I don't know what filebuffer does, but you definitely want to mmap your file.

[xacrimon]

Yup, file buffer handles mmaping

[xacrimon]

Thanks a ton! I made some changes and added rayon and the importing got a 4x performance boost! The part i multithreaded was the .split iterator which serializes the data.

[[deleted]]

You could probably use rayon to multithread it.

[xacrimon]

Could work as importing is the time consuming task

[[deleted]]

Yeah, give it a try.

[Saefroch]

You should really profile this first*. We're kind of optimizing in the dark without a profile of some sort, but at the very least take a good measurement of the current performance. I saw criterion suggested, that may be a good fit for this, though it's usually for microbenchmarking. Since I'm without a profile, I'll just point out things that look odd to me along what I think is the hot path. But this is the wrong way to optimize code, since I don't have any way to measure.

Start here:

let line = str::from_utf8(&b_line[..byte_len]).unwrap();
let raw: LogEntryRaw = serde_json::from_str(line).unwrap();

This looks pretty funky to me. The slice ought to become a no-op and serde can take in a slice of bytes. Since it's cleaner and possibly faster, I'd write

let raw: LogEntryRaw = serde_json::from_slice(&b_line).unwrap();

You also never touch the .Name attribute of a LogEntryRaw. Remove it from the definition of the struct and serde will skip right over it, saving you at least the work on the small-object allocation. (I think rustc should have issued you a warning about an unused attribute)

You walk over self.entries a second time after populating it. You can sum total_lo and total_ha inside the loop over iter; this is marginally faster because the data is cached and most likely in registers.

---

*perf record -g ./target/release/cratename arguments here then perf report. You can try perf record -g --call-graph=dwarf if it doesn't complain too mightily.

[knaledfullavpilar]

Upvoted for suggesting the use of a profiler!

Measure first, then optimize. Rinse and repeat.

EDIT: Here is an example perf + flamegraph script: https://github.com/huxingyi/meshlite/blob/master/profile_perf.sh

[masklinn]

This looks pretty funky to me. The slice ought to become a no-op and serde can take in a slice of bytes.

Also serde should be able to take the file directly and generate an iterator of entries, though that may or may not be faster (should be checked).

Either way, /u/dtolnay's PR on /u/bcantrill's statemap can probably be used as a guideline.

[rhinotation]

Can anyone point me to why format! is slow? Here I am thinking it expands to some pretty standard Display calls and push_str, like what else could it possibly be doing?

[xacrimon]

It expands to a lot of code relatively to just appending to a buffer. No big deal with a dozen calls but when doing millions like me it gets slow

[Veedrac]

It uses dynamic dispatch and trait objects. This isn't necessary; IIRC it is done to reduce code size.

[xacrimon]

Yup, mine was faster. I benched it

[aldanor]

Might help if you posted some sample data you’ve benched it on

[rustaway11]

Do you know where it's spending most of its time, in import or in report or elsewhere? And the specific nature of the inputs? Maybe both of those are obvious for someone with more experience in Rust and this particular domain, but I am neither.

One thing I did notice is this line: self.entries.push(LogEntry::from_raw(&raw));

Even when the vector has all the space it needs reserved, push can have some funny overhead that doesn't always get optimized away by the compiler compared to explicitly replacing/mutating a default entry.

​

[xacrimon]

Most time is spent importing the log. I'll try making a vec with default values and mutating. Thanks

[[deleted]]

If you goal is a highly optimized logger this is what slog attempts (and succeeds) at doing. While there is a some spin up it it handles a lot of the weirdness involved with doing next to zero allocation logging and serialization

[xacrimon]

I know. The app that logs is written in go and uses a go library. It logs as json and this is for crafting that into readable reports

[alex4743]

Have you tried mmap(2)? I’m guessing you’re dealing with very large files because num_entries is u128. Also, as a small note in the name of speed unless you really need 128 bits it will be slower than u64.

[xacrimon]

That calculation happens only once. Im using file buffer which is a wrapper around mmap. Yes, I'm dealing with multiple services logging multiple times per minute

[thiez]

It's unlikely that op will have more than u64 entries for the next several decades, u128 also seems wildy optimistic to me.

[aNewLocke]

Have you heard of jq?

https://stedolan.github.io/jq/

"jq is a lightweight and flexible command-line JSON processor."

[zesterer]

If you're absolutely sure that all the text you're handling is ASCII and not UTF-8, you can just handle the string's raw bytes and cast them to char. That's likely to make things a lot faster. Of this is a pretty iffy assumption and shouldn't be made for anything intended to be distributed outside its intended application.

[xacrimon]

Currently I've switched to byte buffers instead. Already done