В этой статье я поделюсь с вами долгой историей, которая начинается с op.read() opendal, а заканчивается неожиданным поворотом. Это путешествие оказалось для меня достаточно поучительным, надеюсь, и для вас оно будет таким же. Я постараюсь максимально точно воссоздать свой опыт и дополню его выводами, которые сделал в процессе.
Все фрагменты кода и скрипты выложены в Xuanwo/when-i-find-rust-is-slow
TL;DR
Если вам срочно нужно знать ответ, сразу перейдите к разделу «Вывод».
Привязка OpenDAL к Python медленнее, чем Python?
OpenDAL — это слой доступа к данным, позволяющий удобно и эффективно получать данные из различных сервисов хранения единым образом. Мы предоставляем для OpenDAL привязку к Python при помощи pyo3.
Однажды @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
Так-так-так. Меня неприятно поразили эти результаты. У меня быстро возникло несколько гипотез:
-
У Python есть внутренний кэш, способный многократно использовать одну и ту же память?
-
У Python есть какой-то трюк, ускоряющий чтение файлов?
-
Лишняя трата ресурсов возникает из-за PyO3?
Я отрефакторил код:
with open("/tmp/file", "rb") as fp:
result = fp.read()
assert len(result) == 64 * 1024 * 1024
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. Попробуем выявить первопричину.
Я реализовал ту же логику через сервис opendal fs на rust:
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 медленнее, чем python, даже если opendal реализован на rust:
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.
std fs Rust медленнее, чем Python?
OpenDAL реализует сервис fs через std::fs. Возможно, дополнительные затраты вызваны самим OpenDAL?
Мы реализуем ту же логику через std::fs rust:
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
Ого, std fs Rust медленнее, чем Python? Как такое возможно?
std fs Rust медленнее, чем Python? Серьёзно?!
Не могу поверить этим результатам: std fs rust неожиданно медленнее, чем Python.
Я разобрался, как использовать strace для анализа системных вызовов. strace — это трассировщик системных вызовов для Linux, позволяющий выполнять мониторинг системных вызовов и понимать их процессы.
strace исследует все системные вызовы, диспетчеризируемые программой. Нас должны интересовать аспекты, связанные с/tmp/file. Каждая строка вывода strace начинается с имени системного вызова, за которым идут входные аргументы и вывод.
Например:
openat(AT_FDCWD, "/tmp/file", O_RDONLY|O_CLOEXEC) = 3Это значит, что мы вызываем системный вызов openat , указав аргументы AT_FDCWD, "/tmp/file" и O_RDONLY|O_CLOEXEC. При этом возвращается вывод 3 — дескриптор файла, на который выполняется ссылка в последующем системном вызове.
Отлично, мы в совершенстве освоили strace. Давайте воспользуемся им!
Результаты strace для rust-std-fs-read:
> 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, "tP201A225366>260270R365313220{E372274635"353204220s2|7C2052656263"..., 67108864) = 67108864
read(3, "", 0) = 0
close(3) = 0
munmap(0x7f290dd40000, 67112960) = 0
...Результаты strace для python-fs-read:
> 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, "tP201A225366>260270R365313220{E372274635"353204220s2|7C2052656263"..., 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: размер области памяти для отображения. Здесь мы распределяем 64 МиБ + 4 КиБ памяти, дополнительная страница используется для хранения метаданных этой области памяти. -
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, которая позволяет устранять проблемы фрагментации памяти.
По умолчанию все программы на Rust, компилируемые под целевую платформу x86_64-unknown-linux-gnu, используют malloc, предоставляемую glibc.
Использует ли Python тот же распределитель памяти, что и Rust?
По умолчанию Python использует pymalloc — распределитель памяти, оптимизированный под небольшие распределения. Python имеет три диапазона памяти, каждый из который отражает разные стратегии распределения и оптимизирован под разные цели.
pymalloc имеет следующее поведение:
У Python есть распределитель
pymalloc, оптимизированный под мелкие объекты (меньше или равные 512 байтам) с коротким временем жизни. Он использует отображения памяти, называемые «аренами» (arena) c фиксированным размером 256 КиБ (на 32-битных платформах) или 1 МиБ на 64-битных платформах. Если распределения больше 512 байтов, он возвращается к использованию PyMem_RawMalloc() и PyMem_RawRealloc().
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);
}
Ого-о-о!
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
Я попробовал следующие решения:
Включение мер защиты
В 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
Их включение никак не изменило результат.
Настройка Transparent Hugepage
Transparent Hugepage может существенно влиять на производительность. Most modern distributions enable it by default.
> cat /sys/kernel/mm/transparent_hugepage/enabled
[always] madvise never
Переключение на madvise или never влияет на абсолютный результат, но относительное соотношение остаётся неизменным.
Настройка CPU Core Affinity
@Manjusaka предположил, что это связано с CPU Core Spacing.
Я попробовал воспользоваться core_affinity , чтобы привязать процесс к конкретному CPU, но результат оказался таким же.
Измерение задержек системных вызовов при помощи eBPF
@Manjusaka написал для меня программу eBPF, измеряющую задержки системных вызовов чтения. Из её показателей следует, что Rust медленнее, чем Python и на уровне системных вызовов.
Об этой программе eBPF тоже есть длинная история, которую @Manjusaka должен рассказать в отдельном посте!
# 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, но не уверен, в каком аспекте: кэш? частота? core spacing? core affinity? архитектура?
По рекомендациям из Telegram-группы @rust_zh я разработал версию на C:
#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: адрес указателя.
strace дляc-fs-read:
> strace -e raw=read,mmap ./c-fs-read/test
...
mmap(0, 0x4001000, 0x3, 0x22, 0xffffffff, 0) = 0x7f96d1a18000
read(0x3, 0x7f96d1a18010, 0x4000000) = 0x4000000
close(3) = 0strace для python-fs-read
> 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, но системный вызов чтения использует в качестве начального адреса0x7f96d1a18010 , смещение равно 0x10. В python-fs-read mmap возвращает 0x7f27dcfbe000, а системный вызов чтения использует в качестве начального адреса 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!!!
Применив смещение к buffer в c-fs-read , мы повысили его скорость, обогнав Python! Кроме того, мы подтвердили, что проблема воспроизводится и наAMD Ryzen 9 5900X, и на AMD Ryzen 7 5700X.
Новая информация привела меня к другим отчётам о похожей проблеме: Std::fs::read slow? В этом посте @ambiso обнаружил, что производительность системных вызовов связана со смещением области памяти. Он показал, что CPU замедляется, выполняя запись из первых 0x10 байтов каждой страницы:
offset milliseconds
...
14 130
15 130
16 46 <----- 0x10!
17 48
...AMD Ryzen 9 5900X медленный без указания смещения!
Мы доказали, что эта проблема связана с CPU, однако до сих пор не в курсе потенциальных причин. @Manjusaka пригласил присоединиться к обсуждению разработчика ядра @ryncsn.
Он смог воспроизвести тот же результат, запустив демо c-fs-read и c-fs-read-with-offset на AMD Ryzen 9 5900HX. Также он попробовал профилировать эти две программы при помощи perf.
Без смещения:
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% )Со смещением:
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— выборки с упреждением кэша данных L1 CPU. -
L1-dcache-loads— загрузки кэша данных L1 CPU.
Без указания смещения CPU выполняет больше загрузок и выборок с упреждением L1-dcache, что приводит к увеличению времени системных вызовов.
Он провёл углублённое исследование горячей точки 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!
В это время один из моих друзей отправил мне ссылку об ужасной производительности memcpy на Zen 3 при использовании rep movsb. В ней тоже упоминалась rep movsb:
Я обнаружил это при помощи бенчмарка memcpy https://github.com/ska-sa/katgpucbf/blob/69752be58fb8ab0668ada806e0fd809e782cc58b/scratch/memcpy_loop.cpp (скомпилированного при помощи находящегося там же Makefile). Для демонстрации проблемы выполните
./memcpy_loop -b 2113 -p 1000000 -t mmap -S 0 -D 1 0
При этом происходит следующее:
2113-байтные копирования в памяти
1000000 раз за измеряемое время
в памяти, распределённой при помощи mmap
с 0 байтами источника от начала страницы
с 1 байтом адресата от начала страницы
в ядре 0.
Результат равен примерно 3,2 ГБ/с. Если изменить аргумент на 2111, то результат станет больше 100 ГБ/с. То есть случай с REP MOVSB примерно в тридцать раз медленнее!
FSRM (Fast Short REP MOV) — это инновация Intel, недавно внедрённая и в архитектуры AMD; она повышает скорость rep movsb и rep movsd. Она спроектирована с целью повышения эффективности больших объёмов памяти. CPU, в которых заявлена её поддержка, по умолчанию используют glibc в FSRM.
@ryncsn провёл дополнительные исследования и обнаружил, что это не связано с упреждающими выборками L1.
Похоже, производительность
rep movsbнизка, когда данные выровнены по страницам, и она выше, когда данные не выровнены по страницам, что очень забавно...
Вывод
Проблема не связана с ПОconclusion. Python обгоняет по производительности C/Rust из-за бага в процессоре AMD. (И я наконец-то могу спать спокойно.)
Однако наши пользователи по-прежнему испытывают трудности с этой проблемой. К сожалению, функции наподобие FSRM будут реализованы в ucode, не оставляя нам никакого выбора, кроме как ждать ответа AMD. Альтернативное решение может заключаться в том, чтобы не использовать FSRM или предоставить флаг для её отключения. Разработчикам на Rust стоит задуматься о переходе jemallocator для повышения производительности, это выигрышный ход даже без наличия багов в процессорах AMD.
Дополнения
На разбор этой проблемы я потратил почти три дня. Всё началось с жалоб пользователей opendal и в конечном итоге привело меня к ucode CPU.
В ходе анализа я многое узнал о strace, perf и eBPF. Я впервые использовал eBPF для диагностики. Также я исследовал множество различных бесплодных догадок, например, изучил реализацииstd::fs в Rust и подробности реализации чтения в Python и CPython. Поначалу я надеялся разрешить проблему на высоком уровне, но оказалось, что нужно погрузиться глубже.
Большое спасибо всем тем, кто поучаствовал в поиске ответа:
-
@beldathas из discord opendal за выявление проблемы.
-
Команде @datafuselabs за её полезные рекомендации.
-
Нашим друзьям из @rust_zh (telegram-группа по 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
Обновления
Эта статья, написанная 29 ноября 2023 года, привлекла большое внимание! Чтобы не запутывать читателей, я решил не изменять оригинальное содержание; обеспечивать актуальность информации и отвечать на популярные вопросы я буду в обновлениях.
1 декабря 2023 года: знает ли AMD об этом баге?
TL;DR: Да
Насколько я знаю, AMD было известно об этом баге ещё с 2021 года. После публикации статьи многие читатели отправили ссылку в AMD, так что я уверен, что компания о ней проинформирована.
Я уверен, что AMD должна взять на себя ответственность за этот баг и устранить его в amd-ucode. Однако из неподтверждённых источников стало известно, что исправление через amd-ucode маловероятно (по крайней мере, для Zen 3) из-за ограниченного пространства в патче. Если у вас есть какая-то информация по этому вопросу, прошу написать мне.
Наша единственная надежда — изменения в glibc, позволяющие по необходимости отключать FSRM. На этом фронте заметен прогресс: x86: Improve ERMS usage on Zen3. Следите за обновлениями.
1 декабря 2023 года: jemalloc или pymalloc быстрее, чем malloc из glibc?
TL;DR: Нет
Прошу прощения за то, что подробно не написал о связи между распределителем памяти и этим багом. Из поста может показаться, что jemalloc (pymalloc, mimalloc) существенно быстрее, чем malloc из glibc. Однако это не так. Проблема не связана с распределителем памяти. Разница в скорости, из-за которой jemalloc и pymalloc обгоняют malloc glibc, возникла из-за разных смещений области памяти.
Давайте проанализируем strace rust-std-fs-read и rust-std-fs-read-with-jemalloc:
strace для rust-std-fs-read:
> strace -e raw=read,mmap ./rust-std-fs-read/target/release/test
...
mmap(0, 0x4001000, 0x3, 0x22, 0xffffffff, 0) = 0x7f39a6e49000
openat(AT_FDCWD, "/tmp/file", O_RDONLY|O_CLOEXEC) = 3
read(0x3, 0x7f39a6e49010, 0x4000000) = 0x4000000
read(0x3, 0x7f39aae49010, 0) = 0
close(3) = 0strace для rust-std-fs-read-with-jemalloc:
> strace -e raw=read,mmap ./rust-std-fs-read-with-jemalloc/target/release/test
...
mmap(0, 0x200000, 0x3, 0x4022, 0xffffffff, 0) = 0x7f7a5a400000
mmap(0, 0x5000000, 0x3, 0x4022, 0xffffffff, 0) = 0x7f7a55400000
openat(AT_FDCWD, "/tmp/file", O_RDONLY|O_CLOEXEC) = 3
read(0x3, 0x7f7a55400740, 0x4000000) = 0x4000000
read(0x3, 0x7f7a59400740, 0) = 0
close(3) = 0В rust-std-fs-read mmap возвращает 0x7f39a6e49000, но системный вызов чтения использует в качестве начального адреса 0x7f39a6e49010, смещение равно 0x10. В rust-std-fs-read-with-jemalloc mmap возвращает 0x7f7a55400000, а системный вызов чтения использует в качестве начального адреса 0x7f7a55400740, смещение равно0x740.
rust-std-fs-read-with-jemalloc обгоняетrust-std-fs-read из-за большего смещения, которое выходит за пределы проблемного интервала: 0x00..0x10 страницы. Эту проблему можно воспроизвести и с jemalloc.
Автор:
PatientZero
