Potential regression of slower speed v0.22.1->v0.23.0

[makeecat]

Description

The overall logging speed seems to be slower, not sure if it is related to the spawn process of grpc.

Reproduction

## Install dependencies
cargo install hyperfine
cargo install rerun@0.22.1
mv ~/.cargo/bin/rerun ~/.cargo/bin/rerun@0.22.1
cargo install rerun@0.23.0
mv ~/.cargo/bin/rerun ~/.cargo/bin/rerun@0.23.0

## build testbed
git clone git@github.com:makeecat/peng.git peng
git clone git@github.com:makeecat/peng.git peng-prev
## set peng-prev before bumping rerun from 0.22.1 to 0.23.0
cd peng-prev
git checkout 74b8727bac5c49b67677c08c3f47bb7b1676e802
cargo build --release
cd ../peng
cargo build --release
cd ..

## launch rerun 0.22.1
rerun@0.22.1
## launch peng-prev
hyperfine --warmup 10 -r 30 ./peng-prev/target/release/peng_quad

## launch rerun 0.23.0
rerun@0.23.0
## launch peng
hyperfine --warmup 10 -r 30 ./peng/target/release/peng_quad

Result

This is the commit that bumped the rerun version: makeecat/Peng@8cb4077

Since that commit changed other dependencies' versions, I also rolled back the other dependencies. The results are similar, I call this version peng-next.

on MacOS Apple M1, Sequoia 15.4.1:

peng-prev: 987.1ms +- 69.0ms
peng: 1.143ms +- 52.0ms
peng-next: 1.145ms +- 58.0ms

on ROG STRIX15 x64, Ubuntu 22.04:

peng-prev: 812.6ms +- 27.2ms
peng: 842.8ms +- 17.7ms
peng-next: 847.0ms +- 29.2ms

[jprochazk]

Hi, I unfortunately can't reproduce the perf regression on any of my machines.

We profiled similar workloads and found some performance regressions in rrd encode due to excessive allocations. I pushed #9826 which does reduce the number of allocations we do to be the same as in 0.22.1, a little better in some cases.

Could you set the rerun dependency in peng to point to that git branch, and check if it makes any difference for you?

On my end, even that doesn't yield any real difference in the numbers I'm seeing for your repro:

# Mac M2 (Sonoma 14.5)
peng @ 74b8727bac5c49b67677c08c3f47bb7b1676e802 + rerun 0.22.1
  751.5 ms ±  13.6 ms

peng @ main + rerun 0.23.1
  737.1 ms ±  20.5 ms

peng @ main, patched with jan/encode-perf + rerun 0.23.1
  736.6 ms ±  30.0 ms

# 7950x (running Fedora 41, kernel 6.13)
peng @ 74b8727bac5c49b67677c08c3f47bb7b1676e802 + rerun 0.22.1
  528.0 ms ±  14.8 ms

peng @ main + rerun 0.23.1
  547.9 ms ±  10.9 ms

peng @ main, patched with jan/encode-perf + rerun 0.23.1
  544.0 ms ±  10.7 ms

These are somewhat noisy results, but all very close.

Which makes sense, we only started seeing differences when logging ~hundreds of MiB, and the provided benchmark logs a total of 150 MiB per run. It's likely that there just isn't enough allocation pressure for it to matter, but that depends on a large number of factors...

[makeecat]

It did improve the performance:

on MacOS Apple M1, Sequoia 15.4.1:

peng @ 74b8727bac5c49b67677c08c3f47bb7b1676e802 + rerun 0.22.1
812.6 ms ± 27.2 ms
peng @ main + rerun 0.23.1
1143.0 ms ± 52.0 ms
peng @ main, patched with jan/encode-perf + rerun 0.23.1
1018.0 ms ± 141.0 ms

[jprochazk]

That 141ms variance seems really suspicious... Do you think you could make sure that nothing else is running at the same time (like rust-analyzer indexing in the background), and provide a flamegraph of that profile?

# peng @ main patched with jan/encode-perf + rerun 0.23.1
cargo flamegraph # profiles cargo run --release

# peng @ 74b8727bac5c49b67677c08c3f47bb7b1676e802 + rerun 0.22.1
cargo flamegraph

Both will produce a flamegraph.svg file

I also noticed peng uses multithreading for some things - could you turn that off before benchmarking to ensure the variance is as low as possible?

[makeecat]

I disabled the multi-threading by changing config/quad.yaml: use_multithreading_depth_rendering from true to false. Here is the new result with the flame graph. I turned off all other applications during the benchmark. One more thing I noticed: 0.23.1 seems to occupy more memory than 0.22.1, wondering if that is as expected.

on MacOS Apple M1, Sequoia 15.4.1:

peng @ 74b8727bac5c49b67677c08c3f47bb7b1676e802 + rerun 0.22.1
1.275 s ± 0.005 s

peng @ main + rerun 0.23.1
1.284 s ± 0.005 s

peng @ main, patched with jan/encode-perf + rerun 0.23.1
1.285 s ± 0.004 s