作者：Xuanwo
Databend Labs 成员，数据库研发工程师
https://github.com/xuanwo
我即将分享一个冗长的故事，从 OpenDAL 的 op.read()开始，以一个意想不到的转折结束。这个过程对我来说非常有启发性，我希望你也能感受到。我会尽力重现这个经历，并附上我一路学到的教训。让我们开始吧！
所有的代码片段和脚本都可以在 Xuanwo/when-i-find-rust-is-slow 中找到。
OpenDAL Python 绑定比 Python 慢？
OpenDAL 是一个数据访问层，允许用户以统一的方式从各种存储服务中轻松高效地获取数据。我们通过 pyo3 为 OpenDAL 提供了 python 绑定。
有一天，@beldathas 在 discord 向我报告了一个案例，即 OpenDAL 的 python 绑定比 python 慢：
import pathlib
import timeit
import opendal
root = pathlib.Path(__file__).parent
op = opendal.Operator("fs", root=str(root))
filename = "lorem_ipsum_150mb.txt"
def read_file_with_opendal() -> bytes:
with op.open(filename, "rb") as fp:
result = fp.read()
return result
def read_file_with_normal() -> bytes:
with open(root / filename, "rb") as fp:
result = fp.read()
return result
if __name__ == "__main__":
print("normal: ", timeit.timeit(read_file_with_normal, number=100))
print("opendal: ", timeit.timeit(read_file_with_opendal, number=100))结果显示
(venv) $ python benchmark.py
normal: 4.470868484000675
opendal: 8.993250704006641
Emmm，我对这些结果有点尴尬。以下是一些快速的假设：
-
Python 是否有内部缓存可以重复使用相同的内存？
-
Python 是否拥有加速文件读取的一些技巧？
-
PyO3 是否引入了额外的开销？
我将代码重构如下：
python-fs-read
with open("/tmp/file", "rb") as fp:
result = fp.read()
assert len(result) == 64 * 1024 * 1024python-opendal-read
import opendal
op = opendal.Operator("fs", root=str("/tmp"))
result = op.read("file")
assert len(result) == 64 * 1024 * 1024结果显示，Python 比 OpenDAL 快得多：
Benchmark 1: python-fs-read/test.py
Time (mean ± σ): 15.9 ms ± 0.7 ms [User: 5.6 ms, System: 10.1 ms]
Range (min … max): 14.9 ms … 21.6 ms 180 runs
Benchmark 2: python-opendal-read/test.py
Time (mean ± σ): 32.9 ms ± 1.3 ms [User: 6.1 ms, System: 26.6 ms]
Range (min … max): 31.4 ms … 42.6 ms 85 runs
Summary
python-fs-read/test.py ran
2.07 ± 0.12 times faster than python-opendal-read/test.pyOpenDAL 的 Python 绑定似乎比 Python 本身运行得更慢，这并不是个好消息。让我们来探究其背后的原因。
OpenDAL Fs 服务比 Python 慢？
这个谜题涉及到许多元素，如 rust、opendal、python、pyo3 等。让我们集中精力尝试找出根本原因。
我在 rust 中通过 opendal fs 服务实现了相同的逻辑：
rust-opendal-fs-read
use std::io::Read;
use opendal::services::Fs;
use opendal::Operator;
fn main() {
let mut cfg = Fs::default();
cfg.root("/tmp");
let op = Operator::new(cfg).unwrap().finish().blocking();
let mut bs = vec![0; 64 * 1024 * 1024];
let mut f = op.reader("file").unwrap();
let mut ts = 0;
loop {
let buf = &mut bs[ts..];
let n = f.read(buf).unwrap();
let n = n as usize;
if n == 0 {
break
}
ts += n;
}
assert_eq!(ts, 64 * 1024 * 1024);
}然而，结果显示即使 opendal 是用 rust 实现的，它的速度仍然比 python 慢：
Benchmark 1: rust-opendal-fs-read/target/release/test
Time (mean ± σ): 23.8 ms ± 2.0 ms [User: 0.4 ms, System: 23.4 ms]
Range (min … max): 21.8 ms … 34.6 ms 121 runs
Benchmark 2: python-fs-read/test.py
Time (mean ± σ): 15.6 ms ± 0.8 ms [User: 5.5 ms, System: 10.0 ms]
Range (min … max): 14.4 ms … 20.8 ms 166 runs
Summary
python-fs-read/test.py ran
1.52 ± 0.15 times faster than rust-opendal-fs-read/target/release/test虽然 rust-opendal-fs-read 的表现略优于 python-opendal-read，这暗示了在绑定和 pyo3 中有改进的空间，但这些并非核心问题。我们需要进一步深入探究。
啊，opendal fs 服务比 python 慢。
Rust std fs 比 Python 慢？
OpenDAL 通过 std::fs 实现文件系统服务。OpenDAL 本身会产生额外的开销吗？
我使用 std::fs 在 Rust 中实现了相同逻辑：
rust-std-fs-read
use std::io::Read;
use std::fs::OpenOptions;
fn main() {
let mut bs = vec![0; 64 * 1024 * 1024];
let mut f = OpenOptions::new().read(true).open("/tmp/file").unwrap();
let mut ts = 0;
loop {
let buf = &mut bs[ts..];
let n = f.read(buf).unwrap();
let n = n as usize;
if n == 0 {
break
}
ts += n;
}
assert_eq!(ts, 64 * 1024 * 1024);
}但是：
Benchmark 1: rust-std-fs-read/target/release/test
Time (mean ± σ): 23.1 ms ± 2.5 ms [User: 0.3 ms, System: 22.8 ms]
Range (min … max): 21.0 ms … 37.6 ms 124 runs
Benchmark 2: python-fs-read/test.py
Time (mean ± σ): 15.2 ms ± 1.1 ms [User: 5.4 ms, System: 9.7 ms]
Range (min … max): 14.3 ms … 21.4 ms 178 runs
Summary
python-fs-read/test.py ran
1.52 ± 0.20 times faster than rust-std-fs-read/target/release/test哇，Rust 的 std fs 比 Python 还慢？这怎么可能呢？无意冒犯，但是这怎么可能呢？
Rust std fs 比 Python 还慢？真的吗！？
我无法相信这个结果：Rust std fs 的速度竟然比 Python 还要慢。
我尝试学会了如何使用 strace 进行系统调用分析。strace是一个 Linux 系统调用追踪器，它让我们能够监控系统调用并理解其过程。
strace 将包含程序发出的所有系统调用。我们应该关注与/tmp/file 相关的方面。每一行 strace 输出都以系统调用名称开始，后跟输入参数和输出。
比如：
openat(AT_FDCWD, "/tmp/file", O_RDONLY|O_CLOEXEC) = 3这意味着我们使用参数 AT_FDCWD，"/tmp/file" 和 O_RDONLY|O_CLOEXEC调用 openat系统调用。这将返回输出 3 ，这是在后续的系统调用中引用的文件描述符。
好了，我们已经掌握了 strace。让我们开始使用它吧！
rust-std-fs-read 的 strace:
> strace ./rust-std-fs-read/target/release/test
...
mmap(NULL, 67112960, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f290dd40000
openat(AT_FDCWD, "/tmp/file", O_RDONLY|O_CLOEXEC) = 3
read(3, "\tP\201A\225\366>\260\270R\365\313\220{E\372\274\6\35\"\353\204\220s\2|7C\205\265\6\263"..., 67108864) = 67108864
read(3, "", 0) = 0
close(3) = 0
munmap(0x7f290dd40000, 67112960) = 0
...python-fs-read 的 strace:
> strace ./python-fs-read/test.py
...
openat(AT_FDCWD, "/tmp/file", O_RDONLY|O_CLOEXEC) = 3
newfstatat(3, "", {st_mode=S_IFREG|0644, st_size=67108864, ...}, AT_EMPTY_PATH) = 0
ioctl(3, TCGETS, 0x7ffe9f844ac0) = -1 ENOTTY (Inappropriate ioctl for device)
lseek(3, 0, SEEK_CUR) = 0
lseek(3, 0, SEEK_CUR) = 0
newfstatat(3, "", {st_mode=S_IFREG|0644, st_size=67108864, ...}, AT_EMPTY_PATH) = 0
mmap(NULL, 67112960, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f13277ff000
read(3, "\tP\201A\225\366>\260\270R\365\313\220{E\372\274\6\35\"\353\204\220s\2|7C\205\265\6\263"..., 67108865) = 67108864
read(3, "", 1) = 0
close(3) = 0
rt_sigaction(SIGINT, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=SA_RESTORER|SA_ONSTACK, sa_restorer=0x7f132be5c710}, {sa_handler=0x7f132c17ac36, sa_mask=[], sa_flags=SA_RESTORER|SA_ONSTACK, sa_restorer=0x7f132be5c710}, 8) = 0
munmap(0x7f13277ff000, 67112960) = 0
...从分析strace来看，很明显 python-fs-read 的系统调用比 rust-std-fs-read 多，两者都利用了mmap。那为什么 Python 要比 Rust 更快呢？
👨🏻💻 我们这里为什么用了 mmap？
我最初认为mmap仅用于将文件映射到内存，从而通过内存访问文件。然而，mmap还有其他用途。它通常被用来为应用程序分配大块的内存区域。
这可以在 strace 的结果中看到：
mmap(NULL, 67112960, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f13277ff000这个系统调用的含义是
-
NULL：第一个参数表示要映射的内存区域的起始地址。NULL将让操作系统为我们选择一个合适的地址。 -
67112960：要映射的内存区域的大小。我们在这里分配 64MiB + 4KiB 内存，额外的页面用于存储此内存区域的元数据。 -
PROT_READ|PROT_WRITE：该内存区域可读写。 -
MAP_PRIVATE|MAP_ANONYMOUS: -
MAP_PRIVATE意味着对此内存区域进行更改不会对其他映射相同区域的进程可见，并且不会传递到底层文件（如果有）。 -
MAP_ANONYMOUS意味着我们正在分配与文件无关联匿名内存. -
-1: 要的映射文件描述符.-1表示我们没有映射文件。 -
0: 文件中要从哪个偏移量开始映射. 我们并没有映射文件，所以使用0
👨🏻💻 但是我们代码里没有调用 mmap 啊？
mmap系统调用由glibc分派。我们使用malloc向系统请求内存，作为回应， glibc采用了 brk 和 mmap 系统调用来根据我们的请求大小分配内存。如果请求的大小足够大，那么 glibc 会选择使用 mmap, 这有助于缓解内存碎片问题。
默认情况下，所有以目标 x86_64-unknown-linux-gnu 编译的 Rust 程序都使用由 glibc 提供的 malloc 实现。
👨🏻💻 Python 和 Rust 是否使用相同的内存分配器？
默认情况下，Python 使用pymalloc，这是一个针对小型分配进行优化的内存分配器。Python 具有三个内存域，每个代表不同的分配策略，并针对各种目的进行了优化。
pymalloc 有如下行为：
Python has a pymalloc allocator optimized for small objects (smaller or equal to 512 bytes) with a short lifetime. It uses memory mappings called “arenas” with a fixed size of either 256 KiB on 32-bit platforms or 1 MiB on 64-bit platforms. It falls back to PyMem_RawMalloc() and PyMem_RawRealloc() for allocations larger than 512 bytes.
Rust 默认的内存分配器比 Python 慢吗？
我怀疑mmap是导致这个问题的原因。如果我切换到jemalloc，会发生什么情况？
rust-std-fs-read-with-jemalloc
use std::io::Read;
use std::fs::OpenOptions;
#[global_allocator]
static GLOBAL: jemallocator::Jemalloc = jemallocator::Jemalloc;
fn main() {
let mut bs = vec![0; 64 * 1024 * 1024];
let mut f = OpenOptions::new().read(true).open("/tmp/file").unwrap();
let mut ts = 0;
loop {
let buf = &mut bs[ts..];
let n = f.read(buf).unwrap();
let n = n as usize;
if n == 0 {
break
}
ts += n;
}
assert_eq!(ts, 64 * 1024 * 1024);
}Wooooooooooooooow?!
Benchmark 1: rust-std-fs-read-with-jemalloc/target/release/test
Time (mean ± σ): 9.7 ms ± 0.6 ms [User: 0.3 ms, System: 9.4 ms]
Range (min … max): 9.0 ms … 12.4 ms 259 runs
Benchmark 2: python-fs-read/test.py
Time (mean ± σ): 15.8 ms ± 0.9 ms [User: 5.9 ms, System: 9.8 ms]
Range (min … max): 15.0 ms … 21.8 ms 169 runs
Summary
rust-std-fs-read-with-jemalloc/target/release/test ran
1.64 ± 0.14 times faster than python-fs-read/test.py什么？！我知道 jemalloc 是一个高效的内存分配器，但它为啥会这么优秀呢？
只有在我的电脑上，Rust 运行速度比 Python 慢！
随着更多的朋友加入讨论，我们发现只有在我的机器上，Rust运行速度比Python慢。
我的 CPU:
> lscpu
Architecture: x86_64
CPU op-mode(s): 32-bit, 64-bit
Address sizes: 48 bits physical, 48 bits virtual
Byte Order: Little Endian
CPU(s): 32
On-line CPU(s) list: 0-31
Vendor ID: AuthenticAMD
Model name: AMD Ryzen 9 5950X 16-Core Processor
CPU family: 25
Model: 33
Thread(s) per core: 2
Core(s) per socket: 16
Socket(s): 1
Stepping: 0
Frequency boost: enabled
CPU(s) scaling MHz: 53%
CPU max MHz: 5083.3979
CPU min MHz: 2200.0000
BogoMIPS: 6787.49
Flags: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt pdpe1gb rdtscp lm con
stant_tsc rep_good nopl nonstop_tsc cpuid extd_apicid aperfmperf rapl pni pclmulqdq monitor ssse3 fma cx16 sse4_1 sse4_2 movbe popcnt aes xsave avx f
16c rdrand lahf_lm cmp_legacy svm extapic cr8_legacy abm sse4a misalignsse 3dnowprefetch osvw ibs skinit wdt tce topoext perfctr_core perfctr_nb bpex
t perfctr_llc mwaitx cpb cat_l3 cdp_l3 hw_pstate ssbd mba ibrs ibpb stibp vmmcall fsgsbase bmi1 avx2 smep bmi2 erms invpcid cqm rdt_a rdseed adx smap
clflushopt clwb sha_ni xsaveopt xsavec xgetbv1 xsaves cqm_llc cqm_occup_llc cqm_mbm_total cqm_mbm_local user_shstk clzero irperf xsaveerptr rdpru wb
noinvd arat npt lbrv svm_lock nrip_save tsc_scale vmcb_clean flushbyasid decodeassists pausefilter pfthreshold avic v_vmsave_vmload vgif v_spec_ctrl
umip pku ospke vaes vpclmulqdq rdpid overflow_recov succor smca fsrm debug_swap
Virtualization features:
Virtualization: AMD-V
Caches (sum of all):
L1d: 512 KiB (16 instances)
L1i: 512 KiB (16 instances)
L2: 8 MiB (16 instances)
L3: 64 MiB (2 instances)
NUMA:
NUMA node(s): 1
NUMA node0 CPU(s): 0-31
Vulnerabilities:
Gather data sampling: Not affected
Itlb multihit: Not affected
L1tf: Not affected
Mds: Not affected
Meltdown: Not affected
Mmio stale data: Not affected
Retbleed: Not affected
Spec rstack overflow: Vulnerable
Spec store bypass: Vulnerable
Spectre v1: Vulnerable: __user pointer sanitization and usercopy barriers only; no swapgs barriers
Spectre v2: Vulnerable, IBPB: disabled, STIBP: disabled, PBRSB-eIBRS: Not affected
Srbds: Not affected
Tsx async abort: Not affected我的内存:
> sudo dmidecode --type memory
# dmidecode 3.5
Getting SMBIOS data from sysfs.
SMBIOS 3.3.0 present.
Handle 0x0014, DMI type 16, 23 bytes
Physical Memory Array
Location: System Board Or Motherboard
Use: System Memory
Error Correction Type: None
Maximum Capacity: 64 GB
Error Information Handle: 0x0013
Number Of Devices: 4
Handle 0x001C, DMI type 17, 92 bytes
Memory Device
Array Handle: 0x0014
Error Information Handle: 0x001B
Total Width: 64 bits
Data Width: 64 bits
Size: 16 GB
Form Factor: DIMM
Set: None
Locator: DIMM 0
Bank Locator: P0 CHANNEL A
Type: DDR4
Type Detail: Synchronous Unbuffered (Unregistered)
Speed: 3200 MT/s
Manufacturer: Unknown
Serial Number: 04904740
Asset Tag: Not Specified
Part Number: LMKUFG68AHFHD-32A
Rank: 2
Configured Memory Speed: 3200 MT/s
Minimum Voltage: 1.2 V
Maximum Voltage: 1.2 V
Configured Voltage: 1.2 V
Memory Technology: DRAM
Memory Operating Mode Capability: Volatile memory
Firmware Version: Unknown
Module Manufacturer ID: Bank 9, Hex 0xC8
Module Product ID: Unknown
Memory Subsystem Controller Manufacturer ID: Unknown
Memory Subsystem Controller Product ID: Unknown
Non-Volatile Size: None
Volatile Size: 16 GB
Cache Size: None
Logical Size: None所以我尝试了以下事情：
👨🏻💻 开启 Mitigations
CPU 拥有许多可能将私有数据暴露给攻击者的漏洞，其中Spectre是最知名的之一。Linux 内核已经开发了各种缓解这些漏洞的措施，并且默认启用它们。然而，这些缓解措施可能会增加额外的系统成本。因此，Linux 内核也为希望禁用它们的用户提供了一个mitigations开关。
我过去禁用了所有的 mitigations：
title Arch Linux
linux /vmlinuz-linux-zen
initrd /amd-ucode.img
initrd /initramfs-linux-zen.img
options root="PARTUUID=206e7750-2b89-419d-978e-db0068c79c52" rw mitigations=off启用它并不能改变结果
👨🏻💻 调整透明大页
透明大页可以显著影响性能。大多数现代发行版默认启用它。
> cat /sys/kernel/mm/transparent_hugepage/enabled
[always] madvise never切换到 madvise 或 never 会改变绝对结果，但相对比例保持一致。
👨🏻💻 Tune CPU 核心亲和度
@Manjusaka 猜测这可能与 CPU核心间距 有关。我试图使用 core_affinity将进程绑定到特定的CPU，但结果仍然相同。
👨🏻💻 使用 eBPF 精确测量 syscall 延迟
@Manjusaka 也为我创建了 一个eBPF程序，以便我衡量读取系统调用的延迟。研究结果表明，Rust在系统调用级别上就比Python慢。
@Manjusaka 写一篇文章来分享关于这个 eBPF 程序的故事！
# python fs read
Process 57555 read file 8134049 ns
Process 57555 read file 942 ns
# rust std fs read
Process 57634 read file 24636975 ns
Process 57634 read file 1052 ns观察：在我的电脑上，Rust 运行速度比 Python 慢，而且这似乎与软件无关。
C 比 Python 慢？
当用户想要进行大数据分析时，心里所期望的基本是：
我感到相当困惑，无法准确指出差异。我怀疑这可能与 CPU 有关，但我不确定是哪个方面：缓存？频率？核间距？核亲和性？架构？
根据 Telegram 群组 Rust 众 的建议，我开发了一个C版本：
c-fs-read
#include <stdio.h>
#include <stdlib.h>
#define FILE_SIZE 64 * 1024 * 1024 // 64 MiB
int main() {
FILE *file;
char *buffer;
size_t result;
file = fopen("/tmp/file", "rb");
if (file == NULL) {
fputs("Error opening file", stderr);
return 1;
}
buffer = (char *)malloc(sizeof(char) * FILE_SIZE);
if (buffer == NULL) {
fputs("Memory error", stderr);
fclose(file);
return 2;
}
result = fread(buffer, 1, FILE_SIZE, file);
if (result != FILE_SIZE) {
fputs("Reading error", stderr);
fclose(file);
free(buffer);
return 3;
}
fclose(file);
free(buffer);
return 0;
}但是......
Benchmark 1: c-fs-read/test
Time (mean ± σ): 23.8 ms ± 0.9 ms [User: 0.3 ms, System: 23.6 ms]
Range (min … max): 23.0 ms … 27.1 ms 120 runs
Benchmark 2: python-fs-read/test.py
Time (mean ± σ): 19.1 ms ± 0.3 ms [User: 8.6 ms, System: 10.4 ms]
Range (min … max): 18.6 ms … 20.6 ms 146 runs
Summary
python-fs-read/test.py ran
1.25 ± 0.05 times faster than c-fs-read/testC 版本也比 Python 慢！Python 有魔法吗？
在指定的偏移量下，C 语言比 Python 慢！
当用户想要进行大数据分析时，心里所期望的基本是：
在这个时候，@lilydjwg 加入了讨论，并注意到 C 和 Python 之间的内存区域偏移存在差异。
strace -e raw=read,mmap ./program被用来打印系统调用的未解码参数：指针地址。
`c-fs-read` 的 strace:
> strace -e raw=read,mmap ./c-fs-read/test
...
mmap(0, 0x4001000, 0x3, 0x22, 0xffffffff, 0) = 0x7f96d1a18000
read(0x3, 0x7f96d1a18010, 0x4000000) = 0x4000000
close(3) = 0
python-fs-read 的 strace
`python-fs-read` 的 strace
> strace -e raw=read,mmap ./python-fs-read/test.py
...
mmap(0, 0x4001000, 0x3, 0x22, 0xffffffff, 0) = 0x7f27dcfbe000
read(0x3, 0x7f27dcfbe030, 0x4000001) = 0x4000000
read(0x3, 0x7f27e0fbe030, 0x1) = 0
close(3) = 0在 c-fs-read 中，mmap返回 0x7f96d1a18000，但是 read 系统调用使用 0x7f96d1a18010作为起始地址，偏移量是 0x10。在 python-fs-read中， mmap 返回 0x7f27dcfbe000, 并且 read 系统调用使用 0x7f27dcfbe030 作为起始地址, 偏移量是 0x30.
所以 @lilydjwg 尝试用相同的偏移量来调用 'read'。
:) ./bench c-fs-read c-fs-read-with-offset python-fs-read
['hyperfine', 'c-fs-read/test', 'c-fs-read-with-offset/test', 'python-fs-read/test.py']
Benchmark 1: c-fs-read/test
Time (mean ± σ): 23.7 ms ± 0.8 ms [User: 0.2 ms, System: 23.6 ms]
Range (min … max): 23.0 ms … 25.5 ms 119 runs
Warning: Statistical outliers were detected. Consider re-running this benchmark on a quiet system without any interferences from other programs. It might help to use the '--warmup' or '--prepare' options.
Benchmark 2: c-fs-read-with-offset/test
Time (mean ± σ): 8.9 ms ± 0.4 ms [User: 0.2 ms, System: 8.8 ms]
Range (min … max): 8.3 ms … 10.6 ms 283 runs
Benchmark 3: python-fs-read/test.py
Time (mean ± σ): 19.1 ms ± 0.3 ms [User: 8.6 ms, System: 10.4 ms]
Range (min … max): 18.6 ms … 20.0 ms 147 runs
Summary
c-fs-read-with-offset/test ran
2.15 ± 0.11 times faster than python-fs-read/test.py
2.68 ± 0.16 times faster than c-fs-read/test！！！
在c-fs-read中对buffer应用偏移量可以提高其速度，超过 Python！此外，我们已经验证了这个问题在 AMD Ryzen 9 5900X 和 AMD Ryzen 7 5700X 上都能复现。
新的信息让我找到了关于类似问题的其他报告，Std::fs::read slow?。在这篇帖子中，@ambiso 发现系统调用性能与内存区域的偏移量有关。他指出当从每页的前 0x10 字节写入时，这款 CPU 会变慢。
offset milliseconds
...
14 130
15 130
16 46 <----- 0x10!
17 48
...在指定的偏移量下，AMD Ryzen 9 5900X 很慢！
我们已确认这个问题与CPU有关。然而，我们仍然不确定其可能的原因。@Manjusaka 已邀请内核开发者 @ryncsn 加入讨论。
他可以在 AMD Ryzen 9 5900HX 上使用我们的 c-fs-read 和 c-fs-read-with-offset 重现相同的结果。他还尝试使用 perf 对两个程序进行性能分析。
没有 offset:
perf stat -d -d -d --repeat 20 ./a.out
Performance counter stats for './a.out' (20 runs):
30.89 msec task-clock # 0.968 CPUs utilized ( +- 1.35% )
0 context-switches # 0.000 /sec
0 cpu-migrations # 0.000 /sec
598 page-faults # 19.362 K/sec ( +- 0.05% )
90,321,344 cycles # 2.924 GHz ( +- 1.12% ) (40.76%)
599,640 stalled-cycles-frontend # 0.66% frontend cycles idle ( +- 2.19% ) (42.11%)
398,016 stalled-cycles-backend # 0.44% backend cycles idle ( +- 22.41% ) (41.88%)
43,349,705 instructions # 0.48 insn per cycle
# 0.01 stalled cycles per insn ( +- 1.32% ) (41.91%)
7,526,819 branches # 243.701 M/sec ( +- 5.01% ) (41.22%)
37,541 branch-misses # 0.50% of all branches ( +- 4.62% ) (41.12%)
127,845,213 L1-dcache-loads # 4.139 G/sec ( +- 1.14% ) (39.84%)
3,172,628 L1-dcache-load-misses # 2.48% of all L1-dcache accesses ( +- 1.34% ) (38.46%)
<not supported> LLC-loads
<not supported> LLC-load-misses
654,651 L1-icache-loads # 21.196 M/sec ( +- 1.71% ) (38.72%)
2,828 L1-icache-load-misses # 0.43% of all L1-icache accesses ( +- 2.35% ) (38.67%)
15,615 dTLB-loads # 505.578 K/sec ( +- 1.28% ) (38.82%)
12,825 dTLB-load-misses # 82.13% of all dTLB cache accesses ( +- 1.15% ) (38.88%)
16 iTLB-loads # 518.043 /sec ( +- 27.06% ) (38.82%)
2,202 iTLB-load-misses # 13762.50% of all iTLB cache accesses ( +- 23.62% ) (39.38%)
1,843,493 L1-dcache-prefetches # 59.688 M/sec ( +- 3.36% ) (39.40%)
<not supported> L1-dcache-prefetch-misses
0.031915 +- 0.000419 seconds time elapsed ( +- 1.31% )有 offset:
perf stat -d -d -d --repeat 20 ./a.out
Performance counter stats for './a.out' (20 runs):
15.39 msec task-clock # 0.937 CPUs utilized ( +- 3.24% )
1 context-switches # 64.972 /sec ( +- 17.62% )
0 cpu-migrations # 0.000 /sec
598 page-faults # 38.854 K/sec ( +- 0.06% )
41,239,117 cycles # 2.679 GHz ( +- 1.95% ) (40.68%)
547,465 stalled-cycles-frontend # 1.33% frontend cycles idle ( +- 3.43% ) (40.60%)
413,657 stalled-cycles-backend # 1.00% backend cycles idle ( +- 20.37% ) (40.50%)
37,009,429 instructions # 0.90 insn per cycle
# 0.01 stalled cycles per insn ( +- 3.13% ) (40.43%)
5,410,381 branches # 351.526 M/sec ( +- 3.24% ) (39.80%)
34,649 branch-misses # 0.64% of all branches ( +- 4.04% ) (39.94%)
13,965,813 L1-dcache-loads # 907.393 M/sec ( +- 3.37% ) (39.44%)
3,623,350 L1-dcache-load-misses # 25.94% of all L1-dcache accesses ( +- 3.56% ) (39.52%)
<not supported> LLC-loads
<not supported> LLC-load-misses
590,613 L1-icache-loads # 38.374 M/sec ( +- 3.39% ) (39.67%)
1,995 L1-icache-load-misses # 0.34% of all L1-icache accesses ( +- 4.18% ) (39.67%)
16,046 dTLB-loads # 1.043 M/sec ( +- 3.28% ) (39.78%)
14,040 dTLB-load-misses # 87.50% of all dTLB cache accesses ( +- 3.24% ) (39.78%)
11 iTLB-loads # 714.697 /sec ( +- 29.56% ) (39.77%)
3,657 iTLB-load-misses # 33245.45% of all iTLB cache accesses ( +- 14.61% ) (40.30%)
395,578 L1-dcache-prefetches # 25.702 M/sec ( +- 3.34% ) (40.10%)
<not supported> L1-dcache-prefetch-misses
0.016429 +- 0.000521 seconds time elapsed ( +- 3.17% )他发现L1-dcache-prefetches和L1-dcache-loads的值差异很大。
-
L1-dcache-prefetches是 CPU L1 数据缓存的预取。 -
L1-dcache-loads是 CPU L1 数据缓存的加载。
如果没有指定偏移量，CPU 将执行更多的加载和预取操作，导致系统调用时间增加。
他对热点 ASM 进行了进一步研究：
Samples: 15K of event 'cycles:P', Event count (approx.): 6078132137
Children Self Command Shared Object Symbol
- 94.11% 0.00% a.out [kernel.vmlinux] [k] entry_SYSCALL_64_after_hwframe
- entry_SYSCALL_64_after_hwframe
- 94.10% do_syscall_64
- 86.66% __x64_sys_read
ksys_read
- vfs_read
- 85.94% shmem_file_read_iter
- 77.17% copy_page_to_iter
- 75.80% _copy_to_iter
+ 19.41% asm_exc_page_fault
0.71% __might_fault
+ 4.87% shmem_get_folio_gfp
0.76% folio_mark_accessed
+ 4.38% __x64_sys_munmap
+ 1.02% 0xffffffffae6f6fe8
+ 0.79% __x64_sys_execve
+ 0.58% __x64_sys_mmap _copy_to_iter 中的 ASM：
│ copy_user_generic():
2.19 │ mov %rdx,%rcx
│ mov %r12,%rsi
92.45 │ rep movsb %ds:(%rsi),%es:(%rdi)
0.49 │ nop
│ nop
│ nop这里的关键区别是rep movsb的性能。
AMD Ryzen 9 5900X 因为 FSRM 慢！
在这个时候，我的一个朋友给我发送了一个关于Terrible memcpy performance on Zen 3 when using rep movsb的链接。其中也指向了rep movsb：
I've found this using a memcpy benchmark at https://github.com/ska-sa/katgpucbf/blob/69752be58fb8ab0668ada806e0fd809e782cc58b/scratch/memcpy\\_loop.cpp (compiled with the adjacent Makefile). To demonstrate the issue, run
./memcpy_loop -b 2113 -p 1000000 -t mmap -S 0 -D 1 0
This runs:
• 2113-byte memory copies
• 1,000,000 times per timing measurement
• in memory allocated with mmap
• with the source 0 bytes from the start of the page
• with the destination 1 byte from the start of the page
• on core 0.
It reports about 3.2 GB/s. Change the -b argument to 2111 and it reports over 100 GB/s. So the REP MOVSB case is about 30× slower!
FSRM，即 Fast Short REP MOV，是英特尔最初的创新，近期也被AMD采纳，用以提升 rep movsb 和 rep movsd的速度。它旨在提高大量内存复制的效率。声明支持它的CPU将在 glibc 中默认使用 FSRM。
@ryncsn 进一步研究并发现它与 L1 预取无关。
It seems that
rep movsbperformance poorly when DATA IS PAGE ALIGNED, and perform better when DATA IS NOT PAGE ALIGNED, this is very funny...
总结
总的来说，这个问题并非与软件有关。由于 AMD 的一个错误，Python 在性能上超过了 C/Rust。（我终于可以好好睡觉了。）
然而，我们的用户仍然需要面对这个问题。不幸的是，像FSRM这样的功能将会被实现在ucode中，我们别无选择只能等待 AMD 的回应。另一种可能的解决方案是不使用FSRM或者提供一个标志来禁用它。Rust 开发者可能会考虑切换到 jemallocator以提高性能 ，即使没有 AMD CPU Bug 存在，这也是一个好主意！
回顾
我花了近三天的时间来解决这个问题，它始于 opendal: 用户的投诉，并最终引导我到CPU的微代码。这次旅程让我对strace、perf和eBPF有了深入的了解。这是我第一次使用 eBPF进行诊断。我还探索了各种收效甚微的途径，比如研究 rust 的 std::fs 和 Python & CPython 的读取实现细节。起初，我希望能在更高层面上解决这个问题，但发现有必要深入挖掘。
对于所有参与寻找答案的人，我表示衷心感谢：
-
感谢 opendal 的 Discord 上的 @beldathas 发现了这个问题。
-
感谢 @datafuselabs 团队提供的建议。
-
感谢我们在 Rust 众 的朋友们给出的建议和复现努力。
-
感谢 @Manjusaka 复现问题并使用eBPF进行调查，这帮助我们将问题定位到系统调用本身。
-
感谢 @lilydjwg 找出根本原因：内存中
0x20偏移量 -感谢 @ryncsn 他对此事进行了彻底分析。 -
• 还有一位分享了关于 FSRM 有用链接的朋友。
期待我们下次旅程！
引用
-
Xuanwo/when-i-find-rust-is-slow 有所有的样例和脚本
-
Std::fs::read slow? 是来自 Rust 社区的汇报
-
Terrible memcpy performance on Zen 3 when using rep movsb 是来自 ubuntu glibc 的报告
-
[binding/python](rust std fs is slower than python fs: binding/python: rust std fs is slower than python fs · Issue #3665 · apache/incubator-opendal · GitHub)
关于 Databend
Databend 是一款开源、弹性、低成本，基于对象存储也可以做实时分析的新式数仓。期待您的关注，一起探索云原生数仓解决方案，打造新一代开源 Data Cloud。
👨💻 Databend Cloud：https://databend.cn
📖 Databend 文档：Databend - The Future of Cloud Data Analytics. | Databend
💻 Wechat：Databend
✨ GitHub：GitHub - datafuselabs/databend: Modern alternative to Snowflake. Cost-effective and simple for massive-scale analytics. Cloud: https://databend.com
