Rust std fs 比 Python 慢!真的吗!?

作者:Xuanwo

Databend Labs 成员,数据库研发工程师

https://github.com/xuanwo

我即将分享一个冗长的故事,从 OpenDALop.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 * 1024

python-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.py

OpenDAL 的 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采用了 brkmmap 系统调用来根据我们的请求大小分配内存。如果请求的大小足够大,那么 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/test

C 版本也比 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 5900XAMD 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-readc-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-prefetchesL1-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 movsbrep movsd 的速度。它旨在提高大量内存复制的效率。声明支持它的 CPU 将在 glibc 中默认使用 FSRM

@ryncsn 进一步研究并发现它与 L1 预取无关。

It seems that rep movsb performance 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 的微代码。这次旅程让我对straceperfeBPF有了深入的了解。这是我第一次使用 eBPF进行诊断。我还探索了各种收效甚微的途径,比如研究 rust 的 std::fs 和 Python & CPython 的读取实现细节。起初,我希望能在更高层面上解决这个问题,但发现有必要深入挖掘。

对于所有参与寻找答案的人,我表示衷心感谢:

  • 感谢 opendal 的 Discord 上的 @beldathas 发现了这个问题。

  • 感谢 @datafuselabs 团队提供的建议。

  • 感谢我们在 Rust 众 的朋友们给出的建议和复现努力。

  • 感谢 @Manjusaka 复现问题并使用 eBPF 进行调查,这帮助我们将问题定位到系统调用本身。

  • 感谢 @lilydjwg 找出根本原因:内存中0x20偏移量 -感谢 @ryncsn 他对此事进行了彻底分析。

  • • 还有一位分享了关于 FSRM 有用链接的朋友。

期待我们下次旅程!

引用

本文文字及图片出自 InfoQ

余下全文(1/3)
分享这篇文章:

发表回复

您的电子邮箱地址不会被公开。 必填项已用 * 标注