[Parquet] Writing in 57.0.0 seems 10% slower than 56.0.0

[alamb]

Describe the bug
While testing the tpchgen-rs upgrade to arrow 57 in

• chore(deps): update parquet/arrow/arrow-csv from 56 to 57.1 clflushopt/tpchgen-rs#200

@clflushopt, @kevinjqliu and I found that arrow-rs 57 seems to write data around 10% slower than arrow 56: clflushopt/tpchgen-rs#200 (review)

Specifically running this command is around 10% slower

tpchgen-cli --scale-factor=100 --tables=lineitem --parts=10 --format=parquet

56.0.0 takes 0m27.122s
57.0.0 takes 0m28.776s

To Reproduce

rm -rf lineitem && cargo build --release && time ./target/release/tpchgen-cli --scale-factor=100 --tables=lineitem --parts=10 --format=parquet

Expected behavior

57 should be the same or better performance as 56

Additional context
I am doing some git bisecting to see if I can find some more data

[kevinjqliu]

ran the same command locally. v56 is main branch, v57 is the kevinjqliu/update-parquet-arrow-57 branch

v56, 304.60s user 6.58s system 1186% cpu 26.226 total
v57, 359.60s user 6.41s system 1212% cpu 30.182 total

[alamb]

ran the same command locally. v56 is main branch, v57 is the kevinjqliu/update-parquet-arrow-57 branch

v56, 304.60s user 6.58s system 1186% cpu 26.226 total
v57, 359.60s user 6.41s system 1212% cpu 30.182 total

Thanks @kevinjqliu -- so to confirm you also see the slowdown on 57?

[kevinjqliu]

yes! I ran it a couple of times with similar results

v56, 26.226 total
v57, 30.182 total

[alamb]

I think I have isolated the commit that caused the slow down 🥁

• Specifically it appears to be the d5df352 / Use custom thrift parser for parquet metadata (phase 1 of Thrift remodel) #8530 (thrift remodel)

I am testing using this crazy command

cargo build --release && hyperfine --warmup=1 --runs=5 'rm -f lineitem.parquet && ./target/release/tpchgen-cli --scale-factor=10 --tables=lineitem --format=parquet'

Here is the result at that commit:

HEAD is now at d5df352f18 Use custom thrift parser for parquet metadata (phase 1 of Thrift remodel) (#8530)

Benchmark 1: rm -f lineitem.parquet && ./target/release/tpchgen-cli --scale-factor=10 --tables=lineitem --format=parquet
  Time (mean ± σ):      3.606 s ±  0.057 s    [User: 38.845 s, System: 0.925 s]
  Range (min … max):    3.527 s …  3.670 s    5 runs

• Here is the result at the next 521f219 / (Migrate arrow-avro to Rust 2024 #8545)

HEAD is now at 521f219e30 Migrate `arrow-avro` to Rust 2024 (#8545)

Benchmark 1: rm -f lineitem.parquet && ./target/release/tpchgen-cli --scale-factor=10 --tables=lineitem --format=parquet
  Time (mean ± σ):      3.333 s ±  0.034 s    [User: 34.432 s, System: 0.897 s]
  Range (min … max):    3.299 s …  3.385 s    5 runs

[etseidl]

I know the Thrift write path was not profiled at all (we were more concerned with read performance), so hopefully there are some easy wins there.

[alamb]

I spent a few minutes trying to get a profile that showed metadata writing somewhere in the profile, but so far can't find one

Maybe we can try applying this trick from @jhorstmann to the write path

• Introduce a ThriftProtocolError to avoid allocating and formattings strings for error messages #8636

[etseidl]

I did a profile of both versions, and the big change appears to be in some min/max processing (parquet::column::writer::compare_greater) and some differences to do with LogicalType.

I'll look at git blame now and see what changed there.

[etseidl]

Calling ColumnDescriptor::logical_type eventually leads to BasicTypeInfo::logical_type

    pub fn logical_type(&self) -> Option<LogicalType> {
        // Unlike ConvertedType, LogicalType cannot implement Copy, thus we clone it
        self.logical_type.clone()
    }

One big change in #8530 to LogicalType was fleshing out the Variant, Geography, and Geometry variants, as well as adding _Unknown. Given that the geo types include strings, I don't know if clone got way more expensive.

I don't know why logical_type returns a copy anyway...a ref would be better, but that would be a breaking change.

I'll try adding a logical_type_ref and see if that helps.

Could someone (@alamb 👀) give me the Cargo foo necessary to use a branch of parquet in tpchgen-rs?

[kevinjqliu]

Could someone (@alamb 👀) give me the Cargo foo necessary to use a branch of parquet in tpchgen-rs?

I think something like

arrow = { git = "https://github.com/apache/arrow-rs.git", rev = "commit_hash" }

and the changes similar to https://github.com/clflushopt/tpchgen-rs/pull/200/files

[etseidl]

Ok, that was clearly part of the problem.

57
137.743u 28.051s 0:25.69 645.3% 0+0k 0+0io 0pf+0w
134.955u 26.356s 0:24.34 662.6% 0+0k 0+0io 0pf+0w
136.183u 26.470s 0:24.90 653.2% 0+0k 0+0io 0pf+0w

56.2
112.060u 25.816s 0:21.46 642.4% 0+0k 0+0io 0pf+0w
111.992u 25.607s 0:20.90 658.3% 0+0k 0+0io 0pf+0w
113.020u 26.161s 0:21.09 659.9% 0+0k 0+0io 0pf+0w

57-ref
116.639u 26.349s 0:22.28 641.6% 0+0k 0+0io 0pf+0w
116.117u 25.737s 0:21.37 663.7% 0+0k 0+0io 0pf+0w
114.979u 25.467s 0:21.16 663.6% 0+0k 0+0io 0pf+0w

57-ref is https://github.com/etseidl/arrow-rs/tree/log_type_ref

I'll try to see what the last little bit is.

[alamb]

I checked out etseidl/log_type_ref and I confirm it gets back a non trivial amount of the time 👏 -- talk about fast turnaround!

Benchmark 1: rm -f lineitem.parquet && ./target/release/tpchgen-cli --scale-factor=10 --tables=lineitem --format=parquet
  Time (mean ± σ):      3.403 s ±  0.042 s    [User: 36.178 s, System: 0.886 s]
  Range (min … max):    3.378 s …  3.476 s    5 runs

I am also smelling some additional parquet writing optimization / benchmarks coming up